网站建设时间安排表,网站建设实训体会,wordpress首页代码压缩,电影网站排名怎么做这部分我们接着之前的思考#xff0c;看看内核异常日志的分析。
1 Panic 调试
2 Oops调试
内核出现Panic或Oops错误#xff0c;如何分析定位问题原因#xff1f;
首先#xff0c;保留现场#xff0c;如下所示为一次非法虚拟地址访问错误。 EXT4-fs (sdc3): recovery c…
这部分我们接着之前的思考看看内核异常日志的分析。
1 Panic 调试
2 Oops调试
内核出现Panic或Oops错误如何分析定位问题原因
首先保留现场如下所示为一次非法虚拟地址访问错误。 EXT4-fs (sdc3): recovery completeEXT4-fs (sdc3): mounted filesystem with ordered data mode. Opts: (null)Unable to handle kernel NULL pointer dereference at virtual address 00000004pgd cd3cc000[00000004] *pgd4d3bf831, *pte00000000, *ppte00000000Internal error: Oops: 17 [#1] SMP ARMModules linked in: hi_rtc(O) hi_ir(O) hi3536_adec(PO) hi3536_aenc(PO) hi3536_ao(PO) hi3536_ai(PO) hi3536_aio(PO) acodec(PO) gpioi2c(O) hi3536_ive(PO) hi3536_vda(PO) hi3536_jpege(PO) hi3536_h264e(PO) hi3536_chnl(PO) hi3536_venc(PO) hi3536_rc(PO) hi3536_hdmi(O) hifb(PO) hi3536_vou(PO) hi3536_vpss(PO) hi3536_viu(PO) hi3536_vgs(PO) hi3536_region(PO) hi3536_tde(PO) hi3536_jpegd(O) hi3536_vfmw(PO) hi3536_vdec(PO) hi3536_sys(PO) hi3536_base(PO) hiuser(O) hi_media(O) mmz(O) stmmacCPU: 2 PID: 1786 Comm: vecsupgradehisi Tainted: P O 3.10.0_hi3536 #39task: cfb2bc00 ti: ce164000 task.ti: ce164000PC is at rb_insert_color0x1c/0x17cLR is at SyS_epoll_ctl0x584/0x860pc : [c027e574] lr : [c00f9e2c] psr: 60000013sp : ce165f1c ip : 00000000 fp : 00000000r10: 00000001 r9 : cd3b2304 r8 : cd3b2300r7 : c075a1a8 r6 : cd080980 r5 : cf35a6c0 r4 : cd306000r3 : 00000000 r2 : cd080000 r1 : cd3b233c r0 : cd080980Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment userControl: 10c5387d Table: 4d3cc06a DAC: 00000015PC: 0xc027e4f4:e4f4 e8bd41f0 e12fff13 e3833001 e5843000 e8bd81f0 e5963008 e1a00005 e1a01006e514 e3530000 e5853004 13852001 e5865008 e5846008 15832000 e12fff37 e1a03005e534 e1a05006 e5952004 e3851001 e3520000 e5842008 e5854004 e5831000 1affffd6e554 eaffffd9 e5902000 e3520000 0a000054 e5923000 e3130001 112fff1e e92d4030e574 e593c004 e383e001 e1a05003 e152000c 0a000019 e35c0000 0a000002 e59c4000e594 e3140001 0a00001b e592c004 e15c0000 11a0e002 0a00002c e35c0000 e583c008e5b4 e5823004 0a000001 e3830001 e58c0000 e5930000 e3d0c003 e5820000 e583e000e5d4 05812000 08bd8030 e59c1008 e1530001 058c2008 158c2004 e8bd8030 e593c008LR: 0xc00f9dac:9dac e288703c e3a02000 e58d7020 e1a03007 ea000005 e596101c e59b201c e06220019dcc e3520000 da000009 e1a0200b e593b000 e35b0000 0a000007 e5961018 e28b30049dec e59b2018 e1510002 8afffff6 2afffff0 e28b3008 eafffff3 e30a71a8 e34c70759e0c e5862000 e1a00006 e586b004 e586b008 e59d1020 e5836000 e58d7018 eb0611ca9e2c e597c000 e157000c e24cc08c 0a000069 e1a0e00d e3ceed7f e3cee03f e3057dd89e4c e58d502c e34c7079 e58d4030 e1a0500e e58d6014 e1a0400c e59d6018 ea0000039e6c e594c08c e156000c e24c408c 0a000056 e595300c e3050dd8 e3091060 e34c00799e8c e34c100f e1a02004 e58d3000 e1a03004 e587b024 e587b028 e587b02c e587b030SP: 0xce165e9c:5e9c 00000000 00000040 000000d0 c00f9cb4 c09bfef0 00000000 00100100 c027e5745ebc 60000013 ffffffff ce165f04 cd3b2300 c0012b58 cd080980 cd3b233c cd0800005edc 00000000 cd306000 cf35a6c0 cd080980 c075a1a8 cd3b2300 cd3b2304 000000015efc 00000000 00000000 ce165f1c c00f9e2c c027e574 60000013 ffffffff c0446b145f1c cd306000 cf35a6c0 c00f9e2c 00000000 00000000 00000000 cd08098c cd0809b05f3c cd306000 c075a1a8 c07500b4 cd3b233c 00000104 cd306018 c00bef44 000000005f5c 0000001c 00000000 c00f8d04 0000001c cd080980 0000001c b3197858 000000105f7c 00000001 00000000 b1e00f08 00000004 b2ffc5e0 000000fb c0013128 ce164000R0: 0xcd080900:0900 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000000920 00000000 00000000 00000000 00000000 ffffffff ffffffff ffffffff ffffffff0940 ffffffff ffffffff c0756cf0 c0756d20 c0757510 c904b240 c0048858 002000340960 00280006 001d0020 00000000 00000000 00000000 00000000 00000000 000000000980 cd080000 00000000 00000000 cd3b2334 cd3b240c ffffffff cd306000 0000001009a0 00000001 cd23d000 cd23d000 cd3b2300 cd306084 cd306084 00000000 ffffffff09c0 0000001c b3197858 00000010 00000001 c0757510 cecca0c0 c0048858 0020003409e0 00280006 001d0020 00000000 00000000 00000000 00000000 00000000 00000000R1: 0xcd3b22bc:22bc 00000000 00000001 00000001 c0960640 00000000 00000000 cf28f800 0000000022dc 00000000 00000000 00000000 00000000 00000000 00000000 00000000 0000000022fc 00000000 36c236c2 00000000 00000000 cd3b230c cd3b230c cfb2bc00 00000000231c 00000000 cd3b2320 cd3b2320 00000000 cd3b232c cd3b232c cd3b240c cd08098c233c cd080000 ffffffff 00000000 c0756cf0 cf35a6c0 00000000 00000000 00000000235c 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000237c 00000000 cd3b2400 00000000 00000001 00050005 00000000 00000000 00000000239c 00000000 00000000 00000000 00000000 00000380 00000000 00000000 cd3c1f00R2: 0xcd07ff80:ff80 38343730 205d3032 203c3c3c 696d6448 74636f49 756f206c 2e2e2e74 3c23230affa0 31303030 33303030 23233e33 3030305b 34373030 5d303238 3e3e3e20 6d644820ffc0 636f4969 69206c74 2e2e2e6e 3c23230a 31303030 33303031 30305b23 37303030ffe0 33343834 3c3c205d 6448203c 6f49696d 206c7463 2e74756f 230a2e2e 30303c230000 00000000 cd3b2400 cd080980 cd08000c cd08000c ffffffff cd306180 000000110020 00000001 cd23d028 cd23d028 cd3b2300 cd306204 cd306204 00000000 ffffffff0040 0000001c 00000073 00000011 00000000 c0757510 cf32f780 c0048858 002000340060 00280006 001d0020 00000000 00000000 00000000 00000000 00000000 00000000R4: 0xcd305f80:5f80 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000005fa0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000005fc0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000005fe0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000006000 cd306000 cd306000 cf823850 cf429aa0 cf4e64a0 c05a5200 00040004 000000006020 00000002 00000802 00000003 00000000 00000000 00000000 00000000 000000006040 00000000 00000000 00000000 00000000 cd3b2200 00000000 00000000 000000006060 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000R5: 0xcf35a640:a640 00000000 00000000 00000000 00000000 cf24a980 00000000 00000000 00000000a660 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000a680 00000000 cf35a684 cf35a684 cf35a68c cf35a68c 00000000 00000000 00000000a6a0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000a6c0 cf35a6c0 cf35a6c0 cfa58910 cb8b1220 cf4362c0 c0556b74 00000000 00000000a6e0 00000002 00000002 00000003 00000000 00000000 00000000 00000000 00000000a700 00000000 00000000 00000000 00000000 cd3b2200 00000000 00000000 00000000a720 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000R6: 0xcd080900:0900 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000000920 00000000 00000000 00000000 00000000 ffffffff ffffffff ffffffff ffffffff0940 ffffffff ffffffff c0756cf0 c0756d20 c0757510 c904b240 c0048858 002000340960 00280006 001d0020 00000000 00000000 00000000 00000000 00000000 000000000980 cd080000 00000000 00000000 cd3b2334 cd3b240c ffffffff cd306000 0000001009a0 00000001 cd23d000 cd23d000 cd3b2300 cd306084 cd306084 00000000 ffffffff09c0 0000001c b3197858 00000010 00000001 c0757510 cecca0c0 c0048858 0020003409e0 00280006 001d0020 00000000 00000000 00000000 00000000 00000000 00000000R7: 0xc075a128:a128 00000000 c002e900 00000000 c0795dd4 00000000 c065aa7c c07500b0 00000004a148 000001a4 00000000 c002e900 00000000 c0795dd4 00000000 c065aa90 c07500a8a168 00000004 000001a4 00000000 c002e900 00000000 c0795dd4 00000000 00000000a188 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000a1a8 cd30608c cd30608c c075a1b0 c075a1b0 00000000 00000000 c075a1c0 c075a1c0a1c8 cfb2bc00 00000000 c065aa7c c07500b8 00000004 000001a4 00000000 c002e2c4a1e8 00000000 c0795e10 c075a218 00000000 00000000 00000000 00000000 00000000a208 00000000 00000000 00000000 00000000 7fffffff c0664070 00000000 c00fa6c4R8: 0xcd3b2280:2280 00000001 00000000 cd3b2288 cd3b2288 00000000 00000000 000b000b cd3c3bdc22a0 cd3c3bdc 00000000 00000003 00000010 00000001 00000001 00000002 0000000022c0 00000001 00000001 c0960640 00000000 00000000 cf28f800 00000000 0000000022e0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000002300 36c236c2 00000000 00000000 cd3b230c cd3b230c cfb2bc00 00000000 000000002320 cd3b2320 cd3b2320 00000000 cd3b232c cd3b232c cd3b240c cd08098c cd0800002340 ffffffff 00000000 c0756cf0 cf35a6c0 00000000 00000000 00000000 000000002360 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000R9: 0xcd3b2284:2284 00000000 cd3b2288 cd3b2288 00000000 00000000 000b000b cd3c3bdc cd3c3bdc22a4 00000000 00000003 00000010 00000001 00000001 00000002 00000000 0000000122c4 00000001 c0960640 00000000 00000000 cf28f800 00000000 00000000 0000000022e4 00000000 00000000 00000000 00000000 00000000 00000000 00000000 36c236c22304 00000000 00000000 cd3b230c cd3b230c cfb2bc00 00000000 00000000 cd3b23202324 cd3b2320 00000000 cd3b232c cd3b232c cd3b240c cd08098c cd080000 ffffffff2344 00000000 c0756cf0 cf35a6c0 00000000 00000000 00000000 00000000 000000002364 00000000 00000000 00000000 00000000 00000000 00000000 00000000 cd3b2400Process vecsupgradehisi (pid: 1786, stack limit 0xce164238)Stack: (0xce165f1c to 0xce166000)5f00: cd3060005f20: cf35a6c0 c00f9e2c 00000000 00000000 00000000 cd08098c cd0809b0 cd3060005f40: c075a1a8 c07500b4 cd3b233c 00000104 cd306018 c00bef44 00000000 0000001c5f60: 00000000 c00f8d04 0000001c cd080980 0000001c b3197858 00000010 000000015f80: 00000000 b1e00f08 00000004 b2ffc5e0 000000fb c0013128 ce164000 000000005fa0: 01fc727c c0012f80 b1e00f08 00000004 0000000e 00000001 00000010 b2ffc5e05fc0: b1e00f08 00000004 b2ffc5e0 000000fb 00000001 00000001 01fc7668 01fc727c5fe0: b3627ddc b2ffc4fc b334f0b0 b608d3bc 60000010 0000000e 00000000 00000000[c027e574] (rb_insert_color0x1c/0x17c) from [c00f9e2c] (SyS_epoll_ctl0x584/0x860)[c00f9e2c] (SyS_epoll_ctl0x584/0x860) from [c0012f80] (ret_fast_syscall0x0/0x30)Code: e5923000 e3130001 112fff1e e92d4030 (e593c004)---[ end trace a35b773550a06f61 ]---对于最终分析问题原因来讲以上信息的每一行都很重要。
从上述信息中我们可以获得出现问题的主要原因比如这里的地址错误出现问题时的现场信息包括
1 现场PC指针LR指针函数返回时的地址上一级调用点的下一条指令地址寄存器地址堆栈指针等
2 问题出现时当前的进程或者内核线程关键的调用堆栈
3 除此内核还将上述寄存器内容所对应内存地址附近的内存信息dump了出来。对于PC来讲则是机器指令如最后的Code行
基于上述信息我们需要分析问题产生的原因代码中的BUG。
为了便于调试可以按下述步骤进行操作
首先编译带debug版本的kernel在menuconfig中kernel hacking中选中with debug info选项
其次反汇编当前编译的kernel源码使用交叉编译工具的objdump命令输入文件为未压缩的内核二进制文件vmlinux
第一步中便于我们定位代码行第二步便于我们查看实际的汇编指令以便对应到上述日志信息
完成上述两步后首先直接调用交叉编译工具链的gdb程序调试 kernel的 vmlinux文件
输入l *func0Xab 即可显示问题所在行。对于本奔溃输入 l *rb_insert_color0x1cgdb输出 0xc027e574 is in rb_insert_color (lib/rbtree.c:94).89 } else if (rb_is_black(parent))90 break;9192 gparent rb_red_parent(parent);9394 tmp gparent-rb_right;95 if (parent ! tmp) { /* parent gparent-rb_left */96 if (tmp rb_is_red(tmp)) {97 /*98 * Case 1 - color flips
可见地址0xc027e574能够对应上且显示了出问题的代码行为tmp gparent-rb_right;
其实有了这个信息结合日志虚拟地址错误我们可以猜到gparent是一个空地址。4正好是成员变量的偏移。
一般找到出问题的代码行之后可以简单扫扫代码是否有明显的问题或者问题的原因可能出在什么地方。但是一般而言这一步也不会有什么收获。如果是很明显的错误应该不会这么容易留下来。不过我们可以先走一个捷径比如查看Linux内核的修改记录看看是否有针对当前文件或函数的补丁记录。方法是打开下面的网址 https://git.kernel.org/ 在其中找source tree进一步找针对当前使用的版本 kernel/git/torvalds/linux.git - Linux kernel source tree
找到对应目录进入查看修改日志以确认是否后续更新版本有对当前版本所定位到问题点的代码的修改或补丁
这一步不一定有明显的收获但是可以用于快速检查如果正好有就避免了时间浪费。
如果没有明显的收获我们可以下载更新版本的完整源码进行简单对比看看有什么更新。如果对比后还是没有收获则可能需要进一步阅读源码用以获取更加准确和详细的信息。
实际源码分析时我们需要注意到出问题的点只是最后暴露问题的点问题的引入很可能在之前的调用路径上所以可能不仅需要分析当前定位到的代码附近还需要分析调用者及调用者的调用者
这里更详细的进一步调试可以结合反汇编内核得到的汇编指令进行。还是对于上一个例子 arm-hisiv400-linux-objdump -d vmlinux_nodebug vmlinux_nodebug_assembler
用上面命令生成汇编代码用二进制编辑工具打开
也可以只反汇编出问题文件的目标文件即.o格式的文件进行汇编代码查看分析
输入出问题的PC地址0xc027e574可以查看问题点的汇编代码 c027e558 rb_insert_color:c027e558: e5902000 ldr r2, [r0]c027e55c: e3520000 cmp r2, #0c027e560: 0a000054 beq c027e6b8 rb_insert_color0x160c027e564: e5923000 ldr r3, [r2]c027e568: e3130001 tst r3, #1c027e56c: 112fff1e bxne lrc027e570: e92d4030 push {r4, r5, lr}c027e574: e593c004 ldr ip, [r3, #4]可以看到r3加上4给了IP寄存器这里r3的内容是多少可以对应问题现场日志 pc : [c027e574] lr : [c00f9e2c] psr: 60000013sp : ce165f1c ip : 00000000 fp : 00000000r10: 00000001 r9 : cd3b2304 r8 : cd3b2300r7 : c075a1a8 r6 : cd080980 r5 : cf35a6c0 r4 : cd306000r3 : 00000000 r2 : cd080000 r1 : cd3b233c r0 : cd080980看到r3是0加4作为虚拟地址显然是错误的。
其他寄存器最近的寄存器及寄存器值作为地址的内存空间都可以从第一现场获取到也包括SP堆栈内容。结合寄存器和堆栈及内存大概可以分析代码出问题的原因。只不过这部分需要对照代码、汇编以及内存数据仔细分析了。可能需要画出一些数据结构及相关的地址来仔细分析。
对这里例子从代码来看eventpoll结构体对应着一个file描述符挂载着rbtree的根。每次add ctrl时添加新的节点。如果节点的父节点为空说明是根节点会打上黑树标识之后会不断添加子节点。
但是从汇编和现场日志来看当前要添加的节点地址为cd080980其父节点地址为cd080000但是父节点的第一个域也就是再上一级节点为00000000这与黑树节点类型不符。进一步从内存地址来看该节点的右孩子也就是cd080004地址为cb3b2400左孩子也就是cd080008地址为cd080980符合当前要添加节点的地址。这样来看从代码来看正常应该是不会出现0000000的根节点至少也是00000001。那问题会出在哪里内存被修改节点添加过程意外退出
另外需要关注arm调用时堆栈和参数传递问题。
如此分析epoll的红黑树应该是出了问题父节点的父节点为空代码中没有做判断是因为基于红黑树的规则不需要进行判断比如红节点的父节点不是红节点
最后补充说明内核受污染的信息来自网络 1: G: 所有的模块都是GPL的License。如果有模块缺少MODULE_LICENSE()或者声明是Proprietary的则为P。 2: F: 如果有模块是使用 insmod -f 强制载入的。否则为空。 3: S: 如果Oops发生在SMP的CPU上但这个型号的CPU还没有被认为是SMP安全的。 4: R: 如果有模块是使用 rmmod -f 强制卸载的。否则为空。 5: M: 有CPU报告了Machine Check Exception否则为空。 6: B: 如果有page-release函数发现一个错误的page或未知的page标志。 7: U: 来自用户空间的程序设置的这个标志位。 8: D: 内核刚刚死掉比如Oops或者是bug。 9: A: ACPI表被覆盖。 10: W: 之前kernel已经产生过警告。 3 RCU-STALL调试
补充一下内核打印中版本信息中的#xx后面的数字是版本的编译次数。该次数由scripts目录下的脚本生成每次新生成内核时该计数增加1并且会生成一个头文件包含启动 banner需要的信息。
言归正传。内核运行过程中会出现rcu-stall现象
该现象的典型日志0702的日志较为有价值其他的日志stall所发生的核信息不全
INFO: rcu_sched detected stalls on CPUs/tasks: { 0 1} (detected by 3, t4002984 jiffies, g59256, c59255, q494001){ 1} (t4003098 jiffies g59256 c59255 q494001)与rcu有关的一些背景知识关于tree rcu等参考博主文档
https://blog.csdn.net/wwwyue1985/article/details/127347496
基于上述背景分析该现象的产生原因
要定位具体的问题点需要继续进一步研究 rcu的调试方法和手段
RCU的调试方法
阅读内核文档中的相关说明通过分析现象对应日志对问题进行定位。另外也可以尝试人为修改代码引入问题从而辅助对问题的判断。
修改内核主动触发rcu就是人为制造rcu-stall现象
要触发内核错误最直接的方式就是修改内核代码。应用层要完成这一工作较为空难否则这将是内核的一个漏洞或者BUG被利用了。之前想到可以通过内存的操作影响到内核比如通过mmap进行物理虚拟内存映射进行操作但是细想起来映射的还是应用的地址空间并不能操作到内核地址空间所以应该是行不通的。
除了应用层最自然的修改内核的方式就是改动核心代码或者驱动。显然驱动更直接且容易切入影响点较为具体扩散面也较为容易控制整体又方便操作实施。这里为了方便调试我们采用动态加载的方式进行调试。
RCU-STALL既然是CPU有卡住逻辑导致宽限期内没有发生调度即产生平静状态切换参考内核文档 stallwarn.txt)那么模拟一个死循环卡住CPU应该就可以出发STALL了
显然模拟CPU看著最简单的就是在中断中或者原子上下文中进行delay让CPU忙等类似死锁状态。实际中采用定时器方案注册一个字符设备每当打开设备时定时器开始工作这里在定时器中循环调用mdelay产生长时间忙等状态
另外为了更详细的展示问题发生时的信息内核中配置了诸多RCU调试相关的配置。具体参见stallwarn文档。实际中感觉没有多出多少信息。
重新便于内核刷写运行。驱动加载并运行后现象比较容易出现 entry test cdev init test cdev have added to system!cdev open file pointer addr is cd2da6c0 entry cdevdev open pdev (null) cdev (null) cdev timer will entry after 1s current jiffies -15420 cdev timer will entry after 1s current jiffies2 -15419 entry cdevdev write 26953552 cdev write file pointer addr is cd2da6c0 pos0 Driver got data(write by app) 1 Driver got data(write by app) 2 Driver got data(write by app) 3 Driver got data(write by app) 4 Driver got data(write by app) entry cdevdev release cdev release file pointer addr is cd2da6c0 cur atomic count is -1 cdev timer will entry after 1s current jiffies3 -15319 timer param is 10004 timer mdelay... 999 timer mdelay... 998 timer mdelay... 997 timer mdelay... 996 timer mdelay... 941 timer mdelay... 940 timer mdelay... 939 INFO: rcu_sched self-detected stall on CPU { 1} (t6001 jiffies g382 c381 q106563)Backtrace for cpu 1 (current):INFO: rcu_sched detected stalls on CPUs/tasks: { 1} (detected by 3, t6002 jiffies, g382, c381, q106563)CPU: 1 PID: 0 Comm: swapper/1 Tainted: P O 3.10.0_hi3536 #43[c0019d30] (unwind_backtrace0x0/0xf4) from [c0016de4] (show_stack0x10/0x14)[c0016de4] (show_stack0x10/0x14) from [c0018460] (smp_send_all_cpu_backtrace0x70/0xcc)[c0018460] (smp_send_all_cpu_backtrace0x70/0xcc) from [c007e61c] (rcu_check_callbacks0x3a4/0x654)[c007e61c] (rcu_check_callbacks0x3a4/0x654) from [c00328e0] (update_process_times0x40/0x6c)[c00328e0] (update_process_times0x40/0x6c) from [c00645c8] (tick_nohz_handler0xb4/0x11c)[c00645c8] (tick_nohz_handler0xb4/0x11c) from [c002194c] (sp804_timer_isr0x20/0x28)[c002194c] (sp804_timer_isr0x20/0x28) from [c0076a50] (handle_irq_event_percpu0x54/0x17c)[c0076a50] (handle_irq_event_percpu0x54/0x17c) from [c0076bb8] (handle_irq_event0x40/0x60)[c0076bb8] (handle_irq_event0x40/0x60) from [c0079920] (handle_fasteoi_irq0x80/0x158)[c0079920] (handle_fasteoi_irq0x80/0x158) from [c00762d0] (generic_handle_irq0x28/0x40)[c00762d0] (generic_handle_irq0x28/0x40) from [c0013e9c] (handle_IRQ0x40/0x90)[c0013e9c] (handle_IRQ0x40/0x90) from [c0008514] (gic_handle_irq0x34/0x8c)[c0008514] (gic_handle_irq0x34/0x8c) from [c0012bc0] (__irq_svc0x40/0x50)Exception stack(0xcf867e60 to 0xcf867ea8)7e60: 00084885 ffffffff 00003548 c026cfd8 00000342 c07504a4 000003aa cf8660387e80: bf83c03c cf812a14 cf812c14 cf812000 00000001 cf867ea8 bf83c08c c026d0087ea0: 20000113 ffffffff[c0012bc0] (__irq_svc0x40/0x50) from [c026d008] (__loop_delay0x0/0x10)sending IPI to all other CPUs:IPI backtrace for cpu 3CPU: 3 PID: 0 Comm: swapper/3 Tainted: P O 3.10.0_hi3536 #43task: cf85d400 ti: cf86a000 task.ti: cf86a000PC is at arch_cpu_idle0x2c/0x30LR is at arch_cpu_idle0x28/0x30pc : [c00142a8] lr : [c00142a4] psr: 60000013sp : cf86bfe0 ip : 00000000 fp : c0741cf0r10: cf86a000 r9 : cf86a000 r8 : c07775e5r7 : cf86a000 r6 : c0545e6c r5 : c0741d50 r4 : c07775e5r3 : 00000000 r2 : 00013868 r1 : 00000000 r0 : c09b6930Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment kernelControl: 10c5387d Table: 4da4c06a DAC: 00000015PC: 0xc0014228:4228 f10c0040 e3053e6c e34c3054 e5933000 e5930000 e200000f eb09a380 e1a010044248 e59f200c e30400a8 e34c0001 eb0958f2 e7f001f2 c0777888 f1080040 e12fff1e4268 e3a00001 ea004e39 e3a00002 ea004e37 ea148cf5 e92d4008 e3073808 e34c30774288 e5933080 e3530000 0a000002 e12fff33 f1080080 e8bd8008 eb0033ce f108008042a8 e8bd8008 ea004e8b e92d4008 eb0010f8 f10c0080 eafffffe e92d4010 eb0010f442c8 e3073808 e34c3077 e5933084 e3530000 08bd8010 e8bd4010 e12fff13 e92d403842e8 e1a04000 eb0010ea e3053988 e34c3074 e1a01004 e30054a4 e593205c e34c50754308 e5d30000 e3a04ffa e12fff32 e30605b0 e5953004 e3400666 e12fff33 e2544001LR: 0xc0014224:4224 f10c0080 f10c0040 e3053e6c e34c3054 e5933000 e5930000 e200000f eb09a3804244 e1a01004 e59f200c e30400a8 e34c0001 eb0958f2 e7f001f2 c0777888 f10800404264 e12fff1e e3a00001 ea004e39 e3a00002 ea004e37 ea148cf5 e92d4008 e30738084284 e34c3077 e5933080 e3530000 0a000002 e12fff33 f1080080 e8bd8008 eb0033ce42a4 f1080080 e8bd8008 ea004e8b e92d4008 eb0010f8 f10c0080 eafffffe e92d401042c4 eb0010f4 e3073808 e34c3077 e5933084 e3530000 08bd8010 e8bd4010 e12fff1342e4 e92d4038 e1a04000 eb0010ea e3053988 e34c3074 e1a01004 e30054a4 e593205c4304 e34c5075 e5d30000 e3a04ffa e12fff32 e30605b0 e5953004 e3400666 e12fff33
因为RCU-STALL检测超时时间设置为了60所以可以看到60秒后stall现象暴露出来 INFO: rcu_sched self-detected stall on CPU
跟实际设备上的原因信息一致当然具体原因有差异
我们来分析日志看是否能够从日志中定位出人为制造的问题点
首先主要看看堆栈信息从日志打印的堆栈中可以看出最终是在时钟滴答中断中调用rcucallback检查发现超过了宽限期然后主动dump内核异常信息。并且发送了IPI给其他核心触发其他核心的寄存器、内存和堆栈信息。不过对于这里的stall问题其他核心的信息仅仅参考当前看来并不具有太大意义这样整体一看整个日志信息似乎表达的都是废话
但是我们需要注意一个细节问题出现的核心的硬件中断前的日志信息这是最关键的结合当前情况个人的理解。 [c0008514] (gic_handle_irq0x34/0x8c) from [c0012bc0] (__irq_svc0x40/0x50)Exception stack(0xcf867e60 to 0xcf867ea8)7e60: 00084885 ffffffff 00003548 c026cfd8 00000342 c07504a4 000003aa cf8660387e80: bf83c03c cf812a14 cf812c14 cf812000 00000001 cf867ea8 bf83c08c c026d0087ea0: 20000113 ffffffff[c0012bc0] (__irq_svc0x40/0x50) from [c026d008] (__loop_delay0x0/0x10)中断irq_svc是在loop_delay的时候调用的这非常关键
对于这里给出的地址像c026d008 c0012bc0 我们可以在当前编译内核的目录进行定位通过交叉编译链的arm----gdb工具不过前提是内核需要是debug版本。
如果没有编译debug的vmlinux还是可以分析的有两种方法
一种是在当前编译内核的目录下通过System.map文件来分析该文件中保存有内核符号和地址的映射对应关系
一种是根据运行设备的/proc/kallsyms符号表进行定位
鉴于这里内核已经卡死了我们选择第一种可以在不用重启设备的情况下进行分析
比如选择这种方法 cat System.map | grep c0012bc0
但是考虑到地址可能对于函数开始有偏移所以大部分时候除非是在函数调用开始否则几乎不会输出任何东西。所以我们可以查看该地址附近的信息比如通过下面这种方法省略掉后两位地址位看是否有匹配 cat System.map | grep c0012b c0012b20 t __dabt_svc c0012b80 t __irq_svc c0012bd0 t __und_fault c0012be0 t __und_svc
我们看到这个地址附近的函数跟上述日志信息里的函数是有一致的。从这里获取开始地址加上日志中的偏移结合反汇编基本可以定位出调用栈所在的代码。当然前提是内核不要有新的修改编译否则上述地址就可能发生变化。
我们再看看调用者的地址 cat System.map | grep c026d008 c026d008 T __loop_delay
说明是在loog_delay函数中发生了中断然后触发了stall的检查条件。所以问题很可能是在该loop_delay相关的函数中。这里有两点引申含义
1 是说问题可能是由delay导致。这一点比较容易猜想。当delay在让CPU卡住等待时如果时间过长显然肯定会触发rcu-stall的。
2 是说大概就是在delay相关的接口中。为什么是大概呢当然这里的前提还是假设是由delay导致了问题。这涉及到内核的编译处理。
我们知道函数调用涉及入栈出栈的问题如果只是一个简单的函数当被频繁调用那么光是栈处理消耗的CPU就可能远大于函数本身的逻辑处理对CPU的占用。所以这就导致内联函数的产生。更进一步的如果一个函数是静态的且只在当前文件中被调用了一次那么编译器可能也会将其优化为类似内联函数形式。
说了这么多其实要表达的核心思想是代码中看到的函数调用不一定在编译后还是原本的函数调用可能就被嵌入到调用者的汇编里了在汇编代码中看不出有函数调用痕迹。这样一来对定位代码就产生了一些干扰。我们需要结合dump栈中的偏移和汇编代码结合内核代码一起定位调用点在原始C代码中的那个位置。
实际调试时常会发现汇编中的调用总是少于实际C代码的就是因为很多成为了调用者内部逻辑规避了利用栈传递参数的逻辑。
对于ARM架构来讲大部分介绍是说函数调用通过寄存器结合堆栈进行参数传递的这一点在跟踪汇编代码时需要注意。
有了上述信息就可以围绕已有线索展开问题原因的定位分析。
单纯看delay虽然与问题的原因很容易对应上但是范围太广。delay是非常基础的函数在内核中调用点散步很广很难直接下手。这时候就需要对当前CPU的堆栈进行分析。因为堆栈可能会给出这个delay的具体调用者。从而提供更准确的信息。堆栈中记录的调用者与真正导致问题的代码可能比较接近。
上面的日志中也给出了异常栈信息。按照从高地址向低地址增长的方式来看低地址处应该是更接近CPU现场的被调用点高地址是调用者
考虑到内核地址在3-4GB范围内即C0000000--F0000000地址空间所以可以特别关注C开头的地址很可能是内核地址 c026d008 c026d008 T __loop_delay cf867ea8 非内核地址 cf812000 cf81开始的这几个也不是内核地址 可能是内核数据空间也可能是参数地址 c07504a4 c07504a4 D arm_delay_ops
可见loop_delay是由该函数调用到的
struct arm_delay_ops arm_delay_ops {.delay __loop_delay,.const_udelay __loop_const_udelay,.udelay __loop_udelay,};从实际的代码中可以对应上 c026cfd8 c026cfd8 T __loop_const_udelay
从目前的堆栈分析来看函数调用似乎就这么多了。另外一些数据可以猜测验证也是有帮助的。比如000003aa十进制就是938是timedelay的计数值反推时我们可以使用该值验证人为的出发点比如1000-938接近60。但是正向跟踪其实是有点难度的.不过不管怎样也是一些重要信息。可能就在这些蛛丝马迹中发现问题点。还比如一些0或者1的值可能就跟布尔条件变量有关等等。
其实这里的例子还有一些特殊性。为了验证问题采用了动态加载模块的方式
我们对模块进行反汇编看一下arm-hisiv400-linux-objdump -d testdrv.ko
发现其中的地址都是相对地址偏移是基于00000000的所以模块的实际地址可能是在insmod的时候由内核重新分配的。这样来看堆栈中的地址在内核编译符号中找不到可能能够讲得通了。同时从另外一个角度来看如果产品中存在这种动态加载的模块那么当问题产生时给问题的定位会带来一些额外的复杂度和工作。
在保留堆栈日志信息的前提下我们重新加载模块进行进一步的定位分析。 cat /proc/modules 可以查看到外部模块的地址信息 testdrv 6256 0 - Live 0xbf83c000 (O)
比如这里的测试模块可以看到是在0xbf83c000这个地址开始的空间内
此时再回看堆栈日志信息可以看到有两个地址可疑
第一个bf83c08c此时模块是动态加载需要在运行的内核中查看方法同前述
~ # cat /proc/kallsyms | grep bf83c0bf83c000 t $a [testdrv]bf83c00c t my_tasklet_func [testdrv]bf83c0b4 t cdevdev_write [testdrv]bf83c03c t cdevdev_timer [testdrv]bf83c000 t add_var [testdrv]第二个bf83c03c跟之前一样
从这两个地址可以初步定位出问题关键点timer函数。
接下来就需要根据上述地址的具体便宜结合汇编定位出C代码然后检查代码了。因为是人为制造的触发流程代码简单直接 int count 1000;while(count--) {mdelay(1000);printk(KERN_INFO timer mdelay... %d \n, count);}到这一步根据日志定位代码的流程基本就完成了。从上述流程来看异常栈是非常非常重要的信息。
在这整个过程中还有几个问题需要明确
需要明确每次insmod模块时CPU会分配相同的地址吗从上面重新加载模块定位函数来看地址似乎是一样的。这是巧合还是固有设计待验证。
insmod模块时是加载到用户空间地址还是内核空间地址从上述日志来看是在用户空间了因为是B开头的地址。
虽然如上分析问题定位在delay中但也只是一种可能得到了验证。因为根据RCU-STALL的原理来讲还是有其他可能的包括 本cpu的其他地点这里只是凑巧在中断前的地址中发现了问题并凑巧在模块中得到了定位。关键还是要找到宽限期后未经历静止状态的CPU核及其上任务。
2 其他CPU的可能性。这一点可以通过绑定CPU核心来验证。比如将驱动模块的定时器绑定到其他CPU核心上默认时钟滴答是否应该在CPU0上可以编码来验证这一点。
如果得到验证那么其他CPU的寄存器和堆栈就非常值得分析了。
答案应该是明确的。因为存在其他CPU检测到当前CPU出现stall问题。 如果问题最终能定位则可以用该内核放到产品中定位产品测试中出现的stall现象
如果不能则采用重启等补充手段 手段1 使用延迟队列的 restart参见前述kernel_restart部分。
如果循环触发rcu-stall放在工作队列中的restart是否有机会调用待验证。
经过验证该restart几乎没有机会执行。
在应用层部分命令还是可以正常执行比如top可以查看进程和线程的情况。
但是应用层的定时喂狗似乎是存在问题的超时后单片机重启了设备是因为内核卡住定时器不准了还是应用执行被停住了猜测这里是因为insmod的测试驱动使用了mdelay,卡住了cpu可能导致该核心上的应用定时器不再准确从而导致喂狗mcu失败
该机制目前看不太可靠内核的运行逻辑不是固定的。 手段2使用panic当发现rcu-stall后主动触发panic可以挂死上层应用触发单片机看门狗 手段3启用看门狗验证panic和rcu-stall是否会影响到内核中断处理从而触发cpu内部看门狗
首先对于单纯rcu-stall感觉不会影响到硬件中断实际测试确实不会影响中断串口输入还可以正常使用。但是reboot命令本身不起作用。
其次对于panic加看门狗测试看可以生效到时间后cpu被复位
综上针对rcu-stall要重启设备的话可以使用panic结合上层应用使用的MCU喂狗机制可以完成系统的硬复位。内核看门狗作为一种补充手段保留。
其实panic可以使用一个超时参数在panic发生后经过超时时间后重启设备。这需要配置内核但是这个重启是否管用待测试。
经过测试该超时在rcu-stall上下文掉用不能够完成重启跟前述kernel_restart表现一致。因为之前直接调用重启函数不管用才使用了工作队列方式才有了这里所描述的上述方案。 最终的方式就是出现RCU-STALL--触发panic--触发内核看门狗--如果失败触发应用看门狗。两重保障。panic timeout可以保留也可以不保留应该会屏蔽CPU中断这里选择保留。 根据stallwarn文档产生stall的可能原因包括
1 一个CPU在一个RCU读关键区循环. 对应RCU的宽限期图示如果CPU没有出来宽限期就会超时.
2 一个CPU在中断关闭的情况下循环。这个条件会导致RCU-sched和RCU-bh产生stall 中断关闭时如果循环则存在无法打破循环的问题。
3 一个CPU在抢占关闭的情况下循环。这个条件可以导致RCU-sched stalls并且如果ksoftirqd在使用RCU-bh 会stalls。
4 一个CPU在下半部关闭的情况下循环。这个条件会导致RCU-sched和RCU-bh stalls
5 对于非抢占内核CPU在内核任意地方循环而没有主动执行调度。这个条件有个疑问2 3 4 条也是就是中断是否会影响stall的判断从stall堆栈中还能看到中断来看中断本身对stall的影响是比较小的
6 其他一些条件包括RCU本身的bug、硬件bug等。
