SadServers解説#1 "Saint John": what is writing to this log file?
問題概要
シナリオ
このログファイルに書き込んでいるのは何者ですか?
問題詳細
ある開発者が作成したテストプログラムが、ログファイル/var/log/bad.logに書き込み続け、ディスク容量を圧迫しています。例えば、コマンドtail -f /var/log/bad.log
を実行することで確認できます。
~$ tail -f /var/log/bad.log
2024-01-16 13:00:19.007207 token: 590469299
2024-01-16 13:00:19.307685 token: 711233412
2024-01-16 13:00:19.608161 token: 850657266
※終了するには Ctrl+C
このプログラムはもう必要ないため、プログラム見つけて終了させてください。
解決判定
(ログファイルのサイズ計測の間隔よりも長い時間)ログファイルのサイズが変化しないこと。
※例えば、ログファイルのサイズが1秒ごとに観測される場合、1秒以上ファイルサイズが変化しなければ解決と判定されます。
Check My Solution
ボタンをクリックすると、合格を判定するスクリプト/home/admin/agent/check.shが実行されます。
問題解決の方針
【表示する】
とあるプロセスがログファイルに書き込みを続けており、ログファイルへの書き込みを止める必要があります。
そのため、ログファイルに書き込んでいるプロセスを特定し、停止させる必要があります。
解決の手順を表示する
- /var/log/bad.logに書き込んでいるプロセスのプロセスIDを調べる
- 得られたプロセスIDを使用して、当該プロセスを停止する
ヒント
一部、SadServers公式のヒントを改変しています。
ヒント1
ps
コマンドを実行することで、すべてのプロセスを表示し、今回の問題に関連するものがあるかどうか確認できます。
たとえば、ps auxf
コマンドを実行します。
実行コマンド
~$ ps auxf
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
...
admin 585 0.1 1.7 12508 8280 ? S 14:38 0:00 /usr/bin/python3 /home/admin/badlog.py
...
↑怪しいプロセス発見
しかし、上記の方法では、プロセスが開いているファイルを必ずしも確認できるとは限りません。
さらに最適な方法として、lsof
コマンドを実行することで、開かれているファイルを一覧表示することができます。
ヒント2
lsof
コマンドを実行し、bad.logを含む行にフィルタをかけることで、/var/log/bad.logに関連しているプロセスのプロセス名(一列目)とプロセスID(2列目の"PID")を見つけます。[]で囲まれたプロセスはシステムプロセスのため、今回は無視します。
実行コマンド
~$ lsof | head -1
COMMAND PID TID TASKCMD USER FD TYPE DEVICE SIZE/OFF NODE NAME
~$ lsof | grep bad.log
badlog.py 585 admin 3w REG 259,1 45842 265802 /var/log/bad.log
/var/log/bad.logを開いているプロセスのプロセスID(PID)が585であることが分かりました。
※PIDは上記と一致するとは限りません。
ヒント3
/var/log/bad.logに書き込んでいるプロセスのプロセスIDを使い、kill
コマンドを実行してプロセスを終了します。
実行コマンド
~$ kill -9 585
上記コマンドを実行後、Check My Solution
ボタンをクリックしてください。
別解
fuser /var/log/bad.logを実行することでも、問題のプロセスを迅速に見つけることができます。
~$ fuser /var/log/bad.log
/var/log/bad.log: 585
今回は必要ではありませんが、プロセスIDがあれば、pwdx PID
(もっと詳細に知りたい場合は、lsof -p PID
)を実行することで、プログラムが存在するディレクトリを見つけることができます。
これにより、プログラムの所有者を確認したり、プログラムが(バイナリではなく)スクリプトであれば問題のあるコードを調査できたりします。
(補足:バイナリファイルとは、コンピュータが直接実行するエンコード済みファイルのことです。バイナリファイルを人間が中身を読んで理解するのは無茶です)
~$ pwdx 585
585: /home/admin
~$ lsof -p 585
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
badlog.py 585 admin cwd DIR 259,1 4096 272476 /home/admin
badlog.py 585 admin rtd DIR 259,1 4096 2 /
badlog.py 585 admin txt REG 259,1 5479736 5453 /usr/bin/python3.9
…
「いきなり問題を解き始めても調べるばかりになってしまう…」 「やりたいことが分かっても、コマンドが分からない…」 という方は、下記の記事でLinuxのコマンドを復習してから、SadServersの問題に取り掛かってみてはいかがでしょうか。
余談
問題のプログラムを見てみる
cat /home/admin/badlog.py
を実行して、問題のプロセスの中身を見てみます。
#! /usr/bin/python3
# test logging
import random
import time
from datetime import datetime
with open('/var/log/bad.log', 'w') as f:
while True:
r = random.randrange(2147483647)
print(str(datetime.now()) + ' token: ' + str(r), file=f)
f.flush()
time.sleep(0.3)
無限ループのプログラムで、0.3秒ごとにランダムな数字を書き込んでいるようです。
問題一覧はこちら
Discussion