sqlite3においてVirtualTableのプロファイリングをVDBEの命令列レベルで行う方法

SQLiteのVirtual Tableは、DBMSにおけるデータソースとのアクセス部分を、自分で作ったモジュールと取り替えることが出来る機能である。これを用いると好きなファイル（例えばテキストなど）を入力としていろいろなデータをSQLで楽しく扱うことが出来るが、やはり適当に書くとパフォーマンスが劣る。そこで、プロファイリングを行う方法について調べた。

まずはじめに行った内容は、SQLiteのSQLをVDBEの命令列に変換する部分で差異があるかを調べた。なお、VDBEというのはSQLite内部で実装されている仮想マシンであり、SQLiteは内部でSQLを一旦VDBEの命令列に変換してからデータを読み込むという実行形態をとっている。
それを実行可能にするために、--enable-debugというオブションを余分につけてsqlite3をconfigureして、インストールする。
./configure --prefix=$HOME/sqlite-test --enable-load-extension --enable-debug
で、そこで作ったsqlite3を実行するときに、pragma vdbe_trace=onという文を実行すると、それ以降命令列とレジスタのデータ移動が表示される。

sqlite> pragma vdbe_trace=on
VDBE Execution Trace:
0 Trace 0 0 0 00
1 Expire 0 0 0 00
2 Halt 0 0 0 00

.output "/dev/null"とかしてから適当なクエリを実行するとよさげ。

先の調査で、VDBEの命令列レベルではほぼ同等のコードが吐かれていることがわかったので、各命令の実行速度の違いについて次は調査しようと考えた。この方法は、2003-01-01のコミットで追加されたVDBE_PROFILEというものを使えば取得できるようだ。ということで、再度configureからのmake&&make install。このときはデバッグもしたかったので最適化オプションやデバッグオブションもつけた。
CFLAGS="-O0 -g -DVDBE_PROFILE" ./configure --prefix=$HOME/sqlite-test --enable-load-extension --enable-debug
これで適当なクエリを実行すると、vdbe_profile.outというファイルがカレントディレクトリにできるのでそれを見てみる。

---- 9414
0 0 0 0 Trace 0 0 0 00
0 0 0 1 Halt 0 0 0 00

これは、オペコード94 と 14についてのトレースという意味らしい。一番左がイテレーション回数、２つめが総実行時間、３つめが１回あたりの平均実行時間。適当なものをselect * from tableしたクエリの実行時間は以下のように表示される。

---- 940e306529292929292929292929292929292929292929291e073614042f850e
1 288 288 0 Trace 0 0 0 00
1 225 225 1 Goto 0 28 0 00
1 3096 3096 2 OpenRead 0 7 0 20 00
1 44469 44469 3 Rewind 0 26 0 00
238424 548549640 2300 4 Column 0 0 1 00
238424 98481483 413 5 Column 0 1 2 00
238424 141488658 593 6 Column 0 2 3 00
....

これは、Columnという命令(命令番号4-6)たちは238424回実行されているということがわかり、一回あたりの実行が命令４のColumnでは2300clockかかるということがわかる。なお、SQLiteのソースをみた感じではclockはRDTSC命令で計測していた。

ドキュメントが少なかったのでとりあえず簡単にまとめておいた。他になにかいいプロファイリングとかあればぜひコメントください。
とtwitterに流しておいたりするとえろいひとたちから教えてもらえるってぼく知ってる