Node: Segmentation fault in http2 module when cancelling download in Chrome
- Version: v9.5.0, v9.6.1, and v10.0.0-pre commit 743f890
- Platform: linux 64-bit (kernel 4.4.0-116-generic from Ubuntu)
- Subsystem: http2
Steps to reproduce:
- Serve a file from Node.js to Chrome using the
http2module - Cancel the download from Chrome
I have not been able to reproduce this problem locally, however.
This was the stacktrace which was generated by node-segfault-handler (Node.js v9.5.0):
PID 1371 received SIGSEGV for address: 0x0
/home/iczero/prj/buildserver/node_modules/segfault-handler/build/Release/segfault-handler.node(+0x1acd)[0x7fccc33beacd]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fccc59a0390]
node(_ZN4node5http212Http2Session22OnStreamAfterWriteImplEPNS_9WriteWrapEiPv+0x55)[0x90f4b5]
node(_ZN4node10StreamBase10AfterWriteEPNS_9WriteWrapEi+0xa0)[0x94c330]
node(_ZN4node7TLSWrap6EncOutEv+0xc5)[0x999075]
node(_ZN4node10StreamBase10AfterWriteEPNS_9WriteWrapEi+0xa0)[0x94c330]
node(_ZN4node15LibuvStreamWrap10AfterWriteEPNS_9WriteWrapEi+0x1b)[0x9502cb]
node(_ZN4node15LibuvStreamWrap12AfterUvWriteEP10uv_write_si+0x54)[0x950f14]
node[0x14240b9]
node[0x1424d74]
node[0x142ac58]
node(uv_run+0x156)[0x1419676]
node(_ZN4node5StartEP9uv_loop_siPKPKciS5_+0x4bd)[0x8d49ed]
node(_ZN4node5StartEiPPc+0x153)[0x8d12d3]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0)[0x7fccc55e5830]
node[0x89d7e1]
Relevant symbols demangled:
node::http2::Http2Session::OnStreamAfterWriteImpl(node::WriteWrap*, int, void*)
node::StreamBase::AfterWrite(node::WriteWrap*, int)
node::TLSWrap::EncOut()
node::StreamBase::AfterWrite(node::WriteWrap*, int)
node::LibuvStreamWrap::AfterWrite(node::WriteWrap*, int)
node::LibuvStreamWrap::AfterUvWrite(uv_write_s*, int)
A small script that causes the segfault:
const http2 = require('http2');
const fs = require('fs');
const FILE = '/usr/bin/node';
// generate a self-signed cert first:
// $ openssl req -newkey rsa:2048 -nodes -keyout key.pem -x509 -days 365 -out cert.pem
let server = http2.createSecureServer({
key: fs.readFileSync('./key.pem'),
cert: fs.readFileSync('./cert.pem')
}, async (request, response) => {
console.log('a request!');
fs.createReadStream(FILE).pipe(response);
});
server.listen(9998);
iczero
All 39 comments
It seems I'm hitting the same issue when trying an HTTP2 push when Chrome already closed the connection. gdb spits out a similar stack trace:
#0 0x0000000000911185 in node::http2::Http2Session::OnStreamAfterWriteImpl(node::WriteWrap*, int, void*) ()
#1 0x000000000094e240 in node::StreamBase::AfterWrite(node::WriteWrap*, int) ()
#2 0x0000000000998cc4 in ?? ()
#3 0x000000000099b1cf in node::TLSWrap::EncOut() ()
#4 0x000000000094e240 in node::StreamBase::AfterWrite(node::WriteWrap*, int) ()
#5 0x0000000000952bc4 in node::LibuvStreamWrap::AfterUvWrite(uv_write_s*, int) ()
#6 0x0000000001427019 in ?? ()
#7 0x0000000001427cd4 in ?? ()
#8 0x000000000141c57b in uv_run ()
#9 0x00000000008d74bd in node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) ()
I managed to reduce the code to following example:
const fs = require("fs");
const http2 = require("http2");
const options = {
key: fs.readFileSync(`${__dirname}/localhost.key`),
cert: fs.readFileSync(`${__dirname}/localhost.crt`)
};
const server = http2.createSecureServer(options, async (req, res) => {
if (req.url !== "/") {
res.writeHead(404);
res.end();
return;
}
// no crash when pushing a single response
push(req, res, "/dummy1");
push(req, res, "/dummy2");
res.writeHead(200);
res.write("test");
res.end();
});
server.listen(8443);
console.log("Listening");
function push(req, res, path) {
res.createPushResponse({":path": path}, (err, pushResponse) => {
if (err)
return console.error({err}, "createPushResponse failed");
pushResponse.stream.on("error", (err) => {
console.warn("Writing push failed", err);
pushResponse.stream.end();
});
// no crash when immediately sending a response and closing the stream
const readStream = fs.createReadStream(__filename);
readStream.on("end", () => pushResponse.stream.end());
pushResponse.writeHead(200, {});
readStream.pipe(pushResponse.stream);
});
}
Steps:
- run
node ./index.js - import a localhost certificate (I'm using a script that generates one with subjectAltName)
- load
https://localhost:8443/(Chrome Linux 64.0.3282.186) - hit refresh
- node v9.6.1 should crashed at this point
michael42
on 25 Feb 2018
I couldnāt reproduce the segfault with either example yet. :/ If it is at all possible, can you try to reproduce this with Node-only code? I.e. a standalone script that crashes and doesnāt require a browser or other external HTTP/2 clients.
It would be appreciated if you could provide a core dump, or try to dig into this with a debugger if you can. Building a debug build of Node takes a bit, but it should be worth it.
If your local reproduction is reliable enough, you could probably also figure out something meaningful by attaching valgrind to the Node process.
What I can tell from the offsets in the stack traces is that most likely one of the stream_ fields of a WriteWrap created for an Http2Stream is invalid, but thatās not really very telling about the cause of the issue.
v10.0.0-pre commit 743f890
@iczero Does that mean that that commit fixes the issue for you, or that you didnāt try anything that includes that patch? It would be weird if that commit fixed things, the original PR that introduce that bug didnāt make it into Node 9.
addaleax
on 25 Feb 2018
@addaleax I meant that the problem still existed with that commit. Sorry for the confusion.
iczero
on 25 Feb 2018
@iczero @michael42 Could you check whether the patch from https://github.com/nodejs/node/pull/18987 fixes this issue for you? That would be a huge help.
addaleax
on 25 Feb 2018
I think I can check it tomorrow. For now, I can't get it reproduced without Chrome, but here's the output from chrome://net-internals:
t= 2 [st= 0] HTTP2_SESSION_SEND_HEADERS
--> exclusive = true
--> fin = true
--> has_priority = true
--> :method: GET
:authority: localhost:8443
:scheme: https
:path: /
cache-control: max-age=0
upgrade-insecure-requests: 1
user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36
accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
dnt: 1
accept-encoding: gzip, deflate, br
accept-language: de,en;q=0.9,en-US;q=0.8
--> parent_stream_id = 0
--> source_dependency = 11872 (HTTP_STREAM_JOB)
--> stream_id = 3
--> weight = 256
t= 5 [st= 3] HTTP2_SESSION_RECV_PUSH_PROMISE
--> :scheme: https
:authority: localhost:8443
:method: GET
:path: /dummy1
--> id = 3
--> promised_stream_id = 6
t= 5 [st= 3] HTTP2_SESSION_SEND_RST_STREAM
--> description = "Duplicate pushed stream with url: https://localhost:8443/dummy1"
--> error_code = "7 (REFUSED_STREAM)"
--> stream_id = 6
t= 5 [st= 3] HTTP2_SESSION_RECV_PUSH_PROMISE
--> :scheme: https
:authority: localhost:8443
:method: GET
:path: /dummy2
--> id = 3
--> promised_stream_id = 8
t= 5 [st= 3] HTTP2_SESSION_SEND_RST_STREAM
--> description = "Duplicate pushed stream with url: https://localhost:8443/dummy2"
--> error_code = "7 (REFUSED_STREAM)"
--> stream_id = 8
t= 5 [st= 3] HTTP2_SESSION_RECV_HEADERS
--> fin = false
--> :status: 200
date: Sun, 25 Feb 2018 21:13:13 GMT
--> stream_id = 3
t= 5 [st= 3] HTTP2_SESSION_RECV_HEADERS
--> fin = false
--> :status: 200
date: Sun, 25 Feb 2018 21:13:13 GMT
--> stream_id = 6
t= 5 [st= 3] HTTP2_SESSION_RECV_HEADERS
--> fin = false
--> :status: 200
date: Sun, 25 Feb 2018 21:13:13 GMT
--> stream_id = 8
t= 5 [st= 3] HTTP2_SESSION_RECV_DATA
--> fin = false
--> size = 4
--> stream_id = 3
t= 5 [st= 3] HTTP2_SESSION_UPDATE_RECV_WINDOW
--> delta = -4
--> window_size = 15726176
t= 5 [st= 3] HTTP2_SESSION_RECV_DATA
--> fin = true
--> size = 0
--> stream_id = 3
t= 6 [st= 4] HTTP2_SESSION_UPDATE_RECV_WINDOW
--> delta = 4
--> window_size = 15726180
t=11 [st= 9] HTTP2_SESSION_RECV_DATA
--> fin = false
--> size = 1230
--> stream_id = 8
t=11 [st= 9] HTTP2_SESSION_UPDATE_RECV_WINDOW
--> delta = -1230
--> window_size = 15724950
t=11 [st= 9] HTTP2_SESSION_UPDATE_RECV_WINDOW
--> delta = 1230
--> window_size = 15726180
t=14 [st=12] HTTP2_SESSION_CLOSE
--> description = "Connection closed"
--> net_error = -100 (ERR_CONNECTION_CLOSED)
t=14 [st=12] HTTP2_STREAM_ERROR
--> description = "Abandoned."
--> net_error = "ERR_CONNECTION_CLOSED"
--> stream_id = 2
t=14 [st=12] HTTP2_SESSION_UPDATE_RECV_WINDOW
--> delta = 1230
--> window_size = 15727410
t=14 [st=12] HTTP2_STREAM_ERROR
--> description = "Abandoned."
--> net_error = "ERR_CONNECTION_CLOSED"
--> stream_id = 4
t=14 [st=12] HTTP2_SESSION_UPDATE_RECV_WINDOW
--> delta = 1230
--> window_size = 15728640
t=14 [st=12] HTTP2_SESSION_POOL_REMOVE_SESSION
t=14 [st=12] -HTTP2_SESSION
I also ran it under valgrind --leak-check=full (is that correct, never used it before?), but it doesn't crash in that case. It does report some possibly lost bytes (3,004 bytes in 15 blocks), though.
michael42
on 25 Feb 2018
@addaleax It doesn't seem to fix the problem. :(
Thread 1 "node" received signal SIGSEGV, Segmentation fault.
0x000000000089ccba in node::http2::Http2Session::ClearOutgoing(int) ()
I'm going to try running node in gdb to see if I can isolate the problem.
iczero
on 25 Feb 2018
@michael42 Thanks for reporting back! Yes, itās expected that there are some lost bytes since Node doesnāt fully clean up before process exit. It would be more interesting to know about any kind of uninitialized data usage.
@iczero Thanks for the info. :/ Do you think you could try a debug build of Node to possibly provide more context?
addaleax
on 25 Feb 2018
A better backtrace provided by the debug version:
#0 0x00000000014a613f in node::StreamResource::EmitAfterWrite (this=0x3e6d450, w=0x3e76040, status=0) at ../src/stream_base-inl.h:121
#1 0x00000000014a61dc in node::StreamBase::AfterWrite(node::WriteWrap*, int)::{lambda()#1}::operator()() const (__closure=0x7fffffff9b20) at ../src/stream_base-inl.h:138
#2 0x00000000014a6f0c in node::StreamBase::AfterRequest<node::WriteWrap, node::StreamBase::AfterWrite(node::WriteWrap*, int)::{lambda()#1}>(node::WriteWrap*, node::StreamBase::AfterWrite(node::WriteWrap*, int)::{lambda()#1}) (this=0x3e6d450, req_wrap=0x3e76040, emit=...) at ../src/stream_base-inl.h:155
#3 0x00000000014a622b in node::StreamBase::AfterWrite (this=0x3e6d450, req_wrap=0x3e76040, status=0) at ../src/stream_base-inl.h:137
#4 0x00000000014a6322 in node::WriteWrap::OnDone (this=0x3e76040, status=0) at ../src/stream_base-inl.h:413
#5 0x00000000014b43e4 in node::StreamReq::Done (this=0x3e76040, status=0, error_str=0x0) at ../src/stream_base-inl.h:424
#6 0x0000000001523680 in node::http2::Http2Session::ClearOutgoing (this=0x3e6cfb0, status=0) at ../src/node_http2.cc:1454
#0 0x00000000014a613f in node::StreamResource::EmitAfterWrite (this=0x3e6d450, w=0x3e76040, status=0) at ../src/stream_base-inl.h:121
121 listener_->OnStreamAfterWrite(w, status);
#1 0x00000000014a61dc in node::StreamBase::AfterWrite(node::WriteWrap*, int)::{lambda()#1}::operator()() const (__closure=0x7fffffff9b20) at ../src/stream_base-inl.h:138
138 EmitAfterWrite(req_wrap, status);
#2 0x00000000014a6f0c in node::StreamBase::AfterRequest<node::WriteWrap, node::StreamBase::AfterWrite(node::WriteWrap*, int)::{lambda()#1}>(node::WriteWrap*, node::StreamBase::AfterWrite(node::WriteWrap*, int)::{lambda()#1}) (this=0x3e6d450, req_wrap=0x3e76040, emit=...) at ../src/stream_base-inl.h:155
155 emit();
#3 0x00000000014a622b in node::StreamBase::AfterWrite (this=0x3e6d450, req_wrap=0x3e76040, status=0) at ../src/stream_base-inl.h:137
137 AfterRequest(req_wrap, [&]() {
#4 0x00000000014a6322 in node::WriteWrap::OnDone (this=0x3e76040, status=0) at ../src/stream_base-inl.h:413
413 stream()->AfterWrite(this, status);
#5 0x00000000014b43e4 in node::StreamReq::Done (this=0x3e76040, status=0, error_str=0x0) at ../src/stream_base-inl.h:424
424 OnDone(status);
#6 0x0000000001523680 in node::http2::Http2Session::ClearOutgoing (this=0x3e6cfb0, status=0) at ../src/node_http2.cc:1454
1454 wrap->Done(status);
#7 0x0000000001523389 in node::http2::Http2Session::OnStreamAfterWrite (this=0x3e6cfb0, w=0x3e77810, status=0) at ../src/node_http2.cc:1410
1410 ClearOutgoing(status);
@iczero Can you figure out why that is crashing? Is listener_ null?
addaleax
on 25 Feb 2018
Seems like it:
(gdb) p listener_
$1 = (node::StreamListener *) 0x0
@iczero Can you build with ./configure --debug-http2 and share the output for a crashing run, and ideally add logging like this:
--- a/src/node_http2.cc
+++ b/src/node_http2.cc
@@ -1755,2 +1755,3 @@ Http2Stream::Http2Stream(
Http2Stream::~Http2Stream() {
+ DEBUG_HTTP2STREAM2(this, "tearing down stream");
if (session_ != nullptr) {
listener_ == nullptr should basically never happen at that point, it means that all listeners have been removed, which means that the stream destructor has been called. So, it might be nice to figure out how that can happenā¦
addaleax
on 25 Feb 2018
The compile errored with that patch:
In file included from ../src/node_http2.cc:4:0:
../src/node_http2.cc: In destructor āvirtual node::http2::Http2Stream::~Http2Stream()ā:
../src/node_http2.h:39:52: error: expected primary-expression before ā)ā token
#define DEBUG_HTTP2(...) debug_vfprintf(__VA_ARGS__);
^
../src/node_http2.h:66:5: note: in expansion of macro āDEBUG_HTTP2ā
DEBUG_HTTP2("Http2Stream %d (%.0lf) [Http2Session %s (%.0lf)] " message \
^~~~~~~~~~~
../src/node_http2.cc:1756:3: note: in expansion of macro āDEBUG_HTTP2STREAM2ā
DEBUG_HTTP2STREAM2(this, "tearing down stream");
^~~~~~~~~~~~~~~~~~
In file included from ../src/node_http2.cc:4:0:
../src/node_http2.cc: In destructor āvirtual node::http2::Http2Stream::~Http2Stream()ā:
../src/node_http2.h:39:52: error: expected primary-expression before ā)ā token
#define DEBUG_HTTP2(...) debug_vfprintf(__VA_ARGS__);
^
../src/node_http2.h:66:5: note: in expansion of macro āDEBUG_HTTP2ā
DEBUG_HTTP2("Http2Stream %d (%.0lf) [Http2Session %s (%.0lf)] " message \
^~~~~~~~~~~
../src/node_http2.cc:1756:3: note: in expansion of macro āDEBUG_HTTP2STREAM2ā
DEBUG_HTTP2STREAM2(this, "tearing down stream");
Weird, my compiler didnāt complain. :o
Anyway, using DEBUG_HTTP2STREAM instead of DEBUG_HTTP2STREAM2 should fix that (my bad).
addaleax
on 25 Feb 2018
The output now:
Http2Session server (28) reading outbound data for stream 1
Http2Session server (28) stream 1 has pending outbound data
Http2Session server (28) sending 16384 bytes for data frame on stream 1
Http2Session server (28) nghttp2 has 16384 bytes to send directly
Http2Session server (28) reading outbound data for stream 1
Http2Session server (28) deferring stream 1
Http2Session server (28) wants data in return? 1
Http2Session server (28) receiving 13 bytes
Http2Session server (28) receiving 13 bytes [wants data? 1]
Http2Session server (28) complete frame received: type: 3
Http2Session server (28) stream 1 closed with code: 8
Http2Stream 1 (34) [Http2Session server (28)] closed with code 8
Http2Stream 1 (34) [Http2Session server (28)] destroying stream
Http2Stream 1 (34) [Http2Session server (28)] destroying stream
Http2Session server (28) sending pending data
Http2Session server (28) processed 13 bytes. wants more? 1
Http2Stream 1 (34) [Http2Session server (28)] tearing down stream
Http2Session server (28) write finished with status 0
Thread 1 "node_g" received signal SIGSEGV, Segmentation fault.
0x00000000014a613f in node::StreamResource::EmitAfterWrite (this=0x3e6c2c0, w=0x3e6d650, status=0) at ../src/stream_base-inl.h:121
121 listener_->OnStreamAfterWrite(w, status);
Also, I am on gcc 7.2.0-1ubuntu1~16.04.
iczero
on 25 Feb 2018
Thanks, that seems helpful.
One thing that sticks out as weird is the fact that Nvm, they are from different call sites.destroying stream pops up twice in the output, because there is an explicit check that should prevent that.
The hypothesis Iād get from the above is that the delete stream; line in Http2Stream::Destroy is run before the write (that was already posted to the socket) finishes its callback, so accessing the stream object fails at that point.
Can you provide a backtrace for the tearing down stream line? Just to make sure that thatās whatās happeningā¦
You could also try removing the delete stream; line altogether for now. Itās not a good fix, but it should work and not create a memory leak, itās just there to avoid having to wait for garbage collection. (If that doesnāt work Iām probably wrong anyway.)
Iām going to sleep now, but thanks a lot for sticking with me in debugging this. :blue_heart: If somebody else wants to think about the ideal patch here, theyāre welcome to do that, because itās not quite obvious to me at this point what the best approach would be.
addaleax
on 26 Feb 2018
Thanks for your time. Good night!
iczero
on 26 Feb 2018
Backtrace to Http2Stream destructor:
#0 node::http2::Http2Stream::~Http2Stream (this=0x3e6c720, __in_chrg=<optimized out>) at ../src/node_http2.cc:1756
1756 DEBUG_HTTP2STREAM(this, "tearing down stream");
#1 0x0000000001524178 in node::http2::Http2Stream::~Http2Stream (this=0x3e6c720, __in_chrg=<optimized out>) at ../src/node_http2.cc:1764
1764 }
#2 0x000000000153f278 in node::http2::Http2Stream::Destroy()::{lambda(node::Environment*, void*)#1}::operator()(node::Environment*, void*) const (__closure=0x0, env=0x7fffffffd520, data=0x3e6c720)
at ../src/node_http2.cc:1849
1849 delete stream;
#3 0x000000000153f2a0 in node::http2::Http2Stream::Destroy()::{lambda(node::Environment*, void*)#1}::_FUN(node::Environment*, void*) () at ../src/node_http2.cc:1850
1850 }, this, this->object());
#4 0x00000000014abf68 in node::Environment::<lambda()>::operator()(void) const (__closure=0x7fffffffd310) at ../src/env.cc:316
316 it->cb_(this, it->data_);
Okay, I think hereās a real fix: https://github.com/nodejs/node/pull/19002
It would be great if you could check whether that works, possibly combined with #18987.
addaleax
on 26 Feb 2018
Yep it works. Thanks!
iczero
on 26 Feb 2018
Letās keep this open until the PR gets merged.
TimothyGu
on 26 Feb 2018
Oh, sorry about that.
iczero
on 26 Feb 2018
Did a CVE get issued for this? @jasnell @mhdawson
sam-github
on 2 Nov 2018
@sam-github Not according to our CVE management repository. This was also during the time when HTTP/2 support was classified as experimental, I donāt know if we assign CVEs for those cases?
addaleax
on 2 Nov 2018
I don't know either! :-)
On the one hand... "experimental" - use at your own risk, if it breaks, you get to keep the parts.
On the other hand, we shipped it, people are using it, and their servers can be crashed, maybe still can be crashed if https://github.com/nodejs/node/issues/24037 is accurate. A hard crash might deserve a CVE.
@nodejs/security @nodejs/security-wg Anyone have some thoughts on what our policy should be here? Should TSC decide that experimental features accept bug reports, but not vulnerability reports? Or decide that if people are using it they deserve to know about sec problems?
sam-github
on 3 Nov 2018
I think that experimental feature are āuse at your own riskā.
mcollina
on 3 Nov 2018
I agree, this _should_ not need to be fixed in 8.12. We explicitly invoke node with --expose-http2.
Unfortunately, there seems to be a problem with Node 10, https.createServer, our hardware client-devices and OpenSSL/TLS, so we can not update. From our debugging-client, we see
Error: 140736036709248:error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number:../deps/openssl/openssl/ssl/s3_pkt.c:365:
when connecting (from a NodeJS 8.12 (websocket) client) to the updated Node 10 (websocket) server. The server is created using https.createServer({ secureProtocol: "TLSv1_2_method" }), about which I can find no changelog/breaking changes except that Node 10 now supports OpenSSL 1.1.0. The error about SSL3 is weird, considering we supply secureProtocol. Might that be ignored, and thus a bug in Node 10?
hermanbanken
on 5 Nov 2018
/cc @nodejs/crypto for the comment above?
addaleax
on 5 Nov 2018
If you provide standalone scripts that demo this 8.x to 10.x interop problem I will try to debug it.
sam-github
on 5 Nov 2018
@sam-github, I've created a minimal sample repo (docker-compose up) https://gist.github.com/hermanbanken/c1059caabff0d2dac90a773a903fbc07, which produces on the Node 8.12 client:
Error: 140242062162824:error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number:../deps/openssl/openssl/ssl/s3_pkt.c:365
Try running the latest commit (Node8<->Node10) and the pre-latest one (Node8<->Node8).
hermanbanken
on 5 Nov 2018
hermanbanken
on 5 Nov 2018
I think our definitions of standalone differ! I'll be wanting to wireshark the communication, and I don't want to play with docker. I'll see if I can run the client.js/server.js from the gist directly on my Linux laptop.
sam-github
on 6 Nov 2018
Got it. This was a āsimpleā way for me to not have dependencies on which OpenSSL is installed and recreate our exact case (our node server runs in Docker too).
Hopefully the scripts inside produce the same result with your system.
hermanbanken
on 6 Nov 2018
I can reproduce it locally using this wireshark filter tcp.dstport == 44330 or tcp.srcport == 44330 with this bash:
sh make-certs.sh
(nvm use 10.13 && PORT=44330 node server.js) &
(nvm use 8.12 && PORT=44330 node client.js)
I have no experience with Wireshark, but I definitely see something different going on in the Server Hello message. The Node 8 server sends a Server Hello of 83 bytes, while the Node 10 server sends one of 61 bytes. The difference is the next_protocol_negotiation (len=18) field, which is only present with Node 8 and contains 'next protocol http/1.1, next protocol http/1.0'.
After that Hello, the Node 8 and Node 10 servers seem to proceed similarly for a few packets, except that the Node 10 terminates early. With my limited wireshark knowledge I don't know if the following is interesting: in the Node 10 capture Wireshark detects a HTTP switching protocols to Websockets, while in Node 8 Wireshark just marks it as "Application Data".
hermanbanken
on 6 Nov 2018
What's happening is uws, for node 10, is dumping the ws/HTTP "switching protocols" message directly onto the TCP connection, unencrypted! The TLS client then attempts to decode it as a TLS application data record, but since its just unencypted HTTP, it fails to decode, and the client errors out.
Now, why does uws do the wrong thing here, I'm not sure. That will take more digging. I'll take a bit more time to look at this to see if I can tell why its doing that, it could be something changed in node that should not have.
Since uws is dead upstream, doesn't support node 11, and has been spectacularly abandoned by its maintainer, I'm not sure how much time I'll spend on this.
sam-github
on 6 Nov 2018
Sorry, no clue. This disappears into uws' cpp internals, I'm not honestly sure why it ever works with TLS, uws seems to replace all the node TLS code with its own. Its possible it just doesn't support openssl 1.1.0 (8.x used 1.0.2). Btw, this doesn't depend on the client node version, its just the server.
Also, I don't think this issue has anything to do with the one whose thread we are using, I think we hijacked it.
sam-github
on 7 Nov 2018
True, this has nothing to do with this issue.
For your interest: I found that UWS relies on net.Socket._handle.ssl._external. This seems to be gone from Node 10. I'm still looking for if that _external property is somehow exposed elsewhere (if you know how: please tell!). UWS has an internal HTTP & SSL implementation, which really speeds-up our server.
hermanbanken
on 7 Nov 2018
@hermanbanken Fyi, thereās some context in https://github.com/nodejs/node/pull/21711. Itās temporarily added back, but please take this up with the maintainers of UWS, because this is not a permanent solution (if it is unmaintained, you might have to look into finding new people to maintain it :/).
addaleax
on 7 Nov 2018
Eureka, I also just found https://github.com/nodejs/node/pull/21711.
We're aware of the - unfortunate - unmaintainment. We do not have a good replacement ATM. Looking into the @discord/uws fork, and also hoping for a patch in Node 8 HTTP2 (unrelated bug) so we do not need to upgrade ATM.
hermanbanken
on 7 Nov 2018
Related issues
seishun
Ā·
3Comments
loretoparisi
Ā·
3Comments
danialkhansari
Ā·
3Comments
stevenvachon
Ā·
3Comments
addaleax
Ā·
3Comments