サーバー管理自動化ツール Puppet のマニフェスト配信を、Puppet クライアント (puppetd) が Puppet サーバー (puppetmasterd) から能動的に取得するデフォルト方式から、Puppet サーバーが Puppet クライアントに対して puppetrun コマンドで 「取りに来い」 と促さない限り何のアクションもしない受動式に切り替えたのは、既報の通り。
マニフェスト配信方式の切り替え自体は特に困ることもなくすんなり完了したが、しばらく運用を続けているうちに、ある仮想マシン (以下 VM) の Puppet クライアントが反応しないことに気付いた。VM 上で Puppet クライアントは動作しているにもかかわらず、Puppet サーバーからの puppetrun に反応しないのだ。この状態で Puppet クライアントを restart させると起動に失敗し (＝起動したように見えるが、すぐに死ぬ)、VM 自体を再起動させると、Puppet クライアントは普通に起動する。
妙だなとログファイルの /var/log/puppet/http.log を見ると、次のようなログが記録されていた。
INFO WEBrick 1.3.1 INFO ruby 1.8.5 (2006-08-25) [i386-linux] WARN TCPServer Error: Address already in use - bind(2)
最初は "Address already in use" を 「IP アドレスが重複している」 と解釈して困惑していたが (我が家の環境ではまず発生しない)、プロセスの状況を確認すると、原因が判明した。Puppet クライアントが Puppet サーバーからの puppetrun コマンドを listen するのに使う TCP/8139 を、別のプロセスが bind してしまっていたのだ (netstat でプロセスを表示する -p オプションの指定には root 権限が必要)。
・正常な状態 # netstat -anp | grep LISTEN | grep ":8139" tcp 0 0 0.0.0.0:8139 0.0.0.0:* LISTEN 17368/ruby ・別のプロセスが同じポートを使用中の場合 # netstat -anp | grep LISTEN | grep ":8139" tcp 0 0 0.0.0.0:8139 0.0.0.0:* LISTEN 32261/named
上記例の元凶は LAN 内の BIND (Slave サーバー) で、named がランダムで使用するポートがバッティング (と言うより奪って) してしまっていた。この場合はとりあえず BIND を再起動すれば TCP/8139 が開放され、Puppet クライアントが起動するようになる。
我が家で常時稼動している全 Puppet クライアントで TCP/8139 の使用状況を監視 (& バッティング発生時は原因プロセスと puppetd を再起動) するスクリプトを書いて 3週間ほど観察を続けると、ばらつきはあるが、ポートのバッティングが平均すると 2～3日に 1回程度の割合で発生していることがわかった。我が家での主な原因は、rpc.rquotad や rpc.mountd (共に NFS サーバーで発生)、named (BIND の Master/Slave 共々)、openvpn (実家との拠点間 LAN 接続用 OpenVPN サーバー) 等だった。
しかし空きポートを含めて、ポートの使用状況は OS が管理しているはずなので、既に puppetd が使用しているポートを別のプロセスからの要求に従って 「ほらよ」 と渡してしまうと言うのは、奇妙な現象に思える。ひょっとして、puppetd は TCP/8139 を常時 bind しているわけではなく、離してしまうタイミングがあるのだろうか？ これも検証してみよう (後日掲載予定)。
