阅读量:0
了解银河麒麟操作系统更多全新产品，请点击访问麒麟软件产品专区：https://product.kylinos.cn
服务器环境以及配置
物理机 | |
外网/私有网络/无网络 | 私有网络 |
处理器： | Kunpeng 920 |
内存： | 4 TiB |
BIOS版本： | Huawei Corp. |
固件版本： | TaiShan 200 (Model 2280) |
具体操作系统版本 | NeoKylin Linux Advanced Server release V7Update6 (Chromium)-aarch64 |
内核版本 | 4.14.0-115.5.1.el7a.12.aarch64 |
现象描述
生产环境arm V7.6物理机在2024年 4月7号08:49分钟左右宕机（自动重启恢复），生成vmcore文件。
情况分析
查看vmcore-dmesg日志
查看vmcore-dmesg日志如下所示，可以看到本次服务器系统是因为系统触发了softlockup导致的宕机。
[8114761.027875] Kernel panic - not syncing: softlockup: hung tasks [8114761.033855] CPU: 11 PID: 5923 Comm: java Kdump: loaded Tainted: G L ------------ 4.14.0-115.5.1.el7a.12.aarch64 #1 [8114761.045536] Hardware name: Huawei TaiShan 200 (Model 2280)/BC82AMDGK, BIOS 1.87 02/22/2022 [8114761.053934] Call trace: [8114761.056544] [<ffff000008089d54>] dump_backtrace+0x0/0x23c [8114761.062092] [<ffff000008089fb4>] show_stack+0x24/0x2c [8114761.067293] [<ffff00000881cd78>] dump_stack+0x84/0xa8 [8114761.072495] [<ffff0000080d49c8>] panic+0x138/0x2a0 [8114761.077438] [<ffff0000081a86d8>] watchdog+0x0/0x38 [8114761.082380] [<ffff00000815868c>] __hrtimer_run_queues+0x14c/0x2cc [8114761.088618] [<ffff000008159070>] hrtimer_interrupt+0xa8/0x1d8 [8114761.094513] [<ffff0000086902d8>] arch_timer_handler_phys+0x3c/0x48 [8114761.100837] [<ffff000008141e74>] handle_percpu_devid_irq+0x98/0x210 [8114761.107248] [<ffff00000813bf6c>] generic_handle_irq+0x34/0x4c [8114761.113139] [<ffff00000813c688>] __handle_domain_irq+0x6c/0xc4 [8114761.119118] [<ffff000008081848>] gic_handle_irq+0xa0/0x1b8 [8114761.124751] Exception stack(0xffff0000a7fcfab0 to 0xffff0000a7fcfbf0) |
正常来说触发软锁并不会导致系统宕机，查看机器内核参数配置，发现是客户手动设置了kernel.softlockup_panic=1导致的。
具体查看softlockup日志，发现触发软锁的的为CPU: 11，其上正在运行的是java进程，该CPU最终在__d_lookup+0x7c/0x184处执行相关操作超过22s没有进行切换而触发了watchdog。__d_lookup+0x7c/0x184函数是iterate_dir的一部分，用于在目录中查找特定的项，在这个阶段系统可能正在尝试打开或遍历一个目录。
[8114760.616335] watchdog: BUG: soft lockup - CPU#11 stuck for 22s! [java:5923] [8114760.623353] Modules linked in: udp_diag tcp_diag inet_diag bonding sunrpc vfat fat crc32_ce ghash_ce sha2_ce sha256_arm64 sha1_ce ses enclosure sbsa_gwdt hns_roce_hw_v2 hns_roce ib_core ipmi_si sg ipmi_devintf ipmi_msghandler gpio_dwapb gpio_generic ip_tables xfs libcrc32c mlx5_core mlxfw ptp hibmc_drm drm_kms_helper syscopyarea realtek sysfillrect sysimgblt fb_sys_fops ttm hns3 drm hisi_sas_v3_hw hclge pps_core hisi_sas_main devlink hnae3 libsas megaraid_sas scsi_transport_sas i2c_designware_platform i2c_designware_core dm_mirror dm_region_hash dm_log dm_mod [8114760.672838] CPU: 11 PID: 5923 Comm: java Kdump: loaded Not tainted 4.14.0-115.5.1.el7a.12.aarch64 #1 [8114760.682100] Hardware name: Huawei TaiShan 200 (Model 2280)/BC82AMDGK, BIOS 1.87 02/22/2022 [8114760.690499] task: ffffa06f55197600 task.stack: ffff0000a7fc0000 [8114760.696568] PC is at __d_lookup+0x7c/0x184 [8114760.700821] LR is at d_lookup+0x40/0x6c [8114760.704812] pc : [<ffff0000082be270>] lr : [<ffff0000082be3b8>] pstate: 80400009 [8114760.712346] sp : ffff0000a7fcfbf0 [8114760.715818] x29: ffff0000a7fcfbf0 x28: ffffa06f55197600 [8114760.721280] x27: ffffa06f55197600 x26: ffffffffffffffff [8114760.726742] x25: ffff0000a7fcfd10 x24: 0000000000000000 [8114760.732203] x23: ffff806fd22d2040 x22: ffff806fd22d2040 [8114760.737664] x21: 00000000b0c232bc x20: ffffa0423d016d80 [8114760.743125] x19: ffffa0423d016d88 x18: 00000000e3ab91d2 [8114760.748586] x17: 0000ffffa9345dac x16: ffff0000082b7ae8 [8114760.754048] x15: 00000000e3ab9008 x14: 000000008002e388 [8114760.759509] x13: 0000000000000000 x12: 0de59ec22af18900 [8114760.764971] x11: ffff0000a7fcfd40 x10: ffff0000a7fcfd40 [8114760.770433] x9 : 00000000ffffffd8 x8 : 0000000000000000 [8114760.775893] x7 : 0de59ec22af18900 x6 : 0000000000000029 [8114760.781355] x5 : ffffffffffffffff x4 : 0000000000003134 [8114760.786817] x3 : 3e6ec4f4e31ec6bc x2 : 00000000b0c232b7 [8114760.792278] x1 : ffff00000c0d0000 x0 : 0000000005861190 [8114760.797739] Call trace: [8114760.891625] [<ffff0000082be270>] __d_lookup+0x7c/0x184 [8114760.896912] [<ffff0000082be3b8>] d_lookup+0x40/0x6c [8114760.901940] [<ffff0000082be440>] d_hash_and_lookup+0x5c/0x70 [8114760.907746] [<ffff00000831cd08>] proc_fill_cache+0x68/0x194 [8114760.913465] [<ffff000008320dbc>] proc_readfd_common+0x100/0x220 [8114760.919531] [<ffff000008320f0c>] proc_readfd+0x30/0x3c [8114760.924818] [<ffff0000082b73d8>] iterate_dir+0x150/0x1b8 [8114760.930279] [<ffff0000082b7b80>] SyS_getdents64+0x98/0x170 [8114760.935911] Exception stack(0xffff0000a7fcfec0 to 0xffff0000a7fd0000) [8114761.022155] [<ffff00000808392c>] __sys_trace_return+0x0/0x4 |
查看call trace堆栈信息，详细的函数调用流程如下。简单来说问题发生时CPU在处理用户空间对/proc/<pid>/fd目录的遍历请求时（通过getdents64系统调用），在__d_lookup函数中触发了soft lockup。
SyS_getdents64+0x98/0x170-> #该函数是getdents64系统调用的内核实现，用于获取目录中下一个文件或子目录的详细信息，包括inode、名称等。 iterate_dir+0x150/0x1b8-> #该函数用于遍历目录中的文件和子目录，通常在处理getdents系统调用时被调用，为用户提供目录内容列表。 proc_readfd+0x30/0x3c-> #该函数是用户查询进程文件描述符详细信息的入口，通常调用proc_readfd_common来完成实际的读取操作。 proc_readfd_common+0x100/0x220-> #该函数处理/proc/<pid>/fd目录下特定文件描述符（fd）的信息读取请求。 proc_fill_cache+0x68/0x194-> #该函数与/proc文件系统相关，用于填充getdents系统调用所需的目录项缓存，以提供对/proc目录下文件或子目录的遍历支持。 d_hash_and_lookup+0x5c/0x70-> #该函数负责计算给定路径的哈希值，并使用该哈希值在目录项缓存中查找对应的目录项结构，通常会调用d_lookup完成查找。 d_lookup+0x40/0x6c-> #该函数调用__d_lookup进行实际查找工作，并处理一些额外的锁定和错误处理逻辑。 __d_lookup+0x7c/0x184-> # 该函数负责在目录项缓存（dentry cache）中查找与指定路径对应的目录项结构 |
linux系统中软锁（softlockup）的发生通常是因为某个任务在内核态循环超过一定时间，导致其他任务没有机会得到运行。本处问题场景的堆栈信息为一个典型的文件系统操作流程，最终卡住的位置__d_lookup也是一个常见的目录项查找函数，不太可能是死循环、无限递归等原因导致，更像是性能问题导致的锁竞争。且后续结合sosreport文件，我们可以知道当前服务器CPU为鲲鹏920，java进程也未华为bigdata相关业务进程，猜测可能是该进程遍历目录中存在大量小文件而arm CPU性能相较intel/amd较差导致目录遍历耗时较长触发了软锁。
后续原本还想通过vmcore看能否查看问题触发的时间的相关信息，如遍历的目录及查找的目录项等，但由于客户提供 vmcore（大小57G）为网络下载链接，我们尝试几次下载都没能下载到完整的vmcore文件，无法进一步查看更多信息。
查看sa日志
sar -r -f sa07，查看4月7号问题发生时的内存使用率，内存使用率并不高。
sar -u -f sa07，查看问题发生时的CPU使用率，CPU使用率也不高。
sar -P ALL -f sa07，查看各个CPU的使用率，包括触发软锁的CPU 11在内，每个CPU使用率也并不高，可能是sa采样频率为10分钟的缘故。
sar -q -f sa07，查看系统负载情况，系统负载并不高。
sar -d -f sa08，查看磁盘使用情况，问题发生时各个磁盘读写也不高。
分析总结
综上所述，通过查看vmcore-demsg信息我们发现本次系统宕机的原因为系统触发了softlockup机制。详细来说触发软锁的为CPU: 11，其上正在运行的是java进程，该CPU最终在__d_lookup+0x7c/0x184处执行相关操作超过22s没有进行切换而触发了watchdog。默认情况下softlockup并不会导致宕机，本处是因为客户手动设置了kernel.softlockup_panic=1。
查看问题发生时的系统资源使用情况，可以看到问题发生前系统的CPU/内存/磁盘等资源均不高，说明问题发生前几分钟不存在系统资源耗尽的问题。分析call trace堆栈信息，我们发现问题发生时CPU在处理用户空间对/proc/<pid>/fd目录的遍历请求时（通过getdents64系统调用），在__d_lookup函数中触发了soft lockup。
linux系统中软锁（softlockup）的发生通常是因为某个任务在内核态循环超过一定时间，导致其他任务没有机会得到运行。本处问题场景的堆栈信息为一个典型的文件系统操作流程，看起来像是性能问题导致的锁竞争。且后续结合sosreport文件，我们可以知道当前服务器CPU为鲲鹏920，java进程也为bigdata相关业务进程，猜测可能是该进程遍历目录中存在大量小文件而arm CPU性能相较intel/amd较差导致目录遍历耗时较长触发了软锁。
针对该问题建议应用方排查下相应java进程是否存在对大量小文件的目录进行遍历操作，以及根据实际需求看是否考虑关闭kernel.softlockup_panic。
