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

FATAL ERROR: v8::FromJust Maybe value is Nothing. #128

Closed sebreens closed 2 years ago

sebreens commented 3 years ago

We have this job set up that normally works without problems. Every 10 minutes it checks whether any rules are expired and removes the expired ones.

However, seemingly randomly every 1-2 days, the job exits with the following error:

FATAL ERROR: v8::FromJust Maybe value is Nothing.
[2021-09-07T08:30:36.060Z] [error]: Worker for job "delete-expired" had an error
 1: 0xa24ed0 node::Abort() [node]
 2: 0x966115 node::FatalError(char const*, char const*) [node]
 3: 0xb9a9fa v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: 0xa286ed node::fs::FileHandle::CloseReq::Resolve() [node]
 5: 0xa28849  [node]
 6: 0x139ca5d  [node]
 7: 0x13a10b6  [node]
 8: 0x13b3e45  [node]
 9: 0x13a19e8 uv_run [node]
10: 0xadd343 node::worker::Worker::Run() [node]
11: 0xadddd8  [node]
12: 0x7fc31a7cf609  [/lib/x86_64-linux-gnu/libpthread.so.0]
13: 0x7fc31a6f6293 clone [/lib/x86_64-linux-gnu/libc.so.6]
Aborted (core dumped)

I have no idea how to go into debugging this but I assume it is an issue with the bree package core files.

The worker itself:

import { knex } from '../app/utils/connection.js';
import { parentPort } from 'worker_threads';
import { CalculatedPrice as CalculatedPriceModel } from '../app/models/index.js';
import { Cache, CalculatedPrice } from '../app/controllers/index.js'
import { getDate } from '../app/utils/date.js';

(async () => {
    // select all data that expired
    const expiredPrices = await knex('calculated_price').select('contact_id', 'sku').where('ending_date', '<', getDate()).then();
    parentPort.postMessage(JSON.stringify(expiredPrices));

    if (expiredPrices.length !== 0) {
        const expiredKeys = [];
        for (let i=0; i<expiredPrices.length; i++) {
            const { contact_id, sku } = expiredPrices[i]
            expiredKeys.push(`${contact_id}_${sku}`);
        }

        const uniqueExpiredKeys = Array.from(new Set(expiredKeys));
        // delete all that data from calculated_price
        const recalculatePairs = uniqueExpiredKeys.map((key) => key.split('_'));
        parentPort.postMessage(recalculatePairs);
        await knex('calculated_price').whereIn(['contact_id', 'sku'], recalculatePairs).del();
        parentPort.postMessage('Deleted data from calculated_price')

        // recalculate
        const calculationPromises = [];
        for (let i=0; i<expiredPrices.length; i++) {
            const { contact_id, sku } = expiredPrices[i];
            calculationPromises.push(CalculatedPrice.calculatePriceUsingSku(contact_id, sku));
        }
        await Promise.all(calculationPromises);
        parentPort.postMessage('Recalculated')
        // delete from cache or just rewrite
        parentPort.postMessage(expiredKeys);
        await Cache.deleteCachedCalculatedRules(expiredKeys);
        parentPort.postMessage('Deleted from cache')
        // add in cache
        await Cache.setCalculatedPricesInCache(recalculatePairs);
        parentPort.postMessage('Added to cache')
    }

    process.exit(0);
})();

Any help how this could be debugged?

shadowgate15 commented 3 years ago

Try wrapping your function in a try...catch. I'm betting that the promise is returning an error but since it isn't caught you aren't getting good information.

sebreens commented 2 years ago

Thanks for the tip @shadowgate15 . I don't know how I had missed doing that. It did catch a mysql timeout error that caused the task to fail.

However, it just failed again. Now it does happen much more rare as this is the first time since I implemented your suggestion. This is what my logs show:

[2021-09-10T10:09:50.682Z] [info]: Worker for job "delete-expired" online
node[39105]: ../src/node_file-inl.h:160:node::fs::FSReqPromise<AliasedBufferT>::~FSReqPromise() [with AliasedBufferT = node::AliasedBufferBase<double, v8::Float64Array>]: Assertion `finished_' failed.
[2021-09-10T10:09:50.716Z] [error]: Worker for job "delete-expired" had an error
 1: 0xa24ed0 node::Abort() [node]
 2: 0xa24f4e  [node]
 3: 0xa2001a  [node]
 4: 0xa2ac42 node::fs::FSReqAfterScope::~FSReqAfterScope() [node]
 5: 0xa2b69e node::fs::AfterOpenFileHandle(uv_fs_s*) [node]
 6: 0x139ca5d  [node]
 7: 0x13a10b6  [node]
 8: 0x13b3e45  [node]
 9: 0x13a19e8 uv_run [node]
10: 0xadd343 node::worker::Worker::Run() [node]
11: 0xadddd8  [node]
12: 0x7fb1c6280609  [/lib/x86_64-linux-gnu/libpthread.so.0]
13: 0x7fb1c61a7293 clone [/lib/x86_64-linux-gnu/libc.so.6]
Aborted (core dumped)

Any further ideas? The whole contents of the async function are wrapped in a try catch block. It's weird that this error didn't get caught there. I assume it happens within bree/nodejs itself.

sebreens commented 2 years ago

Mhm, that's weird. Just received another instance of the first error. I suppose it wasn't caused by the mysql timeout after all...

[2021-09-10T11:30:10.428Z] [info]: Worker for job "delete-expired" online
FATAL ERROR: v8::FromJust Maybe value is Nothing.
[2021-09-10T11:30:10.452Z] [error]: Worker for job "delete-expired" had an error
 1: 0xa24ed0 node::Abort() [node]
 2: 0x966115 node::FatalError(char const*, char const*) [node]
 3: 0xb9a9fa v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: 0xa286ed node::fs::FileHandle::CloseReq::Resolve() [node]
 5: 0xa28849  [node]
 6: 0x139ca5d  [node]
 7: 0x13a10b6  [node]
 8: 0x13b3e45  [node]
 9: 0x13a19e8 uv_run [node]
10: 0xadd343 node::worker::Worker::Run() [node]
11: 0xadddd8  [node]
12: 0x7f8b6f6b8609  [/lib/x86_64-linux-gnu/libpthread.so.0]
13: 0x7f8b6f5df293 clone [/lib/x86_64-linux-gnu/libc.so.6]
Aborted (core dumped)

Do you have an idea how to catch this error to have more info?

shadowgate15 commented 2 years ago

What version of node are you using?

Does your file open any other files? It looks like the error might be coming from some sort of error inside of filesystem package from node?

sebreens commented 2 years ago

I'm running node 14.17.6 - the latest LTS version. It opens files in so much as it import the other classes. Other than that, well, all the code above is what is getting executed. I'm thinking now, is there something else I could wrap in a try catch to be able to catch this error. The job failing now and then wouldn't be a problem as it's repeated on a schedule, but it crashing the app is a major problem.

shadowgate15 commented 2 years ago

yeah the fact that it is crashing with a V8 error makes me think there is a promise that isn't being caught correctly.

The reason I ask about fs is because it is part of the error chain. That wouldn't fire unless you explicitly used the fs module. Not when loading files as part of import. That is done on the backend not by fs, I believe.

[This] indicates it might be a cache/memory size issue... I don't know if that helps any. I wonder if knex is pulling something that is to large to cache in the system memory... don't know why there isn't a memory out of space issue.

Here is a random idea since that v8::FromJust Maybe value is Nothing error seems to be linked to a module not caching correctly why don't you try wrapping the imports in a try...catch I don't know if you can actually do that... I never have but ESM import is an async operation making it a Promise which would create an issue with not giving a clear error log possibly...

shadowgate15 commented 2 years ago

We might also try posting this on the NodeJS issue list.

climba03003 commented 2 years ago

Just an idea, when I connect mongodb inside a worker but not closing the connection properly before exit. It will throw me a core error about stream.

I assume knex using sqlite will result the same if not properly closing the fs stream?

shadowgate15 commented 2 years ago

It might. although that must be something new and/or something specific to v16 cause I haven't experienced that before. I mean it can cause memory leaks which isn't great... but never got an error cause I didn't close the connection.

shadowgate15 commented 2 years ago

@climba03003 Let us know if it works so we can have that documented here.

TRCSamurai commented 2 years ago

Having the same issue, I'm running Node v16.6.2. I've wrapped every job into a try...catch, but I'm still getting the errors & a memory leak. Jobs are run via pm2.

Every job extends the following class and implements a run fnc.

import listeners from "./../listeners"
import {Model} from "objection";
import Knex from "knex";
import DB_CONFIG from "../config/database";
import logger from "../services/core/Logger";

const {parentPort} = require('worker_threads');
Model.knex(Knex(DB_CONFIG))

export default class CronJob {
    constructor() {
        listeners() // it's just a init function for eventemitter2 instance, which is listening for 3 events.
    }

    exit() {
        if (parentPort) parentPort.postMessage('done');
        else process.exit(0);
    }
}

Example Job class

import CronJob from "./CronJob";
import logger from "../services/core/Logger";

class Job extends CronJob {
    async run() {
        try {
            // logic
        } catch (e) {
            logger.error("error" ,e)
        }
        this.exit()
    }
}

// Run the job
(new Job).run();

In the run function there is a try...catch and after the job is done the exit func. is called. All jobs have closeWorkerAfterMs set.

cronjobs/index.js

const path = require('path');
import ms from 'ms';
import Graceful from '@ladjs/graceful';
import logger from "../services/core/Logger";

// required
const Bree = require('bree');

let jobs = [
    {
        name: 'Cronjob',
        closeWorkerAfterMs: ms('19m'),
        cron: '*/20 * * * *',
        path: path.join(__dirname, 'fractional', 'Cronjob.js')
    }
];

const bree = new Bree({
    logger: logger,
    root: path.resolve('dist/cronjobs'),
    jobs: jobs
});
const graceful = new Graceful({brees: [bree]});
graceful.listen();
bree.start();

Error

FATAL ERROR: v8::FromJust Maybe value is Nothing.
 1: 0xafedf0 node::Abort() [node /var/www/workers/dist/cr]
 2: 0xa1814d node::FatalError(char const*, char const*) [node /var/www/workers/dist/cr]
 3: 0xce766a v8::Utils::ReportApiFailure(char const*, char const*) [node /var/www/workers/dist/cr]
 4: 0xbda9f8 node::ReportWritesToJSStreamListener::OnStreamAfterReqFinished(node::StreamReq*, int) [node /var/www/workers/dist/cr]
 5: 0xbdad5f node::WriteWrap::OnDone(int) [node /var/www/workers/dist/cr]
 6: 0xcad540 node::crypto::TLSWrap::InvokeQueued(int, char const*) [node /var/www/workers/dist/cr]
 7: 0xcae5d9 node::crypto::TLSWrap::EncOut() [node /var/www/workers/dist/cr]
 8: 0xcaf6e8  [node /var/www/workers/dist/cr]
 9: 0xa866f4 node::Environment::RunAndClearNativeImmediates(bool) [node /var/www/workers/dist/cr]
10: 0xa86d7c  [node /var/www/workers/dist/cr]
11: 0x1542066  [node /var/www/workers/dist/cr]
12: 0x1554df5  [node /var/www/workers/dist/cr]
13: 0x1542998 uv_run [node /var/www/workers/dist/cr]
14: 0xa3ff25 node::SpinEventLoop(node::Environment*) [node /var/www/workers/dist/cr]
15: 0xbc6a3a node::worker::Worker::Run() [node /var/www/workers/dist/cr]
16: 0xbc71c8  [node /var/www/workers/dist/cr]
17: 0x7f64ea2a8609  [/lib/x86_64-linux-gnu/libpthread.so.0]
18: 0x7f64ea1cf293 clone [/lib/x86_64-linux-gnu/libc.so.6]
shadowgate15 commented 2 years ago

I'm wondering if this is a knex issue.

TRCSamurai commented 2 years ago

I'm not sure, but I would imagine I would see knex/db related errors in the logs if that was the case.

shadowgate15 commented 2 years ago

you won't if the problem isn't coming from the db but from the knex module.