delveのtraceをデバッグ・デバッグ!

Jun 27, 2023 · 4 min read · Debian Go-lang Debug ·

Share on:

はじめに

GO言語をやっていないとイケてないという風潮に、あせるネバー・フレンズ・Tです。やる気を出すためにGO言語布教の名曲Write in GOをCC(Close Caption)押して聴き、バイブス全開で学習することをおすすめしておきます。

今回は、GO言語のデバッガのdelveで、GO言語学習中に、はまったことを書きます。

delveでDebianパッケージのバイナリをデバッグする

自分のように特定言語の初学者がなにか新しいプログラミング言語を習得する時、言語学習を大いにはかどらせてくれるデバッガには、いつも大変お世話になっております。

GO言語のデバッガとしては、自分の観測範囲では2つあるようで、

gdbでGO言語でbuildしたバイナリをデバッグするやり方、
delveを使うやり方

となっているようです。噂でdelveはイケてるということを聞いたので、早速delveを使ってみました。

ここでは簡単にDebian sidに入っているHugoを、delveでソースコードデバッグをしてみます。delveを使ってhugo version --logを動かしてみることにします。なお、

デバッグされる側のプログラムをdebugee（デバッギー）と呼びます。
Debianパッケージのデバッグにはデバッグパッケージの追加ダウンロードが必要になりますので、HowToGetABacktraceを参照してapt/sources.listファイルをdebian-debugリポジトリが参照できるように予めセットアップしたものとします

では早速動かしてみましょう。

まずは環境の確認です。Debianはちょうど6/10にStable版としてbookwormリリースしたばかりですが、記事を記載したのがその前でしたので、当時のDebian sidの環境もDeiban stableの環境も同じバージョンになっています。ちなみに現在確認するとDebian sidはtrixieと表示されます。

$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 12 (bookworm)
Release:        12
Codename:       bookworm

デバッガのdelveと、debugeeのhugo本体とデバッグ用シンボルファイルをDebianパッケージで導入します。

$ sudo apt install delve hugo hugo-dbgsym

次にDebianのhugoパッケージのソースコードデバッグをするのでソースコードを導入します。

$ mkdir hugo-src
$ cd hugo-src
$ apt-get source hugo

ソースコードの位置はlsとpwdの結果どおり、/home/yours/hugo-src/hugo-0.111.3/になります。

$ ls 
hugo-0.111.3/                 hugo_0.111.3-1.dsc
hugo_0.111.3-1.debian.tar.xz  hugo_0.111.3.orig.tar.gz
$ pwd   
/home/yours/hugo-src

いよいよデバッガ起動です。debugee側に引数を設定する場合は’–‘を入れてからdebugee用の引数を並べるルールです。

$ dlv exec $(command -v hugo) -- version --logs
Type 'help' for list of commands.
(dlv)

sourceコマンドでhugoパッケージがコンパイルされた時のソース位置を確認します。

(dlv) sources 
...中略...
github.com/gohugoio/hugo/bufferpool/bufpool.go
github.com/gohugoio/hugo/cache/filecache/filecache.go
github.com/gohugoio/hugo/cache/filecache/filecache_config.go
github.com/gohugoio/hugo/cache/filecache/filecache_pruner.go
...中略...

hugo パッケージがコンパイルされた位置とソースを展開した場所を結びつけます。

以下の設定をすると、github.com/gohugoio/hugo/bufferpool/bufpool.go –> /home/yours/hugo-src/hugo-0.111.3/bufferpool/bufpool.go にソースコードをマップできるようになります。

(dlv) config substitute-path "github.com/gohugoio/hugo/" "/home/yours/hugo-src/hugo-0.111.3/"

main.mainにブレークポイントを仕掛けてみます。きちんとソースコードが参照されていることがわかります。

(dlv) b main.main
Breakpoint 1 set at 0x1b9140a for main.main() /home/yours/hugo-src/hugo-0.111.3/main.go:22  
# ブレークポイントまで実行する。
(dlv) c
> main.main() /home/yours/hugo-src/hugo-0.111.3/main.go:22 (hits goroutine(1):1 total:1) (PC: 0x1b9140a)
Warning: debugging optimized function
    17:         "os"
    18:
    19:         "github.com/gohugoio/hugo/commands"
    20: )
    21:
=>  22: func main() {
    23:         resp := commands.Execute(os.Args[1:])
    24:
    25:         if resp.Err != nil {
    26:                 if resp.IsUserError() {
    27:                         resp.Cmd.Println("")

とりあえず、正しく引数がdebugeeに渡されたか？を確認します。きちんと、hugo version --logsをdebugeeとして実行できていることがわかります。

(dlv) p os.Args
[]string len: 3, cap: 3, [
        "/usr/bin/hugo",
        "version",
        "--logs",
]

さて、GO言語製のDebianパッケージ梱包のバイナリを好きにデバッグできるようになったわけです。これで存分にデバッガを動かしてGO言語学習にお役立てください！

traceコマンドが動かない!

「さて、delve動いたのでこの記事はおしまいっ」とはいきません。早速トラブルです。ここではdelveで遭遇したトラブルと顛末を紹介します。

delveには、debugee側で特定の文字列パターンを含む関数を実行したらそれを表示しつつdebugeeを実行するという素敵機能があります。例えば、

$ dlv trace -e $(command -v hugo) 'commands\.new'

とやると、debuggeeである、hugoのcommands\.newという正規表現にマッチする関数の実行があったらそれを画面に出しつつdebugeeの実行トレースをしてくれるものです。これは規模の大きいイベントドリブンなプログラムで、イベントハンドラから特定パッケージ内のどの関数がどんな順番で呼び出されるとかを追いかけるときに欠かせない機能です。

ではDebian sidで早速やってみましょう！

Debian sidに含まれるdelveのバージョンはupstream最新版であることを確かめます。

$ dlv version  
Delve Debugger
Version: 1.20.2
Build: $Id: e0c278ad8e0126a312b553b8e171e81bcbd37f60

traceコマンドをhugoに実行します。

$ dlv trace --log -e $(command -v hugo) 'commands\.new'
2023-06-10T15:21:49+09:00 info layer=debugger launching process with args: [/usr/bin/hugo]
2023-06-10T15:21:50+09:00 warning layer=debugger gnu_debuglink link
"7c03fe5487be2cbd7f7097fae18a1337dc56bf.debug" not found in any debug info directory could 
not launch process: could not open debug info - debuggee must not be built with 'go run' 
or -ldflags='-s -w', which strip debug info

ああっと、動きません。なんということでしょう！

--logオプションをつけないと何故動かないのか？のヒントすら出てこないので、わざと--logをつけています。メッセージを見ると、7c03fe5487be2cbd7f7097fae18a1337dc56bf.debugファイルが見つからないようです。見てのとおり、upstream最新版がDebianパッケージのバージョンですので、upstream版でも同じことが発生します。このまま誰か治してくれないかな…と思ったのですが、issueにも上がってないのでこの問題はそもそも人気がないようです。

でも、「やっぱり、わたし気になります！（ズギャーン）」という心の声がしますので、調べちゃうことにしました。

7c03fe5487be～.debugファイルとDWARF

この7c03fe5487be2cbd7f7097fae18a1337dc56bf.debugファイルはDWARFフォーマットであり、Debianパッケージビルド時に、生成されるコマンドに埋め込まれたデバッグ情報を切り出してまとめたものです。Debian の場合、<パッケージ名>-dbgsymという名前をもつパッケージを導入することで、このファイルが/usr/lib/debug/.build-id/ディレクトリ以下に展開されます。これらのファイルはdebuginfoファイルとも呼ばれますので、以降debuginfoと書きます。

DWARFそのものについての詳細と活用例は他の方が書かれたブログ(Qiitaのdwarfタグ)
debuginfoファイルのディストリビューションでの扱いはFedoraのbuildidについてのwiki

を読んでいただくとして、ここではGO言語でdebuginfoを手動で生成しdelveに利用させてdebuginfoの使い方を理解した気になる!ことを目指してみます。

まず、以下のようなgoプログラム（main.go)を用意します。

// main.goファイルの中身
package main

import (
        "fmt"
)
func main() {
        fmt.Printf("hello world!\n")
}

早速コンパイルして実行してみます。

$ mkdir _build
$ ls 
_build/ main.go
$ env GOPATH=$(pwd)/_build GO_EXTLINK_ENABLED=1 go build main.go
$ ls -lh main
-rwxr-xr-x 1 yours yours 1.7M Jun 12 09:39 main
$ ./main
hello world!

あっさり動きます。バイナリのサイズは1.7MBぐらいあります。もちろん、mainファイルにはデバッグ情報が付いたままですので、このままdelveに指定するとソースコードデバッグがそのまま出来ます。なお、後述しますが、本実験をするためにはGO_EXTLINK_ENABLED=1の指定が必須になります。

さて、debuginfo理解のために、手動でデバッグ情報を引き抜いてバイナリをシェイプアップし、debuginfoファイルを所定の位置に格納してもデバッグできることを確かめます。

まずはbuildidを確認します。7cec191a6de3420b1d52f2c2d7a602a36f6c9bffであることが判ります。

$ file main
main: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), dynamically linked, 
interpreter /lib64/ld-linux-x86-64.so.2, 
BuildID[sha1]=7cec191a6de3420b1d52f2c2d7a602a36f6c9bff, for GNU/Linux 3.2.0, not stripped

次にobjcopyで実行ファイルからdebugセクションまるごとコピーしてdebuginfoファイルを作成します。ファイル名はbuildidの行頭2文字を省いたものに.debugという末尾を付けたファイル名で用意することになっています。

$ sudo apt install binutils
$ objcopy --only-keep-debug --compress-debug-sections ./main ec191a6de3420b1d52f2c2d7a602a36f6c9bff.debug
$ ls -lh ec191a6de3420b1d52f2c2d7a602a36f6c9bff.debug
-rw-r--r-- 1 yours yours 553K Jun 12 09:55 ec191a6de3420b1d52f2c2d7a602a36f6c9bff.debug

lsの結果の通り553KBぐらいのファイルが出来ます。

今度は/usr/lib/debug/.build-id/buildidの頭2文字/というディレクトリを作ります。

$ sudo mkdir /usr/lib/debug/.build-id/7c
$ sudo chmod 755 /usr/lib/debug/.build-id/7c

ここでデバッグ情報をバッサリ消去したmain.stripedという実行ファイルを作って動かします。

$ strip --remove-section=.comment --remove-section=.note -o main.striped main
$ ls -lh main
-rwxr-xr-x 1 yours yours 1.7M Jun 12 09:39 main
$ ls -lh main.striped
-rwxr-xr-x 1 yours yours 1.2M Jun 12 10:05 main.striped
$ ./main.striped
hello world!

1.7MBから1.2MBまでサイズが減ったことが確認できました。サイズが減っても動作することは確認できました。

次にdebuginfoが/usr/lib/debug/.build-id/7c/以下にない状況だとデバッグが出来ないことを確かめます。

$ dlv exec ./main.striped
could not launch process: could not open debug info

それではdebuginfoを/usr/lib/debug/.build-id/7c/以下に設置します。

$ sudo mv ec191a6de3420b1d52f2c2d7a602a36f6c9bff.debug /usr/lib/debug/.build-id/7c/
$ sudo chmod 644 /usr/lib/debug/.build-id/7c/ec191a6de3420b1d52f2c2d7a602a36f6c9bff.debug

dlvを起動すると今度はデバッグができるようになります。

$ dlv exec ./main.striped
Type 'help' for list of commands.
(dlv) b main.main
Breakpoint 1 set at 0x47f566 for main.main() ./main.go:6
(dlv) c
> main.main() ./main.go:6 (hits goroutine(1):1 total:1) (PC: 0x47f566)
Warning: debugging optimized function
     1: package main
     2:
     3: import (
     4:         "fmt"
     5: )
=>   6: func main() {
     7:         fmt.Printf("hello world!\n")
     8: }
(dlv)

以上でdebuginfoの作り方と格納の仕方を説明しました¹。簡単ですね！Debianパッケージ開発では、dh_stripコマンドが同じような操作を実行してdebuginfoを取り出します。結果、最後に<パッケージ名>-dbgsymというdebuginfoだけを正しくインストールするパッケージが自動生成されます。

余談：GO_EXTLINK_ENABLED環境変数とは

さて、今回の実験では、GO_EXTLINK_ENABLED=1なる環境変数をつけてコンパイルしています。こちらは、リンカに外部のリンカ（通常はgccというかgnu ld）をいつでも使ってほしいと指示する環境変数の設定です。

GO言語は分割されたソースをコンパイルした結果を保存するとき、ハッシュで分類したディレクトリに格納して管理します。この時に使われるのがGO言語特有のbuildidで、gnu ldが自動生成するbuildidとは完全に独立したidです。ここで、何らかの条件がそろうと、goコマンドがGO言語側で開発したリンカを呼び出してしまい、出来上がる実行ファイルにgnu ldの付与するbuildidが含まれないという問題が起きます。今回コンパイル時にgnu ld形式のbuildidもつけて欲しかったので、強制的にgnu ldを呼び出す設定として、GO_EXTLINK_ENABLED=1を指定しています。

delveをdelveでデバッグして治す

さて、dlv traceコマンドを実行すると、debuginfoが見つからないといわれるわけですから、どこかに不具合があります。早速デバッグです。今回、debuginfoを正しく読めないだけですので、デバッガならではの特定のアドレスで停止もしくは何かdebugeeを動かすというところまでは行っていないことは明らかです。

この状況に限り、デバッガをデバッガでデバッグする（笑）ことが可能です。

早速delveをdelveでデバッグしましょう！舌噛みそうですね！

$ sudo apt install delve-debugsym
$ mkdir delve-src
$ cd delve-src
$ apt-get source delve
$ ls 
delve-1.8.2/  delve_1.8.2-1.debian.tar.xz  delve_1.8.2-1.dsc  delve_1.8.2.orig.tar.xz
$ pwd
/home/yours/delve-src
$ cd ..
$ dlv exec $(command -v dlv) -- trace --log -e $(command -v hugo) 'commands\.new'
Type 'help' for list of commands.
(dlv) config substitute-path "github.com/go-delve/delve/" "/home/yours/delve-src/delve-1.8.2/"
(dlv) b main.main
Breakpoint 1 set at 0x933612 for main.main() ./delve-1.8.2/cmd/dlv/main.go:14
(dlv) c
> main.main() ./delve-1.8.2/cmd/dlv/main.go:14 (hits goroutine(1):1 total:1) (PC: 0x933612)
Warning: debugging optimized function
     9: )
    10:
    11: // Build is the git sha of this binaries build.
    12: var Build string
    13:
=>  14: func main() {
    15:         if Build != "" {
    16:                 version.DelveVersion.Build = Build
    17:         }
    18:         const cgoCflagsEnv = "CGO_CFLAGS"
    19:         if os.Getenv(cgoCflagsEnv) == "" {
(dlv)

ところで、--logオプションをつけると、not found in any debug directoryと出ていたわけですから、その出力を持つ関数が怪しいとなり、この文字列を元にソースをag(apt install silversearcher-ag)とかで探すと、早速そのものずばりのfunc (bi *BinaryInfo) openSeparateDebugInfoがpkg/proc/bininfo.goに見つかります。openSeparateDebugInfoにブレークを仕掛けてステップ実行していくと、openSeparateDebugInfo関数の引数のdebugInfoDirectories変数が空っぽなので、おかしな場所にdebuginfoファイルを探しに行っていることがわかります。

ここまでわかると、openSeparateDebugInfo関数の呼び出しを遡ることで、traceCmd関数（cmd/dlv/cmds/commands.go)内部でconf.DebugInfoDirectories変数をdebugeeの面倒をみるサーバプロセスに渡していないことが、dlv execの時との違いでわかります。ソースは以下の箇所です。

...中略...
func traceCmd(cmd *cobra.Command, args []string, conf *config.Config) int {
...中略...
                // Create and start a debug server
                server := rpccommon.NewServer(&service.Config{
                        Listener:    listener,
                        ProcessArgs: processArgs,
                        APIVersion:  2,
                        Debugger: debugger.Config{
                                AttachPid:      traceAttachPid,
                                WorkingDir:     workingDir,
                                Backend:        backend,
                                CheckGoVersion: checkGoVersion,
                        },       // <--ここにDebugInfoDirectoriesの指定が無いのでdebuginfoが見つからない
                })

ここをちゃんとconf.DebugInfoDirectoriesの値が指定されるように修正したところ、たちまち

$ dlv trace -e $(command -v hugo) 'commands\.new'
>> goroutine(1): => ()
> goroutine(1): github.com/gohugoio/hugo/commands.newEnvCmd()
> goroutine(1): github.com/gohugoio/hugo/commands.newEnvCmd(("*github.com/spf13/cobra.Command")(0xc000216280))
>> goroutine(1): => ()
> goroutine(1): github.com/gohugoio/hugo/commands.newImportCmd()
> goroutine(1): github.com/gohugoio/hugo/commands.newImportCmd(("*github.com/spf13/cobra.Command")(0xc0003f2c80))
>> goroutine(1): => ()
> goroutine(1): github.com/gohugoio/hugo/commands.newGenCmd()
> goroutine(1): github.com/gohugoio/hugo/commands.newGenCmd(("*github.com/spf13/cobra.Command")(0xc00041e780))
> goroutine(1): github.com/gohugoio/hugo/commands.newGenDocCmd()
...中略...
> goroutine(1): github.com/gohugoio/hugo/commands.newCommandeer(true, true, false, ("*github.com/gohugoio/hugo/commands.
hugoBuilderCommon")(0xc000541340), github.com/gohugoio/hugo/commands.flagsToConfigHandler(*github.com/gohugoio/hugo/comm
ands.hugoCmd) 0xbeef000000000408, (unreadable could not find function for 0x48da894804f8c148), (unreadable empty OP stac

と正しく動き出しました。Debianパッケージで導入したhugo内部のcommands.newという名前を関数の一部に持つ関数の実行トレースがdebuginfoを元に無事できるようになりました！簡単に治ってよかったです！これでGO言語の学習の続きができますよ！

おわりに

気分良くなったついでにdelveのupstream側には本修正はPR完了、PRは無事取り込まれました。Debianにも早速取り込んで欲しいなぁとbug reportもしました。ただ、レポートした時期がbookwormのFull Freeze期間だったので、残念ながらDebian stable側のbookwormには取り込まれていません。まあ、upstream側で治しているので、Debian sidには放っておいても取り込まれると思ってます。

GO言語の学習からうっかり脇道にそれてしまいましたが、GO言語についてちょっとだけ自信がついた気がしました。

詳しい人は「あれ？.gnu_debuglinkヘッダにdebuginfoのありかを書き込まなければいけないんじゃなかったけ？」と思われるとおもいます。しかしながらdelveはbuildidから直接debuginfoの位置を生成して読み込む実装も持っているので、特に.gnu_debuglinkヘッダは用意しなくてもdebuginfoを探し当てて読み込んでしまいます。 ↩︎

この記事を書いた人

記事一覧

ネバ―・フレンズ・T

厨二病でFOSS信者。評価/実験/自宅はDebian unstable。最近はブロックチェーンも始めました。

記事一覧

SQUARE ENIXでは一緒に働く仲間を募集しています！

興味をお持ちいただけたら、ぜひ採用情報ページもご覧下さい！

採用情報はこちら