了解更多银河麒麟操作系统全新产品，请点击访问

麒麟软件产品专区：https://product.kylinos.cn

开发者专区：https://developer.kylinos.cn

文档中心：https://documentkylinos.cn

现象描述

启nginx服务，但是报了softlock的错误，而且当时负载比较高，资源占用

现象分析

message日志分析

查看message日志，发现在问题发生时在CPU 3上运行的nginx进程触发了大量的soft lockup软锁报错。

查看这些soft lockup软锁日志信息，发现从11：17-13：03里出现的这三十多次软锁报错基本一致，下面选取11：17：28时第一次出现软锁报错的日志进行分析。

May 14 11:17:28 localhost kernel: [1712957.391935] watchdog: BUG: soft lockup - CPU#3 stuck for 22s! [nginx:2858164]

May 14 11:17:28 localhost kernel: [1712957.393937] Modules linked in: qax_tq_base(OE) binfmt_misc ipt_MASQUERADE nf_conntrack_netlink nfnetlink iptable_nat nf_nat_ipv4 xt_addrtype iptable_filter xt_conntrack nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 br_netfilter bridge stp llc overlay sunrpc vfat fat aes_ce_blk crypto_simd cryptd aes_ce_cipher ghash_ce sha2_ce sha256_arm64 sha1_ce sch_fq_codel ip_tables virtio_net net_failover failover virtio_gpu ttm virtio_console [last unloaded: qax_tq_base]

May 14 11:17:28 localhost kernel: [1712957.403317] CPU: 3 PID: 2858164 Comm: nginx Kdump: loaded Tainted: G           OE     4.19.90-17.ky10.aarch64 #1

May 14 11:17:28 localhost kernel: [1712957.405727] Hardware name: SmartX SMTX OS, BIOS 0.0.0 02/06/2015

May 14 11:17:28 localhost kernel: [1712957.407187] pstate: 60400005 (nZCv daif +PAN -UAO)

May 14 11:17:28 localhost kernel: [1712957.408391] pc : clear_page+0x10/0x24

May 14 11:17:28 localhost kernel: [1712957.409341] lr : __cpu_clear_user_page+0xc/0x18

May 14 11:17:28 localhost kernel: [1712957.410470] sp : ffff8003d655fb70

May 14 11:17:28 localhost kernel: [1712957.411351] x29: ffff8003d655fb70 x28: 0000000000000002

May 14 11:17:28 localhost kernel: [1712957.412656] x27: ffff8003cf72f360 x26: ffff8003d1f94f80

May 14 11:17:28 localhost kernel: [1712957.413956] x25: 0000ffff6f680000 x24: 0000ffff6f680000

May 14 11:17:28 localhost kernel: [1712957.415244] x23: ffff8003cf72f300 x22: ffff8003d9ce7710

May 14 11:17:28 localhost kernel: [1712957.416559] x21: ffff8003d655fc88 x20: ffff7fe000441700

May 14 11:17:28 localhost kernel: [1712957.417853] x19: 0000000000000000 x18: 0000000000000000

May 14 11:17:28 localhost kernel: [1712957.419165] x17: 0000000000000000 x16: 0000000000000000

May 14 11:17:28 localhost kernel: [1712957.420475] x15: 0000000000000000 x14: 0000000000000000

May 14 11:17:28 localhost kernel: [1712957.421774] x13: 0000000000000000 x12: 0000000000000000

May 14 11:17:28 localhost kernel: [1712957.423109] x11: 0000000000000000 x10: 0000000000000001

May 14 11:17:28 localhost kernel: [1712957.424453] x9 : ffff8003ffeb3ed8 x8 : 00008003f6e80000

May 14 11:17:28 localhost kernel: [1712957.425768] x7 : 0000000000000000 x6 : 0000000000000001

May 14 11:17:28 localhost kernel: [1712957.427096] x5 : 000000000000fffd x4 : 00008003f6e80000

May 14 11:17:28 localhost kernel: [1712957.428427] x3 : 0000000000000897 x2 : 0000000000000004

May 14 11:17:28 localhost kernel: [1712957.429751] x1 : 0000000000000040 x0 : ffff8001105c0000

May 14 11:17:28 localhost kernel: [1712957.431061] Call trace:

May 14 11:17:28 localhost kernel: [1712957.431732]  clear_page+0x10/0x24

May 14 11:17:28 localhost kernel: [1712957.432624]  wp_page_copy+0x514/0x6d0

May 14 11:17:28 localhost kernel: [1712957.433590]  do_wp_page+0x98/0x648

May 14 11:17:28 localhost kernel: [1712957.434476]  __handle_mm_fault+0x828/0xc10

May 14 11:17:28 localhost kernel: [1712957.435519]  handle_mm_fault+0x104/0x200

May 14 11:17:28 localhost kernel: [1712957.436520]  do_page_fault+0x210/0x508

May 14 11:17:28 localhost kernel: [1712957.437471]  do_mem_abort+0x3c/0xd0

May 14 11:17:28 localhost kernel: [1712957.438368]  el0_da+0x24/0x28

问题时间点首次触发soft lockup的内核日志如上所示，可以看到触发软锁的原因是CPU 3上nginx:2858164卡住22秒无响应。之后查看该软锁对应的call trace堆栈，可以看到此时nginx进程遇到了一个内存缺页异常，在进行写时复制处理时尝试清理内存页面内容，但该操作长时间未完成导致CPU 3长时间未响应触发软锁。

do_mem_abort //内存访问异常函数

->do_page_fault //直接处理页面错误的函数，包括分配新页面或从磁盘加载页面到内存等操作

->handle_mm_fault //用于用户空间内存访问错误的处理，__handle_mm_fault函数的上层调用

->__handle_mm_fault //内核处理内存管理故障的核心函数

->do_wp_page //处理写保护页面的函数

->wp_page_copy //写时复制（Copy-on-Write, COW）机制处理，当一个进程试图写入共享页面时，会触发此操作

->clear_page //用于清除页面的内容，通常作为页面分配或回收过程的一部分

从上述堆栈上来看这是一个正常的处理流程，进程触发内存缺页中断，并在处理写保护页时进行内存页清理处理。通常来说内存清理不会花费大量的时间，除非相关硬件存在问题或系统内存处于一个十分紧张的状态，一直无法得到一个可用的内存页。

内存使用情况分析

上面我们分析nginx应用触发软锁的原因，针对问题可能出现的原因，我们要去分析问题时间点的系统内存资源使用情况。

首先查看系统整体内存及min_free_kbytes参数情况，可以看到当前机器总内存为16143744KB，min_free_kbytes为802944KB。

查看问题时间点的sar日志，可以看到在5.14日的11：10后系统空闲内存突然下降到min水位线附近，available直接降至为0。从11：10-11：20这十分钟里系统内存就到了一个及其紧张的地步。

而查看这十分钟内存的一个内存使用变化，我们发现了一个十分奇怪的现象。在11：10时，系统的缓存cached、匿名内存anonpg、slab、free等参数加起来之和为15924576KB，和系统总内存大小基本一致。

但到了11：20时free和cached大幅度下降，anonpg、slab等内存却又没有明显上升。同样计算各类内存参数统计之和后发现仅有4338688KB，远小于总内存大小，大量内存突然异常消失。这应该就是导致nginx进程在触发缺页异常时一直无法清理得到一个可用内存页的原因。

内存异常消失情况分析

Linux kernel并没有滴水不漏地统计所有的内存分配，kernel动态分配的内存中就有一部分没有计入/proc/meminfo中。大量内存突然不知所踪，无法在各类内存统计项中找到，这个通常被称为内存黑洞或者内存幽灵现象。

由于黑洞内存无法直接找到，通常都是要根据历史经验并结合实际环境进行相关分析。当前环境已经重启，无法再追踪问题时间的相关信息。但这类问题通常都是由于驱动应用、硬件异常或是虚拟化环境宿主机异常导致。

例如华为hns3网卡驱动初始化会占用大量内存、VMware的balloon驱动会在宿主机内存紧张时直接挤占虚拟机内存，又或是物理机硬件、虚拟化环境异常导致虚拟化系统层无法获取相关内存状态。

本次问题环境查看为虚拟化环境，且是在运行了一段时间后才出现大量内存不知所踪，因此问题原因大概率在虚拟化平台。

建议排查虚拟机问题时间点进行的相关操作以及宿主机虚拟化平台状态。

总结

综上所述，本次服务器出现soft lockup的原因为nginx进程启动时进行内存缺页异常处理，在进行写时复制处理时尝试清理内存页面内容，但该操作长时间未完成导致CPU 3长时间未响应触发软锁。

查看soft luckup堆栈，这是一个正常的处理流程，进程触发内存缺页中断，并在处理写保护页时进行内存页清理处理。通常来说内存清理不会花费大量的时间，除非相关硬件存在问题或系统内存处于一个十分紧张的状态，一直无法得到一个可用的内存页。

分析问题时间点内存使用情况，发现在11：10-11：20中系统大量内存突然不知所踪，available直接变为0，free也来到min水位线附近。这就是导致上述nginx进程启动卡在clear_page函数的原因。

对于大量内存突然不知所踪，无法在各类内存统计项中找到这类内存黑洞现象，通常都是由于驱动应用、硬件异常或是虚拟化环境宿主机异常导致。建议排查虚拟机问题时间点进行的相关操作以及宿主机虚拟化平台状态。

备注

除了上述soft lockup问题外，服务器重启后nginx version: openresty/1.21.4.1应用在reload后就会一直有个进程shutting down，要等几分钟才能没有。

对该现象，由于应用并非麒麟方面适配的rpm应用，而是自行安装，无法确认应用编译、安装时是否存在问题。但nginx应用reload后进程出现shutting down状态本身是个正常现象。使用 reload重载nginx，这是一种平滑重启的方案，不会把已有的连接断掉，而是会继续维护已有连接的 nginx 进程，这些进程会进入worker process is shutting down 状态，直至其所有连接处理结束才会退出，退出之前这些shutting down 状态的worker不会处理新的连接。