Out of Order Console Output #2590
Description
👓 What did you see?
[17:07:03.086] INFO: Preparing a request...
[17:07:03.086] INFO: Base URL...
[17:07:03.086] INFO: Prepared URL...
.[17:07:03.520] INFO: Sending request...
....
75 scenarios (75 passed)
502 steps (502 passed)
6m36.666s (executing steps: 6m34.612s)
[17:07:03.807] INFO: Asserting...
[17:07:03.810] INFO: Asserting...
[17:07:03.810] INFO: Asserting...
[17:07:03.810] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.812] INFO: PASSED (After step executed)
Waiting for the debugger to disconnect...
npm info ok
Waiting for the debugger to disconnect...
npm info ok
✅ What did you expect to see?
[17:07:03.086] INFO: Preparing a request...
[17:07:03.086] INFO: Base URL...
[17:07:03.086] INFO: Prepared URL...
.[17:07:03.520] INFO: Sending request...
....
[17:07:03.807] INFO: Asserting...
[17:07:03.810] INFO: Asserting...
[17:07:03.810] INFO: Asserting...
[17:07:03.810] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.811] INFO: Asserting...
[17:07:03.812] INFO: PASSED (After step executed)
75 scenarios (75 passed)
502 steps (502 passed)
6m36.666s (executing steps: 6m34.612s)
Waiting for the debugger to disconnect...
npm info ok
Waiting for the debugger to disconnect...
npm info ok
📦 Which tool/library version are you using?
Node.js 22.15.0
Cucumber.js 12.0.0
Pino 9.7.0
TS 5.8
🔬 How could we reproduce it?
I would say using pino to do logging on a few test steps with an after hook step defined then see if it outputs in the correct order, I have used two different methods to implement pino to see if anything changes but no luck.
Currently setup pino to log as such:
level: 'info':
transport.target: 'pino-pretty'
options.colorize: true
options.ignore: 'pid,hostname'
options.singleLine: true
pino.destination({ sync: true }):
📚 Any additional context?
Hey there, I am having an out of order issue with console/process output, execution completes but seems the summary is getting output ahead before the last scenario can complete its steps and after step. Attempted a change my pino call to sync it but that did nothing, exploring a custom formatter but seems overkill for this issue, any possible ideas to get it to correctly sync? It was working as expected with console.log, only now using pino, I think it has introduced a slight delay that results in the summary getting output a split second before due to processes being asynchronous.