CouchDBのいけていない点 | Show/List の例外デバッグ手法

昔はMapReduceだとかErlangだとかRESTだとか、Append Only Storageだとか、そんな話をしていたんですが、最近では CouchDBLotus Notesアプリケーションサーバーだよ!っていうことが多くなりました。Webというデータベースの世界で、ロジックとデータを切り分ける必要性がそれほどないことは何となく感じているので、これはよいことだと思います。

で、

普通はいいことが多いけれども、こういう制限事項があるとか、短所はこうだとか、ベンチマークはこうだとか、何らか具体的記述があってもいいのに、一般論的記述に終始していましたので、逆に胡散臭いものを感じました。

http://slashdot.jp/~taro-nishino/journal/493582

ということで、ミゼラブルな点をば。あ、でも、あくまでアプリケーションサーバーとしてのCouchDBの話です。


CouchDB はダイナミックにJavaScriptプロセスプールに関数を送り込み実行します。そして、プログラミングのミスで例外が起こると、ある一定条件の下で*1プロセス管理モジュールの方がJavaScriptプロセスからの応答がない、といって以下のJSONをクライアント側に返してしまいます。

{"error":"normal","reason":"{gen_server,call,\n
            [couch_query_servers,\n
             {ret_proc,{proc,<0.83.0>,<<\"javascript\">>,\n
                             {couch_os_process,prompt},\n
                             {couch_os_process,set_timeout},\n
                             {couch_os_process,stop}}}]}"}

このメッセージが出るときは、CouchDBのログを見るのですが、CouchDBやってらんねーぜ! っていうミゼラブルな状況に陥ります。ロゴのリラックスマンがイラっとくるのです。ということで、りらーくす、りらーくす、といって対応します。

そもそもミゼラブルの主因は、CouchDBJavaScriptプロセスがスタックトレースを全部はき出してくれるのと、Erlang の側でもタイムアウトを起こしたソースコードを全部はき出してくれるのが問題なのです。

[info] [<0.83.0>] OS Process :: stacktrace: ([object Object],"type")@:1329
...(ここにスタックトレース)...
OS Process Error ::
...(ここにタイムアウトを発生させたソースコード)...

今、私の手元のshow関数は、emacs上では50行もないのですが、!code マクロを使ってファイルを分割しているからです。これが、CouchDBにデプロイするときは連結されて、1500行程度になります。なので、エラーが起こると1500行 x 2 = 3000行 が一気にログにはき出される、、、やってられません。

というわけで、開発するときは真っ先に以下を行うべきです。

  1. src/couchdb/couch_os_process.erl の "OS Process Error" のエラー出力の行をコメントアウトする。
  2. share/server/main.js のスタックトレース出力を抑制する。

1. に関しては couch_os_process.erl を grep すればわかります。0.10.0 の場合は56行目をコメントアウトします。Erlangコメントアウトは % です。

55:        Error ->
56:            % ?LOG_ERROR("OS Process Error :: ~p",[Error]),
57:            throw(Error)

2. に関しては、respondError という関数に、スタックトレース出力のコードがあります。

    var logMessage = "function raised error: "+e.toString();
    log(logMessage);
    log("stacktrace: "+ e.stack);

とりあえず、スタックの先頭から5つぐらい出してくれれば事は足りるので(これは使っているライブラリに依存するかと)、次のようにしました。

    var logMessage = "function raised error: "+e.toString();
    log(logMessage);
     var traces = e.stack.split("\n");
     var c = Math.min(traces.length, 5);
     var displays = new Array(c);
     for(var i=0; i<c; i++){
        displays[i] = traces[i];
     }
    log("stacktrace: "+ displays.join("\n"));

これをすると、スタックが省略されて例外の箇所の特定が難しいんじゃ?と話なのですが、安心してください。別にこんなハックしなくても、SpiderMonkeyの例外機構は元々貧弱で、

[info] [<0.83.0>] OS Process :: stacktrace: ([object Object],"type")@:1329
([object Object],[object Object])@:615
call([object Object],[object Object],[object Object])@:0
([object Object])@:615

とまぁ、[object Object] ばっかりなので、元々特定が難しいので、そこはりらーくす、と唱えながら感じ取ってやってください。他のJavaScriptエンジンとかはどうなんでしょうね。Server Side JavaScriptが盛り上がってくれれば、徐々に改善されていく気がします。

というわけで、デバッグが死ぬほどミゼラブル、という話を書いてみました。IDEがないとやってらんねーぜ、という人には絶対におすすめできません。

いやー、Ruby/Rails の例外表示機構はよくできていますよね。。たまに戻りたくなります。

*1:ログにスタックをダンプしているためなのか、スタックの深さが一定量を超えてしまう場合とか