High CPU usage

[alexgleason]

Hi, thank you for this great library! It helped me a lot for finding slow queries. But sometimes, under certain conditions I don't understand, the library itself seems to contribute to slowing down my code.

Check this one, for instance. 5.85ms of measure:

It seems to add up, and often calling measure takes more time than the query itself:

However, this doesn't seem to be a problem when the process first starts... only after it has been running for a while. It it possible I have a memory leak and need to do cleanup? Here is the method I am calling:

  executeQuery<R>({ sql, parameters }: CompiledQuery): QueryResult<R> {
    if (!db) throw new Error('Database not open');

    const perf = new ScopedPerformance();
    perf.mark('start');

    const result = {
      rows: db!.prepare(sql).all(...parameters as any[]) as R[],
      numAffectedRows: BigInt(db!.changes),
      insertId: BigInt(db!.lastInsertRowId),
    };

    const { duration } = perf.measure('end', 'start');
    debug(`${sql} \x1b[90m(${(duration / 1000).toFixed(2)}s)\x1b[0m`);

    return result;
  },

Here is the cpuprofile so you can take a look yourself:
mostr-measure-highcpu.cpuprofile

You can load it into Chrome DevTools here:

[alexgleason]

Hi @esroyo, can you please take a look at this?

It appears performance is suffering due to a call to Deno's performance API itself, specifically findMostRecent:

function findMostRecent(
  name,
  type,
) {
  return ArrayPrototypeFind(
    ArrayPrototypeReverse(ArrayPrototypeSlice(performanceEntries)),
    (entry) => entry.name === name && entry.entryType === type,
  );
}

This must be due to a memory leak, right? We are saving too many entries and then not clearing them, so the list gets longer and longer over time.

Is there anything we can do on our end (or within this library) to prevent that?

EDIT: Maybe I just need to call perf.clearMarks(); perf.clearMeasures();?

EDIT2: https://gitlab.com/soapbox-pub/ditto/-/merge_requests/141

[esroyo]

@alexgleason I'm very sorry to be this late, the notification got totally overlooked 😔 🙏

Your reasoning makes every sense: if there is a problem of time accessing the given measure or mark, it must be form the underlying native Performance implementation, in this case Deno's. The only thing we can do from user-land is to make sure the given measures/marks are removed once the instance is not needed any more (as you already did).

Probably it is a good idea to implement Symbol.dispose on the ScopedPerformance class, so that the clearing is done when the scope ends:

{
    using perf = new ScopedPerformance();
    perf.mark('start');

    // ...
    const { duration } = perf.measure('end', 'start');

}

// when `perf` is not accessible any more, this should happen out-of-the-box
// perf.clearMarks();
// perf.clearMeasures();

[esroyo]

• The upcoming Deno 2.0 release will include a improved implementation of measure():
  perf(ext/web): optimize performance.measure() denoland/deno#25774
• version 3.1.0 of ScopedPerformance supports the using keyword, so we do not need to remember clearing the marks and measures manually.

Thanks for your report @alexgleason, again my apologies for late response 🙏

[alexgleason]

That's perfect. Thank you @esroyo !