Re: pg19b1: TRAP: failed Assert("pgstat_bktype_io_stats_valid(bktype_shstats, MyBackendType)")

Still reproduced on the master branch.

A bit more on what the proposed fix changes.

```
diff --git a/src/backend/storage/buffer/bufmgr.c
b/src/backend/storage/buffer/bufmgr.c
index 3908529872a..e2f209b8ec7 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -1831,9 +1831,12 @@ WaitReadBuffers(ReadBuffersOperation *operation)
/*
* The IO operation itself was already counted earlier, in
* AsyncReadBuffers(), this just accounts for the wait time.
+ * For foreign IO, the read was counted by another backend,
+ * so skip reporting wait time here.
*/
- pgstat_count_io_op_time(io_object, io_context, IOOP_READ,
- io_start, 0, 0);
+ if (!operation->foreign_io)
+ pgstat_count_io_op_time(io_object, io_context, IOOP_READ,
+ io_start, 0, 0);
}
else
{
```

With track_io_timing=on, foreign IO wait time is currently recorded: when
WaitReadBuffers() waits on foreign_io, it calls pgstat_count_io_op_time()
with cnt=0. So we do write non-zero IOOP_READ time into this backend's
pending pg_stat_io stats, without incrementing the read count in this
backend.

Thus, this fix introduces a real change: it disables recording foreign IO
wait time in pg_stat_io statistics for the backend that is performing the
wait.

What we lose is only that wait time. The initiating backend still records
the read count and its own IO time, and the waiting backend still records a
buffer hit once the IO completes.

The current behavior is also not a reliable metric: the wait time is merged
into the shared per-BackendType pg_stat_io bucket (B_BG_WORKER for parallel
workers), and only remains valid if the initiating backend has already
flushed its read count. Otherwise, pgstat_bktype_io_stats_valid() trips on
backend exit — which is the bug we're seeing.

So the fix trades a partial and crash-prone statistic for correctness. A
fuller solution would need separate support for accumulated wait time, as
already noted in a comment near AsyncReadBuffers().

A more complete solution could introduce a dedicated IOOP_WAIT operation
type:

```
if (operation->foreign_io)
pgstat_count_io_op_time(io_object, io_context, IOOP_WAIT, io_start, 1,
0);
else
pgstat_count_io_op_time(io_object, io_context, IOOP_READ, io_start, 0,
0);
```

This would properly account for foreign wait time without breaking stats
consistency, but would require extending pg_stat_io to support a new
operation type. The current fix takes a simpler approach: it drops the
foreign wait time entirely, accepting the loss of this metric in exchange
for stability.

---
Regards,
Rachitskiy Andrey

ср, 8 июл. 2026 г. в 20:26, Andrey Rachitskiy <pl0h0yp1(at)gmail(dot)com>:

> I think the assert in pgstat_io_flush_cb() after 999dec9ec6a comes from IO
> stats on the foreign IO path.
> When AsyncReadBuffers() finds IO already in progress, it sets foreign_io
> and returns without counting a read. But WaitReadBuffers() still calls:
> ```
> pgstat_count_io_op_time(..., IOOP_READ, io_start, 0, 0);
> ```
> The comment there assumes the read was already counted in
> AsyncReadBuffers(). That holds for IO we started ourselves, but not when
> we're waiting on another backend's IO. With track_io_timing = on, we get
> non-zero IOOP_READ time and zero count, and pgstat_bktype_io_stats_valid()
> trips on backend exit.
>
> fix proposal:
> ```
> - pgstat_count_io_op_time(io_object,
> io_context, IOOP_READ,
> -
> io_start, 0, 0);
> + if (!operation->foreign_io)
> + pgstat_count_io_op_time(io_object,
> io_context, IOOP_READ,
> +
> io_start, 0, 0);
> ```
>
> ср, 8 июл. 2026 г. в 19:58, Justin Pryzby <pryzby(at)telsasoft(dot)com>:
>
>> While restoring from backup to v19, I hit a crash adding a unique
>> constraint, since 999dec9ec6a "aio: Don't wait for already in-progress
>> IO."
>>
>> The crash is not consistent, and I don't have an easy reproducer, but I
>> can tell you that the crash involves the counts<=0 case, with
>> IOOBJECT_RELATION / IOCONTEXT_NORMAL / IOOP_READ, and depends on
>> maintenance_work_mem=512MB and track_io_timing=1, and always seems to
>> happens in a parallel worker.
>>
>> LOG: background worker "parallel worker" (PID 1475078) was terminated by
>> signal 6: Aborted
>> DETAIL: Failed process was running: ALTER TABLE ONLY
>> public.counter_latest_data
>> ADD CONSTRAINT counter_latest_data_counter_id_site_id_key
>> UNIQUE (counter_id, site_id);
>> ALTER TABLE public.counter_latest_data CLUSTER ON
>> counter_latest_data_counter_id_site_id_key;
>>
>> (gdb) bt
>> #0 __pthread_kill_implementation (threadid=<optimized out>,
>> signo=signo(at)entry=6, no_tid=no_tid(at)entry=0) at ./nptl/pthread_kill.c:44
>> #1 0x00007f28d65d49ff in __pthread_kill_internal (threadid=<optimized
>> out>, signo=6) at ./nptl/pthread_kill.c:89
>> #2 0x00007f28d657fcc2 in __GI_raise (sig=sig(at)entry=6) at
>> ../sysdeps/posix/raise.c:26
>> #3 0x00007f28d65684ac in __GI_abort () at ./stdlib/abort.c:73
>> #4 0x00005596eca9bec6 in ExceptionalCondition
>> (conditionName=conditionName(at)entry=0x5596ecc47230
>> "pgstat_bktype_io_stats_valid(bktype_shstats, MyBackendType)",
>> fileName=fileName(at)entry=0x5596ecc471d8
>> "../postgresql/src/backend/utils/activity/pgstat_io.c",
>> lineNumber=lineNumber(at)entry=228) at
>> ../postgresql/src/backend/utils/error/assert.c:65
>> #5 0x00005596ec979b6d in pgstat_io_flush_cb (nowait=<optimized out>) at
>> ../postgresql/src/backend/utils/activity/pgstat_io.c:228
>> #6 0x00005596ec9758ba in pgstat_report_stat (force=force(at)entry=true) at
>> ../postgresql/src/backend/utils/activity/pgstat.c:810
>> #7 0x00005596ec975a9c in pgstat_shutdown_hook (code=<optimized out>,
>> arg=<optimized out>) at
>> ../postgresql/src/backend/utils/activity/pgstat.c:646
>> #8 0x00005596ec92e901 in shmem_exit (code=code(at)entry=0) at
>> ../postgresql/src/backend/storage/ipc/ipc.c:250
>> #9 0x00005596ec92ea74 in proc_exit_prepare (code=code(at)entry=0) at
>> ../postgresql/src/backend/storage/ipc/ipc.c:199
>> #10 0x00005596ec92eb2e in proc_exit (code=code(at)entry=0) at
>> ../postgresql/src/backend/storage/ipc/ipc.c:112
>> #11 0x00005596ec89f2f0 in BackgroundWorkerMain (startup_data=<optimized
>> out>, startup_data_len=<optimized out>) at
>> ../postgresql/src/backend/postmaster/bgworker.c:853
>> #12 0x00005596ec8a1a4d in postmaster_child_launch
>> (child_type=child_type(at)entry=B_BG_WORKER, child_slot=239,
>> startup_data=startup_data(at)entry=0x55972a7244d8,
>> startup_data_len=startup_data_len(at)entry=1472,
>> client_sock=client_sock(at)entry=0x0) at
>> ../postgresql/src/backend/postmaster/launch_backend.c:263
>> #13 0x00005596ec8a34bd in StartBackgroundWorker (rw=0x55972a7244d8) at
>> ../postgresql/src/backend/postmaster/postmaster.c:4176
>> #14 maybe_start_bgworkers () at
>> ../postgresql/src/backend/postmaster/postmaster.c:4341
>> #15 0x00005596ec8a4e05 in LaunchMissingBackgroundProcesses () at
>> ../postgresql/src/backend/postmaster/postmaster.c:3416
>> #16 ServerLoop () at
>> ../postgresql/src/backend/postmaster/postmaster.c:1728
>> #17 0x00005596ec8a7257 in PostmasterMain (argc=argc(at)entry=12,
>> argv=argv(at)entry=0x55972a6a0ec0) at
>> ../postgresql/src/backend/postmaster/postmaster.c:1403
>> #18 0x00005596ec5cbd1c in main (argc=12, argv=0x55972a6a0ec0) at
>> ../postgresql/src/backend/main/main.c:231
>>
>> --
>> Justin
>>
>>
>>