Skip to contentSkip to conversation

BUG: unable to handle kernel paging request at ffffffff82200000 (xlog_recover_buffer_pass2)

DISCUSSION Vegard Nossum 3 participants 3 messages Dec 2, 2015 – Apr 11, 2016

lore
Share & tools
lore

Vegard Nossum

author
#0 lore raw

Hi,

Mounting the attached XFS image (fuzzed) gives me the following invalid memory dereference on latest linus/master:

XFS (vda): Mounting V4 Filesystem
XFS (vda): Starting recovery (logdev: internal)
XFS (vda): log record CRC mismatch: found 0x9f534964, expected 0xd46d59ce.
ffffc90000442000: 00 00 00 01 00 00 00 00 69 01 00 00 e6 33 18 19 ........i....3..
ffffc90000442010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*... XFS (vda): log record CRC mismatch: found 0xedba28e, expected 0x9f019b73.
ffffc90000442000: 00 00 00 01 00 00 00 00 69 01 00 00 5c 47 88 1e ........i...\G..
ffffc90000442010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*... XFS (vda): log record CRC mismatch: found 0x9f534964, expected 0xd46d59ce.
ffffc9000044a000: 00 00 00 01 00 00 00 00 69 01 00 00 e6 33 18 19 ........i....3..
ffffc9000044a010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*...

BUG: unable to handle kernel paging request at ffffffff82200000
IP: [<ffffffff81475616>] memcpy_erms+0x6/0x10
PGD 1e10067 PUD 1e11063 PMD 0
Oops: 0000 [#1] SMP KASAN
CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.4.0-rc3+ #245
task: ffff880016e28000 ti: ffff880016e30000 task.ti: ffff880016e30000
RIP: 0010:[<ffffffff81475616>]  [<ffffffff81475616>] memcpy_erms+0x6/0x10
RSP: 0000:ffff880016e377b8  EFLAGS: 00010287
RAX: ffff88001494e380 RBX: 0000000000000027 RCX: ffffffff80285761
RDX: ffffffff81150400 RSI: ffffffff82200000 RDI: ffff88001581901f
RBP: ffff880016e37808 R08: ffff880016429ba8 R09: 0000000000000018
R10: 0000000000000000 R11: 0000000000000000 R12: ffff880016429b90
R13: 0000000000000002 R14: 00000000ff022a08 R15: ffffffff81335361
FS:  0000000000000000(0000) GS:ffff880017200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffff82200000 CR3: 0000000001e0f000 CR4: 00000000001406b0
Stack:
 ffffffff8133eb74 ffff880000079b80 ffff880015bf6e40 ffff880016429ba4
 ffff880000108470 ffff880016429b90 ffff880014c26290 ffff880015bf6e40
 ffff880000108450 ffff880000079b80 ffff880016e37870 ffffffff8133f02a
Call Trace:
 [<ffffffff8133eb74>] ? xlog_recover_do_reg_buffer.isra.23+0x124/0x1b0
 [<ffffffff8133f02a>] xlog_recover_buffer_pass2+0x35a/0x450
 [<ffffffff81340c09>] xlog_recover_commit_pass2+0xe9/0x160
 [<ffffffff81340cbc>] xlog_recover_items_pass2+0x3c/0x60
 [<ffffffff81340ee6>] xlog_recover_commit_trans+0x206/0x230
 [<ffffffff81340f8a>] xlog_recovery_process_trans+0x7a/0xb0
 [<ffffffff8134101e>] xlog_recover_process_ophdr+0x5e/0xc0
 [<ffffffff8134111a>] xlog_recover_process_data+0x9a/0xc0
 [<ffffffff81341580>] xlog_do_recovery_pass+0x440/0x540
 [<ffffffff8115384f>] ? kasan_poison_shadow+0x2f/0x40
 [<ffffffff813416f9>] xlog_do_log_recovery+0x79/0xc0
 [<ffffffff81341751>] xlog_do_recover+0x11/0xe0
 [<ffffffff81342553>] xlog_recover+0xa3/0x140
 [<ffffffff8133718e>] xfs_log_mount+0x24e/0x2c0
 [<ffffffff8132f209>] xfs_mountfs+0x499/0x7d0
 [<ffffffff8132ff91>] ? xfs_mru_cache_create+0x121/0x180
 [<ffffffff81331e2d>] xfs_fs_fill_super+0x38d/0x4a0
 [<ffffffff8115deb5>] mount_bdev+0x185/0x1c0
 [<ffffffff81331aa0>] ? xfs_parseargs+0xaa0/0xaa0
 [<ffffffff81330580>] xfs_fs_mount+0x10/0x20
 [<ffffffff8115e0e4>] mount_fs+0x34/0x160
 [<ffffffff811240b0>] ? __alloc_percpu+0x10/0x20
 [<ffffffff81178a22>] vfs_kern_mount+0x62/0x110
 [<ffffffff81179e6b>] do_mount+0x21b/0xdd0
$ addr2line -e vmlinux -i ffffffff81475616 # memcpy_erms+0x6/0x10
arch/x86/lib/memcpy_64.S:50
$ addr2line -e vmlinux -i ffffffff8133eb74 # xlog_recover_do_reg_buffer.isra.23+0x124/0x1b0
fs/xfs/xfs_log_recover.c:2238
$ addr2line -e vmlinux -i ffffffff8133f02a # xlog_recover_buffer_pass2+0x35a/0x450
fs/xfs/xfs_log_recover.c:2397

which is this bit:

    memcpy(xfs_buf_offset(bp,
            (uint)bit << XFS_BLF_SHIFT),    /* dest */
            item->ri_buf[i].i_addr,         /* source */
            nbits<<XFS_BLF_SHIFT);          /* length */

Because of the memory corruption the bug manifests in different ways, but the stacktrace above is by far the most common.

I can test patches. Thanks,

Vegard

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

#1 lore raw

Hi Vegard
Does this commit fix the crash?

commit 7088c4136fa1cba26531fde40bdcfcf3d2ccd533 (patch)
xfs: detect and trim torn writes during log recovery

B.R.

Quoted 84 lines · Vegard Nossum

Hi,

Mounting the attached XFS image (fuzzed) gives me the following invalid memory dereference on latest linus/master:

XFS (vda): Mounting V4 Filesystem
XFS (vda): Starting recovery (logdev: internal)
XFS (vda): log record CRC mismatch: found 0x9f534964, expected 0xd46d59ce.
ffffc90000442000: 00 00 00 01 00 00 00 00 69 01 00 00 e6 33 18 19 ........i....3..
ffffc90000442010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*... XFS (vda): log record CRC mismatch: found 0xedba28e, expected 0x9f019b73.
ffffc90000442000: 00 00 00 01 00 00 00 00 69 01 00 00 5c 47 88 1e ........i...\G..
ffffc90000442010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*... XFS (vda): log record CRC mismatch: found 0x9f534964, expected 0xd46d59ce.
ffffc9000044a000: 00 00 00 01 00 00 00 00 69 01 00 00 e6 33 18 19 ........i....3..
ffffc9000044a010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*...

BUG: unable to handle kernel paging request at ffffffff82200000
IP: [<ffffffff81475616>] memcpy_erms+0x6/0x10
PGD 1e10067 PUD 1e11063 PMD 0
Oops: 0000 [#1] SMP KASAN
CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.4.0-rc3+ #245
task: ffff880016e28000 ti: ffff880016e30000 task.ti: ffff880016e30000
RIP: 0010:[<ffffffff81475616>]  [<ffffffff81475616>] memcpy_erms+0x6/0x10
RSP: 0000:ffff880016e377b8  EFLAGS: 00010287
RAX: ffff88001494e380 RBX: 0000000000000027 RCX: ffffffff80285761
RDX: ffffffff81150400 RSI: ffffffff82200000 RDI: ffff88001581901f
RBP: ffff880016e37808 R08: ffff880016429ba8 R09: 0000000000000018
R10: 0000000000000000 R11: 0000000000000000 R12: ffff880016429b90
R13: 0000000000000002 R14: 00000000ff022a08 R15: ffffffff81335361
FS:  0000000000000000(0000) GS:ffff880017200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffff82200000 CR3: 0000000001e0f000 CR4: 00000000001406b0
Stack:
 ffffffff8133eb74 ffff880000079b80 ffff880015bf6e40 ffff880016429ba4
 ffff880000108470 ffff880016429b90 ffff880014c26290 ffff880015bf6e40
 ffff880000108450 ffff880000079b80 ffff880016e37870 ffffffff8133f02a
Call Trace:
 [<ffffffff8133eb74>] ? xlog_recover_do_reg_buffer.isra.23+0x124/0x1b0
 [<ffffffff8133f02a>] xlog_recover_buffer_pass2+0x35a/0x450
 [<ffffffff81340c09>] xlog_recover_commit_pass2+0xe9/0x160
 [<ffffffff81340cbc>] xlog_recover_items_pass2+0x3c/0x60
 [<ffffffff81340ee6>] xlog_recover_commit_trans+0x206/0x230
 [<ffffffff81340f8a>] xlog_recovery_process_trans+0x7a/0xb0
 [<ffffffff8134101e>] xlog_recover_process_ophdr+0x5e/0xc0
 [<ffffffff8134111a>] xlog_recover_process_data+0x9a/0xc0
 [<ffffffff81341580>] xlog_do_recovery_pass+0x440/0x540
 [<ffffffff8115384f>] ? kasan_poison_shadow+0x2f/0x40
 [<ffffffff813416f9>] xlog_do_log_recovery+0x79/0xc0
 [<ffffffff81341751>] xlog_do_recover+0x11/0xe0
 [<ffffffff81342553>] xlog_recover+0xa3/0x140
 [<ffffffff8133718e>] xfs_log_mount+0x24e/0x2c0
 [<ffffffff8132f209>] xfs_mountfs+0x499/0x7d0
 [<ffffffff8132ff91>] ? xfs_mru_cache_create+0x121/0x180
 [<ffffffff81331e2d>] xfs_fs_fill_super+0x38d/0x4a0
 [<ffffffff8115deb5>] mount_bdev+0x185/0x1c0
 [<ffffffff81331aa0>] ? xfs_parseargs+0xaa0/0xaa0
 [<ffffffff81330580>] xfs_fs_mount+0x10/0x20
 [<ffffffff8115e0e4>] mount_fs+0x34/0x160
 [<ffffffff811240b0>] ? __alloc_percpu+0x10/0x20
 [<ffffffff81178a22>] vfs_kern_mount+0x62/0x110
 [<ffffffff81179e6b>] do_mount+0x21b/0xdd0
$ addr2line -e vmlinux -i ffffffff81475616 # memcpy_erms+0x6/0x10
arch/x86/lib/memcpy_64.S:50
$ addr2line -e vmlinux -i ffffffff8133eb74 # xlog_recover_do_reg_buffer.isra.23+0x124/0x1b0
fs/xfs/xfs_log_recover.c:2238
$ addr2line -e vmlinux -i ffffffff8133f02a # xlog_recover_buffer_pass2+0x35a/0x450
fs/xfs/xfs_log_recover.c:2397

which is this bit:

    memcpy(xfs_buf_offset(bp,
            (uint)bit << XFS_BLF_SHIFT),    /* dest */
            item->ri_buf[i].i_addr,         /* source */
            nbits<<XFS_BLF_SHIFT);          /* length */

Because of the memory corruption the bug manifests in different ways, but the stacktrace above is by far the most common.

I can test patches. Thanks,

Quoted 7 lines

Vegard

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

#2 lore raw

FWIW, testing it on 4.6.0-rc1 passes for me.

[10756.548578] XFS (loop0): Mounting V4 Filesystem
[10756.555109] XFS (loop0): Torn write (CRC failure) detected at log block 0x2. Truncating head block from 0x9.
[10756.583561] XFS (loop0): Metadata corruption detected at xfs_inode_buf_verify+0x8e/0x160 [xfs], xfs_inode block 0x25c0
[10756.594245] XFS (loop0): Unmount and run xfs_repair
[10756.599117] XFS (loop0): First 64 bytes of corrupted metadata buffer:
[10756.605545] ffff88018945f000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
[10756.614225] ffff88018945f010: 00 01 78 25 b7 33 94 b6 41 dd 8f e4 9f f6 af ef  ..x%.3..A.......
[10756.622906] ffff88018945f020: 02 82 49 4e 41 ed 02 01 00 00 00 00 00 03 00 00  ..INA...........
[10756.631586] ffff88018945f030: 00 00 00 00 00 00 00 00 00 01 56 5e 15 4f 03 14  ..........V^.O..
[10756.640267] XFS (loop0): bad inode magic/vsn daddr 9664 #0 (magic=0)
<repeats>
[10758.604767] XFS (loop0): Detected bogus zero next_unlinked field in inode 5 buffer 0x25c0.
[10758.613032] XFS (loop0): metadata I/O error: block 0x25c0 ("xfs_trans_read_buf_map") error 117 numblks 16
[10758.622601] XFS (loop0): xfs_imap_to_bp: xfs_trans_read_buf() returned error -117.
[10758.630162] XFS (loop0): failed to read root inode

-Eric

Quoted 102 lines · Jia He

Hi Vegard
Does this commit fix the crash?

commit 7088c4136fa1cba26531fde40bdcfcf3d2ccd533 (patch)
xfs: detect and trim torn writes during log recovery

B.R.

Quoted 84 lines · Vegard Nossum

Hi,

Mounting the attached XFS image (fuzzed) gives me the following invalid memory dereference on latest linus/master:

XFS (vda): Mounting V4 Filesystem
XFS (vda): Starting recovery (logdev: internal)
XFS (vda): log record CRC mismatch: found 0x9f534964, expected 0xd46d59ce.
ffffc90000442000: 00 00 00 01 00 00 00 00 69 01 00 00 e6 33 18 19 ........i....3..
ffffc90000442010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*... XFS (vda): log record CRC mismatch: found 0xedba28e, expected 0x9f019b73.
ffffc90000442000: 00 00 00 01 00 00 00 00 69 01 00 00 5c 47 88 1e ........i...\G..
ffffc90000442010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*... XFS (vda): log record CRC mismatch: found 0x9f534964, expected 0xd46d59ce.
ffffc9000044a000: 00 00 00 01 00 00 00 00 69 01 00 00 e6 33 18 19 ........i....3..
ffffc9000044a010: 00 00 00 10 69 00 00 00 4e 41 52 54 2a 00 00 00 ....i...NART*...

BUG: unable to handle kernel paging request at ffffffff82200000
IP: [<ffffffff81475616>] memcpy_erms+0x6/0x10
PGD 1e10067 PUD 1e11063 PMD 0
Oops: 0000 [#1] SMP KASAN
CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.4.0-rc3+ #245
task: ffff880016e28000 ti: ffff880016e30000 task.ti: ffff880016e30000
RIP: 0010:[<ffffffff81475616>]  [<ffffffff81475616>] memcpy_erms+0x6/0x10
RSP: 0000:ffff880016e377b8  EFLAGS: 00010287
RAX: ffff88001494e380 RBX: 0000000000000027 RCX: ffffffff80285761
RDX: ffffffff81150400 RSI: ffffffff82200000 RDI: ffff88001581901f
RBP: ffff880016e37808 R08: ffff880016429ba8 R09: 0000000000000018
R10: 0000000000000000 R11: 0000000000000000 R12: ffff880016429b90
R13: 0000000000000002 R14: 00000000ff022a08 R15: ffffffff81335361
FS:  0000000000000000(0000) GS:ffff880017200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: ffffffff82200000 CR3: 0000000001e0f000 CR4: 00000000001406b0
Stack:
 ffffffff8133eb74 ffff880000079b80 ffff880015bf6e40 ffff880016429ba4
 ffff880000108470 ffff880016429b90 ffff880014c26290 ffff880015bf6e40
 ffff880000108450 ffff880000079b80 ffff880016e37870 ffffffff8133f02a
Call Trace:
 [<ffffffff8133eb74>] ? xlog_recover_do_reg_buffer.isra.23+0x124/0x1b0
 [<ffffffff8133f02a>] xlog_recover_buffer_pass2+0x35a/0x450
 [<ffffffff81340c09>] xlog_recover_commit_pass2+0xe9/0x160
 [<ffffffff81340cbc>] xlog_recover_items_pass2+0x3c/0x60
 [<ffffffff81340ee6>] xlog_recover_commit_trans+0x206/0x230
 [<ffffffff81340f8a>] xlog_recovery_process_trans+0x7a/0xb0
 [<ffffffff8134101e>] xlog_recover_process_ophdr+0x5e/0xc0
 [<ffffffff8134111a>] xlog_recover_process_data+0x9a/0xc0
 [<ffffffff81341580>] xlog_do_recovery_pass+0x440/0x540
 [<ffffffff8115384f>] ? kasan_poison_shadow+0x2f/0x40
 [<ffffffff813416f9>] xlog_do_log_recovery+0x79/0xc0
 [<ffffffff81341751>] xlog_do_recover+0x11/0xe0
 [<ffffffff81342553>] xlog_recover+0xa3/0x140
 [<ffffffff8133718e>] xfs_log_mount+0x24e/0x2c0
 [<ffffffff8132f209>] xfs_mountfs+0x499/0x7d0
 [<ffffffff8132ff91>] ? xfs_mru_cache_create+0x121/0x180
 [<ffffffff81331e2d>] xfs_fs_fill_super+0x38d/0x4a0
 [<ffffffff8115deb5>] mount_bdev+0x185/0x1c0
 [<ffffffff81331aa0>] ? xfs_parseargs+0xaa0/0xaa0
 [<ffffffff81330580>] xfs_fs_mount+0x10/0x20
 [<ffffffff8115e0e4>] mount_fs+0x34/0x160
 [<ffffffff811240b0>] ? __alloc_percpu+0x10/0x20
 [<ffffffff81178a22>] vfs_kern_mount+0x62/0x110
 [<ffffffff81179e6b>] do_mount+0x21b/0xdd0
$ addr2line -e vmlinux -i ffffffff81475616 # memcpy_erms+0x6/0x10
arch/x86/lib/memcpy_64.S:50
$ addr2line -e vmlinux -i ffffffff8133eb74 # xlog_recover_do_reg_buffer.isra.23+0x124/0x1b0
fs/xfs/xfs_log_recover.c:2238
$ addr2line -e vmlinux -i ffffffff8133f02a # xlog_recover_buffer_pass2+0x35a/0x450
fs/xfs/xfs_log_recover.c:2397

which is this bit:

    memcpy(xfs_buf_offset(bp,
            (uint)bit << XFS_BLF_SHIFT),    /* dest */
            item->ri_buf[i].i_addr,         /* source */
            nbits<<XFS_BLF_SHIFT);          /* length */

Because of the memory corruption the bug manifests in different ways, but the stacktrace above is by far the most common.

I can test patches. Thanks,

Quoted 7 lines

Vegard

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

Quoted 4 lines

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs