Uploaded image for project: 'Traffic Server'
  1. Traffic Server
  2. TS-3415

H2 sending FIN stream too early

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 5.3.0
    • Component/s: HTTP/2
    • Labels:
      None

      Description

      With H2 running on the docs/jenkins server, some of us have noticed empty pages on chrome/FF when hitting those servers. Looking at the H2 traces, it seems that ATS is sending FIN streams (both SPDY_SESSION_RECV_HEADERS and SPDY_SESSION_RECV_DATA with fin flag set to true) before sending the data frames. This makes the browser display blank pages.

      Example:

      t=31890437 [st=140]    SPDY_SESSION_RECV_DATA
                             --> fin = true
                             --> size = 0
                             --> stream_id = 1
      t=31890437 [st=140]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 2591
                             --> stream_id = 1
      
      

      Detailed traces below:

      1112054: SPDY_SESSION
      ci.trafficserver.apache.org:443 (DIRECT)
      Start Time: 2015-02-26 13:30:14.060
      
      t=31890297 [st=  0] +SPDY_SESSION  [dt=?]
                           --> host = "ci.trafficserver.apache.org:443"
                           --> proxy = "DIRECT"
      t=31890297 [st=  0]    SPDY_SESSION_INITIALIZED
                             --> protocol = "h2-14"
                             --> source_dependency = 1112049 (SOCKET)
      t=31890297 [st=  0]    SPDY_SESSION_SEND_SETTINGS
                             --> settings = ["[id:3 flags:0 value:1000]","[id:4 flags:0 value:10485760]"]
      t=31890297 [st=  0]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 10420224
                             --> window_size = 10485760
      t=31890297 [st=  0]    SPDY_SESSION_SENT_WINDOW_UPDATE_FRAME
                             --> delta = 10420224
                             --> stream_id = 0
      t=31890297 [st=  0]    SPDY_SESSION_SYN_STREAM
                             --> fin = true
                             --> :authority: ci.trafficserver.apache.org
                                 :method: GET
                                 :path: /job/tsqa-master/180/consoleFull
                                 :scheme: https
                                 accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
                                 accept-encoding: gzip, deflate, sdch
                                 accept-language: en-US,en;q=0.8
                                 cache-control: max-age=0
                                 cookie: [71 bytes were stripped]
                                 user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.115 Safari/537.36
                             --> spdy_priority = 0
                             --> stream_id = 1
                             --> unidirectional = false
      t=31890335 [st= 38]    SPDY_SESSION_RECV_SETTINGS
                             --> clear_persisted = false
                             --> host = "ci.trafficserver.apache.org:443"
      t=31890335 [st= 38]    SPDY_SESSION_RECV_SETTING
                             --> flags = 0
                             --> id = 1
                             --> value = 4096
      t=31890335 [st= 38]    SPDY_SESSION_RECV_SETTING
                             --> flags = 0
                             --> id = 2
                             --> value = 0
      t=31890335 [st= 38]    SPDY_SESSION_RECV_SETTING
                             --> flags = 0
                             --> id = 3
                             --> value = 100
      t=31890436 [st=139]    SPDY_SESSION_RECV_HEADERS
                             --> fin = true
                             --> :status: 200
                                 age: 1
                                 cache-control: no-cache,no-store,must-revalidate
                                 content-encoding: gzip
                                 content-type: text/html;charset=UTF-8
                                 date: Thu, 26 Feb 2015 21:30:14 GMT
                                 expires: Thu, 01 Jan 1970 00:00:00 GMT
                                 server: ATS/5.3.0
                                 set-cookie: [67 bytes were stripped]
                                 strict-transport-security: max-age=86400
                                 via: http/1.1 ATS (ApacheTrafficServer/5.3.0 [cMsSf ])
                                 x-frame-options: sameorigin
                                 x-hudson: 1.395
                                 x-hudson-cli-port: 40666
                                 x-hudson-theme: default
                                 x-instance-identity: MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEA5JuJJnF3WReAyfHqknx9O1JV3chT6Iihwk/UIOYpZ6tLORwKrzPYVO6ho7cpwT9Jtfj91lb9Gpx0FZnhGZXsdh9SMYG8gUfGo3DRy9dLkXjNu5kYo9PQk701PvnCQJSByIpzGWTCoIwfgWTGqMEuGYZ5TvRbLnmm9j9ujo2SQpOeAUXi9f0d27wcb/MOYv8H8nICgsAcpp1AaTcboabfsJYWNodDDPYvtCjfIbQhBov5qDFnsmYXbmWavXaJ2ZGI24jSmdebFcto7NlbLLAI0JFHFualDGvfcY51NGaiK1+MNxllYsEnVSP6kSdxEtJSHOxN7z6oRVGKExh104YyDQIDAQAB
                                 x-jenkins: 1.598
                                 x-jenkins-cli-port: 40666
                                 x-jenkins-cli2-port: 40666
                                 x-jenkins-session: 906fc928
                             --> stream_id = 1
      t=31890437 [st=140]    SPDY_SESSION_RECV_DATA
                             --> fin = true
                             --> size = 0
                             --> stream_id = 1
      t=31890437 [st=140]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 2591
                             --> stream_id = 1
      t=31890437 [st=140]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -2591
                             --> window_size = 10483169
      t=31890437 [st=140]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 2591
                             --> window_size = 10485760
      t=31890437 [st=140]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 5592
                             --> stream_id = 1
      t=31890437 [st=140]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -5592
                             --> window_size = 10480168
      t=31890437 [st=140]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 5592
                             --> window_size = 10485760
      t=31890437 [st=140]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 2591
                             --> stream_id = 1
      t=31890437 [st=140]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -2591
                             --> window_size = 10483169
      t=31890437 [st=140]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 2591
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 3900
                             --> stream_id = 1
      t=31890488 [st=191]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -3900
                             --> window_size = 10481860
      t=31890488 [st=191]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 3900
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 1692
                             --> stream_id = 1
      t=31890488 [st=191]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -1692
                             --> window_size = 10484068
      t=31890488 [st=191]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 1692
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 6491
                             --> stream_id = 1
      t=31890488 [st=191]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -6491
                             --> window_size = 10479269
      t=31890488 [st=191]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 6491
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 1692
                             --> stream_id = 1
      t=31890488 [st=191]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -1692
                             --> window_size = 10484068
      t=31890488 [st=191]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 1692
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 6491
                             --> stream_id = 1
      t=31890488 [st=191]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -6491
                             --> window_size = 10479269
      t=31890488 [st=191]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 6491
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = false
                             --> size = 647
                             --> stream_id = 1
      t=31890488 [st=191]    SPDY_SESSION_UPDATE_RECV_WINDOW
                             --> delta = -647
                             --> window_size = 10485113
      t=31890488 [st=191]    SPDY_STREAM_UPDATE_RECV_WINDOW
                             --> delta = 647
                             --> window_size = 10485760
      t=31890488 [st=191]    SPDY_SESSION_RECV_DATA
                             --> fin = true
                             --> size = 0
                             --> stream_id = 1
      t=31890490 [st=193]    SPDY_SESSION_SYN_STREAM
                             --> fin = true
                             --> :authority: ci.trafficserver.apache.org
                                 :method: GET
                                 :path: /favicon.ico
                                 :scheme: https
                                 accept: */*
                                 accept-encoding: gzip, deflate, sdch
                                 accept-language: en-US,en;q=0.8
                                 cookie: [71 bytes were stripped]
                                 if-modified-since: Fri, 30 Jan 2015 15:31:33 GMT
                                 user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.115 Safari/537.36
                             --> spdy_priority = 4
                             --> stream_id = 3
                             --> unidirectional = false
      t=31890555 [st=258]    SPDY_SESSION_RECV_HEADERS
                             --> fin = true
                             --> :status: 304
                                 date: Thu, 26 Feb 2015 21:30:14 GMT
                                 expires: Mon, 09 Feb 2015 19:39:27 GMT
                                 server: ATS/5.3.0
                                 strict-transport-security: max-age=86400
                                 via: http/1.1 ATS (ApacheTrafficServer/5.3.0 [cSsNfU])
                             --> stream_id = 3
      t=31890555 [st=258]    SPDY_SESSION_RECV_DATA
                             --> fin = true
                             --> size = 0
                             --> stream_id = 3
      

        Attachments

        1. ts-3415.diff
          0.7 kB
          Susan Hinrichs
        2. ts-3415-3414.diff
          1 kB
          Susan Hinrichs
        3. ts-3415-02.diff
          4 kB
          Ryo Okubo

          Issue Links

            Activity

              People

              • Assignee:
                rokubo Ryo Okubo
                Reporter:
                sudheerv Sudheer Vinukonda
              • Votes:
                0 Vote for this issue
                Watchers:
                6 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: