From: | Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> |
---|---|
To: | "David G(dot) Johnston" <david(dot)g(dot)johnston(at)gmail(dot)com> |
Cc: | Justin Pryzby <pryzby(at)telsasoft(dot)com>, Lars Bergeson <larsavatar(at)gmail(dot)com>, "pgsql-performance(at)lists(dot)postgresql(dot)org" <pgsql-performance(at)lists(dot)postgresql(dot)org> |
Subject: | Re: Query is slower with a large proportion of NULLs in several columns |
Date: | 2021-12-21 05:33:06 |
Message-ID: | 2707817.1640064786@sss.pgh.pa.us |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-performance |
"David G. Johnston" <david(dot)g(dot)johnston(at)gmail(dot)com> writes:
> On Monday, December 20, 2021, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>> It would help if somebody had labeled the units of I/O Time
>> ... but I'm guessing those are microsec vs. the millisec
>> of the other times, because otherwise it's completely wrong.
> Related to my preceding observation, from the explain (buffers) docs:
> “…and the time spent reading and writing data file blocks (in milliseconds)
> if track_io_timing
> <https://www.postgresql.org/docs/current/runtime-config-statistics.html#GUC-TRACK-IO-TIMING>
> is enabled.“
Hmm ... the code sure looks like it's supposed to be millisec:
appendStringInfoString(es->str, "I/O Timings:");
if (!INSTR_TIME_IS_ZERO(usage->blk_read_time))
appendStringInfo(es->str, " read=%0.3f",
INSTR_TIME_GET_MILLISEC(usage->blk_read_time));
if (!INSTR_TIME_IS_ZERO(usage->blk_write_time))
appendStringInfo(es->str, " write=%0.3f",
INSTR_TIME_GET_MILLISEC(usage->blk_write_time));
And when I try some cases here, I get I/O timing numbers that are
consistent with the overall time reported by EXPLAIN, for example
Seq Scan on foo (cost=0.00..843334.10 rows=11000010 width=508) (actual time=0.
015..1897.492 rows=11000000 loops=1)
Buffers: shared hit=15874 read=717460
I/O Timings: read=1184.638
Planning:
Buffers: shared hit=5 read=2
I/O Timings: read=0.025
Planning Time: 0.229 ms
Execution Time: 2151.529 ms
So now we have a real mystery about what is happening on Lars'
system. Those numbers can't be right.
regards, tom lane
From | Date | Subject | |
---|---|---|---|
Next Message | Yura Sokolov | 2021-12-21 05:45:52 | Re: Lock contention high |
Previous Message | David G. Johnston | 2021-12-21 05:08:59 | Re: Query is slower with a large proportion of NULLs in several columns |