liburing icon indicating copy to clipboard operation
liburing copied to clipboard

Long tail between submit event to complete event exceed 1 second

Open rowe0x opened this issue 1 year ago • 0 comments

When writing to an NVMe device using io_uring with direct I/O, the tail latency for write operations exceeds 1 second.

ftrace output:

Submit Event:           node-22232   [035] .... 202048.601185: io_uring_submit_sqe: ring 000000002037354d, op 1, data 0x539ba2f00, non block 1, sq_thread 0
Complete Line:           <idle>-0       [014] d.h. 202050.561398: io_uring_complete: ring 000000002037354d, user_data 0x539ba2f00, result 262144

os: Linux 5.10.0-1.0.0.18 #1 SMP Thu Sep 15 03:25:02 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

blktrace:

            Q2G           MIN           AVG           MAX           N
--------------- ------------- ------------- ------------- -----------
io_wqe_worker-    0.000000217  44.012678773 496.539182326     3368198
io_wqe_worker-    0.000000227   5.568830759 496.257569655      534006

            Q2M           MIN           AVG           MAX           N
--------------- ------------- ------------- ------------- -----------
io_wqe_worker-    0.000000257 108.131037097 414.067843228         631
io_wqe_worker-    0.000000276   0.000001115   0.000002231         100

            I2D           MIN           AVG           MAX           N
--------------- ------------- ------------- ------------- -----------
io_wqe_worker-    0.000008381   0.000008517   0.000008652           2
io_wqe_worker-    0.000011869   0.000011869   0.000011869           1


            D2C           MIN           AVG           MAX           N
--------------- ------------- ------------- ------------- -----------
basename          0.000016499   0.000222351   0.000806497          35
bash              0.000016709   0.000091219   0.000500335          20
io_wqe_worker-    0.000008298   0.000192700   0.026433714      622315
io_wqe_worker-    0.000010630   0.000208530   0.026662914      253193

            Q2C           MIN           AVG           MAX           N
--------------- ------------- ------------- ------------- -----------
basename          0.000031786   0.000459890   0.002963355          35
bash              0.000041877   0.001323303   0.002954325          20

io_wqe_worker-    0.000010633   0.000396061  28.098251358      622316
io_wqe_worker-    0.000017459   0.000377369  28.532227354      253193

rowe0x avatar Aug 13 '24 06:08 rowe0x