This article explains how to check the actual trigger & RCA for system abnormal shutdown log messages during auto reboot of the device.
Need to check the version, configurations & collect vmhost kernel logs to proceed accordingly.
When node has auto rebooted silently, we see abnormal shut down log messages before which no any other logged, sometimes the same issue happens repeatedly.
++++++++++++log-messages++++++++++++++++
>>>>>>>>>>>>>1st instant >>>>>>>>>>>>>>>>>
Jun 7 07:46:21 PE_R1 eventd: sendto: No route to host
Jun 7 07:46:21 PE_R1 eventd[20014]: SYSTEM_SHUTDOWN: System <unknown> by <unknown> at <unknown>: no message
Jun 7 07:46:21 PE_R1 eventd[20014]: SYSTEM_OPERATIONAL: System is operational
Jun 7 07:46:21 PE_R1 kernel: ---<<BOOT>>---
Jun 7 07:46:21 PE_R1 kernel: Copyright (c) 1998-2023 Juniper Networks, Inc.
Jun 7 07:46:21 PE_R1 kernel: Copyright (c) 1992-2020 The FreeBSD Project.
Jun 7 07:46:21 PE_R1 kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Jun 7 07:46:21 PE_R1 kernel: The Regents of the University of California. All rights reserved.
Jun 7 07:46:21 PE_R1 kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Jun 7 07:46:21 PE_R1 kernel: FreeBSD JNPR-12.1-20230531.cf35cdf_builder_stable_12_222 #0 r356482+cf35cdf2889(stable/12_222): Thu Jun 22 02:48:48 PDT 2023
Jun 7 07:46:21 PE_R1 kernel: builder@qnc-jre-fbsd01:/volume/build/junos/occam/llvm-10.0/sandbox-222-20230531-cf35cdf/freebsd/stable_12_222/20230531.200057_builder_stable_12_222.cf35cdf/obj/amd64/juniper/kernels/JNPR-AMD64-PRD/kernel
amd64
Jun 7 07:46:21 PE_R1 kernel: Juniper clang version 10.0.1 ([email protected]:tools-tot/llvm 477a470596099ea324b061842debb3f9707ee902)
Jun 7 07:46:21 PE_R1 kernel: VT(vga): text 80x25
Jun 7 07:46:21 PE_R1 kernel: module crypto already present!
Jun 7 07:46:21 PE_R1 kernel: CPU: QEMU Virtual CPU version 2.5+ (1600.04-MHz K8-class CPU)
Jun 7 07:46:21 PE_R1 kernel: ioapic0 <Version 1.1> irqs 0-23 on motherboard
Jun 7 07:46:21 PE_R1 kernel: random: entropy device external interface
Jun 7 07:46:21 PE_R1 kernel: Creating PCI Scan thread
Jun 7 07:46:21 PE_R1 kernel: pcidev module loaded, 0 (null)
>>>>>>>>>>>2nd instant >>>>>>>>>>>>>>>>>>
Jun 15 15:15:41 PE_R1 eventd[20014]: SYSTEM_ABNORMAL_SHUTDOWN: System abnormally shut down
Jun 15 15:15:41 PE_R1 eventd[20014]: SYSTEM_OPERATIONAL: System is operational
Jun 15 15:15:41 PE_R1 kernel: ---<<BOOT>>---
Jun 15 15:15:41 PE_R1: FreeBSD is a registered trademark of The FreeBSD Foundation.
Jun 15 15:15:41 PE_R1 kernel: FreeBSD JNPR-12.1-20230531.cf35cdf_builder_stable_12_222 #0 r356482+cf35cdf2889(stable/12_222): Thu Jun 22 02:48:48 PDT 2023
Jun 15 15:15:41 PE_R1 kernel: builder@qnc-jre-fbsd01:/volume/build/junos/occam/llvm-10.0/sandbox-222-20230531-cf35cdf/freebsd/stable_12_222/20230531.200057_builder_stable_12_222.cf35cdf/obj/amd64/juniper/kernels/JNPR-AMD64-PRD/kernel
Jun 15 15:15:41 PE_R1 kernel: CPU: QEMU Virtual CPU version 2.5+ (1600.04-MHz K8-class CPU)
Jun 15 15:15:41 PE_R1 kernel: TSC: P-state invariant
Jun 15 15:15:41 PE_R1 kernel: Hypervisor: Origin = "KVMKVMKVM"
Jun 15 15:15:41 PE_R1 Using default hgcomm API hgcommdev_io_read
Jun 15 15:15:41 PE_R1 kernel: random: entropy device external interface
Jun 15 15:15:41 PE_R1 kernel: Creating PCI Scan thread
Jun 15 15:15:41 PE_R1 kernel: pcidev module loaded, 0 (null)
Need to capture kernel level vmhost logs from customer by using the below steps & check the kernel logs.
lab> start shell user root
root@:/var/home/lab # vhclient -s
root@local-node:~# tar -cf ~/host_VARLOG_RE0.tar -C /var/log/*
root@local-node:~# ls -l | grep varlog
-rw-r--r--. 1 root root 75509760 Jun 08 18:00 host_VARLOG_RE0_2.tar
Copy the file to VM Routing Engine /var/tmp
root@local-node:~# scp host_VARLOG_RE0.tar [email protected]:/var/tmp/host_varlog_RE0_2.tar
100% 68MB 30.0MB/s 00:03
Kernel level logs shared is same as the last time issue occurred:
++++++++++++++vmhost-kernel logs++++++++++++++++++
2024-03-16T04:56:40.541164+07:00 PE_R1-node kernel: High host-mode time vcpu 0 delay 150247 us exit reason IO_INSTRUCTION rip 0xfff0 info 640040 0
2024-06-07T07:42:59.104277+07:00 PE_R1-node kernel: High host-mode time vcpu 0 delay 115395 us exit reason IO_INSTRUCTION rip 0xfff0 info 640040 0
2024-06-07T08:33:41.555253+07:00 PE_R1-node kernel: EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
2024-06-07T08:33:41.602505+07:00 PE_R1-node kernel: EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
2024-06-07T08:33:43.874497+07:00 PE_R1-node kernel: EXT4-fs (sda4): mounted filesystem with ordered data mode. Opts: (null)
2024-06-15T15:12:23.694254+07:00 PE_R1-node kernel: High host-mode time vcpu 0 delay 110683 us exit reason IO_INSTRUCTION rip 0xfff0 info 640040 0
Need to check if customer has configurations of Source class usage for most of the interfaces and this is one of the trigger for node reboot.
family inet {
accounting {
source-class-usage {
input;
output;
}
When the above configuration is enabled & we see the log messages null value load after NULL check failure. Continuous SNMP polling for an extended period on Junos platforms with SCU/DCU configurations will lead to a kernel crash. The crash is associated with a NULL check failure, attributed to the uninitialised parameters for name length and class name, resulting in traffic disruption.Because of which VMhost got disconnected and rebooted the RE due to which whole device auto-rebooted.
We have a open PR PR1767098 which is matching along with trigger , log messages & kernel vmhost logs , Need to follow the work around mentioned in the PR or upgrade the device to fixed junos version.
NEXT ACTION:
Need to take fix of the below PR
https://prsearch.juniper.net/PR1767098
Resolved-In
junos:22.1R3-S5 junos:22.2R3-S3 junos:22.3R3-S2 junos:22.4R3 junos:23.2R2 junos:23.4R1 junos:23.4R2 junos:24.1R1