Sausalito デバッグ道案内 / 徳植寛（日商エレクトロニクス）

「Sausalito デバッグ道案内」

徳植　寛　（日商エレクトロニクス）

概要

RaQ3,4 あたりまでは Cobalt の管理ソフトウェアは CGI で perl をキックする程度のシンプルな構造でしたが、Sausalito はあちこちにファイルが配置されています。そのため何かエラーが起きてもそれがどこのスクリプトでどういう条件で発生しているのか追うのが少しやりにくくなりました。
Sausalito Developer's Guide などの文書を読んで全体構造を理解して調べていく方法もあるのでしょうが、ここではもう少し乱暴だけれどもシンプルな方法を紹介します。
こうした方法が Sausalito アプリケーションを開発したり、既存のスクリプトを変更するときの参考になれば幸いです。

以後の作業はすべて特権ユーザ (root) でおこないます。システムのファイルを変更する作業もありますので、オペレーションに失敗すると最悪の場合システムを壊してしまう可能性があります。このあたりは自己責任でお願いします。

エラーメッセージをチェック

今回は RaQ550 においてサイトにユーザを追加する手続きを例にとり、そのエラーメッセージがどのスクリプトで、どのような条件で発生しているのか調べる例を示します^[1]。
たとえば「ftp」という名前のユーザを登録しようとした場合、画面の一番下に赤色の背景で以下のようなエラーメッセージが表示されます。

ご指定のユーザ名は、このシステム上で別のユーザが既に使用しています。別のユーザ名をご指定ください。

「そんな筈はない、ftp なんていうユーザはどのサイトにも登録されてないのに？」ということになるでしょう。このエラーはどこのプログラムでチェックされているのか？
このエラーメッセージを手がかりに追跡をはじめます。

mo メッセージファイルの中身を見る

Sausalito のメッセージは /usr/share/locale/ja/LC_MESSAGES 以下に .mo 形式のメッセージファイルとして集められています。

# cd /usr/share/locale/ja/LC_MESSAGES
# ls
base-alpine.mo         base-power.mo          fileutils.mo
base-am.mo             base-product.mo        gnupg.mo
base-apache.mo         base-raid.mo           grep.mo
base-asp.mo            base-sauce-basic.mo    knox-arkeia.mo
base-autoupdate.mo     base-scandetection.mo  legato-networker.mo
.... （以下略）

_swupdate:Sun-Security16633-v1_0.mo といった名前のファイルがあるかも知れませんが、これらはパッチなどを当てるときのものです。

mo メッセージファイルは plain text ではないので、cat base-swatch.mo のような方法では中身を見ることができません。msgunfmt コマンドを利用してテキストファイルに変換します^[2]。
。

[yasuda LC_MESSAGES]$ msgunfmt base-alpine.mo 
msgid "base-personalProfile"
msgstr "個人プロフィール"

msgid "base-personalProfile_description"
msgstr "ユーザアカウント情報が表示されます。"
.... （以下略）

文字化けする場合は漢字コードが違うためと思われますので、端末の漢字コードを EUC に合わせて下さい。

漢字コードが合っていたとしても、以下のように二行目が文字化けする場合があります。

msgid "osDescription"
msgstr ""
"[[base-alpine.osName]] "
"は、[[base-product.productName]]の基本ソフトウェアで、このサーバの動作に必要柊
"垈跳腓淵愁侫肇ΕД▲僖奪院璽犬任后

これは msgunfmt が文字の境界を無視して折り返しているためです。-w オプションに折り返し位置を必要充分に長い値を与えることでこれを回避します。

# msgunfmt -w 1000 base-alpine.mo

これで中身を見ることができました。
grep で検索したい、という作業のために、すべての mo ファイルをテキストファイルに変換することにします。 ~admin/messages というディレクトリを作成し、そこに変換されたテキストファイルを置くスクリプト、msg.sh を作ります。

for i
do 
  msgunfmt -w 1000 -o ~admin/messages/$i.txt $i
done

これを以下のようにして実行。

# cd /usr/share/locale/ja/LC_MESSAGES
# mkdir ~admin/messages
# sh ~admin/messages/msg.sh *.mo

これですべての mo ファイルが変換され、～～.mo.txt というファイル名で残ります。準備完了です。

キーワードをメッセージファイル群から探す

これを使ってメッセージ検索をします。今回のエラーメッセージは「ご指定のユーザ名は、このシステム上で別のユーザが既に使用しています。別のユーザ名をご指定ください。」というものでした。このなかからこのエラーに特徴的であろうと思われる文字列をひとつ選んで、それがどこに含まれているか調べます。
今回は「別のユーザが」という単語を選びました。

# egrep '別のユーザが' *.txt 
[yasuda messages]$ egrep '別のユーザが' *.txt 
base-user.mo.txt:msgstr "ご指定の[[base-user.userNameField]]は、このシステム上で
別のユーザが既に使用しています。別の[[base-user.userNameField]]をご指定ください
。"
#

ファイル base-user.mo.txt:msgstr を見てみると中身がなんとなくわかります。 less で中身を見ますが、テキストモードでは漢字を表示しないので -r オプションをつけます。

# less -r base-user.mo.txt

で raw mode で表示させて中身をチェック。「/別のユーザ」として検索すると、メッセージファイルに [[base-user.userNameField]]というパートがはいっています。これはすぐ下に msgid "userNameField" として定義されており、この参照名のチェインをたどって最終的にメッセージが合成されます。

msgid / キーワードをスクリプトファイル群から探す

ともあれ、下記のメッセージが問題のメッセージであることがわかりました。

msgid "userNameAlreadyTaken"
msgstr "ご指定の[[base-user.userNameField]]は、このシステム上で別のユーザが既に
使用しています。別の[[base-user.userNameField]]をご指定ください。"

続いてこのメッセージを発生させているプログラムがどこにあるかを探します。そのためには userNameAlreadyTaken という msgid を使っているファイルを探せば良いわけです。

# find /usr/sausalito/ -type f -print0 | xargs -0 egrep userNameAlreadyTaken
/usr/sausalito/handlers/base/user/handle_user.pl:                             '[
[base-user.userNameAlreadyTaken]]');
/usr/sausalito/handlers/base/user/handle_user.pl:               $cce->warn('[[ba
se-user.userNameAlreadyTaken]]');
/usr/sausalito/handlers/base/user/handle_user.pl:                       $cce->wa
rn('userNameAlreadyTaken');
/usr/sausalito/ui/web/base/user/userAddHandler.php:     $errors[] = new Error('[
[base-user.userNameAlreadyTaken]]');
/usr/sausalito/ui/web/base/user/userAddHandler.php:             $errors[$i]->mes
sage = '[[base-user.userNameAlreadyTaken]]';

（egrep -r で検索するという手もある。）

これで /usr/sausalito/handlers/base/user/handle_user.pl と /usr/sausalito/ui/web/base/user/userAddHandler.php がひっかかりました。

ともに Perl や PHP のスクリプトです。

handle_user.pl の方からチェックしてみましょう。

（54 行目から....）
if (defined($new->{name})) {
        if ($illegal_usernames{$new->{name}}) {
                $cce->baddata($oid, 'name',
                              '[[base-user.userNameAlreadyTaken]]');
                $errors++;
        } elsif ($new->{name} =~ /^$illegal_nameprefixs/) {
                $cce->warn('[[base-user.userNameAlreadyTaken]]');
                $errors++;
        }

        my @others = $cce->find("User", { 'name' => $new->{name} });

（... 中略 ... 117 行目から....）

        if (($#others > 0) || ($#mlist >= 0) || ($#other_aliases > -1)) {
                if ($i18n->getProperty('genUsername', 'base-user') ne 'no') {
                        my @suggestions = &gen_usernames($new->{name},
                                                 $new->{fullName},
                                                 $new->{site});
                        my $namelist = join(', ',@suggestions);

                        $cce->warn('userNameSuggest', {'list' => ${namelist}});
                } else {
                        # generating user names not possible for this locale
                        $cce->warn('userNameAlreadyTaken');
                }
                $errors++;
        }

デバッグコードを入れる

古典的なプログラミングでよくやる方法どおりに、print 文を入れてこれらのうちのどの行を通過して問題の事象が発生しているのか調べます。
ただし print 文をそのまま書いてもどの画面にそのメッセージは出るのだ？という話になってしまいますので、今回は下記のように指定したファイルにメッセージを書いていくことにします。（この一行については PHPでも perl でも同じ記述で同じように動作します。）

system("echo Step1 >> /home/tmp/toku");

以下のようにこのデバッグコードを埋めてしまうわけですが、作業前に cp -p handle_user.pl handle_user.pl.org とでもしてオリジナルを保存しておきましょう。

        if ($illegal_usernames{$new->{name}}) {
                system("echo Step1 >> /home/tmp/toku");
                $cce->baddata($oid, 'name',
                              '[[base-user.userNameAlreadyTaken]]');
                $errors++;
        } elsif ($new->{name} =~ /^$illegal_nameprefixs/) {
                        system("echo Step2 >> /home/tmp/toku");
                $cce->warn('[[base-user.userNameAlreadyTaken]]');
                $errors++;
        }

今回は三カ所ある userNameAlreadyTaken を使う行の直前にそれぞれ一行ずつメッセージの中身を替えて（Step1, Step2, Step3 と出すようにして）追加。どの動作で発生したのか調べます。
この状態で再びエラーを発生させます。つまりユーザの追加で「ftp」というユーザ名を追加します。エラーが当然発生しますので、その後 /home/tmp/toku というファイルを見ると Step1 となっていました。プログラムの Step1 目印の前後に注目します。

if (defined($new->{name})) {
        if ($illegal_usernames{$new->{name}}) {
                $cce->baddata($oid, 'name',
                              '[[base-user.userNameAlreadyTaken]]');
                $errors++;

直前に illegal_usernames という記述がありますから、これをふたたび find で検索します。

# find /usr/sausalito/ -type f -print0 | xargs -0 egrep illegal_usernames
/usr/sausalito/handlers/base/user/handle_user.pl:my %illegal_usernames = map { $
_ => 1 } qw /
/usr/sausalito/handlers/base/user/handle_user.pl:       if ($illegal_usernames{$
new->{name}}) {
#

となり、結局 handler_user.pl でだけ使っていることがわかります。handeler.pl の中の illegal_usernames という単語を探してみます。

my %illegal_usernames = map { $_ => 1 } qw /
        pop root alterroot bin daemon adm lp sync shutdown halt mail news uucp
        operator games gopher ftp httpd nobody chiliasp named
        postgres mysql qmail share-guest
        majordomo anonymous guest Root Admin ROOT ADMIN squid
/;

というように、ftp というユーザを除外するようにハードコードされてることが読み取れます。当日のプレゼンテーションではこのコードから ftp という単語を抜いて、実際に ftp という名前でサイトにユーザ追加できることを確かめました^[3]。

まとめ

最後に handler_user.pl をオリジナルのものに戻しておきましょう。

このセッションでは、エラーメッセージをたよりに、それがどこで、どういったプログラムが発生させているかを探し、それに関連する動作を追うという作業について紹介しました。
本来、こうした作業は SSDK や各種のドキュメントを読み、全体的な構造を理解して行うのが良いのでしょうが、一方でもっと簡単に、とりあえずここだけについて中を調べてみたい、という要求もあるでしょう。そうしたときの参考になればと思います。
（そういうわけでメイリングリストに質問をするときは完全に正確なメッセージを載せましょうね。）

*1 : 講演者はふだん Cobalt のユーザサポート、リセラーサポートを行っており、例えばこうしたケースの問い合わせ調査に多く携わっている。「 **** という名前のサイトを登録しようとしたらエラーになるが、これはなぜだ？」というような質問を調査するときには、このような追跡手法が有効になる場合が多い。
*2 : セッションでの実験機は RaQ 550 でした。RaQ 550 には msgunfmt コマンドがありますが、BlueQuartz および Fedora Core Reference kit には含まれていません。msgfmt, msgunfmt コマンドは gettext パッケージに含まれていますが、最近のものはバージョンが変わってしまい、550 の頃に作られた mo ファイルを正しく処理できません。BlueQuartz では配布ソースに含まれている po メッセージファイルを見るのが簡単でしょう。（[coba-o:00927]も参照。）
*3 : セッションでの実験機は RaQ 550 でした。ここには ftp という名前の Unix ユーザは存在しないため、ftp というユーザをサイトに追加できました。しかし多くの Linux システムでは anonymous ftp 用のユーザとして ftp ユーザが存在しています。BlueQuartz を Fedora Core Reference Kit の上に構築した場合も、ftp ユーザが存在しています。こうしたケースでは ftp ユーザが /etc/passwd 中にあることから、今回と同じようにして ftp ユーザをサイトに追加しても、また別のエラーが出るでしょう。

Hiroshi Tokuue

BlueQuartz Conference 2004/Summer in Nagano, JAPAN.

All rights are reserved.