node-spdy incompatible with node >= v15

[therealgilles]

I've been using spdy 4.0.2 for some time without a hitch and am suddenly getting http2 protocol errors with 'Server reset stream'. http/1.1 works.

This is what I see in the browser:
Failed to load resource: net::ERR_HTTP2_PROTOCOL_ERROR

Wondering why that could and how I can debug the issue. Any advice would be appreciated.

[therealgilles]

Here is a log extract showing the abort and the RST_STREAM:

  spdy:framer id=1 type=HEADERS +41ms
  spdy:scheduler queue sync [
  <Buffer 00 04 14 01 04 00 00 00 01>,
  <Buffer 3f e1 1f 88 40 90 21 ea 49 6a 4a c8 29 2d b0 c9 f4 b5 67 a0 c4 f5 ff c6 03 90 b2 8e da 12 b2 2c 22 9f e9 05 a2 5f f4 a4 e9 4d 68 b8 c3 1f 2b cc 73 cd ... 994 more bytes>
] +41ms
  spdy:scheduler tick sync pending=2 [
  <Buffer 00 04 14 01 04 00 00 00 01>,
  <Buffer 3f e1 1f 88 40 90 21 ea 49 6a 4a c8 29 2d b0 c9 f4 b5 67 a0 c4 f5 ff c6 03 90 b2 8e da 12 b2 2c 22 9f e9 05 a2 5f f4 a4 e9 4d 68 b8 c3 1f 2b cc 73 cd ... 994 more bytes>
] +0ms
  spdy:scheduler after tick sync pending=0 +0ms
  spdy:stream:server id=1 presend=10 +31ms
  spdy:window:server id=1 side=send update by=-10 [6291446/6291456] +41ms
  spdy:stream:server id=1 send=10 +0ms
  spdy:framer id=1 type=DATA +3ms
  spdy:window:server id=0 side=send update by=-10 [15728630/65535] +0ms
  spdy:scheduler queue async priority=1 stream=1 [
  <Buffer 00 00 0a 00 00 00 00 00 01>,
  <Buffer 1f 8b 08 00 00 00 00 00 00 13>
] +3ms
  spdy:scheduler tick async index=0 start=1 +0ms
  spdy:scheduler tick async pending=2 [
  <Buffer 00 00 0a 00 00 00 00 00 01>,
  <Buffer 1f 8b 08 00 00 00 00 00 00 13>
] +0ms
  spdy:scheduler after tick pending=0 +0ms
  spdy:stream:server id=1 postsend=10 +1ms
  spdy:stream:server id=1 abort +1ms
  spdy:framer id=1 type=RST_STREAM +2ms
  spdy:scheduler queue sync [ <Buffer 00 00 04 03 00 00 00 00 01>, <Buffer 00 00 00 08> ] +2ms
  spdy:scheduler tick sync pending=2 [ <Buffer 00 00 04 03 00 00 00 00 01>, <Buffer 00 00 00 08> ] +0ms
  spdy:scheduler after tick sync pending=0 +0ms
::1 - - [08/Feb/2021:07:37:21 +0000] "GET / HTTP/1.1" 200 - 17.877 ms
  spdy:connection:server id=0 remove stream=1 +34ms

[therealgilles]

Turns out it works with node v14.15.1 and breaks with node v15.4.0. Something must have changed in node v15 that broke http/2.

[anikolov]

I experience the same problem - it is not working with node v15.8.0 and express-session, but it works just fine if you don't set a cookie. I confirm that it works with node v14.15.5 and express-session.

[therealgilles]

Thanks for the report @anikolov.

[multicron]

I also have this happening, with Node 15.8.0 but not with 14.15.4. express 4.17.1, spdy 4.0.2.

[crystalfp]

With node 16.0.0 gives a deprecation warning:
(node:34788) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.
At least the trace obtained with --trace-deprecation starts at spdy/handle.js loading.

[Upd4ting]

Any progress with that?

[lamweili]

With node 16.0.0 gives a deprecation warning:
(node:34788) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.
At least the trace obtained with --trace-deprecation starts at spdy/handle.js loading.

I doubt this is the root cause, as DEP0111 is documented-only deprecation for now.
Ref: https://nodejs.org/api/deprecations.html#DEP0111

Nevertheless, I have submitted a pull request to patch the upcoming deprecation.
Ref: spdy-http2/http-deceiver#7

[lamweili]

I did some testing and here are my findings to assist in finding the root cause of the incompatibility.

nodejs	express	spdy	http1.1	http2
17.3.1	4.17.1	4.0.2	✔️	❌
17.0.0	4.17.1	4.0.2	✔️	❌
16.13.1	4.17.1	4.0.2	✔️	❌
16.0.0	4.17.1	4.0.2	✔️	❌
15.14.0	4.17.1	4.0.2	✔️	❌
15.0.0	4.17.1	4.0.2	✔️	❌
14.18.2	4.17.1	4.0.2	✔️	✔️
14.0.0	4.17.1	4.0.2	✔️	✔️

Even after manually applying both pull requests that resolves DEP0066 and DEP0111, I have the same results.

DEP0066 PR - #367
DEP0111 PR - spdy-http2/http-deceiver#7

The compatibility issue started from NodeJS 15.0.0.