学习 crash命令和其他命令的结合使用方法。

crash是和kdump工具配套使用,用于解析kdump生成的vmcore文件。vmcore是内核的映像(实际上是整个内存的映像,一般来说我们会开启过滤功能,只记录内核页)。内核全部的数据结构都在这个映像里面。crash解析vmcore可以让我们看到触发kdump时刻系统的各种状态和内容,信息非常丰富,是定位分析内核问题的利器。

启动crash
SUSE11:linux11:/var/log/dump/2012-03-16-21:18 # crash /usr/lrsp/kdump/vmlinux-2.6.32.45-0.3-default /boot/vmlinux-2.6.32.45-0.3-default.gz vmcore
/var/log/dump/2012-03-16-21:18 是vmcore文件所在目录;2.6.32.45-0.3-default 是所用内核的版本号,可以用`uname -r`实现应景替换。
SUSE10: linux10:/var/log/dump/2012-03-16-21:18 # crash /usr/lrsp/kdump/vmlinux-2.6.16.46-0.12-smp vmcore
对于早期版本,如果/usr/lrsp/kdump/目录只有一个vmlinux文件,则直接运行 
crash /usr/lrsp/kdump/vmlinux vmcore

以上是针对ATAE环境的。ATAE部署的系统已经预置了包含内核的调试信息的vmlinux。其他环境可以安装debuginfo包或者自己编译vmlinux。

显示内核日志
内核把日志打印到内核态的日志缓冲区内,用户态klogd负责读取并转发给syslog记录到磁盘。在内核故障时,可能无法记录到磁盘,但内核日志缓冲区里面一般会有记录。既然vmcore是内存映像,那么日志缓冲区也就在里面了。内核最后打印的日志往往是我们分析内核问题的起点。 

crash> log | tail -n 20 
92789.909817] Kernel panic - not syncing: Watchdog fired!!!!!!!!!!!!!!!!!!!!!!!!!
92789.909821]
92790.014379] Pid: 31675, comm: bonnie++ Tainted: G M W N 2.6.32.45-0.3.2.3813.0.PTF-default #1
92790.014382] Call Trace:
92790.014405] [<ffffffff810061dc>] dump_trace+0x6c/0x2d0
92790.014412] [<ffffffff81398886>] dump_stack+0x69/0x73
92790.014416] [<ffffffff81398908>] panic+0x78/0x19b
92790.014437] [<ffffffffa012d0bc>] watchdog_fire+0x4c/0x50 [hherwatchdog]
92790.014456] [<ffffffff810583e4>] run_timer_softirq+0x174/0x240
92790.014461] [<ffffffff810534bf>] __do_softirq+0xbf/0x170
92790.014466] [<ffffffff810040bc>] call_softirq+0x1c/0x30
92790.014470] [<ffffffff81005cfd>] do_softirq+0x4d/0x80
92790.014474] [<ffffffff81053345>] irq_exit+0x85/0x90
92790.014478] [<ffffffff8100525e>] do_IRQ+0x6e/0xe0
92790.014484] [<ffffffff81003913>] ret_from_intr+0x0/0xa
92790.014507] [<0000000000403b5d>] 0x403b5d查看内核日志的crash命令是log。
crash是一个交互环境:
你可以输入help显示所有支持的命令;
你可以输入help <命令名>显示这个命令的帮助。
crash命令可以和外部得命令结合使用,比如 log | tail -n 20 ,很灵活很强大。 显示系统信息
crash> sys
KERNEL: /root/vmlinux-2.6.32.45-0.3.2.3813.0.PTF-default
DEBUGINFO: /root/vmlinux-2.6.32.45-0.3.2.3813.0.PTF-default
DUMPFILE: ./vmcore [PARTIAL DUMP]
CPUS: 2
DATE: Fri Jul 6 18:30:41 2012
UPTIME: 1 days, 01:45:49
LOAD AVERAGE: 4.99, 4.31, 2.88
TASKS: 225
NODENAME: linux1114
RELEASE: 2.6.32.45-0.3.2.3813.0.PTF-default
VERSION: #1 SMP 2011-08-22 10:12:58 +0200
MACHINE: x86_64 (2128 Mhz)
MEMORY: 4 GB
PANIC: "[92789.909817] Kernel panic - not syncing: Watchdog fired!!!!!!!!!!!!!!!!!!!!!!!!!"
crash>显示执行KDUMP的堆栈 
crash> bt
PID: 31675 TASK: ffff880118be6580 CPU: 0 COMMAND: "bonnie++"
#0 [ffff88000da03cd8] machine_kexec at ffffffff81020902
#1 [ffff88000da03d28] crash_kexec at ffffffff810875b0
#2 [ffff88000da03df8] panic at ffffffff81398a26
#3 [ffff88000da03e68] watchdog_fire at ffffffffa012d0bc
#4 [ffff88000da03e78] run_timer_softirq at ffffffff810583e4
#5 [ffff88000da03ee8] __do_softirq at ffffffff810534bf
#6 [ffff88000da03f38] call_softirq at ffffffff810040bc
#7 [ffff88000da03f50] do_softirq at ffffffff81005cfd
#8 [ffff88000da03f70] irq_exit at ffffffff81053345
#9 [ffff88000da03f80] do_IRQ at ffffffff8100525e
--- <IRQ stack> ---这个是触发kdump的上下文。通过这个我们跟踪内核崩溃的运行轨迹。比如上面的堆栈是在说:cpu 0发生了中断,中断退出时执行定时器软中断,有一个定时器超时了触发了它绑定的函数watchdog_fire,进而执行panic函数,最终触发了kdump。(machine_kexec停止当前内核并拉起预置的kdump内核,kdump内核启动完毕后,执行kdump用户态程序,保存原内核对应的内存映像,这就是kdump的基本原理)。 
显示进程列表 
crash> ps | more
PID PPID CPU TASK ST %MEM VSZ RSS COMM
0 0 0 ffffffff8180c020 RU 0.0 0 0 [swapper]
0 0 1 ffff88011bdea1c0 RU 0.0 0 0 [swapper]
1 0 1 ffff88011bdca040 IN 0.0 10380 644 init
2 0 1 ffff88011bdce080 IN 0.0 0 0 [kthreadd]
3 2 0 ffff88011bdd40c0 IN 0.0 0 0 [migration/0]
4 2 0 ffff88011bdd8100 IN 0.0 0 0 [ksoftirqd/0]
……crash> ps | grep UN #显示所有D状态(TASK_UNINTERRUPTIBLE)的进程
845 2 1 ffff8801194e6340 UN 0.0 0 0 [kjournald]
2216 1 1 ffff88011fe8e200 UN 0.0 19804 1252 syslog-ng
crash> ps | grep RU #显示所有R状态(TASK_RUNNING)的进程 
0 0 0 ffffffff8180c020 RU 0.0 0 0 [swapper]
0 0 1 ffff88011bdea1c0 RU 0.0 0 0 [swapper]
2298 2 1 ffff8801196fe340 RU 0.0 0 0 [kipmi0]
> 19320 6470 1 ffff880037adc4c0 RU 0.0 121056 1768前面的">"表示该进程正在CPU上执行。
> 31675 31666 0 ffff880118be6580 RU 0.0 11760 1140 bonnie++
crash> ps | grep IN #显示所有S状态(TASK_INTERRUPTIBLE)的进程 
1 0 1 ffff88011bdca040 IN 0.0 10380 644 init
2 0 1 ffff88011bdce080 IN 0.0 0 0 [kthreadd]
3 2 0 ffff88011bdd40c0 IN 0.0 0 0 [migration/0]
……显示进程的内核栈 
crash> bt 7355可以看到是一个缺页异常处理过程,访存->缺页异常->分配->回收->休眠
PID: 7355 TASK: ffff81065a5967a0 CPU: 7 COMMAND: "sshd"
#0 [ffff81065eeb9858] schedule at ffffffff802e916a
#1 [ffff81065eeb9930] cond_resched at ffffffff802e92df
#2 [ffff81065eeb9940] shrink_zone at ffffffff80169bc6
#3 [ffff81065eeb9ae0] try_to_free_pages at ffffffff8016b88e
#4 [ffff81065eeb9b80] __alloc_pages at ffffffff801664cc
#5 [ffff81065eeb9be0] read_swap_cache_async at ffffffff8017715e
#6 [ffff81065eeb9c20] swapin_readahead at ffffffff8016ceb9
#7 [ffff81065eeb9c70] __handle_mm_fault at ffffffff8016f178
#8 [ffff81065eeb9d10] do_page_fault at ffffffff802ec74b
#9 [ffff81065eeb9e00] error_exit at ffffffff8010bd19
exception RIP: copy_user_generic+147]
RIP: ffffffff801f9e93 RSP: ffff81065eeb9eb8 RFLAGS: 00010202
RAX: 0000000000000000 RBX: 0000000000000008 RCX: 0000000000000001
RDX: 0000000000000008 RSI: ffff810667391558 RDI: 00005555556bb6e0
RBP: 0000000000000008 R8: 0000000000000008 R9: ffff8106682145c0
R10: ffff81066886dc34 R11: ffffffff802b3f3b R12: ffff810667391540
R13: 00005555556bb6e0 R14: 0000000000000000 R15: 0000000000000000
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0000
#10 [ffff81065eeb9ec0] sys_select at ffffffff801987dc
#11 [ffff81065eeb9f80] system_call at ffffffff8010ae42查看内存使用信息
crash> kmem -i
PAGES TOTAL PERCENTAGE
TOTAL MEM 6151777 23.5 GB ----
FREE 27816 108.7 MB 0% of TOTAL MEM
USED 6123961 23.4 GB 99% of TOTAL MEM
SHARED 1755 6.9 MB 0% of TOTAL MEM
BUFFERS 58 232 KB 0% of TOTAL MEM
CACHED 4184930 16 GB 68% of TOTAL MEM
SLAB 15548 60.7 MB 0% of TOTAL MEM

TOTAL HIGH 0 0 0% of TOTAL MEM
FREE HIGH 0 0 0% of TOTAL HIGH
TOTAL LOW 6151777 23.5 GB 100% of TOTAL MEM
FREE LOW 27816 108.7 MB 0% of TOTAL LOW

TOTAL SWAP 4194963 16 GB ----
SWAP USED 4194963 16 GB 100% of TOTAL SWAP
SWAP FREE 0 0 0% of TOTAL SWAP
crash>查看数据结构 
crash> ps |grep UN
845 2 1 ffff8801194e6340 UN 0.0 0 0 [kjournald]#ffff8801194e6340就是该进程的task_struct的地址。
2216 1 1 ffff88011fe8e200 UN 0.0 19804 1252 syslog-ng 
crash> struct task_struct ffff88011fe8e200
struct task_struct {
state = 2,
stack = 0xffff88011b268000,
usage = {
counter = 2
……有了task_struct就几乎有了关于这个进程的一切,你可以通过它顺藤摸瓜,找到你想要的信息。 
crash> struct task_struct | more #不给地址时,显示数据结构的成员定义。
struct task_struct {
volatile long int state;
void *stack;
atomic_t usage;
……
crash>
crash> struct task_struct.pid #显示指定成员的定义,以及偏移,偏移很重要。
struct task_struct {
[1176] pid_t pid;
}
crash> struct task_struct.pid ffff88011fe8e200 #显示指定成员的值。
pid = 2216,
crash>查看全局变量 
crash> p sysctl_tcp_rmem #p实际上是gdb命令,crash内嵌了gdb。gdb 的很多命令都可以用,可通过help gdb了解。
sysctl_tcp_rmem = $3 =
{4096, 87380, 4194304}查看per_cpu变量
crash> p per_cpu__irq_stat #变量名称 irq_stat 加上 "per_cpu__" 前缀
PER-CPU DATA TYPE:
irq_cpustat_t per_cpu__irq_stat; #变量类型声明
PER-CPU ADDRESSES:
[0]: ffff88000da13480 # 0号cpu对应的变量地址
[1]: ffff88000da53480 # 1号cpu对应的变量地址 
crash> struct irq_cpustat_t ffff88000da13480 #显示0号cpu地址对应的内容
struct irq_cpustat_t {
__softirq_pending = 538,
__nmi_count = 23198362,
……
}查看某个指令地址对应的代码行
发生了oops,通过log看到了oops的地址Unable to handle kernel NULL pointer dereference at 0000000000000010 RIP:
<ffffffff80280fa7>{sockfd_lookup+53}

ffffffff80280fa7处访问了空指针,那么是哪一行代码?无需对着汇编反推源码位置,直接一个命令搞定 
 
crash> l *0xffffffff80280fa7
0xffffffff80280fa7 is in sockfd_lookup (net/socket.c:448).
443 }
444
445 if (file->f_op == &socket_file_ops)
446 return file->private_data; /* set in sock_map_fd */
447
448这一行:)
449 if (!S_ISSOCK(inode->i_mode)) {
450 *err = -ENOTSOCK;
451 fput(file);
452 return NULL;

还有很多,大家多多敲help …… 

在线使用crash剖析运行中的内核
前面介绍了crash可以从VMCORE中解析出内核的数据结构,帮助我们分析内核问题。既然VMCORE是内存的映像,那么肯定也可以解析运行中的内核。这个会非常有用处,比如:
1. 某个进程D状态僵死了,系统还OK,这时候没必要对系统做KDUMP。而echo t >/proc/sysrq-trigger显示的信息又十分有限。而使用crash对运行内核做剖析,可以获取进程的方方面面,搞清楚问题所在。
2. 某些数据结构内核没有通过proc导出到外部,不能使用简单命令立即获取到,而这些数据结构对某些问题的分析又十分重要,使用crash对运行内核做剖析你可以获取到任何你想要的内容。比如一个tcp连接的全部状态信息,而不仅是/proc/net/tcp导出的那一点点。
3. Hack内核。你可以"偷窥"到内核的数据内容,比如页表。这对分析、学习内核源码会有很大的帮助。而且如果你比较"邪恶" :) 你可以修改它。进入crash 输入help wr你就知道了。前不久suse11内核有一个计数溢出的BUG,需要400天才能重现,用wr命令修改了一个基础变量的值,立马就看到问题现象了,比重新编译内核快多了。

在线使用crash的方法很简单:

SUSE11: 
# crash /boot/vmlinux-2.6.32.45-0.3.2.4445.1.PTF-default.gz /usr/lrsp/kdump/vmlinux-2.6.32.45-0.3.2.4445.1.PTF-default #实际上就是不指定vmcore文件路径。
SUSE10: 
# crash -S /boot/System.map-2.6.16.60-0.21-smp /usr/lrsp/kdump/vmlinux-2.6.16.60-0.21-smp #不指定vmcore文件的路径,同时指定System.map

怎样查看变量的地址:
crash> sym boot_command_line
 c05b114c (T) boot_command_line