systemd-coredump環境で暮らす

Red Hat の森若です。

本記事は赤帽エンジニアAdvent Calendar 2018の7日目です。

RHEL 7 まで、開発中以外のタイミングでクラッシュするプロセスのcoreを取得するのはなかなか大変でした。デフォルトではプロセスのCWDにcoreファイルを保存しますが、このサイズや個数を制御する標準的な方法がなかったため、「ときどきクラッシュするシステム」の問題を解析するためにcore出力を有効にすると、ファイルシステムがあふれてしまう懸念があったのです。

RHEL8 betaではsystemd-coredumpがデフォルトで有効になっています。 systemd-coredumpはプロセス異常終了時に出力されるcoreファイルを管理する仕組みで、以下のような機能を提供します。

  • coreファイルを(各プロセスのCWDではなく)あらかじめ決められた場所に保存する
    • systemd-journal内または/var/lib/systemd/coredump/ 以下の個別のファイルに保存します。RHELではjournal内に保存するのではなくファイルでの保存がデフォルトです。
  • coreファイル取得時のメタデータをsystemd-journalのログに保存する
    • 実行ファイル、systemd unit、タイムスタンプ、ユーザ等
    • さらに可能であればcoreファイル取得と同時にバックトレースを取得
  • あらかじめ決めた基準で過去のcoreファイルを削除する

この仕組みが導入されたことで、長期運用中にcoreファイル出力を有効にすることが(相応のI/Oなどは発生しますが)現実的になってきます。systemd-coredumpが有効な環境でのcoreファイルの扱いについて見ていきましょう。

coreの一覧をみる

ulimit -c unlimited と設定してcore出力を有効にしたのち、適当なプログラムを作成して、わざとSEGVを発生させます。

coredumpctl list で最近取得したcoreの一覧を見る:

$ coredumpctl list
Hint: You are currently not seeing messages from other users and the system.
      Users in the 'systemd-journal' group can see all messages. Pass -q to
      turn off this notice.
TIME                            PID   UID   GID SIG COREFILE  EXE
Wed 2018-12-05 01:11:09 EST    2189  1000  1000  11 present   /home/kmoriwak/tmp/a.out
Wed 2018-12-05 01:16:44 EST    2469  1000  1000  11 present   /home/kmoriwak/tmp/a.out
Wed 2018-12-05 01:16:45 EST    2479  1000  1000  11 present   /home/kmoriwak/tmp/a.out
Wed 2018-12-05 01:16:45 EST    2489  1000  1000  11 present   /home/kmoriwak/tmp/a.out
Wed 2018-12-05 01:16:45 EST    2500  1000  1000  11 present   /home/kmoriwak/tmp/a.out
Wed 2018-12-05 01:16:46 EST    2510  1000  1000  11 present   /home/kmoriwak/tmp/a.out
Wed 2018-12-05 01:16:46 EST    2520  1000  1000  11 present   /home/kmoriwak/tmp/a.out

もし過去に出力されたcoreが多数出力されてみづらいような場合には、 coredumpctl list -S -1day のようにして「1日前以降」のようなフィルタ指定を行うことで絞り込みます。

のように実行ファイルでも絞り込めます。

出力冒頭のHint:という行は、メタデータはsystemd-journalに保存されているため一般ユーザはシステム全体のcoreについての情報は見えないことについての警告です。システム全体のcoreを見たい場合には、ユーザをsystemd-journalグループに入れるかroot権限でcoredumpctlを実行しましょう。

coreの情報をみる

それぞれのcoreについての情報は coredumpctl info コマンドで確認できます。PID(coredumpctl info 2520)や実行ファイル名(coredumpctl info /usr/bin/xfs_spaceman)、journalctlでも使う検索などで出力対象を絞りこめます。ソフトウェアの開発中には直前に出力されたcoreを指定する「-1」オプションが役に立つでしょう。

coredumpctl info でcoreについての情報を見る:

$ coredumpctl info -1
Hint: You are currently not seeing messages from other users and the system.
      Users in the 'systemd-journal' group can see all messages. Pass -q to
      turn off this notice.
           PID: 2520 (a.out)
           UID: 1000 (kmoriwak)
           GID: 1000 (kmoriwak)
        Signal: 11 (SEGV)
     Timestamp: Wed 2018-12-05 01:16:46 EST (6min ago)
  Command Line: ./a.out
    Executable: /home/kmoriwak/tmp/a.out
 Control Group: /user.slice/user-1000.slice/session-3.scope
          Unit: session-3.scope
         Slice: user-1000.slice
       Session: 3
     Owner UID: 1000 (kmoriwak)
       Boot ID: f40028f411b94aad84f61157d9ca0c4a
    Machine ID: 928c334a6b3b4d5193acadcf3b688b5f
      Hostname: client
       Storage: /var/lib/systemd/coredump/core.a\x2eout.1000.f40028f411b94aad84f61157d9c>
       Message: Process 2520 (a.out) of user 1000 dumped core.
                
                Stack trace of thread 2520:
                #0  0x00000000004005a2 n/a (/home/kmoriwak/tmp/a.out)
                #1  0x00007fddd4085813 __libc_start_main (libc.so.6)
                #2  0x00000000004004de n/a (/home/kmoriwak/tmp/a.out)

割とこまかく情報が残っていますね! 実はこの情報以外にもprocfsで取得できる各種の情報がjournalに保存されています。 journalctl SYSLOG_IDENTIFIER=systemd-coredump -o verbose のようにすると確認できるので気になる人は見てみましょう。

gdbからcoreを使う

coreといえばデバッグに利用したいわけですが、coredumpctl gdb PID のように実行することで簡単にgdbを実行できます。

coredumpctl gdb で gdb起動:

$ coredumpctl gdb -1
Hint: You are currently not seeing messages from other users and the system.
      Users in the 'systemd-journal' group can see all messages. Pass -q to
      turn off this notice.
           PID: 2520 (a.out)
           UID: 1000 (kmoriwak)
           GID: 1000 (kmoriwak)
        Signal: 11 (SEGV)
     Timestamp: Wed 2018-12-05 01:16:46 EST (11min ago)
  Command Line: ./a.out
    Executable: /home/kmoriwak/tmp/a.out
 Control Group: /user.slice/user-1000.slice/session-3.scope
          Unit: session-3.scope
         Slice: user-1000.slice
       Session: 3
     Owner UID: 1000 (kmoriwak)
       Boot ID: f40028f411b94aad84f61157d9ca0c4a
    Machine ID: 928c334a6b3b4d5193acadcf3b688b5f
      Hostname: client
       Storage: /var/lib/systemd/coredump/core.a\x2eout.1000.f40028f411b94aad84f61157d9ca0c4a.2520.1543990606000000.lz4
       Message: Process 2520 (a.out) of user 1000 dumped core.
                
                Stack trace of thread 2520:
                #0  0x00000000004005a2 n/a (/home/kmoriwak/tmp/a.out)
                #1  0x00007fddd4085813 __libc_start_main (libc.so.6)
                #2  0x00000000004004de n/a (/home/kmoriwak/tmp/a.out)

GNU gdb (GDB) Red Hat Enterprise Linux 8.2-3.el8
Copyright (C) 2018 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-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/kmoriwak/tmp/a.out...done.
[New LWP 2520]
Core was generated by `./a.out'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00000000004005a2 in main () at a.c:5
5       printf("%d", *a);
Missing separate debuginfos, use: dnf debuginfo-install glibc-2.28-18.el8.x86_64
(gdb) p a
$1 = (int *) 0x0
(gdb) 

典型的なNULL Pointer dereferenceなのでこれはSEGVも起きるというものですね。

coreをファイルに保存する

coredumpctl info で出力されるうちの、 Storage: /var/lib/systemd/coredump/core.a\x2eout.1000.f40028f411b94aad84f61157d9ca0c4a.2520.1543990606000000.lz4 このファイルがcoreファイルです。lz4圧縮されているので通常のcoreファイルよりだいぶ小さくなります。 coreファイルはrootユーザ、rootグループで保存されていますが、ACLで該当userにread権限が付与されています。

アクセス権限を確認:

$ getfacl  '/var/lib/systemd/coredump/core.a\x2eout.1000.f40028f411b94aad84f61157d9ca0c4a.2520.1543990606000000.lz4'
getfacl: Removing leading '/' from absolute path names
# file: var/lib/systemd/coredump/core.a\\x2eout.1000.f40028f411b94aad84f61157d9ca0c4a.2520.1543990606000000.lz4
# owner: root
# group: root
user::rw-
user:kmoriwak:r--
group::r--
mask::r--
other::---

gdb以外のツールで使いたいときや、後述の自動削除で消されたくない場合など、ファイルとしてcoreを使いたいときは、 coredumpctl dump PID --output ファイル名 のようにすると保存されている場所やファイル名を考えずにファイルへ出力できます。

ファイルへ出力

$ coredumpctl dump -1 --output corefile
Hint: You are currently not seeing messages from other users and the system.
      Users in the 'systemd-journal' group can see all messages. Pass -q to
      turn off this notice.
           PID: 2520 (a.out)
           UID: 1000 (kmoriwak)
           GID: 1000 (kmoriwak)
        Signal: 11 (SEGV)
     Timestamp: Wed 2018-12-05 01:16:46 EST (20min ago)
  Command Line: ./a.out
    Executable: /home/kmoriwak/tmp/a.out
 Control Group: /user.slice/user-1000.slice/session-3.scope
          Unit: session-3.scope
         Slice: user-1000.slice
       Session: 3
     Owner UID: 1000 (kmoriwak)
       Boot ID: f40028f411b94aad84f61157d9ca0c4a
    Machine ID: 928c334a6b3b4d5193acadcf3b688b5f
      Hostname: client
       Storage: /var/lib/systemd/coredump/core.a\x2eout.1000.f40028f411b94aad84f61157d9ca0c4a.2520.1543990606000000.lz4
       Message: Process 2520 (a.out) of user 1000 dumped core.
                
                Stack trace of thread 2520:
                #0  0x00000000004005a2 n/a (/home/kmoriwak/tmp/a.out)
                #1  0x00007fddd4085813 __libc_start_main (libc.so.6)
                #2  0x00000000004004de n/a (/home/kmoriwak/tmp/a.out)
More than one entry matches, ignoring rest.

coredumpが消されるのはどういうタイミングか?

systemd-coredump環境では、coreファイルは以下の基準で削除されます。

  • ファイルシステムの残容量が基準(デフォルト 15%)以下
  • ファイルシステムの容量全体にたいするcoreファイルの割合が基準(デフォルト 10%)以上
  • 一定期間(デフォルト 3日)以上アクセスなし

はじめの2つは、systemd-coredumpがcoreを保存する直前と直後にcoredump.conf設定中のMaxUseKeepFreeを反映して削除をおこないます。容量の制限を満たすまで古いものから順に削除されます。ただし今出力したばかりのcoreファイルは維持されます。

systemd/src/coredump/coredump.c より:

static int submit_coredump(
(中略)
        (void) coredump_vacuum(-1, arg_keep_free, arg_max_use);
        /* Always stream the coredump to disk, if that's possible */
        r = save_external_coredump(context, input_fd,
                                   &filename, &coredump_node_fd, &coredump_fd, &coredump_size, &truncated);
(中略)
        /* Vacuum again, but exclude the coredump we just created */
        (void) coredump_vacuum(coredump_node_fd >= 0 ? coredump_node_fd : coredump_fd, arg_keep_free, arg_max_use);

一定期間以上アクセスがない場合については、 systemd-tmpfilesを利用して削除をおこないます。/usr/lib/tmpfiles.d/systemd.conf の中で

d /var/lib/systemd/coredump 0755 root root 3d

と指定されており、このディレクトリの中にある3日以上アクセスがないファイルはsystemd-tmpfiles-cleanが削除します。

systemd-coredump利用時の注意点

前述のとおりcoredumpのメタデータはsystemd-journalのログに保存されています。RHEL8betaのデフォルトではsystemd-journalのログが永続化されておらず、coreファイルは残りますがメタデータが失われてしまいます。あらかじめ /var/log/journal/ ディレクトリを作成してjournalの永続化を行うのがおすすめです。

もしjournalが消えてしまっても、systemd-coredumpが保存するcoreファイルには拡張属性を利用していくつかのメタデータが添付されています。以下はgetfattrでメタデータを確認する例です。

# getfattr  -d core.packagekitd.0.811279367f5541c294300e7ec3c33223.23641.1543801829000000.lz4 
# file: core.packagekitd.0.811279367f5541c294300e7ec3c33223.23641.1543801829000000.lz4
user.coredump.comm="packagekitd"
user.coredump.exe="/usr/libexec/packagekitd"
user.coredump.gid="0"
user.coredump.hostname="snake.usersys.redhat.com"
user.coredump.pid="23641"
user.coredump.rlimit="18446744073709551615"
user.coredump.signal="11"
user.coredump.timestamp="1543801829"
user.coredump.uid="0"

systemd-coredumpのデフォルトでは利用メモリ量が2GBまでのプロセスを対象として、最大2GBのcoreファイルを作成する設定になっています。大容量のメモリを扱うアプリケーションに適用したい場合には上限(ProcessSizeMax および ExternalSizeMax)を変更しましょう。

アプリケーションがcoreファイルの出力先を指定できる(CWDを指定されたディレクトリに変更する)場合にも、systemd-coredumpの仕組みが優先されます。

coreファイルが作成されるディレクトリ /var/lib/systemd/coredump は変更できません。/varと別のファイルシステムにしたい場合にはシンボリックリンクやbind mountなどで対応します。

関連man pages