PowerCMS ブログ

本日(6月25日)MTDDC(Movable Type Developers & Designers Conference)が開催されています。その中でMTチームはセキュリティ強化月間という発表がされていました。

• MTDDC Tokyo 2011

弊社では、MT5.0xから5.1xのリリース時にいくつかの脆弱性レポートもしくはパッチをシックス・アパートのMTチームに送付させていただきました。現在開発が佳境を迎えているPower CMS3の開発の中では、セキュリティポリシーを新たに定め直してコードレビューを行っています。

ここではMTのメソッドを例にとって、どのようにコードを見ていくかについての手順と、脆弱性に限らずバグを発見するためのデバッグ方法のヒントなどを紹介します。

• 参考: MTDDC開催中。セキュリティ強化月間らしいので。

MTに限った話ではないですが、まずはソフトウェアのお作法や開発の慣習を理解することから始まります。MTにおけるメソッドのレビュー・デバッグを例にとって考えてみたいと思います。

通常MTでは mt.cgi?__mode=foo&_type=bar&id=buz&blog_id=1 のような形でリクエストを送ります。

この、__mode=foo のfooを「mode(モード)」と呼びます。この各モードに対する動作を定義しているのが「method(メソッド)」です(MVCで言うところのContoroller)。

mt.cgi?__mode=dashboard

の場合、モードは「dashboard」です。基本的にはモードごとにメソッドが指定されています。

メソッドはMTが標準で定義されているメソッド(core_methods)の他に、プラグインやアドオンで定義されているものも存在します。

※定義されている=registryに登録されているもの

• 参考: 動作モードの追加とモーダルウィンドウの表示

メソッドで行われる処理は基本的に次のようなものです。

“何らかの処理(DBへの書き込み、削除、読み込み、もしくは再構築等の処理)を行った後、テンプレートを読み込んで、パラメタを指定してビルドした結果を返す(もしくは別のmodeへ必要なパラメタを付けてリダイレクトする)。”

mt.cgiの実体はMT::App::CMS(ファイルは mt_dir/lib/MT/App/CMS.pm)で、(MT5.1)の37行目からの sub core_methods{} が各メソッドを定義している部分になります。

sub core_methods {
    my $app = shift;
    my $pkg = '$Core::MT::CMS::';
    return {
        'tools'     => "${pkg}Tools::system_check",
        'dashboard' => "${pkg}Dashboard::dashboard",
        'menu'      => "${pkg}Dashboard::dashboard",
        'admin'     => "${pkg}Dashboard::dashboard",

        ## Generic handlers
        'save'          => "${pkg}Common::save",
        'edit'          => "${pkg}Common::edit",
        'view'          => "${pkg}Common::edit",
        'list'          => "${pkg}Common::list",
# ...

$pkgは'$Core::MT::CMS::'ですので、__mode=dashboard のコードは MT::CMS::Dashboard(ファイルは mt_dir/lib/MT/CMS/Dashboard.pm)の sub dashboard{} がその動作を定義している箇所になります。ダッシュボードの動作で何らかのエラーや確認したい点がある時は、この部分のコードを見ていくということになります。

各プラグインでは以下のように定義されています。

applications:
    cms:
        methods:
            powercms_foo: $PowerCMS::PowerCMS::CMS::powercms_foo

この場合、PowerCMS::PowerCMS::CMS(ファイルは通常 mt_dir/addons/PowerCMS.pack/lib/PowerCMS/CMS.pm もしくは mt_dir/plugins/PowerCMS/lib/PowerCMS/CMS.pmになります)の sub powercms_foo{} がコードになります。

注意したいのは、例えば core_method の save メソッドは

        'save'          => "${pkg}Common::save",

とありますので、MT::CMS::Common の sub save{}がコードの実体ですが、mt_dir/lib/MT/CMS/Common.pm の該当箇所は次のようになっています。

sub save {
    my $app  = shift;
    my $q    = $app->param;
    my $type = $q->param('_type');

    return $app->errtrans("Invalid request.")
        unless $type;

    # being a general-purpose method, lets look for a mode handler
    # that is specifically for editing this type. if we find it,
    # reroute to it.

    my $save_mode = 'save_' . $type;
    if ( my $hdlrs = $app->handlers_for_mode($save_mode) ) {
        return $app->forward($save_mode);
    }
# ...

このメソッドへのリクエストは __mode=save&_type=entry のように_typeパラメタを持ちます(実際はpostリクエストなのでブラウザのアドレスバー等で見かけることはありません)。 つまりこのケースでの変数 $save_mode は 'save_entry' となります。

    if ( my $hdlrs = $app->handlers_for_mode($save_mode) ) {
        return $app->forward($save_mode);
    }

ここで該当するメソッド save_entry が存在するかどうかを調べ、存在すれば $app->forward($save_mode) しています(※そのメソッドに処理をforwardする)。

再び sub core_methods を確認します。以下のように save_entry が存在します。

        'save_entry'   => "${pkg}Entry::save",

つまり、__mode=save&_type=entry で実行されるコードの実体は、MT::CMS::Common の sub save{}ではなく(正確には、このコードを途中まで経由してから別のところへ処理が丸投げされている)、MT::CMS::Entry(ファイルは mt_dir/lib/MT/CMS/Entry.pm)) の sub save{} ということになります。

該当するモードの調べ方

1. ブラウザのアドレスバーで確認する
   getリクエストの場合、はこれで確認できます。
   http://www.example.com/mt_dir/mt.cgi?__mode=foo&_type=bar&id=buz&blog_id=1
2. メソッドを呼び出す直前の画面ソースの form のinput要素(type="hidden" name="__mode")の値を確認する
   ※postの前にJavaScriptで値を書き換えるケースもあるので注意が必要です。
3. ログを取って確認する
   postリクエストの場合では、例えば下記のようなプラグインを書いてプラグインディレクトリに設置し、リクエスト後にシステムログを見て確認します。

name: Debug
id:   Debug
callbacks:
    MT::App::CMS::pre_run: >
        sub {
            my $app = MT->instance;
            $app->log( 'query_string:' . $app->query_string );
            $app->log( 'mode:' . $app->mode );
        }

modeが確認できたら、MT::App::CMS::core_methods もしくはプラグインのregistryの定義を確認して、該当の処理がどこに書かれているかを確認し、処理内容を追っていきます。

該当箇所の特定

MT、もしくはMTにおけるメソッドの話に限りませんが、アプリケーションのファイルが膨大な数になってくると該当の箇所を探すのも大変です。何らかの調査をおこなう際に「箇所を効率良く特定する」ことが大切です。「プラグインでエラーが発生しました」もしくはソースコードの特定の行数がログに残っている場合などは良いのですが、単にエラーが返されたときや手がかりが少ないときなどはエラーメッセージやログに表示されている文字列がヒントに、該当の箇所を特定します。

findコマンドでソースコード内の文字列を grepする

cd /path/to/mt_dir/lib
find . -name "*.pm"|xargs grep 'This is test.'

このコマンドはマッチしたファイル、マッチした箇所前後の文字列を返してくれます。

言語ファイルから特定する

例えば「データベースのエラーでログインを確認できませんでした: ...」というエラーメッセージに遭遇したとします。ユーザーの言語設定が日本語の場合、エラーメッセージは日本語です。mt_dir/lib/MT/L10N/ja.pm を確認して該当のメッセージのオリジナル(英語)の表現を検索します(この検索はテキストエディタ等で行えます)。

    'The login could not be confirmed because of a database error ([_1])' => 'データベースのエラーでログインを確認できませんでした: [_1]',

オリジナルのメッセージを確認できたら先ほどの findコマンドで grepします。

find . -name "*.pm"|xargs grep 'The login could not be confirmed because of a database error'

./lib/MT/App.pm: "The login could not be confirmed because of a database error ([_1])",
./lib/MT/L10N/de.pm:	'The login could not be confirmed because of a database error ([_1])' => 'Anmeldung konnte aufgrund eines Datenbankfehlers nicht durchgeführt werden ([_1])',
./lib/MT/L10N/es.pm:	'The login could not be confirmed because of a database error ([_1])' => 'No se pudo confirmar el acceso debido a un error de la base de datos ([_1])',
./lib/MT/L10N/fr.pm:	'The login could not be confirmed because of a database error ([_1])' => 'L\'identifiant ne peut pas être confirmé en raison d\'une erreur de base de données ([_1])',
./lib/MT/L10N/ja.pm:	'The login could not be confirmed because of a database error ([_1])' => 'データベースのエラーでログインを確認できませんでした: [_1]',
./lib/MT/L10N/nl.pm:	'The login could not be confirmed because of a database error ([_1])' => 'Het aanmelden kon niet worden bevestigd wegens een databaseprobleem ([_1])',

./MT/App.pm以外はすべて言語ファイルなので、該当のエラーは mt_dir/lib/MT/App.pm 内で発生したことがわかります。

おおまかに問題の発生箇所が特定できたら、デバッグログを記録したり、画面に実行状況をフィードバックさせたりしながら検証していきます。

システムログへの保存

先ほど、モードの特定のためのプラグインの例をあげました。システムログへのメッセージの保存は最も手軽なデバッグ方法の一つです。

該当箇所のエラー発生の直前、もしくはモードの先頭箇所からいくつかのポイントに、

MT->log( 'Step 1' );

もしくは

$app->log( 'Step 1' );

といった形でログを残していき、どこまでが正常に実行されたかを特定していきます。

変数の内容を確認したい時には、Data::Dumperモジュールを使うと便利です。例えば変数 $entry が正しくセットされていない時に $entry->id をコールすると

エラーが発生しました: Can't call method "id" on an undefined value at (eval 363) line 1.

のような形でエラーになります。MTのエラー画面にこれが表示されるかシステムログに表示されるかは実行されている処理の種類によります。基本的にメソッドの中で発生した場合はMTのエラー画面にメッセージが表示されます。一方、プラグインによるコールバックの処理などで発生した場合にはシステムログに記録されます(この場合はプラグイン名があわせて記録されるため、特定は比較的容易です)。

変数 $entry が正しくセットされているかをログに残すには、Data::Dumperを用いて以下のようにします。

use Data::Dumper;
MT->log( Dumper $entry );

リアルタイムにフィードバックを得る

MTのシステムログにエラーを表示する方法は手軽ではありますが、実はやってみると結構面倒です。

1. デバッグログ記録のためのコードを入れる
2. ブラウザで当該の処理を実行する
3. システムログをみる

リアルタイムに状態を確認するにはいくつかの方法があります。

メソッドの中で得たい結果を return する

メソッドの実行結果はメソッドのルーチンの中で return したタイミングでブラウザに返されます。 よって、メソッドの中で、

return 'Step 1';

とすればブラウザに結果が返ります。 変数の確認についても先ほどの例と同様に

use Data::Dumper;
return Dumper $entry;

とすれば結果をブラウザでリアルタイムに得ることができます。

強制的にdieする

メソッドから呼ばれているサブルーチンの中では return $foo; が使えないケースがあります。サブルーチンの実行結果をメインルーチンは受け取るだけ、といったケースでは return $foo; は使えません。

この場合は、サブルーチンの中で dieすることでMTのエラーメッセージに確認したい内容を渡すことが出来ます。

die 'Step 1';

または

use Data::Dumper;
die Dumper $entry;

warnings(Perlの警告)を使って確認する

この方法が最も簡単で多くの内容を確認できる方法でです。return や die を使う方法のように、1度に1つの結果しか得られないこともありませんし、システムログのように画面を遷移して結果を確認する必要もありません。また、1度のリクエストの処理に1秒かからなければ、システムログの画面での記録されたログの記録順を確認できないこともあります(同一の秒で保存されたログが保存順に表示されるとは限りません)。

mt-config.cgi に

DebugMode 1

と記述するか、管理画面の全般の設定で、DebugMode を 1に設定します。 あとは、確認したいコードの中に warn $foo; のような形で確認したい内容を吐き出すようにします。

warn 'This is a Debug Message.';

とすると、ブラウザの画面下部に「警告とメッセージ」が表示されます。

Request completed in 1.145 seconds.
This is a Debug Message. at (eval 361) line 1.

尚、DebugMode 2 とするとエラー発生箇所等の情報を画面に表示してくれます。必要に応じて設定しましょう。

• 参考: DebugMode | 環境変数リファレンス