New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cmd/link: combining dwarf on darwin can be very slow #12259

Open
ianic opened this Issue Aug 21, 2015 · 28 comments

Comments

Projects
None yet
@ianic

ianic commented Aug 21, 2015

I'm noticing ~15x increase in build time when switched to go 1.5.
It is somehow connected with a package github.com/ry/v8worker - binding for v8 javascript engine.
I'm building on OS X.

This is a trivial program:

package main
import _ "github.com/ry/v8worker"

func main() {
}

1.4 build time:
real 0m1.075s
user 0m0.964s
sys 0m0.108s

1.5 build time:
real 0m16.816s
user 0m16.225s
sys 0m1.226s

Go 1.5 spends almost all of the time on the link step:
/usr/local/Cellar/go/1.5/libexec/pkg/tool/darwin_amd64/link -o $WORK/slow_build/_obj/exe/a.out -L $WORK -L /Users/ianic/work/web/src/golang/pkg/darwin_amd64 -extld=clang++ -buildmode=exe -buildid=14ca37ec220e553c7bf9829fe97751df5a041f5f $WORK/slow_build.a

1.4 output for: time go build -v -x
WORK=/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-build829145301
slow_build
mkdir -p $WORK/slow_build/_obj/
mkdir -p $WORK/slow_build/_obj/exe/
cd /Users/ianic/work/web/src/golang/src/slow_build
/usr/local/Cellar/go/1.4.2/libexec/pkg/tool/darwin_amd64/6g -o $WORK/slow_build.a -trimpath $WORK -p slow_build -complete -D _/Users/ianic/work/web/src/golang/src/slow_build -I $WORK -I /Users/ianic/work/web/src/golang/pkg/darwin_amd64 -pack ./main.go
cd .
/usr/local/Cellar/go/1.4.2/libexec/pkg/tool/darwin_amd64/6l -o $WORK/slow_build/_obj/exe/a.out -L $WORK -L /Users/ianic/work/web/src/golang/pkg/darwin_amd64 -extld=clang++ $WORK/slow_build.a
mv $WORK/slow_build/_obj/exe/a.out slow_build

real 0m1.075s
user 0m0.964s
sys 0m0.108s

1.5 output for: time go build -v -x
WORK=/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-build145414805
slow_build
mkdir -p $WORK/slow_build/_obj/
mkdir -p $WORK/slow_build/_obj/exe/
cd /Users/ianic/work/web/src/golang/src/slow_build
/usr/local/Cellar/go/1.5/libexec/pkg/tool/darwin_amd64/compile -o $WORK/slow_build.a -trimpath $WORK -p main -complete -buildid 14ca37ec220e553c7bf9829fe97751df5a041f5f -D _/Users/ianic/work/web/src/golang/src/slow_build -I $WORK -I /Users/ianic/work/web/src/golang/pkg/darwin_amd64 -pack ./main.go
cd .
/usr/local/Cellar/go/1.5/libexec/pkg/tool/darwin_amd64/link -o $WORK/slow_build/_obj/exe/a.out -L $WORK -L /Users/ianic/work/web/src/golang/pkg/darwin_amd64 -extld=clang++ -buildmode=exe -buildid=14ca37ec220e553c7bf9829fe97751df5a041f5f $WORK/slow_build.a
mv $WORK/slow_build/_obj/exe/a.out slow_build

real 0m16.816s
user 0m16.225s
sys 0m1.226s

@ianlancetaylor ianlancetaylor changed the title from slow build on Go 1.5 to cmd/link: slow build on Go 1.5 Aug 21, 2015

@ianlancetaylor ianlancetaylor added this to the Go1.6 milestone Aug 21, 2015

@mwhudson

This comment has been minimized.

Contributor

mwhudson commented Aug 24, 2015

Can you try again with -ldflags="-v=2"? I'm willing to have a look at this if you can tell me how to reproduce it on linux (I don't have access to OS X).

@ianic

This comment has been minimized.

ianic commented Aug 24, 2015

Just tried this on linux. Linux build time is ok.
For example (in a docker container):
real 0m1.459s
user 0m1.180s
sys 0m0.340s

This is output of a build with added -ldflags="-v=2" on OS X:

~/work/web/src/golang/src/slow_build>time  go build -ldflags="-v=2"
# slow_build
HEADER = -H1 -T0x2000 -D0x0 -R0x1000
 0.00 addlibpath: srcref: command line objref: command line file: $WORK/slow_build.a pkg: main shlibnamefile:
searching for runtime.a in $WORK/runtime.a
searching for runtime.a in /Users/ianic/work/web/src/golang/pkg/darwin_amd64/runtime.a
searching for runtime.a in /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime.a
 0.00 addlibpath: srcref: internal objref: internal file: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime.a pkg: runtime shlibnamefile:
 0.00 autolib: $WORK/slow_build.a (from command line)
 0.00 ldobj: $WORK/slow_build.a (main)
 0.00 addlib: $WORK/slow_build.a(_go_.o) main pulls in /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a isshlib false
 0.00 addlibpath: srcref: main objref: $WORK/slow_build.a(_go_.o) file: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a pkg: github.com/ry/v8worker shlibnamefile:
 0.00 autolib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime.a (from internal)
 0.00 ldobj: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime.a (runtime)
 0.07 autolib: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a (from $WORK/slow_build.a(_go_.o))
 0.07 ldobj: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a (github.com/ry/v8worker)
 0.07 addlib: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) github.com/ry/v8worker pulls in /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime/cgo.a isshlib false
 0.07 addlibpath: srcref: github.com/ry/v8worker objref: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) file: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime/cgo.a pkg: runtime/cgo shlibnamefile:
 0.07 addlib: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) github.com/ry/v8worker pulls in /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/syscall.a isshlib false
 0.07 addlibpath: srcref: github.com/ry/v8worker objref: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) file: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/syscall.a pkg: syscall shlibnamefile:
 0.07 addlib: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) github.com/ry/v8worker pulls in /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/errors.a isshlib false
 0.07 addlibpath: srcref: github.com/ry/v8worker objref: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) file: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/errors.a pkg: errors shlibnamefile:
 0.07 addlib: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) github.com/ry/v8worker pulls in /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a isshlib false
 0.07 addlibpath: srcref: github.com/ry/v8worker objref: /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o) file: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a pkg: sync shlibnamefile:
 0.07 autolib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime/cgo.a (from /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o))
 0.07 ldobj: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/runtime/cgo.a (runtime/cgo)
 0.07 autolib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/syscall.a (from /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o))
 0.07 ldobj: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/syscall.a (syscall)
 0.08 autolib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/errors.a (from /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o))
 0.08 ldobj: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/errors.a (errors)
 0.08 autolib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a (from /Users/ianic/work/web/src/golang/pkg/darwin_amd64/github.com/ry/v8worker.a(_go_.o))
 0.08 ldobj: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a (sync)
 0.08 addlib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a(_go_.o) sync pulls in /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync/atomic.a isshlib false
 0.08 addlibpath: srcref: sync objref: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a(_go_.o) file: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync/atomic.a pkg: sync/atomic shlibnamefile:
 0.09 autolib: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync/atomic.a (from /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync.a(_go_.o))
 0.09 ldobj: /usr/local/Cellar/go/1.5/libexec/pkg/darwin_amd64/sync/atomic.a (sync/atomic)
 0.09 deadcode
marktext _rt0_amd64_darwin
...
marktext type..eq.runtime.specialfinalizer
 0.10 pclntab=167683 bytes, funcdata total 35028 bytes
 0.10 dodata
 0.11 symsize = 0
 0.11 symsize = 0
 0.11 reloc
 0.12 reloc
 0.12 asmb
 0.12 codeblk
 0.13 datblk
 0.13 dwarf
 0.13 symsize = 0
 0.15 dwarf pass 2.
 0.16 sym
 0.16 headr
host link: "clang++" "-m64" "-gdwarf-2" "-Wl,-no_pie,-headerpad,1144" "-Wl,-pagezero_size,4000000" "-o" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-build933611755/slow_build/_obj/exe/a.out" "-Qunused-arguments" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-link-403087664/000000.o" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-link-403087664/000001.o" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-link-403087664/go.o" "-g" "-O2" "-stdlib=libstdc++" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_libbase.a" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_base.a" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_libplatform.a" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_snapshot.a" "-g" "-O2" "-lpthread"
16.08 cpu time
23501 symbols
17716 liveness data

real    0m16.179s
user    0m15.854s
sys 0m1.169s
@mwhudson

This comment has been minimized.

Contributor

mwhudson commented Aug 24, 2015

@minux

This comment has been minimized.

Member

minux commented Aug 24, 2015

@ianic

This comment has been minimized.

ianic commented Aug 25, 2015

If I understand correctly both 1.4.2 6l and 1.5 link are using clang++ in link step.
Here is the possibly interesting output of go build -ldflags "-v" for 1.4.2 and 1.5
The only significant difference my eye catches is "-headerpad,1144 " directive.

1.4.2

host link: clang++ -m64 -gdwarf-2 -Wl,-no_pie,-pagezero_size,4000000 -o $WORK/slow_build/_obj/exe/a.out -Qunused-arguments /var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T//go-link-Ivwtxz/000000.o /var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T//go-link-Ivwtxz/000001.o /var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T//go-link-Ivwtxz/go.o -g -O2 -stdlib=libstdc++ /Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_libbase.a /Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_base.a /Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_libplatform.a /Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_snapshot.a -g -O2 -lpthread
 1.00 cpu time
12955 symbols
64 sizeof adr
216 sizeof prog
4176 liveness data

1.5

host link: "clang++" "-m64" "-gdwarf-2" "-Wl,-no_pie,-headerpad,1144" "-Wl,-pagezero_size,4000000" "-o" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-build617732236/slow_build/_obj/exe/a.out" "-Qunused-arguments" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-link-655818683/000000.o" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-link-655818683/000001.o" "/var/folders/dx/p9b300dd27dcbqcrz0h9kn800000gn/T/go-link-655818683/go.o" "-g" "-O2" "-stdlib=libstdc++" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_libbase.a" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_base.a" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_libplatform.a" "/Users/ianic/work/web/src/golang/src/github.com/ry/v8worker/v8/out/native/libv8_snapshot.a" "-g" "-O2" "-lpthread"
15.20 cpu time
23493 symbols
17716 liveness data
mv $WORK/slow_build/_obj/exe/a.out slow_build

And little more readable:
1.4

host link: clang++ -m64 -gdwarf-2 -Wl,-no_pie,-headerpad,1144 -Wl,-pagezero_size,4000000 -o .../slow_build/_obj/exe/a.out -Qunused-arguments .../go-link-655818683/000000.o .../go-link-655818683/000001.o .../go-link-655818683/go.o -g -O2 -stdlib=libstdc++ .../native/libv8_libbase.a  .../native/libv8_base.a .../native/libv8_libplatform.a .../native/libv8_snapshot.a -g -O2 -lpthread

1.5

host link: clang++ -m64 -gdwarf-2 -Wl,-no_pie,                    -pagezero_size,4000000 -o .../slow_build/_obj/exe/a.out -Qunused-arguments .../go-link-foZGHw/000000.o    .../go-link-foZGHw/000001.o    .../go-link-foZGHw/go.o    -g -O2 -stdlib=libstdc++ .../native/libv8_libbase.a  .../native/libv8_base.a .../native/libv8_libplatform.a .../native/libv8_snapshot.a -g -O2 -lpthread
@mwhudson

This comment has been minimized.

Contributor

mwhudson commented Aug 25, 2015

Oh, one thing that is new on OS X on darwin is the stuff around combining the debug information. Try -ldflags=-s ?

@ianic

This comment has been minimized.

ianic commented Aug 25, 2015

Flag -s has impact, build time dropped from ~16 to ~2s.
In link arguments -gdwarf-2 is replaced with -s (there is a notice that -s is ignored).

time go build
host link: "clang++" "-m64" "-gdwarf-2" "-Wl,-no_pie,-headerpad,1144" "-Wl,-pagezero_size,4000000" ...
real 0m16.863s
user 0m16.599s
sys 0m1.372s

time go build -ldflags "-s"
host link: "clang++" "-m64" "-s" "-Wl,-no_pie,-headerpad,1144" "-Wl,-pagezero_size,4000000" ...
ld: warning: option -s is obsolete and being ignored
real 0m2.361s
user 0m1.972s
sys 0m0.500s

@minux

This comment has been minimized.

Member

minux commented Aug 25, 2015

@mwhudson

This comment has been minimized.

Contributor

mwhudson commented Aug 25, 2015

Sure, but surely that should be a different bug. I think it makes sense to retitle this one "cmd/link: combining dwarf on darwin can be very slow" or something.

@minux minux changed the title from cmd/link: slow build on Go 1.5 to cmd/link: combining dwarf on darwin can be very slow Aug 25, 2015

@minux minux modified the milestones: Go1.5.1, Go1.6 Aug 25, 2015

@minux

This comment has been minimized.

Member

minux commented Aug 25, 2015

@freeformz

This comment has been minimized.

Contributor

freeformz commented Aug 25, 2015

@minux is there a separate issue open to track the linux compile speed issues?

@minux

This comment has been minimized.

Member

minux commented Aug 25, 2015

@ianlancetaylor ianlancetaylor modified the milestones: Go1.5.2, Go1.5.1 Sep 8, 2015

@rsc

This comment has been minimized.

Contributor

rsc commented Nov 13, 2015

The fact that -s helps does not imply that the problem is the DWARF combining code, as implied by the current issue title. It could be that clang++ is slow to generate the debug info during host link on the Mac, or it could be that dsymutil, used to pull it out, is slow. We need to understand which one.

I can't reproduce this on my Mac, because I don't have pkg-config. Can you try applying this diff:

diff --git a/src/cmd/link/internal/ld/lib.go b/src/cmd/link/internal/ld/lib.go
index e1be263..cda7cf0 100644
--- a/src/cmd/link/internal/ld/lib.go
+++ b/src/cmd/link/internal/ld/lib.go
@@ -1164,6 +1164,7 @@ func hostlink() {
    }

    if Debug['s'] == 0 && debug_s == 0 && HEADTYPE == obj.Hdarwin {
+       return
        // Skip combining dwarf on arm.
        if Thearch.Thechar != '5' && Thearch.Thechar != '7' {
            dsym := fmt.Sprintf("%s/go.dwarf", tmpdir)
@@ -1175,6 +1176,7 @@ func hostlink() {
            if _, err := os.Stat(dsym); os.IsNotExist(err) {
                return
            }
+           return
            // For os.Rename to work reliably, must be in same directory as outfile.
            combinedOutput := outfile + "~"
            if err := machoCombineDwarf(outfile, dsym, combinedOutput); err != nil {

Then rebuild with make.bash and then see what that does to the timings.
Are they better?
If so, remove the first new return (but leave the second) and try again.
Are they still better?

Thanks.

@rsc

This comment has been minimized.

Contributor

rsc commented Nov 18, 2015

A 15 second link is annoying but probably not worth a significant change in a point release.

@rsc rsc modified the milestones: Go1.6, Go1.5.2 Nov 18, 2015

@ianic

This comment has been minimized.

ianic commented Nov 19, 2015

Version with two returns makes difference.
Here are the measurements on the trivial code from the top.

Before:

real 0m14.468s
user 0m12.504s
sys  0m1.812s

With both returns:

real 0m2.412s
user 0m2.006s
sys  0m0.479s

After removing first return:

real 0m14.240s
user 0m12.397s
sys  0m1.614s
@rsc

This comment has been minimized.

Contributor

rsc commented Nov 19, 2015

OK, great. Thanks. That confirms it really is machoCombineDwarf and not clang++.

@rsc

This comment has been minimized.

Contributor

rsc commented Dec 17, 2015

Hmm. I got v8worker working but I can't reproduce the problem still. I see the combining step happening but it takes under a second. Of course, I probably have a different version of Xcode than you do, that is probably writing out different files.

If you can still see this happening, please try adding -ldflags '-cpuprofile=/tmp/link.prof' and then run go tool pprof $(go tool -n link) /tmp/link.prof and play around. Useful commands: top10, web. See also http://blog.golang.org/profiling-go-programs. If you do get a profile I'd be interested to see it:

go tool pprof --svg $(go tool -n link) /tmp/link.prof >/tmp/link.prof.svg

Thanks.

@rsc rsc modified the milestones: Go1.6Maybe, Go1.6 Dec 17, 2015

@ianic

This comment has been minimized.

ianic commented Dec 23, 2015

It's not better with the latest head.

real 0m14.725s
user 0m12.324s
sys  0m2.031s

Here is the profile output:
link.prof.gz

I have Xcode 7.0 (7A220), and xcode command line tools.

gcc --version
Configured with: --prefix=/Applications/Xcode.app/Contents/Developer/usr --with-gxx-include-dir=/usr/include/c++/4.2.1
Apple LLVM version 7.0.0 (clang-700.0.72)
Target: x86_64-apple-darwin15.2.0
Thread model: posix
@sethwklein

This comment has been minimized.

sethwklein commented Jan 3, 2016

I too have a codebase that uses v8worker and compiles much more slowly than it used to.

I see 3s builds with -ldflags=-s and 18s without. (If I forget to touch one of the source files, it's 0.5s.) Only a little of that (pprof claims 2s) is spent in the linker. The OS X thing that shows what command is running in Terminal.app's title bar suggests most of the full run time is spent in llvm-dsymutil.

--- sk@silver: $
which llvm-dsymutil
--- sk@silver:~ $
find /Applications/Xcode.app -name llvm-dsymutil
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/llvm-dsymutil
--- sk@silver:~ $
/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/llvm-dsymutil -v
Apple LLVM 7.0.2 (clang-700.1.81)
--- sk@silver:~ $
go version
go version devel +e2093cd Sun Jan 3 20:52:07 2016 +0000 darwin/amd64
--- sk@silver:~ $

OS X 10.10.5.
XCode Version 7.2 (7C68).

Does this help? Do we need to create a better reproduction case? Is there more information I can provide? (Is this too many questions in one place? 😉 )

@rsc

This comment has been minimized.

Contributor

rsc commented Jan 6, 2016

@sethwklein, thanks. Are you by any chance on OS X before 10.11 El Capitan? The profile seems incomplete in the way caused by earlier versions of OS X. If you are in fact on an older OS X, one option is to try on a newer OS X, and another option is to patch your kernel with rsc.io/pprof_mac_fix. I understand that perhaps neither may be an option.

@sethwklein

This comment has been minimized.

sethwklein commented Jan 7, 2016

How embarrassing. The kext that fixes that refuses to load at boot like it's supposed to and I forgot about it. Hopefully, this is better and sorry for your wasted time: link-pprof-sethwklein-psignalfix-2016-01-06.tar.gz

(BTW, if you need to check what versions I'm running, I pasted a bunch of them a couple-four posts up.)

@rsc

This comment has been minimized.

Contributor

rsc commented Jan 7, 2016

@sethwklein

This comment has been minimized.

sethwklein commented Jan 7, 2016

I probably could post the final binary from the previous run, but I'd rather not. It's my personal information manager and may have personal information in it. But here's a run with the test case from the OP which also exhibits 16s builds normally and sub 2s with -ldflags=-s for me. The binary makes it bigger than GitHub will host so I've hosted it: link-pprof-sethwklein-testcase-2016-01-07.tar.gz.

When wondering what could differ between my setup and yours, @rsc, I realize that I installed v8worker on 16 June 2015, and haven't touched it since, although the .a file under pkg is being touched in some fashion every time.

I also have a list in GOPATH, although I find it hard to believe that could make a difference. v8worker is installed under the first item of two in my GOPATH.

@rsc

This comment has been minimized.

Contributor

rsc commented Jan 13, 2016

@sethwklein Thanks. I looked at the tgz you provided when you posted it 6 days ago, and the profile suggests that we're just spending a lot of time in Write. The writes are not buffered, so you'd think maybe there are lots of small writes happening, but I don't see that either. It looks like it copies one whole DWARF section at a time. So I thought maybe there are many (like 100s) of DWARF sections. But there are not. So I can't tell why it should be so bad.

I may poke at this again over the next couple weeks, but it may have to wait until Go 1.7. I know that's not great.

@rsc

This comment has been minimized.

Contributor

rsc commented Jan 27, 2016

Not going to get to this until Go 1.7. Sorry.

@rsc rsc modified the milestones: Go1.7Early, Go1.6Maybe Jan 27, 2016

@nanoant

This comment has been minimized.

nanoant commented Mar 24, 2016

OK, great. Thanks. That confirms it really is machoCombineDwarf and not clang++.

@rsc I am sorry, but I think you are wrong. Removing first return enables back dsymutil call, but not machoCombineDwarf. I just did reproduce the problem, then I forcefully killed go build with Ctrl+\ when it was stuck in the linker, so I got the temporary files there.

Next I ran dsymutil manually and it seems to be performance hog there. At least in this specific case. Still it for v8 case where libv8_base.a is ~500MB the produced go.dwarf file is ~100MB, which is a lot so I can imagine dsymutil does a lot of work rewriting all this debug information.

$ time /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/dsymutil -f /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-build517742936/_/Users/ono/Code/Applications/Go/bugs/macho/_obj/exe/a.out -o /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-link-980826351/go.dwarf
warning: (x86_64) /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-build546433112/runtime/cgo/_obj/gcc_darwin_amd64.o unable to open object file: No such file or directory
warning: (x86_64) /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-build546433112/runtime/cgo/_obj/gcc_libinit.o unable to open object file: No such file or directory
warning: (x86_64) /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-build546433112/runtime/cgo/_obj/gcc_setenv.o unable to open object file: No such file or directory
warning: (x86_64) /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-build546433112/runtime/cgo/_obj/gcc_util.o unable to open object file: No such file or directory
warning: (x86_64) /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-build546433112/runtime/cgo/_obj/gcc_amd64.o unable to open object file: No such file or directory
while processing /var/folders/pr/80gqg1k12d5fwjfvtxjdh1t40000gn/T/go-link-980826351/go.o:
warning: could not find referenced DIE
...above msg repeating ~20x times

real    0m15.578s
user    0m13.806s
sys 0m1.609s

@bradfitz bradfitz added the ToolSpeed label May 6, 2016

@bradfitz bradfitz modified the milestones: Go1.8, Go1.7Early May 6, 2016

@quentinmit quentinmit added the NeedsFix label Oct 7, 2016

@rsc rsc modified the milestones: Go1.9, Go1.8 Nov 11, 2016

rhysd added a commit to rhysd/gocaml that referenced this issue Feb 12, 2017

make `go build` 60x faster
by disabling dwarf on building LLVM.

golang/go#12259

@bradfitz bradfitz modified the milestones: Go1.10, Go1.9 Jun 7, 2017

@rsc rsc modified the milestones: Go1.10, Go1.11 Nov 22, 2017

@ianlancetaylor ianlancetaylor modified the milestones: Go1.11, Unplanned Jun 23, 2018

@rsc rsc added the release-blocker label Jul 10, 2018

@rsc rsc removed their assignment Jul 10, 2018

@rsc rsc added the early-in-cycle label Jul 10, 2018

@ALTree ALTree removed the release-blocker label Oct 12, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment