Open jfly opened 2 months ago
That query finally finished, and sqlx logged a slow query warning:
$ journalctl -u pr-tracker-fetcher
...
Apr 21 10:37:16 clark pr-tracker-fetcher-start[3570307]: [2024-04-21T17:37:15Z WARN sqlx::query] slow statement: execution time exceeded alert threshold summary="INSERT INTO landings(github_pr, branch_id) …" db.statement="\n\nINSERT INTO\n landin
gs(github_pr, branch_id)\nVALUES\n
[... ~2.8 mb of text ...]
ON CONFLICT (github_pr, branch_id) DO NOTHING\n" rows_affected=0 rows_returned=0 elapsed=1.937380964s slow_threshold=1s
So I guess that means that postgresql was able to chug through the ~8mb query in a bit under 2 seconds, but I also know that from postgresql's perspective, this query started quite some time ago (see above):
query_start | 2024-04-21 16:26:20.188579+00
So from postgresql's perspective, that query took over 1 hour:
$ nix-shell -p 'python3.withPackages (ps: with ps; [ dateutil ])' --run python
>>> import datetime as dt; from dateutil.parser import parse
>>> (parse("2024-04-21T17:37:15Z") - parse("2024-04-21 16:26:20.188579+00")).total_seconds()/3600
1.181892061388889
Ever since upgrading to v3.0.0, I've been seeing pr-tracker-fetcher take a really long time to insert landings. For example, here's some info about a current run:
You can see that this query started over 30 minutes ago!
The rust process seems to be pegging a core, while the postgres process is doing nothing:
I think psql is just waiting on a socket:
And some gdb information on the rust process. It seems to be in the middle of doing some string formatting in the guts of sqlx:
I believe we're stuck here: https://github.com/molybdenumsoftware/pr-tracker/blob/v3.0.0/crates/store/src/lib.rs#L468
Theory: under the hood, sqlx "streams" its output to postgresql, which is why we see the query over in postgresql, but it's still streaming the query, so postgresql has nothing to do.