Bug 1397513

Summary: xfsdump triggers "kernel BUG at ./include/linux/mm.h:445!"
Product: [Fedora] Fedora Reporter: Jason Tibbitts <j>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 24CC: cz172638, esandeen, gansalmon, ichavero, itamar, jonathan, kernel-maint, madhu.chinakonda, mchehab
Target Milestone: ---Flags: jforbes: needinfo?
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-04-28 17:25:34 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Jason Tibbitts 2016-11-22 16:57:07 UTC
I've received the following oops a couple of times, always when my backups kick off just past midnight.  This leads to a bunch of follow-on oopses.  The machine is still up but disk access just hangs so eventually the machine becomes useless.

When this happens, the machine is practically idle except for the backup run.  There should be no memory pressure; the machine has 64GB of RAM and isn't running anything other than one ssh login and a few shells.

Note that there are a few lines before the actual oops for context some of which I'm pretty sure are important.  I have more complete logs and can provide them if you would like to see them.

Nov 22 00:05:01 epithumia.math.uh.edu systemd[1]: Started Amanda Backup System (129.7.128.43:571).
Nov 22 00:05:03 epithumia.math.uh.edu systemd[1]: Started Process Core Dump (PID 9986/UID 0).
Nov 22 00:05:03 epithumia.math.uh.edu systemd-coredump[9987]: Failed to compress /var/lib/systemd/coredump/.#core.xfsdump.0.160232b14aef47deb209233236226794.9985.1479794703000000000000.lz44b0306156376cc56: Invalid argument
Nov 22 00:05:03 epithumia.math.uh.edu systemd-coredump[9987]: Failed to generate stack trace: invalid `Elf' handle
Nov 22 00:05:03 epithumia.math.uh.edu systemd-coredump[9987]: Process 9985 (xfsdump) of user 0 dumped core.
Nov 22 00:06:01 epithumia.math.uh.edu systemd[1]: Started Usertrack client service (129.7.128.201:55440).
Nov 22 00:06:01 epithumia.math.uh.edu systemd[1]: Started Amanda Backup System (129.7.128.43:571).
Nov 22 00:06:02 epithumia.math.uh.edu systemd[1]: Started Process Core Dump (PID 10084/UID 0).
Nov 22 00:06:02 epithumia.math.uh.edu systemd-coredump[10085]: Failed to compress /var/lib/systemd/coredump/.#core.xfsrestore.33.160232b14aef47deb209233236226794.10079.1479794762000000000000.lz4c8b50cdd84ea01ca: Invalid argument
Nov 22 00:06:02 epithumia.math.uh.edu systemd-coredump[10085]: Failed to generate stack trace: invalid `Elf' handle
Nov 22 00:06:02 epithumia.math.uh.edu systemd-coredump[10085]: Process 10079 (xfsrestore) of user 33 dumped core.
Nov 22 00:06:10 epithumia.math.uh.edu systemd[1]: Started Amanda Backup System (129.7.128.43:585).
Nov 22 00:06:18 epithumia.math.uh.edu systemd[1]: Started Amanda Backup System (129.7.128.43:585).
Nov 22 00:08:01 epithumia.math.uh.edu systemd[1]: Started Usertrack client service (129.7.128.201:55786).
Nov 22 00:10:01 epithumia.math.uh.edu systemd[1]: Started Usertrack client service (129.7.128.201:56132).
Nov 22 00:10:36 epithumia.math.uh.edu systemd-logind[1126]: New session 142 of user tibbs.
Nov 22 00:10:36 epithumia.math.uh.edu systemd[1]: Started Session 142 of user tibbs.
Nov 22 00:12:01 epithumia.math.uh.edu systemd[1]: Started Usertrack client service (129.7.128.201:56480).
Nov 22 00:12:12 epithumia.math.uh.edu systemd[1]: Started Amanda Backup System (129.7.128.43:585).
Nov 22 00:12:13 epithumia.math.uh.edu kernel: page:ffffea0000326180 count:0 mapcount:0 mapping:          (null) index:0x0
Nov 22 00:12:13 epithumia.math.uh.edu kernel: flags: 0x1ffffc00000000()
Nov 22 00:12:13 epithumia.math.uh.edu kernel: page dumped because: VM_BUG_ON_PAGE(page_ref_count(page) == 0)
Nov 22 00:12:13 epithumia.math.uh.edu kernel: ------------[ cut here ]------------
Nov 22 00:12:13 epithumia.math.uh.edu kernel: kernel BUG at ./include/linux/mm.h:445!
Nov 22 00:12:13 epithumia.math.uh.edu kernel: invalid opcode: 0000 [#1] SMP
Nov 22 00:12:13 epithumia.math.uh.edu kernel: Modules linked in: snd_usb_audio snd_usbmidi_lib snd_rawmidi nfsv3 nfsv4 dns_resolver nfs fscache rfcomm cts rpcsec_gss_krb5 nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack cmac bnep nct6775 hwmon_vid b43 mac80211 intel_rapl snd_hda_codec_realtek sb_edac snd_hda_codec_generic edac_core x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_hdmi coretemp vfat fat kvm_intel cfg80211 kvm ssb mmc_core iTCO_wdt iTCO_vendor_support mxm_wmi irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel btusb btrtl intel_cstate btbcm btintel intel_uncore bluetooth intel_rapl_perf rfkill snd_hda_intel snd_hda_codec joydev i2c_i801 snd_hda_core i2c_smbus snd_hwdep snd_seq snd_seq_device igb snd_pcm e1000e snd_timer bcma snd dca mei_me soundcore ptp mei lpc_ich pps_core shpchp fjes wmi tpm_tis
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  tpm_tis_core tpm nfsd nfs_acl lockd auth_rpcgss grace binfmt_misc sunrpc xfs libcrc32c hid_logitech_hidpp hid_logitech_dj amdkfd amd_iommu_v2 radeon i2c_algo_bit drm_kms_helper ttm crc32c_intel drm serio_raw nvme nvme_core uas usb_storage
Nov 22 00:12:13 epithumia.math.uh.edu kernel: CPU: 1 PID: 12234 Comm: xfsdump Not tainted 4.8.6-201.fc24.x86_64 #1
Nov 22 00:12:13 epithumia.math.uh.edu kernel: Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./X99E-ITX/ac, BIOS P3.40 08/03/2016
Nov 22 00:12:13 epithumia.math.uh.edu kernel: task: ffff97c75bf13d00 task.stack: ffff97cde5c00000
Nov 22 00:12:13 epithumia.math.uh.edu kernel: RIP: 0010:[<ffffffff951c1a94>]  [<ffffffff951c1a94>] __free_pages+0x34/0x40
Nov 22 00:12:13 epithumia.math.uh.edu kernel: RSP: 0018:ffff97cde5c03a38  EFLAGS: 00010246
Nov 22 00:12:13 epithumia.math.uh.edu kernel: RAX: 000000000000003e RBX: ffff97c76e25f200 RCX: 0000000000000006
Nov 22 00:12:13 epithumia.math.uh.edu kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff97d39f24e040
Nov 22 00:12:13 epithumia.math.uh.edu kernel: RBP: ffff97cde5c03a38 R08: 0000000000035a75 R09: 0000000000000005
Nov 22 00:12:13 epithumia.math.uh.edu kernel: R10: 0000000000000000 R11: 0000000000000544 R12: 0000000000000001
Nov 22 00:12:13 epithumia.math.uh.edu kernel: R13: ffffffffc060dde6 R14: ffff97cde5c03b28 R15: 0000000000000001
Nov 22 00:12:13 epithumia.math.uh.edu kernel: FS:  00007f08fcb65780(0000) GS:ffff97d39f240000(0000) knlGS:0000000000000000
Nov 22 00:12:13 epithumia.math.uh.edu kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Nov 22 00:12:13 epithumia.math.uh.edu kernel: CR2: 00007f08fb80a000 CR3: 0000000adb50b000 CR4: 00000000003406e0
Nov 22 00:12:13 epithumia.math.uh.edu kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Nov 22 00:12:13 epithumia.math.uh.edu kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Nov 22 00:12:13 epithumia.math.uh.edu kernel: Stack:
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  ffff97cde5c03a60 ffffffffc060cef3 ffff97d393a40900 0000000000000000
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  0000000000010015 ffff97cde5c03aa0 ffffffffc060dde6 ffff97c76e25f200
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  0000000000010015 0000000000000001 0000000000010014 ffff97d393a40900
Nov 22 00:12:13 epithumia.math.uh.edu kernel: Call Trace:
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc060cef3>] xfs_buf_free+0x73/0x130 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc060dde6>] xfs_buf_get_map+0x206/0x250 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc060e7dd>] xfs_buf_read_map+0x2d/0x170 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc060e972>] xfs_buf_readahead_map+0x52/0x70 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc05e1c83>] xfs_btree_reada_bufs+0x63/0x80 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc06239fa>] xfs_bulkstat_ichunk_ra.isra.5+0xea/0x140 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc05defa2>] ? xfs_btree_rec_addr+0x12/0x20 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc0624069>] xfs_bulkstat+0x2e9/0x660 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc0623d50>] ? xfs_bulkstat_one_int+0x300/0x300 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc0618754>] xfs_ioc_bulkstat+0xe4/0x1a0 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffffc061b21d>] xfs_file_ioctl+0x9fd/0xaf0 [xfs]
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffff951cc35a>] ? lru_cache_add+0x3a/0x80
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffff951cc53c>] ? lru_cache_add_active_or_unevictable+0x4c/0xf0
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffff951f556f>] ? handle_mm_fault+0xfaf/0x1420
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffff95264dd3>] do_vfs_ioctl+0xa3/0x5f0
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffff95265399>] SyS_ioctl+0x79/0x90
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  [<ffffffff95802572>] entry_SYSCALL_64_fastpath+0x1a/0xa4
Nov 22 00:12:13 epithumia.math.uh.edu kernel: Code: 48 89 e5 85 c0 74 18 f0 ff 4f 1c 75 09 85 f6 74 07 e8 a1 e1 ff ff 5d c3 e8 1a fd ff ff 5d c3 48 c7 c6 f0 dd c1 95 e8 9c c0 02 00 <0f> 0b 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 85 ff 75 
Nov 22 00:12:13 epithumia.math.uh.edu kernel: RIP  [<ffffffff951c1a94>] __free_pages+0x34/0x40
Nov 22 00:12:13 epithumia.math.uh.edu kernel:  RSP <ffff97cde5c03a38>

Comment 1 Eric Sandeen 2016-11-22 22:57:53 UTC
Ok Jason said he had 2 instances of this.  Just for reference:

First page dump:

page:ffffea003f6aed80 count:0 mapcount:0 mapping:          (null) index:0x1
flags: 0x2ffffc00000000()

Second page dump:

page:ffffea0000326180 count:0 mapcount:0 mapping:          (null) index:0x0
flags: 0x1ffffc00000000()

Comment 2 Justin M. Forbes 2017-04-11 15:01:01 UTC
*********** MASS BUG UPDATE **************

We apologize for the inconvenience.  There are a large number of bugs to go through and several of them have gone stale.  Due to this, we are doing a mass bug update across all of the Fedora 24 kernel bugs.

Fedora 25 has now been rebased to 4.10.9-100.fc24.  Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel.

If you have moved on to Fedora 26, and are still experiencing this issue, please change the version to Fedora 26.

If you experience different issues, please open a new bug report for those.

Comment 3 Justin M. Forbes 2017-04-28 17:25:34 UTC
*********** MASS BUG UPDATE **************
This bug is being closed with INSUFFICIENT_DATA as there has not been a response in 2 weeks. If you are still experiencing this issue, please reopen and attach the 
relevant data from the latest kernel you are running and any data that might have been requested previously.