アルパカ三銃士

〜アルパカに酔いしれる獣たちへ捧げる〜

go build をデバッグしてみた

環境

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:448switch 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:477b.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 の事。 とりあえずこの並び替えによって全体の実行時間に影響がないことは分かりました。
深さ優先探索の後順というのはこういうものです。(懐かしい感じ)
tree_postorder_traverse
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.

引数の量がすごいという印象。そこは置いておいて、ここで急に ln が効かなくなって困ったので、もう一度、ソースコードを読んで 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 コマンドをデバッグしないと分からないので、今度はそれにチャレンジをしてみようと思います。

*1:ar コマンドという archive ファイルを操作できるコマンドがありますが、tar は ar の一般化したものだという話を最近講義で習いました。多分このこと