Bug 88631 - unable to handle kernel paging request at __free_pages
Summary: unable to handle kernel paging request at __free_pages
Status: RESOLVED CODE_FIX
Alias: None
Product: File System
Classification: Unclassified
Component: XFS (show other bugs)
Hardware: x86-64 Linux
: P1 normal
Assignee: XFS Guru
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-11-21 09:55 UTC by R.Nageswara Sastry
Modified: 2016-09-22 16:35 UTC (History)
4 users (show)

See Also:
Kernel Version: 3.18.0-rc5, 3.18.0-rc6
Tree: Mainline
Regression: No


Attachments
xfs mangled fsfuzzer image (2.81 MB, application/x-xz)
2015-02-12 04:18 UTC, R.Nageswara Sastry
Details

Description R.Nageswara Sastry 2014-11-21 09:55:16 UTC
While fuzzing xfs with fsfuzzer the following kernel crash occured. Upon request mangled fs image will be provided.


[   39.638471] loop: module loaded
[   39.887766] SGI XFS with ACLs, security attributes, no debug enabled
[   39.890782] XFS (loop0): Mounting V4 Filesystem
[   39.914338] XFS (loop0): Starting recovery (logdev: internal)
[   39.914382] XFS (loop0): log record CRC mismatch: found 0xbdc26540, expected 0xda046ed1.
[   39.914577] ffffc90000c44000: 00 00 00 01 00 00 00 00 69 01 00 00 bf 07 a8 b4  ........i.......
[   39.914749] ffffc90000c44010: 00 00 00 bf 69 00 00 00 4e 41 52 54 2a 00 00 00  ....i...NART*...
[   39.914928] XFS (loop0): xlog_recover_process_ophdr: bad clientid 0x38
[   39.914943] BUG: unable to handle kernel paging request at 000000005e7188cf
[   39.915186] IP: [<ffffffff81178d35>] __free_pages+0x5/0x50
[   39.915253] PGD 0 
[   39.915253] Oops: 0000 [#1] SMP 
[   39.915253] Modules linked in: xfs libcrc32c loop nf_conntrack_netbios_ns nf_conntrack_broadcast ip6t_REJECT nf_reject_ipv6 nf_conntrack_ipv6 nf_defrag_ipv6 nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack cfg80211 rfkill ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_mangle iptable_security iptable_raw ppdev i2c_piix4 i2c_core microcode pcspkr serio_raw parport_pc pvpanic parport floppy nfsd auth_rpcgss ecryptfs nfs_acl lockd grace encrypted_keys sunrpc trusted tpm virtio_blk virtio_pci ata_generic virtio_ring virtio e1000 pata_acpi
[   39.915253] CPU: 0 PID: 989 Comm: mount Not tainted 3.18.0-rc5 #1
[   39.915253] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
[   39.915253] task: ffff88003cf94a00 ti: ffff88003765c000 task.ti: ffff88003765c000
[   39.915253] RIP: 0010:[<ffffffff81178d35>]  [<ffffffff81178d35>] __free_pages+0x5/0x50
[   39.915253] RSP: 0018:ffff88003765fb00  EFLAGS: 00010202
[   39.915253] RAX: ffff880028521940 RBX: 0000000000000001 RCX: 0000000000000003
[   39.915253] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000005e7188b3
[   39.915253] RBP: ffff88003765fb28 R08: 0000000000000ff0 R09: 0000000000000001
[   39.915253] R10: 0000000000000001 R11: ffff88003765f70e R12: ffff880028bca180
[   39.915253] R13: ffffffffa036407e R14: 000000000000001a R15: ffff880028bca000
[   39.915253] FS:  00007f9e2ae5e880(0000) GS:ffff88003fc00000(0000) knlGS:0000000000000000
[   39.915253] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[   39.915253] CR2: 000000005e7188cf CR3: 000000003c5a1000 CR4: 00000000000006f0
[   39.915253] Stack:
[   39.915253]  ffffffffa033e668 ffff88003765fb38 ffff88003c9e2c00 0000000000000002
[   39.915253]  ffff8800284bf000 ffff88003765fb38 ffffffffa036407e ffff88003765fc48
[   39.915253]  ffffffffa0368722 ffff88003765fbc8 ffffffff810d3ea4 0000000000000001
[   39.915253] Call Trace:
[   39.915253]  [<ffffffffa033e668>] ? xfs_buf_free+0x88/0x130 [xfs]
[   39.915253]  [<ffffffffa036407e>] xlog_put_bp+0xe/0x10 [xfs]
[   39.915253]  [<ffffffffa0368722>] xlog_do_recovery_pass+0x372/0x570 [xfs]
[   39.915253]  [<ffffffff810d3ea4>] ? vprintk_emit+0x384/0x510
[   39.915253]  [<ffffffffa0368989>] xlog_do_log_recovery+0x69/0xd0 [xfs]
[   39.915253]  [<ffffffffa0368a0a>] xlog_do_recover+0x1a/0xf0 [xfs]
[   39.915253]  [<ffffffffa036975c>] xlog_recover+0x8c/0xf0 [xfs]
[   39.915253]  [<ffffffffa035db0c>] xfs_log_mount+0x24c/0x2c0 [xfs]
[   39.915253]  [<ffffffffa035551d>] xfs_mountfs+0x44d/0x7a0 [xfs]
[   39.915253]  [<ffffffffa03588ca>] xfs_fs_fill_super+0x2ba/0x330 [xfs]
[   39.915253]  [<ffffffff811e89b4>] mount_bdev+0x194/0x1d0
[   39.915253]  [<ffffffffa0358610>] ? xfs_parseargs+0xbe0/0xbe0 [xfs]
[   39.915253]  [<ffffffffa03568e5>] xfs_fs_mount+0x15/0x20 [xfs]
[   39.915253]  [<ffffffff811e92d9>] mount_fs+0x39/0x1b0
[   39.915253]  [<ffffffff811923e5>] ? __alloc_percpu+0x15/0x20
[   39.915253]  [<ffffffff812038b7>] vfs_kern_mount+0x67/0x110
[   39.915253]  [<ffffffff812065b4>] do_mount+0x204/0xad0
[   39.915253]  [<ffffffff812071bb>] SyS_mount+0x8b/0xe0
[   39.915253]  [<ffffffff816e6b69>] system_call_fastpath+0x12/0x17
[   39.915253] Code: 74 1c 48 8b 03 90 48 8b 7b 08 48 83 c3 10 44 89 ea 4c 89 e6 ff d0 48 8b 03 48 85 c0 75 e8 eb a9 66 0f 1f 44 00 00 0f 1f 44 00 00 <8b> 47 1c 55 48 89 e5 85 c0 74 29 3e ff 4f 1c 74 0a 5d c3 0f 1f 
[   39.915253] RIP  [<ffffffff81178d35>] __free_pages+0x5/0x50
[   39.915253]  RSP <ffff88003765fb00>
[   39.915253] CR2: 000000005e7188cf
[   39.934763] ---[ end trace 771b409f9d94bcb7 ]---
Comment 1 Eric Sandeen 2014-11-25 16:52:12 UTC
I'm interested in the image, if you could send it to me via email, or provide it via a link, I'd appreciate it.

(in general it's hard to fix these without access to the image)

If possible, having the un-mangled image as well might help.

Thanks,
-Eric
Comment 2 R.Nageswara Sastry 2014-11-27 08:39:19 UTC
Hello Eric,

Shared .xz file containing mangled, unmangled images via e-mail to you. Hope ~3MB attachment won't hurt your mail box.

Regards
R.Nageswara Sastry
Comment 3 R.Nageswara Sastry 2014-11-28 07:50:28 UTC
Ran the same image against 3.18.0-rc6 and seeing a different stack trace.



[  178.912356] loop: module loaded
[  179.655537] SGI XFS with ACLs, security attributes, no debug enabled
[  179.659276] XFS (loop0): Mounting V4 Filesystem
[  179.763281] XFS (loop0): Starting recovery (logdev: internal)
[  179.763351] XFS (loop0): log record CRC mismatch: found 0xbdc26540, expected 0xda046ed1.
[  179.764220] ffffc90001c44000: 00 00 00 01 00 00 00 00 69 01 00 00 bf 07 a8 b4  ........i.......
[  179.765062] ffffc90001c44010: 00 00 00 bf 69 00 00 00 4e 41 52 54 2a 00 00 00  ....i...NART*...
[  179.766630] XFS (loop0): xlog_recover_process_ophdr: bad clientid 0x38
[  179.766641] XFS (loop0): log mount/recovery failed: error -5
[  179.766730] XFS (loop0): log mount failed
[  179.891608] BUG: unable to handle kernel paging request at 0000000004200000
[  179.892016] IP: [<ffffffff811cb206>] anon_vma_clone+0x56/0x140
[  179.892016] PGD 36db5067 PUD 3b64f067 PMD 0 
[  179.892016] Oops: 0000 [#1] SMP 
[  179.892016] Modules linked in: xfs libcrc32c loop bnep bluetooth cfg80211 rfkill ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw nfsd i2c_piix4 ppdev pcspkr parport_pc floppy pvpanic parport serio_raw auth_rpcgss nfs_acl lockd grace sunrpc virtio_blk ata_generic bochs_drm drm_kms_helper ttm drm virtio_pci virtio_ring virtio e1000 pata_acpi ecryptfs encrypted_keys trusted tpm
[  179.892016] CPU: 0 PID: 1061 Comm: run_test Not tainted 3.18.0-rc6 #1
[  179.892016] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
[  179.892016] task: ffff88003d672ee0 ti: ffff88003a990000 task.ti: ffff88003a990000
[  179.892016] RIP: 0010:[<ffffffff811cb206>]  [<ffffffff811cb206>] anon_vma_clone+0x56/0x140
[  179.892016] RSP: 0018:ffff88003a993d50  EFLAGS: 00010286
[  179.892016] RAX: ffff88003611e000 RBX: ffff88003cde0e00 RCX: 0000000180400040
[  179.892016] RDX: 0000000000000040 RSI: 0000000000000000 RDI: 0000000000000246
[  179.892016] RBP: ffff88003a993d90 R08: 0000000000000000 R09: 0000000180400040
[  179.892016] R10: 000000003611e001 R11: ffff8800360c5e00 R12: ffff88003adebf80
[  179.892016] R13: 0000000000000000 R14: 0000000004200000 R15: ffff88003611e000
[  179.892016] FS:  00007f3825a81740(0000) GS:ffff88003fc00000(0000) knlGS:0000000000000000
[  179.892016] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[  179.892016] CR2: 0000000004200000 CR3: 000000003cdc2000 CR4: 00000000000006f0
[  179.892016] Stack:
[  179.892016]  ffff88003b51a860 ffff88003cf61398 0000000000000001 ffff88003cde0e00
[  179.892016]  0000000000000000 ffff88003b51a7e8 ffff88003cf61398 0000000000000000
[  179.892016]  ffff88003a993dd0 ffffffff811cb322 ffff88003a993dc0 ffff88003cde0e00
[  179.892016] Call Trace:
[  179.892016]  [<ffffffff811cb322>] anon_vma_fork+0x32/0x100
[  179.892016]  [<ffffffff8109573e>] copy_process.part.25+0x143e/0x1ba0
[  179.892016]  [<ffffffff81096061>] do_fork+0xe1/0x360
[  179.892016]  [<ffffffff81133d14>] ? __audit_syscall_entry+0xb4/0x110
[  179.892016]  [<ffffffff81021cbc>] ? do_audit_syscall_entry+0x6c/0x70
[  179.892016]  [<ffffffff81023223>] ? syscall_trace_enter_phase1+0x143/0x1a0
[  179.892016]  [<ffffffff81096366>] SyS_clone+0x16/0x20
[  179.892016]  [<ffffffff817485a9>] stub_clone+0x69/0x90
[  179.892016]  [<ffffffff81748269>] ? system_call_fastpath+0x12/0x17
[  179.892016] Code: c0 48 39 c1 4c 8d 60 f0 74 6a 0f 1f 00 48 8b 3d 39 16 de 00 be 00 02 00 00 e8 57 ef 01 00 48 85 c0 49 89 c7 74 5f 4d 8b 74 24 08 <49> 8b 1e 4c 39 eb 74 15 4d 85 ed 0f 85 89 00 00 00 48 8d 7b 08 
[  179.892016] RIP  [<ffffffff811cb206>] anon_vma_clone+0x56/0x140
[  179.892016]  RSP <ffff88003a993d50>
[  179.892016] CR2: 0000000004200000
[  179.934960] ---[ end trace e99c7e9e832add01 ]---
[  234.370435] BUG: unable to handle kernel paging request at 0000000100000009
[  234.371011] IP: [<ffffffff811b7321>] anon_vma_interval_tree_remove+0x141/0x260
[  234.371011] PGD 0 
[  234.371011] Oops: 0000 [#2] SMP 
[  234.371011] Modules linked in: xfs libcrc32c loop bnep bluetooth cfg80211 rfkill ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_
[  179.892016]  [<ffffffff81133d14>] ? __audit_syscall_entry+0xb4/0x110
[  179.892016]  [<ffffffff81021cbc>] ? do_audit_syscall_entry+0x6c/0x70
[  179.892016]  [<ffffffff81023223>] ? syscall_trace_enter_phase1+0x143/0x1a0
[  179.892016]  [<ffffffff81096366>] SyS_clone+0x16/0x20
[  179.892016]  [<ffffffff817485a9>] stub_clone+0x69/0x90
[  179.892016]  [<ffffffff81748269>] ? system_call_fastpath+0x12/0x17
[  179.892016] Code: c0 48 39 c1 4c 8d 60 f0 74 6a 0f 1f 00 48 8b 3d 39 16 de 00 be 00 02 00 00 e8 57 ef 01 00 48 85 c0 49 89 c7 74 5f 4d 8b 74 24 08 <49> 8b 1e 4c 39 eb 74 15 4d 85 ed 0f 85 89 00 00 00 48 8d 7b 08 
[  179.892016] RIP  [<ffffffff811cb206>] anon_vma_clone+0x56/0x140
[  179.892016]  RSP <ffff88003a993d50>
[  179.892016] CR2: 0000000004200000
[  179.934960] ---[ end trace e99c7e9e832add01 ]---
[  234.370435] BUG: unable to handle kernel paging request at 0000000100000009
[  234.371011] IP: [<ffffffff811b7321>] anon_vma_interval_tree_remove+0x141/0x260
[  234.371011] PGD 0 
[  234.371011] Oops: 0000 [#2] SMP 
[  234.371011] Modules linked in: xfs libcrc32c loop bnep bluetooth cfg80211 rfkill ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw nfsd i2c_piix4 ppdev pcspkr parport_pc floppy pvpanic parport serio_raw auth_rpcgss nfs_acl lockd grace sunrpc virtio_blk ata_generic bochs_drm drm_kms_helper ttm drm virtio_pci virtio_ring virtio e1000 pata_acpi ecryptfs encrypted_keys trusted tpm
[  234.371011] CPU: 0 PID: 958 Comm: systemd-logind Tainted: G      D        3.18.0-rc6 #1
[  234.371011] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140709_153950- 04/01/2014
[  234.371011] task: ffff88003cef12c0 ti: ffff880036318000 task.ti: ffff880036318000
[  234.371011] RIP: 0010:[<ffffffff811b7321>]  [<ffffffff811b7321>] anon_vma_interval_tree_remove+0x141/0x260
[  234.371011] RSP: 0000:ffff88003631bb18  EFLAGS: 00010286
[  234.371011] RAX: ffff88003adebf60 RBX: ffff880036a846e0 RCX: 0000000100000001
[  234.371011] RDX: 0000000000000000 RSI: ffff88003cd61080 RDI: ffff88003a54e780
[  234.371011] RBP: ffff88003631bb28 R08: 00007fcf22b85000 R09: 0000000000000000
[  234.371011] R10: ffff88003a54e7a0 R11: ffffea0000eb7ac0 R12: ffff88003a54e780
[  234.371011] R13: ffff88003cd61048 R14: ffff88003a54e790 R15: ffff88003cd61048
[  234.371011] FS:  0000000000000000(0000) GS:ffff88003fc00000(0000) knlGS:0000000000000000
[  234.371011] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[  234.371011] CR2: 0000000100000009 CR3: 000000003aba2000 CR4: 00000000000006f0
[  234.371011] Stack:
[  234.371011]  ffff880036acdd68 ffff880036a846e0 ffff88003631bb88 ffffffff811cb0b4
[  234.371011]  ffff88003631bb58 ffff880036a84678 ffff88003cd61048 ffff880036a846f0
[  234.371011]  ffff88003631bb88 ffff880036acd2e0 00007fcf20e85000 0000000000000000
[  234.371011] Call Trace:
[  234.371011]  [<ffffffff811cb0b4>] unlink_anon_vmas+0x84/0x180
[  234.371011]  [<ffffffff811bbcf8>] free_pgtables+0xa8/0x120
[  234.371011]  [<ffffffff811c6be6>] exit_mmap+0xc6/0x1a0
[  234.371011]  [<ffffffff81094003>] mmput+0x63/0x100
[  234.371011]  [<ffffffff810994bf>] do_exit+0x27f/0xa60
[  234.371011]  [<ffffffff81099d2f>] do_group_exit+0x3f/0xa0
[  234.371011]  [<ffffffff810a552d>] get_signal+0x1dd/0x620
[  234.371011]  [<ffffffff81013547>] do_signal+0x37/0x750
[  234.371011]  [<ffffffff810a42ec>] ? do_send_sig_info+0x6c/0xa0
[  234.371011]  [<ffffffff81013cd1>] do_notify_resume+0x71/0xc0
[  234.371011]  [<ffffffff81748507>] int_signal+0x12/0x17
[  234.371011] Code: 00 00 49 83 c9 01 48 89 10 4d 89 0b 45 31 c9 48 85 c0 75 13 eb 5a 0f 1f 40 00 48 89 50 18 48 8b 00 48 83 e0 fc 74 49 48 8b 48 e0 <48> 8b 51 08 48 2b 11 48 8b b9 98 00 00 00 48 8b 48 10 48 c1 ea 
[  234.371011] RIP  [<ffffffff811b7321>] anon_vma_interval_tree_remove+0x141/0x260
[  234.371011]  RSP <ffff88003631bb18>
[  234.371011] CR2: 0000000100000009
[  234.371011] ---[ end trace e99c7e9e832add02 ]---
[  234.371011] Fixing recursive fault but reboot is needed!
Comment 4 Tomer Barletz 2015-02-10 07:51:50 UTC
(In reply to R.Nageswara Sastry from comment #0)
> While fuzzing xfs with fsfuzzer the following kernel crash occured. Upon
> request mangled fs image will be provided.
> ...

Can you please attach the image to this bug?
Comment 5 R.Nageswara Sastry 2015-02-12 04:18:32 UTC
Created attachment 166531 [details]
xfs mangled fsfuzzer image
Comment 6 R.Nageswara Sastry 2015-02-12 04:19:30 UTC
Hello Tomer,

Attached mangled image to this bug, please find the same at URL
https://bugzilla.kernel.org/attachment.cgi?id=166531

Thanks in advance.
Comment 7 R.Nageswara Sastry 2015-03-02 11:25:48 UTC
Hello, Any updates? Thanks in advance.
Comment 8 Eric Sandeen 2016-09-22 16:24:40 UTC
I'm batch-closing all xfs bugs which are more than 1 year old, sorry about that.

If you still have this issue on a current kernel, please retest and re-open with this information.

Thanks,
-Eric
Comment 9 Eric Sandeen 2016-09-22 16:35:32 UTC
Actually, retestin this one on 4.8.0-rc2, there is no oops:

[155854.345059] XFS (loop0): Mounting V4 Filesystem
[155854.352524] XFS (loop0): Torn write (CRC failure) detected at log block 0x2. Truncating head block from 0x1f.
[155854.366327] XFS (loop0): Metadata corruption detected at xfs_inode_buf_verify+0x7c/0xe0 [xfs], xfs_inode block 0x40
[155854.376841] XFS (loop0): Unmount and run xfs_repair
[155854.381804] XFS (loop0): First 64 bytes of corrupted metadata buffer:
[155854.388320] ffff880078e02000: 49 4e 41 ed 02 02 00 00 00 00 00 00 00 00 00 00  INA.............
[155854.397088] ffff880078e02010: 00 00 00 02 00 00 00 00 00 00 00 00 00 00 00 01  ................
[155854.405855] ffff880078e02020: 00 00 00 00 00 00 00 00 54 6d 9a 84 12 5b b5 00  ........Tm...[..
[155854.414629] ffff880078e02030: 54 6d 9a 84 12 5b b5 00 00 00 00 00 00 00 10 00  Tm...[..........
[155854.423409] XFS (loop0): metadata I/O error: block 0x40 ("xfs_trans_read_buf_map") error 117 numblks 16
[155854.432891] XFS (loop0): xfs_imap_to_bp: xfs_trans_read_buf() returned error -117.
[155854.440543] XFS (loop0): failed to read root inode

Note You need to log in before you can comment on or make changes to this bug.