ruby debug
check debug
前回やったrubyのwebrickがDebianで動かない問題を追跡する。OpenBSDで試そうと思ったら、byebugが動かない。なんでかなと思ったらOpenBSD(64bit)には、ruby 3.0系が入っていた。どうも対応していないみたい。(debian 32bitにはruby 3.1が入ってるけど、こちらでも使えなかった)
ob$ byebug -t --no-stop ref.rb Tracing: ref.rb:1 require 'sqlite3' No such file or directory @ rb_sysopen - <internal:/usr/local/lib/ruby/3.0/rubygems/core_ext/kernel_require.rb> ["/usr/local/lib/ruby/gems/3.0/gems/byebug-11.1.3/lib/byebug/helpers/file.rb:20:in `initialize'", ...
このbyebygはgitのいいねを見ると、３万人もの支持を貰っているから、人気なんだけど、近い将来ruby 3.X 対応になるかな。
待っていられないので、rubyのdebug関係をリサーチしたよ。
ふー、時代は変っているのね。
debug.gem
ob$ gem info debug
*** LOCAL GEMS ***
debug (1.5.0, 0.2.1)
Author: Koichi Sasada
Homepage: https://github.com/ruby/debug
Licenses: Ruby, BSD-2-Clause
Installed at (1.5.0): /usr/local/lib/ruby/gems/3.0
(0.2.1, default): /usr/local/lib/ruby/gems/3.0
Debugging functionality for Ruby
gemにはこんなコマンドも用意されてる。巷ではgem installしかお目にかからないけど。
ob$ doas gem uninstall -v 0.2.1 debug Gem debug-0.2.1 cannot be uninstalled because it is a default gem
バージョンを指定して削除しようにもデフォは拒否された。複数のバージョンがある時は、最新のものが使われるのかな？ それとも、ロシアン・ルーレット？ こういう細部が気になるぞと。
ob$ rdbg30 -h
/usr/local/bin/rdbg30 [options] -- [debuggee options]
Debug console mode:
-n, --nonstop Do not stop at the beginning of the script.
:
普通に使おう、rdbgだな。何よりもgdbと同じ使い心地が嬉しい。
tracer
で、少々困ったのが、byebugにあったトレース機能。debugにも有るんだけど、少々目的が違うみたい。
元々rubyの標準装備に、トレーサーが有る亊に気付いた。まずはマニュアルだな。
sakae@deb:~$ ri -a Tracer
-a を付けると、みんな見せてくれるよ。ついでにriの挙動を少々確かめた。
sakae@deb:~$ ri -a Webrick Nothing known about Webrick Did you mean? WEBrick sakae@deb:~$ ri -a webrick Nothing known about .webrick
riを使う時は検索文字の頭を大文字で始めるのがよさそう。これってクラスだな。
で、トレースしたい範囲を指定するのが楽だ。前回やったgd.rbとかに埋め込む。
require 'tracer'
ew = sw + "%"
Tracer.on
db = SQLite3::Database.new("/usr/share/dict/ejdict.sqlite3")
:
stmt.close(); db.close()
Tracer.off
これで、必要部分だけがトレースされる。
#1:gd.rb:36:Object:-: db = SQLite3::Database.new("/usr/share/dict/ejdict.sqlite3")
#1:/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:65:SQLite3::Database:>: def initialize file,
options = {}, zvfs = nil
:
#1:/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib/sqlite3/resultset.rb:136:SQLite3::ResultSet:<: end
#1:gd.rb:46:Object:-: stmt.close(); db.close()
#1:gd.rb:47:Object:-: Tracer.off
#2:/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webrick/utils.rb:187:WEBrick::Utils::TimeoutHandler:-: @queue.clear
勘弁して下さいよ。長い長い接頭語。資料によると、スレッド番号、スクリプトファイルPath、行番号、クラス名、シンボルがコロン区切で並び、その後、ソースって塩梅だ。
ファイル名はdir名前を省いたものが欲しいけど、そんな亊簡単に出来るのか？ 後で調べてみる。
比べてみるぞ。
FreeBSD, Debian で対比してみた。どうもOpenBSDのスレッドは過去に苦い経験があるのでさけたのさ。
#1:gd.rb:36:Object:-: db = SQLite3::Database.new("/usr/sh #1:gd.rb:36:Object:-: db = SQLite3::Database.new("/usr/sh
#1:database.rb:65:SQLite3::Database:>: def initialize fil #1:database.rb:65:SQLite3::Database:>: def initialize fil
:
#1:resultset.rb:109:SQLite3::ResultSet:-: return nil if #1:resultset.rb:109:SQLite3::ResultSet:-: return nil if
#1:resultset.rb:111:SQLite3::ResultSet:-: row = @db.tra <
#1:statement.rb:117:SQLite3::Statement:>: def types <
:
#1:resultset.rb:136:SQLite3::ResultSet:<: end #1:resultset.rb:136:SQLite3::ResultSet:<: end
#1:gd.rb:46:Object:-: stmt.close(); db.close() #1:gd.rb:46:Object:-: stmt.close(); db.close()
#1:gd.rb:47:Object:-: Tracer.off #1:gd.rb:47:Object:-: Tracer.off
> #2:/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webr
左側がFreeBSD、右側がDebianだ。FreeBSDには、ruby 2.7.6と言う、2.X 最後の版が入っている。 やはり、リナは検索をさぼっている。これじゃ進展が無いな。どうする？
次の手段
折角便利なrdbgが有るんだから、使ってみろよってのは、置いておいて別の角度から。straceしてみるかな。ref.rbは、普通にsqliteを使うやつ。前回のsql.rb相当。
sakae@deb:/tmp/t$ strace -o REF ruby ref.rb sakae@deb:/tmp/t$ strace -o GD ruby gd.rb
そしてこんな風に、bashの荒技を繰り出す。一時ファイルを作らなくて済むってのがラクダ。この機能は褒めてやる。普段使いのOpenBSDのshellには無い機能だ。それからBSDにはstrace相当としてktraceが有るけど、数値の羅列でちと不親切。問題発生がリナで良かった。をぃ。
sdiff -w 126 <(grep sqlite3 REF | grep -v 'No such') <(grep sqlite3 GD | grep -v 'No such')
:
lstat64("/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/li lstat64("/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/li
lstat64("/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/li lstat64("/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/li
stat64("/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib stat64("/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib
lstat64("/usr/share/dict/ejdict.sqlite3", {st_mode=S_IFREG|06 <
openat(AT_FDCWD, "/usr/share/dict/ejdict.sqlite3", O_RDWR|O_C <
openat(AT_FDCWD, "/usr/share/dict/ejdict.sqlite3", O_RDONLY|O <
stat64("/usr/share/dict/ejdict.sqlite3", {st_mode=S_IFREG|064 <
stat64("/usr/share/dict/ejdict.sqlite3", {st_mode=S_IFREG|064 <
stat64("/usr/share/dict/ejdict.sqlite3", {st_mode=S_IFREG|064 <
そして、驚愕の事実が判明した。影も形もなく、辞書ファイルにアクセスしていない。
エラーを起してみる
本当に辞書ファイルを認識してるの？ ちょいと辞書名をありえない名前に変更してみる。
sakae@deb:/tmp/t$ ruby ref.rb
Content-type: text/html; charset=UTF-8
/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89:in `open_v2': unable to open database file (SQLite3::CantOpenException)
from /usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89:in `initialize'
from ref.rb:5:in `new'
from ref.rb:5:in `search'
from ref.rb:16:in `<main>'
ちゃんとnewする所でエラーになったな。
sakae@deb:/tmp/t$ ruby gd.rb
[2022-04-19 06:00:44] INFO WEBrick 1.7.0
[2022-04-19 06:00:44] INFO ruby 3.1.1 (2022-02-18) [i686-linux]
[2022-04-19 06:00:44] INFO WEBrick::HTTPServer#start: pid=1727 port=8080
127.0.0.1 - - [19/Apr/2022:06:01:08 JST] "GET / HTTP/1.0" 200 254
- -> /
[2022-04-19 06:01:16] ERROR SQLite3::CantOpenException: unable to open database file
/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89:in `open_v2'
/usr/local/lib/ruby/gems/3.1.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89:in `initialize'
gd.rb:34:in `new'
gd.rb:34:in `block in httpd'
/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webrick/httpservlet/prochandler.rb:39:in `do_GET'
/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webrick/httpservlet/abstract.rb:105:in `service'
/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webrick/httpserver.rb:140:in `service'
/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webrick/httpserver.rb:96:in `run'
/usr/local/lib/ruby/gems/3.1.0/gems/webrick-1.7.0/lib/webrick/server.rb:310:in `block in start_thread'
127.0.0.1 - - [19/Apr/2022:06:01:16 JST] "POST /ejdict HTTP/1.0" 500 308
http://localhost:8080/ -> /ejdict
深い所でエラーが発生。
Internal Server Error unable to open database file ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ WEBrick/1.7.0 (Ruby/3.1.1/2022-02-18) at localhost:8080
そして、こちらはクライアント側のブラウザー画面。昔は、よくこの画面を三田ぞ。
何でOS依存で不都合な亊が起きるのよ。今迄の経験ではリナで動くのにBSD系では駄目ってパターンばかりだった。BSD人口が少くなった今、目が行き届かないってのは理解出来る。でも、リナで動かないってのは、超不満。
OS界隈に例えると、モジュールの中のドライバーが動かなくて、右往左往してる図だな。 それもトップハーフは問題なくてボトムハーフに何か問題ありそう、かな。
今回だと、sqlite3の深い所の問題のように思える。それも sqlite3_native.so あたりの問題。上記のOSの例に例えると、ボトムハーフ問題、かな。どうしたらいいの？ 誰か教えて！！
play with debug.gem
もう、いじけて、遊んでみるしかない。
with chrome
README.mdを見ていると、ブラウザーと接続して使えるようだ。firefoxが対象になっていないのは、民主主義の勝利なんだな。一番利用者が多い所をターゲットにするのは資本主義の道理。
chromeはもしもの為にWindowsに入れてる。そして、debianは、VMWarePlayerの中。そんな環境で使えるのか？
sakae@pen:/tmp/t$ rdbg ref.rb --open=chrome DEBUGGER: Debugger can attach via TCP/IP (127.0.0.1:38139) DEBUGGER: wait for debugger connection... DEBUGGER: With Chrome browser, type the following URL in the address-bar: devtools://devtools/bundled/inspector.html?v8only=true&panel=sources&ws=127.0.0.1:38139/d7a9b....
ローカルホスト限定ってのが辛い所。Debianに入っているchromeもどきなら動くかな？ あれ、近頃BUGに余念がないv8って指定も入っているな。
取り敢えず、関係先を視察する。 … server_cdp.rb
port, path, pid = run_new_chrome
begin
s = Socket.tcp '127.0.0.1', port
when /linux/
'google-chrome'
else
raise "Unsupported OS"
if data.match /DevTools listening on ws:\/\/127.0.0.1:(\d+)(.*)/
req = "GET #{path} HTTP/1.1\r\nHost: 127.0.0.1:#{port}\r\nConnection: U\
pgrade\r\nUpgrade: websocket\r\nSec-WebSocket-Version: 13\r\nSec-WebSocket-Key:\
#{key}==\r\n\r\n"
config
(rdbg)
[89, 98] in /var/lib/gems/2.7.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb
89| open_v2 file.encode("utf-8"), mode, zvfs
90| end
91|
92| @tracefunc = nil
93| @authorizer = nil
=> 94| @encoding = nil
95| @busy_handler = nil
96| @collations = {}
97| @functions = {}
98| @results_as_hash = options[:results_as_hash]
=>#0 SQLite3::Database#initialize(file="/usr/share/dict/ejdict.sqlite3", options={}, zvfs=nil) at /var/lib/gems/2.7.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:94
#1 [C] Class#new at ref.rb:5
# and 2 frames (use `bt' command for all frames)
毎度お馴染の、/var/lib/gem… が煩わしい。こういう時は
(rdbg) config use_short_path = true # command use_short_path = true # UI: Show shorten PATH (like $(Gem)/foo.rb)
短かくしてよの指示を与える。
[91, 100] in $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb
91|
92| @tracefunc = nil
93| @authorizer = nil
94| @encoding = nil
95| @busy_handler = nil
=> 96| @collations = {}
97| @functions = {}
98| @results_as_hash = options[:results_as_hash]
99| @type_translation = options[:type_translation]
100| @type_translator = make_type_translator @type_translation
=>#0 SQLite3::Database#initialize(file="/usr/share/dict/ejdict.sqlite3", options={}, zvfs=nil) at $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb:96
#1 [C] Class#new at ref.rb:5
# and 2 frames (use `bt' command for all frames)
rdbg起動時から有効にするには、~/.rdbgrcに記述しておく。
trace
(rdbg) trace call into: LOG # command Enable CallTracer (enabled) into: LOG (rdbg) trace # command Tracers: * #0 CallTracer (enabled) into: LOG
こういう指定をしておいて、continueすると記録が残る。
sakae@pen:/tmp/t$ head -5 LOG PID:2328 CallTracer (disabled) into: LOG DEBUGGER (trace/call) #th:1 #depth:5 > String#encode at /var/lib/gems/2.7.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89 DEBUGGER (trace/call) #th:1 #depth:5 < String#encode #=> "/usr/share/dict/ejdict.sqlite3" at /var/lib/gems/2.7.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89 DEBUGGER (trace/call) #th:1 #depth:5 > SQLite3::Database#open_v2 at /var/lib/gems/2.7.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89 DEBUGGER (trace/call) #th:1 #depth:5 < SQLite3::Database#open_v2 #=> #<SQLite3::Database:0x00007f9d50066220> at /var/lib/gems/2.7.0/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:89
目が痛くなるようなログが採取された。schemeに装備しなきゃならないtrace機能がdebug.gemから利用出来るのは、良い亊だ。
record
レコードしておくと、過去に戻れる。まずは関連コマンド確認。
(rdbg) h record # help command ### Trace * `record` * Show recording status. * `record [on|off]` * Start/Stop recording. * `step back` * Start replay. Step back with the last execution log. * `s[tep]` does stepping forward with the last log. * `step reset` * Stop replay .
レコードしてから再生ね。
(rdbg) record on # command
Recorder for #<Thread:0x00000712bf9981e8 run>: on (0 records)
(rdbg) s # step command
[90, 95] in $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb
90| end
91|
92| @tracefunc = nil
=> 93| @authorizer = nil
94| @encoding = nil
95| @busy_handler = nil
=>#0 SQLite3::Database#initialize(file="/usr/share/dict/ejdict.sqlite3", opti
ons={}, zvfs=nil) at $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb:93
#1 [C] Class#new at ref.rb:5
# and 2 frames (use `bt' command for all frames)
:
(rdbg) record # command
Recorder for #<Thread:0x00000712bf9981e8 run>: on (15 records)
(rdbg) s back # step command
[replay] [145, 150] in $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb
[replay] 145| #
[replay] 146| def prepare sql
[replay] 147| stmt = SQLite3::Statement.new( self, sql )
[replay] => 148| return stmt unless block_given?
[replay] 149|
[replay] 150| begin
[replay] =>#0 SQLite3::Database#prepare(sql="SELECT word,mean FROM items WHERE
word ...) at $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb:148
[replay] #1 Object#search(sw="ruby") at ref.rb:6
[replay] # and 1 frames (use `bt' command for all frames)
(rdbg)
[replay] [144, 149] in $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb
[replay] 144| # The Statement can then be executed using Statement#execute.
[replay] 145| #
[replay] 146| def prepare sql
[replay] => 147| stmt = SQLite3::Statement.new( self, sql )
[replay] 148| return stmt unless block_given?
[replay] 149|
[replay] =>#0 SQLite3::Database#prepare(sql="SELECT word,mean FROM items WHERE
word ...) at $(Gem)/sqlite3-1.4.2/lib/sqlite3/database.rb:147
[replay] #1 Object#search(sw="ruby") at ref.rb:6
[replay] # and 1 frames (use `bt' command for all frames)
再生中ってマークで、それと分る。
i and o
i と o も大事だよ。ってか、便利だよ。
(rdbg) i # info command %self = #<SQLite3::Statement:0x000007127ef09c08 @connection=#<SQLite3::Datab...> bind_vars = [] @columns = nil @connection = #<SQLite3::Database:0x0000071258d681e0 @tracefunc=nil, @author...> @remainder = "" @types = nil
(rdbg) o # outline command Enumerable#methods: all? any? chain chunk chunk_while collect collect_concat count cycle detect : SQLite3::Statement#methods: active? bind_param bind_parameter_count bind_params clear_bindings! close closed? column_count column_decltype column_name columns database_name done? each execute execute! must_be_open! remainder reset! step types instance variables: @columns @connection @remainder @types locals: bind_vars