go build をデバッグしてみた
環境
- MacBook Air (11-inch, Mid 2012)
- OSX 10.11.6(15G1108)
- メモリ 8 GB
- 2 GHz Intel Core i7
build を行うソースコード
今回、チャネルや goroutine は build 時にどうなるのか気になったので、このようなソースコードを準備しました。
package main func main() { title := "Hello, World" strCh := make(chan string) go func() { s := <-strCh println(s) }() strCh <- title close(strCh) }
gdb で go build を読んでいく
「go1.7.3 の go コマンドを gdb でデバッグする」の内容を把握していることを前提として進めていきます。
gdb で起動する
それではやっていきましょう。 今ディレクトリはこのようになっています。
$ pwd /cloned/path/to/go/bin $ ls ./ ../ go* main.go
この状態で
$ gdb go (gdb) b main.main Breakpoint 1 at... (gdb) r build main.go Starting program: /cloned/path/to/go/bin/go build main.go [New Thread 0x121f of process 50639] [New Thread 0x1403 of process 50639] [New Thread 0x1503 of process 50639] [New Thread 0x1603 of process 50639] [New Thread 0x1703 of process 50639] Thread 1 hit Breakpoint 1... 118 func main() { (gdb)
これで読み進めていけます。
next を cmd.Run(cmd, args)
まで行う
cmd.Run(cmd, args)
は 181 行目 に存在します。commands から range を用いて、 cmd に代入していっている様子がわかりますね。つまりこれが各サブコマンドの実行時のコードとなるわけです。
cmd.Run(cmd, args)
まで来たら
(gdb) s
で中を見てみましょう。
runBuild(cmd *Command, args []string)
の中へステップできたと思います。
/src/cmd/go/build.go
を読んでいく
ここから先は自分の読みたいところを読んでいきましょう。 ここから先は僕の作業ログです。有りえないほど汚いです。
func runBuild
が実行されることを知り,(gdb) b main.runBuild
- 読み進めていき、build.go:448 の
switch buildContext.Compiler {
へ到着します。今回の場合条件分岐はcase "gc"
になりました。 (gdb) b 467
(gdb) c
a := b.action(modeInstall, depMode, p)
へやってきました。この処理がどうなっているか見ていきます。(gdb) s
func (b *builder) action(mode buildMode, depMode buildMode, p *Package) *action { return b.action1(mode, depMode, p, false, "") }
なんだよ b.action1
って!!となりましたが続けます。
build.go の 900 行目です。
return b.action1(mode, depMode, p, false, "")
の所で(gdb) s
を実行しメソッド内へ(gdb) b 1000
を実行
ここでちょこちょこ出てくる modeBuild
, modeInstall
が気になりました。これらの正体は
const ( modeBuild buildMode = iota modeInstall )
なんと iota
さんじゃないですかー :smile:
(gdb) p mode
を実行。 mode == 1 だったので modeInstall
なんだこれは...
a.f = (*builder).install
builder は構造体で、元を辿ると build.go:477 の b.action()
の b
です。
つまり builder から生えてる install メソッドですね!!
そして次の行。
a.deps = []*action{b.action1(modeBuild, depMode, p, lookshared, forShlib)}
またお前か!! >> b.action1
!!
どうやら今回は modeBuild
になる様子。先ほど b 1000
していたので (gdb) n
を実行するとネストで実行された b.action1
の中の 1000 行目で止まります。 (gdb) n
で 1030 行目へ。
a.f = (*builder).build
install と同様、 builder から生えてる build メソッドでした!! んでまたどんどん進めていくと。 - 1055 で作成された action を return することが分かります。
この時の (gdb) bt
です。
(gdb) bt #0 main.(*builder).action1 (b=0xc4201a5c00, mode=0, depMode=0, p=0xc4201c0000, lookshared=false, forShlib="", ~r5=0x0) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1055 #1 0x000000000000c784 in main.(*builder).action1 (b=0xc4201a5c00, mode=1, depMode=0, p=0xc4201c0000, lookshared=false, forShlib="", ~r5=0x0) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1004 #2 0x000000000000b139 in main.(*builder).action (b=0xc4201a5c00, mode=1, depMode=0, p=0xc4201c0000, ~r3=0x0) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:893 #3 0x0000000000006a47 in main.runBuild (cmd=0x64d540 <main.statictmp_5573>, args= []string = {...}) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:477 #4 0x00000000000498a8 in main.main () at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/main.go:181
main() の中の runBuild() 内の b.action() 中の b.action1() のネストの b.action1() が return されることが分かります。これから b.action() としていた理由は action を生成するためのネストしないメソッドだったことが分かりますね!( b.action 自体をネストするのは良くなかったのか...??)
元の b.action1 に戻ってきました。(/src/cmd/go/build.go の 1005行目) next を実行していくと...
main.runBuild (cmd=0x64d540 <main.statictmp_5573>, args= []string = {...}) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:478 478 b.do(a)
やっとで戻ってきましたねー 素早く backtrace を カチャカチャカチャッターン!!
#0 main.runBuild (cmd=0x64d540 <main.statictmp_5573>, args= []string = {...}) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:478 #1 0x00000000000498a8 in main.main () at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/main.go:181
ただいま! main.runBuild !! ここにいます。
b.do(a)
を追う
この記事を書きながら実行しているので予想ですが、このメソッドがコンパイルを行っているんだと思います!(ここでコンパイルしてくれ!!) ちなみにこのコードは build.go:1223 です。
ソースコードにはコメントがあります。
// Build list of all actions, assigning depth-first post-order priority. // The original implementation here was a true queue // (using a channel) but it had the effect of getting // distracted by low-level leaf actions to the detriment // of completing higher-level actions. The order of // work does not matter much to overall execution time, // but when running "go test std" it is nice to see each test // results as soon as possible. The priorities assigned // ensure that, all else being equal, the execution prefers // to do what it would have done first in a simple depth-first // dependency order traversal. all := actionList(root)
actionlist を作って 深さ優先探索の後順で並び替えるということ? leaf action というのは探索木の葉の位置に存在する action の事。
とりあえずこの並び替えによって全体の実行時間に影響がないことは分かりました。
深さ優先探索の後順というのはこういうものです。(懐かしい感じ)
1240行目から始めます。
(gdb) n
(gdb) p all
こういう結果が得られました。
$3 = []*main.action = {0xc420432340, 0xc420432410, 0xc420432270, 0xc4204321a0, 0xc4204324e0, 0xc4204320d0} (gdb) p *all.array[0] $4 = {p = 0xc4201c1200, deps = []*main.action, triggers = []*main.action, cgo = 0x0, args = []string, testOutput = 0x0, f = {void (struct main.builder *, struct main.action *, error *)} 0xc420432340, ignoreFail = false, link = false, pkgdir = "/usr/local/opt/go/libexec/pkg", objdir = "", objpkg = "", target = "", pending = 0, priority = 0, failed = false} (gdb) p *all.array[1] $5 = {p = 0xc4201c1680, deps = []*main.action, triggers = []*main.action, cgo = 0x0, args = []string, testOutput = 0x0, f = {void (struct main.builder *, struct main.action *, error *)} 0xc420432410, ignoreFail = false, link = false, pkgdir = "/usr/local/opt/go/libexec/pkg", objdir = "", objpkg = "", target = "/usr/local/opt/go/libexec/pkg/darwin_amd64/runtime/internal/sys.a", pending = 0, priority = 0, failed = false} (gdb) p *all.array[2] $6 = {p = 0xc4201c0d80, deps = []*main.action = {0xc420432340, 0xc420432410}, triggers = []*main.action, cgo = 0x0, args = []string, testOutput = 0x0, f = {void (struct main.builder *, struct main.action *, error *)} 0xc420432270, ignoreFail = false, link = false, pkgdir = "/usr/local/opt/go/libexec/pkg", objdir = "", objpkg = "", target = "/usr/local/opt/go/libexec/pkg/darwin_amd64/runtime/internal/atomic.a", pending = 0, priority = 0, failed = false} (gdb) p *all.array[3] $7 = {p = 0xc4201c0480, deps = []*main.action = {0xc420432270, 0xc420432410, 0xc420432340, 0xc420432410}, triggers = []*main.action, cgo = 0x0, args = []string, testOutput = 0x0, f = {void (struct main.builder *, struct main.action *, error *)} 0xc4204321a0, ignoreFail = false, link = false, pkgdir = "/usr/local/opt/go/libexec/pkg", objdir = "", objpkg = "", target = "/usr/local/opt/go/libexec/pkg/darwin_amd64/runtime.a", pending = 0, priority = 0, failed = false} (gdb) p *all.array[4] $8 = {p = 0xc4201c0000, deps = []*main.action = {0xc4204321a0}, triggers = []*main.action, cgo = 0x0, args = []string, testOutput = 0x0, f = {void (struct main.builder *, struct main.action *, error *)} 0xc4204324e0, ignoreFail = false, link = true, pkgdir = "", objdir = "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build184457028/command-line-arguments/_obj/", objpkg = "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build184457028/command-line-arguments.a", target = "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build184457028/command-line-arguments/_obj/exe/a.out", pending = 0, priority = 0, failed = false} (gdb) p *all.array[5] $9 = {p = 0xc4201c0000, deps = []*main.action = {0xc4204324e0}, triggers = []*main.action, cgo = 0x0, args = []string, testOutput = 0x0, f = {void (struct main.builder *, struct main.action *, error *)} 0xc4204320d0, ignoreFail = false, link = true, pkgdir = "", objdir = "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build184457028/command-line-arguments/_obj/", objpkg = "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build184457028/command-line-arguments.a", target = "main", pending = 0, priority = 0, failed = false}
a.f
はクロージャですね! a.deps
は action のスライスのようです。
なんかすごい。こうやって見ていくと objdir や objpkg から go もオブジェクトファイルを作っていたんだ!という驚きがありますね!
(gdb) n
で進めていく。- 1245 行目,
b.readySema = make(chan bool, len(all))
- b.readySema を queue として扱っているようです。
- b は builder 構造体のポインタです。現在の中身はこうなってます。
(gdb) p *b $20 = {work = "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build184457028", actionCache = map[main.cacheKey]*main.action = {[{mode = 1, p = 0xc4201c0000, shlib = ""}] = 0xc4204320d0, [{mode = 0, p = 0xc4201c0480, shlib = ""}] = 0xc4204321a0, [{mode = 0, p = 0xc4201c0d80, shlib = ""}] = 0xc420432270, [{mode = 0, p = 0xc4201c1200, shlib = ""}] = 0xc420432340, [{mode = 0, p = 0xc4201c1680, shlib = ""}] = 0xc420432410, [{mode = 0, p = 0xc4201c0000, shlib = ""}] = 0xc4204324e0}, mkdirCache = map[string]bool, flagCache = map[string]bool<error reading variable: Cannot access memory at address 0x9>, print = {void (struct []interface {}, int *, error *, ...)} 0xc4201a5c00, output = {state = 0, sema = 0}, scriptDir = "", exec = {state = 0, sema = 0}, readySema = 0xc4204143f0, ready = { array = 0x0, len = 0, cap = 0}}
...(結構疲れてきた)
- 1248 行目へ
- ここで action を action.deps の中の action.triggers に push していく(何故これを行うのか分からないです)
- 1261 行目でクロージャを作成
- 1306 行目からビルドの始まり
1259 // Handle runs a single action and takes care of triggering 1260 // any actions that are runnable as a result. 1261 handle := func(a *action) { 1262 var err error 1263 if a.f != nil && (!a.failed || a.ignoreFail) { 1264 err = a.f(b, a) 1265 }
先ほど a.f
がクロージャだということは理解してるので 1264 行目に breakpoint を仕掛けます。
(gdb) b build.go:1264
(gdb) c
Thread 6 hit Breakpoint 4, main.(*builder).do.func1 (a=0xc42041e4e0) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1264 1264 err = a.f(b, a) (gdb) s main.(*builder).build (b=0xc4201c1c00, a=0xc420454340, err=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1334 1334 func (b *builder) build(a *action) (err error) {
この結果見て気づいたのは、メソッド呼び出しをクロージャから行う場合、引数を二つ渡してあげることで可能なことが分かりました。
(gdb) l
でソースコードを見ていくと
1493 // Prepare Go import path list. 1494 inc := b.includeArgs("-I", allArchiveActions(a)) 1495 1496 // Compile Go. 1497 ofile, out, err := buildToolchain.gc(b, a.p, a.objpkg, obj, len(sfiles) > 0, inc, gofiles)
よし、見ていくぞ!!
(gdb) b 1497
(gdb) c
Thread 7 hit Breakpoint 5, main.(*builder).build (b=0xc420193c00, a=0xc420428410, err=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1497 1497 ofile, out, err := buildToolchain.gc(b, a.p, a.objpkg, obj, len(sfiles) > 0, inc, gofiles) (gdb) s main.(*gcToolchain).gc (this=0x670e50 <runtime.zerobase>, b=0xc4201b6070, p=0xc4201ca000, archive="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build692270690/command-line-arguments.a", obj="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build692270690/command-line-arguments/_obj/", asmhdr=false, importArgs= []string = {...}, gofiles= []string = {...}, ofile="", output= []uint8, err=...) at <autogenerated>:5 5 <autogenerated>: No such file or directory.
引数の量がすごいという印象。そこは置いておいて、ここで急に l
や n
が効かなくなって困ったので、もう一度、ソースコードを読んで breakpoint を仕掛けてみます。
ソースコードは cmd/go/build.go の 2264 行目です。
この中の 2322 行目の b.runOut
が気になったのでそこで breakpoint を仕掛けます。
(gdb) b cmd/go/build.go:2322
(gdb) s
(gdb) l
(gdb) l
こうするとこれくらいのソースコードを gdb で表示できますね。
2034 return messages 2035 } 2036 2037 // runOut runs the command given by cmdline in the directory dir. 2038 // It returns the command output and any errors that occurred. 2039 func (b *builder) runOut(dir string, desc string, env []string, cmdargs ...interface{}) ([]byte, error) { 2040 cmdline := stringList(cmdargs...) 2041 if buildN || buildX { 2042 var envcmdline string 2043 for i := range env { (gdb) 2044 envcmdline += env[i] 2045 envcmdline += " " 2046 } 2047 envcmdline += joinUnambiguously(cmdline) 2048 b.showcmd(dir, "%s", envcmdline) 2049 if buildN { 2050 return nil, nil 2051 } 2052 } 2053 (gdb) 2054 nbusy := 0 2055 for { 2056 var buf bytes.Buffer 2057 cmd := exec.Command(cmdline[0], cmdline[1:]...) 2058 cmd.Stdout = &buf 2059 cmd.Stderr = &buf 2060 cmd.Dir = dir 2061 cmd.Env = mergeEnvLists(env, envForDir(cmd.Dir, os.Environ())) 2062 err := cmd.Run() 2063
cmd.Run()
を実行してる時点で外部コマンドを実行していることが分かりますね!(まじかよ...)
とりあえず cmdline
を読んでみましょう。
(gdb) n
(gdb) p cmdline
$1 = []string = {"/usr/local/opt/go/libexec/pkg/tool/darwin_amd64/compile", "-o", "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments.a", "-trimpath", "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832", "-p", "main", "-complete", "-buildid", "c9a41e1d0bf90f085a8ae6008ac361fb59c7a503", "-D", "_/Users/CodeHex/.ghq/github.com/go/bin", "-I", "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832", "-pack", "/Users/CodeHex/.ghq/github.com/go/bin/main.go"}
こういう感じに go の compile コマンドを使って archive ファイル*1を作り出してることが分かりますね!
しかしこれだけだと archive ファイルを作って終わりなので、実行ファイルができているということは何かしらリンクが行われていることを予想し、(gdb) b cmd/go/build.go:2039
を行いました。するとどうでしょう
$2 = []string = {"/usr/local/opt/go/libexec/pkg/tool/darwin_amd64/link", "-o", "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments/_obj/exe/a.out", "-L", "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832", "-extld=clang", "-buildmode=exe", "-buildid=c9a41e1d0bf90f085a8ae6008ac361fb59c7a503", "/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments.a"}
link コマンドってあったのかー! ちなみに backtrace は
(gdb) bt #0 main.(*builder).runOut (b=0xc420192070, dir=".", desc="command-line-arguments", env= []string, cmdargs= []interface {} = {...}, ~r4= []uint8, ~r5=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:2041 #1 0x000000000001b308 in main.(*builder).run (b=0xc420192070, dir=".", desc="command-line-arguments", env= []string, cmdargs= []interface {} = {...}, ~r4=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:2007 #2 0x0000000000022dbe in main.gcToolchain.ld (b=0xc420192070, root=0xc420403520, out="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments/_obj/exe/a.out", allactions= []*main.action = {...}, mainpkg="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments.a", ofiles= []string, ~r6=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:2530 #3 0x000000000008d030 in main.(*gcToolchain).ld (this=0x670e50 <runtime.zerobase>, b=0xc420192070, root=0xc420403520, out="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments/_obj/exe/a.out", allactions= []*main.action = {...}, mainpkg="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build038795832/command-line-arguments.a", ofiles= []string, ~r6=...) at <autogenerated>:9 #4 0x0000000000014ccb in main.(*builder).build (b=0xc420192070, a=0xc420403520, err=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1583 #5 0x0000000000084125 in main.(*builder).do.func1 (a=0xc420403520) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1264 #6 0x000000000008462b in main.(*builder).do.func2 (&wg=0xc42041a150, b=0xc420192070, handle={void (struct main.action *)} 0xc420111f88) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1321 #7 0x00000000000ebec1 in runtime.goexit () at /Users/CodeHex/.ghq/github.com/go/src/runtime/asm_amd64.s:2086 #8 0x000000c42041a150 in ?? () #9 0x000000c420192070 in ?? () #10 0x000000c42040f7e0 in ?? () #11 0x0000000000000000 in ?? ()
もともとは main.gcToolchain.ld
から呼び出されているようですね!
しかし link コマンドを実行する際の引数を見て分かる通り、a.out
を吐いていますね。しかし、go build を実行したカレントディレクトリに build したソースコードと同一名のバイナリが吐き出されるはずなので、 a.out
を作った後、move を実行しているに違いないと考えました。検索してみると、moveOrCopyFile
というのがいましたねー
一度処理を終了させて、(gdb) b cmd/go/build.go:1732
を行いもう一度実行してみます。
Thread 4 hit Breakpoint 1, main.(*builder).runOut (b=0xc4201b6070, dir="/Users/CodeHex/.ghq/github.com/go/bin", desc="command-line-arguments", env= []string, cmdargs= []interface {} = {...}, ~r4= []uint8, ~r5=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:2039 2039 func (b *builder) runOut(dir string, desc string, env []string, cmdargs ...interface{}) ([]byte, error) { (gdb) c Continuing. Thread 4 hit Breakpoint 1, main.(*builder).runOut (b=0xc4201b6070, dir=".", desc="command-line-arguments", env= []string, cmdargs= []interface {} = {...}, ~r4= []uint8, ~r5=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:2039 2039 func (b *builder) runOut(dir string, desc string, env []string, cmdargs ...interface{}) ([]byte, error) { (gdb) c Continuing. [Switching to Thread 0x1afb of process 53762] Thread 6 hit Breakpoint 2, main.(*builder).moveOrCopyFile (b=0xc4201b6070, a=0xc420427110, dst="main", src="/var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build294100860/command-line-arguments/_obj/exe/a.out", perm=511, force=false, ~r5=...) at /Users/CodeHex/.ghq/github.com/go/src/cmd/go/build.go:1732 1732 func (b *builder) moveOrCopyFile(a *action, dst, src string, perm os.FileMode, force bool) error {
ビンゴですね!
2 回コマンド(compile, link)を実行した後にカレントディレクトリへ move を実行してそうです。
この時以下のコマンドを別プロセスの shell から実行してみました。
$ ls /var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build294100860/command-line-arguments/_obj/exe ./ ../ a.out* $ /var/folders/8b/tw364d5n15qc3wdz3k622qxm0000gn/T/go-build294100860/command-line-arguments/_obj/exe/a.out Hello, World
これを確認した後に gdb 側で move の処理を終了させてみます。moveOrCopyFile
内の os.Rename(src, dst) の行
ですね!そこに breakpoint を仕掛けます。
そして (gdb) n
を実行すると、カレントディレクトリに main バイナリが作成されます!やったね!
まとめ
- go build はコマンドのラッパーである
- pure go の go build は
compile
,link
を実行する /var
以下にランダムなディレクトリが作成されてその中にa.out
が作成される- 最終的にカレントディレクトにへ move を行う
結局コンパイル時に何をやっているかについては compile コマンドをデバッグしないと分からないので、今度はそれにチャレンジをしてみようと思います。