zlib assertion error

[lpinca]

• Version: 6.10.2
• Platform: Linux
• Subsystem: zlib

Node.js crashes while running the Autobahn Testsuite against ws.

/home/luigi/.nvm/versions/node/v6.10.2/bin/node[12612]: ../src/node_zlib.cc:86:void node::ZCtx::Close(): Assertion `init_done_ && "close before init"' failed.
 1: node::Abort() [node]
 2: node::Assert(char const* const (*) [4]) [node]
 3: node::ZCtx::Close(v8::FunctionCallbackInfo<v8::Value> const&) [node]
 4: v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [node]
 5: 0x9ec20e [node]
 6: 0x9ecaae [node]
 7: 0xba4e8092a7
Aborted (core dumped)

The issue is not reproducible with Node.js 6.10.1 (zlib 1.2.8). In Node.js 6.10.2, zlib has been upgraded to version 1.2.11.

Here is a back trace:

(lldb) v8 bt
 * thread #1: tid = 12612, 0x00007f625684191f libc.so.6`__GI_raise + 159, name = 'node', stop reason = signal SIGABRT
  * frame #0: 0x00007f625684191f libc.so.6`__GI_raise + 159
    frame #1: 0x00007f625684351a libc.so.6`__GI_abort + 362
    frame #2: 0x000000000109b771 node`node::Abort() + 33
    frame #3: 0x000000000109b8a3 node`node::Assert(char const* const (*) [4]) + 211
    frame #4: 0x00000000010d448a node`node::ZCtx::Close(v8::FunctionCallbackInfo<v8::Value> const&) + 298
    frame #5: 0x000000000098d212 node`v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) + 290
    frame #6: 0x00000000009ec20e node`v8::internal::(anonymous namespace)::HandleApiCallHelper(v8::internal::Isolate*, v8::internal::(anonymous namespace)::BuiltinArguments<(v8::internal::BuiltinExtraArguments)3>) + 574
    frame #7: 0x00000000009ecaae node`v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) + 398
    frame #8: 0x000000ba4e8092a7 <exit>
    frame #9: 0x000000ba4e9d7953 _close(this=0x000023d5b6a04381:<undefined>, 0x0000024ce82c2c79:<Object: DeflateRaw>, 0x000023d5b6a04381:<undefined>) at zlib.js:473:16 fn=0x0000024ce8251951
    frame #10: 0x000000ba4e809895 <adaptor>
    frame #11: 0x000000ba4e9dd580 Zlib._handle.onerror(this=0x0000024ce82c48c1:<Object: Zlib>, 0x0000024ce82c4c11:<String: "Init error">, <Smi: -2>) at zlib.js:364:34 fn=0x00000884a5a28e61
    frame #12: 0x000000ba4e83b7a3 <internal>
    frame #13: 0x000000ba4e82508f <entry>
    frame #14: 0x0000000000c53b54 node`v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) + 196
    frame #15: 0x0000000000974d59 node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 313
    frame #16: 0x0000000000982ee1 node`v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 65
    frame #17: 0x000000000108b479 node`node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) + 329
    frame #18: 0x00000000010d6202 node`node::ZCtx::Init(v8::FunctionCallbackInfo<v8::Value> const&) + 1122
    frame #19: 0x000000000098d212 node`v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) + 290
    frame #20: 0x00000000009ec20e node`v8::internal::(anonymous namespace)::HandleApiCallHelper(v8::internal::Isolate*, v8::internal::(anonymous namespace)::BuiltinArguments<(v8::internal::BuiltinExtraArguments)3>) + 574
    frame #21: 0x00000000009ecaae node`v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) + 398
    frame #22: 0x000000ba4e8092a7 <exit>
    frame #23: 0x000000ba4e9d046b Zlib(this=0x0000024ce82c2c79:<Object: DeflateRaw>, 0x0000024ce82c2c39:<Object: Object>, <Smi: 5>) at zlib.js:299:14 fn=0x0000024ce8239391
    frame #24: 0x000000ba4e9db606 DeflateRaw(this=0x0000024ce82c2c79:<Object: DeflateRaw>, 0x0000024ce82c2c39:<Object: Object>) at zlib.js:268:20 fn=0x0000024ce82394f9
    frame #25: 0x000000ba4e83445b <constructor>
    frame #26: 0x000000ba4e9db265 exports.createDeflateRaw(this=0x0000024ce8251819:<Object: Object>, 0x0000024ce82c2c39:<Object: Object>) at zlib.js:83:36 fn=0x000021655bb90cf1
    frame #27: 0x000000ba4e9dacd4 compress(this=0x0000024ce82b49e1:<Object: PerMessageDeflate>, 0x0000024ce82c24d1:<ArrayBufferView 0x00000000034f7250+6816:16>, 0x000023d5b6a043c1:<true>, 0x0000024ce82c2871:<function: perMessageDeflate.compress at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/Sender.js:334:51>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/PerMessageDeflate.js:329:12 fn=0x0000024ce8252b61
    frame #28: 0x000000ba4e9da760 dispatch(this=0x0000024ce82baad9:<Object: Sender>, 0x0000024ce82c24d1:<ArrayBufferView 0x00000000034f7250+6816:16>, 0x000023d5b6a043c1:<true>, 0x0000024ce82c2789:<Object: Object>, 0x000023d5b6a04381:<undefined>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/Sender.js:325:12 fn=0x0000024ce8253399
    frame #29: 0x000000ba4e9d9d92 send(this=0x0000024ce82baad9:<Object: Sender>, 0x0000024ce82c24d1:<ArrayBufferView 0x00000000034f7250+6816:16>, 0x0000024ce82c2331:<Object: Object>, 0x000023d5b6a04381:<undefined>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/Sender.js:255:8 fn=0x0000024ce8253351
    frame #30: 0x000000ba4e9d935b send(this=0x0000024ce82b8769:<Object: EventEmitter>, 0x0000024ce82c2101:<String: "{
   "AutobahnPy">, 0x000023d5b6a04381:<undefined>, 0x000023d5b6a04381:<undefined>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/WebSocket.js:350:8 fn=0x0000024ce8204e69
    frame #31: 0x000000ba4e809895 <adaptor>
    frame #32: 0x000000ba4e9d8d16 ws.on(this=0x0000024ce82b8769:<Object: EventEmitter>, 0x0000024ce82c2101:<String: "{
   "AutobahnPy">) at /home/luigi/Desktop/autobahn/server/index.js:12:20 fn=0x0000024ce82bbd71
    frame #33: 0x000000ba4e9adf50 emitOne(this=0x000023d5b6a04381:<undefined>, 0x0000024ce82bbd71:<function: ws.on at /home/luigi/Desktop/autobahn/server/index.js:12:20>, 0x000023d5b6a043c1:<true>, 0x0000024ce82b8769:<Object: EventEmitter>, 0x0000024ce82c2101:<String: "{
   "AutobahnPy">) at events.js:94:17 fn=0x000021655bb464b1
    frame #34: 0x000000ba4e921780 emit(this=0x0000024ce82b8769:<Object: EventEmitter>, 0x000023d5b6a8be39:<String: "message">) at events.js:136:44 fn=0x000023d5b6ae8571
    frame #35: 0x000000ba4e809895 <adaptor>
    frame #36: 0x000000ba4e9d8c02 _receiver.onmessage(this=0x0000024ce82b9a19:<Object: Receiver>, 0x0000024ce82c2101:<String: "{
   "AutobahnPy">) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/WebSocket.js:146:32 fn=0x00000884a5a1b1f9
    frame #37: 0x000000ba4e9d87a3 dataMessage(this=0x0000024ce82b9a19:<Object: Receiver>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/Receiver.js:359:15 fn=0x0000024ce8252ff1
    frame #38: 0x000000ba4e9d7e8f perMessageDeflate.decompress(this=0x000023d5b6a04381:<undefined>, 0x000023d5b6a04201:<null>, 0x0000024ce82c1f49:<ArrayBufferView 0x00000000034f7250+6800:16>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/Receiver.js:343:51 fn=0x0000024ce82bce49
    frame #39: 0x000000ba4e9d70d7 _inflate.flush(this=0x000023d5b6a04381:<undefined>) at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/PerMessageDeflate.js:314:25 fn=0x0000024ce82c0521
    frame #40: 0x000000ba4e9a8f83 afterWrite(this=0x000023d5b6a04381:<undefined>, 0x0000024ce82bd059:<Object: InflateRaw>, 0x0000024ce82bdbe9:<Object: WritableState>, 0x000023d5b6a04271:<false>, 0x0000024ce82c0521:<function: _inflate.flush at /home/luigi/Desktop/autobahn/server/node_modules/ws/lib/PerMessageDeflate.js:314:25>) at _stream_writable.js:384:20 fn=0x000021655bb4af19
    frame #41: 0x000000ba4e9a88e0 onwrite(this=0x000023d5b6a04381:<undefined>, 0x0000024ce82bd059:<Object: InflateRaw>, 0x000023d5b6a04381:<undefined>) at _stream_writable.js:356:17 fn=0x000021655bb4aed1
    frame #42: 0x000000ba4e9a855f WritableState.onwrite(this=0x000023d5b6a04381:<undefined>, 0x000023d5b6a04381:<undefined>) at _stream_writable.js:89:26 fn=0x00000884a5a20f39
    frame #43: 0x000000ba4e9d5fc9 afterTransform(this=0x000023d5b6a04381:<undefined>, 0x0000024ce82bd059:<Object: InflateRaw>, 0x000023d5b6a04381:<undefined>, 0x000023d5b6a04381:<undefined>) at _stream_transform.js:64:24 fn=0x000021655bb4b3a1
    frame #44: 0x000000ba4e9d5c9f TransformState.afterTransform(this=0x000023d5b6a04381:<undefined>, 0x000023d5b6a04381:<undefined>, 0x000023d5b6a04381:<undefined>) at _stream_transform.js:53:33 fn=0x00000884a5a21481
    frame #45: 0x000000ba4e809895 <adaptor>
    frame #46: 0x000000ba4e9d5638 callback(this=0x0000024ce82bf139:<Object: Zlib>, <Smi: 0>, <Smi: 16368>) at zlib.js:576:20 fn=0x0000024ce82c1af1
    frame #47: 0x000000ba4e83b7a3 <internal>
    frame #48: 0x000000ba4e82508f <entry>
    frame #49: 0x0000000000c53b54 node`v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) + 196
    frame #50: 0x0000000000974d59 node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 313
    frame #51: 0x0000000000982ee1 node`v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 65
    frame #52: 0x000000000108b479 node`node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) + 329
    frame #53: 0x00000000010d827b node`node::ZCtx::After(uv_work_s*, int) + 635
    frame #54: 0x000000000131a825 node`uv__work_done(handle=0x0000000001e1dfb0) + 165 at threadpool.c:236
    frame #55: 0x000000000131c83b node`uv__async_event(loop=0x0000000001e1df00, w=<unavailable>, nevents=<unavailable>) + 171 at async.c:98
    frame #56: 0x000000000131c913 node`uv__async_io(loop=0x0000000001e1df00, w=0x0000000001e1e0c8, events=<unavailable>) + 163 at async.c:138
    frame #57: 0x000000000132cee0 node`uv__io_poll(loop=0x0000000001e1df00, timeout=119985) + 928 at linux-core.c:380
    frame #58: 0x000000000131d3f6 node`uv_run(loop=0x0000000001e1df00, mode=UV_RUN_ONCE) + 342 at core.c:354
    frame #59: 0x00000000010a60b0 node`node::Start(int, char**) + 1360
    frame #60: 0x00007f625682c401 libc.so.6`__libc_start_main + 241
    frame #61: 0x00000000007b8a0d node`_start + 41
    frame #62: 0x00007f6257ccaf80 ld-linux-x86-64.so.2`_rtld_local + 3968
    frame #63: 0x00007f6257ccaf80 ld-linux-x86-64.so.2`_rtld_local + 3968

The test that makes the process crash has the following description:

Send 1000 compressed messages each of payload size 16, auto-fragment to 0 octets. Use permessage-deflate client offers (requestNoContextTakeover, requestMaxWindowBits): [(False, 8)]

[lpinca]

Reduced test case:

$ cat test-case.js 
const zlib = require('zlib');

const deflate = zlib.createDeflateRaw({
  memLevel: 8,
  windowBits: 8
});
$ node test-case.js 
/home/luigi/.nvm/versions/node/v6.10.2/bin/node[87754]: ../src/node_zlib.cc:86:void node::ZCtx::Close(): Assertion `init_done_ && "close before init"' failed.
 1: node::Abort() [node]
 2: node::Assert(char const* const (*) [4]) [node]
 3: node::ZCtx::Close(v8::FunctionCallbackInfo<v8::Value> const&) [node]
 4: v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [node]
 5: 0x9ec20e [node]
 6: 0x9ecaae [node]
 7: 0x2cb23b0092a7
Aborted (core dumped)

[sam-github]

I can reproduce with above. :-(

[cjihrig]

Simple fix is to add ctx->init_done_ = true; before this line. I don't think it's a good fix though because an unhelpful Init error error is emitted before an error handler can be added.

[XadillaX]

Finally I found this in src/node_zlib.cc

switch (ctx->mode_) {
  case DEFLATE:
  case GZIP:
  case DEFLATERAW:
    ctx->err_ = deflateInit2(&ctx->strm_,
                             ctx->level_,
                             Z_DEFLATED,
                             ctx->windowBits_,
                             ctx->memLevel_,
                             ctx->strategy_);
    ctx->env()->isolate()
        ->AdjustAmountOfExternalAllocatedMemory(kDeflateContextSize);
    break;
  case INFLATE:
  case GUNZIP:
  case INFLATERAW:
  case UNZIP:
    ctx->err_ = inflateInit2(&ctx->strm_, ctx->windowBits_);
    ctx->env()->isolate()
        ->AdjustAmountOfExternalAllocatedMemory(kInflateContextSize);
    break;
  default:
    CHECK(0 && "wtf?");
}

if (ctx->err_ != Z_OK) {
  ZCtx::Error(ctx, "Init error");
}

This bug is because deflateInit2 returned -2 (Z_STREAM_ERROR).

[aqrln]

@XadillaX I believe I just did it :)
#13098

[lpinca]

@XadillaX yes, see frame 11 above:

frame #11: 0x000000ba4e9dd580 Zlib._handle.onerror(this=0x0000024ce82c48c1:<Object: Zlib>, 0x0000024ce82c4c11:<String: "Init error">, <Smi: -2>) at zlib.js:364:34 fn=0x00000884a5a28e61