Skip to content
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

Jump to bottom

cmd/api: occasional hangs on 'go list' in NewWalker without useful output #45884

Closed
bcmills opened this issue Apr 30, 2021 · 11 comments
Closed

cmd/api: occasional hangs on 'go list' in NewWalker without useful output #45884

bcmills opened this issue Apr 30, 2021 · 11 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker Testing An issue that has been verified to require only test changes, not just a test failure. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone
Go1.17

Comments

@bcmills
Copy link
Contributor

bcmills commented Apr 30, 2021

2021-04-23T20:57:54-691e1b8/linux-mips64le-mengzhuo (12 minutes on go list)
2021-04-23T13:48:10-bedfeed/linux-mips-rtrk (12 minutes on go list)
2021-04-21T20:24:34-2550563/linux-mips64le-mengzhuo (12 minutes ingo list)

This is probably a bug in one or more of the go command, the os package, or the Linux platform on MIPS.

However, this failure output isn't giving us much useful information. NewWalker should accept a context.Context, which we can then plumb to the test's deadline to send SIGQUIT to go list to get more useful output in case of failure.
@bcmills bcmills added Testing An issue that has been verified to require only test changes, not just a test failure. NeedsFix The path to resolution is known, but the work has not been done. labels Apr 30, 2021
@bcmills bcmills added this to the Backlog milestone Apr 30, 2021
@bcmills bcmills mentioned this issue Apr 30, 2021
Closed
@bcmills
Copy link
Contributor Author

bcmills commented May 5, 2021

Also seen on a linux-arm-aws TryBot:
https://storage.googleapis.com/go-build-log/9041f75f/linux-arm-aws_6baaa067.log

@bcmills
Copy link
Contributor Author

bcmills commented May 5, 2021

I suspect that this is the same deadlock observed in #45916 (CC @prattmic @mknyszek).

@bcmills bcmills changed the title cmd/api: occasional hangs on 'go list' in NewWalker on MIPS without useful output cmd/api: occasional hangs on 'go list' in NewWalker without useful output May 5, 2021
@bcmills
Copy link
Contributor Author

bcmills commented May 5, 2021

2021-05-03T01:35:44-2c9f5a1/linux-mips64le-mengzhuo
2021-04-30T19:38:25-d19eece/aix-ppc64
2021-04-28T18:03:21-90614ff/openbsd-amd64-64
2021-04-23T20:57:54-691e1b8/linux-mips64le-mengzhuo
2021-04-23T13:48:10-bedfeed/linux-mips-rtrk
2021-04-21T20:24:34-2550563/linux-mips64le-mengzhuo
2021-04-21T04:26:11-69c94ad/openbsd-arm64-jsing

@bcmills
Copy link
Contributor Author

bcmills commented May 5, 2021

Marking as release-blocker for Go 1.17, because this is looking like a regression introduced sometime in late April.

@bcmills bcmills added release-blocker NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels May 5, 2021
@bcmills bcmills modified the milestones: Backlog, Go1.17 May 5, 2021
@gopherbot gopherbot removed the NeedsFix The path to resolution is known, but the work has not been done. label May 5, 2021
@bcmills
Copy link
Contributor Author

bcmills commented May 5, 2021

(It's not obvious to me whether the regression is in the runtime or in cmd/go, but from the odd stack traces in #45916 I initially suspect the runtime.)

@prattmic
Copy link
Member

prattmic commented May 5, 2021

The earliest failure here (by filename timestamp) is 2021-04-21T04:26:11-69c94ad/openbsd-arm64-jsing. That ran at 69c94ad, which is before 7e97e4e and ecfce58, two of my top contenders as potentially problematic. So if these issues are all related, those may not be involved.

@bcmills bcmills mentioned this issue May 5, 2021
Closed
@toothrot
Copy link
Contributor

toothrot commented May 6, 2021

/cc @dmitshur

@gopherbot
Copy link

Change https://golang.org/cl/318569 mentions this issue: runtime: hold sched.lock across atomic pidleget/pidleput

@prattmic prattmic mentioned this issue May 10, 2021
Closed
@prattmic
Copy link
Member

It is hard to be certain without more complete stacks, but I think http://golang.org/cl/318569 will fix this. i.e., that #45975, #45916, #45885, and #45884 all have the same cause.

gopherbot pushed a commit that referenced this issue May 11, 2021
@prattmic
runtime: hold sched.lock across atomic pidleget/pidleput
2520e72 
As a cleanup, golang.org/cl/307914 unintentionally caused the idle GC
work recheck to drop sched.lock between acquiring a P and committing to
keep it (once a worker G was found).

This is unsafe, as releasing a P requires extra checks once sched.lock
is taken (such as for runSafePointFn). Since checkIdleGCNoP does not
perform these extra checks, we can now race with other users.

In the case of #45975, we may hang with this sequence:

1. M1: checkIdleGCNoP takes sched.lock, gets P1, releases sched.lock.
2. M2: forEachP takes sched.lock, iterates over sched.pidle without
   finding P1, releases sched.lock.
3. M1: checkIdleGCNoP puts P1 back in sched.pidle.
4. M2: forEachP waits forever for P1 to run the safePointFn.

Change back to the old behavior of releasing sched.lock only after we
are certain we will keep the P. Thus if we put it back its removal from
sched.pidle was never visible.

Fixes #45975
For #45916
For #45885
For #45884

Change-Id: I191a1800923b206ccaf96bdcdd0bfdad17b532e9
Reviewed-on: https://go-review.googlesource.com/c/go/+/318569
Trust: Michael Pratt <mpratt@google.com>
Run-TryBot: Michael Pratt <mpratt@google.com>
TryBot-Result: Go Bot <gobot@golang.org>
Reviewed-by: David Chase <drchase@google.com>
@prattmic
Copy link
Member

I think this bug should be fixed, but can't be sure. Please note here if you see more occurrences.

@prattmic prattmic added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label May 11, 2021
@heschi
Copy link
Contributor

heschi commented May 20, 2021

The last 30 commits, roughly corresponding to the last week, show no signs of this problem. Closing.

@heschi heschi closed this as completed May 20, 2021
@golang golang locked and limited conversation to collaborators May 20, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker Testing An issue that has been verified to require only test changes, not just a test failure. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Milestone
Go1.17
Development

No branches or pull requests
5 participants
@toothrot @prattmic @bcmills @gopherbot @heschi