読者です 読者をやめる 読者になる 読者になる

CubicLouve

Spring_MTの技術ブログです。https://github.com/SpringMT (http://spring-mt.tumblr.com/ からの移転)

gdbを使ってRubyのライブプロセスの情報を取得する

ruby gdb

Rubyのプロセスに対して、非破壊的に中をのぞいてみたいことが時々ありますよね???(詰まっているプロセスとか)

今回、gdbを使ってライブプロセスにアタッチして調べてみました。

準備

今回はAWSamazon Linux上で試しています。

# cat /etc/system-release
Amazon Linux AMI release 2016.09

gcc4.8.3gdb7.6.1を使ってます。

Rubyのバージョンは2.3.3を使いました。

予めrbenvをインストールしておき、rbenvでRubyは管理しておきます。

まずは、Rubyデバッグ用にビルドします。

ビルドオプションとして、最適化を切っておくのとgdbからデバッグ情報を使えるように指定します。

wget https://cache.ruby-lang.org/pub/ruby/2.3/ruby-2.3.3.tar.gz
tar zxf ruby-2.3.3.tar.gz 
cd ruby-2.3.3
./configure optflags="-O0" debugflags="-ggdb3" --prefix="${HOME}/.rbenv/versions/2.3.3-O0_g3"
make
make install

configureのオプションは ./configure --help で確認できます。

ちなみに最適化しない(-O0) + デバッグフラグつけてビルドしたRubyバイナリ

最適化をかけて(-O3) + デバッグフラグつけていないrubyバイナリの大きさはこれくらい違います。

  • 適化しない(-O0) + デバッグフラグつけた : 5.6MB
  • 最適化をかけて(-O3) + デバッグフラグつけていない : 約15MB

gdbでアタッチするRubyプロセスを作る

まずは、かんたんなhttpサーバーを立ち上げてそのプロセスにアタッチしてみます。

今回は単純なhello worldを返すだけのhttpサーバーを立ててます。(pidは控えておいてください)

ソースは下記reposにあります。

rack-hello_world

アタッチしてみる

Cの世界

では、gdbを使ってプロセスにアタッチしてみましょう。

gdbコマンドラインオプションで使いそうなのは下記の通りです。

  • -nw, -nowindows : 強制的にコマンドラインインターフェースを使う
  • -silent : 起動時のバージョン番号を表示しない
  • -x : コマンドを指定されたファイルから読み取って実行する
  • --args : コマンドライン上で実行ファイルより後ろに置かれたものを引数として実行ファイルへ渡す

今回Rubyのソースの中に入っている.gdbinitの内容にちょっと手を加えたgdbinitファイルを使いました。

手を加えた(追加のみですが)部分はこちら。

https://gist.github.com/SpringMT/dfc443f97804f61d1804d3c4a1f56625

アタッチするコマンドは下記の通りです。

gdb -nw -silent -x /PATH/TO/.gdbinit /PATH/TO/bin/ruby [PID]
例: gdb -nw -x ./ruby-2.3.3/.gdbinit -silent /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/bin/ruby 24676

アタッチした後で、

Missing separate debuginfos, use: debuginfo-install hoge

とかでたら、rootユーザーで

debuginfo-install hoge

をしましょう。

gdb経由でプロセスにアタッチしたら、setを使って設定を追加しておくと良いでしょう。

(今回はgdbinit内でやっています。)

(gdb) set print pretty on # 構造体の表示を見やすくします(一行ずつインデント付きで表示します。)
(gdb) set pagination off # ページングを切ります

アタッチしたら、まず手始めにRubyのバージョンを表示させてみましょう。

(gdb) p ruby_version
$1 = "2.3.3"

p はGBDのコマンドで、printエイリアスです。

print は変数、式の値を表示します。

ruby_versionはconst charで宣言されているグローバル変数です。

https://github.com/ruby/ruby/blob/202bbda2bf5f25343e286099140fb9282880ecba/version.c#L29

定義場所はlistコマンドで表示できます

(gdb) list ruby_version
24 const int ruby_api_version[] = {
25 RUBY_API_VERSION_MAJOR,
26 RUBY_API_VERSION_MINOR,
27 RUBY_API_VERSION_TEENY,
28 };
29 const char ruby_version[] = RUBY_VERSION;
30 const char ruby_release_date[] = RUBY_RELEASE_DATE;
31 const char ruby_platform[] = RUBY_PLATFORM;
32 const int ruby_patchlevel = RUBY_PATCHLEVEL;
33 const char ruby_description[] = RUBY_DESCRIPTION;

次に、今アタッチしているプロセスの環境変数をみてみましょう。

(gdb) show environ # environなんかポインタおかしい? environ[0]がでてないような。。。
LESS_TERMCAP_mb=
HOSTNAME=ip-172-30-0-109
TERM=xterm-256color
SHELL=/bin/bash
HISTSIZE=1000
・
・

スレッド情報はどうでしょう。

(gdb) info threads
Id Target Id Frame 
2 Thread 0x7fc266669700 (LWP 26309) "ruby-timer-thr" 0x00007fc26581b64d in poll () at ../sysdeps/unix/syscall-template.S:81
* 1 Thread 0x7fc266660740 (LWP 26300) "rackup" 0x00007fc26581d3c3 in select () at ../sysdeps/unix/syscall-template.S:81

メインスレッド(Rubyのスレッド)とタイマスレッドが見えます。

ここから、実際に実行されている実体に迫って行きます。

では、rackupのスレッドのbacktraceを情報をみてみましょう。

gdbのthreadコマンドでinfo threadsで表示されたIDを指定して、該当スレッドに移動し、backtraceコマンド(bt)を打つとCのバックトレース情報がみれます。

(gdb) thread 1
[Switching to thread 1 (Thread 0x7f416100d740 (LWP 6147))]
#0 0x00007f41601ca3c3 in select () at ../sysdeps/unix/syscall-template.S:81
81 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)
(gdb) backtrace 
#0 0x00007f41601ca3c3 in select () at ../sysdeps/unix/syscall-template.S:81
#1 0x0000556f9688b60a in rb_fd_select (n=9, readfds=0x7ffd5cbddc70, writefds=0x0, exceptfds=0x0, timeout=0x7ffd5cbdd8e0) at thread.c:3431
#2 0x0000556f96883f90 in native_fd_select (n=9, readfds=0x7ffd5cbddc70, writefds=0x0, exceptfds=0x0, timeout=0x7ffd5cbdd8e0, th=0x556f978c05d0) at thread_pthread.c:1090
#3 0x0000556f9688b86e in do_select (n=9, readfds=0x7ffd5cbddc70, writefds=0x0, exceptfds=0x0, timeout=0x7ffd5cbdd8e0) at thread.c:3570
#4 0x0000556f9688bb18 in rb_thread_fd_select (max=9, read=0x7ffd5cbddc70, write=0x0, except=0x0, timeout=0x7ffd5cbddc40) at thread.c:3643
#5 0x0000556f9676379a in select_internal (read=93937774090080, write=8, except=8, tp=0x7ffd5cbddc40, fds=0x7ffd5cbddc70) at io.c:8441
#6 0x0000556f96763bc3 in select_call (arg=140726159400016) at io.c:8511
#7 0x0000556f96727932 in rb_ensure (b_proc=0x556f96763b7d <select_call>, data1=140726159400016, e_proc=0x556f96763bc5 <select_end>, data2=140726159400016) at eval.c:914
#8 0x0000556f96764037 in rb_f_select (argc=4, argv=0x7f4160f0c188, obj=93937772561160) at io.c:8860
#9 0x0000556f96860559 in call_cfunc_m1 (func=0x556f96763f52 <rb_f_select>, recv=93937772561160, argc=4, argv=0x7f4160f0c188) at vm_insnhelper.c:1463
#10 0x0000556f9686107f in vm_call_cfunc_with_frame (th=0x556f978c05d0, reg_cfp=0x7f416100bd90, calling=0x7ffd5cbde930, ci=0x556f98160320, cc=0x556f98161240) at vm_insnhelper.c:1642
#11 0x0000556f9686119c in vm_call_cfunc (th=0x556f978c05d0, reg_cfp=0x7f416100bd90, calling=0x7ffd5cbde930, ci=0x556f98160320, cc=0x556f98161240) at vm_insnhelper.c:1737
#12 0x0000556f96865fcc in vm_exec_core (th=0x556f978c05d0, initial=0) at insns.def:994
#13 0x0000556f96877843 in vm_exec (th=0x556f978c05d0) at vm.c:1650
#14 0x0000556f96878455 in rb_iseq_eval (iseq=0x556f97acc3b0) at vm.c:1882
#15 0x0000556f9672ace7 in rb_load_internal0 (th=0x556f978c05d0, fname=93937774417160, wrap=0) at load.c:619
#16 0x0000556f9672ade6 in rb_load_internal (fname=93937774417160, wrap=0) at load.c:649
#17 0x0000556f9672b0d4 in rb_f_load (argc=1, argv=0x7f4160f0c048) at load.c:717
#18 0x0000556f96860559 in call_cfunc_m1 (func=0x556f9672aff4 <rb_f_load>, recv=93937772668480, argc=1, argv=0x7f4160f0c048) at vm_insnhelper.c:1463
#19 0x0000556f9686107f in vm_call_cfunc_with_frame (th=0x556f978c05d0, reg_cfp=0x7f416100bf90, calling=0x7ffd5cbdfe50, ci=0x556f97b9cdb0, cc=0x556f97b9cf60) at vm_insnhelper.c:1642
#20 0x0000556f9686119c in vm_call_cfunc (th=0x556f978c05d0, reg_cfp=0x7f416100bf90, calling=0x7ffd5cbdfe50, ci=0x556f97b9cdb0, cc=0x556f97b9cf60) at vm_insnhelper.c:1737
#21 0x0000556f96861fd0 in vm_call_method_each_type (th=0x556f978c05d0, cfp=0x7f416100bf90, calling=0x7ffd5cbdfe50, ci=0x556f97b9cdb0, cc=0x556f97b9cf60) at vm_insnhelper.c:2026
#22 0x0000556f968626f6 in vm_call_method (th=0x556f978c05d0, cfp=0x7f416100bf90, calling=0x7ffd5cbdfe50, ci=0x556f97b9cdb0, cc=0x556f97b9cf60) at vm_insnhelper.c:2161
#23 0x0000556f96862844 in vm_call_general (th=0x556f978c05d0, reg_cfp=0x7f416100bf90, calling=0x7ffd5cbdfe50, ci=0x556f97b9cdb0, cc=0x556f97b9cf60) at vm_insnhelper.c:2193
#24 0x0000556f96865fcc in vm_exec_core (th=0x556f978c05d0, initial=0) at insns.def:994
#25 0x0000556f96877843 in vm_exec (th=0x556f978c05d0) at vm.c:1650
#26 0x0000556f96878495 in rb_iseq_eval_main (iseq=0x556f97ad7d00) at vm.c:1893
#27 0x0000556f96725f97 in ruby_exec_internal (n=0x556f97ad7d00) at eval.c:245
#28 0x0000556f967260c0 in ruby_exec_node (n=0x556f97ad7d00) at eval.c:310
#29 0x0000556f96726093 in ruby_run_node (n=0x556f97ad7d00) at eval.c:302
#30 0x0000556f96723d55 in main (argc=2, argv=0x7ffd5cbe0668) at main.c:36

select() が呼ばれているところで止まっているところまではわかりました。

ここまでは、Cの世界ですが、Cの世界だけではわかりにくいので、今度はRubyの世界に降りていきましょう。

Rubyの世界へ

まずは簡単にRubyのcallbackを表示してみます。

rubyのrb_backtrace()を使って表示できます。

https://github.com/ruby/ruby/blob/9cbd6ee09770be3d73a17ab1195a094c59c9f9ee/vm_backtrace.c#L776

gdbのcallコマンドを使って、rb_backtrace()をよびます。

(gdb) call rb_backtrace()

そうすると、プロセスの標準出力(今回はrackupで立ち上げたプロセス)にrubyのbacktraceが表示されます。

from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/bin/rackup:22:in `<main>'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/bin/rackup:22:in `load'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/bin/rackup:4:in `<top (required)>'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/server.rb:147:in `start'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/server.rb:296:in `start'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/handler/webrick.rb:34:in `run'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:164:in `start'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:33:in `start'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:177:in `block in start'
from /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:177:in `select'

更にRubyとCの関数をあわせたbacktrace情報もみてましょう。

rb_backtrace()ではでてきませんでしたが、rb_vmdebug_stack_dump_raw_current()を使えばCの関数呼出しも含まれて標準出力に表示されます。

https://github.com/ruby/ruby/blob/202bbda2bf5f25343e286099140fb9282880ecba/vm_dump.c#L178

実際にはRubyのコールスタックを見やすい形で全てdumpしてくれます。

(gdb) call rb_vmdebug_stack_dump_raw_current()
-- Control frame information -----------------------------------------------
c:0011 p:---- s:0053 e:000052 CFUNC :select
c:0010 p:0117 s:0046 e:000045 BLOCK /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:177
c:0009 p:0006 s:0037 e:000036 METHOD /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:33
c:0008 p:0068 s:0034 e:000033 METHOD /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/2.3.0/webrick/server.rb:164
c:0007 p:0161 s:0029 e:000028 METHOD /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/handler/webrick.rb:34
c:0006 p:0231 s:0022 E:000558 METHOD /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/server.rb:296
c:0005 p:0016 s:0016 e:000015 METHOD /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/server.rb:147
c:0004 p:0023 s:0012 e:000011 TOP /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/bin/rackup:4 [FINISH]
c:0003 p:---- s:0010 e:000009 CFUNC :load
c:0002 p:0136 s:0006 E:000370 EVAL /home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/bin/rackup:22 [FINISH]
c:0001 p:0000 s:0002 E:000aa0 (none) [FINISH]

CFUNCやMTHODとあるのが、スタックフレームのタイプとなり、CFUNCはC コードで書かれた関数のことになります。

MTHEODはRubyのメソッド呼出し、BLOCKはブロックの呼出しとなります。

次は各コールスタックの内容を見ていきましょう。

Rubyのコールスタックはrb_control_frame_t構造体に格納されています。

最新のコールスタックの中身をみてみます。

https://gist.github.com/SpringMT/dfc443f97804f61d1804d3c4a1f56625

ruby_threadvm_frame_type コマンドを使います。

(gdb) ruby_thread 
running_thread set $ruby_thread 
(gdb) vm_frame_type $ruby_thread->cfp 
vm_frame_type 61 CFUNC

CFUNCが返ってくるので、このコールスタックはCの関数呼出しをしていることがわかります。

Cの関数の場合、どういう関数が呼ばれているかはrb_vm_frame_method_entry()を使います。

https://github.com/ruby/ruby/blob/7bbab207cbe0c92777fcb30e21cde787ca9a3863/vm_insnhelper.c#L488

rprubyの.gdbinitに定義されているコマンドでよしなに値をRubyレベルの表示にしてくれます。

(gdb) rp rb_id2str(rb_vm_frame_method_entry($ruby_thread->cfp)->called_id)
[PROMOTED] T_STRING: "select" bytesize:6 (embed) encoding:2 coderange:7bit $19 = (struct RString *) 0x5644ed0393b8

これでselectが呼ばれていることがわかります。

では、ちょっと意図的ですが4つ前のコールスタック(rubyのメソッド呼び出し)のコールスタックも見てみましょう。

下記に定義してある、rb_iseq_disasmも使ってYARV命令列も表示してみます。(標準出力にでます。)

https://github.com/ruby/ruby/blob/4e60f99803e0b9ab49fb368f3660438934bf1a4e/iseq.c#L1402

iseq(instruction sequence、命令列)の部分はRubyの2.3系以降で大きな変更が入っているので、2.3未満のバージョンだと少し挙動が違う可能性があります。

make rb_iseq_t T_IMEMO object (type is imemo_iseq).

また、環境データは環境ポインタで示されるデータのindex 1に入っています。(下記参照)

https://github.com/ruby/ruby/blob/472959f9c20e7aff1776312d6c8e2236a52e29a7/vm_core.h#L994

(gdb) set $cfp = $ruby_thread->cfp + 4 # 4つ前のコールスタック
(gdb) vm_frame_type $cfp
vm_frame_type 11 METHOD # タイプ
(gdb) rp $cfp->iseq->body->location.path
[PROMOTED] T_STRING: "/home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/handler/webrick.rb" bytesize:109 encoding:2 coderange:7bit $9 = (struct RString *) 0x56236cde86a0 # ファイルパス
(gdb) p/d rb_vm_get_sourceline($cfp)
$6 = 34 # ファイルの行数
(gdb) rb_p rb_iseq_disasm($cfp->iseq) # YARV命令列
(gdb) rb_p $cfp->ep[1] # 環境ポインタのデータの中身をdumpする

YARV命令列はこちら

== disasm: #<ISeq:run@/home/ec2-user/.rbenv/versions/2.3.3_O0_ggdb3/lib/ruby/gems/2.3.0/gems/rack-2.0.1/lib/rack/handler/webrick.rb>
local table (size: 5, argc: 1 [opts: 1, rest: -1, post: 0, block: -1, kw: -1@-1, kwrest: -1])
[ 5] app<Arg> [ 4] options<Opt=0>[ 3] environment[ 2] default_host
0000 newhash 0 ( 25)
0002 setlocal_OP__WC__0 4
0004 trace 8
0006 trace 1 ( 26)
0008 getinlinecache 15, <is:0>
0011 getconstant :ENV
0013 setinlinecache <is:0>
0015 opt_aref_with <callinfo!mid:[], argc:1, ARGS_SIMPLE>, <callcache>, \"RACK_ENV\"
0019 dup 
0020 branchif 25
0022 pop 
0023 putstring \"development\"
0025 setlocal_OP__WC__0 3
0027 trace 1 ( 27)
0029 getlocal_OP__WC__0 3
0031 putstring \"development\"
0033 opt_eq <callinfo!mid:==, argc:1, ARGS_SIMPLE>, <callcache>
0036 branchunless 42
0038 putstring \"localhost\"
0040 jump 43
0042 putnil 
0043 setlocal_OP__WC__0 2
0045 trace 1 ( 29)
0047 getlocal_OP__WC__0 4
0049 putobject :BindAddress
0051 getlocal_OP__WC__0 4
0053 putobject :Host
0055 opt_send_without_block <callinfo!mid:delete, argc:1, ARGS_SIMPLE>, <callcache>
0058 dup 
0059 branchif 64
0061 pop 
0062 getlocal_OP__WC__0 2
0064 opt_aset <callinfo!mid:[]=, argc:2, ARGS_SIMPLE>, <callcache>
0067 pop 
0068 trace 1 ( 30)
0070 getlocal_OP__WC__0 4
0072 putobject :Port
0074 dupn 2
0076 opt_aref <callinfo!mid:[], argc:1, ARGS_SIMPLE>, <callcache>
0079 dup 
0080 branchif 91
0082 pop 
0083 putobject 8080
0085 opt_aset <callinfo!mid:[]=, argc:2, ARGS_SIMPLE>, <callcache>
0088 pop 
0089 jump 93
0091 adjuststack 3
0093 trace 1 ( 31)
0095 getinlinecache 107, <is:1>
0098 pop 
0099 putobject Object
0101 getconstant :WEBrick
0103 getconstant :HTTPServer
0105 setinlinecache <is:1>
0107 getlocal_OP__WC__0 4
0109 opt_send_without_block <callinfo!mid:new, argc:1, ARGS_SIMPLE>, <callcache>
0112 setinstancevariable :@server, <is:2>
0115 trace 1 ( 32)
0117 getinstancevariable :@server, <is:3>
0120 putstring \"/\"
0122 getinlinecache 133, <is:4>
0125 getconstant :Rack
0127 getconstant :Handler
0129 getconstant :WEBrick
0131 setinlinecache <is:4>
0133 getlocal_OP__WC__0 5
0135 opt_send_without_block <callinfo!mid:mount, argc:3, ARGS_SIMPLE>, <callcache>
0138 pop 
0139 trace 1 ( 33)
0141 putself 
0142 opt_send_without_block <callinfo!mid:block_given?, argc:0, FCALL|ARGS_SIMPLE>, <callcache>
0145 branchunless 153
0147 getinstancevariable :@server, <is:5>
0150 invokeblock <callinfo!argc:1, ARGS_SIMPLE>
0152 pop 
0153 trace 1 ( 34)
0155 getinstancevariable :@server, <is:6>
0158 opt_send_without_block <callinfo!mid:start, argc:0, ARGS_SIMPLE>, <callcache>
0161 trace 16 ( 35)
0163 leave ( 34)

データはこちら。

#<WEBrick::HTTPServer:0x0055e7bb2e6960 @config={:ServerName=>"ip-172-30-0-109", :BindAddress=>"localhost", :Port=>"8000", :MaxClients=>100, :ServerType=>nil, :Logger=>#<WEBrick::Log:0x0055e7bb2e6550 @level=4, @log=#<IO:<STDERR>>, 
@time_format="[%Y-%m-%d %H:%M:%S]">, :ServerSoftware=>"WEBrick/1.3.1 (Ruby/2.3.3/2016-11-21)", :TempDir=>"/tmp", :DoNotListen=>false, :StartCallback=>nil, :StopCallback=>nil, :AcceptCallback=>nil, :DoNotReverseLookup=>nil, :ShutdownSocketWithoutClose=>false,
:RequestTimeout=>30, :HTTPVersion=>#<WEBrick::HTTPVersion:0x0055e7bb36c240 @minor=1, @major=1>, :AccessLog=>[], :MimeTypes=>{"ai"=>"application/postscript", "asc"=>"text/plain", "avi"=>"video/x-msvideo", "bin"=>"application/octet-stream", "bmp"=>"image/bmp", "class"=>"application/octet-stream", "cer"=>"application/pkix-cert", "crl"=>"application/pkix-crl", "crt"=>"application/x-x509-ca-cert", "css"=>"text/css", "dms"=>"application/octet-stream", "doc"=>"application/msword", "dvi"=>"application/x-dvi", "eps"=>"application/postscript", "etx"=>"text/x-setext", "exe"=>"application/octet-stream", "gif"=>"image/gif", "htm"=>"text/html", "html"=>"text/html", "jpe"=>"image/jpeg", "jpeg"=>"image/jpeg", "jpg"=>"image/jpeg", "js"=>"application/javascript", "lha"=>"application/octet-stream", "lzh"=>"application/octet-stream", "mov"=>"video/quicktime", "mpe"=>"video/mpeg", "mpeg"=>"video/mpeg", "mpg"=>"video/mpeg", "pbm"=>"image/x-portable-bitmap", "pdf"=>"application/pdf", "pgm"=>"image/x-portable-graymap", "png"=>"image/png", "pnm"=>"image/x-portable-anymap", "ppm"=>"image/x-portable-pixmap", "ppt"=>"application/vnd.ms-powerpoint", "ps"=>"application/postscript", "qt"=>"video/quicktime", "ras"=>"image/x-cmu-raster", "rb"=>"text/plain", "rd"=>"text/plain", "rtf"=>"application/rtf", "sgm"=>"text/sgml", "sgml"=>"text/sgml", "svg"=>"image/svg+xml", "tif"=>"image/tiff", "tiff"=>"image/tiff", "txt"=>"text/plain", "xbm"=>"image/x-xbitmap", "xhtml"=>"text/html", "xls"=>"application/vnd.ms-excel", "xml"=>"text/xml", "xpm"=>"image/x-xpixmap", "xwd"=>"image/x-xwindowdump", "zip"=>"application/zip"},
:DirectoryIndex=>["index.html", "index.htm", "index.cgi", "index.rhtml"], :DocumentRoot=>nil, :DocumentRootOptions=>{:FancyIndexing=>true}, :RequestCallback=>nil, :ServerAlias=>nil, :InputBufferSize=>65536,
:OutputBufferSize=>65536, :ProxyAuthProc=>nil, :ProxyContentHandler=>nil, :ProxyVia=>true, :ProxyTimeout=>true, :ProxyURI=>nil, :CGIInterpreter=>nil, :CGIPathEnv=>nil, :Escape8bitURI=>false, :environment=>"development", :pid=>nil, :config=>"/home/ec2-user/rack-hell_world/config.ru"}, 
@status=:Running, @logger=#<WEBrick::Log:0x0055e7bb2e6550 @level=4, @log=#<IO:<STDERR>>, @time_format="[%Y-%m-%d %H:%M:%S]">, @tokens=#<Thread::SizedQueue:0x0055e7bb2e64d8>, @listeners=[#<TCPServer:fd 7>],
@shutdown_pipe=[#<IO:fd 8>, #<IO:fd 9>],
@http_version=#<WEBrick::HTTPVersion:0x0055e7bb36c240 @minor=1, @major=1>, @mount_tab=#<WEBrick::HTTPServer::MountTable:0x0055e7bb2e3968 @tab={""=>[Rack::Handler::WEBrick, [#<Rack::ContentLength:0x0055e7bb2e8d00 @app=#<Rack::Chunked:0x0055e7bb2e8da0 @app=#<Rack::CommonLogger:0x0055e7bb2e8e68 @app=#<Rack::ShowExceptions:0x0055e7bb7efe48 @app=#<Rack::Lint:0x0055e7bb7efe98 @app=#<Rack::TempfileReaper:0x0055e7bb7efee8 @app=#<Application:0x0055e7bb17e280>>, @content_length=nil>>,
@logger=#<IO:<STDERR>>>>>]]}, @scanner=/^()(?=\/|$)/>, @virtual_hosts=[]>

ここまでくれば、処理の流れも追えますし、データもある程度見えているので、ここから大分デバッグもしやすくなるのではないでしょうか。

ライブプロセスの調査を非破壊的にやるにはいろいろ難しい面がありますが、その時の参考になればと思います。

参考にしたサイト・本

unboundを使って、iPhone、Androidの名前解決をよしなにやる

iphone android unbound

開発現場において、本来とは違うIPアドレスを返して確認するということをよくやると思います。

PCで確認できるページであれば、ローカルPCの /etc/hostsを書き換えてチェックするという手法が一般的かと思います。

ただし、iPhoneAndroidで同じようなことをするために、 /etc/hosts を書き換えるのはかなり難しいです。(iPhoneは脱獄とかしないと多分できないはず)

そこで、ローカルにDNSキャッシュサーバーを立てて、そこで名前解決させるようにして、iPhoneAndroidでもPCと同じような確認ができるようにするための手順をまとめました。

今回は、DNSキャッシュサーバーに unbound を使います。

Unbound 導入のすすめ — Mobage Developers Blog

1 unboundを立てる

Macであれば、homebrewでインストールできます。

brew install unbound 

2. unboundのconfの設定と起動

homebrewでインストールしたunboundであれば、 だいたい、 /usr/local/etc/unbound/unbound.conf に設定ファイルが用意されていると思います。

で、下記のようにlocal-dataに書き換えたいレコードを書きます。

server:
  verbosity: 5
  # 使用するインターフェース。以下ではデフォルトルートを指定
  interface: 0.0.0.0
  access-control: 172.0.0.1/12 allow
  username: "nobody"
  # ローカルのサーバの名前とIPアドレスの対応を登録
  local-data: "example.com. IN A 10.0.0.1"

で、起動します

sudo /usr/local/sbin/unbound -d -c /usr/local/etc/unbound/unbound.conf 

3. 端末の設定

端末で、DNSを立ち上げunboundに向ける必要があります。

iPhoneの設定

設定 -> Wi-Fi -> iマーク -> DNS を選択して、DNSIPアドレスを書き換えて下さい。 (書き換える前に、元のDNSIPアドレスは控えておくのが良いかと)

Android

設定 -> Wi-Fi -> 接続されているWi-Fiを長押し -> ネットワークを変更 -> DNS1 を書き換えて保存

で 確認できます!

MySQL 5.6から導入されたoptimizer_traceを使ってみる

mysql

きっかけは下のブログ

rkmathi.hatenablog.com

実際に使われるindexはSQLオプティマイザがコスト計算した結果で変わると思われる。

http://dbstudy.info/files/20120310/mysql_costcalc.pdf

コスト計算の結果は、MySQL 5.6から導入されたoptimizer_traceを使えば分かります。(多分)

MySQL :: MySQL 5.6 リファレンスマニュアル :: 21.11 INFORMATION_SCHEMA OPTIMIZER_TRACE テーブル

optimizer_traceはset optimizer_trace='enabled=on';でonにできる。

mysql>  show variables like 'optimizer_trace';
+-----------------+--------------------------+
| Variable_name   | Value                    |
+-----------------+--------------------------+
| optimizer_trace | enabled=off,one_line=off |
+-----------------+--------------------------+
1 row in set (0.00 sec)

mysql> set optimizer_trace='enabled=on';
Query OK, 0 rows affected (0.00 sec)

mysql>  show variables like 'optimizer_trace';
+-----------------+-------------------------+
| Variable_name   | Value                   |
+-----------------+-------------------------+
| optimizer_trace | enabled=on,one_line=off |
+-----------------+-------------------------+
1 row in set (0.01 sec)

optimizer_traceの結果はSELECT * FROM information_schema.OPTIMIZER_TRACE; で取得できる。

上記ブログのテーブルを少し行数を減らしてEXPLAINした時の、optimizer_traceの結果を比べてみた。

Using index conditionとなる場合

gist03a9f09fb154cf24442a

table_scanのコストが101258。

idx_datetimeを使ったコストが100671。

Using whereとなる場合

gistaa3e50cbf1a9563aa95f

table_scanのコストが101258。

idx_datetimeを使ったコストが109235。

table_scanのコストの方が低くなっているのがわかる。

SideCIの自動rubocop PRが羨ましかったので、自分で作った

ruby

blog-ja.sideci.com

これを見て。

SideCIはGitHub Enterpriseに対応していない(2016/02/13現在)ので、自分で作った。

github.com

サーバー上げて、githubweb hookに仕込むだけでPRを送ったら、自動的にrubocopで自動修正した内容を別PRにして送ってくれます。

こんな感じ f:id:Spring_MT:20160214011516p:plain

以前にhoundを導入したが、吠えるだけだとうざいだけになるので、今回は噛み付いてみました。

今は単純にrackupで動かして様子見しています。

突貫で愚直に書いたツールなので、コードがイマイチなのはご容赦を。。。

MySQL 5.6でロックの状態を詳細に見たい場合

mysql

innodb_lock_monitorを有効にする

有効にする場合

CREATE TABLE innodb_lock_monitor (a INT) ENGINE=INNODB;

そして、

SHOW ENGINE INNODB STATUS;

と打てば、TRANSACTIONSのセクションの中に、ロックの詳細情報が入るようになる。

終わったら、テーブルを落とす。

DROP TABLE innodb_lock_monitor;

項目

TRANSACTIONの項目をみてみる

サンプルのテーブル

CREATE TABLE `test_lock` (
  `id` bigint(20) unsigned NOT NULL,
  `count` tinyint(3) unsigned DEFAULT 0,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB;

試したSQL

UPDATE test_lock SET count = count +1 WHERE id IN (3,13);

結果

TABLE LOCK table `test`.`test_lock` trx id 19883768 lock mode IX

これは、lock mode IX(インテンション排他ロック)というテーブルロックがかかっている。

MySQL :: MySQL 5.6 リファレンスマニュアル :: 14.2.3 InnoDB のロックモード

RECORD LOCKS space id 64731 page no 3 n bits 88 index `PRIMARY` of table `test`.`test_lock` trx id 19883768 lock_mode X locks rec but not gap

このケースでは、locks rec but not gap -> レコードロック、ギャップロックではない。

ロックは、

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 0000000000000003; asc         ;;
 1: len 6; hex 0000012f66f8; asc    /f ;;
 2: len 7; hex 040000034d2a36; asc     M*6;;
 3: len 1; hex 02; asc  ;;

Record lock, heap no 8 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 8; hex 000000000000000d; asc         ;;
 1: len 6; hex 0000012f66f8; asc    /f ;;
 2: len 7; hex 040000034d2a5a; asc     M*Z;;
 3: len 1; hex 02; asc  ;;

2015年おせち料理

料理

2014年に引き続きおせち作りました。

買い出しは一週間前から開始しています。

完成品はこちら

f:id:Spring_MT:20160103000404j:plain

なると、かまぼこ、栗きんとん、酢だこは既成品です。

松前漬

スルメイカ 3枚
昆布 スルメと同量くらい
人参 1/2本

たれ
酒 300cc
醤油(関東濃い口) 150cc
みりん 150cc

30日

  1. 酒 300cc、醤油 150cc、みりん 150ccを火にかけひと煮立ちさせて冷ましておく
  2. スルメイカ、昆布はそのままキッチンバサミで5mm幅程度に切っておく(ここは適当)
  3. 人参は千切りにしておく
  4. 上記を全部混ぜる
  5. 半日位で混ぜなおす
  6. 出来上がり

今回は31日に味付き数の子をいれた。

最終的な出来栄え

美味しかった。

来年もこのレシピでいく。

黒豆

黒豆 250g

煮汁
砂糖 170g
水 800c
醤油(薄口醤油) 大さじ 1
塩 小さじ半分

29日

  1. 煮汁を合わせておいて、沸騰させる
  2. 黒豆を流水で洗う(やさしく洗う!皮がむけてしまう)
  3. 沸騰したら火を止めて、すぐに黒豆を投入
  4. 一晩寝かせる

30日

  1. 圧力鍋で20分火を入れる(今回は強でかけた)

今回は20分以上強で圧力をかけてしまっていて柔らかくなりすぎた。

最終的な出来栄え

美味しかったが、少し柔らかかった。 もしかしたら15分くらい圧力かけて、あとで煮込んで調整してもよいかも。

田作り(去年とは違うレシピ)

田作り 50g位(ライフで買った。一袋まるまる入れた)

たれ
水 大さじ2
砂糖 大さじ2
醤油(九州 甘口) 大さじ1 + 1/2
みりん 大さじ1

31日

  1. 田作りをかりかりになるまで煎る(電子レンジで一分) -> 冷やす
  2. たれを中火にかけて、とろみがつくまで煮込む
  3. たれができたら、煎った田作りをいれてあえる
  4. バットに広げて冷ます

最終的な出来栄え

美味しかった。 前回に比べて、砂糖を多めに入れた結果、甘さがちょうど良くなった。 電子レンジで煎ると臭くなるので要注意

なます

大根 1/2本(細いのだった)  
人参 1/3本

たれ
米酢 100cc
砂糖 大さじ3
だし 100cc

31日

  1. 大根と人参を千切りにする
  2. 千切りにした大根と人参を塩を振って水出しする
  3. 水がでたら、よく絞る
  4. たれを混ぜて完了

色どり的に 大根 3: 人参 1 がよい。

今回水出し忘れて、二回たれにつけている。

最終的な出来栄え

普通。

まあ、来年も同じようなレシピで。

お煮しめ

里芋 小ぶりなものが12個位
ごぼう 1本
人参 2/3本
こんにゃく 一枚
しいたけ 8個
たけのこ 穂先だけのを4つ
蓮根 2ブロックくらい
豆腐 一丁(厚揚げにした)

味付け用調味料
だし3カップ半
醤油(薄口) 大さじ4
醤油(濃い口) 大さじ1
酒 大さじ3
砂糖 大さじ2
みりん 大さじ1
塩 小さじ1/2

人参につける出汁
だし カップ1
砂糖 小さじ1
塩 1つまみ

26日くらい

  1. 里芋を洗わずに皮をむいて、洗って半分にして下茹で
  2. 冷凍

30日

  1. しいたけを水でもどしておく
  2. 蓮根の皮むき、飾り切り、酢水(深皿に水入れて、お酢を垂らす程度)につけておく
  3. ごぼうの皮むきして、蓮根とごぼうを下茹で(10分位)
  4. 人参を飾り切りして、塩入れて下茹で(10分くらい)
  5. 人参の出汁を沸騰させて、粗熱をとっておく
  6. ゆでた人参を人参の出汁に浸けて冷蔵庫にいれておく
  7. だし3カップ半で人参以外の具材を10分炊く
  8. 出汁味付け用調味料を入れて更に15分炊く

絹さやがあったら、人参と同じように下茹でして使う

最終的な出来栄え

普通

ニシンの昆布巻き

身欠きにしん 10本(そのうち8本を使った)
日高昆布 10枚(昆布はすぐにもどるのでにしんの量に合わせてもどせばよい)
かんぴょう 適量

だし
昆布戻し汁3カップ〜3と1/2カップ
米酢 大さじ2
酒 1/2カップ

たれ
砂糖 大さじ4(きび砂糖のほうがよさそう)
本みりん 大さじ2(後で大さじ2程度追加)
しょうゆ 大さじ3(後で大さじ3程度追加)

28日(晩から)

  1. 身欠きにしんを米と昆布と一緒に水につける

29日(晩)

  1. 水を替えておく

30日

  1. 昆布は表面の汚れをさっと拭き取り、3〜4カップの水で戻す。柔らかく巻けるくらいになればよい。戻しすぎない。
  2. かんぴょうはさっと洗い、塩でもんで5分くらい水につけて戻しておく。これも戻しすぎないように。
  3. 昆布でにしんを巻き、昆布の幅に応じてかんぴょうを2〜3ヶ所、2巻きして結ぶ。(かんぴょうはゆるめに巻く。)
  4. 圧力鍋に巻いた昆布を隙間なく並べ、だしの材料を入れて蓋をする。火にかけ、沸騰したら中火にし、12分圧力をかけ、火を止める。
  5. 圧が下がったらふたを開け、たれを加え、弱火で約20分煮含める。焦げないように注意

そもそも、半量のレシピを参考にして、そのままの調味料の量で味付けしたため、最初味が薄かった。

後で、醤油、みりんで味を整えた。

最終的な出来栄え

もうすこし甘くてもよかったかと。

砂糖も二倍量入れれば、ちょうどよかったかなと。

海老の旨煮

甘エビはふるさと納税でGETしました。

www.furusato-tax.jp

甘エビ(有頭) 8尾

たれ
だし 100cc(水でも可)
白出汁 小さじ1 (http://www.amazon.co.jp/%E3%83%95%E3%83%B3%E3%83%89%E3%83%BC%E3%82%AD%E3%83%B3-%E7%99%BD%E3%81%A0%E3%81%97-1000mL/dp/B008ZWP55A)
みりん 大さじ1
酒 大さじ1
醤油 大さじ2
  1. 海老の下ごしらえをする(背わた、ひげを取る)
  2. 鍋にたれを入れ中火にかける。沸騰したら火を弱める。 1.エビを入れる。時々ひっくり返しながら、中火で4~5分煮る。
  3. 冷やして完成(冷やしている時に、味が染み込む。)

最終的な出来栄え

普通 来年は甘エビじゃなくて、車海老にしようかな。。(赤の出方と、ボリューム感で)

伊達巻

家の玉子焼き器で二枚分くらいのレシピ

ハンペン 1枚(80g)
玉子4個

たれ
みりん 小さじ1(よりちょっと多めくらい)
砂糖 大さじ2
塩 少々
麺つゆ(3倍濃縮) 小さじ1と1/2
だし 60 cc位いれたかな
醤油 少々
  1. 卵を4つ割り入れる
  2. フードプロセッサー(ナイフカッター使用)に、卵、ハンペン(手でちぎる程度でOK)、たれをいれて一分程度ミキサーにかける
  3. アルミホイルで蓋を作っておく
  4. 玉子焼き器(テフロン加工したやつ)に卵を流し込む(だいたい半分位をいれる)
  5. 強火で10秒かけた後に、アルミホイルの蓋をかぶせて弱火で10分位火にかける(匂いでこげていそうだったら)
  6. 表側が少し凸凹でもきにしない。あまりにも火が通っていない感じがしたらひっくり返す(最終手段、火を入れちゃうと出汁のジュワッと感がへります。)
  7. 鬼簾がないので、普通のすだれで巻いた。

最終的な出来栄え

伊達巻は最高だった

食べた感じの、出しがいい感じに染み出てくる感と、甘さがちょうど良かった。

にしんの甘露煮

身欠きにしん 2本

水 1 + 1/2カップ
酒 1/2カップ

たれ
砂糖 大さじ3
しょうゆ 大さじ2
みりん 大さじ1
  1. 昆布巻き用に戻した、身欠きにしんを使う。
  2. 鍋に水と酒とにしんを入れて火にかける。煮立ったら弱めの中火にし、ホイルなどで落としぶたをして10分煮る。
  3. たれを入れてとろみが付くまで煮込む。(だいたい20分くらい)

最終的な出来栄え

美味しかった。 年越しそばに添えました。

f:id:Spring_MT:20160103151043j:plain

数の子のからしマヨネーズ和え

数の子はふるさと納税でGET。

数の子(味付き) 適量
マヨネーズ 適量
和からし 少々
  1. 数の子、マヨネーズ、和からしを混ぜて完了

最終的な出来栄え

おつまみとしてはよい。

来年への課題

きび砂糖を買っておく。 重箱を買っておく。 緑をうまい具合に入れる。

nginxのconfの内容をdumpする

nginx

nginxのconfですが、includeとか大量にしていると、うっかり上書きされててハマったことないですか?

自分は最近ドハマりして、イラッとして、confをdumpできるようにならなかと調べてみました。

で、最新のnginxのソースcloneして読んでたらもうあるじゃんと思ったのですが、 自分のマシンに入ってたnginx(1.6.2)にないので、調べてみたら20150/05/15に入った変更だったのですね。。。

github.com

で、1.9.3を手元でコンパイルして試してみました。

nginxのコマンドオプションに-Tが追加されて、これを使うと、confファイルが吐出されるようになります。

# /foo/bar/nginx-1.9.3/objs/nginx -h
nginx version: nginx/1.9.3
Usage: nginx [-?hvVtTq] [-s signal] [-c filename] [-p prefix] [-g directives]

Options:
  -?,-h         : this help
  -v            : show version and exit
  -V            : show version and configure options then exit
  -t            : test configuration and exit
  -T            : test configuration, dump it and exit
  -q            : suppress non-error messages during configuration testing
  -s signal     : send signal to a master process: stop, quit, reopen, reload
  -p prefix     : set prefix path (default: /usr/local/nginx/)
  -c filename   : set configuration file (default: conf/nginx.conf)
  -g directives : set global directives out of configuration file

dumpされる内容はこんな感じ。

# configuration file /nginx.conf:
include ../hoge.conf;
worker_processes 8;

events {
    accept_mutex off;
    worker_connections 8192;
    use epoll;
}

http {
    server_names_hash_bucket_size 64;
    upstream hoge {
        server 127.0.0.1:3000;
    }

    server {
        include ../hoge1.conf;
        listen 80;
        client_max_body_size 500M;
        location / {
            proxy_pass http://hoge;
        }
        keepalive_timeout 5;
        keepalive_requests 5;
    }
}

# configuration file ../hoge.conf:
pid                   /var/run/nginx.pid;
user                  nginx;
worker_rlimit_nofile  65535;

# configuration file ../hoge1.conf:
include           ../mime.types;
default_type               application/octet-stream;

gzip                       on;


# configuration file ../mime.types:

types {
    text/html                             html htm shtml;
    text/css                              css;
    text/xml                              xml;
    image/gif                             gif;
    image/jpeg                            jpeg jpg;
    application/x-javascript              js;
    application/atom+xml                  atom;
    application/rss+xml                   rss;
}

とりあえずconfファイルを出すだけなのか。。。

ネストされている、confも全部だしてくれます。

includeされたファイルを反映させて、最終的に適用される値が出てくるわけではないので、もう一工夫いるなあ。