Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

https/http2: random crashes on macOS with simple server #34854

Closed
silverwind opened this issue Aug 20, 2020 · 18 comments
Closed

https/http2: random crashes on macOS with simple server #34854

silverwind opened this issue Aug 20, 2020 · 18 comments
Labels
http2 Issues or PRs related to the http2 subsystem. https Issues or PRs related to the https subsystem. macos Issues and PRs related to the macOS platform / OSX.

Comments

@silverwind
Copy link
Contributor

silverwind commented Aug 20, 2020

  • Version: v14.8.0
  • Platform: macOS 10.15.6
  • Subsystem: http2, https

What steps will reproduce the bug?

const cert = `-----BEGIN CERTIFICATE-----
MIIBtTCCAVugAwIBAgIUH0XFx/3Z45cPbceJL2ROh32MaeIwCgYIKoZIzj0EAwIw
DTELMAkGA1UEAwwCc3MwIBcNMjAwODIwMTI1MDAyWhgPMjEyMDA3MjcxMjUwMDJa
MA0xCzAJBgNVBAMMAnNzMFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEhWfkYTyp
AysamlBfzKnSEiudcl/c702qC55wJH/4MgFHvYBW95v8KZpVfpCBp/R+liELOZhD
UWVSsMaDjCf5NKOBljCBkzAdBgNVHQ4EFgQUm9b/hx605s6u9ndSGURgSXUKWygw
HwYDVR0jBBgwFoAUm9b/hx605s6u9ndSGURgSXUKWygwDwYDVR0TAQH/BAUwAwEB
/zANBgNVHREEBjAEggJzczAxBgNVHSUEKjAoBggrBgEFBQcDAQYIKwYBBQUHAwIG
CCsGAQUFBwMDBggrBgEFBQcDCDAKBggqhkjOPQQDAgNIADBFAiBfedlcz/vPsug6
zjsXuqldmcBLlcXJJDo/uZJaIhsuxQIhAJbNenmFGPK9yEs84QPmVQmwUQs6RSWh
nEaZwr7pmRni
-----END CERTIFICATE-----`;
const key = `-----BEGIN PRIVATE KEY-----
MIGHAgEAMBMGByqGSM49AgEGCCqGSM49AwEHBG0wawIBAQQgpI25EhAFjYbx2PB6
eYx3OWRk2AyxV8GUR2o4JpCU4xWhRANCAASFZ+RhPKkDKxqaUF/MqdISK51yX9zv
TaoLnnAkf/gyAUe9gFb3m/wpmlV+kIGn9H6WIQs5mENRZVKwxoOMJ/k0
-----END PRIVATE KEY-----`;

require("https").createServer({key, cert}, (_, res) => {
  res.write("ok");
  res.end();
}).listen(4000);

Save and run the script and in a second terminal create some load:

npx autocannon -d 5 -c 300 -p 10 https://localhost:4000

Server should consistently crash within a few seconds.

How often does it reproduce? Is there a required condition?

Every time

What is the expected behavior?

To not crash

What do you see instead?

It will crash with seemingly random crash signatures. Some examples:

node(74236,0x10a8e7dc0) malloc: Incorrect checksum for freed object 0x106920440: probably modified after being freed.
Corrupt value: 0x7b0a0d30310a0d0a
node(74236,0x10a8e7dc0) malloc: *** set a breakpoint in malloc_error_break to debug
[1]    74236 abort      node try.js
node(74448,0x108606dc0) malloc: *** error for object 0x1068189fb: pointer being freed was not allocated
node(74448,0x108606dc0) malloc: *** set a breakpoint in malloc_error_break to debug
[1]    74448 abort      node try.js
[1]    74410 illegal hardware instruction  node try.js
[1]    74874 segmentation fault  node try.js

Additional information

I don't see the crashes when using http, only when using https or http2 modules. Also I could not reproduce on Linux or Windows. Node was installed using Homebrew.

Crash does not happen with res.end("ok"), only with res.write("ok"); res.end().

@silverwind silverwind changed the title https/http2: random crashes on macOs with simple server https/http2: random crashes on macOS with simple server Aug 20, 2020
@lundibundi lundibundi added http2 Issues or PRs related to the http2 subsystem. https Issues or PRs related to the https subsystem. macos Issues and PRs related to the macOS platform / OSX. labels Aug 20, 2020
@bnoordhuis
Copy link
Member

Node was installed using Homebrew.

Does it also happen with binaries from https://nodejs.org/?

@silverwind
Copy link
Contributor Author

Yes, same with the official v14.8.0 binary from the installer.

Also, here's a new signature I've seen while testing. It's so weird.

[1]    7316 bus error  node try.js

@silverwind
Copy link
Contributor Author

Here's a backtrace of one of the illegal hardware instruction:

(lldb)
Core file '/cores/core.7517' (x86_64) was loaded.

(lldb) bt
* thread #1, stop reason = signal SIGSTOP
  * frame #0: 0x00007fff6811715a libsystem_malloc.dylib`tiny_malloc_from_free_list.cold.4
    frame #1: 0x00007fff680f9f22 libsystem_malloc.dylib`tiny_malloc_from_free_list + 1808
    frame #2: 0x00007fff680f9297 libsystem_malloc.dylib`tiny_malloc_should_clear + 288
    frame #3: 0x00007fff680f80c6 libsystem_malloc.dylib`szone_malloc_should_clear + 66
    frame #4: 0x00007fff680f6d7a libsystem_malloc.dylib`malloc_zone_malloc + 104
    frame #5: 0x00007fff680f6cf5 libsystem_malloc.dylib`malloc + 21
    frame #6: 0x00007fff6526fdea libc++abi.dylib`operator new(unsigned long) + 26
    frame #7: 0x00000001000e04ad node`std::__1::deque<node::http2::NgHttp2StreamWrite, std::__1::allocator<node::http2::NgHttp2StreamWrite> >::__add_back_capacity() + 477
    frame #8: 0x0000000100304798 node`v8::internal::TranslatedState::CreateNextTranslatedValue(int, v8::internal::TranslationIterator*, v8::internal::FixedArray, unsigned long, v8::internal::RegisterValues*, __sFILE*) + 1288
    frame #9: 0x00000001002fa77a node`v8::internal::TranslatedState::Init(v8::internal::Isolate*, unsigned long, v8::internal::TranslationIterator*, v8::internal::FixedArray, v8::internal::RegisterValues*, __sFILE*, int) + 1274
    frame #10: 0x00000001002f7f47 node`v8::internal::TranslatedState::TranslatedState(v8::internal::JavaScriptFrame const*) + 247
    frame #11: 0x000000010031924b node`v8::internal::OptimizedFrame::Summarize(std::__1::vector<v8::internal::FrameSummary, std::__1::allocator<v8::internal::FrameSummary> >*) const + 139
    frame #12: 0x000000010031fcfe node`v8::internal::(anonymous namespace)::CaptureStackTrace(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::(anonymous namespace)::CaptureStackTraceOptions) + 318
    frame #13: 0x0000000100320411 node`v8::internal::Isolate::CaptureAndSetSimpleStackTrace(v8::internal::Handle<v8::internal::JSReceiver>, v8::internal::FrameSkipMode, v8::internal::Handle<v8::internal::Object>) + 97
    frame #14: 0x0000000100333ad1 node`v8::internal::ErrorUtils::Construct(v8::internal::Isolate*, v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, v8::internal::FrameSkipMode, v8::internal::Handle<v8::internal::Object>, v8::internal::ErrorUtils::StackTraceCollection) + 337
    frame #15: 0x000000010033396e node`v8::internal::ErrorUtils::Construct(v8::internal::Isolate*, v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>) + 62
    frame #16: 0x0000000100279700 node`v8::internal::Builtin_ErrorConstructor(int, unsigned long*, v8::internal::Isolate*) + 112
    frame #17: 0x0000000100a48259 node`Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_BuiltinExit + 57
    frame #18: 0x00000001009dd6a1 node`Builtins_JSBuiltinsConstructStub + 97
    frame #19: 0x0000000100ac5de3 node`Builtins_ConstructHandler + 643
    frame #20: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #21: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #22: 0x00000001009df23a node`Builtins_JSEntryTrampoline + 90
    frame #23: 0x00000001009df018 node`Builtins_JSEntry + 120
    frame #24: 0x0000000100312b3b node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) + 2891
    frame #25: 0x0000000100311fe2 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>*) + 210
    frame #26: 0x0000000100203213 node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 435
    frame #27: 0x0000000100002290 node`node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) + 800
    frame #28: 0x0000000100015e18 node`node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) + 200
    frame #29: 0x0000000100159240 node`node::ReportWritesToJSStreamListener::OnStreamAfterReqFinished(node::StreamReq*, int) + 416
    frame #30: 0x000000010015931c node`node::WriteWrap::OnDone(int) + 28
    frame #31: 0x00000001001bb107 node`node::TLSWrap::InvokeQueued(int, char const*) + 263
    frame #32: 0x00000001001bc2a9 node`node::TLSWrap::EncOut() + 505
    frame #33: 0x00000001001bdeb6 node`node::TLSWrap::DoWrite(node::WriteWrap*, uv_buf_t*, unsigned long, uv_stream_s*) + 1286
    frame #34: 0x00000001000cb00f node`node::StreamBase::Write(uv_buf_t*, unsigned long, uv_stream_s*, v8::Local<v8::Object>) + 415
    frame #35: 0x0000000100156c9a node`node::StreamBase::Writev(v8::FunctionCallbackInfo<v8::Value> const&) + 2010
    frame #36: 0x00000001001584fd node`void node::StreamBase::JSMethod<&(node::StreamBase::Writev(v8::FunctionCallbackInfo<v8::Value> const&))>(v8::FunctionCallbackInfo<v8::Value> const&) + 253
    frame #37: 0x00000001009e236d node`Builtins_CallApiCallback + 173
    frame #38: 0x00003ce53fb9819c
    frame #39: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #40: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #41: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #42: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #43: 0x00003ce53fb86bc5
    frame #44: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #45: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #46: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #47: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #48: 0x00003ce53fc897ac
    frame #49: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #50: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #51: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #52: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #53: 0x00000001009df23a node`Builtins_JSEntryTrampoline + 90
    frame #54: 0x00000001009df018 node`Builtins_JSEntry + 120
    frame #55: 0x0000000100312b3b node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) + 2891
    frame #56: 0x0000000100311fe2 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>*) + 210
    frame #57: 0x0000000100203213 node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 435
    frame #58: 0x0000000100002290 node`node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) + 800
    frame #59: 0x0000000100015e18 node`node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) + 200
    frame #60: 0x0000000100159240 node`node::ReportWritesToJSStreamListener::OnStreamAfterReqFinished(node::StreamReq*, int) + 416
    frame #61: 0x000000010015931c node`node::WriteWrap::OnDone(int) + 28
    frame #62: 0x00000001001bb107 node`node::TLSWrap::InvokeQueued(int, char const*) + 263
    frame #63: 0x00000001001bc974 node`node::TLSWrap::OnStreamAfterWrite(node::WriteWrap*, int) + 308
    frame #64: 0x0000000100056db3 node`node::Environment::RunAndClearNativeImmediates(bool)::$_5::operator()(node::CallbackQueue<void, node::Environment*>*) const + 99
    frame #65: 0x00000001000565ab node`node::Environment::RunAndClearNativeImmediates(bool) + 171
    frame #66: 0x000000010005608a node`node::Environment::CheckImmediate(uv_check_s*) + 90
    frame #67: 0x00000001009cadc4 node`uv__run_check + 164
    frame #68: 0x00000001009c4349 node`uv_run + 441
    frame #69: 0x00000001000e4917 node`node::NodeMainInstance::Run() + 375
    frame #70: 0x0000000100079562 node`node::Start(int, char**) + 274
    frame #71: 0x00007fff67f40cc9 libdyld.dylib`start + 1
    frame #72: 0x00007fff67f40cc9 libdyld.dylib`start + 1

@silverwind
Copy link
Contributor Author

And another from this signature:

node(7732,0x1083fadc0) malloc: *** error for object 0x1047cb410: pointer being freed was not allocated
node(7732,0x1083fadc0) malloc: *** set a breakpoint in malloc_error_break to debug
[1]    7732 abort (core dumped)  node try.js

Showing all threads in case it matters:

(lldb) bt all
* thread #1, stop reason = signal SIGSTOP
  * frame #0: 0x00007fff6808833a libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff68144e60 libsystem_pthread.dylib`pthread_kill + 430
    frame #2: 0x00007fff6800f808 libsystem_c.dylib`abort + 120
    frame #3: 0x00007fff6810550b libsystem_malloc.dylib`malloc_vreport + 548
    frame #4: 0x00007fff6810840f libsystem_malloc.dylib`malloc_report + 151
    frame #5: 0x00000001004bf803 node`v8::internal::BackingStore::~BackingStore() + 83
    frame #6: 0x00000001001be0e5 node`node::TLSWrap::DoWrite(node::WriteWrap*, uv_buf_t*, unsigned long, uv_stream_s*) + 1845
    frame #7: 0x00000001000cb00f node`node::StreamBase::Write(uv_buf_t*, unsigned long, uv_stream_s*, v8::Local<v8::Object>) + 415
    frame #8: 0x0000000100156c9a node`node::StreamBase::Writev(v8::FunctionCallbackInfo<v8::Value> const&) + 2010
    frame #9: 0x00000001001584fd node`void node::StreamBase::JSMethod<&(node::StreamBase::Writev(v8::FunctionCallbackInfo<v8::Value> const&))>(v8::FunctionCallbackInfo<v8::Value> const&) + 253
    frame #10: 0x00000001009e236d node`Builtins_CallApiCallback + 173
    frame #11: 0x00001cb61f0d7dfc
    frame #12: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #13: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #14: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #15: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #16: 0x00001cb61f0ee3c5
    frame #17: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #18: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #19: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #20: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #21: 0x00001cb61f0e1b8c
    frame #22: 0x00001cb61f0c58cd
    frame #23: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #24: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #25: 0x00000001009e1522 node`Builtins_InterpreterEntryTrampoline + 194
    frame #26: 0x00000001009df23a node`Builtins_JSEntryTrampoline + 90
    frame #27: 0x00000001009df018 node`Builtins_JSEntry + 120
    frame #28: 0x0000000100312b3b node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) + 2891
    frame #29: 0x0000000100311fe2 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>*) + 210
    frame #30: 0x0000000100203213 node`v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) + 435
    frame #31: 0x0000000100002290 node`node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) + 800
    frame #32: 0x0000000100015e18 node`node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) + 200
    frame #33: 0x0000000100159240 node`node::ReportWritesToJSStreamListener::OnStreamAfterReqFinished(node::StreamReq*, int) + 416
    frame #34: 0x000000010015931c node`node::WriteWrap::OnDone(int) + 28
    frame #35: 0x00000001001bb107 node`node::TLSWrap::InvokeQueued(int, char const*) + 263
    frame #36: 0x00000001001bc974 node`node::TLSWrap::OnStreamAfterWrite(node::WriteWrap*, int) + 308
    frame #37: 0x0000000100056db3 node`node::Environment::RunAndClearNativeImmediates(bool)::$_5::operator()(node::CallbackQueue<void, node::Environment*>*) const + 99
    frame #38: 0x00000001000565ab node`node::Environment::RunAndClearNativeImmediates(bool) + 171
    frame #39: 0x000000010005608a node`node::Environment::CheckImmediate(uv_check_s*) + 90
    frame #40: 0x00000001009cadc4 node`uv__run_check + 164
    frame #41: 0x00000001009c4349 node`uv_run + 441
    frame #42: 0x00000001000e4917 node`node::NodeMainInstance::Run() + 375
    frame #43: 0x0000000100079562 node`node::Start(int, char**) + 274
    frame #44: 0x00007fff67f40cc9 libdyld.dylib`start + 1
    frame #45: 0x00007fff67f40cc9 libdyld.dylib`start + 1
  thread #2, stop reason = signal SIGSTOP
    frame #0: 0x00007fff68086766 libsystem_kernel.dylib`kevent + 10
    frame #1: 0x00000001009d6fc0 node`uv__io_poll + 896
    frame #2: 0x00000001009c4341 node`uv_run + 433
    frame #3: 0x0000000100110e59 node`node::WorkerThreadsTaskRunner::DelayedTaskScheduler::Run() + 361
    frame #4: 0x00007fff68145109 libsystem_pthread.dylib`_pthread_start + 148
    frame #5: 0x00007fff68140b8b libsystem_pthread.dylib`thread_start + 15
  thread #3, stop reason = signal SIGSTOP
    frame #0: 0x00007fff68084882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff68145425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x00000001009d1d89 node`uv_cond_wait + 9
    frame #3: 0x0000000100111078 node`node::TaskQueue<v8::Task>::BlockingPop() + 72
    frame #4: 0x000000010010e07b node`node::(anonymous namespace)::PlatformWorkerThread(void*) + 379
    frame #5: 0x00007fff68145109 libsystem_pthread.dylib`_pthread_start + 148
    frame #6: 0x00007fff68140b8b libsystem_pthread.dylib`thread_start + 15
  thread #4, stop reason = signal SIGSTOP
    frame #0: 0x00007fff68084882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff68145425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x00000001009d1d89 node`uv_cond_wait + 9
    frame #3: 0x0000000100111078 node`node::TaskQueue<v8::Task>::BlockingPop() + 72
    frame #4: 0x000000010010e07b node`node::(anonymous namespace)::PlatformWorkerThread(void*) + 379
    frame #5: 0x00007fff68145109 libsystem_pthread.dylib`_pthread_start + 148
    frame #6: 0x00007fff68140b8b libsystem_pthread.dylib`thread_start + 15
  thread #5, stop reason = signal SIGSTOP
    frame #0: 0x00007fff68084882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff68145425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x00000001009d1d89 node`uv_cond_wait + 9
    frame #3: 0x0000000100111078 node`node::TaskQueue<v8::Task>::BlockingPop() + 72
    frame #4: 0x000000010010e07b node`node::(anonymous namespace)::PlatformWorkerThread(void*) + 379
    frame #5: 0x00007fff68145109 libsystem_pthread.dylib`_pthread_start + 148
    frame #6: 0x00007fff68140b8b libsystem_pthread.dylib`thread_start + 15
  thread #6, stop reason = signal SIGSTOP
    frame #0: 0x00007fff68084882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff68145425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x00000001009d1d89 node`uv_cond_wait + 9
    frame #3: 0x0000000100111078 node`node::TaskQueue<v8::Task>::BlockingPop() + 72
    frame #4: 0x000000010010e07b node`node::(anonymous namespace)::PlatformWorkerThread(void*) + 379
    frame #5: 0x00007fff68145109 libsystem_pthread.dylib`_pthread_start + 148
    frame #6: 0x00007fff68140b8b libsystem_pthread.dylib`thread_start + 15
  thread #7, stop reason = signal SIGSTOP
    frame #0: 0x00007fff68081e36 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x00000001009d2310 node`uv_sem_wait + 16
    frame #2: 0x0000000100174c73 node`node::inspector::(anonymous namespace)::StartIoThreadMain(void*) + 19
    frame #3: 0x00007fff68145109 libsystem_pthread.dylib`_pthread_start + 148
    frame #4: 0x00007fff68140b8b libsystem_pthread.dylib`thread_start + 15

@silverwind
Copy link
Contributor Author

Anyone able to reproduce?

I can myself reproduce on two machines but I still wonder if this is something about my particular setups.

@bnoordhuis
Copy link
Member

I've not been able to reproduce with either v14.8.0 or master. I'm running macOS 10.14.6 and using wrk-d 30s -c 50 -t 10 to generate load.

@silverwind
Copy link
Contributor Author

Can't get it to crash using wrk no matter how high I go with connections/threads, but autocannon consistently does it within 5 seconds.

$ wrk -d 5s -c 5000 -t 100 https://localhost:4000
Running 5s test @ https://localhost:4000
  100 threads and 5000 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    93.17ms  182.04ms   1.89s    96.48%
    Req/Sec   115.55    279.75     3.49k    96.75%
  24935 requests in 5.10s, 3.40MB read
  Socket errors: connect 112, read 0, write 0, timeout 829
Requests/sec:   4887.93
Transfer/sec:    682.59KB
$ npx autocannon -d 5 -c 300 -p 10 https://localhost:4000
Running 5s test @ https://localhost:4000
300 connections with 10 pipelining factor

┌─────────┬──────┬──────┬───────┬───────┬──────────┬──────────┬───────────┐
│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%   │ Avg      │ Stdev    │ Max       │
├─────────┼──────┼──────┼───────┼───────┼──────────┼──────────┼───────────┤
│ Latency │ 0 ms │ 4 ms │ 35 ms │ 65 ms │ 10.27 ms │ 18.47 ms │ 325.29 ms │
└─────────┴──────┴──────┴───────┴───────┴──────────┴──────────┴───────────┘
┌───────────┬────────┬────────┬─────────┬─────────┬─────────┬─────────┬────────┐
│ Stat      │ 1%     │ 2.5%   │ 50%     │ 97.5%   │ Avg     │ Stdev   │ Min    │
├───────────┼────────┼────────┼─────────┼─────────┼─────────┼─────────┼────────┤
│ Req/Sec   │ 25871  │ 25871  │ 29215   │ 30927   │ 28888   │ 1686.95 │ 25867  │
├───────────┼────────┼────────┼─────────┼─────────┼─────────┼─────────┼────────┤
│ Bytes/Sec │ 3.7 MB │ 3.7 MB │ 4.18 MB │ 4.42 MB │ 4.13 MB │ 241 kB  │ 3.7 MB │
└───────────┴────────┴────────┴─────────┴─────────┴─────────┴─────────┴────────┘

Req/Bytes counts sampled once per second.

144k requests in 5.22s, 20.7 MB read

@silverwind
Copy link
Contributor Author

silverwind commented Aug 25, 2020

Something odd I noticed: If I set autocannon to test for 15s (-d 15), it will only crash after 15s so maybe the crash reason is something that autocannon does during its teardown. cc: @mcollina.

@szmarczak

This comment has been minimized.

@szmarczak

This comment has been minimized.

@szmarczak

This comment has been minimized.

@szmarczak

This comment has been minimized.

@szmarczak

This comment has been minimized.

@szmarczak

This comment has been minimized.

@szmarczak

This comment has been minimized.

@silverwind
Copy link
Contributor Author

Probably not related unless your crash signatures are random, like mine.

@szmarczak
Copy link
Member

Ok, sorry for driving you away 😅 I'll mark my comments as off topic then and will create a new issue.

@silverwind
Copy link
Contributor Author

Does not reproduce anymore using node v18.8.0.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
http2 Issues or PRs related to the http2 subsystem. https Issues or PRs related to the https subsystem. macos Issues and PRs related to the macOS platform / OSX.
Projects
None yet
Development

No branches or pull requests

4 participants