
Ubuntu日本語フォーラム

ログインしていません。
9.10 にアップデートしたら bind9 が起動できなくなりました。
その原因がわからず悩んでいます。みなさまにアドバイスを頂ければ助かります。
/var/log/messages を見ると、次のようなものが記録されています。
Nov 14 11:23:48 carrot kernel: [ 4410.936235] type=1503 audit(1258165428.438:68): operation="capable" pid=4884 parent=4883 profile="/usr/sbin/named" name="sys_resource"
Nov 14 11:23:48 carrot kernel: [ 4410.938113] type=1503 audit(1258165428.442:69): operation="open" pid=4884 parent=4883 profile="/usr/sbin/named" requested_mask="::r" denied_mask="::r" fsuid=112 ouid=0 name="/etc/ssl/openssl.cnf"
これは監査機能だと思いますが、これが原因で起動に失敗しているのでしょうか?
また、他にチェックすべきものは、あるでしょうか?
非常に困っている状態です。ぜひともアドバイスを頂ければ。
よろしくお願い致します。
オフライン
9.10 では確認していませんが、9.04 でも「audit ... operationa="capable" ... profile="/usr/sbin/named" ...」が出力されていますが、bind9 は問題なく動作しています
ちなみに grep named /var/log/syslog の実行結果には、何かそれらしきものが見受けられないでしょうか
オフライン
ry さん、ありがとうございます。
結論から言うと、先ほど bind9 のみ再インストールしたところ、正常に起動しました。
ログをにらめっこしながら起動スクリプトなどを一行ごとに追っていった苦労が、どこへやら、と。
ちなみに、syslog には以下のように記録されています。
Nov 14 11:26:48 carrot named[4948]: starting BIND 9.6.1-P1 -u bind
Nov 14 11:26:48 carrot named[4948]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-gnu-ld' '--with-dlz-postgres=no' '--with-dlz-mysql=no' '--with-dlz-bdb=yes' '--with-dlz-filesystem=yes' '--with-dlz-ldap=yes' '--with-dlz-stub=yes' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=-Wl,-Bsymbolic-functions' 'CPPFLAGS=' 'CXXFLAGS=-g -O2' 'FFLAGS=-g -O2'
Nov 14 11:26:48 carrot named[4948]: found 4 CPUs, using 4 worker threads
Nov 14 11:26:48 carrot kernel: [ 4591.306641] type=1503 audit(1258165608.811:70): operation="capable" pid=4948 parent=4947 profile="/usr/sbin/named" name="sys_resource"
Nov 14 11:26:48 carrot kernel: [ 4591.308474] type=1503 audit(1258165608.811:71): operation="open" pid=4948 parent=4947 profile="/usr/sbin/named" requested_mask="::r" denied_mask="::r" fsuid=112 ouid=0 name="/etc/ssl/openssl.cnf"
Nov 14 11:26:48 carrot named[4948]: using up to 4096 sockets
先ほどまで悩んでいたとき上記ログも確認したのですが、これを見ても私には何が問題なのか、わかりませんでした。
が、現在(正常に起動した場合)のログを見ると次のようになっています。(一部省略)
Nov 14 11:46:41 carrot named[7128]: starting BIND 9.6.1-P1 -u bind
Nov 14 11:46:41 carrot named[7128]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-gnu-ld' '--with-dlz-postgres=no' '--with-dlz-mysql=no' '--with-dlz-bdb=yes' '--with-dlz-filesystem=yes' '--with-dlz-ldap=yes' '--with-dlz-stub=yes' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=-Wl,-Bsymbolic-functions' 'CPPFLAGS=' 'CXXFLAGS=-g -O2' 'FFLAGS=-g -O2'
Nov 14 11:46:41 carrot named[7128]: adjusted limit on open files from 1024 to 1048576
Nov 14 11:46:41 carrot named[7128]: found 4 CPUs, using 4 worker threads
Nov 14 11:46:41 carrot named[7128]: using up to 4096 sockets
Nov 14 11:46:41 carrot named[7128]: loading configuration from '/etc/bind/named.conf'
Nov 14 11:46:41 carrot named[7128]: using default UDP/IPv4 port range: [1024, 65535]
Nov 14 11:46:41 carrot named[7128]: using default UDP/IPv6 port range: [1024, 65535]
Nov 14 11:46:41 carrot named[7128]: listening on IPv6 interfaces, port 53
(一部省略)
Nov 14 11:46:41 carrot named[7128]: command channel listening on 127.0.0.1#953
Nov 14 11:46:41 carrot named[7128]: command channel listening on ::1#953
(一部省略)
Nov 14 11:46:41 carrot named[7128]: zone localhost/IN: loaded serial 2
Nov 14 11:46:41 carrot named[7128]: running
ゾーンファイルなどを読み込んで、最終的に「running」しています。
今回の問題が、9.10のアップデートメカニズムに原因があったのか、それとも私の固有の環境に原因があったのか、わかりません。
みなさまの参考になるかもしれませんので、上記、ご報告しておきます。
ありがとうございました。
オフライン
うーん、ウソでした。
システムを再起動すると、まったく同じ現象に見舞われます。
つまり、やはり bind9 は起動に失敗します。
しかし、bind9 のみを再インストールすると、正常に起動します。
どうも難しい状況になってきました。
何かヒントになるようなことはないでしょうか?
アドバイスをお願い致します。
オフライン
こんばんは。
body-and-soul による投稿:
システムを再起動すると、まったく同じ現象に見舞われます。
つまり、やはり bind9 は起動に失敗します。
しかし、bind9 のみを再インストールすると、正常に起動します。
不思議な動きですね・・・
そのログを出している本人はappArmorのようなので、以下のファイルを確認してみてください。
/etc/apparmor.d/usr.sbin.named
その中に、
/etc/ssl/openssl.cnf r,
という行があり、ファイルの参照を参照を許可しているはずです。
なお、当方ではbind9をしよしていないため、apt-get intall直後の状態のみしか確認していません。ログに出ているメッセージからすると、再起動した跡で、以下のいずれかの状態なのかもしれません。
・なぜか、該当の行が消える/コメントアウトされてしまう。
・なぜか、usr.sbin.namedのファイルが消えてしまう。
オフライン
weykさん、こんばんは。
ご指摘の点、確認してみました。
/etc/apparmor.d/usr.sbin.named は存在し、その中に次の行も存在します。
/etc/ssl/openssl.cnf r,
また、この行は「システムの再起動後も同様に存在」します。
以上によって確認できたことは、まず、一番最初に報告したログのメッセージは上記の行が存在しても出力されるということになります。
従って、問題の bind9 が起動するかしないかという点に関しては、おそらくですが、無関係であるということになるかと思います。
わからないのは、システムを再起動すると bind9 関係で何が変化するのかという点です。
これが判明しないと、システム再起動するたびごとに bind9 を再インストールする必要があり、こんなバカげたことはありません。
オフライン
そうですか、それは大変失礼しました。
とりあえず、ログはappArmorのものなので、(セキュリティ的に可能なら)apparmorを一時的にとめて、切り分けることをお勧めしようと思ったのですが、無関係なら必要もないですね。
当方では、apt-getでbind9をインストール後、なにも設定を変更せずに何度か再起動を試しましたが、問題なく動作している(ログのrunningと、psで確認)ようです。とくにnamed以外の部分についても、特に変わった設定は行っていない・・・はずです(ほぼ、インストールしたそのまま)。
オフライン
AppArmorが原因でコケているわけではなさそうです。強制アクセス制御によるプロセスの起動失敗は、少なくともbindの場合は明確なエラーを吐いて落ちてくれます。
とりあえず切り分けのため、named.confを標準のものにして(設定したnamed.confを待避した上でapt-get remove --purge bind9してからapt-get install bind9)、その状態で問題が再現するか試すことはできますか?
刺さっている場所がちょうど「loading configuration from '/etc/bind/named.conf'」を吐くことが期待される場所なので、conf回りに何か問題の原因がいる可能性がありそうです。
標準の設定ファイルでも出てしまう場合は、
・ grep named /var/log/* | sort
・ dpkg -l | grep bind
と、「無事に起動に成功した場合」と「失敗した場合」それぞれで
・ sudo lsof | grep named
・ sudo lsof -i | grep named
あたりを取るとどこで止まっているのかが分かるかもしれません。
オフライン
weykさん、こんばんは。
もしもご不快を感じさせてしまったとしたら、たいへん申し訳ありません。
weykさんのご指摘のおかげで、起動に関しては appArmor に直接は関係ないということを理解することができました。
ありがとうございました。
また、hito さん。
ご指摘のチェックポイント、調べてみます。
その結果は、またご報告します。
オフライン
「bind9 apparmor cache files not regenerated on upgrade」
https://bugs.launchpad.net/ubuntu/+source/apparmor/+bug/466315
が症状が似ていると思うのですが。
LPの#10と#11に書いてありますが、
$ sudo apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
で強制的にキャッシュファイルを再生成すると、取り合えずは直るっぽいです。
やる前に、/etc/apparmor.d/cache/usr.sbin.named のバックアップは取っておいてください。(後の調査で必要となるかもしれないので)
# ちなみに、LPの前半部分で出てくる「apparmor-profilesをインストールすると直るよ」は、「実は本当の解決でない」と、後で覆されてます。
--
以下、私なりに調べてみた事を書きます。
apparmorのキャッシュ機構についていまいち把握しきれないので、一部曖昧な書き方になっています。
まず、9.10のbind9は9.04のそれと比べて、/etc/apparmor.d/usr.sbin.namedに「/etc/ssl/openssl.cnf r」というエントリが増えてます。(ファイル差分を見て確認しました。)
問題のUbuntuシステムにおいては、apparmorは起動時に、bind9用のapparmorキャッシュ(/etc/apparmor.d/cache/usr.sbin.named)を見てしまいます(?)
bind9用のapparmorキャッシュは再生成が上手されていないので、当然そのキャッシュには前出の追加エントリは反映しておらず、エラーが起きる。そんな感じです。
ただし、bind9を再インストールすると、インストール直後のpostinstスクリプト内で、新たにインストールされた/etc/apparmor.d/usr.sbin.namedを読み込んでいる為、一時的にそのキャッシュの問題が解決したように見える(らしい?)
新規インストールの9.10にて、擬似的な実験してみました。
$ sudo apt-get update
$ sudo apt-get install bind9
* Starting domain name service... bind9 [ OK ]
$ sudo cp -a /etc/apparmor.d/usr.sbin.named /etc/apparmor.d/usr.sbin.named.orig
$ sudo vi /etc/apparmor.d/usr.sbin.named
のうち、/etc/ssl/openssl.cnf r,
のエントリをコメントアウトしてファイル保存
$ sudo apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
$ sudo service bind9 restart
* Starting domain name service... bind9 [ OK ]
* Starting domain name service... bind9 [fail]
$ tail /var/log/message
Nov 15 15:40:58 localhost named[4448]: starting BIND 9.6.1-P1 -u bind
Nov 15 15:40:58 localhost named[4448]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-gnu-ld' '--with-dlz-postgres=no' '--with-dlz-mysql=no' '--with-dlz-bdb=yes' '--with-dlz-filesystem=yes' '--with-dlz-ldap=yes' '--with-dlz-stub=yes' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=-Wl,-Bsymbolic-functions' 'CPPFLAGS=' 'CXXFLAGS=-g -O2' 'FFLAGS=-g -O2'
Nov 15 15:40:58 localhost named[4448]: adjusted limit on open files from 1024 to 1048576
Nov 15 15:40:58 localhost named[4448]: found 1 CPU, using 1 worker thread
Nov 15 15:40:58 localhost kernel: [ 7070.282183] type=1503 audit(1258267258.835:53): operation="open" pid=4448 parent=4447 profile="/usr/sbin/named" requested_mask="::r" denied_mask="::r" fsuid=114 ouid=0 name="/etc/ssl/openssl.cnf"
Nov 15 15:40:58 localhost named[4448]: using up to 4096 sockets
-----
ログのメッセージがすごく似てます。
STGSAGWAN さん。
非常に貴重な情報をありがとうございます。
hito さんのご親切な助言に従い、bind9 標準構成で何度か試していたのですが、どうにも症状は変化せず、途方にくれていたところでした。
しかし、STGSAGWAN さんのご指摘を見ていると、一体なぜ 9.10 にアップグレードしても bind9 が正常に起動する人がいるのか、逆に、わからなくなりそうです。
いずれにせよ、STGSAGWAN さんの情報を手がかりにして、もう少し試行錯誤してみます。
週末にでも、ご報告します。
オフライン
横から失礼
AppArmorはよくわかりませんが、
auditのログが出ているのなら、
$ cat /var/log/messages | grep audit
で denied 行を見ていけば何らかの手がかりが見つかるかもしれません。
オンライン
STGSAGWAN さん。
試してみました。
確かに以下のコード、
STGSAGWAN による投稿:
コード:
$ sudo apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
これで bind9 が起動します。
とりあえず、/etc/rc.local に以下を書いてバグフィックスを待つことにしました。
/sbin/apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
/etc/init.d/bind9 start
オフライン
#14のbody-and-soulさん
$ sudo apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
はたった一度だけ実行すれば、今後はもう実行しなくてよいですよ。
今回の事でrc.localに何も追記する必要はないですよ。
STGSAGWAN さん。
おはようございます。
STGSAGWAN による投稿:
$ sudo apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
はたった一度だけ実行すれば、今後はもう実行しなくてよいですよ。
あれ?
状況が違うのでしょうか。
上記を実行しないと、システムを再起動するとやはり bind9 の起動に失敗します。
なので、ベタではありますが、rc.local にでも記述しておかないとどうしようもないなと。
ちなみに、システム再起動後の bind9 の起動失敗時のログは以下のものです。
Nov 28 08:42:22 carrot named[3107]: starting BIND 9.6.1-P1 -u bind -4
Nov 28 08:42:22 carrot named[3107]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-gnu-ld' '--with-dlz-postgres=no' '--with-dlz-mysql=no' '--with-dlz-bdb=yes' '--with-dlz-filesystem=yes' '--with-dlz-ldap=yes' '--with-dlz-stub=yes' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=-Wl,-Bsymbolic-functions' 'CPPFLAGS=' 'CXXFLAGS=-g -O2' 'FFLAGS=-g -O2'
Nov 28 08:42:22 carrot named[3107]: found 4 CPUs, using 4 worker threads
Nov 28 08:42:22 carrot kernel: [ 115.161046] type=1503 audit(1259365342.816:37): operation="capable" pid=3107 parent=3106 profile="/usr/sbin/named" name="sys_resource"
Nov 28 08:42:22 carrot kernel: [ 115.162867] type=1503 audit(1259365342.816:38): operation="open" pid=3107 parent=3106 profile="/usr/sbin/named" requested_mask="::r" denied_mask="::r" fsuid=112 ouid=0 name="/etc/ssl/openssl.cnf"
Nov 28 08:42:22 carrot named[3107]: using up to 4096 sockets
apparmor_parser を実行し bind9 を起動するときのログは以下になります。
Nov 28 08:42:44 carrot kernel: [ 136.705817] type=1505 audit(1259365364.360:39): operation="profile_replace" pid=3134 name=/usr/sbin/named
Nov 28 08:42:46 carrot named[3151]: starting BIND 9.6.1-P1 -u bind -4
(これ以後は bind9 起動成功)
とりあえず、以上、ご報告します。
オフライン
#16のbody-and-soulさんへ
おそらく、環境が違うのでしょうね。
私の環境は、9.04→9.10のアップグレードを経ずに、擬似的に作成した環境ですし。
私の環境では、一度キャッシュ再生成すればリブート後もOKで、#10で紹介したLaunchpadでも"キャッシュ再生成すれば直る"という話でしたので、それだけで解決すると思っていました。
STGSAGWAN による投稿:
おそらく、環境が違うのでしょうね。
私の環境は、9.04→9.10のアップグレードを経ずに、擬似的に作成した環境ですし。
なるほど、了解しました。
しかし、rc.local に書き込むなど、我ながら余りにもベタな対応で(笑)。
オフライン
私の場合、bindの起動は問題ないのですが、
$ /sbin/apparmor_parser -T -W -r /etc/apparmor.d/usr.sbin.named
をしないと、bindのログが出力されません。再起動するとログが出なくなってしまいます。
(ログの出力先が自分の指定したディレクトリだからでしょうか)
で、この行を/etc/rc.localに追加しました。
一応ログの出力という点ではこれでOKなのですが、syslogに少しだけ
rc.localが実行される以前のエラーと思われるメッセージが出ます。
ということで、結局、/etc/init.d/apparmorの「start」の項の終わりあたりに
この行を追加しました。
我ながら、素直な方法とはとても言えない。
ので、何かすっきりとした方法はないものでしょうか?
なお私のマシンは9.10のクリーンインストールです。
オフライン