2015年12月15日

SECCON 2015 オンライン CTF での Command-Line Quiz について

telnet でログインしたらシェルが与えられるのに、自由にファイルを読むことができない不思議なシェル環境、あの問題は CaitSith の機能を用いて実現しました。

CaitSith login: root
Password:
$ id
uid=10000 gid=10000 groups=10000
$ ls -l
drwxr-xr-x    2 root     0            1880 Dec  5 05:18 bin
drwxr-xr-x    3 root     0             180 Dec  5 05:02 dev
drwxr-xr-x    2 root     0             100 Dec  5 05:02 etc
-rw-r--r--    1 600      0              87 Dec  5 04:48 flags.txt
-rwx------    1 root     0           13750 Dec  5 05:01 init
drwxr-xr-x    2 root     0              80 Dec  5 05:02 lib
-rwxr-xr-x  313 root     0          831112 Feb 19  2015 linuxrc
dr-xr-xr-x   73 root     0               0 Dec  5 05:18 proc
drwxr-xr-x    2 root     0            1180 Dec  5 05:18 sbin
-rw-r--r--    1 100      0             262 Dec  5 04:48 stage1.txt
-rw-r--r--    1 200      0             265 Dec  5 04:48 stage2.txt
-rw-r--r--    1 300      0             270 Dec  5 04:48 stage3.txt
-rw-r--r--    1 400      0             247 Dec  5 04:48 stage4.txt
-rw-r--r--    1 500      0             280 Dec  5 04:48 stage5.txt
drwxrwxrwt    2 10000    10000          60 Dec 15 13:57 tmp
drwxr-xr-x    4 root     0              80 Dec  5 05:02 usr
$ cat *.txt
cat: can't open 'flags.txt': Operation not permitted
What command do you use when you want to read only top lines of a text file?

Set your answer to environment variable named stage1 and execute a shell.

  $ stage1=$your_answer_here sh

If your answer is what I meant, you will be able to access stage2.txt file.
cat: can't open 'stage2.txt': Operation not permitted
cat: can't open 'stage3.txt': Operation not permitted
cat: can't open 'stage4.txt': Operation not permitted
cat: can't open 'stage5.txt': Operation not permitted
$ stage1=head sh
$ cat *.txt
cat: can't open 'flags.txt': Operation not permitted
cat: can't open 'stage1.txt': Operation not permitted
What command do you use when you want to read only bottom lines of a text file?

Set your answer to environment variable named stage2 and execute a shell.

  $ stage2=$your_answer_here sh

If your answer is what I meant, you will be able to access stage3.txt file.
cat: can't open 'stage3.txt': Operation not permitted
cat: can't open 'stage4.txt': Operation not permitted
cat: can't open 'stage5.txt': Operation not permitted
$ stage2=tail sh
$ cat *.txt
cat: can't open 'flags.txt': Operation not permitted
cat: can't open 'stage1.txt': Operation not permitted
cat: can't open 'stage2.txt': Operation not permitted
What command do you use when you want to pick up lines that match specific patterns?

Set your answer to environment variable named stage3 and execute a shell.

  $ stage3=$your_answer_here sh

If your answer is what I meant, you will be able to access stage4.txt file.
cat: can't open 'stage4.txt': Operation not permitted
cat: can't open 'stage5.txt': Operation not permitted
$ stage3=grep sh
$ cat *.txt
cat: can't open 'flags.txt': Operation not permitted
cat: can't open 'stage1.txt': Operation not permitted
cat: can't open 'stage2.txt': Operation not permitted
cat: can't open 'stage3.txt': Operation not permitted
What command do you use when you want to process a text file?

Set your answer to environment variable named stage4 and execute a shell.

  $ stage4=$your_answer_here sh

If your answer is what I meant, you will be able to access stage5.txt file.
cat: can't open 'stage5.txt': Operation not permitted
$ stage4=awk sh
$ cat *.txt
cat: can't open 'flags.txt': Operation not permitted
cat: can't open 'stage1.txt': Operation not permitted
cat: can't open 'stage2.txt': Operation not permitted
cat: can't open 'stage3.txt': Operation not permitted
cat: can't open 'stage4.txt': Operation not permitted
OK. You reached the final stage. The flag word is in flags.txt file.

flags.txt can be read by only one specific program which is available
in this server. The program for reading flags.txt is one of commands
you can use for processing a text file. Please find it. Good luck. ;-)
$ sed "" flags.txt
OK. You have read all .txt files. The flag word is shown below.

SECCON{CaitSith@AQUA}
$

シェルを起動するたびに読めるファイルが変化したり、環境変数の内容に応じてアクセスの可否が決まったりというのは、 TOMOYO / AKARI / CaitSith ならではのアクセス制限です。どのようなルールを使っていたのかを、ここで紹介します。

POLICY_VERSION=20120401

10 acl execute task.uid!=0 task.domain="<kernel>"
    10 allow transition="stage1"
    20 deny

10 acl execute task.domain="stage1"
    10 allow envp["stage1"]="head" transition="stage2"
    20 allow

10 acl execute task.domain="stage2"
    10 allow envp["stage2"]="tail" transition="stage3"
    20 allow

10 acl execute task.domain="stage3"
    10 allow envp["stage3"]="grep" transition="stage4"
    20 allow

10 acl execute task.domain="stage4"
    10 allow envp["stage4"]="awk" transition="stage5"
    20 allow

10 acl read path.uid=100
    10 allow task.domain="stage1"
    20 deny

10 acl read path.uid=200
    10 allow task.domain="stage2"
    20 deny

10 acl read path.uid=300
    10 allow task.domain="stage3"
    20 deny

10 acl read path.uid=400
    10 allow task.domain="stage4"
    20 deny

10 acl read path.uid=500
    10 allow task.domain="stage5"
    20 deny

10 acl read path.uid=600
    10 allow task.exe="/bin/sed" task.domain="stage5"
    20 deny

10 acl inet_stream_connect task.uid!=0
    10 deny

10 acl inet_stream_listen
    10 allow port=23
    20 deny

10 acl inet_dgram_send task.uid!=0
    10 allow port=53 ip=133.242.0.3
    10 allow port=53 ip=133.242.0.4
    20 deny

最初の規則は、一般ユーザ(UIDが0ではないプロセス)かつドメインが <kernel> であるプロセスからプログラムが実行された場合、 stage1 ドメインへ遷移するという指定です。これは、 root ユーザとしてログイン後、ログインシェルから一般ユーザのユーザIDが割り当てられて、シェルが開始されることにより stage1 ドメインに遷移するという動作に対応します。

次の規則は、ドメインが stage1 であるプロセスからプログラムが実行された場合、環境変数 stage1 の値が head であれば stage2 ドメインに遷移し、それ以外の場合には、ドメインを遷移せずにプログラムを実行するという指定です。これは、 stage1.txt の回答が head であれば stage2 へ進むことができ、そうでなければ stage2 へは進めないという動作に対応します。普通のアクセス制御では許可する場合を列挙したら残りは全て拒否するものですが、ここでは意図的に全てを許可するように指定しています。これにより、正解でも不正解でもシェルが実行できるため、総当たり攻撃による突破を困難にしています。

以下同様に、ドメインが stage2 であるプロセスからプログラムが実行された場合、環境変数 stage2 の値が tail であれば stage3 ドメインに遷移、ドメインが stage3 であるプロセスからプログラムが実行された場合、環境変数 stage3 の値が grep であれば stage4 ドメインに遷移、ドメインが stage4 であるプロセスからプログラムが実行された場合、環境変数 stage4 の値が awk であれば stage5 ドメインに遷移するという指定を行っています。

次に、それぞれのドメインでどのファイルを読めるかについての指定を行います。パス名ベースのアクセス制御の弱点である、パス名が変化するとアクセスの可否も変化してしまうという問題を回避するため、ファイルの所有者IDをキーとして許可を与えるようにしています。この方法なら、細かくリネームやハードリンクなどの作成を制限する必要がありません。パス名以外をキーに指定できる CaitSith の利点が生かせる指定です。

具体的には、所有者IDが100のファイルは、ドメインが stage1 であるプロセスからのみ読み出すことができるという指定を行っています。以下同様に、所有者IDが200のファイルはドメインが stage2 であるプロセスからのみ、所有者IDが300のファイルはドメインが stage3 であるプロセスからのみ、所有者IDが400のファイルはドメインが stage4 であるプロセスからのみ、所有者IDが500のファイルはドメインが stage5 であるプロセスからのみ読み出すことができるという指定を行っています。これらは、それぞれのステージで stage1.txt から stage5.txt までの何れか1個だけを読み出すことができるという動作に対応します。

所有者IDが600である flags.txt を読み出す許可だけは、少し異なる方法で指定しています。具体的には、プロセスのドメインが stage5 で、かつ、実行中のプログラムのパス名が /bin/sed である場合のみ読み出すことができるという指定を行っています。

その他、他のサーバへの攻撃に使われないようにするために、ネットワークの制限も行っています。具体的には、ユーザIDが0ではないプロセスは外向きのTCP接続を全面的に禁止しています。また、内向きのTCP接続はポート23のみを許可しています。ユーザIDが0ではないプロセスは、外向きのUDP接続として、DNSサーバである 133.242.0.3 および 133.242.0.4 のポート53のみを許可しています。

以上が、今回の出題で使われたルールです。もっと複雑なルールを指定することもできますが、エスパー問題化を回避するために、簡単なルールを指定しながら、ヒントも与えるようにしています。ヒントを削ってしまうと、攻略不可能なケロちゃんチェック問題になってしまいますからねぇ。

勝手にQ&A:

  • 何故 root ユーザでログインしているのにシェルのプロンプトが一般ユーザ用なの?→他の挑戦者への妨害を防ぐために、セッション毎に異なるユーザIDや /tmp ディレクトリを割り当てていたためです。

  • シェルログインさせておいて、スパムメールの発射台にされないの?→上述した通り、ネットワーク制限が掛かっているので発射台にはできないでしょう。

  • ハードディスクが見つからなかったのですが?→すべてオンメモリで動作しています。 initramfs 内の busybox により一通りの機能は提供されていました。そのため、 /init と、セッション隔離を行うためのログインシェルである /bin/loginshell 、それらが依存している ld-linux.so.2 と libc.so.6 だけを initramfs に追加し、 CaitSith のポリシーも含めて全て vmlinuz 内に埋め込みました。 vmlinuz ファイル1個だけで動作するので、 PXE で使うのも簡単です。

  • vmlinuz ファイル1個だけで動作する Linux 環境ってどうやって作るの?→今年のセキュリティ・キャンプの事前学習資料で扱っています。この資料で説明されている内容を参考に、NICドライバなど幾つかの機能を追加すればネットワーク接続もできるカーネルができあがります。

  • 何故 ssh ログインじゃないの?→準備時間が足りませんでした。(笑)

posted by 熊猫さくら at 23:07| Comment(0) | TrackBack(0) | CaitSith

2015年08月18日

セキュリティ・キャンプ2015で使用した、熊猫のテキストを公開しました。

去年から今年にかけて、例えば Shell Shock 脆弱性のような、OSレイヤーでの重大な脆弱性が見つかり、セキュリティ意識の高い人たちの間では「 SELinux を使おうよ」という機運が高まっているのかもしれません。しかし、サポートセンターでの経験より、「 SELinux を使ってトラブルが起きても対処できない」という人たちも大勢いることが判りました。そこで、改めて「OSの挙動を知って、OSレイヤーのセキュリティについて考えてみよう」と思い、今年度は「 TOMOYO / AKARI / CaitSith ハンズオン」というテーマにしました。

読むためのPDF版コピペするためのテキスト版

今回のテキストは、事前学習資料部分と当日学習資料部分の2部構成になっています。

事前学習資料部分では、「講義で使う環境に慣れてもらう」ことを意図して、「 PXE ブートして sl コマンドが走る Linux 環境を作る」ことに挑戦していただきました。 Scientific Linux ならぬ、 SL Linux です。(これは、昨年度のキャンプの企業見学からの帰りのバスの中での雑談から思いついたネタです。)

当日学習資料部分では、 TOMOYO をメインライン化するまでのドタバタ劇とか、3年間 RHEL システムのトラブルシューティング業務に従事して痛感した組織の問題点とかのような、技術的に Linux システムに詳しくない人にも何かの役に立つ話を交えたいと思いました。また、緊急コラム「 bash 脆弱性( CVE-2014-6271 )の影響範囲の調査方法について」が掲載されました。で「あまりに dis りすぎたため、公開したら怒られそうな内容になってしまいました」と書いたように、一昨年/昨年のテキストについては公開することを躊躇っていましたが、責任をとらないお偉いさんたちが蔓延していく現在の日本の危機的状況を見て、「来年では間に合わない」と判断し、過去テキストも含めて全テキストへのリンクを含めることにしました。

当日学習で使用した VirtualBox 向けのVMイメージは、 http://jaist.dl.sourceforge.jp/caitsith/63583/ からダウンロードできます。(ただし、サイズが大きいので、1か月後くらいに削除するつもりです。テキストでは CentOS 6 / CentOS 7 / Ubuntu 14.04 の3つしか言及していませんが、受講者の中に Arch Linux ユーザが居ましたので、 Arch Linux 用のVMイメージも用意しました。)

キャンプの様子は http://togetter.com/li/859151 から察していただければと思います。他の講師の方々が公開された資料や、参加者の反応なども見つけることができます。

posted by 熊猫さくら at 01:41| Comment(0) | TrackBack(0) | Linux

2015年05月05日

TOMOYO Linux 1.8.4 / AKARI 1.0.34 が公開されました。

use_group を複数個指定できるようにすることにより、ポリシーの重複部分を削減しやすくなりました。
http://sourceforge.jp/projects/tomoyo/lists/archive/users/2015-May/001004.html

2011年9月以来の久しぶりのアップデートな訳ですが、ずいぶんと状況が変わりました。
http://sourceforge.jp/projects/tomoyo/lists/archive/users/2015-April/001003.html
Linux カーネルと Linux システム管理についての心配事がいろいろと増えてしまい、現実世界の心配事にまで手が回らなくなってしまっています。

posted by 熊猫さくら at 23:44| Comment(0) | TrackBack(0) | TOMOYO Linux

2015年04月03日

makedumpfile コマンドの罠

Red Hat 社のナレッジ の中に、 vmcore ファイルのファイルサイズを削減するには makedumpfile -d 31 を使ってフィルタリングするようにという記述があります。しかし、 RHEL 6 および RHEL 7.0 に含まれている makedumpfile コマンドには、本来はフィルタリングされるべき Transparent Huge Pages の内容がフィルタリングされないという不具合があります。その結果、 vmcore ファイルのファイルサイズが必要以上に大きくなったり、 vmcore ファイル内に機密情報が残存しやすくなったりします。この不具合は RHEL 7.1 に含まれている kexec-tools パッケージで修正され、 RHEL 6 系についても RHEL 6.7 で修正予定とのことです。

RHEL 6.7 がリリースされるまでの暫定対処としては、サポート対象外の方法ではありますが、 RHEL 7.1 用の kexec-tools パッケージを RHEL 6 環境にインストールして使うことができます。 CentOS 6 環境に CentOS 7.1 用の kexec-tools パッケージをインストールする例を以下に示します。既存の環境を壊さないように、 rpm コマンドの実行時に --root オプションを指定しています。

# source=http://ftp.jaist.ac.jp/pub/Linux/CentOS/7.1.1503/os/x86_64/
# dest=~/kexec-tools/
# rpm --root $dest/ --import $source/RPM-GPG-KEY-CentOS-7
# rpm --root $dest/ --nodeps --noscripts -ivh $source/Packages/kexec-tools-2.0.7-19.el7.x86_64.rpm $source/Packages/snappy-1.1.0-3.el7.x86_64.rpm $source/Packages/lzo-2.06-6.el7_0.2.x86_64.rpm $source/Packages/elfutils-libs-0.160-1.el7.x86_64.rpm $source/Packages/xz-libs-5.1.2-9alpha.el7.x86_64.rpm $source/Packages/glibc-2.17-78.el7.x86_64.rpm

取得済みの vmcore ファイルを再度フィルタリングする際の例を以下に示します。 CentOS 6 用ではなく CentOS 7.1 用のライブラリが参照されるようにするために、 LD_LIBRARY_PATH= オプションの指定と /lib64/ld-2.17.so 経由での起動をしています。

# dest=~/kexec-tools/
# LD_LIBRARY_PATH=$dest/lib64/:$dest/usr/lib64/ $dest/lib64/ld-2.17.so $dest/sbin/makedumpfile -l -d 31 フィルタ前のvmcoreファイル フィルタ後のvmcoreファイル

kexec-tools-2.0.0-280.el6.x86_64 がインストールされている CentOS 6.6 環境に、上記の手順で CentOS 7.1 の kexec-tools-2.0.7-19.el7.x86_64 をインストールし、 メモリ 2048MB 中の 1536MB を特定のパターンで埋め尽くした状態で取得した vmcore ファイルを、上記の手順で再度フィルタリングした場合のサイズの変化例を以下に示します。

使用する
パターン
フィルタオプションvmcore ファイルの
サイズの変化
0-d 31100,739,352

91,312,408
-l -d 3129,346,091

20,415,428
1-d 311,706,537,640

91,736,744
-l -d 3140,430,575

20,533,033
rand() 関数の
戻り値
-d 311,705,867,632

91,050,376
-l -d 311,634,827,177

20,510,161

上記は意図的に特定のパターンで埋め尽くした場合に生じる極端な結果ですが、現実のメモリ使用状況でもある程度の効果を期待できる筈です。

posted by 熊猫さくら at 21:11| Comment(0) | TrackBack(0) | Linux

2015年03月31日

最終回「防災訓練ノススメ」が掲載されました。

今回はトラブルに遭遇する前に何ができるかという話です。

OSSセンタで3年間、問合せ対応を行ってきましたが、「発生したトラブルについての原因と対策を教えてほしい」という問合せはあっても、「トラブルが発生した場合の対処手順を教えてほしい」という問合せはありませんでした。それだけ、「どのようなトラブル発生事例があるのか」や「どのようなトラブルが発生しうるのか」についての共有ができていないということなのだと思います。

でも、「どのようなトラブル発生事例があるのか」や「どのようなトラブルが発生しうるのか」を知っているOSSセンタ側も、「トラブルが発生した場合の対処手順」を用意できているとは言い難い状況でした。熊猫はカーネルの開発経験があるため、カーネルクラッシュダンプの取得に関する問合せや解析依頼に対応しながら、取得手順や初期解析の手順を作成してきました。その第一歩が、今回の話に登場した「ナレッジの泉」に反映されています。もちろん、システムに固有の部分については対応できませんが、共通する部分については「トラブルが発生した場合の対処手順」を考えておくべき時期が来たのではないかと思います。

posted by 熊猫さくら at 22:33| Comment(0) | TrackBack(0) | Linux

2015年03月17日

第17回「プログラミング体験ノススメ」が掲載されました。

今回はプログラムを自作してみようという話です。

「たまゆら」を観ていると「 ARIA 」の世界を思い出してしまうのですが、自分の手でやっている感触というんでしょうかね。熊猫は、そういう癒し系アニメに出会うと好きになってしまいます。提供されたAPIを呼び出して結果を待つだけではなく、「ああでもない、こうでもない」と考えて行動した人だけが辿り着ける「(細かな問題点にも気付く)気配り/思いやりスキル」が存在するのだと思います。

世の中がそういうスキルを持つ人たちで満たされていれば対処する必要のない脆弱性に関して重箱の隅をつつき続けた結果、当初は議論に値しないと乗り気でなかったため「30分で終わる」と思っていたらしい Linux Storage filesystem and MM summit での議論が、2時間くらい続く大炎上となった模様です。熊猫は留守番でしたので内容は知りませんが、 LWN.net の記事によると、 3.19-rc6 後に紛れ込んだ予期せぬ挙動の変化を容認する(ファイルシステムエラーなどが起こらないように呼び出し側を修正していく)方向になったようで、そのためのパッチが LKML に投稿されています。ディストリビューションカーネルのデフォルトの挙動にして、エンドユーザにメモリ枯渇時のカーネルの不具合を見つけてもらうことを期待しているようですが、それは無理すぎる気が・・・。

posted by 熊猫さくら at 21:47| Comment(0) | TrackBack(0) | Linux

2015年03月03日

第16回「 kernel-debug ノススメ」が掲載されました。

今回は デバッグ用カーネルの紹介です。でも、デバッグ用カーネルの紹介だけで1話持たせるのは無理があるので、過負荷試験の話も入れました。

今までは「システムがダウンするくらいにまでメモリ負荷を掛けたら、いつ回復するか予測できないストール状態に陥るのは当然だ。そのような負荷を掛けたユーザのほうが悪い」と相手にされなかったのですが、実は「無限ループに陥るトドメの一撃」を喰らわせていたのはユーザ側ではなくメモリ管理機構側だったようです。
前回紹介したメモリ枯渇時の挙動についての議論が、 3.19-rc6 後に紛れ込んだ予期せぬ挙動の変化をきっかけに、一気に動き出しました。
ext4 でファイルシステムエラーが頻発したり、 xfs でページフォールトするだけで OOM killer が発生したりと、全く使い物にならなくなってしまうことが確認されたため、とりあえずは元の挙動に戻されました
そして、 mm のメンテナと ext4 のメンテナと xfs のメンテナとの間で将来に向けてどう修正していくのかの議論の最中なのですが、熊猫が欲している「既存のカーネルにバックポート可能な修正方法」についての話が完全に置いてけぼり状態になっています。
メモリ割り当て要求が原因のシステムフリーズとさよならできるようになる日が来るのはまだ遠いのかなぁ。
来週、ボストンで Linux Storage filesystem and MM summit という 会議があるので、そこで何らかの進展があることを期待しています。

posted by 熊猫さくら at 20:56| Comment(0) | TrackBack(0) | Linux

2015年02月17日

第15回「フォールトインジェクションノススメ」が掲載されました。

今回は SystemTap を使ってエラーを発生させるというちょっと怖いお話です。でも、ここでは目を離した隙にカーネルの挙動が変化しているという別の方向で怖い話をしたいと思います。

使い方1で紹介した不具合は RHEL 6/7 カーネルにバックポートされましたが、修正されたことを知るのは面倒です。というのも、エラータのページにはセキュリティ上の不具合の修正内容についてしか言及されておらず、「その他の修正内容についてはテクニカルノートを見てね」と書かれているのに従ってテクニカルノートのページをチェックしても、今回の不具合に該当しそうな内容が見当たりません。実は、 rpm パッケージの変更履歴の説明文をチェックするかソースコードの差分をチェックして初めて、「あ、修正されたんだな」と判るようになっていたのです。テクニカルノートには全修正内容が網羅されていると思っていると、落し穴にはまるかもしれないということですね。

使い方2で紹介した挙動は、 3.19-rc6 がリリース(1/25)されてから 3.19 がリリース(2/8)されるまでの僅かな間に、 __GFP_FS が含まれていない場合にはメモリ枯渇時に OOM Killer を発動させずに諦めるという変更が適用されてしまいました。 linux-next.git でテストを行って問題が無いことを確認してから linux.git の -rc1 がリリースされるまでにマージするというのが本来の手順なのですが、その手順をすっとばされた訳です。ファイルシステムより低いレイヤーでのメモリ割り当てがメモリ枯渇時に失敗してしまうようだと、ファイルシステムエラーが多発してしまうので困ると思うのですが。そういう変更を適用するのなら、 __GFP_NOFAIL が必要な個所を全て洗い出して修正してからにしてほしかったんだけどなぁ。

posted by 熊猫さくら at 22:56| Comment(0) | TrackBack(0) | Linux

2015年02月03日

緊急コラム「 glibc 脆弱性( CVE-2015-0235 )の影響範囲の調査方法について」が掲載されました。

ルイージ@お化け屋敷のような、次から次へと襲い掛かってくる問合せの嵐に困っています。

glibc の不具合や脆弱性が見つかる度に、影響を受けるプログラムの調査方法を説明するというのも馬鹿げた話ですので、今回の glibc 脆弱性を機に、緊急コラムとして調査方法を説明することにしました。
一昨日考えた内容を急いでダンプしたものなので、全てを網羅できている訳ではありません。でも、影響範囲を調査することの難しさに気付いて素直にアップデートをしていただけるのなら、この記事を作成した意味はあると考えています。

今回の脆弱性については幽霊に振り回されすぎている感がありますが、システムの動作を再確認してみるチャンスかもしれません。任意のホスト名を渡すことができるかどうかをソースコードレベルで網羅的に調査してみたら、OSコマンドインジェクションのような、今まで見落としていた脆弱性が見つかってもおかしくないと思っています。

posted by 熊猫さくら at 21:15| Comment(0) | TrackBack(0) | Linux

2015年02月02日

第14回「 SystemTap ノススメ」が掲載されました。

今回は SystemTap を使って挙動を追跡するというお話です。

とあるシステムで、 Pacemaker を起動してから約70秒後にシステムが予期せぬ再起動をしてしまうというトラブルが発生していました。再起動する直前だけディスクI/Oが多いという傾向が見られたため、何らかのディスクI/Oに関するトラブルに巻き込まれた結果、 /dev/watchdog への書き込みが遅延して watchdog タイムアウトによるリセットが発生しているのではないかと疑ったのですが、原因を掴めませんでした。

そこで、再起動要求が発生した時点の kdump を取得することにより、誰が再起動要求を発生させているのか/どうして再起動要求を発生させることになったのかを調査するために、今回紹介した SystemTap スクリプトを仕掛けて事象を再現してもらいました。すると、何と sfex_daemon という監視プログラムが /proc/sysrq-trigger に b を書き込んだことによるリセットが発生していたことが判明したのです。これをきっかけに、設定の誤りが予期せぬ再起動の原因であったことが判明し、トラブルを解決することができました。

sfex_daemon のソースコードによると、普段はスリープしながら、定期的に update_lock() を呼び出してロックの状態を確認し、異常を検知した場合には failure_todo() を呼び出しているようです。 failure_todo() は cl_log() という関数の中から syslog() 関数を呼び出すことで syslog デーモンにログメッセージを送信後、 /proc/sysrq-trigger に b を書き込んでいるようです。では、何故 syslog() 関数を介して送信した筈のログメッセージが、 syslog ファイルに残っていなかったのでしょうか?実は、 syslog() 関数を介して syslog デーモンにログメッセージを出力する方法には、2つの落し穴があったのです。

1つ目の落し穴は、 rsyslog の version 3 からは、デフォルトで非同期書き込みを行うようになっている点です。そのため、非同期書き込み後すぐに再起動要求が発生してしまっては、ログに残すことができません。2つ目の落し穴は、 syslog() 関数を介して syslog デーモンにログメッセージを出力する方法では、 syslog デーモンがログメッセージを出力するよりも前に syslog() 関数が復帰してしまうため、たとえ同期書き込みを行うようになっていたとしても、同期書き込みの完了を待たずに再起動要求が発生してしまい、ログに残すことができません。

RHEL 7 の登場により、3つ目の落し穴も発見されました。 RHEL 7 の場合はデフォルトのファイルシステムが ext4 から xfs に変更されたため、 ext 系ファイルシステムで行われていた5秒毎の writeback も行われなくなっています。そのため、 RHEL 7 においては、明示的に sync() 関数などを呼ばないと、問題事象発生直前のログが残っていないという可能性が一層高くなっています。

再起動直前のログを確実に残したい場合、 syslog デーモンに頼っていては駄目なのかもしれません。今後 RHEL 7 のシステムが増えてくるに従い、問題事象発生時のログを如何に残すかという課題が出てきそうです。カーネルメッセージであればシリアルコンソールや netconsole 経由で取得するという方法が使えます。アプリケーションのメッセージについても自力でローカルとリモートの両方にログを出力するとかしたほうが良いのかなぁ?

明日は節分ですって? 幽霊は〜外〜。アップデートは〜内〜。(謎)

posted by 熊猫さくら at 22:00| Comment(0) | TrackBack(0) | Linux