[cc Jens] [Jens, data corruption w/ io_uring and simple fio reproducer. see the bz link below.] On Mon, Aug 10, 2020 at 01:56:05PM +1000, Dave Chinner wrote: > On Mon, Aug 10, 2020 at 10:09:32AM +1000, Dave Chinner wrote: > > On Fri, Aug 07, 2020 at 03:12:03AM +0000, bugzilla-daemon@xxxxxxxxxxxxxxxxxxx wrote: > > > --- Comment #1 from Dave Chinner (david@xxxxxxxxxxxxx) --- > > > On Thu, Aug 06, 2020 at 04:57:58AM +0000, bugzilla-daemon@xxxxxxxxxxxxxxxxxxx > > > wrote: > > > > https://bugzilla.kernel.org/show_bug.cgi?id=208827 > > > > > > > > Bug ID: 208827 > > > > Summary: [fio io_uring] io_uring write data crc32c verify > > > > failed > > > > Product: File System > > > > Version: 2.5 > > > > Kernel Version: xfs-linux xfs-5.9-merge-7 + v5.8-rc4 > > > > FWIW, I can reproduce this with a vanilla 5.8 release kernel, > > so this isn't related to contents of the XFS dev tree at all... > > > > In fact, this bug isn't a recent regression. AFAICT, it was > > introduced between in 5.4 and 5.5 - 5.4 did not reproduce, 5.5 did > > reproduce. More info once I've finished bisecting it.... > > f67676d160c6ee2ed82917fadfed6d29cab8237c is the first bad commit > commit f67676d160c6ee2ed82917fadfed6d29cab8237c > Author: Jens Axboe <axboe@xxxxxxxxx> > Date: Mon Dec 2 11:03:47 2019 -0700 > > io_uring: ensure async punted read/write requests copy iovec .... Ok, I went back to vanilla 5.8 to continue debugging and adding tracepoints, and it's proving strangely difficult to reproduce now. However, I did just hit this: [ 4980.136032] ------------[ cut here ]------------ [ 4980.137665] do not call blocking ops when !TASK_RUNNING; state=1 set at [<00000000ef911b51>] prepare_to_wait_exclusive+0x3d/0xd0 [ 4980.141403] WARNING: CPU: 13 PID: 6800 at kernel/sched/core.c:6888 __might_sleep+0x74/0x80 [ 4980.143940] CPU: 13 PID: 6800 Comm: fio Not tainted 5.8.0-dgc+ #2549 [ 4980.146147] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.13.0-1 04/01/2014 [ 4980.148774] RIP: 0010:__might_sleep+0x74/0x80 [ 4980.150455] Code: ff 41 5c 41 5d 41 5e 5d c3 48 8b 90 30 22 00 00 48 c7 c7 a8 b9 50 82 c6 05 38 e4 9a 01 01 48 8b 70 10 48 89 d1 e8 fa 5c fc ff <0f> 0b eb c5 0f 1f 84 00 00 00 002 [ 4980.156255] RSP: 0018:ffffc90005383c58 EFLAGS: 00010282 [ 4980.158299] RAX: 0000000000000000 RBX: 0000561a18122000 RCX: 0000000000000000 [ 4980.160817] RDX: ffff88883eca7de0 RSI: ffff88883ec97a80 RDI: ffff88883ec97a80 [ 4980.163162] RBP: ffffc90005383c70 R08: ffff88883ec97a80 R09: ffff8888070f3000 [ 4980.165635] R10: ffff8888070f3434 R11: ffff8888070f3434 R12: ffffffff8251f46e [ 4980.168115] R13: 00000000000001ba R14: 0000000000000000 R15: ffff888235647740 [ 4980.170714] FS: 00007f80de7af700(0000) GS:ffff88883ec80000(0000) knlGS:0000000000000000 [ 4980.173442] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 4980.175371] CR2: 00007f80d4005008 CR3: 00000005eb01c004 CR4: 0000000000060ee0 [ 4980.177607] Call Trace: [ 4980.178583] change_protection+0x827/0x9e0 [ 4980.180063] ? kvm_clock_read+0x18/0x30 [ 4980.181654] ? kvm_sched_clock_read+0x9/0x20 [ 4980.183426] ? sysvec_apic_timer_interrupt+0x46/0x90 [ 4980.185160] change_prot_numa+0x19/0x30 [ 4980.186607] task_numa_work+0x1c7/0x2e0 [ 4980.188003] task_work_run+0x64/0xb0 [ 4980.189488] io_cqring_wait+0x118/0x290 [ 4980.191136] ? io_uring_poll+0x80/0x80 [ 4980.192430] __x64_sys_io_uring_enter+0x158/0x2d0 [ 4980.194033] do_syscall_64+0x46/0x90 [ 4980.195278] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 4980.197092] RIP: 0033:0x7f8135c59a79 [ 4980.198412] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b8 [ 4980.203953] RSP: 002b:00007f80de7aacd8 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa [ 4980.206596] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f8135c59a79 [ 4980.208924] RDX: 0000000000000001 RSI: 0000000000000000 RDI: 0000000000000008 [ 4980.211334] RBP: 00007f80defb1000 R08: 0000000000000000 R09: 0000000000000000 [ 4980.213656] R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000000001 [ 4980.216045] R13: 0000000000000001 R14: 0000561a1820cd60 R15: 0000000000000000 [ 4980.218469] ---[ end trace 4a8ca123102be9c2 ]--- No idea if it is relevant to the data corruption, but there's definitely something not right here... Cheers, Dave. -- Dave Chinner david@xxxxxxxxxxxxx
