| From: | "Peter Geoghegan" <pg(at)bowt(dot)ie> |
|---|---|
| To: | "Peter Geoghegan" <pg(at)bowt(dot)ie>, "Tomas Vondra" <tomas(at)vondra(dot)me>, "Andres Freund" <andres(at)anarazel(dot)de> |
| Cc: | "Thomas Munro" <thomas(dot)munro(at)gmail(dot)com>, "Nazir Bilal Yavuz" <byavuz81(at)gmail(dot)com>, "Robert Haas" <robertmhaas(at)gmail(dot)com>, "Melanie Plageman" <melanieplageman(at)gmail(dot)com>, "PostgreSQL Hackers" <pgsql-hackers(at)lists(dot)postgresql(dot)org>, "Georgios" <gkokolatos(at)protonmail(dot)com>, "Konstantin Knizhnik" <knizhnik(at)garret(dot)ru>, "Dilip Kumar" <dilipbalaut(at)gmail(dot)com> |
| Subject: | Re: index prefetching |
| Date: | 2025-08-14 18:44:44 |
| Message-ID: | DC2DFSYXBDSJ.2N7WXLD4JT05H@bowt.ie |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-hackers |
On Thu Aug 14, 2025 at 1:57 PM EDT, Peter Geoghegan wrote:
> The only interesting thing about the flame graph is just how little
> difference there seems to be (at least for this particular perf event
> type).
I captured method_io_uring.c DEBUG output from running each query in the
server log, in the hope that it would shed some light on what's really going
on here. I think that it just might.
I count a total of 12,401 distinct sleeps for the sequential/slow backwards
scan test case:
$ grep -E "wait_one with [1-9][0-9]* sleeps" sequential.txt | head
2025-08-14 14:35:03.278 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.278 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.278 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.278 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.278 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.278 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.279 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.279 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.279 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
2025-08-14 14:35:03.279 EDT [2516983][client backend] [[unknown]][0/1:0] DEBUG: 00000: wait_one with 1 sleeps
$ grep -E "wait_one with [1-9][0-9]* sleeps" sequential.txt | awk '{ total += $11 } END { print total }'
12401
But there are only 3 such sleeps seen when the random backwards scan query is
run -- which might begin to explain the mystery of why it runs so much faster:
$ grep -E "wait_one with [1-9][0-9]* sleeps" random.txt | awk '{ total += $11 } END { print total }'
104
--
Peter Geoghegan
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Andres Freund | 2025-08-14 18:53:42 | Re: index prefetching |
| Previous Message | Corey Huinker | 2025-08-14 18:34:43 | Re: Import Statistics in postgres_fdw before resorting to sampling. |