treedown’s Report

システム管理者に巻き起こる様々な事象を読者の貴方へ報告するブログです。会社でも家庭でも"システム"に携わるすべての方の共感を目指しています。

※https化しました。その影響でしばらくリンク切れなどがあるかもしれませんが徐々に修正していきます。 リンク切れなどのお気づきの点がございましたらコメントなどでご指摘いただけますと助かります。

aptでエラーが発生したので対処

ntpを含めてシステムの時刻合わせというのはなかなか重要です。
cron-aptが発行したエラーとその対処についてのご報告です。そのRaspberry Piは10(buster)にdist-upgradeしていました。

対象はRaspberry Pi

以前に<Raspberry Piで問題発生? - treedown’s Report>や<障害の影響でRaspberry Piの時計設定 - treedown’s Report>にて障害が発生したRaspberry Pi。
当然OSはRaspbianですが、OSは"9 (stretch) "だったのを、せっかくコンソールを触れる状況にあったので"10 (buster)"にアップグレードして返送し、再度設置することにしました。

設置自体はさほど問題も無く正常起動、利用していたサービスも問題なく起動してクライアントから参照できることが確認出来ました。しかしその翌日。

発生したエラー

CRON-APTからエラーメールが発行されました。

--------------------------------------------------------------
CRON-APT error on %hostname.hoge% [/etc/cron-apt/config]
--------------------------------------------------------------
CRON-APT RUN [/etc/cron-apt/config]: Sun Jan 31 04:00:01 JST 2021 CRON-APT SLEEP: 657, Sun Jan 31 04:10:58 JST 2021 CRON-APT ACTION: 0-update CRON-APT LINE: /usr/bin/aptitude -o quiet=1 update -o quiet=2
E: Release file for http://packages.microsoft.com/repos/code/dists/stable/InRelease is not valid yet (invalid for another 2d 7h 52min 6s). Updates for this repository will not be applied.
E: Release file for http://raspbian.raspberrypi.org/raspbian/dists/buster/InRelease is not valid yet (invalid for another 2d 10h 5min 5s). Updates for this repository will not be applied.
E: Failed to download some files
W: Failed to fetch http://raspbian.raspberrypi.org/raspbian/dists/buster/InRelease: Release file for http://raspbian.raspberrypi.org/raspbian/dists/buster/InRelease is not valid yet (invalid for another 2d 10h 5min 5s). Updates for this repository will not be applied.
W: Failed to fetch http://packages.microsoft.com/repos/code/dists/stable/InRelease: Release file for http://packages.microsoft.com/repos/code/dists/stable/InRelease is not valid yet (invalid for another 2d 7h 52min 6s). Updates for this repository will not be applied.
E: Some index files failed to download. They have been ignored, or old ones used instead.
--------------------------------------------------------------

各行で「Updates for this repository will not be applied.」=「このリポジトリの更新は適用されません。」という表記、加えて「E: Failed to download some files」=「E:一部のファイルのダウンロードに失敗しました」という表記、最終的に「E: Some index files failed to download. They have been ignored, or old ones used instead.」=「E:一部のインデックスファイルのダウンロードに失敗しました。それらは無視されているか、代わりに古いものが使用されています。」というエラーで締められています。

aptで更新するはずだったリポジトリの更新がなんらかの要因でできないような状況になっている、と考えられます。

確認

実際にコマンド「sudo apt update」を実行してみます。

f:id:treedown:20210208122623p:plain
同様のエラーが確認出来ました。
ん?

対処方法

探してみると、<Ubuntu 18.04 sudo apt-get updateコマンド が Failed to fetchエラーになった時の解決法 - Qiita>にあるようなパッケージリストの問題、という可能性も考えて実施しようと思ったのですが、他にも「時計がずれている場合にこのエラーが発生する」という情報もあり、確認してみることにしました。
それは、前回<障害の影響でRaspberry Piの時計設定 - treedown’s Report>にて時計の問題もあったことですし。
でも、このとき調べた感じだと、「Raspberry Piは"fake-hwclock"とntp(かtimesyncd)で時刻を保持する"という仕組みじゃなかったっけ?

それでも現在時刻を確認してみると、

f:id:treedown:20210208122733p:plain

現在の時刻はズレてしまっているようです。よく見たらCRON-APT errorで記録されているエラーログの日時もおかしいような気がする。
確かに時刻合わせしたんですが…。

もしかして?

時計が三日分ズレていることから障害の対処完了後にシャットダウンして発送⇒後日現地で設置し電源ON、のこのRaspberry Piがシャットダウンしていた時間帯がちょうど三日のような感じがしました。
と、いうことは、現地にRaspberry Piが到着して電源ONされオンライン状態になってから/etc/fake-hwclock.dataが参照されて現在時刻をRaspberry Piが取得したものの、そこからntp(やtimesyncd)で時刻を合わせる機能が動作していないようだ、という仮説が成り立ちそうです。

とりあえず、現在の時刻をdateコマンドで設定し、仮の復旧を。
--------------------------------------------------------------
$ sudo date --set="2021-02-03 13:30:30"
2021年 2月 3日 水曜日 13:30:30 JST
--------------------------------------------------------------

しばらく待ってfake-hwclock.dataを確認してみると、
--------------------------------------------------------------
$ cat /etc/fake-hwclock.data
2021-02-03 05:17:01
--------------------------------------------------------------
無事更新されました。(UTC表記なのでJSTと相違していても+9:00差があれば大丈夫)

aptの実行でエラーが出ることもなく解消しました。
--------------------------------------------------------------
$ sudo apt update
取得:1 http://packages.microsoft.com/repos/code stable InRelease [10.4 kB]
ヒット:2 http://archive.raspberrypi.org/debian buster InRelease
取得:3 http://raspbian.raspberrypi.org/raspbian buster InRelease [15.0 kB]
取得:4 http://packages.microsoft.com/repos/code stable/main arm64 Packages [11.4 kB]
取得:5 http://packages.microsoft.com/repos/code stable/main amd64 Packages [11.1 kB]
取得:6 http://packages.microsoft.com/repos/code stable/main armhf Packages [11.4 kB]
取得:7 http://raspbian.raspberrypi.org/raspbian buster/main armhf Packages [13.0 MB]
13.1 MB を 59秒 で取得しました (221 kB/s)
パッケージリストを読み込んでいます... 完了
依存関係ツリーを作成しています
状態情報を読み取っています... 完了
アップグレードできるパッケージが 2 個あります。表示するには 'apt list --upgradable' を実行してください。
$ sudo apt list --upgradable
一覧表示... 完了
ca-certificates/stable 20200601~deb10u2 all [20200601~deb10u1 からアップグレード可]
tzdata/stable 2021a-0+deb10u1 all [2020e-0+deb10u1 からアップグレード可]
$ sudo apt upgrade
パッケージリストを読み込んでいます... 完了
   ※以下略、実行は正常に完了しました。
--------------------------------------------------------------

よかったよかった。これで終わり…、ではない。

NTP機能の有効化を

手動で時刻合わせを実施してエラーも出なくなったことで、やれやれ、と一息ついたところで、また電源断で同じようなことが起きたら、時刻がズレてしまい問題が再現してしまうのでは?と思いました。

よくよく見てみると、前回<障害の影響でRaspberry Piの時計設定 - treedown’s Report>の「timedatectl status」の実行結果では、「Network time on: yes」と「NTP synchronized: yes」と言う具合に時刻合わせが有効化されていたのですが、改めて「timedatectl status」を実行すると、
--------------------------------------------------------------
$ timedatectl status
Local time: 水 2021-02-03 15:29:43 JST
Universal time: 水 2021-02-03 06:29:43 UTC
RTC time: n/a
Time zone: Asia/Tokyo (JST, +0900)
System clock synchronized: no
NTP service: inactive
RTC in local TZ: no
--------------------------------------------------------------
「NTP service: inactive」と表示されています。うーん、"10 (buster)"にdist-upgradeした際に動作しなくなった?

systemd-timesyncdとntpdは択一式なので、ntpdが動作しているとsystemd-timesyncdは正常に動作しない、systemd-timesyncdで時刻合わせしているとしたらntpdはアンインストールされているか無効化されているはず。で、確認してみれば、
--------------------------------------------------------------
$ sudo systemctl status systemd-timesyncd.service
※中略
Active: inactive (dead)
Condition: start condition failed at Wed 2021-02-03 15:52:49 JST; 46s ago
※以下略
--------------------------------------------------------------
「Active: inactive (dead)」と記載に続いて、「condition failed」とあるため、このRaspberry Piはntpdに依って時刻合わせをしているということが分ります。
ちなみに、正常に動作しているRaspberry Pi(デフォルトで使用している)で同じコマンドを実行してみると…
--------------------------------------------------------------
$ sudo systemctl status systemd-timesyncd.service
※中略
Active: active (running) since Fri 2020-12-04 18:56:19 JST; 2 months 0 days ago
Docs: man:systemd-timesyncd.service(8)
Main PID: 11000 (systemd-timesyn)
Status: "Synchronized to time server for the first time …
※以下略
--------------------------------------------------------------
このように「Active: active (running)」に続いて日付情報や同期先のサーバ情報などが表示されます。

そうなれば、この正常動作していない方のRaspberry PiにおけるNTPの動作を確認する必要が出てくるな、とntpqコマンドを実行すると、
--------------------------------------------------------------
$ ntpq -p
No association ID's returned
--------------------------------------------------------------
プロセスをリスタートしても上記の動作は変わらないため、どうもNTPが正常動作していないよう。
/etc/ntp.confを確認してみれば、

f:id:treedown:20210208123351p:plain
入力ミスがあった模様。上記のように修正し、プロセスをリスタート。(以下)

--------------------------------------------------------------
$ sudo vi /etc/ntp.conf
$ sudo systemctl restart ntp
$ ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
ntp-b3.nict.go. .NICT. 1 u 2 64 1 13.482 2232.90 3.583
ntp1.jst.mfeed. 133.243.236.17 2 u - 64 1 6.705 2237.18 0.001
--------------------------------------------------------------

ntpq -pの実行結果、「No association ID's returned」の表示は設定したNTPサーバのリストに変わっていました。
しばらく待つと、

--------------------------------------------------------------
$ ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*ntp-b3.nict.go. .NICT. 1 u 22 64 17 5.478 -0.038 3.312
ntp1.jst.mfeed. 133.243.236.17 2 u 57 64 17 5.496 0.440 1.340
--------------------------------------------------------------

同期を示す「*」アスタリスクがサーバの先頭に付与されたので、無事ntpで時刻同期が動作し始めたことが確認できました。

なんとか復旧。

このあと、「timedatectl status」コマンドを実行すると

--------------------------------------------------------------
$ timedatectl status
Local time: 水 2021-02-03 16:21:53 JST
Universal time: 水 2021-02-03 07:21:53 UTC
RTC time: n/a
Time zone: Asia/Tokyo (JST, +0900)
System clock synchronized: yes
NTP service: inactive
RTC in local TZ: no
--------------------------------------------------------------

「NTP service: inactive」の表記は変わっていないのですが、「System clock synchronized: yes」となっています。
しかし「NTP service: inactive」の表示の更新には時間が掛かるため、しばらくこれで経過観察。予定では「NTP service: active」になる予定。

ひとまずこれで対処を完了します。