corelight / zeekjs

ZeekJS - Experimental JavaScript support for Zeek.
BSD 3-Clause "New" or "Revised" License
9 stars 4 forks source link

Using pinojs hangs Zeek process #64

Closed awelzel closed 1 year ago

awelzel commented 1 year ago

Mike Peters reported that using pinojs with ZeekJS hangs the process on shutdown: In fact, it spins at 100% CPU

The following JavaScript file reproduces the issue:

const pino = require('pino')();

Example stack trace when hanging:

(gdb) bt
#0  0x00007fbeceaa0406 in v8::internal::LookupIterator::FetchValue(v8::internal::AllocationPolicy) const () from /opt/node-19.8/lib/libnode.so.111
#1  0x00007fbeceabe4ea in v8::internal::Object::GetProperty(v8::internal::LookupIterator*, bool) () from /opt/node-19.8/lib/libnode.so.111
#2  0x00007fbecec1a0f9 in v8::internal::Runtime::GetObjectProperty(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, bool*) () from /opt/node-19.8/lib/libnode.so.111
#3  0x00007fbece61cdc3 in v8::Object::Get(v8::Local<v8::Context>, v8::Local<v8::Value>) () from /opt/node-19.8/lib/libnode.so.111
#4  0x00007fbecdf002b3 in node::errors::TriggerUncaughtException(v8::Isolate*, v8::Local<v8::Value>, v8::Local<v8::Message>, bool) () from /opt/node-19.8/lib/libnode.so.111
#5  0x00007fbece78fdc1 in v8::internal::MessageHandler::ReportMessageNoExceptions(v8::internal::Isolate*, v8::internal::MessageLocation const*, v8::internal::Handle<v8::internal::Object>, v8::Local<v8::Value>) () from /opt/node-19.8/lib/libnode.so.111
#6  0x00007fbece790022 in v8::internal::MessageHandler::ReportMessage(v8::internal::Isolate*, v8::internal::MessageLocation const*, v8::internal::Handle<v8::internal::JSMessageObject>) () from /opt/node-19.8/lib/libnode.so.111
#7  0x00007fbece77d1c8 in v8::internal::Isolate::ReportPendingMessages() () from /opt/node-19.8/lib/libnode.so.111
#8  0x00007fbece7642e8 in v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) () from /opt/node-19.8/lib/libnode.so.111
#9  0x00007fbece76532b in v8::internal::Execution::CallBuiltin(v8::internal::Isolate*, v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) () from /opt/node-19.8/lib/libnode.so.111
#10 0x00007fbece62ebda in v8::internal::InvokeFinalizationRegistryCleanupFromTask(v8::internal::Handle<v8::internal::Context>, v8::internal::Handle<v8::internal::JSFinalizationRegistry>, v8::internal::Handle<v8::internal::Object>) () from /opt/node-19.8/lib/libnode.so.111
#11 0x00007fbece7ee781 in v8::internal::FinalizationRegistryCleanupTask::RunInternal() () from /opt/node-19.8/lib/libnode.so.111
#12 0x00007fbecdf73b35 in node::PerIsolatePlatformData::RunForegroundTask(std::unique_ptr<v8::Task, std::default_delete<v8::Task> >) () from /opt/node-19.8/lib/libnode.so.111
#13 0x00007fbecdf74b06 in node::PerIsolatePlatformData::FlushForegroundTasksInternal() () from /opt/node-19.8/lib/libnode.so.111
#14 0x00007fbecdf74f4a in node::NodePlatform::DrainTasks(v8::Isolate*) () from /opt/node-19.8/lib/libnode.so.111
#15 0x00007fbecde2840c in node::FreeEnvironment(node::Environment*) () from /opt/node-19.8/lib/libnode.so.111
#16 0x00007fbed46bb5a8 in std::unique_ptr<node::Environment, void (*)(node::Environment*)>::~unique_ptr (this=0x6190002e45c8, __in_chrg=<optimized out>) at /usr/include/c++/10/bits/unique_ptr.h:361
#17 0x00007fbed46c7348 in plugin::Nodejs::Instance::~Instance (this=0x6190002e4580, __in_chrg=<optimized out>) at /home/awelzel/corelight-oss/zeekjs/src/Nodejs.h:24
#18 0x00007fbed46c63c9 in plugin::Corelight_ZeekJS::Plugin::Done (this=0x7fbed46ffd40 <plugin::Corelight_ZeekJS::plugin>) at /home/awelzel/corelight-oss/zeekjs/src/Plugin.cc:397
#19 0x000055e773785b23 in zeek::plugin::Manager::FinishPlugins (this=<optimized out>) at ../src/plugin/Manager.cc:547
#20 0x000055e7730a6094 in zeek::detail::terminate_zeek () at ../src/zeek-setup.cc:426
#21 0x000055e7730b4825 in zeek::detail::cleanup (did_run_loop=<optimized out>) at ../src/zeek-setup.cc:1152
#22 0x000055e773d84ffb in main (argc=<optimized out>, argv=<optimized out>) at ../src/main.cc:124
awelzel commented 1 year ago

pinojs uses on-exit-leak-free as a dependency and using that alone seems to trigger the hang:

$ cat on-exit-lf.js 
'use strict'

const { register, unregister } = require('on-exit-leak-free')

const obj = { foo: 'bar' };

console.log("register")
register(obj, shutdown);

function shutdown (obj, eventName) {
  console.log(eventName) // beforeExit
}
console.log("done")
awelzel commented 1 year ago

and after some more reducing, using FinalizationRegistry seems to be the culprit. The following already hangs without any external libraries:

$ cat on-exit-hang.js 
'use strict'

function clear() {
  console.log("clear");
}

const registry = new FinalizationRegistry(clear);

function onExit () {
  console.log("onExit()");
}

setImmediate(() => {
  let obj = {foo: 'bar'};
  let ref = new WeakRef(obj);
  registry.register(obj, ref);
  process.on('exit', onExit);
});