breejs / bree

Bree is a Node.js and JavaScript job task scheduler with worker threads, cron, Date, and human syntax. Built for @ladjs, @forwardemail, @spamscanner, @cabinjs.
https://jobscheduler.net
MIT License
3.01k stars 78 forks source link

Job with simple console.logs exists before finished #121

Closed BertCatsburg closed 3 years ago

BertCatsburg commented 3 years ago

This is almost the same issue as #109, however simpler code.

I have a Bree scheduler written in Typescript. Each job does a lot of async things, therefore the Scheduler and the Jobs (workers) are enclosed in an IFFE

One example Job has just 3 console.log statement. And the job runs every 10 seconds.

First run all 3 console.logs are shown, but starting from the second run only the first is shown. (See output below)

There is a complete reproducable environment on https://github.com/BertCatsburg/BreeJS-Jobs-exit-before-finished

Relevant files

scheduler.ts

import Bree from 'bree';
import {typescript_worker} from "./lib/typescript_worker";

(async () => {
    try {

        const bree = new Bree({
            jobs: [
                {
                    name: 'HelloWorld',
                    path: typescript_worker,
                    interval: 'every 10 seconds',
                    worker: {workerData: { filename: './jobs/hello_world.ts'}}
                }
            ]
        });

        bree.start()
    } catch (error) {
        console.error(error);
    }
})();

typescript_worker.ts

Taken from the documentation

hello_world.ts

const {parentPort} = require('worker_threads');

(async () => {

    try {

        console.log('AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA');
        console.log('BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB');
        console.log('CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC');

    } catch (error) {
        console.error('Something wrong in the HelloWorld Job');
        console.error(error);
    } finally {
        if (parentPort) {
            parentPort.postMessage('done');
        } else {
            process.exit(0);
        }
    }
})();

Output

When doing a npm start the following output appears:

$ npm start

> breejs-testing@1.0.0 start
> nodemon --config nodemon.json

[nodemon] 2.0.12
[nodemon] to restart at any time, enter `rs`
[nodemon] watching path(s): src jobs/**/*
[nodemon] watching extensions: ts,json
[nodemon] starting `ts-node ./scheduler.ts`
Worker for job "HelloWorld" online undefined
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
Worker for job "HelloWorld" signaled completion { message: 'done' }
BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB
CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC
Worker for job "HelloWorld" online undefined
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
Worker for job "HelloWorld" signaled completion { message: 'done' }
Worker for job "HelloWorld" online undefined
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
Worker for job "HelloWorld" signaled completion { message: 'done' }
Worker for job "HelloWorld" online undefined
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
Worker for job "HelloWorld" signaled completion { message: 'done' }
^C

It is strange that the first run the output first shows the ending message and then the last 2 log messages.

And the problem is that starting from the second run the last 2 log messages do not appear.

shadowgate15 commented 3 years ago

Keep in mind that console hijacks stdout which means that anytime the main thread is busy it won't output from the worker. This is a known issue/functionality in nodejs. We suggest passing any console messages back to parent port and use the provided messageHandler functions.

BertCatsburg commented 3 years ago

Yes, that's it. Sorry I did not see that.

I've changed the code as follows and now it works:

scheduler

const bree = new Bree({
            jobs: [
                {
                    name: 'HelloWorld',
                    path: typescript_worker,
                    interval: 'every 10 seconds',
                    worker: {workerData: { filename: './jobs/hello_world.ts'}}
                }
            ],
            workerMessageHandler: (message) => {
                console.log(message);
            }
        });

hello_world.ts

const {parentPort} = require('worker_threads');

(async () => {

    try {

        l('AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA');
        l('BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB');
        l('CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC');

    } catch (error) {
        console.error('Something wrong in the HelloWorld Job');
        console.error(error);
    } finally {
        if (parentPort) {
            parentPort.postMessage('done');
        } else {
            process.exit(0);
        }
    }
})();

function l(message: string) {
    if (parentPort) {
        parentPort.postMessage(message);
    }
}

And now it works.