Re: [Syzkaller & bisect] There is "xfs_dquot_alloc" related BUG in v6.2 in guest
From: Pengfei Xu
Date: Mon Feb 27 2023 - 20:11:32 EST
Hi Dave,
On 2023-02-28 at 08:46:07 +1100, Dave Chinner wrote:
> On Mon, Feb 27, 2023 at 03:29:12PM +0800, Pengfei Xu wrote:
> > Hi Dave and Helge Deller,
> >
> > Thanks Helge Deller to add the xfs mailing list!
> >
> > On 2023-02-27 at 09:34:03 +1100, Dave Chinner wrote:
> > > On Sat, Feb 25, 2023 at 08:58:25PM +0100, Helge Deller wrote:
> > > > Looping in xfs mailing list as this seems to be a XFS problem...
> > > > On 2/24/23 05:39, Pengfei Xu wrote:
> > > > > [ 71.225966] XFS (loop1): Quotacheck: Unsuccessful (Error -5): Disabling quotas.
> > > > > [ 71.226310] xfs filesystem being mounted at /root/syzkaller.qCVHXV/0/file0 supports timestamps until 2038 (0x7fffffff)
> > > > > [ 71.227591] BUG: kernel NULL pointer dereference, address: 00000000000002a8
> > > > > [ 71.227873] #PF: supervisor read access in kernel mode
> > > > > [ 71.228077] #PF: error_code(0x0000) - not-present page
> > > > > [ 71.228280] PGD c313067 P4D c313067 PUD c1fe067 PMD 0
> > > > > [ 71.228494] Oops: 0000 [#1] PREEMPT SMP NOPTI
> > > > > [ 71.228673] CPU: 0 PID: 161 Comm: kworker/0:4 Not tainted 6.2.0-c9c3395d5e3d #1
> > > > > [ 71.228961] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> > > > > [ 71.229400] Workqueue: xfs-inodegc/loop1 xfs_inodegc_worker
> > > > > [ 71.229626] RIP: 0010:xfs_dquot_alloc+0x95/0x1e0
> > > > > [ 71.229820] Code: 80 15 ad 85 48 c7 c6 7c 6b 92 83 e8 75 0f 6b ff 49 8b 8d 60 01 00 00 44 89 e0 31 d2 48 c7 c6 18 ae 8f 83 48 8d bb 18 02 00 00 <f7> b1 a8 02 2
> > > > > [ 71.230528] RSP: 0018:ffffc90000babc20 EFLAGS: 00010246
> > > > > [ 71.230737] RAX: 0000000000000009 RBX: ffff8880093c98c0 RCX: 0000000000000000
> > > > > [ 71.231014] RDX: 0000000000000000 RSI: ffffffff838fae18 RDI: ffff8880093c9ad8
> > > > > [ 71.231292] RBP: ffffc90000babc48 R08: 0000000000000002 R09: 0000000000000000
> > > > > [ 71.231570] R10: ffffc90000baba80 R11: ffff88800af08d98 R12: 0000000000000009
> > > > > [ 71.231850] R13: ffff88800c4bc000 R14: ffff88800c4bc000 R15: 0000000000000004
> > > > > [ 71.232129] FS: 0000000000000000(0000) GS:ffff88807dc00000(0000) knlGS:0000000000000000
> > > > > [ 71.232441] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > > > [ 71.232668] CR2: 00000000000002a8 CR3: 000000000a1d2002 CR4: 0000000000770ef0
> > > > > [ 71.232949] PKRU: 55555554
> > > > > [ 71.233061] Call Trace:
> > > > > [ 71.233162] <TASK>
> > > > > [ 71.233254] xfs_qm_dqread+0x46/0x440
> > > > > [ 71.233410] ? xfs_qm_dqget_inode+0x13e/0x500
> > > > > [ 71.233596] xfs_qm_dqget_inode+0x154/0x500
> > > > > [ 71.233774] xfs_qm_dqattach_one+0x142/0x3c0
> > > > > [ 71.233961] xfs_qm_dqattach_locked+0x14a/0x170
> > > > > [ 71.234149] xfs_qm_dqattach+0x52/0x80
> > > > > [ 71.234307] xfs_inactive+0x186/0x340
> > > > > [ 71.234461] xfs_inodegc_worker+0xd3/0x430
> > > > > [ 71.234630] process_one_work+0x3b1/0x960
> > > > > [ 71.234802] worker_thread+0x52/0x660
> > > > > [ 71.234957] ? __pfx_worker_thread+0x10/0x10
> > > > > [ 71.235136] kthread+0x161/0x1a0
> > > > > [ 71.235279] ? __pfx_kthread+0x10/0x10
> > > > > [ 71.235442] ret_from_fork+0x29/0x50
> > > > > [ 71.235602] </TASK>
> > > > > [ 71.235696] Modules linked in:
> > > > > [ 71.235826] CR2: 00000000000002a8
> > > > > [ 71.235964] ---[ end trace 0000000000000000 ]---
> > >
> > > Looks like a quota disable race with background inode inactivation
> > > reading in dquots.
> > >
> > > Can you test the patch below?
> > >
> > Thanks for your fixed patch in short time!
> > I installed below patch on top of v6.2 kernel.
> > And there was no any BUG dmesg anyway, so the fixed patch worked.
> >
> > And left some "Internal error xfs_iunlink_remove_inode" related Call Trace.
> > I'm new to xfs, could you help to check if it is some other issue or we
> > could ignore it.
>
> I'm guessing this the filesystem detecting a corruption and shutting
> down. That's normal behaviour when tools like syzkaller through
> random crap at the filesystem and expect it to like it.
>
> > I put the dmesg in bugzilla attachment as follow:
> > https://bugzilla.kernel.org/show_bug.cgi?id=217078 ->
> > https://bugzilla.kernel.org/attachment.cgi?id=303793
>
> I am not authorised to access bug 217078, so I can't read any of
> this. Just cut out and attach the relevant dmesg output to the email.
>
Thanks for your check! Yes, there was "XFS (loop6): Corruption detected.
Unmount and run xfs_repair" found at the end of Call Trace info.
Sorry for unaccess link, I put the related dmesg output as follow:
And I put the whole dmesg in github:
https://raw.githubusercontent.com/xupengfe/syzkaller_logs/main/230222_152458_xfs_dquot_alloc_bug/xfs_fixed_BUG_issue_in_v6.2.log
[ 198.601079] XFS (loop2): Ending clean mount
[ 198.601338] XFS (loop6): Quotacheck needed: Please wait.
[ 198.602067] XFS (loop2): Quotacheck needed: Please wait.
[ 198.607537] 00000000: 58 41 47 49 00 00 00 01 00 00 00 00 00 00 80 00 XAGI............
[ 198.607902] 00000010: 00 00 00 40 00 00 00 06 00 00 00 01 00 00 00 37 ...@...........7
[ 198.608223] 00000020: 00 00 00 20 ff ff ff ff ff ff ff ff ff ff ff ff ... ............
[ 198.608553] 00000030: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.608875] 00000040: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.609195] 00000050: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.609514] 00000060: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.609833] 00000070: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.610153] 00000080: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.610473] 00000090: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.610793] 000000a0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.611123] 000000b0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.611443] 000000c0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.611763] 000000d0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.612082] 000000e0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.612402] 000000f0: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.612733] 00000100: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.613052] 00000110: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ................
[ 198.613371] 00000120: ff ff ff ff ff ff ff ff 00 00 00 00 00 00 00 00 ................
[ 198.613690] 00000130: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 198.614009] 00000140: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 198.614328] 00000150: 00 00 00 00 00 00 00 00 ........
[ 198.614621] XFS (loop6): Internal error xfs_iunlink_remove_inode at line 2013 of file fs/xfs/xfs_inode.c. Caller xfs_ifree+0xed/0x9e0
[ 198.615112] CPU: 0 PID: 291 Comm: kworker/0:6 Not tainted 6.2.0-kvmxfs+ #19
[ 198.615394] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
[ 198.615844] Workqueue: xfs-inodegc/loop6 xfs_inodegc_worker
[ 198.616074] Call Trace:
[ 198.616179] <TASK>
[ 198.616274] dump_stack_lvl+0xa7/0xdb
[ 198.616441] dump_stack+0x19/0x1f
[ 198.616587] xfs_corruption_error+0xd7/0xe0
[ 198.616771] ? xfs_ifree+0xed/0x9e0
[ 198.616925] xfs_iunlink_remove+0x32e/0x590
[ 198.617108] ? xfs_ifree+0xed/0x9e0
[ 198.617265] xfs_ifree+0xed/0x9e0
[ 198.617410] ? write_comp_data+0x2f/0x90
[ 198.617580] ? xfs_trans_ijoin+0x47/0x70
[ 198.617750] ? __sanitizer_cov_trace_pc+0x25/0x60
[ 198.617950] ? xfs_trans_add_item+0x79/0x1c0
[ 198.618139] xfs_inactive_ifree+0xf8/0x2a0
[ 198.618316] xfs_inactive+0x226/0x340
[ 198.618475] xfs_inodegc_worker+0xd3/0x430
[ 198.618651] process_one_work+0x3b1/0x960
[ 198.618832] worker_thread+0x52/0x660
[ 198.618993] ? __pfx_worker_thread+0x10/0x10
[ 198.619179] kthread+0x161/0x1a0
[ 198.619326] ? __pfx_kthread+0x10/0x10
[ 198.619495] ret_from_fork+0x29/0x50
[ 198.619666] </TASK>
[ 198.619768] XFS (loop6): Corruption detected. Unmount and run xfs_repair
[ 198.620038] XFS (loop6): xfs_inactive_ifree: xfs_ifree returned error -117
[ 198.657300] kworker/0:6: attempt to access beyond end of device
[ 198.657300] loop6: rw=432129, sector=65535, nr_sectors = 16 limit=65536
[ 198.657940] XFS (loop6): log I/O error -5
[ 198.658295] loop4: detected capacity change from 0 to 65536
[ 198.658706] XFS: ikeep mount option is deprecated.
[ 198.659850] XFS (loop6): Metadata I/O Error (0x1) detected at xfs_inactive_ifree+0x232/0x2a0 (fs/xfs/xfs_inode.c:1612). Shutting down filesystem.
[ 198.660387] XFS (loop6): Please unmount the filesystem and rectify the problem(s)
[ 198.660739] XFS (loop6): Quotacheck: Unsuccessful (Error -5): Disabling quotas.
Thanks!
BR.
-Pengfei.
> -Dave.
> --
> Dave Chinner
> david@xxxxxxxxxxxxx