| From: | "Si, Evan" <evsi(at)amazon(dot)com> |
|---|---|
| To: | surya poondla <suryapoondla4(at)gmail(dot)com>, "pgsql-bugs(at)lists(dot)postgresql(dot)org" <pgsql-bugs(at)lists(dot)postgresql(dot)org> |
| Subject: | Re: BUG #19369: Not documented that io_uring on kernel versions between 5.1 and below 5.6 does not work |
| Date: | 2026-01-12 21:16:48 |
| Message-ID: | A0384D56-5A3B-404C-92D6-DB76AF1483E5@amazon.com |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-bugs |
Hi Surya,
Sure, thanks for the interest. Mainly I think it’d be nice to for the engine to behave similarly as it does pre-5.1 and point out that the kernel version is too old. Or at least for the README to reflect the minimum kernel version (5.6) accurately.
Evan
From: surya poondla <suryapoondla4(at)gmail(dot)com>
Date: Wednesday, January 7, 2026 at 10:53 PM
To: "Si, Evan" <evsi(at)amazon(dot)com>, "pgsql-bugs(at)lists(dot)postgresql(dot)org" <pgsql-bugs(at)lists(dot)postgresql(dot)org>
Subject: RE: [EXTERNAL] BUG #19369: Not documented that io_uring on kernel versions between 5.1 and below 5.6 does not work
CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you can confirm the sender and know the content is safe.
Hi Evan,
In my previous email/findings, I didn't compile postgres with the liburing option.
I did it this time and see the same symptoms as you saw.
surya(at)surya:~/pgdata18$ uname -r
5.4.0-216-generic
surya(at)surya:~/pgdata18$ uname -a
Linux surya 5.4.0-216-generic #236-Ubuntu SMP Fri Apr 11 19:55:34 UTC 2025 aarch64 aarch64 aarch64 GNU/Linux
surya(at)surya:~/pgdata18$
surya(at)surya:~/pgdata18$ ~/pg18/bin/pg_ctl -D ~/pgdata18 restart
waiting for server to shut down.... done
server stopped
waiting for server to start....2026-01-08 06:20:36.301 UTC [17042] LOG: redirecting log output to logging collector process
2026-01-08 06:20:36.301 UTC [17042] HINT: Future log output will appear in directory "log".
done
server started
surya(at)surya:~/pgdata18$ ls log/
postgresql-2026-01-08_061910.log postgresql-2026-01-08_062036.log
postgresql-2026-01-08_061955.log
surya(at)surya:~/pgdata18$ ~/pg18/bin/psql -d postgres
psql: error: connection to server on socket "/tmp/.s.PGSQL.5432" failed: FATAL: could not read blocks 0..0 in file "global/1260": Invalid argument
In the logs, I see
026-01-08 06:24:29.858 UTC [17126] DEBUG: InitPostgres
2026-01-08 06:24:29.858 UTC [17127] DEBUG: logical replication launcher started
2026-01-08 06:24:29.858 UTC [17127] DEBUG: InitPostgres
2026-01-08 06:24:29.858 UTC [17126] DEBUG: io 6400 |op invalid|target invalid|state HANDED_OUT : adding cb #1, id 2/aio_shared_buffer_readv_cb
2026-01-08 06:24:29.858 UTC [17126] DEBUG: io 6400 |op invalid|target smgr|state HANDED_OUT : adding cb #2, id 1/aio_md_readv_cb
2026-01-08 06:24:29.858 UTC [17126] DEBUG: io 6400 |op readv|target smgr|state DEFINED : calling cb #1 2/aio_shared_buffer_readv_cb->stage(0)
2026-01-08 06:24:29.859 UTC [17126] DEBUG: io 6400 |op readv|target smgr|state STAGED : staged (synchronous: 0, in_batch: 1)
2026-01-08 06:24:29.859 UTC [17126] DEBUG: io 6400 |op readv|target smgr|state SUBMITTED : wait_one io_gen: 1, ref_gen: 1, cycle 0
2026-01-08 06:24:29.859 UTC [17126] LOG: could not read blocks 0..0 in file "global/1262": Invalid argument
2026-01-08 06:24:29.859 UTC [17126] DEBUG: io 6400 |op readv|target smgr|state COMPLETED_IO : after shared completion: distilled result: (status ERROR, id 1, error_data: 22, result 0), raw_result: -22
2026-01-08 06:24:29.859 UTC [17126] DEBUG: io 6400 |op readv|target smgr|state COMPLETED_SHARED: after local completion: result: (status ERROR, id 1, error_data 22, result 0), raw_result: -22
2026-01-08 06:24:29.859 UTC [17126] DEBUG: drained 1/1, now expecting 0
2026-01-08 06:24:29.859 UTC [17126] DEBUG: io 6400 |op invalid|target invalid|state IDLE : wait_one io_gen: 2, ref_gen: 1, cycle 0
2026-01-08 06:24:29.859 UTC [17126] DEBUG: wait_one with 0 sleeps
2026-01-08 06:24:29.859 UTC [17126] ERROR: could not read blocks 0..0 in file "global/1262": Invalid argument
2026-01-08 06:24:30.859 UTC [17126] DEBUG: io 6400 |op invalid|target invalid|state HANDED_OUT : adding cb #1, id 2/aio_shared_buffer_readv_cbhe logs
I will do some more testing on this and update my findings.
-Surya Poondla
On Wed, Jan 7, 2026 at 8:15 PM surya poondla <suryapoondla4(at)gmail(dot)com<mailto:suryapoondla4(at)gmail(dot)com>> wrote:
Hi Evsi,
I created a new Ubuntu server and am able to reproduce the same behavior you reported for Postgres 18.1 on aarch64 architecture.
surya(at)surya:~/pgdata18/log$ uname -r
5.4.0-216-generic
surya(at)surya:~/pgdata18/log$ uname -a
Linux surya 5.4.0-216-generic #236-Ubuntu SMP Fri Apr 11 19:55:34 UTC 2025 aarch64 aarch64 aarch64 GNU/Linux
I did some testing and see the below
In the postgresql.conf if I put
io_method = 'worker' or io_method = 'sync', postgres is able to restart with no errors.
But if io_method = 'io_uring' then I see the below on my console
surya(at)surya:~/postgresql-18.1$ vim ~/pgdata18/postgresql.conf
surya(at)surya:~/postgresql-18.1$ ~/pg18/bin/pg_ctl -D ~/pgdata18 restart
waiting for server to shut down....2026-01-08 04:06:07.081 UTC [44973] DEBUG: logger shutting down
2026-01-08 04:06:07.081 UTC [44973] DEBUG: shmem_exit(0): 0 before_shmem_exit callbacks to make
2026-01-08 04:06:07.081 UTC [44973] DEBUG: shmem_exit(0): 0 on_shmem_exit callbacks to make
2026-01-08 04:06:07.081 UTC [44973] DEBUG: proc_exit(0): 0 callbacks to make
2026-01-08 04:06:07.081 UTC [44973] DEBUG: exit(0)
2026-01-08 04:06:07.081 UTC [44973] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2026-01-08 04:06:07.081 UTC [44973] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2026-01-08 04:06:07.081 UTC [44973] DEBUG: proc_exit(-1): 0 callbacks to make
done
server stopped
waiting for server to start....2026-01-08 04:06:07.172 GMT [44988] LOG: invalid value for parameter "io_method": "io_uring"
2026-01-08 04:06:07.172 GMT [44988] HINT: Available values: sync, worker.
2026-01-08 04:06:07.172 UTC [44988] FATAL: configuration file "/home/surya/pgdata18/postgresql.conf" contains errors
2026-01-08 04:06:07.172 UTC [44988] DEBUG: shmem_exit(1): 0 before_shmem_exit callbacks to make
2026-01-08 04:06:07.172 UTC [44988] DEBUG: shmem_exit(1): 0 on_shmem_exit callbacks to make
2026-01-08 04:06:07.172 UTC [44988] DEBUG: proc_exit(1): 0 callbacks to make
2026-01-08 04:06:07.172 UTC [44988] DEBUG: exit(1)
stopped waiting
pg_ctl: could not start server
Examine the log output.
From the above we can see that the stderr says that "invalid value for parameter "io_method": "io_uring""
And in the logs I see similar thing like you reported
2026-01-08 04:05:31.438 UTC [44972] DEBUG: starting background worker process "logical replication launcher"
2026-01-08 04:05:31.438 UTC [44981] DEBUG: autovacuum launcher started
2026-01-08 04:05:31.438 UTC [44981] DEBUG: InitPostgres
2026-01-08 04:05:31.438 UTC [44982] DEBUG: logical replication launcher started
2026-01-08 04:05:31.438 UTC [44982] DEBUG: InitPostgres
2026-01-08 04:05:31.438 UTC [44981] DEBUG: io 6400 |op invalid|target invalid|state HANDED_OUT : adding cb #1, id 2/aio_shared_buffer_readv_cb
2026-01-08 04:05:31.438 UTC [44981] DEBUG: io 6400 |op invalid|target smgr|state HANDED_OUT : adding cb #2, id 1/aio_md_readv_cb
2026-01-08 04:05:31.438 UTC [44981] DEBUG: io 6400 |op readv|target smgr|state DEFINED : calling cb #1 2/aio_shared_buffer_readv_cb->stage(0)
2026-01-08 04:05:31.438 UTC [44981] DEBUG: io 6400 |op readv|target smgr|state STAGED : staged (synchronous: 0, in_batch: 1)
2026-01-08 04:05:31.439 UTC [44974] DEBUG: io 6400 |op readv|target smgr|state COMPLETED_IO : after shared completion: distilled result: (status OK, id 0, error_data: 0, result 1), raw_result: 8192
2026-01-08 04:05:31.439 UTC [44981] DEBUG: io 6400 |op readv|target smgr|state COMPLETED_SHARED: after local completion: result: (status OK, id 0, error_data 0, result 1), raw_result: 8192
I am working on a patch and will fix the inconsistencies in documentation about io_uring.
Best,
Surya Poondla
On Wed, Jan 7, 2026 at 7:54 PM PG Bug reporting form <noreply(at)postgresql(dot)org<mailto:noreply(at)postgresql(dot)org>> wrote:
The following bug has been logged on the website:
Bug reference: 19369
Logged by: Evan Si
Email address: evsi(at)amazon(dot)com<mailto:evsi(at)amazon(dot)com>
PostgreSQL version: 18.1
Operating system: Amazon Linux 2
Description:
Hello,
The documentation doesn't explicitly state a minimum kernel version for
io_uring, but in src/backend/storage/aio/README.md, it claims that:
> io_method=io_uring is available on Linux 5.1+.
Attempting to set io_method to io_uring on versions without io_uring at all
(below 5.1) causes the server to graciously report that "[the k]ernel does
not support io_uring".
But setting io_uring on kernel versions between 5.1 and 5.6 sees the server
start but connections failing with EINVAL.
```
[ec2-user(at)ip-172-31-56-49 postgres]$ psql postgres
psql: error: connection to server on socket "/tmp/.s.PGSQL.5432" failed:
FATAL: could not read blocks 0..0 in file "global/1260": Invalid argument
```
It seems like the implementation in postgres leverages non-vectored I/O
(i.e. io_uring_prep_read and io_uring_prep_write) in
src/backend/storage/aio/method_io_uring.c.
But, these opcodes aren't actually available until kernel 5.6
(https://github.com/axboe/liburing/issues/44)
(https://man7.org/linux/man-pages/man2/io_uring_enter.2.html - under
IORING_OP_READ, IORING_OP_WRITE).
It seems kernel 5.4 LTS ended last month, but this seems worth clarifying, I
think.
--
Precise reproduction example:
OS details
```
[ec2-user(at)ip-172-31-56-49 postgres]$ uname -a
Linux ip-172-31-56-49.us-west-2.compute.internal
5.4.301-221.450.amzn2.x86_64 #1 SMP Tue Nov 18 16:40:04 UTC 2025 x86_64
x86_64 x86_64 GNU/Linux
```
Build postgres with liburing 2.8, set postgresql.conf with
io_method=io_uring, log_min_messages = debug3.
Postgres starts without complaint, but trying to connect will fail:
```
[ec2-user(at)ip-172-31-56-49 postgres]$ psql postgres
psql: error: connection to server on socket "/tmp/.s.PGSQL.5432" failed:
FATAL: could not read blocks 0..0 in file "global/1260": Invalid argument
```
Inside logfile:
```
2026-01-02 22:35:43.862 UTC [8517] DEBUG: io 6400 |op invalid|target
invalid|state HANDED_OUT : adding cb #1, id
2/aio_shared_buffer_readv_cb
2026-01-02 22:35:43.862 UTC [8517] DEBUG: io 6400 |op invalid|target
smgr|state HANDED_OUT : adding cb #2, id 1/aio_md_readv_cb
2026-01-02 22:35:43.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state DEFINED : calling cb #1
2/aio_shared_buffer_readv_cb->stage(0)
2026-01-02 22:35:43.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state STAGED : staged (synchronous: 0, in_batch: 1)
2026-01-02 22:35:43.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state SUBMITTED : wait_one io_gen: 3, ref_gen: 3, cycle 0
2026-01-02 22:35:43.863 UTC [8517] LOG: could not read blocks 0..0 in file
"global/1262": Invalid argument
2026-01-02 22:35:43.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state COMPLETED_IO : after shared completion: distilled result:
(status ERROR, id 1, error_data: 22, result 0), raw_result: -22
2026-01-02 22:35:43.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state COMPLETED_SHARED: after local completion: result: (status ERROR,
id 1, error_data 22, result 0), raw_result: -22
2026-01-02 22:35:43.863 UTC [8517] DEBUG: drained 1/1, now expecting 0
2026-01-02 22:35:43.863 UTC [8517] DEBUG: io 6400 |op invalid|target
invalid|state IDLE : wait_one io_gen: 4, ref_gen: 3, cycle 0
2026-01-02 22:35:43.863 UTC [8517] DEBUG: wait_one with 0 sleeps
2026-01-02 22:35:43.863 UTC [8517] ERROR: could not read blocks 0..0 in
file "global/1262": Invalid argument
2026-01-02 22:35:44.057 UTC [8512] DEBUG: assigned pm child slot 1 for
backend
2026-01-02 22:35:44.058 UTC [8512] DEBUG: forked new client backend,
pid=8521 socket=151
2026-01-02 22:35:44.058 UTC [8521] DEBUG: InitPostgres
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op invalid|target
invalid|state HANDED_OUT : adding cb #1, id
2/aio_shared_buffer_readv_cb
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op invalid|target
smgr|state HANDED_OUT : adding cb #2, id 1/aio_md_readv_cb
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op readv|target
smgr|state DEFINED : calling cb #1
2/aio_shared_buffer_readv_cb->stage(0)
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op readv|target
smgr|state STAGED : staged (synchronous: 0, in_batch: 1)
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op readv|target
smgr|state SUBMITTED : wait_one io_gen: 1, ref_gen: 1, cycle 0
2026-01-02 22:35:44.059 UTC [8521] LOG: could not read blocks 0..0 in file
"global/1260": Invalid argument
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op readv|target
smgr|state COMPLETED_IO : after shared completion: distilled result:
(status ERROR, id 1, error_data: 22, result 0), raw_result: -22
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op readv|target
smgr|state COMPLETED_SHARED: after local completion: result: (status ERROR,
id 1, error_data 22, result 0), raw_result: -22
2026-01-02 22:35:44.059 UTC [8521] DEBUG: drained 1/1, now expecting 0
2026-01-02 22:35:44.059 UTC [8521] DEBUG: io 0 |op invalid|target
invalid|state IDLE : wait_one io_gen: 2, ref_gen: 1, cycle 0
2026-01-02 22:35:44.059 UTC [8521] DEBUG: wait_one with 0 sleeps
2026-01-02 22:35:44.059 UTC [8521] FATAL: could not read blocks 0..0 in
file "global/1260": Invalid argument
2026-01-02 22:35:44.059 UTC [8521] DEBUG: shmem_exit(1): 5
before_shmem_exit callbacks to make
2026-01-02 22:35:44.059 UTC [8521] DEBUG: shmem_exit(1): 7 on_shmem_exit
callbacks to make
2026-01-02 22:35:44.059 UTC [8521] DEBUG: proc_exit(1): 2 callbacks to make
2026-01-02 22:35:44.059 UTC [8521] DEBUG: exit(1)
2026-01-02 22:35:44.059 UTC [8521] DEBUG: shmem_exit(-1): 0
before_shmem_exit callbacks to make
2026-01-02 22:35:44.059 UTC [8521] DEBUG: shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2026-01-02 22:35:44.059 UTC [8521] DEBUG: proc_exit(-1): 0 callbacks to
make
2026-01-02 22:35:44.060 UTC [8512] DEBUG: releasing pm child slot 1
2026-01-02 22:35:44.060 UTC [8512] DEBUG: client backend (PID 8521) exited
with exit code 1
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op invalid|target
invalid|state HANDED_OUT : adding cb #1, id
2/aio_shared_buffer_readv_cb
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op invalid|target
smgr|state HANDED_OUT : adding cb #2, id 1/aio_md_readv_cb
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state DEFINED : calling cb #1
2/aio_shared_buffer_readv_cb->stage(0)
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state STAGED : staged (synchronous: 0, in_batch: 1)
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state SUBMITTED : wait_one io_gen: 4, ref_gen: 4, cycle 0
2026-01-02 22:35:44.863 UTC [8517] LOG: could not read blocks 0..0 in file
"global/1262": Invalid argument
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state COMPLETED_IO : after shared completion: distilled result:
(status ERROR, id 1, error_data: 22, result 0), raw_result: -22
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op readv|target
smgr|state COMPLETED_SHARED: after local completion: result: (status ERROR,
id 1, error_data 22, result 0), raw_result: -22
2026-01-02 22:35:44.863 UTC [8517] DEBUG: drained 1/1, now expecting 0
2026-01-02 22:35:44.863 UTC [8517] DEBUG: io 6400 |op invalid|target
invalid|state IDLE : wait_one io_gen: 5, ref_gen: 4, cycle 0
2026-01-02 22:35:44.863 UTC [8517] DEBUG: wait_one with 0 sleeps
2026-01-02 22:35:44.863 UTC [8517] ERROR: could not read blocks 0..0 in
file "global/1262": Invalid argument
```
| From | Date | Subject | |
|---|---|---|---|
| Next Message | PG Bug reporting form | 2026-01-13 06:15:10 | BUG #19377: Query planner interesting behaviour |
| Previous Message | Tom Lane | 2026-01-12 19:29:32 | Re: Inconsistent handling of signed zero (-0) between INNER JOIN and INTERSECT ALL |