麒麟软件产品专区:https://product.kylinos.cn
开发者专区:https://developer.kylinos.cn
文档中心:https://document.kylinos.cn
现象描述
某虚拟化平台多台虚拟机于凌晨触发异常重启,需要分析机器异常重启原因。
现象分析
分析vmcore
分析04:31:51的vmcore
查看vmcore-dmesg,出现了Unable to handle kernel paging request at virtual address 0041414141414141,无法处理的虚拟地址0041414141414141,导致了panic。而在内核模块信息打印的日志中,我们发现机器加载了qax_tq_base(OE)、dattobd(OE)、sfs(OE) i2dtrack(OE)、sysmon_edr(OE)等第三方模块,最后还提示了 [last unloaded: qax_tq_base],这说明系统宕机前最后在执行qax_tq_base模块的相关操作。
[4875934.820651] Unable to handle kernel paging request at virtual address 0041414141414141 [4875934.820653] Mem abort info: [4875934.820654] ESR = 0x96000004 [4875934.820655] Exception class = DABT (current EL), IL = 32 bits [4875934.820656] SET = 0, FnV = 0 [4875934.820657] EA = 0, S1PTW = 0 [4875934.820657] Data abort info: [4875934.820658] ISV = 0, ISS = 0x00000004 [4875934.820659] CM = 0, WnR = 0 [4875934.820660] [0041414141414141] address between user and kernel address ranges [4875934.820661] Internal error: Oops: 96000004 [#1] SMP [4875934.822854] Modules linked in: qax_tq_base(OE) ip6table_filter ip6_tables iptable_filter nfsv3 nfsv4 dns_resolver nfs fscache dattobd(OE) sfs(OE) i2dtrack(OE) rpcsec_gss_krb5 tcp_diag inet_diag binfmt_misc isofs fuse sysmon_edr(OE) nfsd auth_rpcgss nfs_acl lockd rfkill grace sunrpc vfat fat aes_ce_blk crypto_simd cryptd aes_ce_cipher crct10dif_ce ghash_ce sha2_ce sha256_arm64 sha1_ce sch_fq_codel ip_tables sr_mod cdrom virtio_gpu virtio_scsi virtio_net virtio_console net_failover failover [last unloaded: qax_tq_base] [4875934.833337] Process qax_kfanth (pid: 3065131, stack limit = 0x0000000054a9bf15) [4875934.835088] CPU: 3 PID: 3065131 Comm: qax_kfanth Kdump: loaded Tainted: G OE 4.19.90-23.8.v2101.ky10.aarch64 #1 [4875934.837745] Hardware name: QEMU KVM Virtual Machine, BIOS 0.0.0 02/06/2015 [4875934.839400] pstate: 20400005 (nzCv daif +PAN -UAO) [4875934.840585] pc : kmem_cache_alloc_trace+0x8c/0x1f0 [4875934.841793] lr : kmem_cache_alloc_trace+0x44/0x1f0 [4875934.842987] sp : ffff8001c2543b80 [4875934.843851] x29: ffff8001c2543b80 x28: ffff8001a0027ce0 [4875934.845145] x27: ffff8001a0043e28 x26: ffff8001c2543d70 [4875934.846438] x25: 0000000000000000 x24: ffff8001c001fc00 [4875934.847746] x23: 000000000000000b x22: ffff8001c001fc00 [4875934.848989] x21: ffff0000083c8d60 x20: 0000000000480020 [4875934.850283] x19: 4141414141414141 x18: 0000000000000000 [4875934.851566] x17: 0000000000000000 x16: 0000000000000000 [4875934.852788] x15: 0000000000000000 x14: 0000000000000000 [4875934.854042] x13: 0000000000000000 x12: 0000000000000000 [4875934.855321] x11: 0000000000000000 x10: a5bfbdffb6bcb5a3 [4875934.856619] x9 : 0000000000000000 x8 : ffff8001a0026390 [4875934.857884] x7 : c0dc71521da5d8cd x6 : 000000002ed0530e [4875934.859158] x5 : 000000071d78334e x4 : ffff8001ff5a3ea0 [4875934.860417] x3 : ffff8001d6cd6a00 x2 : ffff7fe0000d76c0 [4875934.861674] x1 : 00008001f6120000 x0 : 0000000000000000 [4875934.863000] Call trace: [4875934.863647] kmem_cache_alloc_trace+0x8c/0x1f0 [4875934.864691] proc_self_get_link+0xb0/0xc8 [4875934.865701] link_path_walk.part.9+0x470/0x4f0 [4875934.866818] path_openat+0xa4/0x280 [4875934.867715] do_filp_open+0x70/0xe8 [4875934.868606] do_sys_open+0x178/0x200 [4875934.869494] __arm64_sys_openat+0x2c/0x38 [4875934.870516] el0_svc_common+0x78/0x130 [4875934.871449] el0_svc_handler+0x38/0x78 [4875934.872383] el0_svc+0x8/0x1b0 [4875934.873176] Code: f100005f fa401a64 54000960 b9402300 (f8606a66) [4875934.874625] SMP: stopping secondary CPUs [4875934.877221] Starting crashdump kernel... |
继续分析vmcore中的堆栈信息,将其梳理如下所示。可以看到内核崩溃前正在执行一个openat系统调用时,在进行文件遍历、获取进程链接信息时尝试从内核的内存缓存中分配内存访问了异常的内存地址导致系统重启。
__arm64_sys_openat //arm64架构的特定实现,用于处理openat系统调用 -> link_path_walk.part.9 /遍历文件系统路径,检查每个路径元素的有效性 -> proc_self_get_link //用于获取当前进程的链接信息 ->kmem_cache_alloc_trace //用于从内核的内存缓存中分配内存 |
分析04:32:18的vmcore
继续查看第二台机器的vmcore-dmesg,我们发现日志中同样出现了Unable to handle kernel paging request at virtual address 0041414141414141,无法处理的虚拟地址0041414141414141,导致了panic。而在内核模块信息打印的日志中,显示该机器同样也加载了一样的第三方模块,且同样提示了 [last unloaded: qax_tq_base]。
[4875601.789175] Unable to handle kernel paging request at virtual address 0041414141414141 [4875601.796112] Mem abort info: [4875601.798680] ESR = 0x96000004 [4875601.801578] Exception class = DABT (current EL), IL = 32 bits [4875601.806625] SET = 0, FnV = 0 [4875601.809509] EA = 0, S1PTW = 0 [4875601.812500] Data abort info: [4875601.815225] ISV = 0, ISS = 0x00000004 [4875601.818680] CM = 0, WnR = 0 [4875601.821535] [0041414141414141] address between user and kernel address ranges [4875601.827652] Internal error: Oops: 96000004 [#1] SMP [4875601.831878] Modules linked in: qax_tq_base(OE) binfmt_misc ip6table_filter ip6_tables iptable_filter tcp_diag inet_diag isofs fuse rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace i2dtrack(OE) fscache dattobd(OE) sfs(OE) rfkill sunrpc vfat fat aes_ce_blk crypto_simd cryptd aes_ce_cipher crct10dif_ce ghash_ce sha2_ce sha256_arm64 sha1_ce sch_fq_codel ip_tables sr_mod cdrom virtio_gpu virtio_net virtio_scsi net_failover virtio_console failover [last unloaded: qax_tq_base] |
继续分析vmcore中的堆栈信息,将其梳理如下所示。可以看到内核崩溃前正在执行一个socket系统调用,但在创建新的套接字并为其分配相关内核资源时出现了异常内存地址访问,导致系统重启。
__arm64_sys_socket //ARM64架构的socket系统调用的具体实现 -> alloc_file /负责分配一个新的struct file对象,并对其进行初始化。 -> alloc_empty_file //用于分配一个空的struct file对象,通常作为后续填充的起点。 ->__alloc_file //用于分配一个新的struct file对象,这是对打开的文件进行抽象的核心数据结构。 ->security_file_alloc //内核安全模块相关函数,用于分配与文件相关的安全结构。 ->kmem_cache_alloc_trace //用于从内核的内存缓存中分配内存 |
分析04:32:20的vmcore
继续查看第三台机器的vmcore-dmesg,和前两台一样,我们发现日志中同样出现了Unable to handle kernel paging request at virtual address 0041414141414141,无法处理的虚拟地址0041414141414141,导致了panic。而在内核模块信息打印的日志中,显示该机器同样也加载了一样的第三方模块,且同样提示了 [last unloaded: qax_tq_base]。
[4875662.661143] Unable to handle kernel paging request at virtual address 0041414141414141 [4875662.668401] Mem abort info: [4875662.671289] ESR = 0x96000004 [4875662.674297] Exception class = DABT (current EL), IL = 32 bits [4875662.679759] SET = 0, FnV = 0 [4875662.682865] EA = 0, S1PTW = 0 [4875662.685982] Data abort info: [4875662.689030] ISV = 0, ISS = 0x00000004 [4875662.692797] CM = 0, WnR = 0 [4875662.695858] [0041414141414141] address between user and kernel address ranges [4875662.702494] Internal error: Oops: 96000004 [#1] SMP [4875662.707187] Modules linked in: qax_tq_base(OE) binfmt_misc ip6table_filter ip6_tables iptable_filter tcp_diag inet_diag isofs fuse rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd grace fscache i2dtrack(OE) dattobd(OE) sfs(OE) rfkill sunrpc vfat fat aes_ce_blk crypto_simd cryptd aes_ce_cipher crct10dif_ce ghash_ce sha2_ce sha256_arm64 sha1_ce sch_fq_codel ip_tables sr_mod cdrom virtio_gpu virtio_net virtio_console net_failover failover virtio_scsi [last unloaded: qax_tq_base] |
继续分析vmcore中的堆栈信息,将其梳理如下所示。可以看到内核崩溃前正在执行一个sendto系统调用发送数据到Netlink套接字,但在为Netlink消息分配sk_buff结构时于内存申请处出现了问题,访问了异常的内存地址导致机器重启。
__arm64_sys_sendto //ARM64架构的sendto()系统调用的具体实现 -> __alloc_skb /网络子系统中的内核函数,用于分配一个新的sk_buff(Socket Buffer)结构,这是Linux网络协议栈中用于存储网络数据包的核心数据结构 -> __kmalloc_reserve.isra.9 //用于分配指定大小的内存,并确保分配的内存块是连续且未被使用的 ->__kmalloc_node_track_caller//用于在特定NUMA节点上分配指定大小的内存,并记录调用者信息以支持调试 |
小结
经过对vmcore日志的仔细分析,发现本次三台机器异常重启,均因无法处理的内存地址0041414141414141。值得注意的是,这三次异常重启涉及的堆栈跟踪在每次重启时都不相同,且涉及的堆栈函数分布于不同的内核模块。具体来看三台机器重启前执行的内核函数openat/socket/sendto这些函数均属于内核的基础功能,因此可以排除内核函数本身的缺陷作为直接原因。
不同机器在同一时间同时触发异常重启,且在执行不同的内核基础函数时遇到了同一个异常的内存地址,这表明问题原因基本不在系统本身而是有第三方应用、模块等存在如堆栈溢出等异常改写了正常的内存数据。
综合分析,多台机器异常重启的时间点基本一致,这降低了硬件问题的可能性,也不太可能是内核自身的问题。这些迹象表明可能是某个特定应用或进程在固定的时间点执行某些特定的逻辑代码,触发了这些异常。系统内存在大量的内存虚拟地址被替换为 4141414141414141,系统堆栈空间也出现了覆盖现象,且vmcore日志中存在[last unloaded: qax_tq_base]的信息,这可能是由于第三方内核模块 qax_tq_base 或某个应用程序导致的堆栈溢出。同时,这也可能是缓冲区溢出漏洞或遭受缓冲区溢出病毒攻击的结果。
备注
针对该问题我们核对了以往的问题工单,发现在另一个项目上出现过同样的问题,该项目上存在虚拟机大规模在凌晨4:30左右异常重启的问题,与本次虚拟机大规模异常重启时间一致。且排查后发现该问题中虚拟机内核同样是在执行不同任务时访问了如00414141414141a1、 0041414141414131、0041414141414141的异常内存地址,和本次问题类似。且在该问题中虚拟机同样加载了第三方模块qax_tq_base ,vmcore日志中也报出了[last unloaded: qax_tq_base]的信息。建议让第三方模块qax_tq_base 厂商进行相关排查。