がとらぼ
INTAA.NET

fr24feedが正常に自動起動するようにする

この記事は、自宅に設置したアンテナとRTL-SDRレシーバで航空機の飛行状況を取得し、FlightRadar24にフィードして情報共有する話の続き。fr24feedはデータをフィードするソフトウエア。piawareはFlightAwareにフィードするソフトウエア。dump1090-faはRTL-SDRレシーバで受信したADS-Bの信号を文字にして出力するデコーダソフトウエア。

先日の設定で、fr24feedが一応正常に動いているようなのだが、システムを再起動するとfr24feedのFR24 MLATでフェイルが発生する。この状態だとFlightRadar24では「接続しているがオフライン」という扱いになるみたい。フィードが停止するようなのでそれは困る。

$ fr24feed-status
[ ok ] FR24 Feeder/Decoder Process: running.
[ ok ] FR24 Stats Timestamp: 2020-03-12 10:15:00.
[ ok ] FR24 Link: connected [UDP].
[ ok ] FR24 Radar: *-******.
[ ok ] FR24 Tracked AC: 0.
[ ok ] Receiver: connected (0 MSGS/ SYNC).
[FAIL] FR24 MLAT: not running ... failed!

要するに異常だが、これはfr24feedサービスを再起動すると正常になる。
つまりfr24feedの起動タイミングが悪いっぽい。

systemdによるサービスの起動順序とタイミングを調べてみる。

$ systemd-analyze plot > ~/systemd-analyze.svg
ホームディレクトリに出力されたsystemd-analyze.svgは一応画像形式だけど、ブラウザで見るのがおすすめ。

systemdのサービス起動順序 1
これによるとdump1090-faが起動してからfr24feedが立ち上がり、後にpiawareが起動している。fr24feedよりpiawareが先の方が良い筈なので順序指定をしてやれば良さそう 。しかし、仮にfr24feedをpiawareより後にしても、piaware起動開始とほぼ同タイミングだとまだ失敗する可能性がある。Linuxの普通の作法では、おそらくサービスはrc.localが実行される前に全て起動させるのだろうが、rc.localの中でdump1090exporterを起動する前に20秒ほどsleepする処理を入れているのでこれが待ち時間としては最適かもと思った。だから、fr24feedはrc.localの後に実行させることにした。これならpiawareの起動開始タイミングから20秒(と少し)後にfr24feedが起動する筈。

例によって fr24feed を停めて無効化してからサービスのファイルを編集して有効化させる。

$ sudo service fr24feed stop　　　←サービス停止
$ sudo systemctl disable fr24feed ←サービス無効化

/etc/systemd/system/fr24feed.service (ファイルの最初の辺りを編集) 
[Unit]
Description=Flightradar24 Decoder & Feeder
#After=network-online.target  ←元の設定をコメント化、または行削除
After=rc-local.service　  ←変更後(追加した)


$ sudo systemctl enable fr24feed ←サービス有効化
$ sudo shutdown -r now   ←システム再起動

systemdのサービス起動順序 2
システム起動後に再度サービスの起動順序とタイミングを確認する。
今度は指定通りに最後の方のrc-localサービスが完了した後にfr24feedが起動している。

2020年5月21日追記:
上の起動タイミングをズラしただけで暫く満足していたが、これでもまだfr24feedのFR24 MLATがエラーになることがあった。そこで、もっと起動を遅らせることに。
上で編集したのと同じ /etc/systemd/system/fr24feed.service に1行挿入。LimitCORE=infinityの次あたりに。
ExecStartPre=/bin/sleep 90
これでfr24feedの起動をさらに90秒遅らすことができる。これだけ遅ければシステム起動直後の高負荷は完全に避けられるし、flightawareも安定した状態になっているはず。これならきっとFR24 MLATもエラーにならないことでしょう。

$ fr24feed-status
[ ok ] FR24 Feeder/Decoder Process: running.
[ ok ] FR24 Stats Timestamp: 2020-03-12 11:01:27.
[ ok ] FR24 Link: connected [UDP].
[ ok ] FR24 Radar: *-******.
[ ok ] FR24 Tracked AC: 7.
[ ok ] Receiver: connected (16266 MSGS/0 SYNC).
[ ok ] FR24 MLAT: ok [UDP].
[ ok ] FR24 MLAT AC seen: 4.

ステータス表示も意図したとおりになった。(確認はfr24feed起動後1分は待ってから)

関連記事:

fr24feedのログ出力が訳がわからないので消した話

システム監視 1

FlightRadar24におそらく正常にフィードできるようになって翌朝、いつものようにシステムの稼働状況を確認していたら飲んでたお茶を吹き出しそうになった。

システム監視 2
上側のグラフがメモリの使用状況で、朝9:00に日替わり処理で何かしらが行われてキャッシュ・バッファが100MBほど減少した。このホストは元々はタイムゾーンを日本時間にしていたんだけど、昨日の記事のようにfr24feedが文句を言うのでGMT+0にした。だから、日本より9時間遅れの時刻を指して動いているので日替わり処理は朝の9時に行われる。
で、メモリの方は使用量が減っているのでそれで良いんだけど、下側のグラフがディスクの仕様状況で、水色が朝9:00にドカンと跳ね上がっている。 (前日の20:00頃にガクンと減っているのはログファイルが溜まっていたのを消したから。)
この水色はログを格納する/var/logのパーティション。グラフはそれぞれのパーティションの使用割合いなので例えば50%になったらディスク全容量の半分を喰ったということではなく、分割されたそれぞれの領域の中の半分を喰ったということ。

$ df -BM
Filesystem     1M-blocks  Used Available Use% Mounted on
udev                172M    0M      172M   0% /dev
tmpfs                48M    6M       43M  13% /run
/dev/mmcblk0p1    14777M 1867M    12731M  13% /
tmpfs               240M    1M      240M   1% /dev/shm
tmpfs                 5M    0M        5M   0% /run/lock
tmpfs               240M    0M      240M   0% /sys/fs/cgroup
tmpfs               240M    1M      240M   1% /tmp
/dev/zram0           49M   19M       27M  43% /var/log   ←これ
tmpfs                48M    0M       48M   0% /run/user/1000

今回のホストは16GBのMicroSDカードをストレージにしているシングルボードコンピューターなので今どきのPCに登載されているHDDやSSDとは桁違いに低容量。その/var/log領域はもともと僅か50MBしか確保されていない。この領域はZRAMなのでメモリ上に圧縮されて存在している。その半分近くが一瞬で喰われたらねぇ。

fr24feed ログ
しかも、そのログが内容の詰まった情報ならまだしも、(昨日も書いたけど)上の画像のような凄い無駄の塊。そして、昨日正常にフィードが行なわれるようになってからログを消したにも関わらず、今朝9:00に書き出されたのは昨日のフィードが正しく行われていなかった時間帯のステータスの変化。
その大量のデータを朝9:00にログに書き出すまでどこに溜め込んでいたのか知らないけど、MicroSDカードの領域に書き込んでたのなら勘弁して欲しい。というかfr24feedはRaspberry Pi用なら容量の関係で迂闊にログ出力して欲しくないってことも、書き換え耐性が低いMicroSDカードに書き込んで欲しくないってことも解ってる筈でしょ？

$ sudo zramctl
NAME       ALGORITHM DISKSIZE  DATA COMPR TOTAL STREAMS MOUNTPOINT
/dev/zram1 lzo         239.6M 31.8M 10.6M 11.5M       4 [SWAP]
/dev/zram0 zstd           50M   19M  5.1M  5.7M       4 /var/log   ←これ

MicroSDカードに書き込むシングルボードコンピュータ用のLinuxならおそらくログ用のパーティションはZRAMなどのメモリディスクなどに割り当てられている筈。ログパーティションは書き換えが多いのでMicroSDカードを壊さないためにもこれがありがたい。しかし、この手のシングルボードコンピュータはメモリ登載量が少ないので割り当てられる容量も極小に。ZRAMは圧縮が効くので50MB割り当てても実際のメモリの使用量はそれよりだいぶ小さい。

$ ls -l /var/log/fr24feed
total 18492
-rw-r--r-- 1 root root 18932825 Mar 10 00:00 fr24feed.log

日替わり時に一気に19MB吐き出されたログ。その後は増えていない。最後の記録が正常にフィードできるようになる前のだし。
ログは出力しない設定にしたつもりだったけど、ステータスの変化しまくった翌日？にこんな突然大量に吐き出されたら怖い。
そこで、この /var/log/fr24feed/fr24feed.log を消して /dev/null にシンボリックリンクしておいた。

$ sudo rm /var/log/fr24feed/fr24feed.log　←削除
$ sudo ln -s /dev/null /var/log/fr24feed/fr24feed.log　←シンボリックリンクを張る
$ ls -l /var/log/fr24feed
total 0
lrwxrwxrwx 1 root root 9 Mar 10 07:34 fr24feed.log -> /dev/null　←確認

これでfr24feedが「王様の耳はロバの耳」って叫んでもそのまま消えて無くなるのでめでたしめでたし。
ただし、異変には気付けるようにしておかないと。
一応、dump1090-exporterでdump1090-faが動いていることは監視しているので後はフィードが順調かどうかを確認できようにしたいところ。Prometheus+Grafanaで監視できるようにpiaware-exporterとかfr24feed-exporterとか出ないかしら？

以上、いつもにも増してしょーもない日記でスミマセン。

関連記事:
Up