cmd/go: go get -u=patch hangs while using CPU while 1.17.1 doesn't #48511

mvdan · 2021-09-21T09:24:11Z

This seems to be a regression in master since 1.17 was released.

Repro steps below; luckily, I encountered the hang in an open source module repo.

$ cd /tmp
$ git clone https://github.com/vocdoni/vocdoni-node
$ cd vocdoni-node/
$ git checkout 31d448d170f6be0537f775772a710a59208317b3
$ go version
go version devel go1.18-c7543e5db9 Tue Sep 21 03:15:20 2021 +0000 linux/amd64
$ go get -d -u=patch ./...
(may download some modules, then hangs forever, using ~300% CPU; I kill it after one minute)
^C
$ wgo1 go version
go version go1.17.1 linux/amd64
$ wgo1 go get -d -u=patch ./...
go get: upgraded github.com/DataDog/zstd v1.4.5 => v1.4.8
go get: upgraded github.com/Workiva/go-datastructures v1.0.52 => v1.0.53
[more lines, then finishes successfully]

I haven't narrowed down the reproducer or bisected just yet. I think this might be enough information for @bcmills or @jayconrod to have a good guess as to what recent change added this hang.

I tried using ^\ to get a stack trace of the process, but I get seemingly harmless stack traces that show cmd/go doing work, so perhaps the endless loop is at a higher level - for example, loading the same package over and over again.

Marking as release-blocker for now, as it looks like a regression.

The text was updated successfully, but these errors were encountered:

bcmills · 2021-09-21T13:32:15Z

(sigh) Ok, breaking out git bisect. Thanks for including an exact commit to reproduce it!

bcmills · 2021-09-21T16:01:04Z

git bisect complete!

a627fcd3c4fdacdc9bbcccdb926e4804ca6d6815 is the first bad commit
commit a627fcd3c4fdacdc9bbcccdb926e4804ca6d6815
Author: Michael Matloob <matloob@golang.org>
Date:   Fri May 14 11:46:26 2021 -0400

    [dev.cmdgo] cmd/go: replace Target with MainModules, allowing for multiple targets

    This change replaces the Target variable that represents the main module
    and the pathPrefix and inGorootSrc which provide other information about
    the main module with a single MainModules value that represents multiple
    main modules and holds their path prefixes, module roots, and whether
    they are in GOROOT/src. In cases where the code checks Target or its
    previously associated variables, the code now checks or iterates over
    MainModules. In some cases, the code still assumes a single main module
    by calling MainModules.MustGetSingleMainModule. Some of those cases are
    correct: for instance, there is always only one main module for
    mod=vendor. Other cases are accompanied with TODOs and will have to be
    fixed in future CLs to properly support multiple main modules.

    This CL (and other cls on top of it) are planned to be checked into a
    branch to allow for those evaluating the workspaces proposal to try it
    hands on.

    For #45713

    Change-Id: I3b699e1d5cad8c76d62dc567b8460de8c73a87ea
    Reviewed-on: https://go-review.googlesource.com/c/go/+/334932
    Trust: Michael Matloob <matloob@golang.org>
    Run-TryBot: Michael Matloob <matloob@golang.org>
    TryBot-Result: Go Bot <gobot@golang.org>
    Reviewed-by: Jay Conrod <jayconrod@google.com>

 src/cmd/go/internal/get/get.go           |   6 +-
 src/cmd/go/internal/load/pkg.go          |   7 +-
 src/cmd/go/internal/modcmd/download.go   |  14 +-
 src/cmd/go/internal/modcmd/vendor.go     |   2 +-
 src/cmd/go/internal/modget/get.go        |  50 +++---
 src/cmd/go/internal/modget/query.go      |   6 +-
 src/cmd/go/internal/modload/build.go     |  19 +-
 src/cmd/go/internal/modload/buildlist.go |  77 ++++++---
 src/cmd/go/internal/modload/edit.go      |  20 ++-
 src/cmd/go/internal/modload/import.go    |  24 +--
 src/cmd/go/internal/modload/init.go      | 286 ++++++++++++++++++++++---------
 src/cmd/go/internal/modload/list.go      |   6 +-
 src/cmd/go/internal/modload/load.go      | 148 ++++++++++------
 src/cmd/go/internal/modload/modfile.go   |  12 +-
 src/cmd/go/internal/modload/mvs.go       |   4 +-
 src/cmd/go/internal/modload/query.go     | 111 +++++++-----
 src/cmd/go/internal/modload/search.go    |  15 +-
 src/cmd/go/internal/modload/vendor.go    |   1 +
 src/cmd/go/internal/mvs/mvs.go           |  34 ++--
 src/cmd/go/internal/mvs/mvs_test.go      |   2 +-
 src/cmd/go/internal/search/search.go     |  33 ++--
 21 files changed, 563 insertions(+), 314 deletions(-)
bisect run success

CC @matloob @jayconrod

bcmills · 2021-09-21T16:13:43Z

~/tmp/vocdoni-node$ timeout --signal=QUIT --kill-after=10s 30s go get -d -u=patch ./...
SIGQUIT: quit
PC=0x4670c1 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex()
        /usr/local/google/home/bcmills/go-review/src/runtime/sys_linux_amd64.s:519 +0x21
runtime.futexsleep(0x466cb3, 0x1cf06f, 0x28777828)
        /usr/local/google/home/bcmills/go-review/src/runtime/os_linux.go:44 +0x36
runtime.notesleep(0xd938b0)
        /usr/local/google/home/bcmills/go-review/src/runtime/lock_futex.go:160 +0x87
runtime.mPark()
        /usr/local/google/home/bcmills/go-review/src/runtime/proc.go:1441 +0x2a
runtime.stopm()
        /usr/local/google/home/bcmills/go-review/src/runtime/proc.go:2408 +0x78
runtime.findrunnable()
        /usr/local/google/home/bcmills/go-review/src/runtime/proc.go:2984 +0x865
runtime.schedule()
        /usr/local/google/home/bcmills/go-review/src/runtime/proc.go:3367 +0x239
runtime.park_m(0xc0004824e0)
        /usr/local/google/home/bcmills/go-review/src/runtime/proc.go:3516 +0x14d
runtime.mcall()
        /usr/local/google/home/bcmills/go-review/src/runtime/asm_amd64.s:307 +0x43

goroutine 1 [runnable]:
syscall.Syscall6(0x106, 0xffffffffffffff9c, 0xc00131e014, 0xc000fb0038, 0x100, 0x0, 0x0)
        /usr/local/google/home/bcmills/go-review/src/syscall/asm_linux_amd64.s:43 +0x5
syscall.fstatat(0xc0001d6640, {0xc00131e010, 0x8fb0e0}, 0xc000fb0038, 0x44f554)
        /usr/local/google/home/bcmills/go-review/src/syscall/zsyscall_linux_amd64.go:1441 +0x10f
syscall.Lstat(...)
        /usr/local/google/home/bcmills/go-review/src/syscall/syscall_linux_amd64.go:74
os.lstatNolog.func1(...)
        /usr/local/google/home/bcmills/go-review/src/os/stat_unix.go:46
os.ignoringEINTR(...)
        /usr/local/google/home/bcmills/go-review/src/os/file_posix.go:246
os.lstatNolog({0xc00131e010, 0x3})
        /usr/local/google/home/bcmills/go-review/src/os/stat_unix.go:45 +0x5b
os.Lstat({0xc00131e010, 0x4})
        /usr/local/google/home/bcmills/go-review/src/os/stat.go:22 +0x34
path/filepath.walkSymlinks({0xc000ef4000, 0xc000ef4030})
        /usr/local/google/home/bcmills/go-review/src/path/filepath/symlink.go:84 +0x174
path/filepath.evalSymlinks(...)
        /usr/local/google/home/bcmills/go-review/src/path/filepath/symlink_unix.go:7
path/filepath.EvalSymlinks({0xc000ef4000, 0x0})
        /usr/local/google/home/bcmills/go-review/src/path/filepath/path.go:235 +0x1e
go/build.(*Context).hasSubdir(0x0, {0xc000ef4000, 0x2c}, {0xc000daeab0, 0x10})
        /usr/local/google/home/bcmills/go-review/src/go/build/build.go:163 +0x6e
go/build.(*Context).Import(0xd92680, {0x994548, 0x1}, {0xc000a44030, 0x4}, 0x0)
        /usr/local/google/home/bcmills/go-review/src/go/build/build.go:588 +0x6e7
go/build.(*Context).ImportDir(...)
        /usr/local/google/home/bcmills/go-review/src/go/build/build.go:485
cmd/go/internal/search.(*Match).MatchDirs.func1({0xc000a44030, 0x10}, {0xa761c8, 0xc0003cf930}, {0x0, 0x0})
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/search/search.go:317 +0x33b
cmd/go/internal/fsys.walk({0xc000a44030, 0x10}, {0xa761c8, 0xc0003cf930}, 0xc0001d72a0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/fsys/fsys.go:413 +0xba
cmd/go/internal/fsys.walk({0xc001e305e0, 0x8}, {0xa761c8, 0xc00160dc70}, 0xc0001d72a0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/fsys/fsys.go:427 +0x1e5
cmd/go/internal/fsys.walk({0xc00244e0b3, 0x2}, {0xa761c8, 0xc00160cb60}, 0xc0001d72a0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/fsys/fsys.go:427 +0x1e5
cmd/go/internal/fsys.Walk({0xc00244e0b3, 0x2}, 0xc0001d72a0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/fsys/fsys.go:443 +0x85
cmd/go/internal/search.(*Match).MatchDirs(0xc002b92060, {0xc0000a9400, 0xc000030044, 0x1})
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/search/search.go:271 +0xa2b
cmd/go/internal/modload.matchLocalDirs({0xa72340, 0xc0000b0000}, 0xc002b92060, 0x8)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modload/load.go:448 +0x445
cmd/go/internal/modload.LoadPackages.func1(0x0, 0x0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modload/load.go:258 +0x256
cmd/go/internal/modload.LoadPackages.func2(0xc0014846e0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modload/load.go:338 +0x2c
cmd/go/internal/modload.loadFromRoots({0xa72340, 0xc0000b0000}, {{{0x0, 0x0}, 0xc0004d80f0, 0x0, {0x0, 0x0}, 0x1, 0x0, ...}, ...})
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modload/load.go:1036 +0x5d1
cmd/go/internal/modload.LoadPackages({0xa72340, 0xc0000b0000}, {{0x0, 0x0}, 0xc0004d80f0, 0x0, {0x0, 0x0}, 0x1, 0x0, ...}, ...)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modload/load.go:331 +0x328
cmd/go/internal/modget.(*resolver).loadPackages(0xc000328100, {0xa72340, 0xc0000b0000}, {0xc000a26400, 0x1, 0x1}, 0xc000468ee0)
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modget/get.go:1178 +0x18c
cmd/go/internal/modget.(*resolver).findAndUpgradeImports(0xc000328100, {0xa72340, 0xc0000b0000}, {0xc0000be050, 0x1, 0x0})
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modget/get.go:1133 +0x252
cmd/go/internal/modget.runGet({0xa72340, 0xc0000b0000}, 0xc0000de240, {0xc0000c2040, 0x1, 0x1})
        /usr/local/google/home/bcmills/go-review/src/cmd/go/internal/modget/get.go:336 +0x3a7
main.invoke(0xd86bc0, {0xc0000c2010, 0x4, 0x4})
        /usr/local/google/home/bcmills/go-review/src/cmd/go/main.go:216 +0x2f6
main.main()
        /usr/local/google/home/bcmills/go-review/src/cmd/go/main.go:173 +0x78e

goroutine 290 [IO wait]:
internal/poll.runtime_pollWait(0x7eff64cf8bd0, 0x72)
        /usr/local/google/home/bcmills/go-review/src/runtime/netpoll.go:229 +0x89
internal/poll.(*pollDesc).wait(0xc000265b80, 0xc000d68000, 0x0)
        /usr/local/google/home/bcmills/go-review/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/google/home/bcmills/go-review/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000265b80, {0xc000d68000, 0x228a, 0x228a})
        /usr/local/google/home/bcmills/go-review/src/internal/poll/fd_unix.go:167 +0x25a
net.(*netFD).Read(0xc000265b80, {0xc000d68000, 0xc002520240, 0x0})
        /usr/local/google/home/bcmills/go-review/src/net/fd_posix.go:56 +0x29
net.(*conn).Read(0xc00062f290, {0xc000d68000, 0xc000f087f0, 0x40e4f4})
        /usr/local/google/home/bcmills/go-review/src/net/net.go:183 +0x45
crypto/tls.(*atLeastReader).Read(0xc000810270, {0xc000d68000, 0x0, 0x40b2ad})
        /usr/local/google/home/bcmills/go-review/src/crypto/tls/conn.go:777 +0x3d
bytes.(*Buffer).ReadFrom(0xc000dfccf8, {0xa65220, 0xc000810270})
        /usr/local/google/home/bcmills/go-review/src/bytes/buffer.go:204 +0x98
crypto/tls.(*Conn).readFromUntil(0xc000dfca80, {0xa65760, 0xc00062f290}, 0x46095b)
        /usr/local/google/home/bcmills/go-review/src/crypto/tls/conn.go:799 +0xe5
crypto/tls.(*Conn).readRecordOrCCS(0xc000dfca80, 0x0)
        /usr/local/google/home/bcmills/go-review/src/crypto/tls/conn.go:606 +0x112
crypto/tls.(*Conn).readRecord(...)
        /usr/local/google/home/bcmills/go-review/src/crypto/tls/conn.go:574
crypto/tls.(*Conn).Read(0xc000dfca80, {0xc000d23000, 0x1000, 0xc000f08cd0})
        /usr/local/google/home/bcmills/go-review/src/crypto/tls/conn.go:1277 +0x16f
bufio.(*Reader).Read(0xc000bcd680, {0xc0008e90d8, 0x9, 0xc000f08d10})
        /usr/local/google/home/bcmills/go-review/src/bufio/bufio.go:227 +0x1b4
io.ReadAtLeast({0xa64a60, 0xc000bcd680}, {0xc0008e90d8, 0x9, 0x9}, 0x9)
        /usr/local/google/home/bcmills/go-review/src/io/io.go:328 +0x9a
io.ReadFull(...)
        /usr/local/google/home/bcmills/go-review/src/io/io.go:347
net/http.http2readFrameHeader({0xc0008e90d8, 0x9, 0x6f304b}, {0xa64a60, 0xc000bcd680})
        /usr/local/google/home/bcmills/go-review/src/net/http/h2_bundle.go:1553 +0x6e
net/http.(*http2Framer).ReadFrame(0xc0008e90a0)
        /usr/local/google/home/bcmills/go-review/src/net/http/h2_bundle.go:1811 +0x95
net/http.(*http2clientConnReadLoop).run(0xc000f08fa0)
        /usr/local/google/home/bcmills/go-review/src/net/http/h2_bundle.go:8428 +0x165
net/http.(*http2ClientConn).readLoop(0xc00088b200)
        /usr/local/google/home/bcmills/go-review/src/net/http/h2_bundle.go:8350 +0x79
created by net/http.(*http2Transport).newClientConn
        /usr/local/google/home/bcmills/go-review/src/net/http/h2_bundle.go:7302 +0xb45

rax    0xca
rbx    0x0
rcx    0x4670c3
rdx    0x0
rdi    0xd938b0
rsi    0x80
rbp    0x7ffe8f161b08
rsp    0x7ffe8f161ac0
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x7ffe8f161c18
r13    0xfb
r14    0xd92b20
r15    0xffffffffffffffff
rip    0x4670c1
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

bcmills · 2021-10-27T16:14:44Z

I'm planning to look at this again once CL 357169 lands, since it may interact nontrivially.

mvdan · 2021-10-27T16:22:17Z

While this is a release blocker, I think it's worth pointing out it's not extremely urgent: one can sidestep the issue by using go get -u=patch on 1.17.x and then going back to tip for building/testing/etc.

bcmills · 2021-11-15T22:20:21Z

I've made some progress tracking this down, but no fix yet. It appears that modload.EditBuildList is reporting spurious changes, which causes modget to loop trying to resolve those changes. Since the changes are spurious, there is nothing to resolve and it gets stuck in a loop.

heschi · 2021-11-24T17:07:00Z

The beta is getting close and this is currently marked as blocking the beta. Any news here?

bcmills · 2021-11-30T16:27:21Z

Found it. Missed Version check in cmd/go/internal/modload/mvs.go, causing mvs.Req to accidentally prune out the dependencies of other versions of the main module.

Next step: regression test!

gopherbot · 2021-12-01T14:40:23Z

Change https://golang.org/cl/368136 mentions this issue: cmd/go/internal/modload: fix up main-module checks from CL 334932

mvdan added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker labels Sep 21, 2021

mvdan added this to the Go1.18 milestone Sep 21, 2021

bcmills self-assigned this Oct 5, 2021

gopherbot closed this as completed in ab79055 Dec 1, 2021

rsc unassigned bcmills Jun 23, 2022

golang locked and limited conversation to collaborators Jun 23, 2023

gopherbot added the FrozenDueToAge label Jun 23, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

cmd/go: go get -u=patch hangs while using CPU while 1.17.1 doesn't #48511

cmd/go: go get -u=patch hangs while using CPU while 1.17.1 doesn't #48511

mvdan commented Sep 21, 2021

bcmills commented Sep 21, 2021

bcmills commented Sep 21, 2021

bcmills commented Sep 21, 2021

bcmills commented Oct 27, 2021

mvdan commented Oct 27, 2021

bcmills commented Nov 15, 2021

heschi commented Nov 24, 2021

bcmills commented Nov 30, 2021

gopherbot commented Dec 1, 2021

cmd/go: go get -u=patch hangs while using CPU while 1.17.1 doesn't #48511

cmd/go: go get -u=patch hangs while using CPU while 1.17.1 doesn't #48511

Comments

mvdan commented Sep 21, 2021

bcmills commented Sep 21, 2021

bcmills commented Sep 21, 2021

bcmills commented Sep 21, 2021

bcmills commented Oct 27, 2021

mvdan commented Oct 27, 2021

bcmills commented Nov 15, 2021

heschi commented Nov 24, 2021

bcmills commented Nov 30, 2021

gopherbot commented Dec 1, 2021