Apacheモジュールの作成とgdbとloggerでのデバッグ方法
ApacheのFilterモジュールを作った話しをしたらid:c9katayamaに情報公開しろと言われたままでしたので公開します。
C言語の勉強しようかな、Apache2.xのモジュールを作ってみようかな、gdb使ってデバッグしてみようかなと考えてた人にお勧めです。
JavaでのServletの開発経験のある人であれば、Filterの処理の動きやリクエストコンテキストの考え方は分かり易いはずなので、エントリを読み終わる頃にはApacheのモジュールをgdbでデバッグしながら作る事が出来るはずです。
mod_orzを作成
今回はmod_orzというApacheモジュールを作成します。
Apacheモジュールを作成する際には、apxsというモジュール開発用のコマンドを使用しテンプレートを作ります。
# apxs -g -n orz Creating [DIR] orz Creating [FILE] orz/Makefile Creating [FILE] orz/modules.mk Creating [FILE] orz/mod_orz.c Creating [FILE] orz/.deps # ls orz Makefile mod_orz.c modules.mk
コマンド引数-gでテンプレート出力、-nでモジュール名を指定するとorzフォルダが作成され、その中にモジュールのテンプレートが出来上がります。
このままでもサンプルとして動きますがmod_orzらしく表示させたいのでmod_orz.cのorz_handlerを以下のように変えます。
static int orz_handler(request_rec *r) { if (strcmp(r->handler, "orz")) { return DECLINED; } r->content_type = "text/html"; if (!r->header_only) { int i = 0; for (i = 0; i <= 100; i++) { ap_rputs("orz ", r); } } return OK; }
コンパイルする際にはmake installでも可能ですが、apacheの設定ファイル(httpd.conf)にLoadModuleディレクティブを追加しmodulesディレクトリにモジュールもコピーしたいのでapxsコマンドを使用します。
# apxs -i -a -c mod_orz.c
コマンド引数-iでmodulesにコピー、-aでhttpd.confにLodModuleディレクティブ追加、-cでコンパイルです。
一応、nmで確認しましょう。
# nm /usr/local/apache2/modules/mod_orz.so | grep orz 00000470 t orz_handler 000016a0 D orz_module 00000430 t orz_register_hooks
ここまで来たら、あとはhttpd.confに以下の設定を追加します。
<Location "/orz/"> SetHandler orz </Location>
これで /orz/ のリクエストに対し作成したmod_orzモジュールが呼び出されます。
apacheを再起動し、http://アパッチのサーバ/orz/ にアクセスするとorzが100回表示されているのが分かると思います。
表示されていますね！
C言語もApacheモジュール作成も初めての人でも5分足らずでモジュール作成出来たと思います。
Apacheモジュールのデバッグ方法(stderr/ap_log_rerror/customlog/gdb)
Error Log
gdbでデバッグする前に、まずはfprintfを使ってデバッグしてみます。
mod_orz.cのfor文の中に以下を追加しループカウンタをデバッグします。
fprintf(stderr, "i=[%d]\n", i);
追加後にapxs -i -a -c mod_orz.cを実行し、error_logをtailしながらデバッグします
先ほどのページにアクセスすると、error_logにループカウンタが表示されるのが分かると思います。
※apacheを-X付きの内部デバッグ用としてシングルプロセスモード（子プロセスはforkしない）で実行する必要があります
Apache API ap_log_rerror
httplog.hにある、Apache APIのap_log_rerrorを使います。
#include "http_log.h" // さっきのループカウンタをap_log_rerrorで出力 ap_log_rerror(APLOG_MARK, APLOG_CRIT, 0, r, "use ap_log_error:[%d]", i);
ap_log_rerrorを使うと時間付きでerror_logに出力されます。
[Mon May 11 23:10:02 2009] [crit] [client 192.168.56.101] use ap_log_error:[100]
第2引数を切り替えてinfo, debguも出力出来ます。
APLOG_MARKマクロはデバッグした場合にファイル名と行数も出力されます。
#define APLOG_MARK __FILE__,__LINE__
出力例
[Mon May 11 23:10:02 2009] [debug] mod_orz.c(61): [client 192.168.56.101] 111:[1]
Custom Log
Custom Logへモジュールからログを出力するには、メモ領域であるrequest_rec->notes（リクエストコンテキストのノート）を使います。
Apache API（apr_table_set/apr_table_get)には、内部にkey=value形式で値を保持しておけるので各フェーズで値を共有することも可能です。
このkey=value形式のtableを使ってモジュールからCustom Logへログ出力を行います。
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{MyMessage}n\"" common
- mod_orz.c（プログラムからはノート(r->notes)にメッセージを設定します）
apr_table_set(r->notes, "MyMessage", "CustomeMessage!!!");
192.168.56.101 - - [11/May/2009:23:35:26 +0900] "GET /orz/ HTTP/1.1" 200 404 "CustomMessage"
この、Hash領域からは、エラー情報も取得出来ます。
err_msg = apr_table_get(r->notes, "error-notes");
但し、このtabelから取得したメッセージはエスケープされていないので直接HTMLに出力する際はエスケープ処理を入れて下さい。
gdbでデバッグ
デバッグする際に、ブレークポイントを設定したい、ステップ実行したいという方にはgdbでのデバッグをお勧めします。
gdbに関しては、こちらがお勧めです。
- 作者: リチャードストールマン,ローランドペシュ,Richard M. Stallman,Roland H. Pesch,コスモプラネット
- 出版社/メーカー: アスキー
- 発売日: 1999/01
- メディア: 単行本
- 購入: 4人 クリック: 64回
- この商品を含むブログ (14件) を見る
gdbを起動します
# gdb /usr/local/apache2/bin/httpd
orz_handlerメソッドにブレイクポイントを仕掛けます（bはbreakのalias）
(gdb) b orz_handler
引数-X付きで起動（rはrunのalias）
(gdb) r -X
この状態で、http://アパッチサーバ/orz/ にアクセスすると、ブラウザは応答待ちでgdbのコンソールに処理が戻ります。
Breakpoint 1, orz_handler (r=0x9feb2d0) at mod_orz.c:49 49 if (strcmp(r->handler, "orz")) { (gdb)
ここで、ステップ実行します（nはnextのalias）
(gdb) n 54 if (!r->header_only) { (gdb) n 52 r->content_type = "text/html"; (gdb) n 54 if (!r->header_only) {
ステップ実行しているのが分かると思います。どんどん実行してループに入ります
(gdb) n 58 ap_log_rerror(APLOG_MARK, APLOG_CRIT, 0, r, "use ap_log_error:[%d]", i);
この時に、ループカウンタを表示させてみます（pはprintのalias）
(gdb) p i $1 = 1
(gdb) n 56 for (i = 0; i <= 100; i++) { (gdb) p i $4 = 4
さすがに100回もループさせるのもしんどいので、ループを抜けます（uはuntilのalias）
(gdb) n 56 for (i = 0; i <= 100; i++) { (gdb) u 60 apr_table_set(r->notes, "MyMessage", "CustomMessage");
ここでリクエストコンテキスト（request_rec）の中身を見てみます。p *r と打ってください。
(gdb) p *r $5 = {pool = 0x8add298, connection = 0x8ad9458, server = 0x8a2f188, next = 0x0, prev = 0x0, main = 0x0, the_request = 0x8ade0b8 "GET /orz/ HTTP/1.1", assbackwards = 0, proxyreq = 0, header_only = 0, protocol = 0x8ade128 "HTTP/1.1", proto_num = 1001, hostname = 0x8ade4c0 "192.168.56.102", request_time = 1242663142199134, status_line = 0x0, status = 200, method = 0x8ade108 "GET", method_number = 0, allowed = 0, allowed_xmethods = 0x0, allowed_methods = 0x8add470, sent_bodyct = 0, bytes_sent = 0, mtime = 0, chunked = 0, range = 0x0, clength = 0, remaining = 0, read_length = 0, read_body = 0, read_chunked = 0, expecting_100 = 0, headers_in = 0x8add4a0, headers_out = 0x8add930, err_headers_out = 0x8addad8, subprocess_env = 0x8add6e8, notes = 0x8addc30, content_type = 0xf69654 "text/html", handler = 0x8aad910 "orz", content_encoding = 0x0, content_languages = 0x0, vlist_validator = 0x0, user = 0x0, ap_auth_type = 0x0, no_cache = 0, no_local_copy = 0, unparsed_uri = 0x8ade118 "/orz/", uri = 0x8ade120 "/orz/", filename = 0x8ade7f0 "/usr/local/apache2/htdocs/orz", canonical_filename = 0x8ade7f0 "/usr/local/apache2/htdocs/orz", path_info = 0x8ade78d "/", args = 0x0, finfo = {pool = 0x8add298, valid = 7598448, protection = 1877, filetype = APR_NOFILE, user = 0, group = 0, inode = 1579484, device = 64768, nlink = 2, size = 4096, csize = 623422955655647896, atime = 1242586928000000, mtime = 1228576600000000, ctime = 1242545432000000, fname = 0x8ade7f0 "/usr/local/apache2/htdocs/orz", name = 0x8aada00 "/usr/local/apache2/htdocs", filehand = 0x8ade125}, parsed_uri = {scheme = 0x0, hostinfo = 0x0, user = 0x0, password = 0x0, hostname = 0x0, port_str = 0x0, path = 0x8ade120 "/orz/", query = 0x0, fragment = 0x0, hostent = 0x0, port = 0, is_initialized = 1, dns_looked_up = 0, dns_resolved = 0}, used_path_info = 2, per_dir_config = 0x8adeca0, request_config = 0x8addd88, htaccess = 0x0, output_filters = 0x8ade038, input_filters = 0x8ade4d0, proto_output_filters = 0x8ade038, proto_input_filters = 0x8ade4d0, eos_sent = 0}
request_recには、かなりの情報が格納されています。apacheの構造の理解を深めるにはgdbで都度確認してみると良いでしょう。
見難い場合には、以下の設定(set print pretty on)で改行され見やすくなります。
(gdb) set print pretty on (gdb) p *r $6 = { pool = 0x8485298, connection = 0x8481458, server = 0x83d7188, next = 0x0, prev = 0x0, main = 0x0, the_request = 0x84860b8 "GET /orz/ HTTP/1.1", assbackwards = 0, proxyreq = 0, header_only = 0, protocol = 0x8486128 "HTTP/1.1", proto_num = 1001, hostname = 0x84864c0 "192.168.56.102", request_time = 1242663810469588, status_line = 0x0, status = 200, method = 0x8486108 "GET", method_number = 0, allowed = 0, allowed_xmethods = 0x0, allowed_methods = 0x8485470, sent_bodyct = 0, bytes_sent = 0, mtime = 0, chunked = 0, range = 0x0, clength = 0, remaining = 0, read_length = 0, read_body = 0, read_chunked = 0, expecting_100 = 0, headers_in = 0x84854a0, headers_out = 0x8485930, err_headers_out = 0x8485ad8, subprocess_env = 0x84856e8, notes = 0x8485c30, content_type = 0x0, handler = 0x8455910 "orz", content_encoding = 0x0, content_languages = 0x0, vlist_validator = 0x0, user = 0x0, ap_auth_type = 0x0, no_cache = 0, no_local_copy = 0, unparsed_uri = 0x8486118 "/orz/", uri = 0x8486120 "/orz/", filename = 0x84867f0 "/usr/local/apache2/htdocs/orz", canonical_filename = 0x84867f0 "/usr/local/apache2/htdocs/orz", path_info = 0x848678d "/", args = 0x0, finfo = { pool = 0x8485298, valid = 7598448, protection = 1877, filetype = APR_NOFILE, user = 0, group = 0, inode = 1579484, device = 64768, nlink = 2, size = 4096, csize = 594853245512864408, atime = 1242586928000000, mtime = 1228576600000000, ctime = 1242545432000000, fname = 0x84867f0 "/usr/local/apache2/htdocs/orz", name = 0x8455a00 "/usr/local/apache2/htdocs", filehand = 0x8486125 }, parsed_uri = { scheme = 0x0, hostinfo = 0x0, user = 0x0, password = 0x0, hostname = 0x0, port_str = 0x0, path = 0x8486120 "/orz/", query = 0x0, fragment = 0x0, hostent = 0x0, port = 0, is_initialized = 1, dns_looked_up = 0, dns_resolved = 0 }, used_path_info = 2, per_dir_config = 0x8486ca0, request_config = 0x8485d88, htaccess = 0x0, output_filters = 0x8486038, input_filters = 0x84864d0, proto_output_filters = 0x8486038, proto_input_filters = 0x84864d0, eos_sent = 0 }
最後にc（continue）して処理を終わらせるとブラウザにorzが表示されるのが分かると思います。
(gdb) c Continuing.
gdbは、とても便利なデバッガですので触ってみようかなぁと思っていた人にはお勧めです。
