Buffer console writes every 100ms

[mariusandra]

Changes

This is an attempt to lazily solve #424 by buffering console.log calls to run every 100ms. My theory is that writing ASAP causes strain (wildly fluctuating usage) on the postgres connection pool, which leads to deadlocks and those errors that I'm seeing.

Prior to this PR, when I ran this plugin locally:

export const jobs = {
    processEvent (event, meta) {
        console.log('retrying job!')
    }
}
export function processEvent (event, { jobs }) {
    console.log('in processEvent')
    jobs.processEvent(event).runIn(3, 'seconds')
    return event
}

... and browsed around app locally, I saw these timeouts in my console.

After the changes in this PR I at first thought the timeouts got better, but not really. Soon after this happened:

[worker(worker-304ea0492a41cf15ba)] INFO: Completed task 928 (pluginJob) with success (0.43ms)
[worker(worker-0014bf26d851335d6e)] INFO: Completed task 929 (pluginJob) with success (0.47ms)
[MAIN] 12:02:05 🕒 Processed 5 events in 12s
[MAIN] 12:03:39 🕒 Processed 4 events in 94.43s
⌛⌛⌛ Postgres slow query warning after 30 sec {
  queryTextOrConfig: 'INSERT INTO posthog_pluginlogentry (id, team_id, plugin_id, plugin_config_id, timestamp, source,type, message, instance_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9)',
  values: [
    '0179a81f-96e3-0000-3ac2-10e5c14925ad',
    1,
    3,
    10,
    '2021-05-26 10:01:53.123',
    'CONSOLE',
    'LOG',
    'retrying job!',
    '0179a81e-acb0-0000-9cb6-8e9003fb7044'
  ]
}
⌛⌛⌛ Postgres slow query warning after 30 sec {
  queryTextOrConfig: 'INSERT INTO posthog_pluginlogentry (id, team_id, plugin_id, plugin_config_id, timestamp, source,type, message, instance_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9)',
  values: [
    '0179a81f-96e4-0000-cfe1-43b1c779d85c',
    1,
    3,
    10,
    '2021-05-26 10:01:53.124',
    'CONSOLE',
    'LOG',
    'retrying job!',
    '0179a81e-acb0-0000-9cb6-8e9003fb7044'
  ]
}
[worker(worker-6dd44ed891298975a3)] INFO: Completed task 932 (pluginJob) with success (0.81ms)
[worker(worker-c97bc884304d2e01cd)] INFO: Completed task 930 (pluginJob) with success (0.57ms)
[worker(worker-0014bf26d851335d6e)] INFO: Completed task 931 (pluginJob) with success (0.50ms)

Going to leave this PR up regardless to discuss what to do. This might be a undiagnosed problem in production as well, so we should treat it seriously :).

Checklist

• Updated Settings section in README.md, if settings are affected
• Jest tests

[mariusandra]

Also, a real buffer would obviously also write the entire buffer one statement, but not yet here...

[Twixes]

Well, it may be that this would benefit significantly from batch insertion instead of multiple single insertions, the buffer doesn't change much without that I think. That should be trivial to add.

[yakkomajuri]

Closing in favor of #486