Tests hang #26

Activity

1. stefan-guggisberg commented on Mar 13, 2020

   

   stefan-guggisberg

   on Mar 13, 2020

   ContributorAuthor

   More actions

   Clarification: The process doesn't hang indefinitely. The process exits after exactly 2 minutes.
2. mgabeler-lee-6rs commented on Jun 15, 2020

   

   mgabeler-lee-6rs

   on Jun 15, 2020

   More actions

   I ran into a similar issue that I believe has the same root cause. In my case, speccy (https://github.com/wework/speccy) hangs when it is trying to download external references from servers that support HTTP/2.

   I was able to bisect this to having been introduced in nodejs 12.17.0.

   I ran with lots of node trace/debug stuff enabled, and comparing the succeeding and failing logs, I suspect that this was introduced by nodejs/node#32958, but that's hard for me to verify.

   ---

   Some snippets of debug traces (NODE_OPTIONS=--trace-tls NODE_DEBUG=*) from where they start differing (note: this is a speccy lint run, but the code that's running at this point is from this package). This starts just after the certificate exchange.

   Working with 12.16.3:

   TLS 301274: client onhandshakedone
   TLS 301274: client _finishInit handle? true alpn h2 servername <snip>
   TLS 301274: client emit secureConnect. authorized: true
   HTTP2 301274: Http2Session client: setting up session handle
   HTTP2 301274: Http2Session client: sending settings
   HTTP2 301274: Http2Session client: submitting settings
   HTTP2 301274: Http2Session client: created
   HTTP2 301274: Http2Session client: initiating request
   HTTP2 301274: Http2Session client: connected, initializing request
   STREAM 301274: resume
   (node:301274) Warning: Setting the NODE_DEBUG environment variable to 'http2' can expose sensitive data (such as passwords, tokens and authentication headers) in the resulting log.
   HTTP2 301274: Http2Stream 1 [Http2Session client]: _final shutting down
   STREAM 301274: resume false
   STREAM 301274: read 0
   STREAM 301274: need readable false
   STREAM 301274: length less than watermark true
   STREAM 301274: do read
   STREAM 301274: flow true
   STREAM 301274: read undefined
   STREAM 301274: need readable true
   STREAM 301274: length less than watermark true
   STREAM 301274: reading or ended false
   Sent Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 162
     Inner Content Type = ApplicationData (23)
   Received Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 545
     Inner Content Type = Handshake (22)
       NewSessionTicket, Length=260
           ticket_lifetime_hint=172800
           ticket_age_add=858443592
           ticket_nonce (len=1): 00
           ticket (len=242): <snip>
           extensions, length = 4
             extension_type=UNKNOWN(27242), length=0
   
       NewSessionTicket, Length=260
           ticket_lifetime_hint=172800
           ticket_age_add=2125917300
           ticket_nonce (len=1): 01
           ticket (len=242): <snip>
           extensions, length = 4
             extension_type=UNKNOWN(27242), length=0
   
   Received Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 57
     Inner Content Type = ApplicationData (23)
   Sent Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 26
     Inner Content Type = ApplicationData (23)
   Received Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 26
     Inner Content Type = ApplicationData (23)
   HTTP2 301274: Http2Session client: settings received
   Received Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 172
     Inner Content Type = ApplicationData (23)
   HTTP2 301274: Http2Stream 1 [Http2Session client]: headers received
   HTTP2 301274: Http2Stream 1 [Http2Session client]: emitting stream 'response' event
   

   The response finishes from here.

   Failing with 12.17.0:

   TLS 301302: client onhandshakedone
   TLS 301302: client _finishInit handle? true alpn h2 servername <snip>
   TLS 301302: client emit secureConnect. authorized: true
   HTTP2 301302: Http2Session client: created
   HTTP2 301302: Http2Session client: initiating request
   STREAM 301302: resume
   (node:301302) Warning: Setting the NODE_DEBUG environment variable to 'http2' can expose sensitive data (such as passwords, tokens and authentication headers) in the resulting log.
   STREAM 301302: resume false
   STREAM 301302: read 0
   STREAM 301302: need readable false
   STREAM 301302: length less than watermark true
   STREAM 301302: do read
   STREAM 301302: flow true
   STREAM 301302: read undefined
   STREAM 301302: need readable true
   STREAM 301302: length less than watermark true
   STREAM 301302: reading or ended false
   Received Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 545
     Inner Content Type = Handshake (22)
       NewSessionTicket, Length=260
           ticket_lifetime_hint=172800
           ticket_age_add=169979864
           ticket_nonce (len=1): 00
           ticket (len=242): <snip>
           extensions, length = 4
             extension_type=UNKNOWN(43690), length=0
   
       NewSessionTicket, Length=260
           ticket_lifetime_hint=172800
           ticket_age_add=1669237012
           ticket_nonce (len=1): 01
           ticket (len=242): <snip>
           extensions, length = 4
             extension_type=UNKNOWN(43690), length=0
   
   Received Record
   Header:
     Version = TLS 1.2 (0x303)
     Content Type = ApplicationData (23)
     Length = 57
     Inner Content Type = ApplicationData (23)
   STREAM 301302: readableAddChunk <Buffer <snip>>
   STREAM 301302: emitReadable true false
   STREAM 301302: emitReadable null
   STREAM 301302: emitReadable_ false 40 false
   STREAM 301302: flow null
   STREAM 301302: maybeReadMore read 0
   STREAM 301302: read 0
   STREAM 301302: need readable true
   STREAM 301302: length less than watermark true
   STREAM 301302: do read
   NET 301302: _read
   

   The app hangs from here.
3. mgabeler-lee-6rs commented on Jun 15, 2020

   

   mgabeler-lee-6rs

   on Jun 15, 2020

   More actions

   Possibly also related: grantila/fetch-h2#104
4. hisco

   closed this as completedon Jul 23, 2021