Introduction and Problem Description

In the world of IT administration, one of the most frustrating things is not knowing the root cause of an issue. This is particularly true when it comes to kernel panics, which can cause servers to freeze (or, if configured, reboot automatically) without providing any valuable information about what has led to the problem. During a kernel panic, the server screen is often the only place where the final portion of logs ends up, because the system log daemon instantly becomes inoperative. For croit PXE booted Ceph servers, this problem is particularly acute, because these servers are configured to reboot automatically on panic – which is a useful feature to keep the cluster up and running, but such automatic reboots erase the panic messages from the screen.

In this blog article, we will discuss how to use the netconsole kernel module to configure your croit PXE booted Ceph servers to capture and log kernel panics to a different server, enabling you to more easily diagnose and resolve issues. Even if you’re not using croit, this article can provide helpful guidance for using netconsole in other use cases as well.

A brief explanation of kernel crash logs

A crash log is a record of events that occurred leading up to a system crash or error. It can provide valuable information for diagnosing and resolving issues. The kernel panic or oops messages contain the function call stack at the time of the crash, the hex dump of the machine code that the CPU was trying to execute, the contents of all CPU registers, the kernel modules involved, and other potentially useful information for debugging.

Here is one relatively short example of a crash in a WiFi driver on a desktop Linux system

[   27.868370] BUG: kernel NULL pointer dereference, address: 00000000000000a8
[   27.868379] #PF: supervisor write access in kernel mode
[   27.868382] #PF: error_code(0x0002) - not-present page
[   27.868384] PGD 0 P4D 0
[   27.868387] Oops: 0002 [#1] PREEMPT SMP PTI
[   27.868400] CPU: 1 PID: 613 Comm: napi/phy0-323 Not tainted 6.1.3-zen1-1-zen #1 e84ae47f4a6d6b4d7d2701d8d72f471c5f76a3ff
[   27.868404] Hardware name: MSI MS-7851/Z87I (MS-7851), BIOS V1.9 05/15/2015
[   27.868406] RIP: 0010:ieee80211_deliver_skb+0x4c/0x1a0 [mac80211]
[   27.868465] Code: 00 00 8b 55 70 49 8b 85 50 05 00 00 65 48 03 05 0a 63 34 3e 48 01 50 08 48 ff 00 48 83 7b 28 00 74 11 48 8b 43 30 48 63 53 44 <48> 83 84 d0 a8 00 00 00 01 8b 87 e8 11 00 00 8d 50 fd 83 fa 01 0f
[   27.868468] RSP: 0018:ffffbbb3c0917ae8 EFLAGS: 00010286
[   27.868470] RAX: 0000000000000000 RBX: ffffbbb3c0917c90 RCX: 0000000000000008
[   27.868472] RDX: 0000000000000000 RSI: ffffa0eaaece064e RDI: ffffa0ea895109c0
[   27.868474] RBP: ffffa0eaabc4f000 R08: 000000000000003b R09: 0000000000000171
[   27.868476] R10: 0000000000000171 R11: 0000000000000000 R12: 0000000000004000
[   27.868488] R13: ffffa0ea89510000 R14: 0000000000004288 R15: ffffa0eaabc4f000
[   27.868490] FS:  0000000000000000(0000) GS:ffffa0ed4f640000(0000) knlGS:0000000000000000
[   27.868493] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   27.868548] CR2: 00000000000000a8 CR3: 00000002bf210006 CR4: 00000000001706e0
[   27.868550] Call Trace:
[   27.868554]  
[   27.868557]  __ieee80211_rx_h_amsdu+0x22f/0x5b0 [mac80211 5aa547b8289f4567c72ef207cdf47dd6bfda0f0f]
[   27.868621]  ? ieee80211_prepare_and_rx_handle+0x1384/0x1cb0 [mac80211 5aa547b8289f4567c72ef207cdf47dd6bfda0f0f]
[   27.868671]  ieee80211_prepare_and_rx_handle+0x1384/0x1cb0 [mac80211 5aa547b8289f4567c72ef207cdf47dd6bfda0f0f]
[   27.868721]  ieee80211_rx_list+0xa42/0xd70 [mac80211 5aa547b8289f4567c72ef207cdf47dd6bfda0f0f]
[   27.868763]  mt76_rx_complete+0x207/0x2e0 [mt76 778938866a7f3ea5ea095213dfa0e7b90189f510]
[   27.868773]  mt76_rx_poll_complete+0x356/0x580 [mt76 778938866a7f3ea5ea095213dfa0e7b90189f510]
[   27.868781]  ? mt76_dma_rx_fill.isra.0+0x1a0/0x220 [mt76 778938866a7f3ea5ea095213dfa0e7b90189f510]
[   27.868788]  mt76_dma_rx_poll+0x397/0x500 [mt76 778938866a7f3ea5ea095213dfa0e7b90189f510]
[   27.868797]  ? __napi_poll+0x190/0x190
[   27.868801]  __napi_poll+0x2b/0x190
[   27.868805]  napi_threaded_poll+0x157/0x170
[   27.868810]  kthread+0xde/0x110
[   27.868814]  ? kthread_complete_and_exit+0x20/0x20
[   27.868817]  ret_from_fork+0x22/0x30
[   27.868823]  
[   27.868824] Modules linked in: xt_conntrack xt_MASQUERADE nf_conntrack_netlink xt_addrtype iptable_filter br_netfilter cmac ccm tun nft_reject_ipv4 nf_reject_ipv4 nft_reject nft_ct nft_masq nft_chain_nat nf_tables nfnetlink nf_nat_h323 nf_conntrack_h323 nf_nat_pptp nf_conntrack_pptp nf_nat_tftp nf_conntrack_tftp nf_nat_sip nf_conntrack_sip nf_nat_irc nf_conntrack_irc nf_nat_ftp nf_conntrack_ftp iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 netconsole bridge stp llc xt_TCPMSS xt_policy xt_tcpudp iptable_mangle snd_hda_codec_realtek intel_rapl_msr snd_hda_codec_generic ledtrig_audio intel_rapl_common snd_hda_codec_hdmi x86_pkg_temp_thermal mt76x2e snd_hda_intel spi_nor intel_powerclamp mt76x2_common uvcvideo snd_intel_dspcfg coretemp mt76x02_lib snd_intel_sdw_acpi mtd videobuf2_vmalloc videobuf2_memops mt76 kvm_intel iTCO_wdt videobuf2_v4l2 snd_hda_codec mac80211 videobuf2_common mei_pxp kvm mei_hdcp snd_hda_core intel_pmc_bxt irqbypass snd_usb_audio snd_usbmidi_lib
[   27.868860]  snd_rawmidi spi_intel_platform libarc4 videodev snd_hwdep spi_intel mei_me rapl at24 snd_seq_device r8169 iTCO_vendor_support cfg80211 i2c_i801 realtek intel_cstate snd_pcm snd_timer mc i2c_smbus mdio_devres mei intel_uncore snd rfkill mxm_wmi pcspkr soundcore libphy lpc_ich joydev mousedev mac_hid dm_multipath sg crypto_user fuse bpf_preload ip_tables x_tables btrfs blake2b_generic libcrc32c crc32c_generic xor raid6_pq usbhid dm_crypt cbc encrypted_keys trusted asn1_encoder tee dm_mod crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic gf128mul ghash_clmulni_intel sha512_ssse3 aesni_intel crypto_simd sr_mod cryptd xhci_pci cdrom xhci_pci_renesas nls_iso8859_1 nls_utf8 vfat fat i915 drm_buddy intel_gtt video wmi drm_display_helper cec ttm
[   27.868903] CR2: 00000000000000a8
[   27.868905] ---[ end trace 0000000000000000 ]---
[   27.868907] RIP: 0010:ieee80211_deliver_skb+0x4c/0x1a0 [mac80211]
[   27.868936] Code: 00 00 8b 55 70 49 8b 85 50 05 00 00 65 48 03 05 0a 63 34 3e 48 01 50 08 48 ff 00 48 83 7b 28 00 74 11 48 8b 43 30 48 63 53 44 <48> 83 84 d0 a8 00 00 00 01 8b 87 e8 11 00 00 8d 50 fd 83 fa 01 0f
[   27.868938] RSP: 0018:ffffbbb3c0917ae8 EFLAGS: 00010286
[   27.868940] RAX: 0000000000000000 RBX: ffffbbb3c0917c90 RCX: 0000000000000008
[   27.868942] RDX: 0000000000000000 RSI: ffffa0eaaece064e RDI: ffffa0ea895109c0
[   27.868945] RBP: ffffa0eaabc4f000 R08: 000000000000003b R09: 0000000000000171
[   27.868948] R10: 0000000000000171 R11: 0000000000000000 R12: 0000000000004000
[   27.868950] R13: ffffa0ea89510000 R14: 0000000000004288 R15: ffffa0eaabc4f000
[   27.868952] FS:  0000000000000000(0000) GS:ffffa0ed4f640000(0000) knlGS:0000000000000000
[   27.868954] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   27.868956] CR2: 00000000000000a8 CR3: 00000002bf210006 CR4: 00000000001706e0
[   27.868958] Kernel panic - not syncing: Fatal exception in interrupt
[   27.869243] Kernel Offset: 0x32000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[   27.869257] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---

Solution

The croit OS images provide a kernel command line parameter, panic=45, that reboots the server automatically within 45 seconds after detecting any fatal issue like a panic or hard-lockup. To debug such issues, a kernel developer would require logs related to the crash, which croit cannot collect by normal means. In this case, configuring netconsole helps capture the fatal kernel crash logs to a file.

Setting up netconsole involves two parts: a UDP listener in the croit container, and a hook script that configures the kernel to send the logs to the listener even during a panic. To set up a UDP listener, run the following command in the container:

nohup socat -u udp-recv:4444 /tmp/netconsole.log < /dev/null > /dev/null 2>&1 &

This command forwards all log lines received over UDP port 4444 to /tmp/netconsole.log. Unfortunately, no information is retained about which system produced each log line, but the server with the lowest uptime is generally the most recently crashed one.

To set up the sender, create a hook script named “Netconsole setup” with the Hooks set to PostNetworkConfig. This script should be run on all potentially problematic servers. The script should include the following code, which can be modified as per the environment:

#!/bin/bash
LOCAL_PORT=4444
LOCAL_IFACE="bond0"
LOCAL_IP=$(ip -f inet -json addr list | jq -r '.[] | select(.ifname=="bond0") | .addr_info[].local' | head -n 1)
REMOTE_PORT=4444
REMOTE_IP="10.1.6.130"
REMOTE_MAC="4e:d2:11:f8:26:cc"
modprobe netconsole netconsole=${LOCAL_PORT}@${LOCAL_IP}/${LOCAL_IFACE},${REMOTE_PORT}@${REMOTE_IP}/${REMOTE_MAC}

In the above code, replace the variables with the correct values for your local network setup.

REMOTE_IP is the croit container IP. Similarly, REMOTE_MAC is the MAC address of the network adapter on the croit management host if it is on the same network; otherwise, it should be replaced with the gateway MAC address. Although the script can be improved to auto-detect the aforementioned values, it has not been implemented thus far.

When the netconsole module gets loaded, it sends all kernel messages from the ring buffer to the configured remote server over UDP. Then, any newly produced kernel log lines are also sent over the network.

After a server crashes, inspect /tmp/netconsole.log in the croit container. It will most likely contain the final kernel logs that could not be saved otherwise. If the log is too large to inspect manually, search for “RIP:”. As you can see from the previously provided example of the panic, this will produce a match close enough to the beginning of the panic message.

Cleaning up

To clean up the netconsole setup, follow these steps:

Delete the hook script by unchecking the “all servers” box and selecting no servers, or simply delete the hook script.
Create and run a temporary hook script to remove the netconsole module:
#!/bin/bash
rmmod netconsole
Execute the temporary hook script on all servers that were previously set up with netconsole.
In the croit container, stop the UDP listener by running the command:
pkill socat
Finally, remove the log file by running:
rm /tmp/netconsole.log

What to Do If It Doesn’t Help

In the event that netconsole fails to collect any logs, double-check that the replaceable parameters were replaced correctly. Manually inspect one server and verify that the dmesg output shows the correct configuration parameters. It should resemble the following:

[ 48.537509] netpoll: netconsole: local port 4444
[ 48.538171] netpoll: netconsole: local IPv4 address 10.1.6.158
[ 48.538817] netpoll: netconsole: interface 'bond0'
[ 48.539466] netpoll: netconsole: remote port 4444
[ 48.540084] netpoll: netconsole: remote IPv4 address 10.1.6.130
[ 48.540677] netpoll: netconsole: remote ethernet address 4e:d2:11:f8:26:cc
[ 48.546404] printk: console [netcon0] enabled
[ 48.546977] netconsole: network logging started

If there are logs present but no kernel panic or hard lockup, it may not be a kernel issue. In this case, use ipmitool to determine the cause of the reboot.

Final words

A kernel panic is always a bug in the kernel. The only right solution is to update the kernel to a version that includes the fix, or maybe temporarily revert to an older version that doesn’t yet include the bug. Having the crash messages captured with netconsole is what allows kernel developers to fix the bug promptly.

How to capture kernel panic messages with netconsole