Slowness in the Event Loop

[gsteri1]

Hi all,

I am running into a hard to debug issue. I am using better-sqlite3 to log some activity from a webapp into a table with a handful of columns.

CREATE TABLE IF NOT EXISTS sometable('key' varchar, 'value' varchar, 'createdAt' DATETIME NOT NULL, 'updatedAt' DATETIME NOT NULL, 'TTL' INTEGER); The table is written to sporadically and not very intensively, so once a day there are 40-70 writes, the value varchar can be large 2-3mb, but is typically small (less than 100-200 characters). The better-sqlite store replaces an in memory cache, literally a js map. The application is a long running webapp in node.

After the joy of everything working faded, the app seemed sluggish. At first, I thought it was my imagination, so I added a little bit of software to check when the event loop gets behind:

module.exports = function (fn, options) {
    const opts = options || {};
    let start = process.hrtime();
    const interval = opts.interval || 100;
    const threshold = opts.threshold || 10;

    return setInterval(function () {
        const delta = process.hrtime(start);
        const nanosec = delta[0] * 1e9 + delta[1];
        const ms = nanosec / 1e6;
        const n = ms - interval;

        if (n > threshold) {
            fn(Math.round(n));
        }
        start = process.hrtime();
    }, interval).unref();
}; 

When the application is mostly idle the callback fires every few seconds, even if the threshold is set to 250 millis. When there is load on the application it (delay) can spike by an order or two of magnitude. I do have WAL mode set.

Is there anything happening in the background that would cause this behavior? Going back to the map returns the app to its former timings. For reference, all of the access to the underlying SQLITE db is via cached prepared statements. Here's a get statement:

 const getKeyIfExists = db.prepare(`SELECT key FROM sometable where key = ? LIMIT 1`);
 const test = getKeyIfExists .get(key);

Is there some clean up I need to do?

Thank you!

Node version 16.16.0

[Prinzhorn]

1. Please properly format your message, so that the code is readable https://docs.github.com/en/get-started/writing-on-github/getting-started-with-writing-and-formatting-on-github/basic-writing-and-formatting-syntax
2. Upgrade to the latest better-sqlite3 and to a supported Node.js version (end of life for 16 was five months ago)

[gsteri1]

@Prinzhorn The behavior is the same in v18. I have edited the code in the original report.

[Prinzhorn]

Is there anything happening in the background that would cause this behavior?

There is nothing happening that you don't control/trigger.

It's impossible to tell what is happening here with this little information. Can you trace down which call exactly is taking so long? Can you create a minimal demo that demonstrates the issue (with better-sqlite3 as only dependency)?

[gsteri1]

@Prinzhorn Thanks for the quick responses. I will try to hack something up.

In the meantime swapping out to Sqlite3 does not result in a similar issue (slowing the event loop). I understand this is apples to oranges, but that's why I asked about any background processing.

[Prinzhorn]

See https://nodejs.org/en/guides/simple-profiling for how to profile where the time is spent, I assume one of your queries is super slow.

You have key indexed, right?

In the meantime swapping out to Sqlite3 does not result in a similar issue (slowing the event loop). I understand this is apples to oranges, but that's why I asked about any background processing.

You're probably doing something very slow and sqlite3 is masking that by giving control back to the event loop.

[gsteri1]

Yeah, I agree that this is my doing. I will try the indexing to see if that cures it.

[gsteri1]

So adding the index has helped dramatically. Adding in the following pragmas also seems to help. PRAGMA journal_mode = WAL; PRAGMA synchronous = normal; pragma temp_store = memory;

More testing to be done.

[gsteri1]

I am closing this issue. More and more, this looks like my misuse of the library. The application was creating a lot of queries for a field that was stored in one of the tables. Async code of the Sqlite3 was masking the scale of those requests. Fixing the app removed the problem with the stuck event queue. Thanks to the responder @Prinzhorn for the gentle nudge. Apologies for the dead end.