15 second timeout for POST requests?

[Ben Maurer]

Hey --

Returning from Munich I was using the terrible airport wifi and noticed that some of my post requests were being aborted after exactly 15 seconds. I've attached a net-internals trace from that request below. The full H2 session trace is here: https://gist.githubusercontent.com/bmaurer/0d38c32681a4937cc92079a5269757c3/raw/56441a46b4182c6ef0315788030cfefeb0e0108f/gistfile1.txt

Is there some kind of timeout that would cause this request to get aborted after 15 seconds? It looks like the socket was very much alive both before and after this POST request (though I was limited by bandwidth and packet loss).

-b

t=125329 [st=    0] +REQUEST_ALIVE  [dt=14999]
t=125329 [st=    0]   +URL_REQUEST_DELEGATE  [dt=1]
t=125329 [st=    0]      DELEGATE_INFO  [dt=1]
                         --> delegate_info = "extension AdBlock"
t=125330 [st=    1]   -URL_REQUEST_DELEGATE
t=125330 [st=    1]   +URL_REQUEST_START_JOB  [dt=6]
                       --> load_flags = 33026 (BYPASS_CACHE | MAYBE_USER_GESTURE | VERIFY_EV_CERT)
                       --> method = "POST"
                       --> priority = "LOW"
                       --> upload_id = "0"
                       --> url = "https://www.facebook.com/ajax/bz"
t=125335 [st=    6]      SERVICE_WORKER_START_REQUEST
t=125335 [st=    6]      SERVICE_WORKER_WAITING_FOR_REQUEST_BODY_BLOB  [dt=0]
                         --> success = true
t=125336 [st=    7]      SERVICE_WORKER_FALLBACK_RESPONSE
t=125336 [st=    7]   -URL_REQUEST_START_JOB
t=125336 [st=    7]   +URL_REQUEST_START_JOB  [dt=14992]
                       --> load_flags = 33026 (BYPASS_CACHE | MAYBE_USER_GESTURE | VERIFY_EV_CERT)
                       --> method = "POST"
                       --> priority = "LOW"
                       --> upload_id = "0"
                       --> url = "https://www.facebook.com/ajax/bz"
t=125336 [st=    7]      URL_REQUEST_DELEGATE  [dt=0]
t=125336 [st=    7]      HTTP_CACHE_GET_BACKEND  [dt=0]
t=125336 [st=    7]      URL_REQUEST_DELEGATE  [dt=0]
t=125336 [st=    7]     +HTTP_STREAM_REQUEST  [dt=5]
t=125336 [st=    7]        HTTP_STREAM_REQUEST_STARTED_JOB
                           --> source_dependency = 2371 (HTTP_STREAM_JOB)
t=125340 [st=   11]        HTTP_STREAM_REQUEST_BOUND_TO_JOB
                           --> source_dependency = 2371 (HTTP_STREAM_JOB)
t=125341 [st=   12]     -HTTP_STREAM_REQUEST
t=125341 [st=   12]     +HTTP_TRANSACTION_SEND_REQUEST  [dt=1]
t=125341 [st=   12]        HTTP_TRANSACTION_HTTP2_SEND_REQUEST_HEADERS
                           --> :authority: www.facebook.com
                               :method: POST
                               :path: /ajax/bz
                               :scheme: https
                               accept: */*
                               accept-encoding: gzip, deflate, br
                               accept-language: en-US,en;q=0.8
                               cache-control: no-cache
                               content-length: 721
                               content-type: application/x-www-form-urlencoded
                               cookie: [752 bytes were stripped]
                               origin: https://www.facebook.com
                               pragma: no-cache
                               referer: https://www.facebook.com/
                               user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2704.84 Safari/537.36
t=125342 [st=   13]     -HTTP_TRANSACTION_SEND_REQUEST
t=125342 [st=   13]     +HTTP_TRANSACTION_READ_HEADERS  [dt=14986]
t=125342 [st=   13]        HTTP2_STREAM_UPDATE_SEND_WINDOW
                           --> delta = -721
                           --> stream_id = 333
                           --> window_size = 64815
t=140328 [st=14999]        CANCELLED
t=140328 [st=14999]   -URL_REQUEST_START_JOB
                       --> net_error = -3 (ERR_ABORTED)
t=140328 [st=14999]    URL_REQUEST_DELEGATE  [dt=0]
t=140328 [st=14999] -REQUEST_ALIVE

[Matt Menke]

On network timeouts, you'd generally see ERR_TIMED_OUT, ERR_CONNECTION_TIMEOUT, or a SPDY/QUIC ping timeout.

ERR_ABORTED generally isn't generated by the network stack (With the exception of entering suspend mode, and maybe network changes, in some cases).  Unless that was happening, the cancellations most likely didn't come from the network stack.

--
You received this message because you are subscribed to the Google Groups "net-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to net-dev+u...@chromium.org.
To post to this group, send email to net...@chromium.org.
To view this discussion on the web visit https://groups.google.com/a/chromium.org/d/msgid/net-dev/984d5bc4-4b9d-4f59-8a10-9df2c5359ea1%40chromium.org.

[Ben Maurer]

Ah, that's a useful hint. I think I found where in our code we might be aborting the request on our own :-)

-b