systemd が重いのを解決する

こんにちは、masm11 です。

家に Mini PC を家庭内サーバとして置いています。ほとんどファイルサーバですが。

こんなやつです。

ふと気づくと、定期的にファンが唸っていました。 何が動いてるんだろう？ と top コマンドで調べてみたところ、 なんと systemd (PID=1) が CPU を 100% 使っていました。

今回は、これを解決するまでの数ヶ月を、日記から振り返ってみます。

7/29 気づく

もう3ヶ月以上も前ですね。

この時は、systemd が重いことに気づいて reboot しました。

7/30 調子いい

次の日になって、もう一度確認して、大丈夫そうでした。

これで一安心かと思っていました。

8/14 strace かけてみる

また systemd が CPU 100% であることに気づきました。

何か対応しようとして sudo すると、やたら時間がかかるんです。 パスワード聞かれるまで数分、入力したあとも数分。

ls -l も時間がかかるし、id コマンドも時間がかかります。

何をやってるのかは、strace を使うとどんなシステムコールが 実行されているのかを見ることができます。 strace -p 1 で PID=1 に attach できます。

なんというか、DBus アクセスが多いです。 DBus というのは、プロセス間通信に使われる、ソフトウェア的なバスですね。

DBus でどんな通信をしているかは、sudo busctl monitor で確認できます。 どうも udev っぽいです。明確に書かれてたわけではないのですが、 文字列からそう推測しました。

udev というのは、デバイスが検出された時や外された時に、 初期化・終了処理、/dev 内のデバイスファイルの作成などを行っています。

udev というと、思い当たることが一つあります。 プリンタの設定として /etc/udev/rules.d/00-pixma.rules を置いています。 が、プリンタはインクがうまく出なくなったので、もう電源を切ったままです。

そのあたり、何か関係してるのかもしれません。 この設定ファイルを削除 (というか移動) しました。

あと、sudo で時間がかかる点について、ググったところ、 /etc/hosts に書き忘れてるとそうなる場合がある、ということで、 設定しました。

上記2点を実施したところ、なんと sudo がさくさく動くようになりました。

ls -l も id も時間がかかっていたのが解消しました。

実施した2点のうちどちらが効果があったのかは不明ですが、 とりあえずこれで様子見することにします。

9/15 いろいろ時間がかかるのを解消

やっぱり重くなるんです…

reboot 直後はさくさく反応するんですが、時間が経つにつれて、 重くなっているように感じます。

いろいろ時間がかかって、全然調査が進みません。

  • ssh で login する時に時間がかかる
  • sudo に時間がかかる
  • ls は速いけど ls -altr は時間がかかる
  • id も時間がかかる
  • systemctl status は時間がかかって timeout する。
  • sudo systemctl stop ... も時間かかって結局 timeout する。

もう、何もできません。

どこに原因があるのでしょう？

nss ですかね？ nss は name service switch の略ですね。例えば UID ⇔ ユーザ名 の変換をする際に、いろいろな場所にテーブルがあります。/etc/passwd や NIS, NIS+, systemd-homed 等があります。これらをどういう順序で検索するべきか、 というのを設定する機構です。UID ⇔ ユーザ名の他にも、IPアドレス ⇔ ホスト名の変換に 使うサービスの順序もここに定義されます。

ssh, sudo, ls, id に共通するものと言えば、ユーザ名とUIDの変換です。 これに時間がかかっているように思えます。

とりあえず nss の設定ファイルである /etc/nsswitch.conf をいじりました。

passwd: files
group: files
shadow: files
gshadow: files

systemd が含まれていたので外しました。

これだけで見事に速くなりました。しかし systemctl に時間がかかっているのは、 これでは説明できません。 おそらく systemd が重い方が根っこで、nss が遅かったのはそれによる影響なのでしょう。 で、systemd とのつながりを切ったので、軽くなった、と考えられます。

9/16 systemd を crash させてしまう

sudo や ls は速くなりましたが、相変わらず systemd が重いです。

strace -p 1 ではこれ以上何もわからないので、gdb に頼ってみましょう。

gdb で attach 1 を2回実行したところ、フリーズしました。

おそらく systemd が crash してしまったのでしょう……

gdb は使わない方がいいですね。別の方法を考えましょう…

10/17 DBus を観察する

dbus-daemon が重くなるんです。 systemd ほどではありませんが。 DBus が重いってことで。何をやってるのかが見たいですね。 QDBusViewer を使ってみましょう。

家庭内サーバでどうやって QDBusViewer を起動するかは別の記事にするとして、 これで見たところ、 systemd1 をクリックした瞬間に固まりました。 そして何分か経った後にエラーが表示されました。 おそらく systemd が反応しなくて timeout した、ってところでしょう。

nss は速くなりましたが、やはり systemd が重いです。 systemd に働きかけて調査しようとすると、失敗します。

ここで、最近の変更って何かなー、って考えて、ClamAV に思い当たりました。 ClamAV 全部止めてみます。

10/24 やっぱり重い

メインのノート PC は頻繁に再起動するので比較できませんが、 日記を置いている VPS サーバの systemd はほとんど CPU を 食っていないので、「そういうもの (重いのが普通)」ということは なさそうです。

cups.service も止めてみました。 cups.service と cups.socket を disable/stop してから、 ちょっと反応が軽くなった気もしますが、気のせいかもしれません。

11/2 再インストール

全然解決しないので、OS を再インストールすることにしました。

インストール中は、こんな姿になります。普段、ケーブルは2本くらいなんですけどね。

ざっくりインストールしてみましたが、設定を終える前に、 systemd の CPU 時間がすぐ 16s になりました。 ノート PC や VPS サーバはまだ 1s 程度なので、 比較すると、まだ CPU をあまり食ってはいないものの、 既に少しずつ食っているようです。

再インストールで解決してしまうと、それ以上調査はできなかったのですが、 もう少し調査ができそうです。

11/4 何度か再インストール

使ってる CPU 時間に注意しつつ、何度か再インストールしてみました。

  • base linux linux-firmware をインストール
  • base-devel man-db man-pages をインストール
  • vim をインストール
  • /etc/hostname を設定
  • systemd-networkd, systemd-resolved を設定
  • ruby をインストール

これだけで CPU 時間が食われます。

ruby をインストールする前は全然大丈夫そうだったのに、 ruby をインストールした途端、ちょっと CPU を食うようになったように見えました。

11/5 検索で見つける

昨日の手順から ruby のインストールや systemd-networkd, systemd-resolved の設定を 省略しても CPU 時間が食われます。

これはいったい…？ インストールしただけで、何もしてない、といっても過言じゃないくらいです。 もうハードウェアしかないです。

CPU が Celeron のせい？ そんなことあり？

という方向でググったところ、こんな記事に出会いました。

https://bbs.archlinux.org/viewtopic.php?id=278426

なんと…… 定期的に重くなり、 boot 後、少しの間は大丈夫だけど、 そのうちどんどん重くなっていく。 重いのは systemd と dbus。 症状が全く同じです。 やっと見つけました。

SD カードデバイス (or ドライバ) に問題があり、 SD カードを挿したら治った、という情報があります。

私の Mini PC にも SD カードスロットが?? と思ったら、ありました。 気づいてなかった。

TF と書いてあるスロットがそれらしいです。

lsusb コマンドの結果に以下の行がありました。

Bus 001 Device 002: ID 0bda:0153 Realtek Semiconductor Corp. 3-in-1 (SD/SDHC/SDXC) Card Reader

上の記事の人と全く同じデバイスですね。デバイス ID (0bda:0153) が同じです。

https://github.com/systemd/systemd/issues/25021

↑こちらも見つけました。この reporter の場合は、media change イベントが頻繁に発行されていた、 とのことです。

該当デバイスだけ電源を切れるといいのでしょうが、 それはさすがに無理っぽいので、別の方法を考えます。 そうですね、ドライバを外してみましょうか。

ドライバはいっぱいあります。lsmod | wc -l すると、140個以上の kernel module が読み込まれています。この中から該当のドライバを 探す必要があります。

/sys/bus/usb/ 以下と、上に挙げた lsusb の 結果を照らし合わせて、「きっとこれ!」というものを 1つピックアップ しました。ums_realtek です。かなり直感が含まれてるので、 ピックアップ手順は省略します。

mike2:~ % cat /etc/modprobe.d/ums_realtek.conf 
blacklist ums_realtek
mike2:~ %

このように設定すると、kernel module の ums-realtek.ko が 自動的に読み込まれることはなくなります。

こんな感じで reboot してみました。

11/6 解決策と認定

10時間以上放置してましたが、CPU を 0.2s 程度しか食ってません！

これが解決策になりそうです。

まとめ

今回の問題は、起動直後は問題なく、徐々に重くなっていく、という症状のため、 解決までにすごく時間がかかりました。

調査のためには、症状が起きている状態にする必要があり、 糸口がない状態では、待つしかありません。 また、待ちすぎると、今度は sudo や ls にすら時間がかかり、思うように調査が進みません。 nss 設定による解決策を思いついて、その点は改善されました。

そして再インストールしたわけですが、 再インストール後も引き続き症状は発生しており、 調査することができました。

これまでもググってはいました。 「systemd が重い」という症状はたくさん見つかりましたが、 どれも「これだ!!」と思えるものではありませんでした。 最後に見つけた archlinux の issue は私の症状とほぼ同じで、 これを見つけられたのは幸運でした。