| From: | Dmytro Astapov <dastapov(at)gmail(dot)com> |
|---|---|
| To: | weijie JL <weijie1006jl(at)gmail(dot)com> |
| Cc: | pgsql-bugs(at)lists(dot)postgresql(dot)org |
| Subject: | Re: BUG #19725: PostgreSQL 18.6: pg_restore read failure with io_uring, not observed with worker |
| Date: | 2026-11-03 01:08:59 |
| Message-ID: | CAFQUnFgzDMoPx9NzUSHmKKB2evPYDZBNLYNDSkgBO8MV1Ps3vA@mail.gmail.com |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-bugs |
JFYI, the kernel fix for this was merged into Linux 7.4 this Sat
(2026-10-31), and the fix was included in all stable kernel versions as
well.
Best regards, Dmytro
On Sat, Oct 24, 2026 at 1:07 PM Dmytro Astapov <dastapov(at)gmail(dot)com> wrote:
> Hi,
>
> A follow-up to my earlier message. On further examination, *this is a
> kernel bug, not a Postgres bug*. The changes I suggested for Postgres
> (calling io_uring_register_iowq_max_workers(), or not setting IOSQE_ASYNC)
> would only be workarounds, and my suggestion was therefore wrong.
>
> As a quick recap, Postgres assumes that a buffered read of a regular file,
> submitted with IOSQE_ASYNC, goes to io_uring's bounded worker pool. This
> assumption is valid. That pool is limited to min(SQ ring size, 4 × CPUs),
> which for Postgres is about io_max_concurrency workers per backend. This
> is how io_uring is meant to work: reads and writes of regular files and
> block devices are bounded work.
>
> The kernel instead sends these requests to the unbound pool, whose only
> limit is RLIMIT_NPROC. It decides the pool in io_prep_async_work(), but
> for an IOSQE_ASYNC request the file has not been looked up yet at that
> point (req->file is NULL), so the read is treated as "not a regular
> file". With enough backends and a cold cache, the worker threads use up
> RLIMIT_NPROC. After that, fork() fails and queued reads complete with
> -ECANCELED.
>
> This bug was introduced in Linux 5.18 by commit 6bf9c47a3989 ("io_uring:
> defer file assignment"), which was also marked for 5.15+ stable kernels:
> https://github.com/torvalds/linux/commit/6bf9c47a398911e0ab920e362115153596c80432
>
> A fix was made on 2025-10-15, and is queued for 7.4 in Jens Axboe's tree,
> as commit 98bc044d5a53 ("io_uring: look up the file before queueing to
> io-wq"):
> https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux.git/commit/?id=98bc044d5a5374f8d3605fe55a8e2df6d6fc3f82
>
> It is not (yet?) tagged for stable releases, so older kernels might only
> get it if someone backports it. Until then, io_method = worker is the
> safe choice, as you have already done.
>
> I have a small C program that reproduces the issue (no Postgres needed),
> which could be used to check the if host is susceptible to this problem.
> Let me know if anyone wants it.
>
> Best regards, Dmytro
>
>
> On Fri, Oct 23, 2026 at 8:16 AM weijie JL <weijie1006jl(at)gmail(dot)com> wrote:
>
>> Hi Dmytro,
>>
>> Thanks for reproducing the issue and for the detailed analysis and
>> proposed fixes. This is very helpful.
>>
>> Over the past few days, normal SQL queries in our test environment have
>> also triggered this error. To work around the issue in the current version,
>> I’ve switched all our production environments to the default io_method =
>> worker setting.
>>
>> 2026年10月22日 01:44,Dmytro Astapov <dastapov(at)gmail(dot)com> 写道:
>>
>> Hi!
>>
>> I can reproduce this on version 18.6 + kernel 6.12.109.el8, and I think
>> that I have the explanation for how it happens + proposal for the fix as
>> well.
>>
>> *What I think is happening*: postgres io_uring requests hit the kernel
>> codepath where new io workers are spawned up to RLIMIT_NPRPOC. Once this
>> limit is hit, no new workers can't be spawned, but also postgresmaster
>> can't fork() or system() anymore, leading to "could not read blocks X..Y
>> in file ...: Operation canceled"
>>
>> *How it could be fixed*: postgres should either call
>> io_uring_register_iowq_max_workers, or don't set IOSQE_ASYNC for reads.
>>
>> *Detailed description of the chain of events follows:*
>>
>>
>> *1. Postgres asks io_uring to send buffered reads to worker threads*
>> In method_io_uring.c (line 441), once a backend already has more than 4
>> I/Os in flight, every further buffered read gets IOSQE_ASYNC:
>>
>> if (in_flight_before > 4 && (ioh->flags & PGAIO_HF_BUFFERED))
>> io_uring_sqe_set_flags(sqe, IOSQE_ASYNC);
>>
>> If `maintenance_io_concurrency` is higher that 4, then all of the
>> maintenance reads starting from 5th will take this path.
>>
>>
>> *2. The kernel places these reads into the pool whose only cap is
>> RLIMIT_NPROC*
>> Each task's io_uring worker pool has two halves:
>> - bounded (meant for regular files), capped at min(sq_entries, 4*ncpu);
>> - unbound, capped only at the task's RLIMIT_NPROC (io-wq.c).
>>
>> Requests are classified in io_prep_async_work (
>> https://github.com/torvalds/linux/blob/v6.12/io_uring/io_uring.c#L480-L492
>> ):
>>
>> if (req->file && (req->flags & REQ_F_ISREG)) { ... bound ... }
>> else if (!req->file || !S_ISBLK(...)) {
>> if (def->unbound_nonreg_file) // set for READ/READV
>> atomic_or(IO_WQ_WORK_UNBOUND, ...);
>> }
>>
>> However, io_init_req sets req->file = NULL (at
>> https://github.com/torvalds/linux/blob/v6.12/io_uring/io_uring.c#L2046)
>> and the file is only attached later, at issue time. An IOSQE_ASYNC request
>> goes straight though io_queue_iowq() to io_prep_async_work() while
>> `req->file` is still NULL.
>>
>> So a read of a regular file ends up routed to the unbound pool, whose cap
>> is RLIMIT_NPROC (65536), not a capped one. IOSQE_ASYNC also marks the work
>> as IO_WQ_WORK_CONCURRENT, which lets each enqueue create a worker instead
>> of waiting for a running one.
>>
>> *3. Workers get created far faster than the actual I/O needs*
>>
>> In io_wq_dec_running, when a worker blocks and it was the last running
>> worker while work is still queued, the kernel queues creation of a
>> brand-new worker immediately.
>>
>> It doesn't wake one of the idle workers. On a cold buffer cache almost
>> every read blocks on disk, so this code path fires constantly. As a result,
>> the new worker handles one item and then goes idle. Only the head of the
>> free list gets reused, so the rest of the workers sit idle until
>> WORKER_IDLE_TIMEOUT = 5s expires and then they exit.
>>
>> As a result, the steady-state thread count is therefore roughly "creation
>> rate × 5 s", not "I/Os in flight". The cap for the workers, as was
>> mentioned earlier, is RLIMIT_NPROC.
>>
>> *Similar threads or bugs from the past*
>>
>> - Justin Pryzby on pgsql-hackers
>> <https://www.mail-archive.com/pgsql-hackers(at)lists(dot)postgresql(dot)org/msg208462.html> (2025-10-17)
>> reported could not read blocks 122..126 ...: Operation canceled from
>> pg_dump under io_uring. He guessed it might be related to the
>> io_uring file descriptors leaking after crash-restarts, but I cannot find a
>> resolution.
>> - Alexander Lakhin's AIO stress test
>> <https://www.mail-archive.com/pgsql-hackers(at)lists(dot)postgresql(dot)org/msg196158.html> (pgsql-hackers,
>> April 2025, before 18.0) hit could not read blocks 0..0 in file
>> "global/1213": Operation canceled with parallel createdb/dropdb jobs,
>> on kernels 6.8 and 6.11. The bugs fixed later in that thread (1
>> <https://www.mail-archive.com/pgsql-hackers(at)lists(dot)postgresql(dot)org/msg196804.html>
>> , 2
>> <https://www.mail-archive.com/pgsql-hackers(at)lists(dot)postgresql(dot)org/msg197025.html>)
>> were different ones, a pg_aios crash and a PANIC from interrupt
>> handling. As far as I can see, the ECANCELED was never explained or fixed.
>>
>>
>> io_uring bugs that look relevant to me
>>
>> - liburing #420 <https://github.com/axboe/liburing/issues/420> (2021):
>> a user found IOSQE_ASYNC "spawns a thread for each request, meaning
>> 10000+ threads". There is a commen there that bounded work is limited but
>> unbounded work "really [is] not". That discussion led to creation of
>> IORING_REGISTER_IOWQ_MAX_WORKERS.
>> - liburing #349 <https://github.com/axboe/liburing/issues/349> (2021)
>> reported "unexpected high count of io_worker threads by using the
>> IOSQE_ASYNC flag".
>> - Cloudflare, "Missing Manuals – io_uring worker pool"
>> <https://blog.cloudflare.com/missing-manuals-io_uring-worker-pool/> explains
>> that unbound workers default to RLIMIT_NPROC for each thread, and
>> that raising RLIMIT_NPROC without IORING_REGISTER_IOWQ_MAX_WORKERS can
>> backfire. The io_uring_register_iowq_max_workers(3)
>> <https://man7.org/linux/man-pages/man3/io_uring_register_iowq_max_workers.3.html> man
>> page says the same.
>>
>>
>> So, in conclusion, it looks to me that the issue is that req->file is
>> still NULL when an IOSQE_ASYNC request is classified, and the reads end
>> up in the unbound pool, and the fix is either to call
>> io_uring_register_iowq_max_workers, or don't set IOSQE_ASYNC for reads.
>>
>> Best regards, Dmytro
>>
>>
>> On Sun, Oct 4, 2026 at 10:51 AM weijie JL <weijie1006jl(at)gmail(dot)com> wrote:
>>
>>> After setting backtrace_functions=md_readv_report, I received more log
>>> information:
>>> 2026-10-04 17:46:08.322 CST [local] test001 postgres [154450]LOG:
>>> XX000: could not read blocks 143..158 in file "base/6406098/6407866":
>>> Operation canceled
>>> 2026-10-04 17:46:08.322 CST [local] test001 postgres [154450]LOCATION:
>>> md_readv_report, md.c:2059
>>> 2026-10-04 17:46:08.322 CST [local] test001 postgres [154450]BACKTRACE:
>>> postgres: postgres test001 [local] CREATE INDEX() [0x92eafc]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x92f7ec]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(pgaio_io_call_complete_shared+0xfa) [0x8ef3ea]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x8f209c]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x8f2b63]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x8f0127]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(WaitReadBuffers+0x1f7) [0x8f5137]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(read_stream_next_buffer+0x211) [0x8f6ac1]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x5874d6]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(heap_getnext+0x88) [0x5878e8]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x58dcbd]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x5b11ae]
>>> postgres: postgres test001 [local] CREATE INDEX(btbuild+0xb05)
>>> [0x5b7325]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(index_build+0x19c) [0x61fa2c]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(index_create+0x1328) [0x621608]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(DefineIndex+0x9bb) [0x6d11cb]
>>> postgres: postgres test001 [local] CREATE INDEX() [0xb18111]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(standard_ProcessUtility+0x3f8) [0x93c1d8]
>>> /usr/pgsql-18/lib/pg_stat_statements.so(+0x7375) [0x7f209b366375]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x93cc3a]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x93cdaf]
>>> postgres: postgres test001 [local] CREATE INDEX(PortalRun+0x291)
>>> [0x93d371]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x935ab0]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(PostgresMain+0x1f1b) [0x937f6b]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x9389d5]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(postmaster_child_launch+0x12d) [0x888ced]
>>> postgres: postgres test001 [local] CREATE INDEX() [0x891cb2]
>>> postgres: postgres test001 [local] CREATE
>>> INDEX(PostmasterMain+0xce9) [0x894309]
>>> postgres: postgres test001 [local] CREATE INDEX(main+0x1d0)
>>> [0x531bc0]
>>> /lib64/libc.so.6(+0x2a610) [0x7f209b82a610]
>>> /lib64/libc.so.6(__libc_start_main+0x80) [0x7f209b82a6c0]
>>> postgres: postgres test001 [local] CREATE INDEX(_start+0x25)
>>> [0x5321b5]
>>> 2026-10-04 17:46:08.322 CST [local] test001 postgres [154450]STATEMENT:
>>> CREATE INDEX idx_sys_notification_channel_notification_id ON
>>> dhr.sys_notification_channel USING btree (c_notification_id);
>>>
>>>
>>>
>>>
>>>
>>> > 2026年9月28日 11:34,PG Bug reporting form <noreply(at)postgresql(dot)org> 写道:
>>> >
>>> > The following bug has been logged on the website:
>>> >
>>> > Bug reference: 19725
>>> > Logged by: weijie JL
>>> > Email address: weijie1006jl(at)gmail(dot)com
>>> > PostgreSQL version: 18.6
>>> > Operating system: RockyLinux9
>>> > Description:
>>> >
>>> > Hello,
>>> >
>>> > I can reproduce a read failure during pg_restore with
>>> io_method=io_uring.
>>> > The error disappears with worker and recurs after switching back to
>>> > io_uring.
>>> >
>>> > Environment:
>>> > - PostgreSQL 18.6, x86_64
>>> > - VMware VM: 8 vCPUs, 32 GB RAM
>>> > - Kernel: 5.14.0-611.55.1.el9_7.x86_64
>>> >
>>> > Settings:
>>> > effective_io_concurrency = 256
>>> > maintenance_io_concurrency = 16
>>> > max_parallel_maintenance_workers = 2
>>> >
>>> > Restore command:
>>> > nohup pg_restore -d test001 dhr.dump/ -j8 -v > test.log 2>&1 &
>>> >
>>> > One failing statement:
>>> > ALTER TABLE ONLY dhr.obj_permission_object
>>> > ADD CONSTRAINT obj_permission_object_pkey PRIMARY KEY (id);
>>> >
>>> > Server error:
>>> > ERROR: could not read blocks 143..158 in file "base/1684908/1686127":
>>> > Operation canceled
>>> > LOCATION: md_readv_report, md.c:2059
>>> > SQLSTATE: XX000
>>> >
>>> > Observed test sequence:
>>> > 1. io_method=io_uring: the read error occurred during index creation.
>>> > 2. Changed io_method to worker: retried without errors.
>>> > 3. Changed io_method back to io_uring: the read error was reproduced.
>>> >
>>> > I have not measured the failure rate or prepared a self-contained
>>> > minimal reproducer.
>>> >
>>> > One earlier run also reported "could not map dynamic shared memory
>>> > segment" from parallel workers immediately after the read error.
>>> > Those DSM errors have not recurred in subsequent failing tests.
>>> >
>>> > Does this match a known PostgreSQL bug or kernel-side io_uring issue?
>>> > What additional logs or tracing would help identify the cause?
>>> >
>>> > Thank you.
>>> >
>>> >
>>>
>>>
>>>
>>>
>>
| From | Date | Subject | |
|---|---|---|---|
| Next Message | David Rowley | 2026-11-03 01:14:12 | Re: BUG #19827: postgres_fdw: Assert in add_foreign_ordered_paths() with redundant ORDER BY in set-op input |
| Previous Message | Venu K | 2026-11-02 16:08:46 | Re: BUG #19828: "plan should not reference subplan's variable" with Memoize since f8da64e6 |