x/tools/go/internal/gcimporter: frequent failures without useful output #38415

bcmills · 2020-04-13T16:18:30Z

linux-ppc64le-power9osu …
…
haserrors/haserrors.go:2:22: cannot convert "" (untyped string constant) to untyped int
haserrors/haserrors.go:3:18: undeclared name: undefined
FAIL	golang.org/x/tools/go/internal/gcimporter	31.391s

https://build.golang.org/log/50ebd814481ff8a3c0976a9ec32602bdca86e185
https://build.golang.org/log/4f4af454dd05bbeccf2dd92c3d045a5d463f6889
https://build.golang.org/log/aeb6a5acd91e7cea78a93621877395caea90f785
https://build.golang.org/log/f4f7db7b08ee567d0086336920d3faf69363b080

(CC @griesemer, @stamblerre for gcimporter.)

These sorts of patterns would be a lot easier to spot if fetchlogs worked on the x repos (#35515; CC @andybons for prioritization).

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

stamblerre · 2020-04-13T16:30:53Z

Is it possible that this test is running out of memory or timing out? I'm not sure how to debug this failure because the test actually always prints those haserrors messages, even when it passes.

bcmills · 2020-04-13T17:50:21Z

Maybe! @dmitshur has tracked down several other OOM-related builder failures recently; he might have more experience with the symptoms of OOM test failures.

griesemer · 2020-04-13T17:52:06Z

The TestBExportData_stdlib test always reported these two errors (I believe they are expected) and the test is expected to pass (I don't recall why the output is reported). It would probably be a good to track down where this happens, verify the expected output and silence it.

bcmills · 2020-04-13T18:06:10Z

I'm not sure if this is OOM-related. In local testing, I always get non-empty output for that, even when the process is terminated by the kernel instead of the runtime:

example.com$ go test ./oom
signal: killed
FAIL    example.com/oom 71.700s
FAIL

-- go.mod --
module example.com

go 1.14
-- oom/oom_test.go --
package oom_test

import (
        "math/rand"
        "runtime"
        "testing"
)

func TestOutOfMemory(t *testing.T) {
        var stuff [][]byte
        for {
                next := make([]byte, 1<<30)
                for i := 0; i < len(stuff); i += 4 << 10 {
                        next[i] = byte(rand.Int())
                }
                stuff = append(stuff, next)
        }
        runtime.KeepAlive(stuff)
}

Is it possible that the test is somehow invoking os.Exit itself with a nonzero exit code?

laboger · 2020-04-13T20:22:58Z

I've tried this on several machines and it shows the expected output and then says PASS. But when it fails shouldn't the output report which test failed?

=== RUN   TestBExportData_stdlib
haserrors/haserrors.go:2:22: cannot convert "" (untyped string constant) to untyped int
haserrors/haserrors.go:3:18: undeclared name: undefined
--- PASS: TestBExportData_stdlib (6.08s)
=== RUN   TestVeryLongFile
--- PASS: TestVeryLongFile (0.01s)
=== RUN   TestTypeAliases
--- PASS: TestTypeAliases (0.00s)
=== RUN   TestIExportData_stdlib
haserrors/haserrors.go:2:22: cannot convert "" (untyped string constant) to untyped int
haserrors/haserrors.go:3:18: undeclared name: undefined
--- PASS: TestIExportData_stdlib (6.08s)
=== RUN   TestIExportData_long
--- PASS: TestIExportData_long (0.01s)
=== RUN   TestIExportData_typealiases
--- PASS: TestIExportData_typealiases (0.00s)
PASS

bcmills · 2020-04-13T20:33:04Z

It should, but without the -v flag the output is buffered until the test process exits. So probably something is killing or otherwise terminating the test process before it has the chance to flush its output.

laboger · 2020-04-13T22:07:30Z

In all the failure logs above, it is only printing the output once, which would indicate it executes TestBExportData_stdlib but doesn't get to TestIExportData_stdlib. If you suspect an OOM or other kernel failure, TestVeryLongFile seems a likely candidate.

It's curious to me that it is only failing on the power9 and not other power machines. I will try running it multiple times to see if I can reproduce it.

bcmills · 2021-05-10T14:58:40Z

It's curious to me that it is only failing on the power9 and not other power machines.

Now that #35515 is fixed, we can bring fetchlogs to bear on this failure mode — and it turns out not to even be specific to POWER.

bcmills · 2021-05-10T15:04:11Z

Given the very high failure rate (~160 failures in April alone), I'm marking this as a release-blocker for 1.17 via #11811.

(CC @golang/release)

bcmills · 2021-05-10T16:20:12Z

I wonder if this failure mode is actually an out-of-memory condition (compare #45931) combined with missing error reporting on some path.

heschi · 2021-05-13T18:14:39Z

Weekly check-in: this needs to be investigated before beta 1.

findleyr · 2021-05-25T00:25:41Z

Looked into this a bit today. Like Bryan, I tried to repro the silent failure mode via various ways of terminating the process. All of them (even os.Exit) resulted in some form of output on my machine.

I was able to repro on gomote, twice, then succeeded the next ~20 times I tried, so wasn't able to iterate on debugging. Probably a next step would be to SSH into one of the machines and try dmesg.

Note that most of the non-ppc build failures above are not so mysterious: test timeouts or segfaults, the latter on openbsd (which is #36563). However, there are at least some non-ppc build failures that exhibit the silent failure mode (such as 2021-05-07T20:56:39-f05e912/linux-arm64-packet).

Also, note that the linux-ppc64le-power9osu machines, per their documented specs, are pretty large.
go-le-bionic-1: (20 GB RAM, 50 GB disk, 10 cores, POWER9)
https://cs.opensource.google/go/x/build/+/master:env/linux-ppc64le/osuosl/NOTES;l=12;drc=c53d4ba783d113c1e97ca07be915b7e2f6142ede
An OOM with these specs would be surprising to me (but who knows, there could be extenuating circumstances).

heschi · 2021-06-10T18:16:21Z

Ping; any progress?

stamblerre · 2021-06-18T17:24:33Z

We're currently trying to debug the test failure using https://golang.org/cl/327990. It's hard to do because it doesn't reproduce locally, and we can't actually tell which test is failing.

toothrot · 2021-06-25T18:17:53Z

Friendly reminder that the RC is imminent.

findleyr · 2021-06-25T23:52:42Z

Here are the failures this month. The power9osu failures seem to have mostly stopped, which probably explains why it isn't reproducing in the CL above.

findleyr · 2021-06-28T17:20:49Z

Note that the openbsd failures are actually tracked separately by #36563, and the scaleway failures went away when the scaleway machines were removed in #45066.

So, filtering those out as well yields the following recent failures:

I.e. 7 in the last month. In our recent attempts to debug this, we've been unsuccessful at reproducing it with either slowbots or gomote. We can keep trying, but IMO this should not be a release blocker: the overlap between "too infrequent to debug" and "frequent enough to be a release blocker" should be empty. I think if we want to achieve a lower level of flakiness on the builders, we need to first make it easier to identify and diagnose flakes.

@bcmills, @stamblerre, @golang/release please let me know if you feel differently. I'd like to wait for consensus before removing the release-blocker label.

It may also be worthwhile to brainstorm about what tooling could make this easier. I have some ideas, but don't want to distract the conversation from deciding whether this should be a release blocker.

bcmills · 2021-06-28T18:34:00Z

We can keep trying, but IMO this should not be a release blocker: the overlap between "too infrequent to debug" and "frequent enough to be a release blocker" should be empty.

I agree with that assessment. I think 7 failures per month is still too high long-term, but it's far lower than the failure rate in May. I think it's good enough not to be a release-blocker at this point.

bcmills · 2021-10-04T19:08:20Z

The good news is, this appears to be reproducing frequently again, so now we can debug it! 🎉

The bad news is, this appears to be reproducing frequently again. ~126 failures in the past month, and that's excluding the ones that match #36563. I think we're back to release-blocker levels of flakiness. 😩

greplogs --dashboard -md -l -e \(\?m\)haserrors.\*\\nFAIL --since=2021-06-26

bcmills · 2021-10-14T18:52:15Z

An interesting clue from https://build.golang.org/log/f68a7c2dcb411c0067dd3bd2489f9d191072383a:

haserrors/haserrors.go:2:22: cannot convert "" (untyped string constant) to untyped int
haserrors/haserrors.go:3:18: undeclared name: undefined
cgo failed: [go tool cgo -objdir /workdir/tmp/net_C3953996859 -- -I /workdir/tmp/net_C3953996859 cgo_linux.go cgo_resnew.go cgo_socknew.go cgo_unix.go]: signal: killed
Assembler messages:
Fatal error: can't create /workdir/tmp/net_C3953996859/_cgo_.o: No such file or directory
FAIL	golang.org/x/tools/go/internal/gcimporter	79.665s

laboger · 2021-10-18T19:54:49Z

I've been trying to reproduce this problem on a few systems. I can get it to consistently fail on 2 power9's but not on another. The the one where it passes has an older kernel. So far I can't get it to fail on a power8. I also tried building the test using go1.17 and it doesn't fail on the power9s when using go1.17 either.

On one of the power9's where it fails consistently, here is the output log, with most of the logged information about valid imports removed. The error about constraints appears to be causing the problem.

 go test
--- FAIL: TestImportStdLib (2.18s)
  
    ...... many lines logging valid imports ....

    gcimporter_test.go:83: testPath(constraints): cannot import "constraints" (unexpected tag: 85), possibly version skew - reinstall package

    ...... many more lines logging valid imports

    gcimporter_test.go:254: tested 433 imports
haserrors/haserrors.go:2:22: invalid operation: "" + 0 (mismatched types untyped string and untyped int)
haserrors/haserrors.go:3:18: undeclared name: undefined
haserrors/haserrors.go:2:22: invalid operation: "" + 0 (mismatched types untyped string and untyped int)
haserrors/haserrors.go:3:18: undeclared name: undefined
--- FAIL: TestIExportData_stdlib (13.76s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x1e4870]

goroutine 3271 [running]:
testing.tRunner.func1.2({0x2218e0, 0x3d6b60})
	/home/boger/golang/plain/go/src/testing/testing.go:1327 +0x1fc
testing.tRunner.func1()
	/home/boger/golang/plain/go/src/testing/testing.go:1330 +0x354
panic({0x2218e0, 0x3d6b60})
	/home/boger/golang/plain/go/src/runtime/panic.go:814 +0x238
golang.org/x/tools/go/internal/gcimporter.iexportCommon.func1()
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:54 +0xb0
panic({0x2218e0, 0x3d6b60})
	/home/boger/golang/plain/go/src/runtime/panic.go:814 +0x238
go/types.(*Named).Obj(...)
	/home/boger/golang/plain/go/src/go/types/named.go:91
golang.org/x/tools/go/internal/gcimporter.(*exportWriter).doTyp(0xc034873e50, {0x2ad480, 0xc020f338c0}, 0xc07df4fa90)
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:465 +0x5e0
golang.org/x/tools/go/internal/gcimporter.(*iexporter).typOff(0xc07d0f1c30, {0x2ad480, 0xc020f338c0}, 0x6)
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:387 +0xc8
golang.org/x/tools/go/internal/gcimporter.(*exportWriter).typ(0xc034873e00, {0x2ad480, 0xc020f338c0}, 0x2437e0)
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:370 +0x58
golang.org/x/tools/go/internal/gcimporter.(*iexporter).doDecl(0xc07d0f1c30, {0x2af080, 0xc080233d60})
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:286 +0x2f0
golang.org/x/tools/go/internal/gcimporter.iexportCommon({0x2ac000, 0xc01e3ebc20}, 0xc05eafc5c0, 0x0, {0xc00ef9bb30, 0x1, 0x0})
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:96 +0x258
golang.org/x/tools/go/internal/gcimporter.IExportData(...)
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport.go:38
golang.org/x/tools/go/internal/gcimporter_test.iexport(0xc05d68d1e0, 0xc07df4fa90)
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport_test.go:59 +0x78
golang.org/x/tools/go/internal/gcimporter_test.TestIExportData_stdlib(0xc05d68d1e0)
	/home/boger/gocode/src/golang.org/x/tools/go/internal/gcimporter/iexport_test.go:122 +0x90c
testing.tRunner(0xc05d68d1e0, 0x26aaf0)
	/home/boger/golang/plain/go/src/testing/testing.go:1377 +0x11c
created by testing.(*T).Run
	/home/boger/golang/plain/go/src/testing/testing.go:1424 +0x36c
exit status 2
FAIL	golang.org/x/tools/go/internal/gcimporter	30.480s

findleyr · 2021-10-18T23:03:46Z

@laboger are you testing x/tools@master using go@master? The x/tools gcimporter has been updated to support generics, so that test failure looks like it came from an older version of x/tools.

laboger · 2021-10-20T15:58:37Z

@findleyr You are correct. I didn't have the latest. Now if I try on various systems I have access to, I am not able to reproduce a failure with this test, even when using the same configuration as the build machines.

laboger · 2021-10-25T21:25:35Z

One of the recent ppc64le p9 failures has something similar in the log as what happened on arm64:

haserrors/haserrors.go:3:18: undeclared name: undefined
cgo failed: [go tool cgo -objdir /workdir/tmp/net_C2332453631 -- -I /workdir/tmp/net_C2332453631 cgo_linux.go cgo_resnew.go cgo_socknew.go cgo_unix.go]: signal: killed
cgo: open /workdir/tmp/net_C2332453631/cgo_linux.cgo1.go: no such file or directory
FAIL	golang.org/x/tools/go/internal/gcimporter	54.500s

bcmills · 2021-11-02T21:01:28Z

I suspect that this is an awkward side-effect of running out of RAM in memory-intensive tests (#33959).

(It would be nice if the failure mode of running out of RAM for this test were clearer, but that doesn't appear to be directly related to gcimporter.)

bcmills · 2021-11-02T21:07:47Z

Marking WaitingForInfo to remind myself to check for further unexplained failures after CL 193181.

x/tools/go/loader by default prints errors to stderr. TestBExportData_stdlib and TestIExportData_stdlib intentionally load packages with errors, resulting in spurious (and confusing) output from passing tests when the test binary fails for other reasons. Suppress these spurious errors by setting each tests's types.Config to print errors to the test log instead. For golang/go#38415 Change-Id: I93fee06c4141bb4c15bd285844668df6eec44892 Reviewed-on: https://go-review.googlesource.com/c/tools/+/360914 Trust: Bryan C. Mills <bcmills@google.com> Run-TryBot: Bryan C. Mills <bcmills@google.com> gopls-CI: kokoro <noreply+kokoro@google.com> TryBot-Result: Go Bot <gobot@golang.org> Reviewed-by: Robert Findley <rfindley@google.com>

gopherbot · 2021-11-02T21:24:33Z

Change https://golang.org/cl/360915 mentions this issue: go/internal/gcimporter: remove skipSpecialPlatforms

gopherbot · 2021-11-02T21:24:34Z

Change https://golang.org/cl/360914 mentions this issue: go/internal/gcimporter: avoid printing to stderr in passing tests

It does not appear to be needed any more. For golang/go#38415 Change-Id: I5c9525a96606df93c58cc15a4cb4281f95b93902 Reviewed-on: https://go-review.googlesource.com/c/tools/+/360915 Trust: Bryan C. Mills <bcmills@google.com> gopls-CI: kokoro <noreply+kokoro@google.com> Run-TryBot: Bryan C. Mills <bcmills@google.com> Reviewed-by: Robert Findley <rfindley@google.com> TryBot-Result: Go Bot <gobot@golang.org>

bcmills · 2021-11-03T15:11:48Z

These failures appear to have stopped abruptly as of CL 193181. I'm calling this fixed.

greplogs --dashboard -md -l -e ^FAIL\\s+golang\\.org/x/tools/go/internal/gcimporter --since=2021-11-02

bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 13, 2020

gopherbot added this to the Unreleased milestone Apr 13, 2020

gopherbot added the Tools This label describes issues relating to any tools in the x/tools repository. label Apr 13, 2020

bcmills changed the title ~~x/tools/go/internal/gcimporter: test failures on linux-ppc64le-power9osu builder~~ x/tools/go/internal/gcimporter: failures with "undeclared name: undefined" May 10, 2021

bcmills changed the title ~~x/tools/go/internal/gcimporter: failures with "undeclared name: undefined"~~ x/tools/go/internal/gcimporter: frequent failures with "undeclared name: undefined" May 10, 2021

bcmills modified the milestones: Unreleased, Go1.17 May 10, 2021

bcmills added the release-blocker label May 10, 2021

bcmills mentioned this issue May 25, 2021

x/tools/gopls/internal/regtest/*: frequent failures on smaller builders #46183

Open

dmitshur added the okay-after-beta1 Used by release team to mark a release-blocker issue as okay to resolve either before or after beta1 label May 27, 2021

heschi removed the okay-after-beta1 Used by release team to mark a release-blocker issue as okay to resolve either before or after beta1 label Jun 10, 2021

stamblerre removed the release-blocker label Jun 28, 2021

mknyszek modified the milestones: Go1.17, Backlog Aug 18, 2021

bcmills modified the milestones: Backlog, Go1.18 Oct 4, 2021

bcmills added the release-blocker label Oct 4, 2021

bcmills changed the title ~~x/tools/go/internal/gcimporter: frequent failures with "undeclared name: undefined"~~ x/tools/go/internal/gcimporter: frequent failures without useful output Nov 2, 2021

bcmills added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Nov 2, 2021

bcmills closed this as completed Nov 3, 2021

golang locked and limited conversation to collaborators Nov 3, 2022

gopherbot added the FrozenDueToAge label Nov 3, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

x/tools/go/internal/gcimporter: frequent failures without useful output #38415

x/tools/go/internal/gcimporter: frequent failures without useful output #38415

bcmills commented Apr 13, 2020

stamblerre commented Apr 13, 2020

bcmills commented Apr 13, 2020

griesemer commented Apr 13, 2020 •

edited

bcmills commented Apr 13, 2020

laboger commented Apr 13, 2020

bcmills commented Apr 13, 2020

laboger commented Apr 13, 2020

bcmills commented May 10, 2021

bcmills commented May 10, 2021

bcmills commented May 10, 2021

heschi commented May 13, 2021

findleyr commented May 25, 2021

heschi commented Jun 10, 2021

stamblerre commented Jun 18, 2021

toothrot commented Jun 25, 2021

findleyr commented Jun 25, 2021

findleyr commented Jun 28, 2021

bcmills commented Jun 28, 2021

bcmills commented Oct 4, 2021 •

edited

bcmills commented Oct 14, 2021

laboger commented Oct 18, 2021

findleyr commented Oct 18, 2021

laboger commented Oct 20, 2021

laboger commented Oct 25, 2021

bcmills commented Nov 2, 2021

bcmills commented Nov 2, 2021

gopherbot commented Nov 2, 2021

gopherbot commented Nov 2, 2021

bcmills commented Nov 3, 2021

x/tools/go/internal/gcimporter: frequent failures without useful output #38415

x/tools/go/internal/gcimporter: frequent failures without useful output #38415

Comments

bcmills commented Apr 13, 2020

stamblerre commented Apr 13, 2020

bcmills commented Apr 13, 2020

griesemer commented Apr 13, 2020 • edited

bcmills commented Apr 13, 2020

laboger commented Apr 13, 2020

bcmills commented Apr 13, 2020

laboger commented Apr 13, 2020

bcmills commented May 10, 2021

bcmills commented May 10, 2021

bcmills commented May 10, 2021

heschi commented May 13, 2021

findleyr commented May 25, 2021

heschi commented Jun 10, 2021

stamblerre commented Jun 18, 2021

toothrot commented Jun 25, 2021

findleyr commented Jun 25, 2021

findleyr commented Jun 28, 2021

bcmills commented Jun 28, 2021

bcmills commented Oct 4, 2021 • edited

bcmills commented Oct 14, 2021

laboger commented Oct 18, 2021

findleyr commented Oct 18, 2021

laboger commented Oct 20, 2021

laboger commented Oct 25, 2021

bcmills commented Nov 2, 2021

bcmills commented Nov 2, 2021

gopherbot commented Nov 2, 2021

gopherbot commented Nov 2, 2021

bcmills commented Nov 3, 2021

griesemer commented Apr 13, 2020 •

edited

bcmills commented Oct 4, 2021 •

edited