sourcegraph / lsif-go

Language Server Indexing Format (LSIF) generator for Go
https://lsif.dev/
MIT License
116 stars 20 forks source link

`lsif-go --animation` hangs when listing dependencies on sourcegraph/sourcegraph #228

Open chrismwendt opened 2 years ago

chrismwendt commented 2 years ago
Delve goroutines ``` (dlv) goroutines -t 1000 Goroutine 1 - User: /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:71 github.com/sourcegraph/lsif-go/internal/output.WithProgressParallel.func2 (0x102dd842c) [select] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c65aac in runtime.selectgo at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/select.go:327 2 0x0000000102dd842c in github.com/sourcegraph/lsif-go/internal/output.WithProgressParallel.func2 at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:71 3 0x0000000102dd8a08 in github.com/sourcegraph/lsif-go/internal/output.withTitleAnimated.func1 at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:114 4 0x0000000102dd6754 in github.com/efritz/pentimento.PrintProgress at /Users/chrismwendt/go/pkg/mod/github.com/efritz/pentimento@v0.0.0-20190429011147-ade47d831101/printer.go:46 5 0x0000000102dd87d8 in github.com/sourcegraph/lsif-go/internal/output.withTitleAnimated at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:109 6 0x0000000102dd8504 in github.com/sourcegraph/lsif-go/internal/output.withTitle at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:89 7 0x0000000102dd8340 in github.com/sourcegraph/lsif-go/internal/output.WithProgressParallel at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:69 8 0x0000000102dd8268 in github.com/sourcegraph/lsif-go/internal/output.WithProgress at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:56 9 0x0000000102f080f4 in github.com/sourcegraph/lsif-go/internal/gomod.ListDependencies at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/gomod/dependencies.go:73 10 0x000000010304b768 in main.mainErr at /Users/chrismwendt/github.com/sourcegraph/lsif-go/cmd/lsif-go/main.go:59 11 0x000000010304b3a0 in main.main at /Users/chrismwendt/github.com/sourcegraph/lsif-go/cmd/lsif-go/main.go:21 12 0x0000000102c546e4 in runtime.main at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:255 13 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 2 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [force gc (idle) 456959h19m52.782832459s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c549c0 in runtime.goparkunlock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:372 2 0x0000000102c549c0 in runtime.forcegchelper at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:306 3 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 3 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC sweep wait] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c402b0 in runtime.goparkunlock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:372 2 0x0000000102c402b0 in runtime.bgsweep at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgcsweep.go:182 3 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 4 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC scavenge wait] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c3e570 in runtime.goparkunlock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:372 2 0x0000000102c3e570 in runtime.bgscavenge at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgcscavenge.go:314 3 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 5 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [finalizer wait 456959h19m52.785584459s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c35028 in runtime.goparkunlock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:372 2 0x0000000102c35028 in runtime.runfinq at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mfinal.go:177 3 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 10 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/sema.go:56 sync.runtime_Semacquire (0x102c803d8) [semacquire 456959h21m57.201825084s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c66b08 in runtime.goparkunlock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:372 2 0x0000000102c66b08 in runtime.semacquire1 at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/sema.go:144 3 0x0000000102c803d8 in sync.runtime_Semacquire at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/sema.go:56 4 0x0000000102c9b624 in sync.(*WaitGroup).Wait at /opt/homebrew/Cellar/go/1.17/libexec/src/sync/waitgroup.go:130 5 0x0000000102f096cc in github.com/sourcegraph/lsif-go/internal/gomod.resolveImportPaths at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/gomod/dependencies.go:264 6 0x0000000102f08788 in github.com/sourcegraph/lsif-go/internal/gomod.ListDependencies.func1 at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/gomod/dependencies.go:69 7 0x0000000102dd8044 in github.com/sourcegraph/lsif-go/internal/parallel.Run.func1 at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/parallel/parallel.go:24 8 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 29 - User: /Users/chrismwendt/go/pkg/mod/github.com/efritz/pentimento@v0.0.0-20190429011147-ade47d831101/printer.go:112 github.com/efritz/pentimento.(*Printer).Refresh.func1 (0x102dd6da8) [chan receive 456959h21m57.203261084s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c234a4 in runtime.chanrecv at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/chan.go:576 2 0x0000000102c22e98 in runtime.chanrecv2 at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/chan.go:444 3 0x0000000102dd6da8 in github.com/efritz/pentimento.(*Printer).Refresh.func1 at /Users/chrismwendt/go/pkg/mod/github.com/efritz/pentimento@v0.0.0-20190429011147-ade47d831101/printer.go:112 4 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 35 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/sema.go:56 sync.runtime_Semacquire (0x102c803d8) [semacquire 456959h21m57.204448084s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c66b08 in runtime.goparkunlock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:372 2 0x0000000102c66b08 in runtime.semacquire1 at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/sema.go:144 3 0x0000000102c803d8 in sync.runtime_Semacquire at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/sema.go:56 4 0x0000000102c9b624 in sync.(*WaitGroup).Wait at /opt/homebrew/Cellar/go/1.17/libexec/src/sync/waitgroup.go:130 5 0x0000000102dd8488 in github.com/sourcegraph/lsif-go/internal/output.WithProgressParallel.func1 at /Users/chrismwendt/github.com/sourcegraph/lsif-go/internal/output/output.go:65 6 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 36 - User: /Users/chrismwendt/go/pkg/mod/github.com/efritz/pentimento@v0.0.0-20190429011147-ade47d831101/printer.go:112 github.com/efritz/pentimento.(*Printer).Refresh.func1 (0x102dd6da8) [chan receive] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c234a4 in runtime.chanrecv at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/chan.go:576 2 0x0000000102c22e98 in runtime.chanrecv2 at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/chan.go:444 3 0x0000000102dd6da8 in github.com/efritz/pentimento.(*Printer).Refresh.func1 at /Users/chrismwendt/go/pkg/mod/github.com/efritz/pentimento@v0.0.0-20190429011147-ade47d831101/printer.go:112 4 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 55 - User: :0 ??? (0x18e1385a0) (thread 6519685) [chan receive 456959h21m52.808257042s] 0 0x000000018e1385a0 in ??? at ?:-1 1 0x0000000102c83a8c in runtime.asmcgocall at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:935 error: protocol error E08 during memory read for packet $mffffffffffc00e20,8 (truncated) Goroutine 82 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle) 456959h21m57.209622084s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 83 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle)] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 84 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle)] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 85 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle) 456959h21m56.325406584s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 98 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle)] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 99 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle)] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 114 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle) 456959h21m56.890885542s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 115 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 runtime.gopark (0x102c54b3c) [GC worker (idle) 456959h21m55.663103792s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c38034 in runtime.gcBgMarkWorker at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/mgc.go:1200 2 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 Goroutine 559 - User: /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/netpoll.go:229 internal/poll.runtime_pollWait (0x102c7e9f4) [IO wait 456959h21m52.815328042s] 0 0x0000000102c54b3c in runtime.gopark at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/proc.go:367 1 0x0000000102c4d2d8 in runtime.netpollblock at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/netpoll.go:445 2 0x0000000102c7e9f4 in internal/poll.runtime_pollWait at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/netpoll.go:229 3 0x0000000102ce03a8 in internal/poll.(*pollDesc).wait at /opt/homebrew/Cellar/go/1.17/libexec/src/internal/poll/fd_poll_runtime.go:84 4 0x0000000102ce148c in internal/poll.(*pollDesc).waitRead at /opt/homebrew/Cellar/go/1.17/libexec/src/internal/poll/fd_poll_runtime.go:89 5 0x0000000102ce148c in internal/poll.(*FD).Read at /opt/homebrew/Cellar/go/1.17/libexec/src/internal/poll/fd_unix.go:167 6 0x0000000102ce7524 in os.(*File).read at /opt/homebrew/Cellar/go/1.17/libexec/src/os/file_posix.go:32 7 0x0000000102ce7524 in os.(*File).Read at /opt/homebrew/Cellar/go/1.17/libexec/src/os/file.go:119 8 0x0000000102d16b24 in bytes.(*Buffer).ReadFrom at /opt/homebrew/Cellar/go/1.17/libexec/src/bytes/buffer.go:204 9 0x0000000102cbf5a4 in io.copyBuffer at /opt/homebrew/Cellar/go/1.17/libexec/src/io/io.go:409 10 0x0000000102db6514 in io.Copy at /opt/homebrew/Cellar/go/1.17/libexec/src/io/io.go:382 11 0x0000000102db6514 in os/exec.(*Cmd).writerDescriptor.func1 at /opt/homebrew/Cellar/go/1.17/libexec/src/os/exec/exec.go:311 12 0x0000000102db6f58 in os/exec.(*Cmd).Start.func1 at /opt/homebrew/Cellar/go/1.17/libexec/src/os/exec/exec.go:441 13 0x0000000102c83c64 in runtime.goexit at /opt/homebrew/Cellar/go/1.17/libexec/src/runtime/asm_arm64.s:1133 [19 goroutines] ```

CleanShot 2022-02-18 at 12 29 56@2x

I don't know why there are no goroutines in that block. It appears as though it's in deadlock.

However, I noticed there's a frame in os/exec.(*Cmd).Start.func1 and deeper in io.Copy waiting for stdout from a subprocessed, so I checked pstree for child processes and found:

 |   |       \-+= 29322 chrismwendt /Users/chrismwendt/github.com/sourcegraph/lsif-go/lsif-go
 |   |         \-+- 29730 chrismwendt git ls-remote git+ssh://git.apache.org/thrift
 |   |           \--- 29731 chrismwendt /usr/bin/ssh -o SendEnv=GIT_PROTOCOL git.apache.org git-upload-pack '/thrift'

I ran it myself:

$ git ls-remote git+ssh://git.apache.org/thrift
The authenticity of host 'git.apache.org (52.202.80.70)' can't be established.
ECDSA key fingerprint is SHA256:EzwREkEsDEDLPU4dybKtxgPuXW8Gt/P5Qapo1VheWqw.
Are you sure you want to continue connecting (yes/no/[fingerprint])?

And it hung. When I typed yes, it said "permission denied".

I'm not sure why this is hanging for me when recent lsif-go runs in CI are working https://github.com/sourcegraph/sourcegraph/runs/5252625222?check_suite_focus=true#step:4:5

jlisee commented 2 years ago

As a customer I get this as well and it's a confusing and bad first experience. I suggest updating whatever system you have here to detect the request for input and drop out of interactive mode and ask the user for input.

Here is what it looked like:

✔ Resolving module name... Done (890.16ms)
⠸ Listing dependencies... 0/1
⠹ Listing dependencies... 0/1

⠼ Listing dependencies... 0/1

I was able to get around it by doing:

$ lsif-go -v --no-animation

Resolving module name
Finished in 911.09ms.

Listing dependencies
WARNING: Failed to resolve repo aurora.tech/av (unrecognized import path "<hidden>") %!s(*vcs.RepoRoot=<nil>).
The authenticity of host 'git.apache.org (65.108.73.173)' can't be established.
ECDSA key fingerprint is SHA256:hKCOFRIQOmR+9NuChvXFrggGWmP9F7Sg+EsHR6mzLLg.
Are you sure you want to continue connecting (yes/no)? yes
Finished in 8.29s
chrismwendt commented 2 years ago

Checking out a different commit (and in one case checking out commit A, B, then A again) fixed the problem somehow. Maybe there's some stale local git checkout state floating around?

olafurpg commented 2 years ago

I updated the title to reflect that this bug only reproduces with --animation enabled. I just released 1.9.1, which disabled animation by default. Thank you @jlisee for identifying the workaround!