解读系统(Kernel)奔溃(Oops)

我们通常在遇到系统的奔溃时会做什么?不去管具体的原因而直接重启系统?还是尝试着去发现些什么?可能作为一个普通的用户来说,确实不太需要关心太多,重启或者就可以了。不过一些企业中,或者这种情况发生在你的一个提供基础服务的服务器上时,如果不去关心这些错误原因,可能会给以后埋下一颗定时炸弹,因为你不知道什么时候它会再次发生奔溃。
有时我们是需要一些Geek精神的,例如我们看到我们系统的串口里有这样的一段输出代码时该怎么办。

[  257.264914] BUG: unable to handle kernel NULL pointer dereference at 0000000000000001
[  257.266396] IP: crasher_write+0x77/0xb0 [crasher]
[  257.267382] PGD 0 
[  257.267383] 
[  257.267771] Oops: 0002 [#1] SMP
[  257.268071] Modules linked in: crasher(OE) binfmt_misc crct10dif_pclmul crc32_pclmul ghash_clmulni_intel tpm_tis joydev tpm_tis_core ppdev virtio_
balloon qxl ttm drm_kms_helper snd_hda_codec_generic drm tpm snd_hda_intel snd_hda_codec snd_hda_core snd_pcsp snd_hwdep snd_pcm snd_timer parport_pc
 snd parport i2c_piix4 soundcore virtio_net virtio_blk virtio_console virtio_rng crc32c_intel serio_raw virtio_pci virtio_ring virtio ata_generic pata_acpi qemu_fw_cfg
[  257.275238] CPU: 0 PID: 1933 Comm: bash Tainted: G           OE   4.11.9-300.fc26.x86_64 #1
[  257.276360] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1.fc26 04/01/2014
[  257.277783] task: ffff9ced39202580 task.stack: ffffaa02c0634000
[  257.278787] RIP: 0010:crasher_write+0x77/0xb0 [crasher]
[  257.279601] RSP: 0018:ffffaa02c0637e08 EFLAGS: 00010246
[  257.280457] RAX: 0000000000000032 RBX: 0000000000000002 RCX: 0000000000000000
[  257.281647] RDX: 0000000000000001 RSI: 000055fb4a6edda1 RDI: ffffaa02c0637e0c
[  257.282873] RBP: ffffaa02c0637e20 R08: ffffaa02c0638000 R09: ffff9ced38c754e4
[  257.284253] R10: 0000000000000001 R11: ffff9ced39202580 R12: fffffffffffffffb
[  257.285370] R13: ffffaa02c0637f18 R14: 000055fb4a6edda0 R15: ffff9cecf5753200
[  257.286329] FS:  00007eff6cda5b40(0000) GS:ffff9ced3fc00000(0000) knlGS:0000000000000000
[  257.287397] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  257.288163] CR2: 0000000000000001 CR3: 000000007be80000 CR4: 00000000001406f0
[  257.289419] Call Trace:
[  257.289812]  proc_reg_write+0x42/0x70
[  257.290400]  __vfs_write+0x37/0x160
[  257.291121]  ? selinux_file_permission+0xfb/0x120
[  257.292028]  ? security_file_permission+0x3b/0xc0
[  257.292817]  vfs_write+0xb1/0x1a0
[  257.293373]  SyS_write+0x55/0xc0
[  257.293943]  entry_SYSCALL_64_fastpath+0x1a/0xa9
[  257.294822] RIP: 0033:0x7eff6c4871f0
[  257.295511] RSP: 002b:00007ffdfc380208 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  257.296914] RAX: ffffffffffffffda RBX: 000000000000001b RCX: 00007eff6c4871f0
[  257.298474] RDX: 0000000000000002 RSI: 000055fb4a6edda0 RDI: 0000000000000001
[  257.299815] RBP: 000055fb48e68c10 R08: 000000000000000a R09: 00007eff6cda5b40
[  257.301592] R10: 000055fb4a7167c0 R11: 0000000000000246 R12: 0000000000000065
[  257.303198] R13: 000055fb48e68700 R14: 0000000000000024 R15: 0000000000000013
[  257.304313] Code: 48 8d 7d ec e8 db 8c 39 e0 48 8d 7d ec e8 d2 8c 39 e0 48 89 d8 48 8b 4d f0 65 48 33 0c 25 28 00 00 00 75 3a 48 83 c4 10 5b 5d c3 <c6> 04 25 01 00 00 00 41 eb dd 48 c7 c0 f2 ff ff ff eb d7 3c 30 
[  257.307443] RIP: crasher_write+0x77/0xb0 [crasher] RSP: ffffaa02c0637e08
[  257.308717] CR2: 0000000000000001

第一眼看到后确实会头大,不知所措,然后等着系统重启,如果系统Hang住了,就只有冷启动了。不过,让我们尝试着去读懂下这个输出,这样或许在下次遇到这样的问题或许会有解决办法,又或者可以避免这样的事情再次发生。

[  257.264914] BUG: unable to handle kernel NULL pointer dereference at 0000000000000001

表明发生panic的原因是因为空指针操作发生在地址 0000000000000001。

[  257.266396] IP: crasher_write+0x77/0xb0 [crasher]

IP表示指令的指针,表示发生错误的地址。

[  257.267771] Oops: 0002 [#1] SMP

这是个用16进制表示的错误代码,它会有不同的代码来表示不同的错误:

bit 0 == 0 means no page found, 1 means a protection fault
bit 1 == 0 means read, 1 means write
bit 2 == 0 means kernel, 1 means user-mode
[#1] — this value is the number of times the Oops occurred. Multiple Oops can be triggered as a cascading effect of the first one.
[  257.268071] Modules linked in: crasher(OE) binfmt_misc crct10dif_pclmul crc32_pclmul ghash_clmulni_intel tpm_tis joydev tpm_tis_core ppdev virtio_
balloon qxl ttm drm_kms_helper snd_hda_codec_generic drm tpm snd_hda_intel snd_hda_codec snd_hda_core snd_pcsp snd_hwdep snd_pcm snd_timer parport_pc
 snd parport i2c_piix4 soundcore virtio_net virtio_blk virtio_console virtio_rng crc32c_intel serio_raw virtio_pci virtio_ring virtio ata_generic pata_acpi qemu_fw_cfg

系统所加载的模块。

[  257.275238] CPU: 0 PID: 1933 Comm: bash Tainted: G           OE   4.11.9-300.fc26.x86_64 #1
[  257.276360] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1.fc26 04/01/2014

发生panic的CPU,process,kernel version,hardware等信息。在内核文件/kernel/panic.c中有对Bash Tainted的一些描述:

static const struct tnt tnts[] = {
    { TAINT_PROPRIETARY_MODULE, 'P', 'G' },
    { TAINT_FORCED_MODULE,      'F', ' ' },
    { TAINT_UNSAFE_SMP,     'S', ' ' },
    { TAINT_FORCED_RMMOD,       'R', ' ' },
    { TAINT_MACHINE_CHECK,      'M', ' ' },
    { TAINT_BAD_PAGE,       'B', ' ' },
    { TAINT_USER,           'U', ' ' },
    { TAINT_DIE,            'D', ' ' },
    { TAINT_OVERRIDDEN_ACPI_TABLE,  'A', ' ' },
    { TAINT_WARN,           'W', ' ' },
    { TAINT_CRAP,           'C', ' ' },
    { TAINT_FIRMWARE_WORKAROUND,    'I', ' ' },
    { TAINT_OOT_MODULE,     'O', ' ' },
};

详细的信息可以参考这个内核文件,在这里 P,G表示专有模块已经被加载。

[  257.277783] task: ffff9ced39202580 task.stack: ffffaa02c0634000

发生panic时当前进程task的信息。

[  257.278787] RIP: 0010:crasher_write+0x77/0xb0 [crasher]

RIP:被执行的指令(代码),在这里被翻译成了函数名字+偏移值。

[  257.279601] RSP: 0018:ffffaa02c0637e08 EFLAGS: 00010246
[  257.280457] RAX: 0000000000000032 RBX: 0000000000000002 RCX: 0000000000000000
[  257.281647] RDX: 0000000000000001 RSI: 000055fb4a6edda1 RDI: ffffaa02c0637e0c
[  257.282873] RBP: ffffaa02c0637e20 R08: ffffaa02c0638000 R09: ffff9ced38c754e4
[  257.284253] R10: 0000000000000001 R11: ffff9ced39202580 R12: fffffffffffffffb
[  257.285370] R13: ffffaa02c0637f18 R14: 000055fb4a6edda0 R15: ffff9cecf5753200
[  257.286329] FS:  00007eff6cda5b40(0000) GS:ffff9ced3fc00000(0000) knlGS:0000000000000000
[  257.287397] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  257.288163] CR2: 0000000000000001 CR3: 000000007be80000 CR4: 00000000001406f0

转储CPU寄存器的内容,这些寄存器的地址可以作为错误分析时的入口地址。

[  257.289419] Call Trace:
[  257.289812]  proc_reg_write+0x42/0x70
[  257.290400]  __vfs_write+0x37/0x160
[  257.291121]  ? selinux_file_permission+0xfb/0x120
[  257.292028]  ? security_file_permission+0x3b/0xc0
[  257.292817]  vfs_write+0xb1/0x1a0
[  257.293373]  SyS_write+0x55/0xc0
[  257.293943]  entry_SYSCALL_64_fastpath+0x1a/0xa9

Call Trace,系统发生panic之前的函数调用。可以从大致的分析出系统发生错误的原因。“?”表示一个位于堆栈上的指针,但不适合'frame',是一个会消失的指令。

[  257.304313] Code: 48 8d 7d ec e8 db 8c 39 e0 48 8d 7d ec e8 d2 8c 39 e0 48 89 d8 48 8b 4d f0 65 48 33 0c 25 28 00 00 00 75 3a 48 83 c4 10 5b 5d c3 <c6> 04 25 01 00 00 00 41 eb dd 48 c7 c0 f2 ff ff ff eb d7 3c 30 

Code:发生panic时正在运行的机器的代码部分十六进制转储。可以用‘./scripts/decodecode’去反汇编它。

# ./decodecode < code.code 
[ 257.304313] Code: 48 8d 7d ec e8 db 8c 39 e0 48 8d 7d ec e8 d2 8c 39 e0 48 89 d8 48 8b 4d f0 65 48 33 0c 25 28 00 00 00 75 3a 48 83 c4 10 5b 5d c3 <c6> 04 25 01 00 00 00 41 eb dd 48 c7 c0 f2 ff ff ff eb d7 3c 30
All code
========
   0:   48 8d 7d ec             lea    -0x14(%rbp),%rdi
   4:   e8 db 8c 39 e0          callq  0xffffffffe0398ce4
   9:   48 8d 7d ec             lea    -0x14(%rbp),%rdi
   d:   e8 d2 8c 39 e0          callq  0xffffffffe0398ce4
  12:   48 89 d8                mov    %rbx,%rax
  15:   48 8b 4d f0             mov    -0x10(%rbp),%rcx
  19:   65 48 33 0c 25 28 00    xor    %gs:0x28,%rcx
  20:   00 00 
  22:   75 3a                   jne    0x5e
  24:   48 83 c4 10             add    $0x10,%rsp
  28:   5b                      pop    %rbx
  29:   5d                      pop    %rbp
  2a:   c3                      retq   
  2b:*  c6 04 25 01 00 00 00    movb   $0x41,0x1     <-- trapping instruction
  32:   41 
  33:   eb dd                   jmp    0x12
  35:   48 c7 c0 f2 ff ff ff    mov    $0xfffffffffffffff2,%rax
  3c:   eb d7                   jmp    0x15
  3e:   3c 30                   cmp    $0x30,%al

Code starting with the faulting instruction
===========================================
   0:   c6 04 25 01 00 00 00    movb   $0x41,0x1
   7:   41 
   8:   eb dd                   jmp    0xffffffffffffffe7
   a:   48 c7 c0 f2 ff ff ff    mov    $0xfffffffffffffff2,%rax
  11:   eb d7                   jmp    0xffffffffffffffea
  13:   3c 30                   cmp    $0x30,%al
[  257.307443] RIP: crasher_write+0x77/0xb0 [crasher] RSP: ffffaa02c0637e08
[  257.308717] CR2: 0000000000000001

再一次的打印出错误发生的代码。

OK,到此一个简单的Call Trace代码的大概意思就明白了,系统发生panic是由于使用了未知的空指针代码,发生在自注册的模块代码中。

其实,大多时候我们自己的电脑上只能看到黑屏在系统发生了崩溃之后,这样我们要如何去分析错误了。这样就需要用到一个专门的技术"KDUMP",它可以把发生崩溃时系统的内存保存起来,这样就可以在系统重启后使用"Crash"(类似于gdb)这个工具去分析。我们在之后的文章中再做介绍。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 204,293评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,604评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,958评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,729评论 1 277
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,719评论 5 366
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,630评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,000评论 3 397
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,665评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,909评论 1 299
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,646评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,726评论 1 330
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,400评论 4 321
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,986评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,959评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,197评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 44,996评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,481评论 2 342

推荐阅读更多精彩内容