Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

panic in xfs_trans_free_items -- null pointer #2592

Open
grepory opened this issue Jun 10, 2019 · 8 comments

Comments

Projects
None yet
2 participants
@grepory
Copy link

commented Jun 10, 2019

Issue Report

Bug

We're seeing panics in the XFS write path during page faults. This is on hosts running Cassandra in a fairly large C* cluster. So, in general, these are writes to mmap'd files on a large XFS partition (~3.5TB).

oops/panic pstore logs here: https://gist.github.com/grepory/cf0972eacf257ea4a3a4986589708d6a

These hosts were previously running CentOS with the same version of Cassandra/JVM and firmware without issue. They were recently reprovisioned with CoreOS and have since begun panicking.

There are two stack traces that we've observed:

<0>[287043.255988] watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [java:38791]
<4>[287043.263041] Modules linked in: mpt3sas raid_class scsi_transport_sas mptctl mptbase falco_probe(OE) xt_nat veth dell_rbu ipt_MASQUERADE nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo iptable_nat nf_nat_ipv4 xt_addrtype iptable_filter xt_conntrack nf_nat br_netfilter bridge stp llc overlay nls_ascii nls_cp437 vfat fat xfs ipmi_ssif coretemp x86_pkg_temp_thermal kvm_intel kvm evdev iTCO_wdt mei_me iTCO_vendor_support dcdbas mei irqbypass i2c_i801 ipmi_si ipmi_devintf ipmi_msghandler bonding pcc_cpufreq button sch_fq_codel nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c ext4 crc32c_generic crc16 mbcache jbd2 fscrypto dm_verity dm_bufio sd_mod crc32c_intel aesni_intel xhci_pci aes_x86_64 ahci crypto_simd igb libahci xhci_hcd cryptd glue_helper megaraid_sas i2c_algo_bit libata ixgbe i2c_core
<4>[287043.334625]  usbcore hwmon scsi_mod mdio usb_common dm_mirror dm_region_hash dm_log dm_mod
<4>[287043.343536] CPU: 1 PID: 38791 Comm: java Tainted: G           OE     4.19.34-coreos #1
<4>[287043.352097] Hardware name: Dell Inc. PowerEdge R740xd/00WGD1, BIOS 2.1.8 04/30/2019
<4>[287043.360415] RIP: 0010:xfs_log_commit_cil+0xbd/0x610 [xfs]
<4>[287043.366222] Code: 89 41 20 49 8b 44 24 10 48 39 c3 4c 8d 60 f0 0f 84 f5 00 00 00 c7 44 24 40 00 00 00 00 c7 44 24 44 00 00 00 00 49 8b 44 24 40 <a8> 08 74 d5 49 8b 44 24 68 48 8d 54 24 44 48 8d 74 24 40 4c 89 e7
<4>[287043.385868] RSP: 0000:ffffb9c1a456fc28 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13
<4>[287043.394086] RAX: 0000000000000001 RBX: ffffa032ff650f30 RCX: ffffa032e1e6da00
<4>[287043.401866] RDX: 0000000000000150 RSI: 0000000000000064 RDI: 0000000000000064
<4>[287043.409648] RBP: ffffa032ff650e80 R08: 0000000129a6a4a4 R09: 0000000000000001
<4>[287043.417422] R10: 0000000000001000 R11: ffffb9c1a456fc90 R12: ffffa002c4381980
<4>[287043.425198] R13: ffffa0333118ec00 R14: 0000000000000000 R15: 00000000000001b8
<4>[287043.432971] FS:  00007fdfde9b6700(0000) GS:ffffa0333f000000(0000) knlGS:0000000000000000
<4>[287043.441698] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[287043.447852] CR2: 00007fc4ef86e7ee CR3: 0000005efeab4005 CR4: 00000000007606e0
<4>[287043.455635] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[287043.463417] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[287043.471198] PKRU: 55555554
<4>[287043.474309] Call Trace:
<4>[287043.477175]  ? xfs_iomap_write_unwritten+0x71d/0xdc0 [xfs]
<4>[287043.483080]  xfs_trans_free_items+0x1a7/0x450 [xfs]
<4>[287043.488377]  xfs_iomap_write_unwritten+0x71d/0xdc0 [xfs]
<4>[287043.494099]  file_update_time+0xe0/0x130
<4>[287043.498438]  xfs_extent_busy_ag_cmp+0xff0/0x1240 [xfs]
<4>[287043.503988]  do_page_mkwrite+0x30/0x90
<4>[287043.508144]  __handle_mm_fault+0xcbf/0x1180
<4>[287043.512737]  handle_mm_fault+0xdc/0x210
<4>[287043.516985]  __do_page_fault+0x243/0x4c0
<4>[287043.521321]  ? page_fault+0x8/0x30
<4>[287043.525128]  page_fault+0x1e/0x30
<4>[287043.528847] RIP: 0033:0x7fe146aeb009
<4>[287043.532826] Code: 8b 5b 18 2b cb 83 f9 04 0f 8c c8 09 00 00 41 0f b6 4b 2a 85 c9 0f 85 3c 04 00 00 44 8b 4c 24 3c 41 0f c9 49 8b 4b 10 48 63 fb <44> 89 0c 39 83 c3 04 41 89 5b 18 8b 7c 24 3c 44 8b cf 41 c1 e9 18
<4>[287043.552471] RSP: 002b:00007fdfde9b5580 EFLAGS: 00010246
<4>[287043.558104] RAX: 00000001c3ad6940 RBX: 000000000042b7ee RCX: 00007fc4ef443000
<4>[287043.565888] RDX: 00000000f8007ee2 RSI: 0000000000000fff RDI: 000000000042b7ee
<4>[287043.573669] RBP: 00000001c3ad68d0 R08: 000000003875ad1a R09: 0000000064000000
<4>[287043.581444] R10: 00000001c3ad6910 R11: 00000001c3ad68d0 R12: 0000000000000000
<4>[287043.589218] R13: 00000001c3ad68b0 R14: 00000003222b1100 R15: 00007fe0a8c32800
<0>[287043.596991] Kernel panic - not syncing: softlockup: hung tasks

and

<1>[213826.307823] BUG: unable to handle kernel NULL pointer dereference at 0000000000000037
<6>[213826.315823] PGD 8000005f6f888067 P4D 8000005f6f888067 PUD 5f7031f067 PMD 0
<4>[213826.322956] Oops: 0000 [#1] SMP PTI
<4>[213826.326616] CPU: 82 PID: 18288 Comm: java Tainted: G           OE     4.19.34-coreos #1
<4>[213826.334784] Hardware name: Dell Inc. PowerEdge R740xd/00WGD1, BIOS 2.1.8 04/30/2019
<4>[213826.342637] RIP: 0010:xfs_trans_free_items+0x70/0x450 [xfs]
<4>[213826.348383] Code: 63 40 f7 48 8b 4b 10 48 8b 53 18 49 83 fc ff 48 89 51 08 48 89 0a 48 89 43 10 48 89 43 18 74 13 48 8b 43 68 4c 89 e6 48 89 df <48> 8b 40 38 e8 87 4a f8 d8 45 84 ed 74 05 f0 41 80 0f 02 48 8b 43
<4>[213826.367319] RSP: 0000:ffffa61f1113fbf0 EFLAGS: 00010217
<4>[213826.372936] RAX: ffffffffffffffff RBX: ffff8bc8bb981660 RCX: ffff8bc8bb981670
<4>[213826.380682] RDX: ffff8bc8bb981670 RSI: 000000000004b598 RDI: ffff8bc8bb981660
<4>[213826.388430] RBP: ffff8bc8bb981660 R08: 00003a55c022d820 R09: ffffffffc0a833db
<4>[213826.396187] R10: ffffa61f1113fc28 R11: 0000000000000000 R12: 000000000004b598
<4>[213826.403935] R13: 0000000000000000 R14: ffff8b96407ab1e8 R15: ffff8bc8bb9816a0
<4>[213826.411692] FS:  00007ef72b2fb700(0000) GS:ffff8b9901040000(0000) knlGS:0000000000000000
<4>[213826.420400] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[213826.426546] CR2: 0000000000000037 CR3: 0000005f38062002 CR4: 00000000007606e0
<4>[213826.434291] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[213826.442048] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[213826.449798] PKRU: 55555554
<4>[213826.452898] Call Trace:
<4>[213826.455768]  xfs_log_commit_cil+0x48e/0x610 [xfs]
<4>[213826.460879]  ? xfs_iomap_write_unwritten+0x71d/0xdc0 [xfs]
<4>[213826.466771]  xfs_trans_free_items+0x1a7/0x450 [xfs]
<4>[213826.472057]  xfs_iomap_write_unwritten+0x71d/0xdc0 [xfs]
<4>[213826.477770]  file_update_time+0xe0/0x130
<4>[213826.482101]  xfs_extent_busy_ag_cmp+0xff0/0x1240 [xfs]
<4>[213826.487629]  do_page_mkwrite+0x30/0x90
<4>[213826.491769]  __handle_mm_fault+0xcbf/0x1180
<4>[213826.496345]  handle_mm_fault+0xdc/0x210
<4>[213826.500577]  __do_page_fault+0x243/0x4c0
<4>[213826.504891]  ? page_fault+0x8/0x30
<4>[213826.508687]  page_fault+0x1e/0x30
<4>[213826.512397] RIP: 0033:0x7f28cc297138
<4>[213826.516364] Code: 8b 43 18 41 2b c8 83 f9 04 0f 8c c0 09 00 00 0f b6 4b 2a 85 c9 0f 85 8e 03 00 00 44 8b 4c 24 3c 41 0f c9 48 8b 4b 10 49 63 d0 <44> 89 0c 11 41 83 c0 04 44 89 43 18 8b 4c 24 3c 44 8b c9 41 c1 e9
<4>[213826.535957] RSP: 002b:00007ef72b2fa590 EFLAGS: 00010246
<4>[213826.541574] RAX: 00000001ebb73a68 RBX: 00000001ebb739f8 RCX: 00007e2d3224d000
<4>[213826.549322] RDX: 00000000016965bb RSI: 0000000000002002 RDI: 00000000f8007ee2
<4>[213826.557069] RBP: 00000001ebb739f8 R08: 00000000016965bb R09: 0000000064000000
<4>[213826.564817] R10: 00000001ebb73a38 R11: 000000003d76e73f R12: 0000000000000000
<4>[213826.572565] R13: 00000001ebb739d8 R14: 0000000315e30808 R15: 00007f289542e800
<4>[213826.580313] Modules linked in: sg binfmt_misc mpt3sas raid_class scsi_transport_sas mptctl mptbase falco_probe(OE) veth dell_rbu xt_nat ipt_MASQUERADE nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo iptable_nat nf_nat_ipv4 xt_addrtype iptable_filter xt_conntrack nf_nat br_netfilter bridge stp llc overlay nls_ascii nls_cp437 vfat fat xfs ipmi_ssif coretemp x86_pkg_temp_thermal kvm_intel evdev iTCO_wdt dcdbas iTCO_vendor_support kvm irqbypass ipmi_si bonding mei_me i2c_i801 ipmi_devintf mei ipmi_msghandler pcc_cpufreq button sch_fq_codel nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c ext4 crc32c_generic crc16 mbcache jbd2 fscrypto dm_verity dm_bufio sd_mod crc32c_intel aesni_intel aes_x86_64 ahci xhci_pci crypto_simd cryptd xhci_hcd libahci glue_helper igb libata megaraid_sas i2c_algo_bit
<4>[213826.653368]  ixgbe usbcore i2c_core hwmon scsi_mod mdio usb_common dm_mirror dm_region_hash dm_log dm_mod
<4>[213826.663555] CR2: 0000000000000037
<4>[213826.667292] ---[ end trace b23585326c60c5ea ]---

Container Linux Version

NAME="Container Linux by CoreOS"
ID=coreos
VERSION=2079.3.0
VERSION_ID=2079.3.0
BUILD_ID=2019-04-22-2119
PRETTY_NAME="Container Linux by CoreOS 2079.3.0 (Rhyolite)"
ANSI_COLOR="38;5;75"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://issues.coreos.com"
COREOS_BOARD="amd64-usr"

Environment

We are running on a mixture of Dell PowerEdge r730's and r740xd's

Reproduction Steps

I have tried a number of configurations of fio to try to reproduce this, but have failed miserably. I also have not seen this behavior with Cassandra on a single node running cassandra-stress against it. It's very probably related to the load these machines are under (load averages ~50 on machines with 2 cpus x 12 cores (the r730s) or 2 cpus x 22 cores (r740s). Hyperthreading is enabled.

@ajeddeloh

This comment has been minimized.

Copy link

commented Jun 10, 2019

Thanks for the report.

Do you know if older versions had this problem (i.e. the problem is new with 2079.3.0) or is this the only version you've ran?

You're on a slightly out of date version of CL; you should update to the latest stable and see if the issue persists. You also might try alpha, as it has a newer kernel that might have a fix. If it does, that makes the problem much easier to track down and fix.

@grepory

This comment has been minimized.

Copy link
Author

commented Jun 10, 2019

@grepory

This comment has been minimized.

Copy link
Author

commented Jun 11, 2019

We are working on updating CoreOS to try a newer kernel version. For some additional context, prior to running CoreOS they were CentOS with kernel versions:

3.10.0-862.9.1.el7.x86_64
3.10.0-862.3.3.el7.x86_64

I know it’s kind of apples and oranges outside of the kernel, but wanted to make a note of that.

@grepory

This comment has been minimized.

Copy link
Author

commented Jun 12, 2019

It appears that this was introduced sometime between

4.14.96-coreos-r1 (1967.6.0) and 4.19.34-coreos (2079.3.0). The machines with the earlier OS / kernel version are not panicking.

@ajeddeloh

This comment has been minimized.

Copy link

commented Jun 12, 2019

Can you narrow it down to set of consecutive alpha releases (they release every two weeks roughly, so the version spread will be smaller)? We can't really repro it without your hardware/workload.

@grepory

This comment has been minimized.

Copy link
Author

commented Jun 12, 2019

Yeah. We don’t really know how to install specific versions of CoreOS. I only saw some user group posts discussing it and that it requires the enterprise management stuff. If you can give us some guidance on how to install specific versions that would be helpful.

Also, if you know how to make the kernel dump core, I would appreciate being able to dig in a bit deeper. Can I just add a systemd-coredump service unit?

@ajeddeloh

This comment has been minimized.

Copy link

commented Jun 12, 2019

If you're using the coreos-install script, you can use the -V flag to specify versions (see a list at https://coreos.com/releases). See https://coreos.com/os/docs/latest/installing-to-disk.html.

As for getting kernel core dumps I'm not sure. Looks like we do ship the kdump tool, so maybe look into that?

Hope that helps.

@grepory

This comment has been minimized.

Copy link
Author

commented Jun 13, 2019

We're working on rolling back to a known working version of CoreOS (1967.6.0).

I haven't been able to get a crash kernel to work or obtain a core dump, but I am starting to look into diffs between 4.14.96 and 4.19.34. I dug through the patches CoreOS applied to the kernel between these two releases, but I found nothing changed along the path where our crashes are happening.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.