Go 言語用デバッガー delve を活用する

問題解決を速める


Posted on 2020年 2月 12日 (水)
Tags golang, delve, debug
golang, delve, debug

delve で Go のプログラムをデバッグする

Go はかれこれ 4年ほど書いているが、これまで debugger を使わなくても、スタックトレースと log.Printf("%+v") でこれまで過ごしてきた。 Go は静的型付け言語であり、また言語仕様もシンプル(ジェネリクスが現状なかったり)のため、コンパイルして問題箇所に気づくことも多い。

個人の開発は delve を使わずとも、コンパイルエラーや実行したエラーログで済んでいたが、今後、チームでの開発を進めることになるため、便利なツールはおさえておきたく delve を使ってみた。

delve とは

GitHub - go-delve/delve: Delve is a debugger for the Go programming language. によると、simple で多機能な Go の debug ツールを目指したプロジェクトとある。

インストールは簡単で、go get で取得できるが、自分は VSCode をよく利用するため、VSCode の Go プラグインでインストールする。

VSCode での利用方法については、Visual Studio CodeでGo言語のデバッグ環境を整える - Qiita という記事があるため、ここでは述べない。

実際にデバッグをしてみる

さっそく、個人開発している go-zen-chu/hachi にてデバッグをしてみる。delve が活きるのは、コンパイルは成功したが、実行してみるとエラーになるランタイムエラーで解析する場合などだ。

そこで、実際に開発中に遭遇したランタイムエラーをデバッグしてみる。

nil pointer のデバッグを実施する

hachi の開発中、さっそく build して実行してみたら、nil pointer でランタイムエラーになった。これを delve でデバッグしてみる。

VSCode の Go extension にて delve をインストールし、下記タブから debug を実行した(左上の再生マーク)結果、

1Failed to continue - bad access
2Failed to next - bad access

というエラーが出てきた。本来は、どの変数が nil だったのか、どのステップが問題だったのかを知りたいところだが、On macOS a SIGSEGV (EXC_BAD_ACCESS) can not be propagated back to the target · Issue #852 · go-delve/delve という issue の通り、まだそのような実装ができていなそうだ。 (full feature とは…)

そこで、まず始めに go build して実行してみて、スタックトレースを確認する。

 1git clone git@github.com:go-zen-chu/hachi.git
 2# debug 用にあえて runtime error が発生するバージョンを残した
 3git checkout abdfd733da97d615726dddeeddca710278bec3d5
 4# build は通る
 5go build .
 6
 7# runtime error が発生する
 8./hachi serve
 9
10serve called
11panic: runtime error: invalid memory address or nil pointer dereference
12[signal SIGSEGV: segmentation violation code=0x1 addr=0x50 pc=0x1440de5]
13
14goroutine 1 [running]:
15github.com/spf13/viper.pflagValue.HasChanged(0x0, 0xc000093680)
16        /Users/amasuda/go/pkg/mod/github.com/spf13/viper@v1.6.2/flags.go:41 +0x5
17github.com/spf13/viper.(*Viper).find(0xc0000bab40, 0x154b74c, 0x4, 0x1, 0x10d3017, 0xc000095790)
18        /Users/amasuda/go/pkg/mod/github.com/spf13/viper@v1.6.2/viper.go:1075 +0x1681
19github.com/spf13/viper.(*Viper).Get(0xc0000bab40, 0x154b74c, 0x4, 0x1, 0x1)
20        /Users/amasuda/go/pkg/mod/github.com/spf13/viper@v1.6.2/viper.go:728 +0x81
21github.com/spf13/viper.Get(...)
22        /Users/amasuda/go/pkg/mod/github.com/spf13/viper@v1.6.2/viper.go:725
23github.com/go-zen-chu/hachi/cmd.glob..func1(0x1929aa0, 0x194eb30, 0x0, 0x0)
24        /Users/amasuda/personal/hachi/cmd/serve.go:19 +0x9e
25github.com/spf13/cobra.(*Command).execute(0x1929aa0, 0x194eb30, 0x0, 0x0, 0x1929aa0, 0x194eb30)
26        /Users/amasuda/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:830 +0x2aa
27github.com/spf13/cobra.(*Command).ExecuteC(0x1929820, 0x103cd1a, 0x18e9580, 0xc000000180)
28        /Users/amasuda/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914 +0x2fb
29github.com/spf13/cobra.(*Command).Execute(...)
30        /Users/amasuda/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
31github.com/go-zen-chu/hachi/cmd.Execute()
32        /Users/amasuda/personal/hachi/cmd/root.go:24 +0x31
33main.main()
34        /Users/amasuda/personal/hachi/main.go:6 +0x20

スタックトレースから nil pointer で落ちていること、hachi プログラムの中では、root.go の 24 行目での処理が失敗していることがわかる。 さらに、プログラム内で利用している viper ライブラリの flags.go 41行目で nil pointer が起きているようだ。

該当コードをみると、

1// HasChanged returns whether the flag has changes or not.
2func (p pflagValue) HasChanged() bool {
3 return p.flag.Changed   <——
4}

ここで発生しているようだ。nil pointer なので、 p か p.flag の中身が nil になっていることが想像つく。

このように、スタックトレースを見るだけでも何が問題になっていそうかわかるが、より複雑な条件で発生しているランタイムエラーは、この変数の中に何が入っているかを確認できると嬉しい。

そこで、delve の出番になる。

上記の通り、そのままデバッグを行ってしまうと、どこで落ちたのか、どのような変数が入っていたのか分からないまま異常終了してしまうため、root.go 24行と flags.go 41行目に break point を置いておく。

その後、continue (F5) で、スタックトレースをたどっていく。このとき、touch bar に出てくるのは地味に嬉しい(F5, F10 とか覚えるの辛いので)

breakpoint の場所で止まると、 p.flag の中身が nil になっている(左上)。そのため、なぜ nil なのかを考えればよい。

これは、viper にてオプションをルックアップするときに、Flags の中身から取得しようとして nil になっていた。 (本来、error 返すとかしてくれたほうが嬉しいのだが…)

そのため、Flags ではなく、設定している PersistentFlags 関数に置き換えるとこの nil ポインタのエラーは解消された。

delve で使える便利機能

ブレークポイントに条件をもたせる

これは他のデバッガーでも利用できるが、例えば for 文の中で「この index のときだけ落ちる」というような場合、ブレークポイントに条件をもたせることで、エラーになる直前の状況を確認できる。

VSCode だと、ブレークポイントの場所にて右クリックで有効にできる。

他の goroutine の状態を確認する

go で並列処理するときに欠かせない goroutine の状態を確認できる。 基本的に main.main goroutine を見ていることが多いが、Go runtime が Go GC の goroutine を走らせているのを確認できる。

をみると、runtime.forcegchelper や runtime.bgsweep が別の goroutine として動作していることがわかる。

runtime の goroutine は gopark が呼び出されており、xxx.gopark という名前になっている。これは goroutine が一時停止状態になっている。

実行中の go バイナリにアタッチする

1go build -gcflags "-N -l" .

と GC flag を指定して、build すると、関数のインライン化と最適化をなくすことができる。 こうすることで、ソースコードの行番号と実際に動作している機械語の 1:1 の対応を取ることができる(その代わりパフォーマンスを犠牲にする)

gcflags の詳細については下記のとおり go tool compile -h で取得できる。

 1$ go tool compile -h
 2usage: compile [options] file.go...
 3  -%    debug non-static initializers
 4  -+    compiling runtime
 5  -B    disable bounds checking
 6  -C    disable printing of columns in error messages
 7  -D path
 8        set relative path for local imports
 9  -E    debug symbol export
10  -I directory
11        add directory to import search path
12  -K    debug missing line numbers
13  -L    show full file names in error messages
14  -N    disable optimizations
15  -S    print assembly listing
16  -V    print version and exit
17  -W    debug parse tree after type checking
18  -asmhdr file
19        write assembly header to file
20  -bench file
21        append benchmark times to file
22  -blockprofile file
23        write block profile to file
24  -buildid id
25        record id as the build id in the export metadata
26  -c int
27        concurrency during compilation, 1 means no concurrency (default 1)
28  -complete
29        compiling complete package (no C or assembly)
30  -cpuprofile file
31        write cpu profile to file
32  -d list
33        print debug information about items in list; try -d help
34  -dwarf
35        generate DWARF symbols (default true)
36  -dwarfbasentries
37        use base address selection entries in DWARF
38  -dwarflocationlists
39        add location lists to DWARF in optimized mode (default true)
40  -dynlink
41        support references to Go symbols defined in other shared libraries
42  -e    no limit on number of errors reported
43  -gendwarfinl int
44        generate DWARF inline info records (default 2)
45  -goversion string
46        required version of the runtime
47  -h    halt on error
48  -importcfg file
49        read import configuration from file
50  -importmap definition
51        add definition of the form source=actual to import map
52  -installsuffix suffix
53        set pkg directory suffix
54  -j    debug runtime-initialized variables
55  -l    disable inlining
56  -lang string
57        release to compile for
58  -linkobj file
59        write linker-specific object to file
60  -live
61        debug liveness analysis
62  -m    print optimization decisions
63  -memprofile file
64        write memory profile to file
65  -memprofilerate rate
66        set runtime.MemProfileRate to rate
67  -mutexprofile file
68        write mutex profile to file
69  -newescape
70        enable new escape analysis (default true)
71  -nolocalimports
72        reject local (relative) imports
73  -o file
74        write output to file
75  -p path
76        set expected package import path
77  -pack
78        write to file.a instead of file.o
79  -r    debug generated wrappers
80  -race
81        enable race detector
82  -s    warn about composite literals that can be simplified
83  -shared
84        generate code that can be linked into a shared library
85  -smallframes
86        reduce the size limit for stack allocated objects
87  -std
88        compiling standard library
89  -symabis file
90        read symbol ABIs from file
91  -traceprofile file
92        write an execution trace to file
93  -trimpath prefix
94        remove prefix from recorded source file paths
95  -v    increase debug verbosity
96  -w    debug type checking
97  -wb
98        enable write barrier (default true)
1$ dlv attach <PID>
2(dlv) break main.go:8

のようにして、実行中のバイナリに対して dlv を attach できる。 この間、バイナリは停止しているが、continue を実施すれば処理を再開するため、ブレークポイントを置いて、continue して様子を見るということが可能。

coredump を dlv で確認する

1gcore <PID>
2dlv core <binary name> <coredump name>

これで coredump の中の変数の状態やスタックトレースを確認できる。 しかし、2020/02/15 現在のところ、Windows, Linux にのみ対応していそう。

 1$ dlv core --help
 2
 3Examine a core dump.
 4
 5The core command will open the specified core file and the associated executable and let you examine the state of the process when the core dump was taken.
 6
 7Currently supports linux/amd64 core files and windows/amd64 minidumps.
 8
 9Usage:
10  dlv core <executable> <core> [flags]

そこで、Mac からでも dlv core の検証が行えるように、Linux で gcore を利用できるサンプルを https://github.com/go-zen-chu/delve-debug-sample で作った。

 1# run with security option to use ptrace
 2docker run --rm --cap-add=SYS_PTRACE --security-opt seccomp=unconfined \
 3  -it -v ${PWD}:/delve-debug-sample centos8-gdb /bin/bash
 4# in centos8 container
 5cd /delve-debug-sample
 6./delve-debug-sample &
 7gcore <PID>
 8exit
 9
10# on MacOS
11dlv core delve-debug-sample core.<PID>
12(dlv) goroutines

まあ、本番稼働する Go のバイナリを Mac で走らせることはそうないだろうし、Linux でのやり方がわかっていればよいのではないですかね(暴論)

Share


See also