temporalio
[Bug] Jest detects open handle
cd activities-examples
npm run jest -- -t httpWorkflow
results in:
A worker process has failed to exit gracefully and has been force exited. This is likely caused by tests leaking due to improper teardown. Try running with --detectOpenHandles to find leaks. Active timers can also cause this, ensure that .unref() was called on them.
npm run jest -- -t httpWorkflow --detectOpenHandles
results in:
Jest has detected the following 1 open handle potentially keeping Jest from exiting:
● neon threadsafe function
> 1 | import { TestWorkflowEnvironment } from '@temporalio/testing';
| ^
2 | import { Worker, Runtime, DefaultLogger, LogEntry } from '@temporalio/worker';
3 | import { v4 as uuid4 } from 'uuid';
4 | import { httpWorkflow } from './workflows';
at Object.<anonymous> (node_modules/@temporalio/worker/src/worker.ts:95:8)
at Object.<anonymous> (node_modules/@temporalio/worker/src/index.ts:29:1)
at Object.<anonymous> (node_modules/@temporalio/testing/src/index.ts:20:1)
at Object.<anonymous> (src/workflows.test.ts:1:1)
I did a bunch of digging on this. Haven't been able to make much headway, however my best guess is that Jest is preventing something in Worker package from cleaning up properly.
Below is the info on the only entry in process._getActiveHandles() in afterAll() that isn't stdio.
<ref *1> ReadStream {
connecting: false,
_hadError: false,
_parent: null,
_host: null,
_readableState: ReadableState {
objectMode: false,
highWaterMark: 0,
buffer: BufferList { head: null, tail: null, length: 0 },
length: 0,
pipes: [],
flowing: null,
ended: false,
endEmitted: false,
reading: false,
constructed: true,
sync: false,
needReadable: true,
emittedReadable: false,
readableListening: false,
resumeScheduled: false,
errorEmitted: false,
emitClose: false,
autoDestroy: true,
destroyed: false,
errored: null,
closed: false,
closeEmitted: false,
defaultEncoding: 'utf8',
awaitDrainWriters: null,
multiAwaitDrain: false,
readingMore: false,
dataEmitted: false,
decoder: null,
encoding: null,
[Symbol(kPaused)]: null
},
_events: [Object: null prototype] {
end: [Function: onReadableStreamEnd],
pause: [Function (anonymous)]
},
_eventsCount: 2,
_maxListeners: undefined,
_writableState: WritableState {
objectMode: false,
highWaterMark: 0,
finalCalled: false,
needDrain: false,
ending: false,
ended: false,
finished: false,
destroyed: false,
decodeStrings: false,
defaultEncoding: 'utf8',
length: 0,
writing: false,
corked: 0,
sync: true,
bufferProcessing: false,
onwrite: [Function: bound onwrite],
writecb: null,
writelen: 0,
afterWriteTickInfo: null,
buffered: [],
bufferedIndex: 0,
allBuffers: true,
allNoop: true,
pendingcb: 0,
constructed: true,
prefinished: false,
errorEmitted: false,
emitClose: false,
autoDestroy: true,
errored: null,
closed: false,
closeEmitted: false,
writable: false,
[Symbol(kOnFinished)]: []
},
allowHalfOpen: false,
_sockname: null,
_pendingData: null,
_pendingEncoding: '',
server: null,
_server: null,
isRaw: false,
isTTY: true,
fd: 0,
[Symbol(async_id_symbol)]: 355,
[Symbol(kHandle)]: TTY { reading: false, [Symbol(owner_symbol)]: [Circular *1] },
[Symbol(kSetNoDelay)]: false,
[Symbol(lastWriteQueueSize)]: 0,
[Symbol(timeout)]: null,
[Symbol(kBuffer)]: null,
[Symbol(kBufferCb)]: null,
[Symbol(kBufferGen)]: null,
[Symbol(kCapture)]: false,
[Symbol(kBytesRead)]: 0,
[Symbol(kBytesWritten)]: 0
}
Below is the "neon threadsafe function" entries that pop up from why-is-node-running.
# neon threadsafe function
node:internal/async_hooks:201
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/@temporalio/worker/lib/worker.js:65 - native.registerErrors(errors);
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1714 - compiledFunction.call(
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1223 - this._execModule(localModule, options, moduleRegistry, fromPath);
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1047 - this._loadModule(
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1248 - return this.requireModule(from, moduleName);
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/@temporalio/worker/lib/index.js:38 - var worker_1 = require("./worker");
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1714 - compiledFunction.call(
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1223 - this._execModule(localModule, options, moduleRegistry, fromPath);
# neon threadsafe function
node:internal/async_hooks:201
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/@temporalio/worker/lib/worker.js:65 - native.registerErrors(errors);
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1714 - compiledFunction.call(
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1223 - this._execModule(localModule, options, moduleRegistry, fromPath);
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1047 - this._loadModule(
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1248 - return this.requireModule(from, moduleName);
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/@temporalio/worker/lib/index.js:38 - var worker_1 = require("./worker");
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1714 - compiledFunction.call(
/home/val/Workspace/temporalio/samples-typescript/activities-examples/node_modules/jest-runtime/build/index.js:1223 - this._execModule(localModule, options, moduleRegistry, fromPath);
Neither is especially helpful from what I can tell, but maybe this helps someone else.
I noticed that there's also a lag at the end of Mocha tests, so I suspect this problem isn't limited to just Jest. However, Mocha exits fine, it just takes a while. I can confirm the same thing in Jest: if I add a sufficiently high timeout (about 9200 on my machine), Jest exits without error:
afterAll(async () => {
// Reduce this to 9100 and I still get the open handles issue. But at 9200, the open handles issue goes away
await new Promise(resolve => setTimeout(resolve, 9200));
});
With Mocha, I get a similar issue: the test process hangs for approximately 9.1 seconds before exiting.
@bergundy is there anything you can think of in the test environment that has a 9 or 10 second timeout?
I can’t think of anything with that timeout, might be something that happens internally in core. I think the old test environment didn’t have this issue, I’ll dig into this.
Thanks for looking at it, @vkarpov15
I also just hit this. Ported the example workflow test https://github.com/temporalio/samples-typescript/blob/a0574c6e27bf58b36bcc5f983e8a0941b412c606/activities-examples/src/workflows.test.ts to my app and I now see the following when running Jest:
jest --detectOpenHandles
...
Jest has detected the following 1 open handle potentially keeping Jest from exiting:
● neon threadsafe function
> 1 | import { TestWorkflowEnvironment } from '@temporalio/testing';
