Ubuntu Weekly Recipe

第674回 カーネルのクラッシュ情報を解析する

この記事を読むのに必要な時間:およそ 9.5 分

クラッシュダンプの解析

crashコマンドを使ってクラッシュダンプを解析するには「デバッグ用のカーネル本体」「対象のvmcoreファイル」が必要になります。このうちデバッグパッケージによってインストールされるデバッグ用のカーネル一式は/usr/lib/debug以下にダウンロードされます。そこで,次のようなコマンドでcrashマンドを起動しましょう。

$ crash /usr/lib/debug/boot/vmlinux-5.11.0-22-generic /var/crash/202107040335/dump.202107040335

crash 7.2.9
(中略)
GNU gdb (GDB) 7.6
(中略)

      KERNEL: /usr/lib/debug/boot/vmlinux-5.11.0-22-generic
    DUMPFILE: 202107040335/dump.202107040335  [PARTIAL DUMP]
        CPUS: 4
        DATE: Sun Jul  4 03:34:41 JST 2021
      UPTIME: 00:29:50
LOAD AVERAGE: 0.38, 0.18, 0.09
       TASKS: 475
    NODENAME: ubuntu-ax2
     RELEASE: 5.11.0-22-generic
     VERSION: #23-Ubuntu SMP Thu Jun 17 00:34:23 UTC 2021
     MACHINE: x86_64  (1695 Mhz)
      MEMORY: 3.9 GB
       PANIC: "Kernel panic - not syncing: sysrq triggered crash"
         PID: 111191
     COMMAND: "tee"
        TASK: ffff8b4702b3b080  [THREAD_INFO: ffff8b4702b3b080]
         CPU: 3
       STATE: TASK_RUNNING (PANIC)

crash>

第一引数がvmlinuxファイルで,第二引数がクラッシュダンプイメージです。システムによってはロードに時間がかかるかもしれません。必要なファイルが揃っているなら,上記のように情報が表示されるはずです。上記の内容自体は,dmesgファイルにもある情報ですね。teeコマンドによるタスクがCPU 3で動いているときに,sysrq-triggerによってpanicしたことがわかります。

crashをうまく起動できたら,あとは普通のデバッガとして使うだけです。たとえばバックトレースなら次のように表示できます。

crash> bt
PID: 111191  TASK: ffff8b4702b3b080  CPU: 3   COMMAND: "tee"
 #0 [ffffa2cd898cfc80] machine_kexec at ffffffffa1a77b63
 #1 [ffffa2cd898cfce0] __crash_kexec at ffffffffa1b66a42
 #2 [ffffa2cd898cfdb0] panic at ffffffffa25dd1a3
 #3 [ffffa2cd898cfe30] sysrq_handle_crash at ffffffffa2160bfa
 #4 [ffffa2cd898cfe40] __handle_sysrq.cold at ffffffffa26094b6
 #5 [ffffa2cd898cfe78] write_sysrq_trigger at ffffffffa21615f8
 #6 [ffffa2cd898cfe90] proc_reg_write at ffffffffa1dcc6ca
 #7 [ffffa2cd898cfeb0] vfs_write at ffffffffa1d1eb76
 #8 [ffffa2cd898cfee8] ksys_write at ffffffffa1d21277
 #9 [ffffa2cd898cff28] __x64_sys_write at ffffffffa1d2130a
#10 [ffffa2cd898cff38] do_syscall_64 at ffffffffa2636ab8
#11 [ffffa2cd898cff50] entry_SYSCALL_64_after_hwframe at ffffffffa280008c
    RIP: 00007f3a4110cc27  RSP: 00007ffeb514fbd8  RFLAGS: 00000246
    RAX: ffffffffffffffda  RBX: 0000000000000002  RCX: 00007f3a4110cc27
    RDX: 0000000000000002  RSI: 00007ffeb514fcc0  RDI: 0000000000000003
    RBP: 00007ffeb514fcc0   R8: 0000000000000002   R9: 0000000000000001
    R10: 00000000000001b6  R11: 0000000000000246  R12: 0000000000000002
    R13: 00005622844eb4e0  R14: 0000000000000002  R15: 00007f3a411e68a0
    ORIG_RAX: 0000000000000001  CS: 0033  SS: 002b
crash>

このあたりはdmesgで表示されているものと同じですね。タスクのリストはpsコマンドで確認できます。

crash> ps
   PID    PPID  CPU       TASK        ST  %MEM     VSZ    RSS  COMM
>     0      0   0  ffffffffa361a940  RU   0.0       0      0  [swapper/0]
>     0      0   1  ffff8b4800a81840  RU   0.0       0      0  [swapper/1]
      0      0   2  ffff8b4800a86100  RU   0.0       0      0  [swapper/2]
      0      0   3  ffff8b4800a848c0  RU   0.0       0      0  [swapper/3]
      1      0   1  ffff8b4800276100  IN   0.2  165012  11152  systemd
(中略)
   3755   3746   1  ffff8b4727169840  IN   1.2  496448  57560  dconf worker
   3761   3750   0  ffff8b47029a8000  IN   0.1   19476   3928  tmux: client
>  3797   3191   2  ffff8b4702b2b080  RU   0.1   20136   4244  tmux: server
   3805   3797   3  ffff8b47029ab080  IN   0.1   21328   6076  bash
(中略)
  110886   3191   2  ffff8b4727766100  IN   0.5  372332  23340  pool-tracker-st
  111190   3805   1  ffff8b473b840000  IN   0.1   24104   6004  sudo
> 111191  111190   3  ffff8b4702b3b080  RU   0.0   18008   2048  tee

>が付いているのが実行中のタスクです。上記は2コア4スレッドのCPUなので,4個表示されています。たとえばtmuxサーバーが動いていたPID=3797の情報は次のように表示できます。

crash> bt 3797
PID: 3797   TASK: ffff8b4702b2b080  CPU: 2   COMMAND: "tmux: server"
 #0 [ffffa2cd8127fe88] crash_nmi_callback at ffffffffa1a6a997
 #1 [ffffa2cd8127fe98] nmi_handle at ffffffffa1a38d29
 #2 [ffffa2cd8127fee8] default_do_nmi at ffffffffa2638367
 #3 [ffffa2cd8127ff18] exc_nmi at ffffffffa26385db
 #4 [ffffa2cd8127ff50] asm_exc_nmi at ffffffffa28014c3
    RIP: 00007f989b16aad9  RSP: 00007ffd8ceb0590  RFLAGS: 00000206
    RAX: 0000563e6009d430  RBX: 0000000000000000  RCX: 0000000000000000
    RDX: 0000000000000000  RSI: 0000000000000000  RDI: 0000000000000000
    RBP: 0000563e600f3468   R8: 0000000000000003   R9: 0000000000000001
    R10: 0000000000000003  R11: 0000000000000000  R12: 0000563e600f3468
    R13: 0000000000000000  R14: 0000563e600f3468  R15: 0000563e6009d430
    ORIG_RAX: ffffffffffffffff  CS: 0033  SS: 002b

crash> task 3797
PID: 3797   TASK: ffff8b4702b2b080  CPU: 2   COMMAND: "tmux: server"
struct task_struct {
  thread_info = {
    flags = 0,
    syscall_work = 0,
    status = 0
  },
(後略)

psやtaskのように行数が多い場合はページャー経由での表示になります。もしページャーを無効化したい場合はset scroll offを実行してください。

グローバル変数などはpコマンドで内容を確認できます。またアドレスがわかっていれば,シンボル名指定以外の方法も可能です。

crash> p jiffies
jiffies = $1 = 4296457959
crash> p vermagic
vermagic = $2 = "5.11.0-22-generic SMP mod_unload modversions "

タスクごとのファイルディスクリプター一覧は次のように確認できます。

crash> files 732
PID: 732    TASK: ffff8b480defb080  CPU: 2   COMMAND: "NetworkManager"
ROOT: /    CWD: /
 FD       FILE            DENTRY           INODE       TYPE PATH
  0 ffff8b480d2b7f00 ffff8b4800462240 ffff8b48010cd420 CHR  /dev/null
  1 ffff8b48077a3600 ffff8b4803c15180 ffff8b48085fca40 SOCK UNIX
  2 ffff8b48077a3600 ffff8b4803c15180 ffff8b48085fca40 SOCK UNIX
  3 ffff8b48077ef500 ffff8b4803c689c0 ffff8b4801a98be0 UNKN [eventfd]
  4 ffff8b4807b09b00 ffff8b4803d04480 ffff8b4801a98be0 UNKN [eventfd]
  5 ffff8b4807b09600 ffff8b4803d046c0 ffff8b4803d46e00 SOCK UNIX
  6 ffff8b4807339300 ffff8b4803c47d80 ffff8b4803d44080 SOCK UNIX
  7 ffff8b48023e3300 ffff8b4803d603c0 ffff8b4801a98be0 UNKN [eventfd]
  8 ffff8b480735b800 ffff8b4803ce5b40 ffff8b4803ba84c0 REG  /
  9 ffff8b480735be00 ffff8b4803cfe480 ffff8b4803c1b1e0 REG  /
 10 ffff8b48073aff00 ffff8b4803cfea80 ffff8b4803d26ac0 SOCK NETLINK
 11 ffff8b48073af100 ffff8b4803cfe840 ffff8b4803d25a80 SOCK NETLINK
 12 ffff8b48073af300 ffff8b4803cfeb40 ffff8b4803d26780 SOCK NETLINK
 13 ffff8b480c344700 ffff8b4803d67180 ffff8b4801a98be0 UNKN inotify
 14 ffff8b4809f39900 ffff8b4803d67c00 ffff8b4801a98be0 UNKN inotify
 15 ffff8b480dc0c100 ffff8b473c5ecd80 ffff8b480e2cca40 SOCK NETLINK
 16 ffff8b473c100a00 ffff8b473c5ed000 ffff8b473c64ca40 SOCK NETLINK
 17 ffff8b470289e700 ffff8b4703c57b40 ffff8b4801a98be0 UNKN [eventpoll]
 18 ffff8b4809205500 ffff8b473c7fe180 ffff8b47396048e0 FIFO /run/systemd/inhibit/systemd/inhibit/3.ref
 19 ffff8b4702b61900 ffff8b4714818600 ffff8b4801a98be0 UNKN [eventpoll]
 20 ffff8b4702b61200 ffff8b47148189c0 ffff8b4801a98be0 UNKN [timerfd]
 21 ffff8b4719513700 ffff8b473c749e40 ffff8b47149d2e00 SOCK RAWv6
 22 ffff8b4702b61700 ffff8b4714818f00 ffff8b473c785dc0 SOCK UDPv6
 23 ffff8b4702b61800 ffff8b4714818540 ffff8b473c784a40 SOCK PACKET
 24 ffff8b473c39d700 ffff8b4720aab180 ffff8b473c786440 SOCK UDP
 25 ffff8b471ce4da00 ffff8b4714baaa80 ffff8b4801a98be0 UNKN [timerfd]

crashでは他にもさまざまなコマンドで,情報を確認できます。詳細はhelpコマンドやhelpページを参照してください。

著者プロフィール

柴田充也(しばたみつや)

Ubuntu Japanese Team Member株式会社 創夢所属。数年前にLaunchpad上でStellariumの翻訳をしたことがきっかけで,Ubuntuの翻訳にも関わるようになりました。