Red Hatの森若です。
この記事はRed Hat Advent Calendar 2023 の21日目です。
デバッグなどのためにsystemdのservice unitで起動されるプロセスにstraceを仕掛けたいとき、ちょっとしたハマり所があるのでその説明とワークアラウンドを紹介します。
目次
実行中のserviceをstraceする
この場合は特にハマるところはありません。
既に実行中のプロセスへのstraceは、cgroupで関連するプロセス一覧が管理されているので、それを利用します。関連する全てのプロセスを指定し、-fでforkも追跡することで、関連する全プロセスを指定します。
- serviceに対応するcgroupを確認する。
$ systemctl show dbus-broker.service |grep ControlGroup=
ControlGroup=/system.slice/dbus-broker.service
または
$ systemctl status dbus-broker.service |grep CGroup
CGroup: /system.slice/dbus-broker.service
- cgroupの
cgroup.procsを利用してstrace の -p オプションに関連プロセスを指定する
# strace -fttTvyy -s 4096 -o /tmp/dbus.strace -p $(tr \\n , < /sys/fs/cgroup/system.slice/dbus-broker.service/cgroup.procs)
実行開始からserviceをstraceする
実行開始直後の初期化なども観測対象にする場合、起動時に straceの子プロセスとしてプログラムを実行開始します。 つまり以下のように指定して実行します。以下で説明しますが一部で問題が発生します。
ExecStart=/usr/bin/strace -fttTvyy -s 4096 -o /tmp/strace.log もとのコマンド…
Type=forking 時の問題
systemdのservice unitにはType という属性がありsimple, oneshot, forkingなどいくつかの種類にわかれています。Type=forkingの場合にはExecStartの書き換えだけでは期待通りに動作しません。
systemctl start foobar.service としたあとしばらく activating状態で動作し、起動に失敗したとして終了します。
まずType=forkingの通常の動作について紹介します。この場合systemdが直接実行する「起動プロセス」と実際にサービスを提供する「サービスプロセス」が別になっています。
上図のように、systemdは起動プロセスの実行終了をもって、service unitがactiveになったとみなします。
単純にExecStartの先頭にstraceを付与した場合、上図のようになります。straceは起動プロセスとサービスプロセスの両方をトレースしてログを出力し続けます。起動プロセスは終了し、サービスプロセスも通常どおりサービスを提供します。
このときsystemdの視点では実行したプロセス(strace)が終了しないので、起動処理が完了しません。デフォルトでは1分30秒でsystemdはservice unitの起動が失敗したと判断し、シグナルを送信して関連するプロセスを停止します。これがさきほどの終了の原因です。
ここまでわかれば対策は単純です。Type=forking を Type=simple のように変更します。
Type=simpleの場合、最初のfork実行時点でactiveとなり、プログラムが終了するとサービスがinactiveになります。
さて Type=oneshotでは、長時間動作するサービスプロセスにあたるものはなく、プロセスもタイムアウトより早く終了することが求められます。straceは全プロセス終了にともない早く終了します。そのため本来は類似の問題はほぼ発生しません。
ただしType=forkingを指定するべきアプリケーションに誤ってType=oneshotが指定されている場合があり、そのような場合には同様の問題が発生します。
参考文献
詳しくは以下のman pagesに記載があります。
