このブログもそうだが、Linuxの上で動いている。
クラウド上でポチポチと設定するだけで使える時代なので、OSについて特に気にしないユーザも多いだろう。ありがたいことに安定稼働しているので、トラブルに遭遇することがほとんどない。
しかし、システムはクラッシュすることがまれにある。
クラッシュしたときに、クラッシュダンプファイルがあると、原因の特定に役立つことがある。
交通事故でたとえるならば、事故発生時の写真のようなものだ。
もちろん証拠写真だけで解決できないこともある。
途中経過までたどる場合には別途ログを調べる必要があるが、今回はcrashコマンドのみにフォーカスしてみよう。
crashコマンドとは
カーネルがクラッシュした時に、メモリの状態をファイルに書き出すことで、システムをリブートしたときにユーザがクラッシュ時の状態を把握できるようにしている。
そのファイルは、vmcoreと呼ばれcrashコマンドを使って中身を確認することができる。
ちなみに、今回使用する環境は、以下のとおりだ。よって、バージョンがことなると結果がことなる可能性がある。
# cat /etc/redhat-release
Red Hat Enterprise Linux release 8.2 (Ootpa)
# uname -r
4.18.0-193.1.2.el8_2.x86_64crashコマンドのインストール
では早速crashパッケージをインストールしてみよう。ついでに、カーネルのデバッグに必要なファイルもインストールしておこう。
RHEL8のkernel-debuginfoパッケージは、500MBぐらいの大きさだ。
# dnf install crash
# crash --version
crash 7.2.7-3.el8
# debuginfo-install kernelcrashコマンドが使えるか確認してみよう。
# crash
...
KERNEL: /usr/lib/debug/lib/modules/4.18.0-193.1.2.el8_2.x86_64/vmlinux
DUMPFILE: /proc/kcore
CPUS: 2
DATE: Tue May 26 18:10:03 2020
UPTIME: 00:06:27
LOAD AVERAGE: 0.31, 0.40, 0.26
TASKS: 486
NODENAME: localhost.localdomain
RELEASE: 4.18.0-193.1.2.el8_2.x86_64
VERSION: #1 SMP Thu May 7 16:37:54 UTC 2020
MACHINE: x86_64 (3591 Mhz)
MEMORY: 4 GB
PID: 2921
COMMAND: "crash"
TASK: ffff99825d0b2f80 [THREAD_INFO: ffff99825d0b2f80]
CPU: 1
STATE: TASK_RUNNING (ACTIVE)Kdumpの設定
Kdump HelperというWebのアプリがあるので、条件を選択してポチポチと設定するだけで設定スクリプトが作成される。
そして、ファイルをダウンロードして、次のように実行するだけだ。
# chmod +x kdumpconfig.sh
# ./kdumpconfig.sh
...
-Restarting the kdump service...
kexec: unloaded kdump kernel
Stopping kdump: [OK]
Detected change(s) in the following file(s):
/etc/kdump.conf
Rebuilding /boot/initramfs-4.18.0-193.1.2.el8_2.x86_64kdump.img
kexec: loaded kdump kernel
Starting kdump: [OK]
-Starting to Configure extra diagnostic options...
-Backed up /etc/sysctl.conf to /etc/sysctl.conf.kdumphelper.20-05-26-16:55:55.
kernel.sysrq=1 set in /etc/sysctl.conf
kernel.unknown_nmi_panic=1 set in /etc/sysctl.conf
kernel.softlockup_panic=1 set in /etc/sysctl.conf
vm.panic_on_oom=1 set in /etc/sysctl.conf
# rebootクラッシュさせる
いつクラッシュするかわからないので、ここでは無理矢理クラッシュさせよう。
もちろん、本番環境ではなく、開発環境やテスト環境で実行してほしい。
すると、次のようなファイルが作成されるので再起動後に確認してほしい。
# pwd
/var/crash/127.0.0.1-2020-05-26-18:19:15
# ls -lh
total 1.2G
-rw-------. 1 root root 1.2G May 26 18:20 vmcore
-rw-r--r--. 1 root root 50K May 26 18:19 vmcore-dmesg.txtvmcoreの読み込み
先程作成したvmcoreを解析してみよう。「crash vmlinux vmcore」を実行して、crash を起動する。
vmlinuxはカーネルの非圧縮イメージだ。kernel-debuginfoパッケージをインストールすると一緒にインストールされる。
# crash /usr/lib/debug/lib/modules/4.18.0-193.1.2.el8_2.x86_64/vmlinux vmcore
...
GNU gdb (GDB) 7.6
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-linux-gnu"...
WARNING: kernel relocated [22MB]: patching 94976 gdb minimal_symbol values
KERNEL: /usr/lib/debug/lib/modules/4.18.0-193.1.2.el8_2.x86_64/vmlinux
DUMPFILE: vmcore [PARTIAL DUMP]
CPUS: 2
DATE: Tue May 26 18:19:09 2020
UPTIME: 00:15:34
LOAD AVERAGE: 0.00, 0.08, 0.15
TASKS: 487
NODENAME: localhost.localdomain
RELEASE: 4.18.0-193.1.2.el8_2.x86_64
VERSION: #1 SMP Thu May 7 16:37:54 UTC 2020
MACHINE: x86_64 (3591 Mhz)
MEMORY: 4 GB
PANIC: "sysrq: SysRq : Trigger a crash"
PID: 2525
COMMAND: "bash"
TASK: ffff99825d0b4740 [THREAD_INFO: ffff99825d0b4740]
CPU: 0
STATE: TASK_RUNNING (SYSRQ)
crash>helpコマンド
helpと入力すると、利用できるコマンドの一覧が表示される。そして、help + コマンドと入力すると各コマンドの使い方が表示される。
crash> help
* extend log rd task
alias files mach repeat timer
ascii foreach mod runq tree
bpf fuser mount search union
bt gdb net set vm
btop help p sig vtop
dev ipcs ps struct waitq
dis irq pte swap whatis
eval kmem ptob sym wr
exit list ptov sys q
crash version: 7.2.7-3.el8 gdb version: 7.6
For help on any command above, enter "help <command>".
For help on input options, enter "help input".
For help on output options, enter "help output".
crash> help ps
NAME
ps - display process status information
SYNOPSIS
ps [-k|-u|-G|-y policy] [-s] [-p|-c|-t|-[l|m][-C cpu]|-a|-g|-r|-S|-A]
[pid | task | command] ...
DESCRIPTION
This command displays process status for selected, or all, processes
in the system. If no arguments are entered, the process data is
is displayed for all processes. Specific processes may be selected
by using the following identifier formats:
...sysコマンド
sysと入力すると、システムの情報が表示される。時間やCPUのロードアベレージ、カーネルパニックの原因などが表示される。これは、crashを起動して最初に表示される情報と同じだ。
crash> sys
KERNEL: /usr/lib/debug/lib/modules/4.18.0-193.1.2.el8_2.x86_64/vmlinux
DUMPFILE: vmcore [PARTIAL DUMP]
CPUS: 2
DATE: Tue May 26 18:19:09 2020
UPTIME: 00:15:34
LOAD AVERAGE: 0.00, 0.08, 0.15
TASKS: 487
NODENAME: localhost.localdomain
RELEASE: 4.18.0-193.1.2.el8_2.x86_64
VERSION: #1 SMP Thu May 7 16:37:54 UTC 2020
MACHINE: x86_64 (3591 Mhz)
MEMORY: 4 GB
PANIC: "sysrq: SysRq : Trigger a crash"
Desktop Management Interface（DMI）情報を表示させることもできる。
crash> sys -i
DMI_BIOS_VENDOR: SeaBIOS
DMI_BIOS_VERSION: 1.13.0-2.fc32
DMI_BIOS_DATE: 04/01/2014
DMI_SYS_VENDOR: QEMU
DMI_PRODUCT_NAME: Standard PC (Q35 + ICH9, 2009)
DMI_PRODUCT_VERSION: pc-q35-4.2
...
crash> sys -i
DMI_BIOS_VENDOR: LENOVO
DMI_BIOS_VERSION: G4ET37WW (1.12 )
DMI_BIOS_DATE: 05/29/2012
DMI_SYS_VENDOR: LENOVO
DMI_PRODUCT_NAME: 2429BQ1
DMI_PRODUCT_VERSION: ThinkPad T530
システムコールのテーブルを表示させることもできる。
crash> sys -c
NUM SYSTEM CALL FILE AND LINE NUMBER
0 __x64_sys_read ../fs/read_write.c: 586
1 __x64_sys_write ../fs/read_write.c: 607
2 __x64_sys_open ../fs/open.c: 1082
3 __x64_sys_close ../fs/open.c: 1163
4 __x64_sys_newstat ../fs/stat.c: 333
5 __x64_sys_newfstat ../fs/stat.c: 371
6 __x64_sys_newlstat ../fs/stat.c: 344
7 __x64_sys_poll ../fs/select.c: 990
8 __x64_sys_lseek ../fs/read_write.c: 322
...-tオプションは汚染されているか表示する。0ならば、汚染されていない。Pならば、プロプライエタリ(Proprietary)ライセンスを持つモジュールが使われている。
crash> sys -t
TAINTED_MASK: 0
crash> sys -t
TAINTED_MASK: 1 P
crash> mod -t
NAME TAINTS
hpvsa P(U)
snapapi26 P(U) < Uは、Unsigned。
...hexコマンド
hexと入力すると、表示を16進数に変更できる。そして、evalを使うと16進数と10進数の両方が表示できる。
crash> hex
output radix: 16 (hex)
crash> eval 24
hexadecimal: 18
decimal: 24
octal: 30
binary: 0000000000000000000000000000000000000000000000000000000000011000btコマンド
btと入力すると、プロセスのバックトレースが表示される。全プロセスを表示させるには、foreachと組み合わせる。
-tオプションはスタックにテキストシンボルがある場合はすべて表示する。
-fオプションはフレーム内のスタックデータをすべて表示する。関数への引数を確認するときに便利だ。
crash>foreach bt -tf
PID: 0 TASK: ffffffff83812780 CPU: 0 COMMAND: "swapper/0"
START: __schedule at ffffffff82e8f8ff
[ffffffff83803e48] __schedule at ffffffff82e8f8ff
[ffffffff83803e50] irqtime_account_process_tick at ffffffff826e57a9
[ffffffff83803ea8] schedule_idle at ffffffff82e8ffee
...
PID: 1 TASK: ffff99830778df00 CPU: 1 COMMAND: "systemd"
START: __schedule at ffffffff82e8f8ff
[ffffb6eec0633d38] __schedule at ffffffff82e8f8ff
[ffffb6eec0633d50] ep_item_poll at ffffffff82913550
[ffffb6eec0633d98] schedule at ffffffff82e8fd2f
...-lオプションはファイル名と行数を表示する。
crash> bt -l 1
PID: 1 TASK: ffff99830778df00 CPU: 1 COMMAND: "systemd"
#0 [ffffb6eec0633d00] __schedule at ffffffff82e8f8ff
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/kernel/sched/core.c: 2822
#1 [ffffb6eec0633d98] schedule at ffffffff82e8fd2f
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/./arch/x86/include/asm/current.h: 15
#2 [ffffb6eec0633da8] schedule_hrtimeout_range_clock at ffffffff82e93e7d
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/kernel/time/hrtimer.c: 1937
#3 [ffffb6eec0633e40] ep_poll at ffffffff82915448
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/fs/eventpoll.c: 1811
...-aオプションはカレントプロセスのみ表示する。これは、ライブシステムでは利用できない。
crash> bt -a
PID: 2525 TASK: ffff99825d0b4740 CPU: 0 COMMAND: "bash"
#0 [ffffb6eec11fbbe0] machine_kexec at ffffffff8265982e
#1 [ffffb6eec11fbc38] __crash_kexec at ffffffff827591bd
#2 [ffffb6eec11fbd00] crash_kexec at ffffffff8275a09d
#3 [ffffb6eec11fbd18] oops_end at ffffffff82621edd
#4 [ffffb6eec11fbd38] no_context at ffffffff8266872e
#5 [ffffb6eec11fbd90] do_page_fault at ffffffff82669262
#6 [ffffb6eec11fbdc0] async_page_fault at ffffffff8300123e
[exception RIP: sysrq_handle_crash+18]
...
PID: 0 TASK: ffff9983077d5f00 CPU: 1 COMMAND: "swapper/1"
#0 [fffffe0000032e50] crash_nmi_callback at ffffffff8264ce93
#1 [fffffe0000032e58] nmi_handle at ffffffff82622893
#2 [fffffe0000032eb0] default_do_nmi at ffffffff82622d4e
#3 [fffffe0000032ed0] do_nmi at ffffffff82622f28
#4 [fffffe0000032ef0] end_repeat_nmi at ffffffff830016b4
[exception RIP: native_safe_halt+14]
RIP: ffffffff82e947be RSP: ffffb6eec0693ea8 RFLAGS: 00000246
RAX: ffffffff82e94410 RBX: 0000000000000001 RCX: 7fffff267326013f
RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff99837bb1d5c0
RBP: 0000000000000001 R8: 0000018970364f46 R9: 0000000000000001
R10: 00000000fa83b2da R11: 00000000000000e4 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
--- <NMI exception stack> ---
#5 [ffffb6eec0693ea8] native_safe_halt at ffffffff82e947be
#6 [ffffb6eec0693ea8] default_idle at ffffffff82e9442c
#7 [ffffb6eec0693ed0] do_idle at ffffffff826e67d1
#8 [ffffb6eec0693f10] cpu_startup_entry at ffffffff826e6a3f
#9 [ffffb6eec0693f30] start_secondary at ffffffff8264ea17
#10 [ffffb6eec0693f50] secondary_startup_64 at ffffffff826000e7
disコマンド
disと入力すると、逆アセンブルをする。
crash> bt -l
...
#7 [ffffb6eec11fbe78] __handle_sysrq.cold.9 at ffffffff82b25308
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 587
#8 [ffffb6eec11fbea8] write_sysrq_trigger at ffffffff82b251cb
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 1114
...
crash> dis -l write_sysrq_trigger
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 1105
0xffffffff82b251a0 <write_sysrq_trigger>: nopl 0x0(%rax,%rax,1) [FTRACE NOP]
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 1106
0xffffffff82b251a5 <write_sysrq_trigger+0x5>: push %rbx
0xffffffff82b251a6 <write_sysrq_trigger+0x6>: mov %rdx,%rbx
0xffffffff82b251a9 <write_sysrq_trigger+0x9>: test %rdx,%rdx
0xffffffff82b251ac <write_sysrq_trigger+0xc>: je 0xffffffff82b251cb <write_sysrq_trigger+0x2b>
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 1109
0xffffffff82b251ae <write_sysrq_trigger+0xe>: mov %rsi,%rax
0xffffffff82b251b1 <write_sysrq_trigger+0x11>: callq 0xffffffff82e82010 <__get_user_1>
0xffffffff82b251b6 <write_sysrq_trigger+0x16>: mov %eax,%esi
0xffffffff82b251b8 <write_sysrq_trigger+0x18>: mov $0xfffffffffffffff2,%rax
0xffffffff82b251bf <write_sysrq_trigger+0x1f>: test %esi,%esi
0xffffffff82b251c1 <write_sysrq_trigger+0x21>: jne 0xffffffff82b251ce <write_sysrq_trigger+0x2e>
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 1111
0xffffffff82b251c3 <write_sysrq_trigger+0x23>: movsbl %dl,%edi
0xffffffff82b251c6 <write_sysrq_trigger+0x26>: callq 0xffffffff82b24d40 <__handle_sysrq>
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/drivers/tty/sysrq.c: 1114
0xffffffff82b251cb <write_sysrq_trigger+0x2b>: mov %rbx,%rax
0xffffffff82b251ce <write_sysrq_trigger+0x2e>: pop %rbx
0xffffffff82b251cf <write_sysrq_trigger+0x2f>: retq
crash> dis -s write_sysrq_trigger
FILE: drivers/tty/sysrq.c
LINE: 1105
1100 /*
1101 * writing 'C' to /proc/sysrq-trigger is like sysrq-C
1102 */
1103 static ssize_t write_sysrq_trigger(struct file *file, const char __user *buf,
1104 size_t count, loff_t *ppos)
* 1105 {
1106 if (count) {
1107 char c;
1108
1109 if (get_user(c, buf))
1110 return -EFAULT;
1111 __handle_sysrq(c, false);
1112 }
1113
1114 return count;
1115 }
crash>
または、-sオプション＋アドレスでソースコードの場所を特定することもできる。
crash> dis -s ffffffff82b251cb
FILE: drivers/tty/sysrq.c
LINE: 1114
1109 if (get_user(c, buf))
1110 return -EFAULT;
1111 __handle_sysrq(c, false);
1112 }
1113
* 1114 return count;
1115 }
よくある命令（例）:
mov 0x160(%rbx),%rbx
これは、RBXレジスタで表されるアドレスからオフセット0x160バイトの位置にある内容をRBXレジスタに格納する命令だ。
setコマンド
setと入力すると、カレントコンテクストを任意のプロセスに切り替えることができる。例えば、PID1511の”rsyslogd”がオープンしているファイルは、このように表示する。
crash> set 1511
PID: 1511
COMMAND: "rsyslogd"
TASK: ffff99835ee617c0 [THREAD_INFO: ffff99835ee617c0]
CPU: 1
STATE: TASK_INTERRUPTIBLE
crash> files
PID: 1511 TASK: ffff99835ee617c0 CPU: 1 COMMAND: "rsyslogd"
ROOT: / CWD: /
FD FILE DENTRY INODE TYPE PATH
0 ffff998376bc9400 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
1 ffff998376bc9b00 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
2 ffff998376bc9b00 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
3 ffff99835b445100 ffff99837b6b7b40 ffff998347c21b20 CHR /dev/urandom
4 ffff99835b4f3000 ffff99837564a840 ffff99830783a6b0 SOCK UNIX
5 ffff99835b53bd00 ffff998375e92b40 ffff998375ea2bc0 REG /var/log/messages
6 ffff99835b53b500 ffff998375e92e40 ffff998375ea1680 REG /var/log/cron
7 ffff99835b53b900 ffff998375e926c0 ffff998375ea3000 REG /var/log/secure
8 ffff99835b4d9200 ffff99837564a3c0 ffff99837b6cbc30 UNKN inotify
10 ffff99835b4d9900 ffff99837aab8540 ffff9983467b4950 REG /run/log/journal/e6a1f2e21c8a4df5b8f758dcc5c02d26/system.journal
modコマンド
modと入力すると、現在インストールされたモジュール情報を表示する。
-sオプションをつけると、指定したモジュールをロードすることができる。
crash> mod|grep nfs
ffffffffc0953140 nfsv3 49152 (not loaded) [CONFIG_KALLSYMS]
ffffffffc0ae2000 nfs_acl 16384 (not loaded) [CONFIG_KALLSYMS]
ffffffffc0bbb280 nfs 327680 (not loaded) [CONFIG_KALLSYMS]
crash> mod -s nfsv3
MODULE NAME SIZE OBJECT FILE
ffffffffc0953140 nfsv3 49152 /usr/lib/debug/usr/lib/modules/4.18.0-193.1.2.el8_2.x86_64/kernel/fs/nfs/nfsv3.ko.debugsourceコマンド
source + FILEと入力すると、ファイルからコマンドを読み込むことができる。例えば、/root/macros/nfs-pointersにつぎのような設定をすることができる。
crash> cat /root/macros/nfs-pointers
define superblk-to-nfs-pointers
set $sb = (struct super_block *)$arg0
set $nfs_server = (struct nfs_server *)($sb->s_fs_info)
set $nfs_client = $nfs_server->nfs_client
print $sb
print $nfs_server
print $nfs_client
endそのファイルを読み込むことで、使い回しができるようになる。例えば、SUPERBLKのアドレスを渡すだけで、nfs_serverやnfs_clientのアドレスを取得できる。
crash> mount
MOUNT SUPERBLK TYPE DEVNAME DIRNAME
ffff940b07776300 ffff940b07c12000 rootfs rootfs /
ffff940b07777680 ffff940b74d9a000 sysfs sysfs /sys
...
ffff940b38726000 ffff940b5c778000 nfs 192.168.1.103:/c/backup /mnt
crash> mod -s nfs
MODULE NAME SIZE OBJECT FILE
ffffffffc0bbb280 nfs 327680 /usr/lib/debug/usr/lib/modules/4.18.0-193.1.2.el8_2.x86_64/kernel/fs/nfs/nfs.ko.debug
crash> source /root/macros/nfs-pointers
crash> superblk-to-nfs-pointers 0xffff940b5c778000
$1 = (struct super_block *) 0xffff940b5c778000
$2 = (struct nfs_server *) 0xffff940b7540d800
$3 = (struct nfs_client *) 0xffff940b3f620c00
structコマンド
structコマンドは構造体の定義や実際のアドレスから指定した構造体にマッチしたデータを表示する。
-oオプションでオフセット情報も表示できる。
crash> struct -o nfs_client
struct nfs_client {
[0x0] refcount_t cl_count;
[0x4] atomic_t cl_mds_count;
[0x8] int cl_cons_state;
[0x10] unsigned long cl_res_state;
....
crash> struct nfs_client 0xffff940b3f620c00
struct nfs_client {
cl_count = {
refs = {
counter = 0x1
}
},
...
cl_addrlen = 0x10,
cl_hostname = 0xffff940b1313edd0 "192.168.1.103",
cl_acceptor = 0x0,
...
cl_rpcclient = 0xffff940b39a53600,
...
crash> struct rpc_clnt 0xffff940b39a53600
struct rpc_clnt {
...
cl_xprt = 0xffff940b75409000,
cl_procinfo = 0xffffffffc094f5c0,
...
crash> struct rpc_xprt 0xffff940b75409000
struct rpc_xprt {
kref = {
refcount = {
refs = {
counter = 0x4
}
}
},
ops = 0xffffffffc085a900,
...
crash> struct rpc_xprt 0xffff940b75409000|grep state
state = 0x12,
crash> eval -b 0x12
hexadecimal: 12
decimal: 18
octal: 22
binary: 0000000000000000000000000000000000000000000000000000000000010010
bits set: 4 1
stateのビットを確認すると接続されているかもチェックできる。
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/include/linux/sunrpc/xprt.h
/*
* Reserved bit positions in xprt->state
*/
#define XPRT_LOCKED (0)
#define XPRT_CONNECTED (1)
#define XPRT_CONNECTING (2)
#define XPRT_CLOSE_WAIT (3)
#define XPRT_BOUND (4)
#define XPRT_BINDING (5)
#define XPRT_CLOSING (6)
ビット1がセットされているから、接続されていることが確認できる。
rdコマンド
rdコマンドはメモリを直接読むコマンドだ。
# cat /proc/sys/fs/mqueue/queues_max
256この情報をcrashのrdコマンドで読み取ってみる。
crash> sym sysctl_table_root
ffffffffaf50d4a0 (d) sysctl_table_root
crash> whatis sysctl_table_root
struct ctl_table_root sysctl_table_root;
crash> struct ctl_table_root ffffffff8390d4a0
...
ctl_table = 0xffffffff8390d520,
このctl_tableを使って、階層をたどってみよう。はじめに、/proc/sys/fsをチェックしてみる。その後、その下のmqueueのctl_tableアドレスをチェックする。
crash> struct ctl_table 0xffffffff8390d520 1000|grep procname|grep fs
struct: invalid kernel virtual address: fffffffffeffffff type: "gdb_readmem_callback"
struct: invalid kernel virtual address: fffffffffeffffff type: "gdb_readmem_callback"
procname = 0xffffffff836e41c6 "sysfs",
procname = 0xffffffff836771af "ramfs",
procname = 0xffffffff836a2cc5 "tracefs",
procname = 0xffffffff836b8918 "fs",
procname = 0xffffffff836bfc3b "securityfs",
struct: seek error: kernel virtual address: ffffffffffffffff type: "gdb_readmem_callback"
struct: seek error: kernel virtual address: ffffffffffffffff type: "gdb_readmem_callback"
crash> struct ctl_table 0xffffffff8390d520 1000|grep -s -e 'procname = 0xffffffff836b8918 \"fs\"' -A 5
struct: invalid kernel virtual address: fffffffffeffffff type: "gdb_readmem_callback"
struct: invalid kernel virtual address: fffffffffeffffff type: "gdb_readmem_callback"
procname = 0xffffffff836b8918 "fs",
data = 0x0,
maxlen = 0,
mode = 365,
child = 0xffffffff83910be0,
proc_handler = 0x0,
crash> struct ctl_table 0xffffffff83910be0
struct ctl_table {
procname = 0xffffffff836bebe0 "mqueue",
data = 0x0,
maxlen = 0,
mode = 365,
child = 0xffffffff83910c60,
proc_handler = 0x0,
poll = 0x0,
extra1 = 0x0,
extra2 = 0x0
}0xffffffff836bebe0を使って、ctl_tableの値をチェックし、procname=”queues_max”の情報を確認できる。
crash> struct ctl_table 0xffffffff83910c60
struct ctl_table {
procname = 0xffffffff836beeee "queues_max",
data = 0xffffffff8390e724,
maxlen = 4,
mode = 420,
child = 0x0,
proc_handler = 0xffffffff82977570 <x86_64_start_kernel+88>,
poll = 0x0,
extra1 = 0x0,
extra2 = 0x0
}このdataはアドレスを表示してるので、サイズをチェックして10進数の値に変換しよう。
/usr/src/debug/kernel-4.18.0-193.1.2.el8_2/linux-4.18.0-193.1.2.el8_2.x86_64/ipc/mq_sysctl.c
tatic struct ctl_table mq_sysctls[] = {
{
.procname = "queues_max",
.data = &init_ipc_ns.mq_queues_max,
.maxlen = sizeof(int),
つまり、int型のサイズは、4バイト(=32ビット)だ。
crash> rd -32 0xffffffff8390e724
ffffffff8390e724: 00000100 ....
crash> p/d 0x00000100
$1 = 256filesコマンド
filesと入力すると、プロセスがオープンしているファイルを表示する。
crash> files
PID: 1052 TASK: ffff9983782897c0 CPU: 0 COMMAND: "sshd"
ROOT: / CWD: /
FD FILE DENTRY INODE TYPE PATH
0 ffff99837a06c700 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
1 ffff99837a06c000 ffff9983756ff480 ffff99837ab6d630 SOCK UNIX
2 ffff99837a06c000 ffff9983756ff480 ffff99837ab6d630 SOCK UNIX
3 ffff9983782a8a00 ffff998375510d80 ffff9983767e7cc0 REG /var/lib/sss/mc/passwd
4 ffff9983782a8b00 ffff99837570a6c0 ffff99837576eef0 SOCK UNIX
5 ffff9983768f4500 ffff99837570a480 ffff99837576de70 SOCK TCP
...
/var/log/配下のファイルだけ表示するには、次のように実行する。
crash> foreach files -R /var/log
PID: 853 TASK: ffff9983733d2f80 CPU: 1 COMMAND: "auditd"
ROOT: / CWD: /
FD FILE DENTRY INODE TYPE PATH
6 ffff99837a1ae000 ffff99837b113540 ffff99837b250e00 REG /var/log/audit/audit.log
...
PID: 1511 TASK: ffff99835ee617c0 CPU: 1 COMMAND: "rsyslogd"
ROOT: / CWD: /
FD FILE DENTRY INODE TYPE PATH
5 ffff99835b53bd00 ffff998375e92b40 ffff998375ea2bc0 REG /var/log/messages
6 ffff99835b53b500 ffff998375e92e40 ffff998375ea1680 REG /var/log/cron
7 ffff99835b53b900 ffff998375e926c0 ffff998375ea3000 REG /var/log/secure
crash> files
PID: 1511 TASK: ffff99835ee617c0 CPU: 1 COMMAND: "rsyslogd"
ROOT: / CWD: /
FD FILE DENTRY INODE TYPE PATH
0 ffff998376bc9400 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
1 ffff998376bc9b00 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
2 ffff998376bc9b00 ffff99837b6b7180 ffff998347c22fe8 CHR /dev/null
3 ffff99835b445100 ffff99837b6b7b40 ffff998347c21b20 CHR /dev/urandom
4 ffff99835b4f3000 ffff99837564a840 ffff99830783a6b0 SOCK UNIX
5 ffff99835b53bd00 ffff998375e92b40 ffff998375ea2bc0 REG /var/log/messages
6 ffff99835b53b500 ffff998375e92e40 ffff998375ea1680 REG /var/log/cron
7 ffff99835b53b900 ffff998375e926c0 ffff998375ea3000 REG /var/log/secure
8 ffff99835b4d9200 ffff99837564a3c0 ffff99837b6cbc30 UNKN inotify
10 ffff99835b4d9900 ffff99837aab8540 ffff9983467b4950 REG /run/log/journal/e6a1f2e21c8a4df5b8f758dcc5c02d26/system.journal
crash> jiffies
jiffies = $1 = 0x10009ae04
crash> struct inode ffff998375ea3000|grep when
dirtied_when = 0xfffc2333,
dirtied_time_when = 0x0,
crash> pd (0x10009ae04 - 0xfffc2333)/1000/60
$12 = 14/var/log/secureは、約15分(14分47秒)前に更新があった。
kmemコマンド
kmemコマンドはカーネルのメモリに関する情報を表示する。
-sオプションでスラブキャッシュの情報を表示する。/proc/slabinfoと同じ情報だ。
crash> kmem -s
CACHE OBJSIZE ALLOCATED TOTAL SLABS SSIZE NAME
ffff9983409fbe00 1056 119 120 8 16k xfs_inode(2111:systemd-tmpfiles-clean.service)
ffff9983533c9600 192 120 126 6 4k dentry(2111:systemd-tmpfiles-clean.service)
ffff99833d262c00 576 206 224 16 8k radix_tree_node(2087:dnf-makecache.service)
...-iオプションでメモリの情報を表示する。
crash> kmem -i
PAGES TOTAL PERCENTAGE
TOTAL MEM 967220 3.7 GB ----
FREE 166272 649.5 MB 17% of TOTAL MEM
USED 800948 3.1 GB 82% of TOTAL MEM
SHARED 115695 451.9 MB 11% of TOTAL MEM
BUFFERS 530 2.1 MB 0% of TOTAL MEM
CACHED 330964 1.3 GB 34% of TOTAL MEM
SLAB 37855 147.9 MB 3% of TOTAL MEM
TOTAL HUGE 0 0 ----
HUGE FREE 0 0 0% of TOTAL HUGE
TOTAL SWAP 524287 2 GB ----
SWAP USED 0 0 0% of TOTAL SWAP
SWAP FREE 524287 2 GB 100% of TOTAL SWAP
COMMIT LIMIT 1007897 3.8 GB ----
COMMITTED 1249934 4.8 GB 124% of TOTAL LIMIT
アドレスを指定することもできる。[]で囲まれているとまだ解放されていない。
// /var/log/secure の inode から
crash> struct inode ffff998375ea3000|grep mapping
i_mapping = 0xffff998375ea3178,
crash> struct address_space.host 0xffff998375ea3178
host = 0xffff998375ea3000
crash> kmem 0xffff998375ea3000
CACHE OBJSIZE ALLOCATED TOTAL SLABS SSIZE NAME
ffff99835ef6ea00 1056 17 45 3 16k xfs_inode(1615:rsyslog.service)
SLAB MEMORY NODE TOTAL ALLOCATED FREE
ffffe739c5d7a800 ffff998375ea0000 0 15 4 11
FREE / [ALLOCATED]
[ffff998375ea2ec0]
PAGE PHYSICAL MAPPING INDEX CNT FLAGS
ffffe739c5d7a8c0 175ea3000 dead000000000400 0 0 17ffffc0000000listコマンド
listコマンドはlist_head構造体をたどって順にアドレスを表示する。
モジュールのリストを順にたどるには、次のように実行する。
crash> whatis modules
struct list_head modules;
crash> list modules
ffffffff838adc30
ffffffffc0c9e088
ffffffffc0c28108
ffffffffc0c23148
...グローバル変数のfile_systemsのnextによって現在登録されているファイルシステムのタイプを表示するには、次のように実行する。
crash> p file_systems
file_systems = $2 = (struct file_system_type *) 0xffffffff8390d760
crash> list file_system_type.next -s file_system_type.name 0xffffffff8390d760
ffffffff8390d760
name = 0xffffffff836e41c6 "sysfs"
ffffffff83812700
name = 0xffffffff836b7509 "rootfs"
ffffffff8390de60
name = 0xffffffff836771af "ramfs"
ffffffff838fa240
name = 0xffffffff836b7bbd "bdev"
ffffffff8390d3c0
name = 0xffffffff836a4b06 "proc"
ffffffff838b4de0
name = 0xffffffff836afb9f "cpuset"
...
crash> file_system_type ffffffff8390d3c0
struct file_system_type {
name = 0xffffffff836a4b06 "proc",
fs_flags = 8,
mount = 0xffffffff82942bc0,
kill_sb = 0xffffffff82942b80,
owner = 0x0,
next = 0xffffffff838b4de0,
fs_supers = {
first = 0xffff998307c158e0
},
...netコマンド
netと入力すると、ネットワークデバイスのリストを表示する。
crash> net
NET_DEVICE NAME IP ADDRESS(ES)
ffff99837bbd7000 lo 127.0.0.1
ffff998373f27000 enp1s0 192.168.122.45
ffff998355a20000 virbr0 192.168.124.1
ffff998355a9c000 virbr0-nic MACアドレスとIPアドレスの関連付け情報を保存したARP(Address Resolution Protocol)キャッシュを表示するには、次のように入力する。
crash> net -a
NEIGHBOUR IP ADDRESS HW TYPE HW ADDRESS DEVICE STATE
ffff998359eca600 224.0.0.22 ETHER 01:00:5e:00:00:16 virbr0 NOARP
ffff998359f34400 224.0.0.251 ETHER 01:00:5e:00:00:fb virbr0 NOARP
ffff99835ec6dc00 224.0.0.22 ETHER 01:00:5e:00:00:16 enp1s0 NOARP
ffff99835b69d400 224.0.0.251 ETHER 01:00:5e:00:00:fb enp1s0 NOARP
ffff998360301e00 0.0.0.0 UNKNOWN 00 00 00 00 00 00 lo NOARP
ffff99835ec6cc00 192.168.122.1 ETHER 52:54:00:4a:1e:7f enp1s0 REACHABLEpsコマンド
psコマンドはプロセス情報を表示する。
割り込み不可(uninterruptible)プロセスを表示するには、タスクステートがUNを検索する。また、そのプロセスが何分ぐらいそのような状態なのかチェックするには、次のようにする。
crash> ps |grep oracle|grep UN
8193 1 4 ffff81012263e100 UN 0.1 6544360 17704 oracle
8223 1 7 ffff8101d1dfa100 UN 0.3 6557744 47308 oracle
crash> set 8193
PID: 8193
COMMAND: "oracle"
TASK: ffff8104109bf7a0 [THREAD_INFO: ffff8103b9780000]
CPU: 5
STATE: TASK_UNINTERRUPTIBLE
crash> px per_cpu__runqueues | grep "\[5\]"
[5]: ffff810237072120
crash> px ((struct rq *) 0xffff810237072120)->timestamp_last_tick
$5 = 0x6d70f2e3d90b
crash> px ((struct task_struct *) 0xffff8104109bf7a0)->last_ran
$6 = 0x6c0bdeddcf88
crash> pd (0x6d70f2e3d90b-0x6c0bdeddcf88)/1000000000
$7 = 1533 <- ~25 min
// 追記: timestamp_last_tick は、RHEL8では定義されていないので、-mオプションを利用する。
crash> ps -m |grep UN
-aオプションを追加するとコマンドライン引数と環境変数を表示する。
crash> ps -a rsyslogd
PID: 1511 TASK: ffff99835ee617c0 CPU: 1 COMMAND: "rsyslogd"
ARG: /usr/sbin/rsyslogd -n
ENV: LANG=en_US.UTF-8
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin
NOTIFY_SOCKET=/run/systemd/notify
INVOCATION_ID=cc20aba676a343fe93d6c4094497734f
SYSLOGD_OPTIONS=-tオプションを追加するとプロセスの動作時間、開始時間、ユーザ空間(UTIME)、カーネル空間(STIME)での実行時間を表示する。
utimeは、USER TIMEになり、単位はミリ秒だ。つまり、50000ならば50秒だ。
crash> ps -t
PID: 0 TASK: ffffffff83812780 CPU: 0 COMMAND: "swapper/0"
RUN TIME: 00:15:34
START TIME: 0
UTIME: 0
STIME: 0
PID: 1 TASK: ffff99830778df00 CPU: 1 COMMAND: "systemd"
RUN TIME: 00:15:34
START TIME: 4000000
UTIME: 249462850
STIME: 1390583301
PID: 0 TASK: ffff9983077d5f00 CPU: 1 COMMAND: "swapper/1"
RUN TIME: 00:15:34
START TIME: 5000000
UTIME: 0
STIME: 0-Aオプションを追加するとアクティブなプロセスだけ表示できる。
crash> ps -A
PID PPID CPU TASK ST %MEM VSZ RSS COMM
> 0 0 1 ffff9983077d5f00 RU 0.0 0 0 [swapper/1]
> 2525 2522 0 ffff99825d0b4740 RU 0.3 38308 17104 bash
これと同じ。
crash> ps|grep '>'
> 0 0 1 ffff9983077d5f00 RU 0.0 0 0 [swapper/1]
> 2525 2522 0 ffff99825d0b4740 RU 0.3 38308 17104 bashrunqコマンド
runqと入力すると、スケジューラのランキューを表示する。
crash> runq
CPU 0 RUNQUEUE: ffff99837ba29c40
CURRENT: PID: 2525 TASK: ffff99825d0b4740 COMMAND: "bash"
RT PRIO_ARRAY: ffff99837ba29e80
[no tasks queued]
CFS RB_ROOT: ffff99837ba29cf0
[120] PID: 501 TASK: ffff998372cc8000 COMMAND: "kworker/u4:4"
CPU 1 RUNQUEUE: ffff99837bb29c40
CURRENT: PID: 0 TASK: ffff9983077d5f00 COMMAND: "swapper/1"
RT PRIO_ARRAY: ffff99837bb29e80
[no tasks queued]
CFS RB_ROOT: ffff99837bb29cf0
[no tasks queued]taskコマンド
taskと入力すると、task_struct構造体を表示する。
crash> task
PID: 2525 TASK: ffff99825d0b4740 CPU: 0 COMMAND: "bash"
struct task_struct {
thread_info = {
flags = 2147483776,
status = 0
},
state = 0,
stack = 0xffffb6eec11f8000,
usage = {
counter = 2
},
flags = 4194304,
...whatisコマンド
シンボルなどの構造体の定義を表示する。
crash> whatis jiffies
volatile unsigned long jiffies;
crash> whatis modules
struct list_head modules;
crash> whatis task_struct
struct task_struct {
struct thread_info thread_info;
volatile long state;
void *stack;
atomic_t usage;
unsigned int flags;
...fuserコマンド
ファイルのパスやinodeを指定すると、そのファイルを使用しているタスクを表示できる。
crash> fuser /var/log/messages
PID TASK COMM USAGE
1511 ffff99835ee617c0 "rsyslogd" fd
1529 ffff99835b4fdf00 "in:imjournal" fd
1530 ffff99835b50af80 "rs:main Q:Reg" fd searchコマンド
メモリを検索するには、searchを利用します。
例えば、次の文字列を含むカーネルメモリを検索するには、以下のように実行します。
crash> search -k -c "can't allocate memory" "Failure to"
ffff8800013ddec1: can't allocate memory for key lists..<3>%s %s: error con
ffff8801258be748: Failure to install fence: %d..<3>[drm:%s] *ERROR* Failed
ffff880125f07ec9: can't allocate memory..<3>ACPI: Invalid data..Too many d
ffffffff813ddec1: can't allocate memory for key lists..<3>%s %s: error con補足：Python extension
こちらのサイトのダウンロードをクリックすると、現時点ではmpykdump-3.1.0-x86_64.tar.gzがダウンロードされる。
Python/CRASH API / Wiki / Home
sourceforge.net
ファイルを展開してmpykdump64.soをcrashコマンドからロードしよう。
はじめは、オプションなしでcrashinfoと入力すると、次のような結果が表示される。
crash> extend /root/mpykdump64.so
Setting scroll off while initializing PyKdump
/root/mpykdump64.so: shared object loaded
crash> crashinfo
+==========================+
| * Crashinfo v1.3.4 * |
+==========================+
KERNEL: /usr/lib/debug/lib/modules/4.18.0-193.1.2.el8_2.x86_64/vmlinux
DUMPFILE: vmcore [PARTIAL DUMP]
CPUS: 2
DATE: Tue May 26 18:19:09 2020
UPTIME: 00:15:34
LOAD AVERAGE: 0.00, 0.08, 0.15
TASKS: 487
NODENAME: localhost.localdomain
RELEASE: 4.18.0-193.1.2.el8_2.x86_64
VERSION: #1 SMP Thu May 7 16:37:54 UTC 2020
MACHINE: x86_64 (3591 Mhz)
MEMORY: 4 GB
PANIC: "sysrq: SysRq : Trigger a crash"
+--------------------------+
>------------------------| Per-cpu Stacks ('bt -a') |------------------------<
+--------------------------+
-- CPU#0 --
PID=2525 CPU=0 CMD=bash
#0 machine_kexec+0x1be
#1 __crash_kexec+0x6d
#2 crash_kexec+0x3d
#3 oops_end+0xbd
#4 no_context+0x1be
#5 do_page_fault+0x32
#6 async_page_fault+0x1e
#-1 sysrq_handle_crash+0x12, 477 bytes of data
#7 __handle_sysrq.cold.9+0x48
#8 write_sysrq_trigger+0x2b
#9 proc_reg_write+0x3c
#10 vfs_write+0xa5
#11 ksys_write+0x4f
#12 do_syscall_64+0x5b
#13 entry_SYSCALL_64_after_hwframe+0x65, 477 bytes of data
-- CPU#1 --
PID=0 CPU=1 CMD=swapper/1
#0 crash_nmi_callback+0x33
#1 nmi_handle+0x63
#2 default_do_nmi+0x4e
#3 do_nmi+0x128
#4 end_repeat_nmi+0x16
#-1 native_safe_halt+0xe, 507 bytes of data
#5 native_safe_halt+0xe
#6 default_idle+0x1c
#7 do_idle+0x1f1
#8 cpu_startup_entry+0x6f
#9 start_secondary+0x1a7
#10 secondary_startup_64+0xb7
+--------------------------------+
>---------------------| How This Dump Has Been Created |---------------------<
+--------------------------------+
Dump has been initiated: with sysrq
- programmatically (via sysrq-trigger)
- using unknown dump method
+---------------+
>------------------------------| Tasks Summary |------------------------------<
+---------------+
Number of Threads That Ran Recently
--------------------
last second 40
last 5s 89
last 60s 174
----- Total Numbers of Threads per State ------
TASK_INTERRUPTIBLE 426
TASK_RUNNING 3
TASK_UNINTERRUPTIBLE 57
+++WARNING+++ There are 13 threads running in their own namespaces
Use 'taskinfo --ns' to get more details
+-----------------------+
>--------------------------| 5 Most Recent Threads |--------------------------<
+-----------------------+
PID CMD Age ARGS
----- -------------- ------ ----------------------------
2525 bash 0 ms -bash
501 kworker/u4:4 0 ms (no user stack)
2522 sshd 1 ms sshd: root@pts/0
616 xfsaild/dm-0 27 ms (no user stack)
2468 python3 32 ms python3 /usr/bin/awx-manage run_callback_receiver
+------------------------+
>-------------------------| Memory Usage (kmem -i) |-------------------------<
+------------------------+
PAGES TOTAL PERCENTAGE
TOTAL MEM 967220 3.7 GB ----
FREE 166272 649.5 MB 17% of TOTAL MEM
USED 800948 3.1 GB 82% of TOTAL MEM
SHARED 115695 451.9 MB 11% of TOTAL MEM
BUFFERS 530 2.1 MB 0% of TOTAL MEM
CACHED 330964 1.3 GB 34% of TOTAL MEM
SLAB 37855 147.9 MB 3% of TOTAL MEM
TOTAL HUGE 0 0 ----
HUGE FREE 0 0 0% of TOTAL HUGE
TOTAL SWAP 524287 2 GB ----
SWAP USED 0 0 0% of TOTAL SWAP
SWAP FREE 524287 2 GB 100% of TOTAL SWAP
COMMIT LIMIT 1007897 3.8 GB ----
COMMITTED 1249934 4.8 GB 124% of TOTAL LIMIT
Traceback (most recent call last):
File "/root/mpykdump64.so/progs/crashinfo.py", line 1620, in <module>
File "/root/mpykdump64.so/progs/crashinfo.py", line 1066, in print_blkreq
File "/home/alexs/tools/pykdump/LinuxDump/Dev.py", line 905, in print_request_queues
File "/home/alexs/tools/pykdump/LinuxDump/Dev.py", line 892, in get_blkreq_info
File "/home/alexs/tools/pykdump/LinuxDump/Dev.py", line 686, in check_request_queue
File "/home/alexs/tools/pykdump/pykdump/wrapcrash.py", line 565, in getattr
KeyError: '<struct request_queue> does not have a field <in_flight>'
******************************************************************************
********************** A Summary Of Problems Found ***********************
******************************************************************************
-------------------- A list of all +++WARNING+++ messages --------------------
There are 13 threads running in their own namespaces
Use 'taskinfo --ns' to get more details
--------------------
** Execution took 5.29s (real) 3.51s (CPU), Child processes: 1.54s
crash>
–findオプションでキーワードを含むスタック情報を表示できる。
crash> crashinfo --find crash
PID=0 CPU=1 CMD=swapper/1
#0 crash_nmi_callback+0x33
#1 nmi_handle+0x63
#2 default_do_nmi+0x4e
#3 do_nmi+0x128
#4 end_repeat_nmi+0x16
#-1 native_safe_halt+0xe, 507 bytes of data
#5 native_safe_halt+0xe
#6 default_idle+0x1c
#7 do_idle+0x1f1
#8 cpu_startup_entry+0x6f
#9 start_secondary+0x1a7
#10 secondary_startup_64+0xb7
PID=2525 CPU=0 CMD=bash
#0 machine_kexec+0x1be
#1 __crash_kexec+0x6d
#2 crash_kexec+0x3d
#3 oops_end+0xbd
#4 no_context+0x1be
#5 do_page_fault+0x32
#6 async_page_fault+0x1e
#-1 sysrq_handle_crash+0x12, 477 bytes of data
#7 __handle_sysrq.cold.9+0x48
#8 write_sysrq_trigger+0x2b
#9 proc_reg_write+0x3c
#10 vfs_write+0xa5
#11 ksys_write+0x4f
#12 do_syscall_64+0x5b
#13 entry_SYSCALL_64_after_hwframe+0x65, 477 bytes of data
–sysctlオプションでsysctlの設定を表示できる。
crash> crashinfo --sysctl
abi.vsyscall32 1
crypto.fips_enabled 0
debug.exception-trace 1
debug.kprobes-optimization 0
dev.cdrom.autoclose 1
dev.cdrom.autoeject 0
dev.cdrom.check_media 0
dev.cdrom.debug 0
dev.cdrom.info
dev.cdrom.lock 1
dev.hpet.max-user-freq 64
dev.mac_hid.mouse_button2_keycode 97
dev.mac_hid.mouse_button3_keycode 100
...–helpオプションで利用可能なオプションを表示できる。
crash> crashinfo --help
Usage: crashinfo [options]
Options:
-h, --help show this help message and exit
-v verbose output
-q quiet mode - print warnings only
--fast Fast mode - do not run potentially slow tests
--sysctl Print sysctl info.
--ext3 Print EXT3 info.
--blkreq Print Block I/O requests
--blkdevs Print Block Devices Info
--filelock Print filelock info.
--stacksummary Print stacks (bt) categorized summary.
--findstacks=FINDSTACKS
Print stacks (bt) containing functions that match the provided pattern
--checkstacks Check stacks of all threads for corruption
--decodesyscalls=DECODESYSCALLS
Decode Syscalls on the Stack
--keventd_wq Decode keventd_wq
--kblockd_wq Decode kblockd_workqueue
--lws Print Locks Waitqueues and Semaphores
--devmapper Print DeviceMapper Tables
--runq Print Runqueus
--semaphore=SEMA Print 'struct semaphore' info
--rwsemaphore=RWSEMA Print 'struct rw_semaphore' info
--mutex=MUTEX Print Mutex info
--umem Print User-space Memory Usage
--ls=LS Emulate 'ls'. You can specify either dentry address or full pathname
--workqueues Print Workqueues - just for some kernels
--radix_tree_element=root offset
Find and print a radix tree element
--pci Print PCI Info
--version Print program version and exit
** Execution took 0.01s (real) 0.01s (CPU)
crash> また、xportshowコマンドで、ネットワーク関連情報も表示できる。
詳細は、-hで確認してみよう。
crash> xportshow -h
usage: xportshow [-h] [-a] [-v] [-r] [--program PROGRAM] [--pid [PID]] [--netfilter] [--softnet]
[--summary] [-s] [-i] [--interface IF1] [--decode DECODE [DECODE ...]]
[--port PORT] [-l] [-t] [--tcpstate TCPSTATE] [-u] [-w] [-x] [--sysctl]
[--devpack] [--arp] [--rtcache] [--skbuffhead SKBUFFHEAD] [--netns NETNS]
[--version] [--everything]
optional arguments:
-h, --help show this help message and exit
-a print all sockets
-v verbose output
-r Print routing table. Adding -v prints all routing tables and policies
--program PROGRAM print sockets for cmdname
--pid [PID] print sockets for PID
--netfilter Print Netfilter Hooks
--softnet Print Softnet Queues
--summary Print A Summary
-s, --statistics Print Statistics
-i Print Interface Info
--interface IF1 Limit output to the specified interface only
--decode DECODE [DECODE ...]
Decode iph/th/uh
--port PORT Limit output to the specified port (src or dst)
-l, --listening Print LISTEN sockets only
-t Print TCP Info
--tcpstate TCPSTATE Limit display for this state only, e.g. SYN_SENT
-u, --udp Print UDP Info
-w, --raw Print RAW Info
-x, --unix Print UNIX Info
--sysctl Print sysctl info for net.
--devpack Print dev_pack info
--arp Print ARP & Neighbouring info
--rtcache Print the routing cache
--skbuffhead SKBUFFHEAD
Print sk_buff_head
--netns NETNS Set net ns address
--version Print program version and exit
--everything Run all functions available for regression testing
** Execution took 0.01s (real) 0.01s (CPU)
crash> TCPの情報を表示するには、-tオプションをつける。
crash> xportshow -t
tcp 127.0.0.1:39736 127.0.0.1:5432 TIME_WAIT
tcp 127.0.0.1:4369 127.0.0.1:55741 ESTABLISHED
tcp6 ::ffff:127.0.0.1:5672 ::ffff:127.0.0.1:42182 ESTABLISHED
tcp 127.0.0.1:5432 127.0.0.1:39254 ESTABLISHED
tcp 127.0.0.1:39744 127.0.0.1:5432 TIME_WAIT
tcp 127.0.0.1:39724 127.0.0.1:5432 TIME_WAIT
tcp 127.0.0.1:39772 127.0.0.1:5432 ESTABLISHED
tcp 127.0.0.1:39740 127.0.0.1:5432 TIME_WAIT
...-lオプションでLISTENソケットのみを表示できる。
crash> xportshow -l
tcp6 :::443 :::* LISTEN
tcp 0.0.0.0:443 0.0.0.0:* LISTEN
tcp6 :::5672 :::* LISTEN
tcp 0.0.0.0:25672 0.0.0.0:* LISTEN
tcp6 :::111 :::* LISTEN
tcp 0.0.0.0:111 0.0.0.0:* LISTEN
tcp6 :::80 :::* LISTEN
tcp 0.0.0.0:80 0.0.0.0:* LISTEN
tcp6 :::4369 :::* LISTEN
tcp 0.0.0.0:4369 0.0.0.0:* LISTEN
tcp 192.168.124.1:53 0.0.0.0:* LISTEN
tcp6 :::22 :::* LISTEN
tcp 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0.0.0.0:15672 0.0.0.0:* LISTEN
...予備知識 (oops)
[ 934.371472] sysrq: SysRq : Trigger a crash
[ 934.371519] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[ 934.371522] PGD 0 P4D 0
[ 934.371527] Oops: 0002 [#1] SMP PTIこのようなメッセージを見たことがあるひともいるだろう。
では、Oopsの数字の意味は何か？
実はこの数字には、次のパターンしかない。
| Bit | 0 | 1 |
| 0 | No page found | Invalid access or Protection fault |
| 1 | Read or Execute | Write |
| 2 | Kernel mode | User mode |
| 3 | No instruction fetch | Instruction fetch |
0002(decimal)は、0010(binary)だ。
右から左に順に確認しよう。ビット1は、ゼロ。ビット2は、1。ビット3と4は、ゼロ。
そして、ゼロスタートでカウントしている。
0002を英語で表現するとこうなる。
“we have a page not found during a write operation in Kernel mode; the fault was not an Instruction Fetch.“
予備知識 (%rdi, %rsi, %rdx)
x86_64では、関数呼出し時の引数の格納先として、rdiを1番目として次の順に利用する。
- %rdi
- %rsi
- %rdx
- %rcx
- %r8
- %r9
Intel CPUアーキテクチャについて簡単に触れてみよう。汎用レジスタについてこちらを見てほしい。
| 32-bit | 64-bit | 用途 |
| EAX | RAX | オペランドの演算、結果 |
| EBX | RBX | DSセグメントのデータへのポインタ |
| ECX | RCX | 文字列やループのカウンタ |
| EDX | RDX | I/Oポインタ |
| ESI | RSI | DSレジスタによって示されるセグメントにあるデータへのポインタ。あるいは、文字列操作のソースポインタ。 |
| EDI | RDI | ESレジスタによって示されるセグメントにあるデータへのポインタ。あるいは、文字列操作のデスティネーションポインタ。 |
| ESP | RSP | スタックポインタ |
| EBP | RBP | スタック上のデータへのポインタ |
よくあるパターン
- カーネルパニック(NULLポインタ参照)
- NULLポインタアクセスによってOopsする。
BUG: unable to handle kernel NULL pointer dereference at xyz...- カーネルパニック(リスト破壊)
- カーネルで実装されている双方向リストlist_headなどで破壊されたリストや解放済みのリストを参照することによって発生する。
例1：
[3893008.345544] WARNING: at lib/list_debug.c:53 __list_del_entry+0x63/0xd0()
[3893008.345547] list_del corruption, ffff881fe5c31e10->next is LIST_POISON1 (dead000000100100)
例2：
[34745.679014] WARNING: CPU: 0 PID: 1113 at lib/list_debug.c:62 __list_del_entry+0x82/0xd0
[34745.679020] list_del corruption. next->prev should be fffff5bc43a025a0, but was fffff5bc6ec540a0- カーネルパニック(レースコンディション 競合)
- 複数のプロセスが共有メモリにアクセスして競合するとパニックが発生する。たまにしか発生しないタイプのバグ。
- ソースコードを確認して競合の仕組みを理解する必要がある。
- カーネルのストール(無限ループ)
- 応答しなくなる状態。ハングやフリーズともいう。
- ウォッチドッグを使いカーネルクラッシュダンプを採取する。
- vmcoreから各スレッドが何をしているか確認する。
- カーネルのストール(スピンロックによるデッドロック)
- スピンロックとはスレッドがロックを獲得するまでループ（スピン）して定期的んロックをチェックしながら待つこと。その結果、2つ以上のスレッドが互いの処理終了を待ち、結果としてどの処理も先に進めなくなることをデッドロックという。
- スピンロックはビジーウェイトなので、バックトレースをチェックしよう。
NMI Watchdog detected LOCKUP on CPU 0
CPU 0
...
RIP: 0010:[<ffffffff80064bcb>] [<ffffffff80064bcb>] .text.lock.spinlock+0x11/0x30
RSP: 0018:ffff8111a007f670 EFLAGS: 00000086x86_64アーキテクチャでは、EFLAGS00000086を観るとIFフラグ（割り込みフラグ）がクリアされている。つまり、割り込み禁止状態だ。もしこれが、00000286ならばIFフラグがセットされているので割り込み許可状態だとわかる。
- カーネルのストール(セマフォ)
- セマフォは、排他制御の仕組みで、同時に使える資源があと何個使えるかを示す数字だ。
- psコマンドでプロセスがUN(=UNITERRUPTABLE)かどうかチェックしよう。
- そのプロセスをbtでバックトレース情報をだして、セマフォ関連処理がないかチェックしよう。例：down_read、 up_read、 down_write、 up_write。
- セマフォ待ちとわかったら、何のセマフォ操作をしているかチェックしよう。
絞り込み
CPUの使用率とプロセスの状態から、ざっくりと切り分けてみよう。もちろん、ケースバイケースなので、あくまで目安としてとらえてほしい。
| ケース | CPU使用率 | プロセスの状態 |
| 1 | 高い(100%に近い) | R |
| 2 | いろいろ | R または S |
| 3 | 低い (0%に近い) | S または D |
| 4 | 低い (0%に近い) | S または D |
| 5 | 0% | T |
| 状態 | 意味 |
| D | 割り込み不可能なスリープ状態 (通常 IO 中) |
| R | 実行中または実行可能状態 (実行キューにある) |
| S | 割り込み可能なスリープ状態 (イベントの完了を待っている) |
| T | ジョブ制御シグナルまたはトレースされているために停止中の状態 |
| W | ページング状態 (2.6.xx カーネルからは無効) |
| X | 死んだ状態 (見えるべきではない) |
| Z | 終了したが、親プロセスによって回収されなかった、 消滅した (ゾンビ) プロセス |
| ケース | 状態 |
| 1 | どこかで無限ループ |
| 2 | 何かエラーが発生し、リトライ中 |
| 3 | プロセスが何かイベント待ち（シグナル待ち、スリープ中） |
| 4 | デッドロック |
| 5 | SIGSTOPなどでプロセス停止 |
コメント