2005年06月06日(Mon) ビール飲み過ぎで起動が遅いです [同日]
● なんちて
● Pythonの起動は遅い(かもしれない)
enbug diaryより。へぇ。ちょっと手元でも実験してみました。
$ time perl -e '' real 0m0.003s user 0m0.000s sys 0m0.003s $ time ruby -e '' real 0m0.005s user 0m0.003s sys 0m0.002s $ time python -c '' real 0m0.016s user 0m0.011s sys 0m0.005s
ほんとだ。perl, v5.8.5、ruby 1.8.3、Python 2.3.4です。
straceするとシステムコールの回数がわかるのかな。
$ strace perl -e '' 2>&1 | wc -l 141 $ strace ruby -e '' 2>&1 | wc -l 121 $ strace python -c '' 2>&1 | wc -l 718
ふむふむ。じゃあ起動して終了するまでにreadしたバイト数。
$ strace -e trace=read perl -e '' 2>&1 | awk '{s+=$NF}END{print(s)}' 4132 $ strace -e trace=read ruby -e '' 2>&1 | awk '{s+=$NF}END{print(s)}' 3104 $ strace -e trace=read python -c '' 2>&1 | awk '{s+=$NF}END{print(s)}' 142929
1.5桁ほどちがいますね。バイトコードを実行するようになってるあたりが違うのでしょうか?
$ strace -e trace=open python -c '' 2>&1 | grep -v ENOENT | lv
なんだか日本語エンコーディング関連のようなファイル名が沢山見えました。ならば、
$ LANG=C time python -c '' 0.00user 0.00system 0:00.02elapsed 65%CPU (0avgtext+0avgdata 0maxresident)k 0inputs+0outputs (0major+606minor)pagefaults 0swaps
速くなった?
$ LANG=C time perl -e '' 0.00user 0.00system 0:00.00elapsed 0%CPU (0avgtext+0avgdata 0maxresident)k 0inputs+0outputs (0major+309minor)pagefaults 0swaps $ LANG=C time ruby -e '' 0.00user 0.00system 0:00.00elapsed 60%CPU (0avgtext+0avgdata 0maxresident)k 0inputs+0outputs (0major+358minor)pagefaults 0swaps
うんにゃ。しかしロケールでtimeの出力が違うのにびっくり。(追記:普段はja_JP.EUC-JPになってます。、下にもっと追記)
readしたバイト数をファイル名に関連づけられるともう少しいろいろわかるのでしょうけど、また今度にしまーす。
(もっと追記)timeの出力が変化するのはロケールのせいじゃなかったです。LANG=ja_JP.EUC-JP time …
でもLANG=C
を付けた時と同じ出力が得られました。コマンドラインの最初にtimeを書くとbashの予約語のtimeとして解釈されて、LANG=…の後にtimeを書くとコマンド名として解釈されて/usr/bin/timeが実行される、というのが真相のようです。失礼しました。
● straceからファイル名と読んだデータの大きさを得る
そういうわけで簡単なスクリプトを作ってみました。ファイル名にダブルクォーテーションが含まれてたりするとどうなるか知らない。
#!/usr/bin/ruby # Copyright 2005 by zunda at freeshell.org, distributed under GPL fds = Hash.new bytes = Hash.new( 0 ) ARGF.each do |line| if /^open\("([^"]+)",[^)]+\)\s*=\s(\d+)/ =~ line then path = $1 fd = $2.to_i fds[fd] = path if fd >= 0 elsif /^read\((\d+),[^)]+\)\s*=\s(\d+)/ =~ line then fd = $1.to_i byte = $2.to_i bytes[fds[fd]] += byte end end bytes.to_a.sort_by{|x| x[1]}.reverse.each do |x| puts "#{'%5d' % x[1]} bytes from #{x[0]}" end
ここではstrace.rbというファイル名にしてあります。結果はというと、
$ LANG=C strace perl -e '' 2>&1 | ruby strace.rb | head -5 512 bytes from /lib/tls/libpthread.so.0 512 bytes from /lib/libutil.so.1 512 bytes from /lib/tls/libm.so.6 512 bytes from /lib/tls/libc.so.6 512 bytes from /usr/lib/perl5/5.8.5/i686-linux-thread-multi/CORE/libperl.so $ LANG=C strace ruby -e '' 2>&1 | ruby strace.rb | head -5 512 bytes from /lib/tls/libpthread.so.0 512 bytes from /lib/tls/libm.so.6 512 bytes from /lib/tls/libc.so.6 512 bytes from /usr/lib/libruby.so.1.8 512 bytes from /lib/libcrypt.so.1 $ LANG=C strace python -c '' 2>&1 | ruby strace.rb | head -5 28530 bytes from /usr/lib/python2.3/codecs.pyc 27272 bytes from /usr/lib/python2.3/os.pyc 14433 bytes from /usr/lib/python2.3/posixpath.pyc 11831 bytes from /usr/lib/python2.3/UserDict.pyc 11787 bytes from /usr/lib/python2.3/site.pyc
へぇ。バイトコードになったPythonスクリプトをたくさん読んでるのかな?
perlでもrubyでも、そしてpythonでも、共有オブジェクトは512バイトずつ読まれてるのですが、ELFでは最初の512バイトにシンボルテーブルが書かれてたりするのでしょうか。いつか調べるー。いつー。
● うりゃ。man -t select_tut | ps2pdf - - >| select_tut.pdf
最近のツッコまれどころ