linux内核bug问题排查过程详细报告

最新推荐文章于 2025-04-09 08:19:17 发布

蔷薇理想人生

最新推荐文章于 2025-04-09 08:19:17 发布

阅读量3.1w

点赞数 6

分类专栏： linux源代码学习系列文章标签： linux 内核 bug soft lo

本文链接：https://blog.csdn.net/qiangweiloveforever/article/details/8302064

版权

本文详细分析了Linux内核中出现的soft lockup问题，主要涉及CPU#1和CPU#11。通过对内核日志的分析，发现是由于某些进程或内核线程被锁死，导致看门狗进程未按预期执行。软死锁可能由用户开发的软件或第三方软件引起，这里以qmgr进程为例。通过内核源码分析，发现在ring_buffer.c文件中出现错误，提示delta值过大，可能存在内存破坏情况。最后，虽然无法重现错误，但怀疑问题可能与scsi_scan_wait内核模块有关，将继续排查。

摘要生成于 C知道，由 DeepSeek-R1 满血版支持，前往体验 >

Linux Kernel BUG:soft lockup CPU#1 stuck分析

1.线上内核bug日志

kernel: Deltaway too big! 18428729675200069867 ts=18446743954022816244 write stamp =18014278822746377

kernel:------------[ cut here ]------------

kernel:WARNING: at kernel/trace/ring_buffer.c:1988 rb_reserve_next_event+0x2ce/0x370()(Not tainted)

kernel:Hardware name: ProLiant DL360 G7

kernel:Modules linked in: fuse ipv6 power_meter bnx2 sg microcode serio_raw iTCO_wdtiTCO_vendor_support hpilo hpwdt i7core_edac edac_core shpchp ext4 mbcache jbd2sd_mod crc_t10dif hpsa radeon ttm drm_kms_helper drm i2c_algo_bit i2c_coredm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan]

kernel: Pid:5483, comm: master Not tainted 2.6.32-220.el6.x86_64 #1

kernel: CallTrace:

kernel:[<ffffffff81069b77>] ? warn_slowpath_common+0x87/0xc0

kernel:[<ffffffff81069bca>] ? warn_slowpath_null+0x1a/0x20

kernel:[<ffffffff810ea8ae>] ? rb_reserve_next_event+0x2ce/0x370

kernel:[<ffffffff810eab02>] ? ring_buffer_lock_reserve+0xa2/0x160

kernel:[<ffffffff810ec97c>] ? trace_buffer_lock_reserve+0x2c/0x70

kernel:[<ffffffff810ecb16>] ? trace_current_buffer_lock_reserve+0x16/0x20

kernel:[<ffffffff8107ae1e>] ? ftrace_raw_event_hrtimer_cancel+0x4e/0xb0

kernel:[<ffffffff81095e7a>] ? hrtimer_try_to_cancel+0xba/0xd0

kernel:[<ffffffff8106f634>] ? do_setitimer+0xd4/0x220

kernel:[<ffffffff8106f88a>] ? alarm_setitimer+0x3a/0x60

kernel:[<ffffffff8107c27e>] ? sys_alarm+0xe/0x20

kernel:[<ffffffff8100b308>] ? tracesys+0xd9/0xde

kernel: ---[end trace 4d0a1ef2e62cb1a2 ]---

abrt-dump-oops: Reported 1 kernel oopses to Abrt

kernel: BUG: softlockup - CPU#11 stuck for 4278190091s! [qmgr:5492]

kernel: CPU 11

kernel:

kernel: Pid:5492, comm: qmgr Tainted: G W ---------------- 2.6.32-220.el6.x86_64 #1 HPProLiant DL360 G7

kernel: RIP:0010:[<ffffffff8106f730>] [<ffffffff8106f730>]do_setitimer+0x1d0/0x220

kernel: RSP:0018:ffff88080a661ef8 EFLAGS: 00000286

kernel: RAX:ffff88080b175a08 RBX: ffff88080a661f18 RCX: 0000000000000000

kernel: RDX:0000000000000000 RSI: 0000000000000082 RDI: ffff88080c8c4c40

kernel: RBP:ffffffff8100bc0e R08: 0000000000000000 R09: 0099d7270e01c3f1

kernel: R10:0000000000000000 R11: 0000000000000246 R12: ffffffff810ef9a3

kernel: R13:ffff88080a661e88 R14: 0000000000000000 R15: ffff88080a65a544

kernel: FS:00007f10b245f7c0(0000) GS:ffff88083c4a0000(0000) knlGS:0000000000000000

kernel: CS:0010 DS: 0000 ES: 0000 CR0: 000000008005003b

kernel: CR2:00007ff955977380 CR3: 000000100a80b000 CR4: 00000000000006e0

kernel: DR0:0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000

kernel: DR3:0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400

kernel:Process qmgr (pid: 5492, threadinfo ffff88080a660000, task ffff880809577500)

kernel: Stack:

kernel:00007f10b323def0 00007f10b248ead0 00007f10b26d0f78 00007f10b248ede0

kernel:<0> ffff88080a661f68 ffffffff8106f88a 0000000000000000 0000000000000000

kernel:<0> 000000000000014c 00000000000f423d 0000000000000000 0000000000000000

kernel: CallTrace:

kernel:[<ffffffff8106f88a>] ? alarm_setitimer+0x3a/0x60

kernel:[<ffffffff8107c27e>] ? sys_alarm+0xe/0x20

kernel:[<ffffffff8100b308>] ? tracesys+0xd9/0xde

kernel: Code:89 ef e8 74 66 02 00 83 3d 15 69 b5 00 00 75 37 49 8b 84 24 70 07 00 00 48 0508 08 00 00 66 ff 00 66 66 90 fb 66 0f 1f 44 00 00 <31> c0 e9 64 fe ff ff49 8b 84 24 68 07 00 00 48 c7 80 d0 00 00

kernel: CallTrace:

kernel:[<ffffffff8106f769>] ? do_setitimer+0x209/0x220

kernel:[<ffffffff8106f88a>] ? alarm_setitimer+0x3a/0x60

kernel:[<ffffffff8107c27e>] ? sys_alarm+0xe/0x20

kernel:[<ffffffff8100b308>] ? tracesys+0xd9/0xde

abrt-dump-oops: Reported 1 kernel oopses to Abrt

2.内核软死锁（soft lockup）bug原因分析

Soft lockup名称解释：所谓，soft lockup就是说，这个bug没有让系统彻底死机，但是若干个进程（或者kernel thread）被锁死在了某个状态（一般在内核区域），很多情况下这个是由于内核锁的使用的问题。

Linux内核对于每一个cpu都有一个监控进程，在技术界这个叫做watchdog（看门狗）。通过ps –ef | grep watchdog能够看见，进程名称大概是watchdog/X（数字：cpu逻辑编号1/2/3/4之类的）。这个进程或者线程每一秒钟运行一次，否则会睡眠和待机。这个进程运行会收集每一个cpu运行时使用数据的时间并且存放到属于每个cpu自己的内核数据结构。在内核中有很多特定的中断函数。这些中断函数会调用soft lockup计数，他会使用当前的时间戳与特定（对应的）cpu的内核数据结构中保存的时间对比，如果发现当前的时间戳比对应cpu保存的时间大于设定的阀值，他就假设监测进程或看门狗线程在一个相当可观的时间还没有执。Cpu软锁为什么会产生，是怎么产生的？如果linux内核是经过精心设计安排的CPU调度访问，那么怎么会产生cpu软死锁？那么只能说由于用户开发的或者第三方软件引入，看我们服务器内核panic的原因就是qmgr进程引起。因为每一个无限的循环都会一直有一个cpu的执行流程（qmgr进程示一个后台邮件的消息队列服务进程），并且拥有一定的优先级。Cpu调度器调度一个驱动程序来运行，如果这个驱动程序有问题并且没有被检测到，那么这个驱动程序将会暂用cpu的很长时间。根据前面的描述，看门狗进程会抓住（catch）这一点并且抛出一个软死锁（soft lockup）错误。软死锁会挂起cpu使你的系统不可用。

如果是用户空间的进程或线程引起的问题backtrace是不会有内容的，如果内核线程那么在soft lockup消息中会显示出backtrace信息。

3.根据linux内核源码分析错误

根据我们第一部分内核抛出的错误信息和call trace（linux内核的跟踪子系统）来分析产生的具体原因。

首先根据我们的centos版本安装相应的linux内核源码，具体步骤如下：

（1）下载源码的rpm包kernel-2.6.32-220.17.1.el6.src.rpm

（2）安装相应的依赖库，命令：yuminstall rpm-build redhat-rpm-config asciidoc newt-devel

（3）安装源码包：rpm -ikernel-2.6.32-220.17.1.el6.src.rpm

（4）进入建立源码的目录：cd~/rpmbuild/SPECS

（5）建立生成源码目录：rpmbuild-bp --target=`uname -m` kernel.spec

下面开始真正的根据内核bug日志分析源码：

（1）第一阶段内核错误日志分析（时间在Dec 4 14:03:34这个阶段的日志输出代码分析，其实这部分代码不会导致cpu软死锁，主要是第二阶段错误日志显示导致cpu软死锁）

我们首先通过日志定位到相关源代码：看下面日志：Dec 4 14:03:34 BP-YZH-1-xxxx kernel: WARNING: atkernel/trace/ring_buffer.c:1988 rb_reserve_next_event+0x2ce/0x370() (Not tainted)

根据日志内容我们可以很容易的定位到kernel/trace/ring_buffer.c这个文件的1988行代码如下：WARN_ON(1)。

先简单解释一下WARN_ON的作用：WARN_ON只是打印出当前栈信息，不会panic。所以会看到后面有一大堆的栈信息。这个宏定义如下：

#ifndef WARN_ON

#defineWARN_ON(condition) ({ \

int __ret_warn_on = !!(condition); \

if (unlikely(__ret_warn_on)) \

__WARN(); \

unlikely(__ret_warn_on); \

})

#endif

这个宏很简单保证传递进来的条件值为0或者1（两次逻辑非操作的结果），然后使用分支预测技术（保证执行概率大的分支紧邻上面的指令）判断是否需要调用__WARN()宏定义。如果满足条件执行了__WARN()宏定义也接着执行一条空指令;。上面调用WARN_ON宏是传递的1，所以会执行__WARN()。下面继续看一下__WARN()宏定义如下：

#define __WARN() warn_slowpath_null(__FILE__,__LINE__)

从接下来的call trace信息中我们也确实发现调用了warn_slowpath_null这个函数。通过在linux内核源代码中搜索这个函数的实现，发现在panic.c（内核恐慌时的相关功能实现）中实现如下：

voidwarn_slowpath_null(const char *file, int line)

{

warn_slowpath_common(file, line,__builtin_return_address(0),

TAINT_WARN, NULL);

}

EXPORT_SYMBOL(warn_slowpath_null);//都出这个符号，让其他模块可以使用这个函数

同样的我们看到了warn_slowpath_common这个函数，而在call trace当中这个函数在warn_slowpath_null函数之前打印出来，再次印证了这个流程是正确的。同样在panic.c这个文件中我发现了warn_slowpath_common这个函数的实现如下：

static voidwarn_slowpath_common(const char *file, int line, void *caller,

unsigned taint, struct slowpath_args *args)

{

const char *board;

printk(KERN_WARNING "------------[ cut here]------------\n");

printk(KERN_WARNING "WARNING: at %s:%d %pS()(%s)\n",

file, line, caller, print_tainted());

board = dmi_get_system_info(DMI_PRODUCT_NAME);//得到dmi系统信息

if (board)

printk(KERN_WARNING "Hardware name:%s\n", board);//通过我们的日志信息可以发现我们硬件名称是ProLiant DL360 G7

if (args)

vprintk(args->fmt, args->args);

print_modules();//打印系统模块信息

dump_stack();//dump信息输出（call trace开始）

print_oops_end_marker();//打印oops结束

add_taint(taint);

}

分析这个函数的实现不难发现我们的很多日志信息从这里开始输出，包括打印一些系统信息，就不继续深入分析了（请看代码注释，里面调用相关函数打印对应信息，通过我分析这些函数的实现和我们的日志信息完全能够对应，其中dump_stack是与cpu体系结构相关的，我们的服务器应该是属于x86体系）。这里在继续分析一下dump_stack函数的实现，因为这个是与cpu体系结构相关的，而且这个函数直接反应出导致内核panic的相关进程。这个函数实现如下：

* The architecture-independent dump_stackgenerator

void dump_stack(void)

{