2,3年前に構築してしばらく放置していた CentOS7.4-1708 のサーバでDiskが100% になる事象がありました。
監視にmuninを使用しておりアラートがslackに飛んでいたのですが、そのチャンネルをたまにしかみてなかった(意味ない。。。)ので気づくのが遅れました。
以下、muninのディスク使用量グラフです。幸いサービスには影響なかったのですが1ヶ月近く100%でしたorz
事象
あるサーバ群からディスク溢れになった当該サーバへ向け、毎分sshでファイルを読み込むバッチを実行していました。
アラートに気づきsshで当該サーバへログインし(できました)たところ /var/run/systemd/sessions ディレクトリ配下に大量のファイルが作成されていました。
# ls -l
...
-rw-r--r-- 1 root root 273 11 17 12:39 2152524
-rw-r--r-- 1 root root 273 11 17 12:39 2152525
-rw-r--r-- 1 root root 273 11 17 12:39 2152526
-rw-r--r-- 1 root root 273 11 17 12:39 2152527
-rw-r--r-- 1 root root 273 11 17 12:40 2152528
-rw-r--r-- 1 root root 273 11 17 12:40 2152529
-rw-r--r-- 1 root root 257 11 17 12:40 2152530
-rw-r--r-- 1 root root 273 11 17 12:40 2152531
-rw-r--r-- 1 root root 273 11 17 12:40 2152532
...
中身を確認すると以下のようにsshのセッション情報らしきものが記載されていました。
# cat 2261263
# This is private data. Do not parse.
UID=1000
USER=hoge
ACTIVE=1
STATE=closing
REMOTE=1
STOPPING=1
TYPE=tty
CLASS=user
SCOPE=session-2261263.scope
REMOTE_HOST=11.22.33.44
SERVICE=sshd
POS=0
LEADER=25390
AUDIT=2261263
REALTIME=1607773080477008
MONOTONIC=91089158095196
#
このファイルはどうやらssh接続時にrefというパイプファイルともに作成され、接続中は STATE=active となり切断後に、refファイルが削除され STATE=closing となっているようでした。
# ls -l 2152536*
-rw-r--r-- 1 root root 305 11 17 12:41 2152536
prw------- 1 root root 0 11 17 12:41 2152536.ref
#
# cat 2152536
# This is private data. Do not parse.
UID=0
USER=root
ACTIVE=1
STATE=active ・・・接続中はactive
REMOTE=1
STOPPING=0
TYPE=tty
CLASS=user
SCOPE=session-2152536.scope
FIFO=/run/systemd/sessions/2152536.ref
REMOTE_HOST=11.22.33.44
SERVICE=sshd
POS=0
LEADER=18047
AUDIT=2152536
REALTIME=1605584477392233
MONOTONIC=88900555010420
#
原因
おそらくCentOSのバグと思われます。
こちらのバグトラッカーによると、systemdのパッケージ更新によるdbus接続の切断が影響と情報がありました。
ただ自分のケースはログと記憶を辿ると容量が上がり始めた9月初めに、たまたまこの記事の再確認のため当該サーバで
$ sudo yum install bzip2-devel openssl-devel readline-devel sqlite-devel patch gcc
を実施しており、そのときインストール、アップデートされたパッケージにはsystemd自体は入っていませんでした。(正確にはsystemd-219-42.el7_4.4.x86_64 のまま。そもそもこのVersionに問題があった?)
ちなみに以下が(依存関係含め)そのときインストール、アップデートされたパッケージでした。
# cat /var/log/yum.log
...
Sep 04 00:11:02 Updated: libgcc-4.8.5-39.el7.x86_64
Sep 04 00:11:03 Updated: glibc-2.17-307.el7.1.x86_64
Sep 04 00:11:10 Updated: glibc-common-2.17-307.el7.1.x86_64
Sep 04 00:11:10 Installed: mpfr-3.1.1-4.el7.x86_64
Sep 04 00:11:10 Installed: libmpc-1.0.1-3.el7.x86_64
Sep 04 00:11:11 Installed: cpp-4.8.5-39.el7.x86_64
Sep 04 00:11:11 Updated: libgomp-4.8.5-39.el7.x86_64
Sep 04 00:11:18 Installed: kernel-headers-3.10.0-1127.19.1.el7.x86_64
Sep 04 00:11:19 Installed: glibc-headers-2.17-307.el7.1.x86_64
Sep 04 00:11:19 Installed: glibc-devel-2.17-307.el7.1.x86_64
Sep 04 00:11:21 Installed: gcc-4.8.5-39.el7.x86_64
Sep 04 00:16:20 Updated: libcom_err-1.42.9-17.el7.x86_64
Sep 04 00:16:22 Updated: libsepol-2.5-10.el7.x86_64
Sep 04 00:16:22 Updated: libselinux-2.5-15.el7.x86_64
Sep 04 00:16:22 Updated: zlib-1.2.7-18.el7.x86_64
Sep 04 00:16:22 Updated: 1:openssl-libs-1.0.2k-19.el7.x86_64
Sep 04 00:16:22 Updated: krb5-libs-1.15.1-46.el7.x86_64
Sep 04 00:16:22 Updated: readline-6.2-11.el7.x86_64
Sep 04 00:16:22 Updated: sqlite-3.7.17-8.el7_7.1.x86_64
Sep 04 00:16:23 Installed: libkadm5-1.15.1-46.el7.x86_64
Sep 04 00:16:23 Installed: zlib-devel-1.2.7-18.el7.x86_64
Sep 04 00:16:23 Installed: libsepol-devel-2.5-10.el7.x86_64
Sep 04 00:16:23 Updated: e2fsprogs-libs-1.42.9-17.el7.x86_64
Sep 04 00:16:23 Installed: libcom_err-devel-1.42.9-17.el7.x86_64
Sep 04 00:16:23 Updated: libss-1.42.9-17.el7.x86_64
Sep 04 00:16:24 Installed: ncurses-devel-5.9-14.20130511.el7_4.x86_64
Sep 04 00:16:24 Installed: libverto-devel-0.2.5-4.el7.x86_64
Sep 04 00:16:24 Installed: pcre-devel-8.32-17.el7.x86_64
Sep 04 00:16:24 Installed: libselinux-devel-2.5-15.el7.x86_64
Sep 04 00:16:25 Installed: keyutils-libs-devel-1.5.8-3.el7.x86_64
Sep 04 00:16:25 Installed: krb5-devel-1.15.1-46.el7.x86_64
Sep 04 00:16:26 Installed: 1:openssl-devel-1.0.2k-19.el7.x86_64
Sep 04 00:16:26 Installed: readline-devel-6.2-11.el7.x86_64
Sep 04 00:16:26 Updated: e2fsprogs-1.42.9-17.el7.x86_64
Sep 04 00:16:26 Installed: sqlite-devel-3.7.17-8.el7_7.1.x86_64
Sep 04 00:16:27 Updated: 1:openssl-1.0.2k-19.el7.x86_64
Sep 04 00:16:27 Updated: libselinux-utils-2.5-15.el7.x86_64
Sep 04 00:16:27 Updated: libselinux-python-2.5-15.el7.x86_64
Sep 04 00:16:27 Installed: bzip2-devel-1.0.6-13.el7.x86_64
...
#
対応
cronで削除
サーバの用途上すぐに再起動できなかったため、3日以上アクセスがなく STATE=closing となっているファイルを削除するcronを暫定的に設定しました。
5 11 * * * root find /var/run/systemd/sessions -type f -mtime +2 -regextype posix-egrep -regex "/var/run/systemd/sessions/[0-9]+[0-9]$" | xargs -i grep -l "STATE=closing" {} | xargs -i rm -f {}
またsystemdによるログ出力が停止していたため、journaldを再起動しました。(rsyslogの再起動だけじゃだめだった。というか不要だったかもしれない)
# systemctl restart rsyslog
# systemctl restart systemd-journald
OS再起動
恒久的な対応としてはバグトラッカーに再起動すれば良いと記載されていたので、バグ再現した検証サーバでOS再起動を行ったところ解消しました。
ssh接続→切断後、正常に /var/run/systemd/sessions のファイルが消えていました。
参考
(*ゝω・)ノ ァリガトネー
Cleanup /var/run full of systemd session
CentOS Bug Tracker
rsyslogとjournaldのこと