🕵️

ログメッセージだけから segfault 原因を調査する

2022/10/10に公開約5,000字

ログメッセージだけから segfault 原因を調査する

はじめに

システムログに残された悲しいメッセージ。全く再現ができないのでコアダンプは採取できない…そんな場合にどこまで悪あがきできるか、まとめました。

segv.out[31620]: segfault at abcd ip 00007fb3d5c865a4 sp 00007ffdae3f7528 error 4 in libc.so.6[7fb3d5b11000+195000]

手順

まず発生したプログラムカウンタ(IP)から共有ライブラリのアドレスを引いて、発生位置を求めます。

0x7fb3d5c865a4 - 0x7fb3d5b11000 = 0x1755A4

次に objdump や readelf で共有ライブラリのプログラムヘッダテーブルを表示し、実行可能なセグメントのオフセットを探します。( <---- をつけた箇所のオフセット 28000)

$ objdump -p /lib/x86_64-linux-gnu/libc.so.6

/lib/x86_64-linux-gnu/libc.so.6: 	ファイル形式 elf64-x86-64

プログラムヘッダ:
     PHDR off 0x0000000000000040 vaddr 0x0000000000000040 paddr 0x0000000000000040 align 2**3
       filesz 0x0000000000000310 memsz 0x0000000000000310 flags r--
   INTERP off 0x00000000001e3e30 vaddr 0x00000000001e3e30 paddr 0x00000000001e3e30 align 2**4
       filesz 0x000000000000001c memsz 0x000000000000001c flags r--
     LOAD off 0x0000000000000000 vaddr 0x0000000000000000 paddr 0x0000000000000000 align 2**12
       filesz 0x0000000000027fe0 memsz 0x0000000000027fe0 flags r--
     LOAD off 0x0000000000028000 vaddr 0x0000000000028000 paddr 0x0000000000028000 align 2**12
       filesz 0x00000000001944c1 memsz 0x00000000001944c1 flags r-x <----
     LOAD off 0x00000000001bd000 vaddr 0x00000000001bd000 paddr 0x00000000001bd000 align 2**12
       filesz 0x00000000000578cc memsz 0x00000000000578cc flags r--
     LOAD off 0x00000000002148f0 vaddr 0x00000000002158f0 paddr 0x00000000002158f0 align 2**12
       filesz 0x0000000000004f98 memsz 0x0000000000012560 flags rw-
  DYNAMIC off 0x0000000000217bc0 vaddr 0x0000000000218bc0 paddr 0x0000000000218bc0 align 2**3
       filesz 0x00000000000001d0 memsz 0x00000000000001d0 flags rw-
...

この2つを足し合わせた 0x1755A4 + 0x28000 = 0x19D5A4 が所望のアドレスです。

シンボルテーブルから付近のアドレスを検索します。

objdump -t /lib/x86_64-linux-gnu/libc.so.6 | grep 00019d5 | sort
000000000019d580 l 	F .text    0000000000000206 __strchrnul_avx2

strchrnul …文字列操作かな…? くらいまで絞り込めました。

答え合わせ

segfault を発生させたプログラムの元ソースは、以下の通り printf で不正なアドレスを表示しようとしていました。

#include <stdio.h>
void segv(void) {
	printf((const char*)0x0000abcd); // invalid access
}

int main(void) {
	segv();
	return 0;
}

デバッガで実行してみましょう。

$ gdb ./segv.out
(gdb) r
Program received signal SIGSEGV, Segmentation fault.
__strchrnul_avx2 () at ../sysdeps/x86_64/multiarch/strchr-avx2.S:65
(gdb) bt
#0  __strchrnul_avx2 () at ../sysdeps/x86_64/multiarch/strchr-avx2.S:65
#1  0x00007ffff7df9162 in __find_specmb (format=0xabcd <error: Cannot access memory at address 0xabcd>) at ./stdio-common/printf-parse.h:111
#2  __vfprintf_internal (s=0x7ffff7f9e780 <_IO_2_1_stdout_>, format=0xabcd <error: Cannot access memory at address 0xabcd>, ap=ap@entry=0x7fffffffdf10,
    mode_flags=mode_flags@entry=0) at ./stdio-common/vfprintf-internal.c:1255
#3  0x00007ffff7de481f in __printf (format=<optimized out>) at ./stdio-common/printf.c:33
#4  0x0000555555555160 in segv () at segv.c:3
#5  0x00005555555551b3 in main () at segv.c:7

先程の解析と同じ __strchrnul_avx2 に到達しました。

解説

上記でオフセットの加算が必要な理由は以下の通り。

ログメッセージは以下2つに分かれる。

  • 前半部: segfault at XXXX ip XXXXXXXXXXXXXXXX sp XXXXXXXXXXXXXXXX error X
  • 後半部: in XXX.so[XXXXXXXXX000+XXX000]

前半部はカーネルソースの arch/x86/mm/fault.cshow_signal_msg で、後半部は mm/memory.cprint_vma_addr で出力される。

上記ソースを読むとメッセージ後半部は、実行位置アドレス(IP) を含むメモリマップ (/proc/<PID>/maps)のファイル名・開始アドレス・マップサイズを表示していることがわかる。

共有ライブラリ(に限らずELF ファイル)はセグメント毎に別れてマッピングされるので、メッセージ後半部は コードセグメントの開始アドレス が表示されていることになる。このことより、コードセグメントのオフセットを加味すれば良いとわかる。

昔はコードセグメントが一番最初に配置されていた気がするのだが最近は(?) .hash .dynsym .dynstr などを含むデータセグメント(下記02)が .text を含むコードセグメント(下記03)の前に定義されており、上記オフセットを処置しないと正しい位置が求まらない。

$ readelf -e /usr/lib/x86_64-linux-gnu/libc.so.6 | tail -n 14
   00	 
   01 	.interp
   02 	.note.gnu.property .note.gnu.build-id .note.ABI-tag .gnu.hash .dynsym .dynstr .gnu.version .gnu.version_d .gnu.version_r .rela.dyn .rela.plt
   03 	.plt .plt.got .plt.sec .text __libc_freeres_fn
   04 	.rodata .stapsdt.base .interp .eh_frame_hdr .eh_frame .gcc_except_table .hash
   05 	.tdata .init_array __libc_subfreeres __libc_atexit __libc_IO_vtables .data.rel.ro .dynamic .got .got.plt .data .bss
   06 	.dynamic
   07 	.note.gnu.property
   08 	.note.gnu.build-id .note.ABI-tag
   09 	.tdata .tbss
   10 	.note.gnu.property
   11 	.eh_frame_hdr
   12	 
   13 	.tdata .init_array __libc_subfreeres __libc_atexit __libc_IO_vtables .data.rel.ro .dynamic .got

まとめ

上記例は恣意的なもので、実不具合ではどこからでも呼ばれそうな組み込み関数ということしかわからず、悲しい思いをすることも少なくありません。
(当初 strcpy でサンプルを書こうと思っていましたが __memmove_avx_unaligned_erms という AVX 組み込み関数に到達してしまい、printf に変更しています。)

しかし上記のようにデバッグ環境とログを突き合わせることで、同じ不具合を再現できていそうだ、という心安めくらいには使えるかなと思います。

参考

【Linux】コアダンプ無しで、クラッシュを特定する : ほぼこちらの手順そのままです。

Discussion

ログインするとコメントできます