トップ 最新 追記   RSS 1.0 FEED  

Journal InTime


2005-02-01 (Tue) [長年日記]

_ [Ruby] プロファイラ

profile.rbがあまりにも遅いのでCで書いてみた。

<URL:http://svn.shugo.net/src/ruby-prof/trunk/>

profile.rbの30倍くらいになったようだ(当社比)。

profile.rb:

$ time ruby -r profile fib.rb
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 75.06     3.13      3.13    21891     0.14     2.58  Object#fib
 10.31     3.56      0.43    21891     0.02     0.02  Fixnum#<
  9.83     3.97      0.41    21890     0.02     0.02  Fixnum#-
  4.80     4.17      0.20    10945     0.02     0.02  Fixnum#+
  0.00     4.17      0.00        1     0.00     0.00  Fixnum#to_s
  0.00     4.17      0.00        2     0.00     0.00  IO#write
  0.00     4.17      0.00        1     0.00     0.00  Module#method_added
  0.00     4.17      0.00        1     0.00     0.00  Kernel.print
  0.00     4.17      0.00        1     0.00     0.00  Profiler__.start_profile
  0.00     4.17      0.00        1     0.00  4170.00  #toplevel
6765

real	0m4.307s
user	0m4.172s
sys	0m0.071s

prof.so:

$ time ruby -r doprof fib.rb
6765
  %%   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
100.00    0.050     0.050    21891    0.002    0.032  Object#fib
  0.00    0.050     0.000        1    0.000   50.000  #toplevel
  0.00    0.050     0.000        1    0.000    0.000  Kernel.print
  0.00    0.050     0.000    21890    0.000    0.000  Fixnum#-
  0.00    0.050     0.000        2    0.000    0.000  IO#write
  0.00    0.050     0.000        1    0.000    0.000  Module#method_added
  0.00    0.050     0.000    10945    0.000    0.000  Fixnum#+
  0.00    0.050     0.000    21891    0.000    0.000  Fixnum#<
  0.00    0.050     0.000        1    0.000    0.000  Fixnum#to_s

real	0m0.128s
user	0m0.057s
sys	0m0.069s

難点はRubyにパッチをあてる必要があること。 call_trace_func自体が遅いので、こればっかりはどうしようもない。 staticじゃなかったらLD_PRELOADで何とかなるかもしれないけど。

本日のツッコミ(全4件) [ツッコミを入れる]

_ まつもと [うーむ、30倍。標準添付するか。 AspectRのプロファイラを導入するのとどっちが良いか。 あっちはRubyで書い..]

_ shugo [プロファイラはともかく、Cレベルでフックがかけられる機能があるとうれしいです。APIはもうちょっと検討しないといけな..]

_ ささだ [ruby のどの辺にパッチが要るんですか?]

_ shugo [このへんです。 http://svn.shugo.net/src/ruby-prof/trunk/ruby-1.9..]


2005-02-02 (Wed) [長年日記]

_ [Ruby] プロファイラ(2)

profile.rbがあまりにも遅いのでCで書いてみた。

[Journal InTime - プロファイラより引用]

やはりバグ*1が あったので修正。

ついでに、Windowsだとtimes(2)がないようなので、clock(3)を使うよう変更。

あと、

$ ruby -r doprofreal -e 'sleep(0.1)'
  %%   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 99.93     0.10      0.10        1   99.061   99.061  Kernel.sleep
  0.07     0.10      0.00        1    0.071   99.132  #toplevel

のように実時間で計測できるようにしてみた。

*1  Ruby 1.9用のパッチではreturnのトレースが足りなかった。

_ [その他] Matzにっきのコメント欄の登場人物

会社の後輩の多くが、Matzにっきにコメントを書いているkazuhoさんかずひこさんだと思っていたのを知りびっくり。 ぜんぜんキャラ違うじゃん。 ちなみに、maedaさんは私じゃないですよ。 こちらはだれも私だと思ってなかったみたいだけど。

本日のツッコミ(全6件) [ツッコミを入れる]

_ 上司 [それはあんまりだ。人を見る目を養う研修が必要か。]

_ ささだ [どんな研修になるんでしょう・・・.]

_ まつもと [「ゆきひろ」と「ひろゆき」を区別したり、「kazuhiko」と「kazuho」を区別したりするんでしょう。]

_ ただただし [そういう能力を養うには2chが最適?]

_ おくじ [面白すぎます。ネタじゃないんですか?]

_ shugo [ネタじゃないんですよね、これがまた。 しかも、自分も「ひろゆき」は経験があったりするので人のことは言えないという。]


2005-02-03 (Thu) [長年日記]

_ [ソフトウェア] 本日のリンク元

サーバの負荷が異常に高いので、試しに本日のリンク元を非表示にしてみた。


2005-02-08 (Tue) [長年日記]

_ [Debian] libapr0とapr_off_t

Debianのlibapr0は(少なくともi386だと)apr_off_tが32ビットなので、 2GBを超えるファイルが上手く扱えない(apr_file_seekできない)ようだ。 うーん。

本日のツッコミ(全1件) [ツッコミを入れる]

_ yohgaki [Momonga Linuxのtrunk版はlarge fileに対応しています。使えるISOが公開されていませんが...]


2005-02-09 (Wed) [長年日記]

_ [C] エラー出力用マクロで可変長引数を使わずに__FILE__や__LINE__を埋め込む

Subversionのコードを読んでいて、GCC拡張やC99の可変長引数マクロを使わずに、 エラー出力用マクロで__FILE__や__LINE__を埋め込む方法を発見。

まず、次のようにエラー出力用の関数を用意しておく。

error.c:

#include <stdio.h>
#include <stdarg.h>

static const char *error_file = NULL;
static int error_line = -1;

void
my_error_locate(const char *file, int line)
{
    error_file = file;
    error_line = line;
}

void
my_error(const char *fmt, ...)
{
    va_list ap;

    fprintf(stderr, "%s:%d: ", error_file, error_line);
    va_start(ap, fmt);
    vfprintf(stderr, fmt, ap);
    va_end(ap);
    fprintf(stderr, "\n");
}

そして、おもむろに次のようなマクロを定義。

error.h:

void my_error_locate(const char *file, int line);
void my_error(const char *fmt, ...);

#define error (my_error_locate(__FILE__, __LINE__), my_error)

あとは、このマクロをprintfのように使えばよい。

error_test.c:

#include <stdio.h>
#include "error.h"

int
main()
{
    error("error - %d", 12345);
    return 0;
}

コンパイル時に-ansi -pendanticを付けても文句を言われない。

$ gcc -ansi -pedantic -Wall error.c error_test.c -o error_test

実行すると、当然ちゃんとファイル名と行番号が出る。

$ ./error_test
error_test.c:7: error - 12345

念のため動作原理を説明すると、

error("error - %d", 12345);

は展開されると、

(my_error_locate("error_test.c", 7), my_error)("error - %d", 12345);

のようになる。 my_error_locate()はstaticな変数にファイル名と行番号を格納する。 問題はその後だ。 カンマ演算子は左から右に評価されて、最後に評価された式の値が全体の値となる。 したがって、(..., my_error)の値はmy_errorの値、すなわち、 my_error()を指す関数ポインタになる。 その後で括弧が続いているということは・・・ そう、関数ポインタを経由したmy_error()の呼び出しになっているのだ。

#define error (*(my_error_locate(__FILE__, __LINE__), my_error))

と書いた方がわかりやすいかもしれない。 で、my_error()の中では、my_error_locate()が値をセットしたstaticな 変数を参照しているので、ファイル名と行番号をちゃんと表示できるというわけ。 よくできてますよね。

ちなみに、スレッドセーフじゃないんじゃ・・・というのが誰もが考えるところ だろうが、Subversionのコードには以下のようなコメントが書いてあった。

void
svn_error__locate (const char *file, long line)
{
  /* XXX TODO: Lock mutex here */
  error_file = file;
  error_line = line;
}
本日のツッコミ(全1件) [ツッコミを入れる]

_ moris [この方法でソース中に埋め込んだ全デバックを、一括で無効にしたい場合にいい方法はありますか?]


2005-02-11 (Fri) [長年日記]

_ [ソフトウェア] mod_ftpd

会社の後輩に作ったらどうかと言っていたのだが、すでにあったようだ。 mod_pop3なんてのもあるらしい。 ではIMAPも、と思って、mod_imapを見つけた方はちょっと違うので要注意。


2005-02-12 (Sat) [長年日記]

_ [その他] 「ツァラトゥストラはかく語りき」ナムコの商標です(予定)

ナムコがゲームの商標として「ツァラトゥストラはかく語りき」を出願してたそうだ。

[スラッシュドット ジャパン | 「ツァラトゥストラはかく語りき」はナムコの商標です(予定)より引用]

岡嶋二人のゲームブックでそんなのなかったっけ。

本日のツッコミ(全1件) [ツッコミを入れる]

_ サイロス誠 [講談社から出ていた「ツァラトゥストラの翼」ですね。 謎解きに使う暗号が難しすぎて講談社にヘルプの郵便が多数届いたとい..]


2005-02-22 (Tue) [長年日記]

_ [仕事] busy

ぜんぜん他のことに手が回らない。何かいろいろ(おもに英語の)メールもらってるけど返事できず。

やっぱりチームで仕事をするのは大変だ。 でもいつまでも個人プレーにばかり頼っているわけにもいかない。 ここがふんばりどころ。