dtrace
/usr/ports 方面では、jpeg とか xorgでお祭になっていたようだけど、私は淡々と portupgrade しましたよ。そしたら、nmapが月(lua)を伴って、やって来ました。 configureの最終画面が、AA だったので、記念撮影しておきます。(笑)
config.status: creating config.h . . \`-"'"-'/ } 6 6 { ==. Y ,== /^^^\ . / \ ) Ncat: A modern interpretation of classic Netcat ( )-( )/ -""---""--- / / Ncat \_/ ( ____ \_.=|____E Configuration complete. ( ) /\ _ ( \ | ( \ ( \.( ) _____ \ \ \ ` ` ) \ ( ___ / _ \ (_` \+ . x ( .\ \/ \____-----------/ (o) \_ - .- \+ ; ( O \____ (__ +- .( -'.- <. \_____________ ` \ / (_____ ._._: <_ - <- _- _ VVVVVVV VV V\ \/ . /./.+- . .- / +-- - . (--_AAAAAAA__A_/ | (__ ' /x / x _/ ( \______________//_ \_______ , x / ( ' . / . / \___' \ / / / _/ / + | \ / ' (__/ / \/ / \ NMAP IS A POWERFUL TOOL -- USE CAREFULLY AND RESPONSIBLY Configuration complete. Type make (or gmake on some *BSD machines) to compile.
apt-get dist-upgrade とかだと、作者の息吹が感じられなくてつまんないけど、srcから だと、こういう楽しみがあって、好きだったりします。それにしても、作者さんは、2chで修行したのだろうか? それとも、寄贈品?
dtrace
風の噂では、ruby-1.9.2 で、dtrace をサポートするそうだ。プローブを埋め込んで びしばしと鍛えあげようって算段なのでしょうか。それとも、macruby方面からの圧力で ruby.specに盛り込まれたので、MRIでも実現せにゃとなったのでしょうか?
プローブって、オシロスコープに観測したい電気信号を導くための針の事です。えっ、 オシロスコープを知らないって? そんなら、SICP本のp165に例が出てますね。言って みれば、debug-printか。但し、debug-printだとユーザーが必要そうな所に埋め込んで あげなければならないし、enable/disableも面倒。得られた結果を統計処理(何回、Hit したか等)したいなんてのは、夢のまた夢であったりする。
dtraceは、これらの難題を統一的に解決する仕組みだ。D言語を使ってスクリプト化して おけるし、LLみたいにその場で臨機応変にプローブを活性化してデータ採取しても良い。 勿論、必要そうな所にあらかじめプローブが埋め込まれている。どんなプローブが必要か は、OS屋さん(かどうかは知らないけれど)が決めて、埋め込んでくれている。
dtraceとかzfsは、Sunで開発されて、FreeBSDとかMacには取り込まれているけど、 主義主張が違うLinux方面には、取り込めないみたいです。まあ、目玉の多いLinux 方面ですから、SystemTap なるものが作られています。
Tapって、怪しい雰囲気で好きだなあ。電話線に針を立てたりして。。こういうのは公安の 得意技かな。おいらは、黄色く太いケーブルに、よく針を立ててトランシーバーを 取り付け、パソコンをネット参加させたものです。今の人は知らないだろうけど。
偉そうにこんな事を書いてますが、実は私もdtraceを良く知らんのです。この際だから どんな物か少々手をだし手みる事にします。
資料など
そりゃ、man dtraceでしょうとなる訳だが、ちと歯が立たない。rubyを使いこなすに man rubyじゃ無理ってのと一緒。相手は何せ、D言語ですからねえ。
Sunのサイトへ資料を探しに行きましたよ。そしたら、何とまあ、真っ赤に紅葉してる じゃないですか。Oracleですって。そのうちに、docs.sun.comのURLも無くなっちゃう んでしょうか? 一抹の寂しさが沸いてきますねぇ。
資料は2つ DTrace ユーザーガイドと Solaris 動的トレースガイド。 前者の方で概要を掴んで、後者は詳細を調べるって使い方になるかな。 仕組みについての、 技術的説明はここが参考になります。
参考と言いつつ、いきなりチョモランマまで征服するような飛ばしっぷりで、中高年は 途中で遭難しかねません。まずは、近くの山で足腰を鍛えてからにしますかね。 東京周辺では、ハイヒールでも登っちゃう高尾山ぐらいからですかね。(って、山を 舐めたら、遭難するぜー。せいぜい、ゼイゼイしない、山からですかね)
と思っていたら、トレーニング用も用意されて いました。ありがたい事です。更にはいろいろと 楽しい記事が満載されてました。 もう、自分で実験してみる事は無いかな?
いやいや、科学の進歩は、追試による所も多いので。。。
dtrace追試
まずは、型通り、どんなプローブがあるか調べてみます。
sakae@solaris:~/DTRACE$ dtrace -l | head dtrace: failed to initialize dtrace: DTrace requires additional privileges
型通りにエラーになりました。そう、普通のユーザーにはセキュリティーの観点から 使用を禁止されてます。その事を上のエラーから読み取れたら、以下は読まなくて結構。 そんじゃ一応root権限でやります。
root@solaris:~/DTRACE# dtrace -l | head -5 ID PROVIDER MODULE FUNCTION NAME 1 dtrace BEGIN 2 dtrace END 3 dtrace ERROR 4 fbt bl bl_attach entry root@solaris:~/DTRACE# dtrace -l | tail -5 60779 lockstat genunix rw_tryupgrade rw-upgrade 60780 lockstat genunix rw_downgrade rw-downgrade 60781 lockstat genunix thread_lock thread-spin 60782 lockstat genunix thread_lock_high thread-spin 61789 profile tick-1sec
プローブのリストです。非常にたくさん(私の所では、6万個以上ありました)あるので 最初と最後を出してみました。 いろいろな目的のプローブがあるので、ユーザーが迷わないように階層化されてます。 D言語内でプローブを指定する時は、PROVIDER:MODULE:FUNCTION:NAME という風に 指定します。fbt:bl:bl_attach:entryとかprofile:::tick-1sec みたいにですね。(略記法も あるようですが)
特定の階層に属すのもリストできます。その場合は -P,-m,-f,-nを付けます。
root@solaris:~/DTRACE# dtrace -lm genunix | head -5 ID PROVIDER MODULE FUNCTION NAME 2435 sysinfo genunix mod_remove_by_name modunload 2436 sysinfo genunix mod_uninstall_all modunload 2437 sysinfo genunix modunrload modunload 2438 sysinfo genunix modrload modload
root@solaris:~/DTRACE# cat count.d pid$target:a.out::entry { @counts[probefunc] = count(); } pid$target:a.out::return { }
例に出ていた、D言語スクリプトです。ユーザープログラムの関数呼び出し状況を 調べてくれます。
root@solaris:~/DTRACE# dtrace -s count.d -q -c ../work/mosc 13 ^C __fsr 1 _start 1 main 1 setup_audio 1 fill 2
おお、ちゃんと検査してくれてるよ。_startはいいとして、__fsrて何よ。Solaris特有な もの?
次は、関数の実行時間をレポートするものだ。
root@solaris:~/DTRACE# cat time.d pid$target:a.out::entry { self->ts[probefunc] = timestamp; } pid$target:a.out::return /probefunc != "main"/ { @sum[probefunc] = sum(timestamp - self->ts[probefunc] ); self->ts[probefunc] = 0; }
root@solaris:~/DTRACE# dtrace -s time.d -q -c ../work/mosc 310 __fsr 30886 fill 44913 setup_audio 116918763
出てくる数値は、ナノ秒単位との事。上の例だと、fill関数は、約45マイクロ秒で 実行されてるんだな。
D言語って、進化したawkみたいな言語だな。time.dを例にすれば、指定されたプローブに 出会ったら、ブロック内を実行せよだな。但し /.../で、条件を付けられるよと。
関数に突入した時の時間を、関数名をKeyにした連想配列に記憶。関数からreturn する(但し、main関数以外)時、実行時間を求めてから、加算せよ。 dtraceを終了する時は、今までの結果を出力せよ、と言う、あ、うんの呼吸になってる。 ね、専用のawkでしょ。(BEGINとかENDも指定すれば、ちゃんと動くよ)
awkと言えば、一行野郎がかかせません。もどきのdtraceも勿論使えます。
root@solaris:~/DTRACE# dtrace -n 'pid$target:::entry{}' -c pwd | more dtrace: description 'pid$target:::entry' matched 3419 probes /export/home/sakae/DTRACE CPU ID FUNCTION:NAME 0 61068 tsort:entry 0 61014 set_environ:entry 0 60899 lookup_sym:entry : 0 63150 pthread_setcancelstate:entry 0 63440 lmutex_lock:entry 0 63158 set_cancel_pending_flag:entry 0 63441 lmutex_unlock:entry dtrace: pid 2620 has exited
たかがpwdなれど、内部では呆れるぐらいたくさんの関数が呼びだされていましたよ。
コマンド集を見る
dtraceがスクリプトなら、きっと誰かがそれ用のアプリケーションを書いているに違いない。 誰も、rubyそのものだけじゃ使わないのと一緒だな。
opensolarisの場合は、/opt/DTT以下に、既に準備されてます。 ネット上にも公開されてます。
この下にあるBinの中には、たくさんの*.dがありますが、中には .dと言うサフィックス 無しも混じっています。これって、/usr/bin/bashあたりでdtraceをラッッピングした ものだったりします。
root@solaris:/opt/DTT/Bin# ./dappprof ls anonpgpid.d j_cputime.d php_cpudist.d rb_flow.d swapinfo.d : j_cpudist.d php_calltime.d rb_cputime.d statsnoop zvmstat CALL ELAPSED set_char_quoting 26008 get_quoting_style 26224 __fsr 27492 : quote_name 154025990 sort_files 157179287 print_many_per_line 312593350 print_dir 546241557
プロファイラーですね。
つらつら見てたらスクリプトの名前に、rbとかpyとかで始まるやつがあったよ。これって ひょっとして、ruby用とかpython用?
rubyでもdtrace?
sakae@solaris:/opt/DTT/Ruby$ ls Readme rb_calltime.d rb_flow.d rb_funccalls.d rb_objcpu.d rb_syscalls.d rb_calldist.d rb_cpudist.d rb_flowinfo.d rb_lines.d rb_objnew.d rb_syscolors.d rb_calls.d rb_cputime.d rb_flowtime.d rb_malloc.d rb_stat.d rb_who.d sakae@solaris:/opt/DTT/Ruby$ sakae@solaris:/opt/DTT/Ruby$ more Readme Ruby - DTracing Ruby These scripts trace activity of the Ruby programming language, and require the DTrace Ruby provider written by Joyent. Currently, the DTrace Ruby provider is a seperate download either in patch, source or binary form. Start with the "Ruby DTrace" link on http://dtrace.joyent.com/, and after getting a version running, the scripts in this directory should work. Since the DTrace Ruby provider is under development, there is a chance that it has changed slightly by the time you are reading this, causing these scripts to either break or behave oddly. Firstly, check for newer versions of the DTraceToolkit; if it hasn't been updated and you need to use these scripts immediately, then updating them shouldn't take too long. The following was the state of the provider when these scripts were written - check for changes and update the scripts accordingly, :
つう事で、dtrace入りのrubyを configure --enable-dtrace して、こさえてみました。 早速実験してみます。
sakae@solaris:~/DTRACE$ /usr/local/bin/ruby -v ruby 1.8.6 (2007-03-13 patchlevel 0) [i386-solaris2.11] sakae@solaris:~/DTRACE$ cat func_slow.rb #!/usr/local/bin/ruby -w def func_c print "Function C\n" i = 0 while i < 300000 i = i + 1 j = i + 1 end end def func_b print "Function B\n" i = 0 while i < 200000 i = i + 1 j = i + 1 end func_c end def func_a print "Function A\n" i = 0 while i < 100000 i = i + 1 j = i + 1 end func_b end func_a
dtrace入りのrubyは、ちとVerが古いけど、許してね。 そして、観測用のD言語は
sakae@solaris:~/DTRACE$ cat rb_funccalls.d #!/usr/sbin/dtrace -Zs /* * rb_funccalls.d - count Ruby function (method) calls using DTrace. * Written for the Ruby DTrace provider. * * $Id: rb_funccalls.d 20 2007-09-12 09:28:22Z brendan $ * * This traces activity from all Ruby programs on the system that are * running with Ruby provider support. * * USAGE: rb_funccalls.d # hit Ctrl-C to end * * FIELDS: * FILE Filename of the Ruby program * METHOD Method name * COUNT Number of calls during sample * * Filename and method names are printed if available. * * COPYRIGHT: Copyright (c) 2007 Brendan Gregg. * * CDDL HEADER START * * The contents of this file are subject to the terms of the * Common Development and Distribution License, Version 1.0 only * (the "License"). You may not use this file except in compliance * with the License. * * You can obtain a copy of the license at Docs/cddl1.txt * or http://www.opensolaris.org/os/licensing. * See the License for the specific language governing permissions * and limitations under the License. * * CDDL HEADER END * * 09-Sep-2007 Brendan Gregg Created this. */ #pragma D option quiet dtrace:::BEGIN { printf("Tracing... Hit Ctrl-C to end.\n"); } ruby*:::function-entry { @funcs[basename(copyinstr(arg2)), copyinstr(arg0), copyinstr(arg1)] = count(); } dtrace:::END { printf(" %-32.32s %-16s %-16s %8s\n", "FILE", "CLASS", "METHOD", "CALLS"); printa(" %-32.32s %-16s %-16s %@8d\n", @funcs); }
先に、観測用のスクリプトを起動しておきます。すると、終了はCtrl-Cねって案内が 出てきます。そしたら、別端末から、rubyスクリプトを起動します。 このrubyスクリプトが終了したら、観測用スクリプトを終了させます。すると、
root@solaris:~/DTRACE# ./rb_funccalls.d Tracing... Hit Ctrl-C to end. ^C FILE CLASS METHOD CALLS func_slow.rb Object func_a 1 func_slow.rb Object func_b 1 func_slow.rb Object func_c 1 func_slow.rb IO write 3 func_slow.rb Module method_added 3 func_slow.rb Object print 3 func_slow.rb Fixnum < 600003 func_slow.rb Fixnum + 1200000
いいですねぇ。これで、Railsの暗闇が暴けますね。パチパチパチ。だから早くruby-1.9.2 にも、適用してくださいな。パッチは、下記のようにに当たってました。
sakae@solaris:~/ruby-1.8.6$ grep -l DTRACE *.c eval.c gc.c object.c tracer.c sakae@solaris:~/ruby-1.8.6$ ls *trace* dtrace.d dtrace.h dtrace.o tracer.c tracer.o sakae@solaris:~/ruby-1.8.6$ more dtrace.d /* -*- Mode: C -*- */ provider ruby { probe function__entry(char*, char*, char*, int); probe function__return(char*, char*, char*, int); probe raise(char*, char*, int); probe rescue(char*, int); probe line(char*, int); /* gc probes */ probe gc__begin(); probe gc__end(); /* Some initial memory type probes */ probe object__create__start(char*, char*, int); probe object__create__done(char*, char*, int); probe object__free(char*); probe ruby__probe(char*, char*); }; #pragma D attributes Evolving/Evolving/Common provider ruby provider #pragma D attributes Private/Private/Common provider ruby module #pragma D attributes Private/Private/Common provider ruby function #pragma D attributes Evolving/Evolving/Common provider ruby name #pragma D attributes Evolving/Evolving/Common provider ruby args
ツボな所に針を埋め込んでますねぇ。しかもその針が用途に合わせて選ばれているよ。 作者さんは、ひょっとして鍼灸師? 1.9.2だと、これらに プラスして、仮想マシンにも埋め込む? いえいえ、仮想マシンは、あの人がカリカリ にチューニングしてますから不要とおっしゃるかな?