Skip to content

Index job logs by job and timestamp - #820

Open
thomashoneyman wants to merge 1 commit into
masterfrom
perf/job-log-index
Open

thomashoneyman wants to merge 1 commit into
masterfrom
perf/job-log-index

Conversation

@thomashoneyman

@thomashoneyman thomashoneyman commented Nov 10, 2026 •

Copy link
Copy Markdown
Member

I was checking in on the logs and noticed nextui and nextjs publishes were hitting the registry’s ten-minute timeout. This was happening, oddly enough, in dependency installation rather than compilation.

While investigating, I found Node using about a full CPU core on the server. A three-second strace sample showed 45,445 pread64 calls, with sequential reads targeting SQLite; the job-log query took about a second even though it returned at most 100 rows. That is...extremely slow.

The logs table has no secondary indexes, so every poll scanned the table and built a temporary sort. With a 595 MB database and synchronous SQLite queries, polling the job’s progress was itself blocking the server. Pretty bad!

So this change adds an index on logs (jobId, timestamp). SQLite can now seek to one job’s time window and read it in either timestamp order without sorting. The query and API behavior are unchanged. There is a reversible dbmate migration for existing databases and a schema update for fresh ones.

I checked this locally using the actual query function against a file-backed database containing one million synthetic logs across 1,000 jobs. These are median timings from nine warmed calls:

Query Before After
First page, ascending 267.9 ms 0.169 ms
First page, descending 275.4 ms 0.163 ms
Tail poll 272.1 ms 0.058 ms
ERROR-only 269.3 ms 0.404 ms
Empty window 270.2 ms 0.024 ms
Missing job 265.0 ms 0.022 ms

The returned rows all match, and the plans changed from a table scan and temporary sort to a search using idx_logs_job_timestamp. I also checked the same query against a copy of the production database after applying the migration, which took 7.58 seconds. The query went from 1010.6 ms to 2.03 ms, with an identical result hash and no temporary sort. Node CPU dropped from about 100% to 4%, and the running next-ui retry installed its dependencies within a few seconds.

@thomashoneyman

Copy link
Copy Markdown
Member Author

Since this is affecting the actual server I went ahead and applied the migration directly. You can see the job succeeded now in 1.5 mins:
https://www.purescript.org/registry-dev/#/jobs/8c9795ea-57cc-4432-85df-328f262a4021

...where previously it had failed due to being killed in a timeout after 10 minutes:
https://www.purescript.org/registry-dev/#/jobs/2b614e70-b7e0-4e50-befa-11014ed8f37c

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant