panic
panic
どうした事か、FreeBSDを使っていたらpanicで落る事が３回あった。４度目の正直にならないように防止策を検討しないとな。
３度目の時、コンソール画面に目をこらしていたら(正確にはpanicした後の再起動時)、/var/crashの中を覗いてみろってご神託に気が付いた。
[sakae@fb ~]$ ls -ltr /var/crash/ total 733464 -rw-r--r-- 1 root wheel 5 Apr 9 2021 minfree -rw------- 1 root wheel 401 Sep 11 15:06 info.0 -rw------- 1 root wheel 311848960 Sep 11 15:06 vmcore.0 -rw-r--r-- 1 root wheel 128501 Sep 11 15:06 core.txt.0 -rw------- 1 root wheel 362 Sep 11 16:48 info.1 -rw------- 1 root wheel 252727296 Sep 11 16:48 vmcore.1 -rw-r--r-- 1 root wheel 129010 Sep 11 16:48 core.txt.1 -rw-r--r-- 1 root wheel 2 Sep 15 07:38 bounds -rw------- 1 root wheel 401 Sep 15 07:38 info.2 -rw------- 1 root wheel 253448192 Sep 15 07:38 vmcore.2 lrwxr-xr-x 1 root wheel 6 Sep 15 07:38 info.last@ -> info.2 lrwxr-xr-x 1 root wheel 8 Sep 15 07:38 vmcore.last@ -> vmcore.2 -rw-r--r-- 1 root wheel 134464 Sep 15 07:38 core.txt.2
infoを見ればいいんだな。
root@fb:/var/crash # cat info.2 Dump header from device: /dev/ada0p3 Architecture: i386 Architecture Version: 2 Dump Length: 253448192 Blocksize: 512 Compression: none Dumptime: 2022-09-15 06:14:50 +0900 Hostname: fb Magic: FreeBSD Kernel Dump Version String: FreeBSD 13.1-RELEASE-p2 GENERIC Panic String: vm_page_free_prep: page 0x3253f94 has references Dump Parity: 1363963683 Bounds: 2 Dump Status: good
これだけじゃ、餓鬼の使い、もとえM＄並みの全く役にたたないメッセージだ。他にテキストなやつって事で、開いてみる。
root@fb:/var/crash # lv core.txt.2
fb dumped core - see /var/crash/vmcore.2
:
panic: vm_page_free_prep: page 0x3253f94 has references
GNU gdb (GDB) 12.1 [GDB v12.1 for FreeBSD]
:
Unread portion of the kernel message buffer:
WARNING !drm_modeset_is_locked(&crtc->mutex) failed at /wrkdirs/usr/ports/graphi
cs/drm-fbsd13-kmod/work/drm-kmod-drm_v5.4.191_1/drivers/gpu/drm/drm_atomic_helpe
r.c:621
#0 0x2679f329 at linux_dump_stack+0x19
#1 0x26e36eb2 at drm_atomic_helper_check_modeset+0x92
:
ps -axlww
UID PID PPID C PRI NI VSZ RSS MWCHAN STAT TT TIME COMMAND
0 0 0 0 -16 0 0 0 swapin DLs - 0:00.02 [kernel]
:
------------------------------------------------------------------------
vmstat -s
673894 cpu context switches
322699 device interrupts
:
------------------------------------------------------------------------
pstat -T
164/124987 files
0M/0M swap space
------------------------------------------------------------------------
netstat -s
tcp:
2765 packets sent
:
------------------------------------------------------------------------
fstat
USER CMD PID FD MOUNT INUM MODE SZ|DV R/W
sakae vi 1259 root / 2 drwxr-xr-x 1024 r
:
------------------------------------------------------------------------
dmesg
:
drmn0: <drmn> on vgapci0
vgapci0: child drmn0 requested pci_enable_io
vgapci0: child drmn0 requested pci_enable_io
[drm] Unable to create a private tmpfs mount, hugepage support will be disabled(-19).
:
------------------------------------------------------------------------
kernel config
options CONFIG_AUTOGENERATED
ident GENERIC
:
3000行近い、その時の状況レポートだった。cscope経由でviを使っていたよ。それから、drmなんて語句も出てる。
思い起すと、Xがvesaしか使っていなかったんで、インテル入ってるってドライバーを追加したんだった。ハードの対応に嬉しくなってLinux由来のDRMサポートが動き出したんだな。そいつが、不安定なものだから、カーネルを巻き込んで落ちたって推測出来る。
ならば、インテル・ドライバーを外して様子をみよう。
where panic
所で、panicってどうなってるの？ panic(9)なんてのがあるけど、余り役に立たないぞ。 こういう場合な、ソースに当るのが正解。
C symbol: panic
File Function Line
0 fuse_vfsops.c fuse_vfsop_unmount 485 panic("no private
data for mount
point?");
1 fuse_vnops.c fuse_vnop_reclaim 1976 panic("FUSE: no vnode
data during
recycling");
2 msdosfs_denode.c deextend 515 panic("deextend: file
too large");
3 msdosfs_fat.c extendfile 1090 panic("extendfile:
pcbmap");
4 msdosfs_vfsops.c msdosfs_sync 1011 panic("msdosfs_sync:
rofs mod");
5 msdosfs_vnops.c msdosfs_create 166 panic("msdosfs_create
: no name");
* Lines 1044-1050 of 2643, 1594 more - press the space bar to display more *
シンボル検索したら、2643ヶも語句が見付かった。それだけ厳しく監視してますって事だな。 Teoさんが言ってた、カーネルは気難しい愛人って感想が実感できますよ。
Global definition: panic
File Line
0 zfssubr.c 39 #define panic(...) do { \
1 zfs_context.h 158 extern void panic(const char *, ...) __NORETURN;
2 kernel.c 624 panic(const char *fmt, ...)
3 lstate.h 143 lua_CFunction panic;
4 bxe.h 1758 int panic;
5 kern_shutdown.c 839 panic(const char *fmt, ...)
6 subr_stats.c 196 #define panic(fmt, ...) do { \
7 aeabi_unwind.c 37 #define panic(x) (void )0
8 radix.c 52 #define panic(x) fprintf(stderr, "PANIC: %s", x), exit(1)
9 key_debug.c 83 #define panic(fmt, ...) { printf(fmt, ## __VA_ARGS__);
exit(-1); }
a dn_heap.c 56 #define panic(x...) fprintf(stderr, ## x), exit(1)
b test_dn_heap.c 44 #define panic(x...) fprintf(stderr, ## x), exit(1)
c kassert.h 75 void panic(const char *, ...) __dead2 __printflike(1, 2);
で、定義場所を探すと、あちこちに出て来る。No.5が本物で、後はエイリアスっぽいな。
/*
* Panic is called on unresolvable fatal errors. It prints "panic: mesg",
* and then reboots. If we are called twice, then we avoid trying to sync
* the disks as this often leads to recursive panics.
*/
void
panic(const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
vpanic(fmt, ap);
}
本当の処理は、vpanicの中で行われている。SMPなシステムなら、余分なCPUを停止して、変な事がおきないように処置。それからスケジューラーを停止、それから、 kern_reboot を呼び出すとな。
この kern_reboot を見ていくと、doadump(TRUE)なんてのも行われている。ソースを眺めるのもいいけど、 kern_reboot(9) も折角用意したんだから見てね、なんてソースに書いてあった。
1. If this is the first invocation of kern_reboot() and the
RB_NOSYNC flag is not set in howto, syncs and unmounts the
system disks by calling vfs_unmountall(9).
2. Disables interrupts.
3. If rebooting after a crash (i.e., if RB_DUMP is set in howto,
but RB_HALT is not), saves a system crash dump.
4. Runs any shutdown hooks previously registered.
5. Prints a message indicating that the system is about to be
halted or rebooted.
6. If RB_HALT is set in howto, halts the system. Otherwise,
reboots the system.
要になるカーネルの関数は、マニュアルにも記述してあるのね。
dumpの本体は、 kern_dump.c に用意されてる。
crashinfo
上で、色々なpanic時の状況を報告するやつ、解析スクリプトになってた。勿論シェルスクリプトだ。perlとかpythonとかじゃないよ。
libexec/rc/rc.d/savecore から、呼ばれているっぽい。
NAME
crashinfo – analyze a core dump of the operating system
DESCRIPTION
The crashinfo utility analyzes a core dump saved by savecore(8). It
generates a text file containing the analysis in the same directory as
the core dump. For a given core dump file named vmcore.XX the generated
text file will be named core.txt.XX.
どんな事をやってるか気楽に眺めてみる。/usr/src/usr.sbin/crashinfo/
file=`mktemp /tmp/crashinfo.XXXXXX`
if [ $? -eq 0 ]; then
echo "bt" >> $file
echo "quit" >> $file
${GDB%gdb}kgdb $KERNEL $VMCORE < $file
rm -f $file
echo
fi
こんな風にgdbを操作して捜査を走査するんだねぇ。同音異義が並んだ。
echo "------------------------------------------------------------------------" echo "vmstat -s" echo vmstat -M $VMCORE -N $KERNEL -s
その他、これはと思われる状況を調べてる。ps,netstat,iostat …
いずれのコマンドも共通で、-M, -N をサポートしてる。何者かは想像付くけど、一応当っておく。
-M Extract values associated with the name list from the specified
core.
-N If -M is also specified, extract the name list from the specified
system instead of the default, which is the kernel image the
system has booted from.
coreした中から、特定の変数なりテーブルを取出したい。例えばプロセステーブル。これが参照出来れば、その時に動いていたプロセス即ちアプリが判明する。
その為には、カーネルエリアの何処にそのエリアがあるかの情報が必要。それを正常なカーネルから貰ってくるって事だ。gdbでcoreを調べる時も、同じ事をやるね。
-M, -N
iostatの例を調べてみる。
case 'M':
memf = optarg;
break;
case 'N':
nlistf = optarg;
break;
if (memf != NULL) {
kd = kvm_openfiles(nlistf, memf, NULL, O_RDONLY, buf);
if ((ret = kvm_nlist(kd, nl)) != 0) {
kvm_openfiles は、Kernel Data Access Libraryを使う時のお決まり。 kvm_nlist は、下記のように欲しいテーブルをnlに入れて呼ぶ。これで、構造にアクセス出来る。
DESCRIPTION
The kvm_nlist() function retrieves the symbol table entries indicated by
the name list argument nl. This argument points to an array of nlist
structures, terminated by an entry whose n_name field is NULL (see
実際に使う時は下記のようにもう一段下のアクセスが必要
if (kvm_read(kd, nl[NL_TTY_LIST].n_value, &tl, sizeof tl) != sizeof tl)
errx(1, "kvm_read(): %s", kvm_geterr(kd));
tp = TAILQ_FIRST(&tl);
while (tp != NULL) {
if (kvm_read(kd, (u_long)tp, &tty, sizeof tty) != sizeof tty)
errx(1, "kvm_read(): %s", kvm_geterr(kd));
[sakae@fb ~]$ pstat -t
LINE INQ CAN LIN LOW OUTQ USE LOW COL SESS PGID STATE
sysmouse 0 0 0 0 0 0 0 0 0 0 -
ttyv0 1920 0 0 192 2016 0 202 21 1126 1127 Oi
ttyv1 1920 0 0 192 2016 0 202 7 988 988 Oil
:
pts/0 7680 0 0 768 7812 0 782 99999 1115 1116 Oil
pts/1 1920 0 0 192 2016 0 202 179 1119 16267 Oi
pts/2 1920 0 0 192 2016 73 202 0 1121 16342 Oi
pstatのSEE ALSOには、 K. Thompson, UNIX Implementation.が名を連ねているなあ。
config
crashinfoで使われていた、カーネルのconfig状況確認プログラムで後追い。DEBUGオプションがついていたんですねぇ。で、これを眺めると、ムラムラと自分KERNELを作りたくなるんだけど、それをやっちゃうと後々面倒な事がおきるので自粛。
[sakae@fb /usr/src]$ config -x /boot/kernel/kernel options CONFIG_AUTOGENERATED ident GENERIC machine i386 cpu I686_CPU cpu I586_CPU cpu I486_CPU makeoptions WITH_CTF=1 makeoptions DEBUG=-g options IICHID_SAMPLING options VESA device sc device vt device vt_vga device vt_vbefb device agp :
by hand
crashinfoで使ってるgdbを手動操作してみたい。肝はそれぞれをフルパスで指定する事(特にkernelのpath)。手抜きをすると、そんなファイル正式じゃ無いと意地悪される。プチ、セキュリティーに配慮した対策になってる。なんたって、coreファイルには大事なデータが格納されてますからねぇ。取扱注意品ですよ。
root@fb:/tmp # /usr/local/bin/kgdb /boot/kernel/kernel /var/crash/vmcore.2
GNU gdb (GDB) 12.1 [GDB v12.1 for FreeBSD]
:
Reading symbols from /boot/kernel/kernel...
Reading symbols from /usr/lib/debug//boot/kernel/kernel.debug...
Unread portion of the kernel message buffer:
WARNING !drm_modeset_is_locked(&crtc->mutex) failed at /wrkdirs/usr/ports/graphi
cs/drm-fbsd13-kmod/work/drm-kmod-drm_v5.4.191_1/drivers/gpu/drm/drm_atomic_helpe
r.c:621
#0 0x2679f329 at linux_dump_stack+0x19
:
<4>WARN_ON(!mutex_is_locked(&dev->struct_mutex))
<4>WARN_ON(!mutex_is_locked(&fbc->lock))WARN_ON(!mutex_is_locked(&fbc->lock))
Physical memory: 3905 MB
Dumping 241 MB:..7%..14%..27%..34%..47%..53%..67%..73%..87%..93%
0x0102d895 in doadump (textdump=<optimized out>)
at /usr/src/sys/kern/kern_shutdown.c:398
398 savectx(&dumppcb);
ここまでがgdbを起動した時の前振りなんだ。カーネル自身が記憶してる秘密の日記を閲覧してるんだな。だからそれを晒してしまおうと言うあこぎな事をやってしまうとな。後は普通のgdb操作になるのね。と言う事はkgdbの特別仕様を使ってる事になる。
root@fb:/tmp # /usr/local/bin/gdb -q /boot/kernel/kernel /var/crash/vmcore.2 Reading symbols from /boot/kernel/kernel... Reading symbols from /usr/lib/debug//boot/kernel/kernel.debug... "/var/crash/vmcore.2" is not a core dump: file format not recognized
どもうもcoreの前に余計なデータが付いている。これを理解出来無いから、フォーマット違いというエラーになるんだな。
(kgdb) bt 3
#0 0x0102d895 in doadump (textdump=<optimized out>)
at /usr/src/sys/kern/kern_shutdown.c:398
#1 0x0102d6d6 in kern_reboot (howto=260)
at /usr/src/sys/kern/kern_shutdown.c:487
#2 0x0102daab in vpanic (
fmt=0x14c1a2a "vm_page_free_prep: page %p has references",
ap=0x263a71ec "\224?%\003\320\003")
at /usr/src/sys/kern/kern_shutdown.c:920
(More stack frames follow...)
(kgdb) info locals
error = 0
coredump = <optimized out>
savecore
swap-dirに保存されたcoreファイルを/var/crashにcpして、後の解析に役立てる。そのための収集プログラムだ。
DESCRIPTION
The savecore utility copies a core dump into directory, or the current
working directory if no directory argument is given, and enters a reboot
message and information about the core dump into the system log.
debug how to
ちょっと古い投稿だけど、言わんとしてる事は今でも健在。
ddbに入って、panicさせたいんだけど、どうやったら入れる？