From: Tom Lane <tgl@sss.pgh.pa.us>
To: David G. Johnston <david.g.johnston@gmail.com>
Cc: Justin Pryzby <pryzby@telsasoft.com>
Cc: Lars Bergeson <larsavatar@gmail.com>
Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
Subject: Re: Query is slower with a large proportion of NULLs in several columns
Date: Tue, 21 Dec 2021 00:33:06 -0500
Message-ID: <2707817.1640064786@sss.pgh.pa.us> (raw)
In-Reply-To: <CAKFQuwZ==D+f656wsZcctpChQ2xWx5t2fjEhr8+VQWCSCWaWgQ@mail.gmail.com>
References: <CAK66RGYim22Sd8-NvmufcxEQ_P99=UTAyJ9agnwDyEbCiVGEQg@mail.gmail.com>
<2688019.1640051519@sss.pgh.pa.us>
<CAK66RGbd8n46xEp3fTKOa3pO3eC=NT8tEHHZYjuNZq4Y0SQHTw@mail.gmail.com>
<20211221045138.GZ17618@telsasoft.com>
<2704544.1640062888@sss.pgh.pa.us>
<CAKFQuwZ==D+f656wsZcctpChQ2xWx5t2fjEhr8+VQWCSCWaWgQ@mail.gmail.com>
"David G. Johnston" <david.g.johnston@gmail.com> writes:
> On Monday, December 20, 2021, Tom Lane <tgl@sss.pgh.pa.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
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-performance@postgresql.org
Cc: tgl@sss.pgh.pa.us, david.g.johnston@gmail.com, pryzby@telsasoft.com, larsavatar@gmail.com, pgsql-performance@lists.postgresql.org
Subject: Re: Query is slower with a large proportion of NULLs in several columns
In-Reply-To: <2707817.1640064786@sss.pgh.pa.us>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox