linux kernel debug 之 CallTrace

本文针对UWB无线调试中出现的Kernel警告问题进行了深入分析,并提供了具体的解决方案,包括Kernel中断请求与释放、内存页分配与释放及内核锁等方面的内容。

这篇文章是基于上次UWB(WUSB) wireless debug 的一个问题,然后引申出来的一个话题,对kenel有一定理解的同学可能会有一定的帮助。

--其实这个问题,个人认为,这个个CallTrace会一起down机,cpuhold的等问题,还是一个很大的问题。不过从一般意义上来讲,他是个warning我们可以不用管他。但谁让自己是做技术的呢,没办法,眼里容不得沙子。来吧干货。

1.      Kernel int request & free

Call Trace:

Apr  7 10:44:56 magic kernel: ------------[ cuthere ]------------

Apr  7 10:44:56 magic kernel: WARNING: atkernel/softirq.c:159 local_bh_enable_ip+0x7d/0xb0() (Tainted: P           ---------------   )

Apr  7 10:44:56 magic kernel: Hardware name: HPZ420 Workstation

Apr  7 10:44:56 magic kernel: Modules linked in:usb_skeleton(U) wusb_cbaf(U) elok_s(P)(U) tun bridge iptable_mangle iptable_natnf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 iptable_filter ip_tablessunrpc bnx2fc cnic uio fcoe libfcoe 8021q garp stp libfc llc scsi_transport_fcscsi_tgt cpufreq_ondemand acpi_cpufreq freq_table mperf ipv6 rcim2usb(U)psysdrv(P)(U) esdcan_pci200(P)(U) realtek_uwb(U) vfat fat hwa_hc(U) wusb_wa(U)ext3 wusbcore(U) jbd hwa_rc(U) uwb(U) wmi xhci_hcd nvidia(P)(U) igb dca ptppps_core sg microcode serio_raw i2c_i801 i2c_core iTCO_wdt iTCO_vendor_supportsnd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdepsnd_seq snd_seq_device snd_pcm snd_timer snd soundcore snd_page_alloc e1000eshpchp ext4 mbcache jbd2 sd_mod crc_t10dif sr_mod cdrom firewire_ohcifirewire_core crc_itu_t isci libsas mpt2sas scsi_transport_sas raid_class ahcipata_acpi ata_generic dm_mirror dm_region_hash dm_log dm_mod [last unloaded:scsi_wait_scan]

Apr  7 10:44:56 magic kernel: Pid: 6127, comm:java Tainted: P          ---------------   2.6.32-358.11.1.el6.x86_64 #1

Apr  7 10:44:56 magic kernel: Call Trace:

Apr  7 10:44:56 magic kernel: <IRQ>  [<ffffffff8106e2e7>] ? warn_slowpath_common+0x87/0xc0

Apr  7 10:44:56 magic kernel:[<ffffffff8106e33a>] ? warn_slowpath_null+0x1a/0x20

Apr  7 10:44:56 magic kernel:[<ffffffff810778dd>] ? local_bh_enable_ip+0x7d/0xb0

Apr  7 10:44:56 magic kernel:[<ffffffff815106db>] ? _spin_unlock_bh+0x1b/0x20

Apr  7 10:44:56 magic kernel:[<ffffffffa0bcd8f7>] ? uwb_rc_set_drp_cmd_done+0x67/0x100 [uwb]

Apr  7 10:44:56 magic kernel:[<ffffffff8108107d>] ? del_timer+0x7d/0xe0

Apr  7 10:44:56 magic kernel:[<ffffffffa0bd0e95>] ? uwb_rc_neh_cb+0x25/0x40 [uwb]

Apr  7 10:44:56 magic kernel:[<ffffffffa0bd11a2>] ? uwb_rc_neh_grok+0x252/0x4d0 [uwb]

Apr  7 10:44:56 magic kernel:[<ffffffffa01e6e39>] ? hwarc_neep_cb+0x59/0x168 [hwa_rc]

Apr  7 10:44:56 magic kernel:[<ffffffff813b4ad4>] ? usb_hcd_giveback_urb+0x64/0xe0

Apr  7 10:44:56 magic kernel:[<ffffffffa0c6a26e>] ? xhci_irq+0x4be/0x17f0 [xhci_hcd]

Apr  7 10:44:56 magic kernel:[<ffffffff81082128>] ? add_timer+0x18/0x30

Apr  7 10:44:56 magic kernel:[<ffffffff810e70ea>] ? __rcu_process_callbacks+0x25a/0x350

Apr  7 10:44:56 magic kernel:[<ffffffffa0c6b5d1>] ? xhci_msi_irq+0x31/0x40 [xhci_hcd]

Apr  7 10:44:56 magic kernel:[<ffffffff810e1670>] ? handle_IRQ_event+0x60/0x170

Apr  7 10:44:56 magic kernel:[<ffffffff8107700f>] ? __do_softirq+0x11f/0x1e0

Apr  7 10:44:56 magic kernel:[<ffffffff810e3dbe>] ? handle_edge_irq+0xde/0x180

Apr  7 10:44:56 magic kernel:[<ffffffff8100de89>] ? handle_irq+0x49/0xa0

Apr  7 10:44:56 magic kernel:[<ffffffff815171bc>] ? do_IRQ+0x6c/0xf0

Apr  7 10:44:56 magic kernel: [<ffffffff8100b9d3>]? ret_from_intr+0x0/0x11

Apr  7 10:44:56 magic kernel: <EOI>

Apr  7 10:44:56 magic kernel: ---[ end trace580801de7dc9f3db ]---

Apr  7 10:44:56 magic kernel: in uwb_rsv_timer

结合Call Trace,我们上相应内核代码:

static inline void _local_bh_enable_ip(unsignedlong ip)

{

         WARN_ON_ONCE(in_irq()|| irqs_disabled());

#ifdef CONFIG_TRACE_IRQFLAGS

         local_irq_disable();

#endif

         /*

          * Are softirqs going to be turned on now:

          */

         if(softirq_count() == SOFTIRQ_DISABLE_OFFSET)

                   trace_softirqs_on(ip);

         /*

          * Keep preemption disabled until we are donewith

          * softirq processing:

         */

         sub_preempt_count(SOFTIRQ_DISABLE_OFFSET- 1);

 

         if(unlikely(!in_interrupt() && local_softirq_pending()))

                   do_softirq();

 

         dec_preempt_count();

#ifdef CONFIG_TRACE_IRQFLAGS

         local_irq_enable();

#endif

         preempt_check_resched();

}

 

warning是由WARN_ON_ONCE(in_irq()|| irqs_disabled());代码产生的

 

解决方法

解决了disconnect CallTrace

/drivers/usb/host/hwa-hc.c

static void hwahc_disconnect(structusb_interface *usb_iface)

{

       struct usb_hcd *usb_hcd;

       struct wusbhc *wusbhc;

       struct hwahc *hwahc;

 

       printk("in hwahc_disconnect\n");

 

       usb_hcd = usb_get_intfdata(usb_iface);

       wusbhc = usb_hcd_to_wusbhc(usb_hcd);

       hwahc = container_of(wusbhc, struct hwahc, wusbhc);

 

 

       wusbhc_b_destroy(&hwahc->wusbhc);

       usb_remove_hcd(usb_hcd);

       hwahc_destroy(hwahc);

       usb_put_hcd(usb_hcd);

}

 

static int hwahc_probe(struct usb_interface*usb_iface,

                       const structusb_device_id *id)

{

                   …

                   usb_hcd->wireless= 1;

       usb_hcd->irq= -1;

                  

}

 

以上解决了disconnect的问题。

2.      Memory page alloc & free

Call Trace

Jun 11 03:09:14magic kernel: [  263.849177]  [<ffffffff81137d09>] ?free_pages+0x49/0x50

Jun 11 03:09:14magic kernel: [  263.849186]  [<ffffffffa01949b2>] ? hwarc_neep_release+0x32/0x40[hwa_rc]

Jun 11 03:09:14magic kernel: [  263.849202]  [<ffffffffa0359f7b>] ? uwb_rc_rm+0x3b/0xd0 [uwb]

Jun 11 03:09:14magic kernel: [  263.849211]  [<ffffffffa01940a1>] ?hwarc_disconnect+0x41/0x70 [hwa_rc]

Jun 11 03:09:14magic kernel: [  263.849225]  [<ffffffff813d5998>] ?usb_unbind_interface+0x78/0x160

Jun 11 03:09:14magic kernel: [  263.849235]  [<ffffffff8137407f>] ?__device_release_driver+0x6f/0xe0

Jun 11 03:09:14magic kernel: [  263.849241]  [<ffffffff813741ed>] ?device_release_driver+0x2d/0x40

Jun 11 03:09:14magic kernel: [  263.849248]  [<ffffffff813730f3>] ?bus_remove_device+0xa3/0x110

Jun 11 03:09:14magic kernel: [  263.849258]  [<ffffffff81370b2d>] ?device_del+0x12d/0x1e0

Jun 11 03:09:14magic kernel: [  263.849266]  [<ffffffff813d1c50>] ?usb_disable_device+0xb0/0x2b0

Jun 11 03:09:14magic kernel: [  263.849273]  [<ffffffff813ca862>] ?usb_disconnect+0xa2/0x1c0

Jun 11 03:09:14magic kernel: [  263.849280]  [<ffffffff813cc6fe>] ?hub_thread+0x75e/0x1820

Jun 11 03:09:14magic kernel: [  263.849291]  [<ffffffff8100969d>] ?__switch_to+0x7d/0x340

Jun 11 03:09:14magic kernel: [  263.849304]  [<ffffffff810a1460>] ?autoremove_wake_function+0x0/0x40

Jun 11 03:09:14magic kernel: [  263.849311]  [<ffffffff813cbfa0>] ?hub_thread+0x0/0x1820

Jun 11 03:09:14magic kernel: [  263.849320]  [<ffffffff810a0fce>] ?kthread+0x9e/0xc0

Jun 11 03:09:14magic kernel: [  263.849327]  [<ffffffff8100c28a>] ?child_rip+0xa/0x20

Jun 11 03:09:14 magickernel: [  263.849336]  [<ffffffff810a0f30>] ? kthread+0x0/0xc0

Jun 11 03:09:14magic kernel: [  263.849341]  [<ffffffff8100c280>] ?child_rip+0x0/0x20

Jun 11 03:09:14magic kernel: [  263.849345] Disablinglock debugging due to kernel taint

 

/drivers/uwb /hwa-rc.c

staticvoid hwarc_neep_release(struct uwb_rc *rc)

{

        struct hwarc *hwarc = rc->priv;

 

        usb_kill_urb(hwarc->neep_urb);

        usb_free_urb(hwarc->neep_urb);

        printk("%srd_buffer=%p\n",__func__, hwarc->rd_buffer);

        if (hwarc->rd_buffer != NULL){

                printk("%srd_buffer=%p\n",__func__, hwarc->rd_buffer);

                free_page((unsigned long)hwarc->rd_buffer);

                hwarc->rd_buffer = NULL;

        }

}

 

 

staticint hwarc_post_reset(struct usb_interface *iface)

{

        struct hwarc *hwarc = NULL;

        ssleep(1);

        hwarc = usb_get_intfdata(iface);

        if(hwarc == NULL){

                printk("hwarc_post_reset:ERROR hwarc is NULL in hwarc_post_reset\n");

                return 0;

        }

        struct uwb_rc *uwb_rc =hwarc->uwb_rc;

 

        return uwb_rc_post_reset(uwb_rc);

}

以上解决了内核Page free的问题。

 

3.      Kernellock

Call Trace

About the Spin lock. Kernel lock:mutex_lock  semaphore_lock  spin_lock atomic_lock

/drivers/uwb/drp.c  +913

static voiduwb_rc_set_drp_cmd_done(struct uwb_rc *rc, void *arg,

                                    structuwb_rceb *reply, ssize_t reply_size)

{

        struct uwb_rc_evt_set_drp_ie *r =(struct uwb_rc_evt_set_drp_ie *)reply;

        unsigned long flags;

        printk("inuwb_rc_set_drp_cmd_done!!!!!!!!\n");

 

        if (r != NULL) {

                if (r->bResultCode !=UWB_RC_RES_SUCCESS)

                       dev_err(&rc->uwb_dev.dev, "SET-DRP-IE failed: %s(%d)\n",

                                uwb_rc_strerror(r->bResultCode),r->bResultCode);

        } else

               dev_err(&rc->uwb_dev.dev, "SET-DRP-IE: timeout\n");

 

        //spin_lock_bh(&rc->rsvs_lock);

       spin_lock_irqsave(&rc->rsvs_lock, flags);

        if (rc->set_drp_ie_pending > 1) {

                rc->set_drp_ie_pending = 0;

                uwb_rsv_queue_update(rc);

        } else {

                rc->set_drp_ie_pending = 0;

        }

        spin_unlock_irqrestore(&rc->rsvs_lock, flags);

        //spin_unlock_bh(&rc->rsvs_lock);

}

 

以上解决了内核锁嵌套问题!

<think>我们正在讨论如何通过`refcount_warn_saturate`的Call Trace来定位具体代码缺陷。 引用[1]中提到了crash可以使用`refcount_warn_saturate`来触发,当引用计数被设置为0时会触发警告。同时,引用[2]说明了当引用计数为0时调用`kref_get()`(即增加引用计数)会触发警告,因为此时对象可能正在被释放(竞争条件)。引用[3]则强调了Call Trace在调试中的重要性,即使在panic时,栈回溯信息仍然可用。 因此,我们可以按照以下步骤定位问题: ### 一、理解Call Trace结构 当`refcount_warn_saturate`被触发时,内核会打印警告信息并输出调用栈(Call Trace)。例如: ``` [ 3245.671741] refcount_t: underflow; use-after-free. [ 3245.672245] Call Trace: [ 3245.672491] <TASK> [ 3245.672703] refcount_warn_saturate+0x63/0x70 [ 3245.673155] obj_free+0x47/0x80 [target_module] [ 3245.673589] another_function+0x1a/0x30 [target_module] ... ``` 此Call Trace展示了从触发警告的函数(`refcount_warn_saturate`)开始,逐级回溯到引发问题的函数(如`obj_free`)。 ### 二、定位问题函数的步骤 1. **获取完整Call Trace** 通过`dmesg`或`/var/log/kern.log`获取完整日志,重点关注包含`refcount_t: underflow`或`saturation`的行及其下方的Call Trace。 2. **提取关键函数地址** 在Call Trace中,每一行格式为: `函数名+偏移量/函数总长度 [模块名]` 例如:`obj_free+0x47/0x80 [target_module]` 其中`0x47`是触发问题时的指令相对于函数起始地址的偏移量,`0x80`是函数总长度。 3. **使用调试工具解析地址** 使用`addr2line`或`gdb`将地址映射到源码行号: ```bash # 使用addr2line $ addr2line -e vmlinux -f -C 0xffffffffa0000047 # 示例地址 obj_free /path/to/source.c:123 # 使用gdb $ gdb vmlinux (gdb) l *obj_free+0x47 ``` 4. **分析问题函数** 定位到具体函数后,检查引用计数操作: - 是否在引用计数为0时执行了`refcount_dec()`? - 是否在引用计数为0时执行了`refcount_inc()`?[^2] - 是否在引用计数达到饱和后继续增加? 常见错误模式: ```c // 错误:未检查就减少 refcount_dec(&obj->ref); // 如果ref已为0,触发下溢 // 错误:未检查就增加 if (some_condition) refcount_inc(&obj->ref); // 若obj已被释放,ref可能为0 ``` ### 三、动态调试辅助 1. **内核内存检测工具** 启用`CONFIG_DEBUG_REFCOUNT`和`CONFIG_KASAN`,可捕获更多引用计数异常细节。 2. **触发路径追踪** 在可疑函数中加入堆栈打印: ```c // 在引用计数操作前添加 pr_info("Operation at: %pS\n", (void *)_RET_IP_); ``` 3. **竞争条件检测** 若问题由竞争引起(如引用[2]所述),使用锁或原子操作修复: ```c spin_lock(&obj_lock); if (refcount_inc_not_zero(&obj->ref)) { // 安全增加 /* 操作对象 */ } spin_unlock(&obj_lock); ``` ### 四、实战案例解析 #### 案例1:引用计数下溢 - **Call Trace**: ``` refcount_warn_saturate+0x63/0x70 release_object+0x3e/0x60 [module_x] ``` - **定位过程**: 1. 解析`release_object+0x3e`对应源码行 2. 发现代码:`refcount_dec(&obj->ref);` 但未检查`ref`是否已归零 - **修复方案**: ```diff - refcount_dec(&obj->ref); + if (refcount_dec_and_test(&obj->ref)) + kfree(obj); ``` #### 案例2:引用计数为0时增加 - **Call Trace**: ``` refcount_warn_saturate+0x5d/0x70 get_object+0x2a/0x50 [module_y] ``` - **定位过程**: 1. 解析`get_object+0x2a`地址 2. 对应代码:`refcount_inc(&obj->ref);` 但此时`obj`可能已被释放 - **修复方案**: ```diff - refcount_inc(&obj->ref); + if (!refcount_inc_not_zero(&obj->ref)) + return -ENOENT; // 对象已失效 ``` ### 五、常见陷阱 1. **并发访问缺失保护** 未用锁保护引用计数操作,导致多个线程同时修改。 2. **模块卸载问题** 模块卸载时未释放所有引用计数,可能触发后续误操作。 3. **循环引用** A引用B,B引用A,导致两者无法释放。 > 通过Call Trace定位问题本质是**逆向追踪执行路径**,结合源码分析与动态验证可高效修复缺陷[^3]。 --- ### 相关问题 1. 如何在内核模块中正确实现引用计数管理? 2. 使用`refcount_inc_not_zero()`时需要注意哪些竞争条件? 3. 如何配置内核以捕获引用计数相关的错误? 4. 引用计数与内存泄漏检测工具有哪些结合使用方法? [^1]: Balsn战队EXP分析 [^2]: Linux内核kref机制详解 [^3]: Linux内核调试方法总结之Call Trace </think>根据引用内容,通过`refcount_warn_saturate`的Call Trace定位代码缺陷需遵循以下系统化方法: ### 一、Call Trace关键要素解析 1. **警告类型识别** - **下溢(underflow)**:引用计数减到负数(通常出现在`refcount_dec()`操作) ``` refcount_t: underflow; use-after-free. [^1] ``` - **饱和(saturation)**:引用计数接近最大值(`REFCOUNT_SATURATED`,默认$2^{32}-1$) ``` refcount_t: addition overflow [^1] ``` 2. **函数地址解析** 使用`addr2line`工具将Call Trace中的地址映射到源码: ```bash $ addr2line -e /usr/lib/debug/boot/vmlinux-$(uname -r) 0xffffffffa3b7c047 drivers/net/ethernet/intel/igb/igb_main.c:4885 # 输出具体源码位置 ``` *注:需安装对应内核的调试符号包* 3. **内存池关联分析**(引用[1]的`kmalloc-32/128`困惑) - `kmalloc-XX`表示对象从特定大小的SLUB分配器缓存池分配 - 通过`/proc/slabinfo`验证: ```bash $ grep 'kmalloc-128' /proc/slabinfo kmalloc-128 2048 2048 128 32 1 : tunables 0 0 0 : slabdata 64 64 0 ``` ### 二、缺陷定位四步法 1. **回溯引用计数操作点** 在Call Trace中定位`refcount_warn_saturate()`的上层调用函数: ``` Call Trace: refcount_warn_saturate+0x63/0x70 obj_free+0x47/0x80 [target_module] # 关键线索 cleanup_handler+0x1a/0x30 ``` 2. **验证引用计数操作逻辑** - **下溢场景**:检查是否对已归零的引用计数执行`refcount_dec()` ```c // 错误示例:未检查直接减计数 refcount_dec(&obj->refcnt); // 当refcnt=0时触发警告 ``` - **饱和场景**:检查循环引用或缺少释放逻辑 ```c for (int i=0; i<1000000; i++) refcount_inc(&obj->refcnt); // 导致饱和 ``` 3. **并发竞争检测**(引用[2]) 使用`spin_lock_irqsave()`保护引用计数操作: ```c unsigned long flags; spin_lock_irqsave(&obj_lock, flags); if (refcount_inc_not_zero(&obj->refcnt)) { // 安全增加[^2] /* 操作对象 */ } spin_unlock_irqrestore(&obj_lock, flags); ``` 4. **内存状态验证** 通过`kmemleak`检测关联对象的内存状态: ```bash $ echo scan > /sys/kernel/debug/kmemleak # 触发内存扫描 $ cat /sys/kernel/debug/kmemleak # 检查未释放对象 ``` ### 三、自动化调试策略 1. **日志监控脚本**(解决引用[1]的`dmesg`手动操作问题) ```python # 自动捕获refcount警告及Call Trace import subprocess proc = subprocess.Popen(['dmesg', '-w'], stdout=subprocess.PIPE) while True: line = proc.stdout.readline() if b'refcount_t' in line: print("检测到异常:") print(line.decode()) for _ in range(10): # 捕获后续10行Call Trace print(proc.stdout.readline().decode()) ``` 2. **Kprobe动态追踪** 在内核运行时注入探针: ```bash $ echo 'p:ref_warn refcount_warn_saturate' > /sys/kernel/debug/tracing/kprobe_events $ echo 1 > /sys/kernel/debug/tracing/events/kprobes/ref_warn/enable $ cat /sys/kernel/debug/tracing/trace_pipe # 实时输出调用上下文 ``` ### 四、典型修复案例 ```c // 修复前:存在下溢风险 void obj_release(struct object *obj) { refcount_dec(&obj->refcnt); // 可能减到负数 if (refcount_read(&obj->refcnt) == 0) kfree(obj); } // 修复后:使用安全递减 void obj_release(struct object *obj) { if (refcount_dec_and_test(&obj->refcnt)) // 原子操作检测归零[^1] kfree(obj); } ``` > **关键结论**:Call Trace分析需结合引用计数操作点的**原子性验证**、**内存状态检测**和**并发场景模拟**,才能准确定位到代码缺陷层[^3]。 --- ### 相关问题 1. 如何在内核模块开发中避免引用计数管理错误? 2. 引用计数饱和攻击(DoS)有哪些防御方案? 3. 如何配置`kmemleak`进行内核内存泄漏检测? 4. 使用Kprobe进行动态调试的最佳实践是什么? [^1]: Balsn战队EXP分析 [^2]: Linux内核kref机制竞争条件 [^3]: Linux内核Call Trace调试方法
评论
成就一亿技术人!
拼手气红包6.0元
还能输入1000个字符
 
红包 添加红包
表情包 插入表情
 条评论被折叠 查看
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值