id:MysticDoll です。
2024/02/11 に起きた自宅kubernetesクラスタのサービスが正常に利用出来なかった障害についての報告致します。
と思っていたんですが、長期間ほったらかしていてログを紛失したので雑なまとめです。
障害内容
一部podへのアクセスが失敗、またpodからの通信も一部失敗していた。
一時対応
調査の結果、失敗するpodは特定のnodeに乗っているものだと分かったので、そのnodeをcordonし、正常なcontrol-planeとnodeのみを残して再度スケジューリングしなおしてほぼ解決。
podからの通信失敗については kubectl exec 等で確認したところ名前解決に失敗していたため、node本体に入り、systemd-resolved systemd-networkdなどを再起動してgot事無き。
実際にはステークホルダーが自分しかいないので雑にnodeを再起動したりついでにArch Linuxのシステム更新をしたりとハチャメチャなことをしました。仕事では絶対こんなことしません。
node障害
一時対応の最中、再起動した bengal と名付けたnodeに疎通しなくなる事象が発生しました。
これは自宅kubernetesのクラスタ達は(配線が面倒だったのとL2スイッチを持っていなかったので)無線で自宅ネットワークに接続しており、どうやら bengal で iwd.service の起動に失敗していたことに起因するようです。
iwd 起動失敗の原因
結論から言うと iwd 自体の問題などではなくdbusのソケットをiwd (正確には iwdが依存している ell.so の内部関数) から見つけられていなかったことが原因でした。
さすがにシステム更新してもdbus周りの挙動が破壊される経験がなく、ドライバを入れ直したり古いバージョンへ各種パッケージをロールバックしたりなどしましたが全く無意味でした。
$ journalctl -xeu iwd.service などしてログを確認したところ以下のように出ていたので、普通にdbusを疑うべきだったのはそうかもしれない。
Feb 11 19:00:49 bengal iwd[330]: Wireless daemon version 2.13
Feb 11 19:00:49 bengal iwd[330]: Loaded configuration from /etc/iwd/main.conf
Feb 11 19:00:49 bengal iwd[330]: Failed to initialize D-Bus
Feb 11 19:00:49 bengal systemd[1]: iwd.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 19:00:49 bengal systemd[1]: iwd.service: Failed with result 'exit-code'.
Feb 11 19:00:49 bengal systemd[1]: Failed to start Wireless service.
iwd 起動失敗の調査
とはいえ、適当にロールバックとかしてダメだった場合ちゃんと調査する必要があって、dbusを疑うにしても /run/dbus/system_bus_socket 自体は存在していたことや、dbusのパッケージバージョンを変えたりしてもダメだったので、コードを見に行くことにしました。
kernel.googlesource.com
Failed to initialize D-Bus というエラーを出している部分はここしかないので、ここを見に行くと l_dbus_new_default という関数の呼び出しで失敗していそうなことが分かります。
dbus = l_dbus_new_default(L_DBUS_SYSTEM_BUS);
if (!dbus) {
l_error("Failed to initialize D-Bus");
goto failed_dbus;
}
で、 l_dbus_new_default という関数は以下にありました。どうしてここに辿りついたのかは完全に忘れたのですが、たぶん l_dbus_new_default だけで検索したらこの ell のヘッダファイルのコードがヒットしたので、そこから辿ったのだと思います。
kernel.googlesource.com
蛇足ですが、筋の良い探し方としては、本体のソースにないということは共有ライブラリのコードという推測が立つので、 ldd をかけてそれらしいライブラリ名と共に探すのが良いかと思います。
[mysticdoll@bengal ~]$ ldd /lib/iwd/iwd
linux-vdso.so.1 (0x00007ffda8d2d000)
libell.so.0 => /usr/lib/libell.so.0 (0x000070f9a56b6000)
libgcc_s.so.1 => /usr/lib/libgcc_s.so.1 (0x000070f9a5691000)
libc.so.6 => /usr/lib/libc.so.6 (0x000070f9a54af000)
/lib64/ld-linux-x86-64.so.2 => /usr/lib64/ld-linux-x86-64.so.2 (0x000070f9a5837000)
さておき、コードを見ると dbus = l_dbus_new_default(L_DBUS_SYSTEM_BUS); とあるので case L_DBUS_SYSTEM_BUS: の処理を見れば良さそうです。
case L_DBUS_SYSTEM_BUS:
address = getenv("DBUS_SYSTEM_BUS_ADDRESS");
if (!address)
address = DEFAULT_SYSTEM_BUS_ADDRESS;
break;
システムかユーザーセッションかどうかで参照すべきdbusソケットのアドレスを切り替える実装のようで、ここでiwdのunitファイルを見てみると
[mysticdoll@bengal ~]$ sudo systemctl cat iwd.service
# /usr/lib/systemd/system/iwd.service
[Unit]
Description=Wireless service
Documentation=man:iwd(8) man:iwd.config(5) man:iwd.network(5) man:iwd.ap(5)
After=network-pre.target
Before=network.target
Wants=network.target
[Service]
Type=dbus
BusName=net.connman.iwd
ExecStart=/usr/lib/iwd/iwd
NotifyAccess=main
LimitNPROC=1
Restart=on-failure
CapabilityBoundingSet=CAP_NET_ADMIN CAP_NET_RAW CAP_NET_BIND_SERVICE
PrivateTmp=true
NoNewPrivileges=true
DevicePolicy=closed
DeviceAllow=/dev/rfkill rw
ProtectHome=yes
ProtectSystem=strict
unit内では環境変数 DBUS_SYSTEM_BUS_ADDRESS を指定していないので DEFAULT_SYSTEM_BUS_ADDRESS が採用されていそうと分かります。
kernel.googlesource.com
#define DEFAULT_SYSTEM_BUS_ADDRESS "unix:path=/var/run/dbus/system_bus_socket"
とあるので、いやさすがにあるじゃろ…と思ったんですが、 なんと /var/run が 普通のディレクトリとして生えてました。その上本来あるはずのdbusのソケットは当然ありません。
[mysticdoll@bengal ~]$ sudo ls -la /var/run
total 12
drwx------ 1 root root 78 Feb 13 08:41 .
drwxr-xr-x 1 root root 116 Feb 12 17:27 ..
(snip)
というわけで、以下のようにunitファイルから直接 /run 側のdbusソケットを参照してもらうように環境変数を設定して無事iwdは起動しました。
(snip)
[Service]
Type=dbus
BusName=net.connman.iwd
Environment=DBUS_SYSTEM_BUS_ADDRESS=unix:path=/run/dbus/system_bus_socket
(snip)
他にも docker-cri が動いてない(これもdocker.sockが/var/run にないから)とかの問題があったので一応良く使うところだけsymlinkを生やして応急対応して終了です。
後で /var/run は /run へのsymlinkに直しておきます、気が向いたら…nodeのuncordonもしてないのでそのうちします、そのうち…
