Hi,

On 2026-01-26 10:40:52 +0100, Jakub Wartak wrote:

I'm proposing that we add pgstatio_histogram that would track/show I/O
latencies profile, so we could quickly identify I/O outliers.

I think that's an interesting feature!

For measuring particularly stuck things, I've been wondering about having

regular timer that starts to collect more information if stuck in a place

a while. That would probably end up being lower overhead than constantly
measuring... But it would also be a lot more work.

Right now the patch does not include per-backend/PID tracking,

there will be interest in this, I'll add it, but I would like to first

if that's a good idea. The current implementation uses fast bucket
calculation to avoid overheads and tries to cover most useful range of
devices via buckets (128us..256ms, so that covers both NVMe/SSD/HDD and
abnormally high latency too as from time to time I'm try to help with

stuck for seconds, usually a sign of some I/O multipath issues, device
resetting, or hypervisor woes).

Hm. Isn't 128us a pretty high floor for at least reads and writes? On a

NVMe disk you'll get < 10us, after all.

I see a few problems with the source of the latency measurements though:

- The latency gathered is that it's quite heavily affected by scheduler
noise. If your process isn't scheduled because other processes are busy
doing stuff on the CPU, it's quite possible to get results many orders

magnitude wrong.

- With AIO, you're measuring wait time, and that time can be affected by

IOs in the queue. That will often drastically overestimate IO latency
measured this way.

I don't see how we can do better absent cooperation from the kernel (by
putting lower-level measurements into io_uring completions, for example)
though. So maybe this is just how it has to be and we ought to just

it.

dd if=/dev/zero of=/fs bs=1M count=1024
losetup /dev/loop15 /fs
echo "0 $(blockdev --getsz /dev/loop15) delay /dev/loop15 0 2" | \
    dmsetup create delay
mkfs.ext4 /dev/mapper/delay
mount /dev/mapper/delay /mnt

(sic!) with this:
select pg_stat_reset_shared();
pgbench -i -s 10 -p 1234 -h /tmp postgres
checkpoint;

it's not that high, sample of the view

vs eBPF, which does not seem to see that, worst case seem to be like

~20us (gap is between user and kernel)

    [fdatasync] PID 54197  | Kernel: 12943  us | User: 12964  us | Lag: 21us

[..but usually it's just:]

    [    fsync] PID 52266  | Kernel: 1711   us | User: 1714   us | Lag: 3us
    [    fsync] PID 52266  | Kernel: 19913  us | User: 19916  us | Lag: 3us
    [    fsync] PID 52266  | Kernel: 1993   us | User: 1996   us | Lag: 3us
    [    fsync] PID 52266  | Kernel: 1994   us | User: 1995   us | Lag: 1us
    [    fsync] PID 52266  | Kernel: 53734  us | User: 53736  us | Lag: 2us
    [    fsync] PID 52266  | Kernel: 8066   us | User: 8072   us | Lag: 6us
    [    fsync] PID 52266  | Kernel: 2107   us | User: 2109   us | Lag: 2us
    [    fsync] PID 52266  | Kernel: 1972   us | User: 1974   us | Lag: 2us

(this is on 2ms delayed + noatime fs + with CONFIG_HZ=1000 + laptop's

that's idle).

FileClose(), but I haven't witnessed long close(), it's still

in the docs yet, dunno if I should add it there like the next item on the

backend | object | context | iotype | latus | lat_ms | count
----------+----------+-----------+-----------+--------+--------+-------
autovacu | relation | normal | read | 128 | 0.128 | 54

Perhaps the latency should be represented as a range?

substring(backend_type,1,8) as btype,
object, context, io_type, bucket_latency_us as lat_us, bucket_count as

bucket_count > 0

 checkpoi | relation | normal  | write     | [0,9)       |  33
 checkpoi | relation | normal  | write     | [8,17)      |   8
 checkpoi | relation | normal  | write     | [16,33)     |   1

Of course most of the I/O calls today are hitting page cache, so one

expect they'll be < 128us most of the time

Have you measured whether overhead is measurable when hitting the page

I'd hope that it doesn't, due to io combing amortizing the cost somewhat.

it seems worth measuring.

I assume you made pgstatgetioopname() return "hit?" because you don't
expect that to ever be hit?

+static inline int getbucketindex(uint32_t val) {
+#define MINPGSTATIOHIST_LATENCY 127
+ const uint32t maxindex = PGSTATIOHIST_BUCKETS - 1;
+ /*
+ * hopefully calculated to be 25 by the compiler:
+ * clz(127) = clz(01111111b on uint32) = 25
+ */
+ const uint32t minlatencyleadingzeros =
+ pgleadingzerobits32(MINPGSTATIOHISTLATENCY);
+
+ /*
+ * make sure the tmp value at least 127 (our minimum bucket size)
+ * as __builtin_clz might return undefined behavior when

+ */
+ uint32t tmp = val | MINPGSTATIOHISTLATENCY;

+ / count leading zeros /
+ int leadingzeros = pgleadingzerobits32(tmp);
+
+ / normalize the index /
+ uint32t index = minlatencyleadingzeros - leading_zeros;
+
+ / clamp it to the maximum /

+ return (index > maxindex) ? maxindex : index;

+}

Wouldn't it be easier to handle the minimum latency by shifting right?

I think we may also need to handle inputs that don't fit a uint32.

[..] For things
like a stopped VM or such we could see IOs that that don't fit into a

when measured in microseconds. So perhaps I'd make the input to the

calc 64 bits, then shift to the minimum precision and mask to implement
clamping.

@@ -152,6 +189,10 @@ pgstatcountiooptime(IOObject io_object,

io_time);

+ / calculate the bucket_index based on latency in us /
+ bucket_index =

+

+
/ Add the per-backend count /
pgstatcountbackendiooptime(ioobject, io_context,

It's annoying to have to convert to microseconds here, that's not free :(.

+ HISTIOCOL_COUNT,
+ HISTIOCOLRESETTIME,
+ HISTIONUM_COLUMNS
+} historygethistory_state;

think this should be introduced in the middle of the pgstatio

+/*
+ * pgleadingzero_bits32
+ * Returns the number of leading 0-bits in x, starting at

+ * Word must not be 0 (as it is undefined behavior).
+ */
+static inline int
+pgleadingzero_bits32(uint32 word)

Do we really need this in addition to the already existing
pgleftmostone_pos32()? Particularly because that already has an msvc
implementation...