このところ自作した目覚まし時計のフリーズに悩まされて来たのだが、ついにこれだという原因にたどり着いた。
thom.hateblo.jp
ヒントになったのがLinux Essentials試験の学習で得たメモリ管理まわり。
freeコマンドでメモリの状況を確認できるのでメモリリークを疑ってみようと思ったのだ。
試しに疑わしいスクリプトのcron実行を1分に1回の起動に変えてみたうえ、同じタイミングで毎回freeコマンドでメモリ容量を~/free.txtに書き込むようにしてみたところ次のような結果になった。
Thu 4 May 20:46:01 JST 2023
total used free shared buff/cache available
Mem: 931432 93744 706304 964 131384 778148
Swap: 102396 0 102396
Thu 4 May 20:47:01 JST 2023
total used free shared buff/cache available
Mem: 931432 99220 700760 964 131452 772652
Swap: 102396 0 102396
Thu 4 May 20:48:01 JST 2023
total used free shared buff/cache available
Mem: 931432 104972 694472 964 131988 766880
Swap: 102396 0 102396
～中略～
Thu 4 May 21:03:01 JST 2023
total used free shared buff/cache available
Mem: 931432 192092 605556 964 133784 679380
Swap: 102396 0 102396これだ！
かなりのハイペースでメモリを食い続けている。
今回の犯人はwokeup.pyというスクリプト
前提として目覚まし時計は鳴るタイミングでcron起動されるalarm.pyと、常時起動のwokeup.pyで構成されている。
以前、常時起動の方が落ちていたことがあったのでいずれデーモン化しようと思っているのだが面倒なのでとりいそぎcronで毎時10分と40分に起動させている。
wokeup.pyはすでに起動しているwokeup.pyがあればpkillで落とすような仕様なので疑って無かったんだけど、psコマンドで確認してみると53件ものwokeupが起動中。まじか。
thom@alarm:~ $ ps aux | grep -c wokeup 53
とりいそぎ手動でpkillしたところ起動直後の基準まで落ち着いた。
thom@alarm:~ $ pkill wokeup
thom@alarm:~ $ ps aux | grep -c wokeup
1
thom@alarm:~ $ free
total used free shared buff/cache available
Mem: 931432 82632 714468 972 134332 788768
Swap: 102396 0 102396
wokeupスクリプト内で原因となっているのはこの部分。
要するにpkillに失敗しているらしい。
cmd = "sudo pkill wokeup" proc = Popen(cmd.strip().split(" ")) proc.wait() sp.setproctitle("wokeup")
そういえばalarm.pyも二重に鳴ったことがあってsudoを外したら上手く行ったんだった。
ひとつ思い当たる節はセキュリティ強化の為にsudo実行にパスワードを要求するように設定したこと。
スクリプト内のsudoならcronがうまく捌いてくれるかなと勝手に思い込んでいたんだけどダメだったみたいだ。
また、プロセスを終了させるpkillコマンドはroot権限じゃないと動かないという勘違いもあった。
自分で起動したプロセスなんだから、当然自分でpkillできるんだ。
コマンドの場所もsbinじゃなくてbinになっている。
thom@alarm:~ $ which pkill /usr/bin/pkill
修正後の記録がこちら。
Thu 4 May 21:14:01 JST 2023
total used free shared buff/cache available
Mem: 931432 90912 706048 972 134472 780488
Swap: 102396 0 102396
Thu 4 May 21:15:02 JST 2023
total used free shared buff/cache available
Mem: 931432 85292 711736 964 134404 786152
Swap: 102396 0 102396
Thu 4 May 21:16:01 JST 2023
total used free shared buff/cache available
Mem: 931432 85196 711728 964 134508 786268
Swap: 102396 0 102396
Thu 4 May 21:17:01 JST 2023
total used free shared buff/cache available
Mem: 931432 88988 707948 964 134496 782508
Swap: 102396 0 102396
～中略～
Thu 4 May 21:23:01 JST 2023
total used free shared buff/cache available
Mem: 931432 87892 708996 964 134544 783620
Swap: 102396 0 102396増減は見られるが修正前のように徐々に確実に減っていくということはない。
プロセスも確認してみた。周辺コマンドが表示されてしまっているもののwokeup本体は1つのみ。
thom@alarm:~ $ ps aux | grep wokeup thom 1369 0.0 0.0 2064 468 ? Ss 21:26 0:00 /bin/sh -c /home/thom/wokeup.py thom 1371 2.0 1.0 24284 9680 ? Sl 21:26 0:00 wokeup thom 1377 0.0 0.0 5908 752 pts/0 S+ 21:26 0:00 grep --color=auto wokeup
ということで恐らく解決。
これまでは馬鹿の一つ覚えとして落ちた後にひたすらsyslogを確認するということをしていたのだが知識不足で何が起きているのか分からず。
また、メモリの枯渇という概念を知識としては持っていたものの確認コマンドを知らなかったがためにメモリが枯渇しているという状況を想定すらできていなかった。
今回はLinux Essential試験に向けた網羅的な学習がヒントとなって解決できた形。
手段がなければ目的すら見えない。
これまでもいろんなところで実感してきたことだが今回も改めてそう認識した次第である。
