2019-06-05921最初に触ったUnixはVAX-11/785で動いていたUltrixだったので、自分は根っからのBSD派だ。これは大学の計算機室に鎮座していたマシンで、緑色しか表示できないCRTを搭載したVT端末を通して使うものだった。いえ、やることと言えばnewsの閲覧ぐらいだった。3年生になるころには研究室に入り浸るようになりSun3/4上のSunOSを使うようになったからだ。ところが例のSolarisが出てきて、SunはSVR4になってしまった。インストールして最初に衝撃を受けたのが、termcapがなくなっていることだった。最初にそれを確認する自分もどうかと思うんだけど......。怒り狂っていたことはよく覚えている。それ以来、ずっとSVR4は嫌いだし、そういうわけでLinuxも嫌いなのだった。現代においては、Linuxは避けて通れないOSだ。仮想化全盛となり、qemuベースのシステムを作った張本人としては......。Linuxに慣れるためには、と思って自宅のシステムを置き換えてみたら、だんだんマルチのOSをメンテナンスするのが面倒になって、結局今では全部Linuxで動かしている始末である。これは決してLinuxが好きになったという意味ではない。端末PCにWindowsを使い続けているからといってWindowsが好きなわけではないのと同じだ。妥協の結果、そうなってしまっているに過ぎない。Linuxで特に嫌いなのが、伝統に敬意を払わないことだ。今回取り上げるjournaldもそうだ。なんでよりによってsyslogを置き換えちゃうのか......。いや、優れた後継プログラムに転換していくのは構わない。名前や仕組みを大きく変えてしまうのはどうか、と思うのだ。この辺の愚痴を書き連ねていると、あと100行ぐらいかかってしまうのでそろそろやめとこう。/var/log/messagesが空っぽになった自分が管理するサーバ一覧をみると、ざっと10台ぐらいのLinuxマシンが並んでいる。作った端からすぐ消してしまうようなマシンもあるが、このブログサーバのように恒久的にメンテし続ける必要があるマシンもある。それが10台ぐらいあるということだ。これらは定期的にアップデートしなくてはいけないし、ログに異常があればチェックもしたい。24/365で常時監視するほど大切ではないが、脆弱性を突かれて乗っ取られるようなマヌケはしない程度に管理しておきたいワケである。ときどきmessagesなどをチェックするのだが、いくつかのマシンでmessagesのサイズが0になっていることに気づいた。messages以外にも、secureやらmailやら、rsyslogが吐くファイルがほとんどすべて、空っぽになっているのだ。いう問題なのかなとググってみると、たとえばRHELのこんなページがヒットする。コマンドを実行しても何も起こらないが、rsyslogはjournaldから情報を取るからrsyslog.confをちゃんと設定しておいてね、と書いてあるだけだ。調べると、こんなBugzillaがあることが分かる。logging問題のマシンもVMなので、これかもしれない。ワークアラウンドが示されているので試してみる......具体的には/var/lib/rsyslog/imjournal.stateというファイルを削除してrsyslogdを再起動してみな、というのだが、これでも解決しない。journaldの導入でsyslogはどうなったかここでsyslogの仕組みをおさらいしてみよう。いうときは古典に頼るに限る。詳解UNIXプログラミングのp.438-442に詳しく説明されている。単純だった頃のsyslogdデーモンは、図中の中上のユーザプロセスにあたり、syslog(3)を呼んで/dev/logにメッセージを送る。syslogdはこれを経由してメッセージを受け取り、facilityとlevelに応じてファイルに書くとかなんとかするわけだ。journald/rsyslogdによる現在の構成journaldは元々syslogdのいた位置を占め、いったんすべてのメッセージを受け取る。systemd経由で起動したデーモンのSTDERRも受け取るようにできている。journaldは、syslogdが集めなかったメタ情報も集める。非常に細かな大量の情報を集めて、受け取ったメッセージと共にジャーナルとして保管する。この保管場所は小さいので時間が経つとすぐに消えてしまうし、リブートしても消えてしまう。そこで2つの選択肢がある。恒久的な場所に保管するよう変更する。それでもサイズ上限はあるので、適度に広げる必要はあるrsyslogを使って恒久化する。今度はrsyslogのサイズ上限があるので、適度に管理する必要が生じるというわけで、rsyslogはちゃんと存在している。rsyslogはいまやjournaldから間接的にログを分けてもらう存在に成り下がっている。使い勝手は従来と同じだ。これで後方互換性は保たれるというわけだ(助かった)。トラブルシュートさてmessagesにログが残らない問題のマシンだ。loggerのソースをダウンロードしてみた。調べてみると、ふつーにsyslog(3)を使っているので一安心だ(journaldのAPIを直に叩いていたらどうしようかな、と思っていたのだ)。そこでsyslogを使ったごく小さなコードを書いて、問題が生じているマシンで再現実験をしてみた。0;}しかし何をどうやってもmessagesには何も記録されない。おかしい......と、ここで思い立ってjournalctlを使ってそちらに何が記録されているかを確認してみた。すると、そちらにも記録されていなかった。rsyslogの問題かと思っていたら、journaldからしてうまく動いていないようだ。はてさて、どういうことだろう......と思っていたところで、ようやく思い出したことがあった。いやフィルタを一つ入れていたぞ。Sessionどうちゃら、というメッセージが大量に記録される問題に悩まされる。これはユーザがログインするたびに記録されてしまうのでうざったい。この問題をググると、こんなワークアラウンドが見つかる。ログがあふれるいわく、rsyslogにフィルタルールを書いて遮断せよ、とある。いうことで言われるままにこれを入れた。管理しているサーバが数台のうちはよかった。コピペするとかscpするなどして、都度対応していればよい。サーバ数が増えてくると、なんだが段々面倒くさくなってくる。いうとき自分はどうしているかというと、アップデートスクリプトを使って対応する。sliceなんちゃらを抑制するフィルタがなければそれを追加するとかで、その該当部分はこんな感じだった。fifiこれは修正後のコードだが、修正前は「$」がエスケープされていなかった。変数が実行前にすべて評価されてしまい、結果として壊れたフィルタルールがマシンに書かれてしまい、壊れたルールに従ってrsyslogがフィルタをしてしまうという状況に陥ってしまっていたのだった。messagesが空になっているマシンは、フィルタをこのスクリプトで処理しはじめた後のものばかりで、正常に動いていたものは手でコピペしていた世代のものだった。問題の生じているマシンは、すべて壊れたフィルタが入っていたので、これらをすべて正しいフィルタに書き換え、リブートすることですべて正常に戻った。結局技術的には成長してない原因調査を始めたときは、これを機にjournaldを完全に理解するぜーと意気込んだのだが、オチてしまうとやる気がなくなってしまっていけない。本来取り組むべきは、もうちょっとマシなサーバ管理機構を導入するログ管理を一元化する。