io-uring stressor from ubuntu_stress_smoke_test hangs on AWS instances
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
ubuntu-kernel-tests |
Fix Released
|
Undecided
|
Unassigned |
Bug Description
io-uring stressor will hang with the latest stress-ng. This issue can only be found on AWS c3.xlarge, c4.large instances, with Ubuntu Jammy / Mantic / Noble kernels.
Test output with J-5.15.0-112:
$ sudo ./stress-ng -v -t 5 --io-uring 4 --io-uring-ops 3000 --ignite-cpu --syslog --verbose --verify --oomable
stress-ng: debug: [1282] invoked with './stress-ng -v -t 5 --io-uring 4 --io-uring-ops 3000 --ignite-cpu --syslog --verbose --verify --oomable' by user 0 'root'
stress-ng: debug: [1282] stress-ng 0.18.00 g5be042abcc7b
stress-ng: debug: [1282] system: Linux ip-172-31-41-225 5.15.0-112-generic #122-Ubuntu SMP Thu May 23 07:48:21 UTC 2024 x86_64, gcc 11.4.0, glibc 2.35, little endian
stress-ng: debug: [1282] RAM total: 3.6G, RAM free: 3.2G, swap free: 0.0
stress-ng: debug: [1282] temporary file path: '/home/
stress-ng: debug: [1282] CPUs have 2 idle states: C1, POLL
stress-ng: debug: [1282] 2 processors online, 2 processors configured
stress-ng: info: [1282] setting to a 5 secs run per stressor
stress-ng: debug: [1282] CPU data cache: L1: 32K, L2: 256K, L3: 25600K
stress-ng: debug: [1282] cache allocate: shared cache buffer size: 25600K
stress-ng: info: [1282] dispatching hogs: 4 io-uring
stress-ng: debug: [1282] starting stressors
stress-ng: debug: [1283] io-uring: [1283] started (instance 0 on CPU 1)
stress-ng: debug: [1282] 4 stressors started
stress-ng: debug: [1285] io-uring: [1285] started (instance 2 on CPU 0)
stress-ng: debug: [1286] io-uring: [1286] started (instance 3 on CPU 1)
stress-ng: debug: [1284] io-uring: [1284] started (instance 1 on CPU 0)
stress-ng: warn: [1283] cannot terminate process 1287, gave up after 120 seconds
stress-ng: warn: [1284] cannot terminate process 1290, gave up after 120 seconds
stress-ng: debug: [1284] io-uring: [1284] exited (instance 1 on CPU 0)
stress-ng: warn: [1286] cannot terminate process 1289, gave up after 120 seconds
stress-ng: debug: [1286] io-uring: [1286] exited (instance 3 on CPU 0)
stress-ng: warn: [1285] cannot terminate process 1288, gave up after 120 seconds
stress-ng: debug: [1285] io-uring: [1285] exited (instance 2 on CPU 0)
stress-ng: debug: [1283] io-uring: [1283] exited (instance 0 on CPU 0)
stress-ng: debug: [1282] io-uring: [1283] terminated (success)
stress-ng: debug: [1282] io-uring: removing temporary files in ./tmp-stress-
syslog:
[ 484.045024] INFO: task systemd:1 blocked for more than 120 seconds.
[ 484.046289] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.047408] "echo 0 > /proc/sys/
[ 484.048961] task:systemd state:D stack: 0 pid: 1 ppid: 0 flags:0x00000002
[ 484.048965] Call Trace:
[ 484.048967] <TASK>
[ 484.048970] __schedule+
[ 484.048976] ? bit_wait+0x70/0x70
[ 484.048979] schedule+0x69/0x110
[ 484.048982] io_schedule+
[ 484.048993] bit_wait_
[ 484.048996] __wait_
[ 484.048998] out_of_
[ 484.049002] ? var_wake_
[ 484.049006] do_get_
[ 484.049011] jbd2_journal_
[ 484.049014] __ext4_
[ 484.049017] __ext4_
[ 484.049022] ? ext4_lookup.
[ 484.049026] ext4_mkdir+
[ 484.049029] vfs_mkdir+
[ 484.049033] do_mkdirat+
[ 484.049036] __x64_sys_
[ 484.049039] x64_sys_
[ 484.049044] do_syscall_
[ 484.049048] ? syscall_
[ 484.049051] ? x64_sys_
[ 484.049054] ? do_syscall_
[ 484.049057] ? x64_sys_
[ 484.049060] ? do_syscall_
[ 484.049063] ? do_syscall_
[ 484.049066] entry_SYSCALL_
[ 484.049071] RIP: 0033:0x7eff89eb745b
[ 484.049074] RSP: 002b:00007ffdc9
[ 484.049077] RAX: ffffffffffffffda RBX: f49998db0aa753ff RCX: 00007eff89eb745b
[ 484.049079] RDX: 0000000000000030 RSI: 00000000000001c0 RDI: 0000555b727d07a0
[ 484.049080] RBP: 00000000b504f32d R08: 0000000000000004 R09: 0000000000000001
[ 484.049082] R10: 0000000663a83b5c R11: 0000000000000212 R12: 27bb2ee687b0b0fd
[ 484.049084] R13: 0000555b727d07a0 R14: 00007eff89f7fc00 R15: 00000000006cee2a
[ 484.049087] </TASK>
[ 484.049089] INFO: task kworker/u30:0:9 blocked for more than 120 seconds.
[ 484.050421] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.051530] "echo 0 > /proc/sys/
[ 484.053090] task:kworker/u30:0 state:D stack: 0 pid: 9 ppid: 2 flags:0x00004000
[ 484.053094] Workqueue: writeback wb_workfn (flush-202:0)
[ 484.053100] Call Trace:
[ 484.053102] <TASK>
[ 484.053103] __schedule+
[ 484.053108] schedule+0x69/0x110
[ 484.053111] io_schedule+
[ 484.053114] ? wbt_cleanup_
[ 484.053117] rq_qos_
[ 484.053121] ? elv_merge+0xb0/0xe0
[ 484.053125] ? wbt_rqw_
[ 484.053127] ? sysv68_
[ 484.053130] ? wbt_cleanup_
[ 484.053133] wbt_wait+0x9f/0xf0
[ 484.053135] __rq_qos_
[ 484.053138] blk_mq_
[ 484.053143] __submit_
[ 484.053147] submit_
[ 484.053150] submit_
[ 484.053153] ext4_bio_
[ 484.053157] mpage_submit_
[ 484.053160] mpage_process_
[ 484.053162] mpage_prepare_
[ 484.053166] ext4_writepages
[ 484.053170] ? select_
[ 484.053174] ? cpumask_
[ 484.053179] do_writepages+
[ 484.053182] ? mpage_map_
[ 484.053185] ? do_writepages+
[ 484.053188] ? _raw_spin_
[ 484.053191] ? fprop_fraction_
[ 484.053193] ? __wb_calc_
[ 484.053196] __writeback_
[ 484.053199] writeback_
[ 484.053203] __writeback_
[ 484.053206] wb_writeback+
[ 484.053209] wb_do_writeback
[ 484.053212] wb_workfn+
[ 484.053215] ? _raw_spin_
[ 484.053217] ? try_to_
[ 484.053221] ? raw_spin_
[ 484.053224] process_
[ 484.053227] worker_
[ 484.053229] ? process_
[ 484.053231] kthread+0x12a/0x150
[ 484.053234] ? set_kthread_
[ 484.053237] ret_from_
[ 484.053241] </TASK>
[ 484.053247] INFO: task kworker/u30:3:106 blocked for more than 120 seconds.
[ 484.054614] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.055730] "echo 0 > /proc/sys/
[ 484.057275] task:kworker/u30:3 state:D stack: 0 pid: 106 ppid: 2 flags:0x00004000
[ 484.057279] Workqueue: writeback wb_workfn (flush-202:0)
[ 484.057283] Call Trace:
[ 484.057284] <TASK>
[ 484.057285] __schedule+
[ 484.057289] ? bit_wait+0x70/0x70
[ 484.057292] schedule+0x69/0x110
[ 484.057295] io_schedule+
[ 484.057298] bit_wait_
[ 484.057301] __wait_
[ 484.057305] out_of_
[ 484.057309] ? var_wake_
[ 484.057313] do_get_
[ 484.057317] jbd2_journal_
[ 484.057320] __ext4_
[ 484.057324] ext4_mb_
[ 484.057328] ext4_mb_
[ 484.057332] ext4_ext_
[ 484.057336] ext4_map_
[ 484.057339] ? ext4_alloc_
[ 484.057341] mpage_map_
[ 484.057345] ext4_writepages
[ 484.057349] ? update_
[ 484.057354] do_writepages+
[ 484.057357] ? mpage_map_
[ 484.057360] ? do_writepages+
[ 484.057362] ? __percpu_
[ 484.057367] ? fprop_fraction_
[ 484.057370] ? __wb_calc_
[ 484.057373] __writeback_
[ 484.057376] writeback_
[ 484.057381] __writeback_
[ 484.057384] wb_writeback+
[ 484.057387] wb_do_writeback
[ 484.057391] wb_workfn+
[ 484.057393] ? psi_task_
[ 484.057396] ? raw_spin_
[ 484.057399] ? finish_
[ 484.057402] process_
[ 484.057405] worker_
[ 484.057407] ? process_
[ 484.057409] kthread+0x12a/0x150
[ 484.057412] ? set_kthread_
[ 484.057415] ret_from_
[ 484.057419] </TASK>
[ 484.057421] INFO: task jbd2/xvda1-8:294 blocked for more than 120 seconds.
[ 484.058763] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.059876] "echo 0 > /proc/sys/
[ 484.061421] task:jbd2/xvda1-8 state:D stack: 0 pid: 294 ppid: 2 flags:0x00004000
[ 484.061424] Call Trace:
[ 484.061425] <TASK>
[ 484.061426] __schedule+
[ 484.061430] ? bit_wait+0x70/0x70
[ 484.061433] schedule+0x69/0x110
[ 484.061436] io_schedule+
[ 484.061439] bit_wait_
[ 484.061443] __wait_
[ 484.061447] out_of_
[ 484.061451] ? var_wake_
[ 484.061454] __wait_
[ 484.061458] jbd2_journal_
[ 484.061463] kjournald2+
[ 484.061466] ? wait_woken+
[ 484.061469] ? load_superblock
[ 484.061473] kthread+0x12a/0x150
[ 484.061476] ? set_kthread_
[ 484.061479] ret_from_
[ 484.061483] </TASK>
[ 484.061485] INFO: task systemd-journal:367 blocked for more than 120 seconds.
[ 484.062882] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.063998] "echo 0 > /proc/sys/
[ 484.065548] task:systemd-
[ 484.065551] Call Trace:
[ 484.065552] <TASK>
[ 484.065554] __schedule+
[ 484.065558] ? bit_wait+0x70/0x70
[ 484.065561] schedule+0x69/0x110
[ 484.065564] io_schedule+
[ 484.065568] bit_wait_
[ 484.065571] __wait_
[ 484.065574] out_of_
[ 484.065578] ? var_wake_
[ 484.065580] do_get_
[ 484.065583] jbd2_journal_
[ 484.065586] __ext4_
[ 484.065589] ext4_orphan_
[ 484.065591] ? __ext4_
[ 484.065594] ext4_truncate+
[ 484.065597] ext4_setattr+
[ 484.065599] ? ext4_xattr_
[ 484.065603] notify_
[ 484.065606] do_truncate+
[ 484.065609] ? do_truncate+
[ 484.065612] do_sys_
[ 484.065615] __x64_sys_
[ 484.065617] x64_sys_
[ 484.065620] do_syscall_
[ 484.065623] ? x64_sys_
[ 484.065626] ? do_syscall_
[ 484.065629] entry_SYSCALL_
[ 484.065632] RIP: 0033:0x7fdb30236fbb
[ 484.065634] RSP: 002b:00007fff6b
[ 484.065637] RAX: ffffffffffffffda RBX: 00007fff6b5d3e60 RCX: 00007fdb30236fbb
[ 484.065639] RDX: 000055d31f5acc80 RSI: 0000000000800000 RDI: 0000000000000017
[ 484.065640] RBP: 000055d31f5b3b50 R08: 0000000000000001 R09: 000055d31f5b3bd4
[ 484.065642] R10: 0000000000000010 R11: 0000000000000206 R12: 000055d31f589310
[ 484.065643] R13: 00007fff6b5d3e58 R14: 0000000000000003 R15: 0000000000000000
[ 484.065646] </TASK>
[ 484.065655] INFO: task stress-
[ 484.067070] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.068179] "echo 0 > /proc/sys/
[ 484.069729] task:stress-
[ 484.069732] Call Trace:
[ 484.069733] <TASK>
[ 484.069735] __schedule+
[ 484.069738] ? path_parentat+
[ 484.069742] schedule+0x69/0x110
[ 484.069744] rwsem_down_
[ 484.069749] down_write+
[ 484.069751] vfs_unlink+
[ 484.069754] do_unlinkat+
[ 484.069757] __x64_sys_
[ 484.069760] x64_sys_
[ 484.069763] do_syscall_
[ 484.069767] ? do_syscall_
[ 484.069770] ? do_syscall_
[ 484.069773] ? do_syscall_
[ 484.069776] entry_SYSCALL_
[ 484.069780] RIP: 0033:0x7fe36d6a70ab
[ 484.069782] RSP: 002b:00007fffa6
[ 484.069784] RAX: ffffffffffffffda RBX: 0000557fef023888 RCX: 00007fe36d6a70ab
[ 484.069786] RDX: 0000000000000000 RSI: 0000000000004000 RDI: 00007fffa66cc260
[ 484.069788] RBP: 00007fffa66cc260 R08: 00007fe36b83f000 R09: 00007fffa66cbe30
[ 484.069790] R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000000000
[ 484.069791] R13: 000000000000007b R14: 00007fffa66cc060 R15: 00007fffa66cc260
[ 484.069794] </TASK>
[ 484.069795] INFO: task iou-wrk-1287:1293 blocked for more than 120 seconds.
[ 484.071161] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.072275] "echo 0 > /proc/sys/
[ 484.073816] task:iou-wrk-1287 state:D stack: 0 pid: 1293 ppid: 1 flags:0x00024006
[ 484.073820] Call Trace:
[ 484.073821] <TASK>
[ 484.073822] __schedule+
[ 484.073827] schedule+0x69/0x110
[ 484.073830] jbd2_log_
[ 484.073834] ? wait_woken+
[ 484.073837] jbd2_complete_
[ 484.073840] ext4_fc_
[ 484.073842] ext4_sync_
[ 484.073846] vfs_fsync_
[ 484.073849] io_issue_
[ 484.073853] io_wq_submit_
[ 484.073856] io_worker_
[ 484.073859] io_wqe_
[ 484.073863] ? raw_spin_
[ 484.073866] ? finish_
[ 484.073869] ? io_worker_
[ 484.073872] ? io_worker_
[ 484.073876] ret_from_
[ 484.073878] RIP: 0033:0x0
[ 484.073880] RSP: 002b:0000000000
[ 484.073882] RAX: 0000000000000000 RBX: 00007fffa66cc0a0 RCX: 00007fe36d6af88d
[ 484.073884] RDX: 0000000000000001 RSI: 0000000000000001 RDI: 0000000000000004
[ 484.073885] RBP: 00007fe36b83d000 R08: 0000000000000000 R09: 0000000000000000
[ 484.073887] R10: 0000000000000001 R11: 0000000000000246 R12: 00007fe36d5783a8
[ 484.073888] R13: 0000557fef023888 R14: 0000557fef02de37 R15: 0000557fef2da500
[ 484.073891] </TASK>
[ 484.073892] INFO: task iou-wrk-1287:1294 blocked for more than 120 seconds.
[ 484.075248] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.076360] "echo 0 > /proc/sys/
[ 484.077910] task:iou-wrk-1287 state:D stack: 0 pid: 1294 ppid: 1 flags:0x00024006
[ 484.077913] Call Trace:
[ 484.077914] <TASK>
[ 484.077915] __schedule+
[ 484.077918] schedule+0x69/0x110
[ 484.077922] rwsem_down_
[ 484.077925] ? aa_file_
[ 484.077928] down_write+
[ 484.077931] ext4_fallocate+
[ 484.077934] vfs_fallocate+
[ 484.077937] io_issue_
[ 484.077941] io_wq_submit_
[ 484.077945] io_worker_
[ 484.077950] io_wqe_
[ 484.077954] ? raw_spin_
[ 484.077957] ? finish_
[ 484.077960] ? io_worker_
[ 484.077964] ? io_worker_
[ 484.077968] ret_from_
[ 484.077971] RIP: 0033:0x0
[ 484.077972] RSP: 002b:0000000000
[ 484.077974] RAX: 0000000000000000 RBX: 00007fffa66cc0a0 RCX: 00007fe36d6af88d
[ 484.077976] RDX: 0000000000000001 RSI: 0000000000000001 RDI: 0000000000000004
[ 484.077977] RBP: 00007fe36b83d000 R08: 0000000000000000 R09: 0000000000000000
[ 484.077979] R10: 0000000000000001 R11: 0000000000000246 R12: 00007fe36d5783a8
[ 484.077980] R13: 0000557fef023888 R14: 0000557fef02de37 R15: 0000557fef2da500
[ 484.077983] </TASK>
[ 484.077984] INFO: task iou-wrk-1287:1295 blocked for more than 120 seconds.
[ 484.079351] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.080477] "echo 0 > /proc/sys/
[ 484.082015] task:iou-wrk-1287 state:D stack: 0 pid: 1295 ppid: 1 flags:0x00024006
[ 484.082018] Call Trace:
[ 484.082019] <TASK>
[ 484.082020] __schedule+
[ 484.082024] schedule+0x69/0x110
[ 484.082027] jbd2_log_
[ 484.082030] ? wait_woken+
[ 484.082033] jbd2_complete_
[ 484.082035] ext4_fc_
[ 484.082037] ext4_sync_
[ 484.082040] vfs_fsync_
[ 484.082043] io_issue_
[ 484.082046] ? __schedule+
[ 484.082049] io_wq_submit_
[ 484.082052] io_worker_
[ 484.082056] io_wqe_
[ 484.082060] ? raw_spin_
[ 484.082062] ? finish_
[ 484.082065] ? io_worker_
[ 484.082068] ? io_worker_
[ 484.082071] ret_from_
[ 484.082074] RIP: 0033:0x0
[ 484.082076] RSP: 002b:0000000000
[ 484.082078] RAX: 0000000000000000 RBX: 00007fffa66cc0a0 RCX: 00007fe36d6af88d
[ 484.082079] RDX: 0000000000000001 RSI: 0000000000000001 RDI: 0000000000000004
[ 484.082080] RBP: 00007fe36b83d000 R08: 0000000000000000 R09: 0000000000000000
[ 484.082082] R10: 0000000000000001 R11: 0000000000000246 R12: 00007fe36d5783a8
[ 484.082083] R13: 0000557fef023888 R14: 0000557fef02de37 R15: 0000557fef2da500
[ 484.082086] </TASK>
[ 484.082087] INFO: task iou-wrk-1287:1296 blocked for more than 120 seconds.
[ 484.083461] Not tainted 5.15.0-112-generic #122-Ubuntu
[ 484.084602] "echo 0 > /proc/sys/
[ 484.086133] task:iou-wrk-1287 state:D stack: 0 pid: 1296 ppid: 1 flags:0x00024006
[ 484.086136] Call Trace:
[ 484.086137] <TASK>
[ 484.086138] __schedule+
[ 484.086142] schedule+0x69/0x110
[ 484.086145] rwsem_down_
[ 484.086148] ? aa_file_
[ 484.086152] down_write+
[ 484.086154] ext4_fallocate+
[ 484.086157] vfs_fallocate+
[ 484.086159] io_issue_
[ 484.086163] io_wq_submit_
[ 484.086166] io_worker_
[ 484.086169] io_wqe_
[ 484.086173] ? raw_spin_
[ 484.086175] ? finish_
[ 484.086178] ? io_worker_
[ 484.086181] ? io_worker_
[ 484.086184] ret_from_
[ 484.086187] RIP: 0033:0x0
[ 484.086189] RSP: 002b:0000000000
[ 484.086191] RAX: 0000000000000000 RBX: 00007fffa66cc0a0 RCX: 00007fe36d6af88d
[ 484.086192] RDX: 0000000000000001 RSI: 0000000000000001 RDI: 0000000000000004
[ 484.086193] RBP: 00007fe36b83d180 R08: 0000000000000000 R09: 0000000000000000
[ 484.086195] R10: 0000000000000001 R11: 0000000000000246 R12: 00007fe36d5783a8
[ 484.086196] R13: 0000557fef023888 R14: 0000557fef02de37 R15: 0000557fef2da500
[ 484.086199] </TASK>
Bisect shows 5fd6bbb [1] is very likely the first bad commit.
Issue reported upstream https:/
[1] https:/
This issue has been fixed with stress-ng update.
Hints removed.