シングルボードコンピュータのOrangePi OneをARMBIANで運用していますが、パッケージ更新後再起動したらSSH接続できなくなりました。
後述しますが、原因はsystemdの229-4ubuntu21.15にあると思われるため、armhfアーキで同様の環境の方は無暗にUpgradeするのは危険かもしれません。
(2018/1/16追記: 原因はsystemdの229-4ubuntu21.15と古めのLinux Kernelの組み合わせにあるようです。229-4ubuntu21.15への更新前にカーネル更新をしておけば本問題は発生しないと考えられます。)
以下、参考までに発生事象と調査内容、対応方法を記載します。
発生事象
ARMBIANが稼働中のOrangePi Oneをapt update && apt upgrade後にrebootしたところ、SSH接続できなくなりました。
$ ssh username@orangepione
ssh: connect to host orangepione port 22: Connection refused
経緯
私の環境では概ね1か月ごとにapt update及びupgradeを実行しています。
今回apt upgradeを実行したところ、以下のパッケージ群がUpgrade対象となっていました。
$ sudo apt upgrade Reading package lists... Done Building dependency tree Reading state information... Done Calculating upgrade... Done The following NEW packages will be installed: ubuntu-advantage-tools The following packages will be upgraded: ca-certificates chromium-browser chromium-codecs-ffmpeg-extra cpp-5 g++-5 gcc-5 gcc-5-base gfortran-5 git git-core git-man initramfs-tools initramfs-tools-bin initramfs-tools-core iproute2 kmod libasan2 libatomic1 libcc1-0 libcups2 libgcc-5-dev libgfortran-5-dev libgfortran3 libgomp1 libgraphicsmagick-q16-3 libgraphicsmagick1-dev libkmod2 libldap-2.4-2 libnm0 libnss-myhostname libnss3 libnss3-nssdb libpam-systemd libperl5.22 libpython2.7 libpython2.7-minimal libpython2.7-stdlib libpython3.5 libpython3.5-minimal libpython3.5-stdlib libsasl2-2 libsasl2-modules-db libssh-gcrypt-4 libssl-dev libssl1.0.0 libstdc++-5-dev libstdc++6 libsystemd0 libubsan0 libudev1 libwavpack1 libwbclient0 linux-firmware linux-libc-dev network-manager openssh-client openssh-server openssh-sftp-server openssl perl perl-base perl-modules-5.22 python-samba python-software-properties python2.7 python2.7-minimal python3-software-properties python3.5 python3.5-minimal samba samba-common samba-common-bin samba-libs software-properties-common swftools systemd systemd-sysv tzdata ubuntu-minimal udev 80 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. Need to get 164 MB of archives. After this operation, 1,893 kB of additional disk space will be used.
この後、コンソール上には普段同様にUpgrade過程が表示されますが、systemdの設定中に以下のように大量にBad file descriptorという出力が含まれていました。
Setting up systemd (229-4ubuntu21.15) ... addgroup: The group `systemd-journal' already exists as a system group. Exiting. [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring. Failed to validate path /var: Bad file descriptor Failed to validate path /var/log: Bad file descriptor Failed to validate path /var/lib: Bad file descriptor Failed to validate path /run/sendsigs.omit.d: Bad file descriptor Failed to validate path /home: Bad file descriptor Failed to validate path /srv: Bad file descriptor Failed to validate path /dev/net: Bad file descriptor Failed to validate path /run/lock/subsys: Bad file descriptor Failed to validate path /var/cache: Bad file descriptor Failed to validate path /var/cache/man: Bad file descriptor Failed to validate path /run/samba: Bad file descriptor Failed to validate path /var/run/screen: Bad file descriptor Failed to validate path /var/run/sshd: Bad file descriptor Failed to validate path /var/run/sudo: Bad file descriptor Failed to validate path /var/run/sudo/ts: Bad file descriptor Failed to validate path /run/user: Bad file descriptor Failed to validate path /run/systemd/ask-password: Bad file descriptor Failed to validate path /run/systemd/seats: Bad file descriptor Failed to validate path /run/systemd/sessions: Bad file descriptor Failed to validate path /run/systemd/users: Bad file descriptor Failed to validate path /run/systemd/machines: Bad file descriptor Failed to validate path /run/systemd/shutdown: Bad file descriptor Failed to validate path /run/systemd/netif: Bad file descriptor Failed to validate path /run/systemd/netif/links: Bad file descriptor Failed to validate path /run/systemd/netif/leases: Bad file descriptor Failed to validate path /run/log: Bad file descriptor Failed to validate path /var/lib/systemd: Bad file descriptor Failed to validate path /var/lib/systemd/coredump: Bad file descriptor Failed to validate path /tmp: Bad file descriptor Failed to validate path /var/log/wtmp: Bad file descriptor Failed to validate path /var/log/btmp: Bad file descriptor Failed to validate path /var/spool: Bad file descriptor Failed to validate path /tmp/.X11-unix: Bad file descriptor Failed to validate path /tmp/.ICE-unix: Bad file descriptor Failed to validate path /tmp/.XIM-unix: Bad file descriptor Failed to validate path /tmp/.font-unix: Bad file descriptor Failed to validate path /tmp/.Test-unix: Bad file descriptor Failed to validate path /run/log/journal: Bad file descriptor Failed to validate path /run/log/journal/bad4775cb70c41dc85c9b140e9434836: Bad file descriptor
上記Bad file descriptorが気になるものの、とりあえずupgradeは完了したので、rebootをかけたところリモートからSSH接続できない状態に陥りました。
SDカードが壊れたとか、H/Wが壊れたとかそういった可能性も考えましたが、OrangePi OneにはHDMIやUSBポートがあります。普段Server用途で運用しているので、これらのポートには何もつないでいなかったのですが、モニタとキーボードを接続してみたところローカルコンソールは生きておりログインできました。
とりあえずsshdが生きているか、psコマンドで確認したところ居ませんでした。
sshdを起動すべくsystemctl start sshを叩いてもエラーとなり、sshdは起動しません。
journalctl -xeでジャーナルを確認すると以下の出力が繰り返し記録されていました。
Jan 12 22:18:03 orangepione systemd[1]: Starting OpenBSD Secure Shell server... -- Subject: Unit ssh.service has begun start-up -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ssh.service has begun starting up. Jan 12 22:18:03 orangepione sshd[5417]: Missing privilege separation directory: /var/run/sshd Jan 12 22:18:03 orangepione systemd[1]: ssh.service: Control process exited, code=exited status=255 Jan 12 22:18:03 orangepione systemd[1]: Failed to start OpenBSD Secure Shell server. -- Subject: Unit ssh.service has failed -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ssh.service has failed. -- -- The result is failed. Jan 12 22:18:03 orangepione systemd[1]: ssh.service: Unit entered failed state. Jan 12 22:18:03 orangepione systemd[1]: ssh.service: Failed with result 'exit-code'. Jan 12 22:18:03 orangepione systemd[1]: ssh.service: Service hold-off time over, scheduling restart. Jan 12 22:18:03 orangepione systemd[1]: Stopped OpenBSD Secure Shell server. -- Subject: Unit ssh.service has finished shutting down -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ssh.service has finished shutting down.
そして、最終的に再試行回数上限に到達して起動失敗と記録されています。
Jan 12 22:18:06 orangepione systemd[1]: ssh.service: Unit entered failed state. Jan 12 22:18:06 orangepione systemd[1]: ssh.service: Failed with result 'start-limit-hit'.
ジャーナルによれば、/var/run/sshdが無いと言っているので、とりあえず手でディレクトリ作成後、sshd起動を再試行したところ、今度は起動しました。ジャーナルにも以下のように正常起動した旨の出力が記録されています。
Jan 12 22:25:09 orangepione systemd[1]: Starting OpenBSD Secure Shell server... -- Subject: Unit ssh.service has begun start-up -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ssh.service has begun starting up. Jan 12 22:25:09 orangepione sshd[5559]: Server listening on 0.0.0.0 port 22. Jan 12 22:25:09 orangepione sshd[5559]: Server listening on :: port 22. Jan 12 22:25:09 orangepione systemd[1]: Started OpenBSD Secure Shell server. -- Subject: Unit ssh.service has finished start-up -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ssh.service has finished starting up. -- -- The start-up result is done.
もちろん外部マシンからリモートでSSH接続できるようになったことも確認できました。
何故/var/run/sshdが無いのか不明ながらも、とりあえず復旧したのでrebootかけたところ、再びリモートからSSH接続できなくなりました。
ジャーナルの出力も先と同様で、/var/run/sshdディレクトリもありませんでした(ので、とりあえずまた手でディレクトリを作成しました)。
どうやら、/var/run/sshdが存在しない原因を根本的に調べる必要がありそうです。
ところで、systemctlで確認すると、以下の2つのサービスがfailedになっていることに気が付きました。
● systemd-tmpfiles-setup-dev.service loaded failed failed Create Static Device Nodes in /dev ● systemd-tmpfiles-setup.service loaded failed failed Create Volatile Files and Directories
改めてジャーナルを確認するとsystemd-tmpfiles-setupサービスが起動失敗した様子が記録されていました。
-- Unit systemd-tmpfiles-setup.service has begun starting up. Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/log: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/lib: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/sendsigs.omit.d: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /home: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /srv: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/lock/subsys: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/cache: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/cache/man: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/samba: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/run/screen: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/run/sshd: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/run/sudo: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/run/sudo/ts: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/nologin: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/user: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/utmp: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/ask-password: Bad file descripto Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/seats: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/sessions: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/users: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/machines: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/shutdown: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/netif: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/netif/links: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/systemd/netif/leases: Bad file descripto Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/log: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/lib/systemd: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/lib/systemd/coredump: Bad file descripto Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /tmp: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/log/wtmp: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/log/btmp: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /var/spool: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /tmp/.X11-unix: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /tmp/.ICE-unix: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /tmp/.XIM-unix: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /tmp/.font-unix: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /tmp/.Test-unix: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/log/journal: Bad file descriptor Jan 12 22:35:05 orangepione systemd-tmpfiles[495]: Failed to validate path /run/log/journal/bad4775cb70c41dc85c9b140e943 Jan 12 22:35:05 orangepione systemd[1]: systemd-tmpfiles-setup.service: Main process exited, code=exited, status=1/FAILU
この大量のBad file descriptorはapt upgrade時にコンソール出力されたものと酷似しています。
そもそもこのUnitが何をしているのか調べてみると、/bin/systemd-tmpfilesを実行しており、その設定ファイル群は/usr/lib/tmpfiles.dにあるようです。
この設定ファイル群を確認してみると、tmpfsを使用する揮発性の各種ディレクトリやファイル群が作成されるように記述されているようで、/var/run/sshdを作成する設定もありました。
各設定ファイルを、OS環境が非常に類似しつつも正常に稼働しているNanoPi Neoの同一ファイルと比較してみても差異はなく、設定ファイルの問題では無さそうです。
現状を整理すると、以下のような因果関係になっていることが判ります。
- リモートからSSH接続できない
さらに、前述の通りsystemd-tmpfilesの設定ファイル群には問題がない(と思われる)ことから、今回229-4ubuntu21.15へとUpgradeされたsystemdの障害である可能性が高いと考えられます。
systemdの更新内容
今回障害を起こしているとみられるsystemdのバージョンは、229-4ubuntu21.15のarmhfアーキテクチャ版です。
229-4ubuntu21.15の更新内容は以下URLから確認できます。
229-4ubuntu21.15 : systemd package : Ubuntu
これによれば、以下のようにsystemd-tmpfiles絡みの修正も入っており、これが原因でデグレードを起こしていると考えられます。
* SECURITY UPDATE: symlink mishandling in systemd-tmpfiles
- debian/patches/CVE-2018-6954.patch: don't resolve pathnames when traversing
recursively through directory trees
- debian/patches/CVE-2018-6954_2.patch: backport the remaining patches to
resolve this completely
- CVE-2018-6954
この変更はCVE-2018-6954に対するセキュリティアップデートとのことですので、Upgradeを適用するか否かは慎重な判断が必要です。
NVD - CVE-2018-6954
JVNDB-2018-002344 - JVN iPedia - 脆弱性対策情報データベース
ARMBIANフォーラムの情報
以下のトピックの末尾の方に、今回私の環境で発生している事象と同じと思われる事象が報告されています(本来は別原因の障害についてのトピックですが、SSH接続できないという事象は同じなので同一トピックに追記されたっぽい)。
forum.armbian.com
上記フォーラムのvfrolov氏の情報によれば229-4ubuntu21.11ならこの問題は発生しないそうです(私のUpgrade前の229-4ubuntu21.5も大丈夫です)。
というわけで、旧バージョンへのダウングレードを試みるも、
$ sudo apt install systemd=229-4ubuntu21.11 Reading package lists... Done Building dependency tree Reading state information... Done E: Version '229-4ubuntu21.11' for 'systemd' was not found
$ sudo apt install systemd=229-4ubuntu21.5 Reading package lists... Done Building dependency tree Reading state information... Done E: Version '229-4ubuntu21.5' for 'systemd' was not found
既に229-4ubuntu21.11も229-4ubuntu21.5もソースに無いようです。
$ apt-cache madison systemd systemd | 229-4ubuntu21.15 | http://ports.ubuntu.com xenial-security/main armhf Packages systemd | 229-4ubuntu21.15 | http://ports.ubuntu.com xenial-updates/main armhf Packages systemd | 229-4ubuntu4 | http://ports.ubuntu.com xenial/main armhf Packages
今回のデグレードを発生させている229-4ubuntu21.15か、だいぶ古い229-4ubuntu4しか無いようで。
暫定対応
systemdのsshd用ユニットファイルを書き換えて、sshdの起動前に/var/run/sshdを作成するようにします。
具体的には以下のようにExecStartPre=-/bin/mkdir -p /var/run/sshdを追記します。
$ cat /etc/systemd/system/sshd.service [Unit] Description=OpenBSD Secure Shell server After=network.target auditd.service ConditionPathExists=!/etc/ssh/sshd_not_to_be_run [Service] EnvironmentFile=-/etc/default/ssh ### Add as a temporary solution against systemd 229-4ubuntu21.15 ExecStartPre=-/bin/mkdir -p /var/run/sshd ### ExecStartPre=/usr/sbin/sshd -t ExecStart=/usr/sbin/sshd -D $SSHD_OPTS ExecReload=/usr/sbin/sshd -t ExecReload=/bin/kill -HUP $MAINPID KillMode=process Restart=on-failure RestartPreventExitStatus=255 Type=notify [Install] WantedBy=multi-user.target Alias=sshd.service
これでsystemdを229-4ubuntu21.15にUpgradeしてしまった場合でも、rebootかけてもsshdが起動するようになります。
ただし根本的にはsystemd-tmpfiles-setup-dev.service、systemd-tmpfiles-setup.serviceはfailedのままなので、/var/run/sshd以外のsystemd-tmpfilesによってディレクトリやファイルが作成されることを前提としているソフトウェアの動作には影響が残りますので(そのようなソフトウェアを利用していれば)個別対応が必要です。
補足
今回問題が発生しているOrangePi OneのOSバージョンは、ARMBIAN 5.60 stable Ubuntu 16.04.5 LTS 3.4.113-sun8i です(追記: ARMBIAN 5.70 stable Ubuntu 16.04.5 LTS 3.4.113-sun8iへ更新されましたがこのバージョンでも同様です)。
なお、NanoPi Neo(ARMBIAN 5.60 stable Ubuntu 16.04.5 LTS 4.14.84-sunxi)ではsystemdを229-4ubuntu21.15へUpgradeしても正常稼働しています。
両機ともarmhfアーキのAllWinner H3搭載という点でH/Wの類似性は比較的高いのですが、OrangePi Oneのみで発生していることから、32bit ARM搭載機で広く発生する問題ではなく、問題発現には何らかの条件があると考えられます。
なお、普通のamd64なPCサーバには影響はないと思われます。
amd64向けの最新のsystemdは237-3ubuntu10.11ですが、これにUpgradeしたUbuntu 18.04.1 LTS (GNU/Linux 4.15.0-43-generic x86_64)環境では特に問題は発生していません。
(2018/1/16追記ここから)
恒久対応
前述の通り私の手元ではOrangePi Oneではこの問題が発生するものの、NanoPi Neoでは発生しませんでした。
OrangePi OneのLinux Kernelが3.4.113-sun8iであるのに対し、NanoPi Neoの方が4.14.84-sunxiと新しいことが本障害発生有無の違いではないかと考え、OrangePi Oneのカーネルを更新してみました。
更新後のOrangePi OneのLinux Kernelは4.19.13-sunxiになり、229-4ubuntu21.15のsystemdでも問題なくsystemd-tmpfiles-setup-dev.service及びsystemd-tmpfiles-setup.serviceが正常に実行されるようになったことを確認しました。/var/run/sshdも従来通り生成されるためsshdも正常起動します。暫定対応としてユニットファイルに追記したディレクトリ作成のExecStartPreも不要になります(残したままでも実害はありませんが)。
カーネル更新前
$ uname -a Linux orangepione 3.4.113-sun8i #2 SMP PREEMPT Sat Jan 12 15:54:26 CET 2019 armv7l armv7l armv7l GNU/Linux
カーネル更新後
$ uname -a Linux orangepione 4.19.13-sunxi #5.70 SMP Sat Jan 12 15:43:21 CET 2019 armv7l armv7l armv7l GNU/Linux
以上。
