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

runtime/pprof: TestVMInfo failures #62352

Closed
gopherbot opened this issue Aug 29, 2023 · 58 comments
Closed

runtime/pprof: TestVMInfo failures #62352

gopherbot opened this issue Aug 29, 2023 · 58 comments
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@gopherbot
Copy link
Contributor

gopherbot commented Aug 29, 2023

#!watchflakes
post <- pkg == "runtime/pprof" && test == "TestVMInfo"

Issue created automatically to collect these failures.

Example (log):

--- FAIL: TestVMInfo (0.37s)
    vminfo_darwin_test.go:59: exit status 255

watchflakes

@gopherbot gopherbot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 29, 2023
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime/pprof" && test == "TestVMInfo"
2023-08-29 16:16 darwin-amd64-nocgo go@4e48e467 runtime/pprof.TestVMInfo (log)
--- FAIL: TestVMInfo (0.37s)
    vminfo_darwin_test.go:59: exit status 255

watchflakes

@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Aug 29, 2023
@bcmills
Copy link
Contributor

bcmills commented Aug 29, 2023

This test is new during the Go 1.22 cycle (https://go.dev/cl/503919; attn @cosnicolaou @cherrymui).

A good starting point would probably be to update the test to log the Stderr field of the *exec.ExitError on failure:
https://cs.opensource.google/go/go/+/master:src/runtime/pprof/vminfo_darwin_test.go;l=59;drc=fdc9cf3c3aaf779387f0341125680f018e5f0275

@cosnicolaou
Copy link
Contributor

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/524156 mentions this issue: runtime/pprof: print stderr on test failure

@mknyszek mknyszek moved this from Todo to In Progress in Go Compiler / Runtime Aug 30, 2023
@mknyszek mknyszek added this to the Backlog milestone Aug 30, 2023
gopherbot pushed a commit that referenced this issue Sep 1, 2023
Print Stderr on test failure to track down the intermittent
test failure reported in issue #62352.

Change-Id: I547a3220dc07d05578dac093d6c028a9103b552a
Reviewed-on: https://go-review.googlesource.com/c/go/+/524156
Reviewed-by: Michael Knyszek <mknyszek@google.com>
Reviewed-by: Dmitri Shuralyov <dmitshur@google.com>
Reviewed-by: Bryan Mills <bcmills@google.com>
Reviewed-by: Cherry Mui <cherryyz@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
@bcmills bcmills added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Sep 5, 2023
@bcmills
Copy link
Contributor

bcmills commented Sep 5, 2023

The new logging is in place, so I've marked this WaitingForInfo to see what turns up after https://go.dev/cl/524936.

@bcmills bcmills added WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. and removed WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. labels Sep 5, 2023
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime/pprof" && test == "TestVMInfo"
2023-09-08 20:37 darwin-arm64-11 go@a742ae49 runtime/pprof.TestVMInfo (log)
--- FAIL: TestVMInfo (0.29s)
    vminfo_darwin_test.go:61: vmmap failed: Process:         pprof.test [15435]
        Path:            /private/tmp/*/pprof.test
        Load Address:    0x100f50000
        Identifier:      pprof.test
        Version:         ???
        Code Type:       ARM64
        Parent Process:  go [15399]

        Date/Time:       2023-09-08 16:41:16.280 -0400
...
        ===========                     ======= ========    =====  ======= ========   ======    =====  ======= 
        TOTAL                              2.1G   326.5M    16.0M       0K       0K       0K       0K      355 

                                         VIRTUAL   RESIDENT      DIRTY    SWAPPED ALLOCATION      BYTES DIRTY+SWAP          REGION
        MALLOC ZONE                         SIZE       SIZE       SIZE       SIZE      COUNT  ALLOCATED  FRAG SIZE  % FRAG   COUNT
        ===========                      =======  =========  =========  =========  =========  =========  =========  ======  ======
        DefaultMallocZone_0x10129c000      9216K        64K        64K         0K        209        11K        53K     83%       2

    vminfo_darwin_test.go:63: /usr/bin/vmmap 15435: exit status 255
        vmmap[15527]: [fatal]  child process status could not be determined; exit code unavailable.

watchflakes

@bcmills bcmills removed the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Sep 8, 2023
@cosnicolaou
Copy link
Contributor

cosnicolaou commented Sep 11, 2023 via email

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/527276 mentions this issue: runtime/pprof: TestVMInfo reworked to avoid test flakiness.

@cosnicolaou
Copy link
Contributor

See #527276

@github-project-automation github-project-automation bot moved this from In Progress to Done in Go Compiler / Runtime Sep 14, 2023
@gopherbot gopherbot reopened this Oct 25, 2023
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime/pprof" && test == "TestVMInfo"
2023-10-18 14:46 darwin-amd64-12_0 go@1ec427e7 runtime/pprof.TestVMInfo (log)
--- FAIL: TestVMInfo (0.52s)
    vminfo_darwin_test.go:62: vmmap output: 
    vminfo_darwin_test.go:64: /usr/bin/vmmap 10392: exit status 255
        vmmap[10478]: [fatal] Failed to generate corpse from the process: 6 ((os/kern) resource shortage), exiting
    vminfo_darwin_test.go:66: /usr/bin/vmmap 10392: exit status 255
    vminfo_darwin_test.go:74: failed to parse vmmap output, vmmap reported an error: vmmap no text segment found

watchflakes

@github-project-automation github-project-automation bot moved this from Done to In Progress in Go Compiler / Runtime Oct 25, 2023
@cosnicolaou
Copy link
Contributor

Well, I'm not sure what to do about this, since it looks as if the CI runner doesn't have the resources to run another subprocess given the error message vmmap[10478]: [fatal] Failed to generate corpse from the process: 6 ((os/kern) resource shortage), exiting What would you suggest? There is no other way of testing this functionality other than comparing the values that the runtime generates with the values that the OS would generate. I'm open to suggestions!

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "runtime/pprof" && test == "TestVMInfo"
2023-11-08 14:13 darwin-amd64-12_0 go@8fb8d0df runtime/pprof.TestVMInfo (log)
--- FAIL: TestVMInfo (0.39s)
    vminfo_darwin_test.go:62: vmmap output: 
    vminfo_darwin_test.go:64: /usr/bin/vmmap 10481: exit status 255
        vmmap[10563]: [fatal] Failed to generate corpse from the process: 6 ((os/kern) resource shortage), exiting
    vminfo_darwin_test.go:66: /usr/bin/vmmap 10481: exit status 255
    vminfo_darwin_test.go:74: failed to parse vmmap output, vmmap reported an error: vmmap no text segment found

watchflakes

@bcmills
Copy link
Contributor

bcmills commented Nov 8, 2023

@cosnicolaou, at the very least, perhaps the test should skip instead of failing if the output matches that failure mode.

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && test == "TestVMInfo"
2024-04-22 13:29 gotip-darwin-amd64-longtest go@2dddc7ef runtime/pprof.TestVMInfo (log)
=== RUN   TestVMInfo
    exec.go:193: test timed out while running command: /usr/bin/vmmap 62841
    vminfo_darwin_test.go:79: vmmap output: 
    vminfo_darwin_test.go:87: /usr/bin/vmmap 62841: signal: quit
    vminfo_darwin_test.go:39: failed to parse vmmap output, vmmap reported an error: vmmap no text segment found
--- FAIL: TestVMInfo (2346.21s)

watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && test == "TestVMInfo"
2024-04-22 14:55 gotip-darwin-amd64_14 go@69aa1974 runtime/pprof.TestVMInfo (log)
=== RUN   TestVMInfo
    exec.go:193: test timed out while running command: /usr/bin/vmmap 68865
    vminfo_darwin_test.go:79: vmmap output: 
    vminfo_darwin_test.go:87: /usr/bin/vmmap 68865: signal: quit
    vminfo_darwin_test.go:39: failed to parse vmmap output, vmmap reported an error: vmmap no text segment found
--- FAIL: TestVMInfo (475.69s)

watchflakes

@gopherbot gopherbot modified the milestones: Go1.23, Go1.24 Aug 13, 2024
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && test == "TestVMInfo"
2024-10-21 13:40 gotip-darwin-amd64_14 go@c0a126b8 runtime/pprof.TestVMInfo (log)
=== RUN   TestVMInfo
    exec.go:213: test timed out while running command: /usr/bin/vmmap 45638
    vminfo_darwin_test.go:79: vmmap output: 
    vminfo_darwin_test.go:87: /usr/bin/vmmap 45638: signal: quit
    vminfo_darwin_test.go:39: failed to parse vmmap output, vmmap reported an error: vmmap no text segment found
--- FAIL: TestVMInfo (467.47s)

watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && test == "TestVMInfo"
2024-10-21 15:56 gotip-darwin-amd64-nocgo go@a1c4fb43 runtime/pprof.TestVMInfo (log)
=== RUN   TestVMInfo
    exec.go:213: test timed out while running command: /usr/bin/vmmap 17751
    vminfo_darwin_test.go:79: vmmap output: 
    vminfo_darwin_test.go:87: /usr/bin/vmmap 17751: signal: quit
    vminfo_darwin_test.go:39: failed to parse vmmap output, vmmap reported an error: vmmap no text segment found
--- FAIL: TestVMInfo (956.97s)

watchflakes

@mknyszek mknyszek moved this from In Progress to Todo in Go Compiler / Runtime Nov 13, 2024
@mknyszek mknyszek modified the milestones: Go1.24, Backlog Nov 13, 2024
@mknyszek
Copy link
Contributor

In triage, we're thinking this is actually due to some problems with the tool provided by Apple, and maybe we should just wrap it in retries.

@cosnicolaou
Copy link
Contributor

cosnicolaou commented Nov 13, 2024 via email

@cherrymui
Copy link
Member

@cosnicolaou thanks. Does the CL fix the failures? If so, maybe rebase and get it submitted (it has a merge conflict)? Thanks.

@cosnicolaou
Copy link
Contributor

cosnicolaou commented Nov 15, 2024 via email

@github-project-automation github-project-automation bot moved this from Todo to Done in Go Compiler / Runtime Nov 16, 2024
@dmitshur dmitshur added NeedsFix The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Nov 19, 2024
@dmitshur dmitshur modified the milestones: Backlog, Go1.24 Nov 19, 2024
@gopherbot gopherbot reopened this Dec 19, 2024
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "runtime/pprof" && test == "TestVMInfo"
2024-12-19 04:48 gotip-darwin-amd64_12 go@4f0561f9 runtime/pprof.TestVMInfo (log)
=== RUN   TestVMInfo
    vminfo_darwin_test.go:97: vmmap output: 
    vminfo_darwin_test.go:99: /usr/bin/vmmap 24373: exit status 255
        vmmap[25675]: [fatal] Failed to generate corpse from the process: 6 ((os/kern) resource shortage), exiting
    vminfo_darwin_test.go:105: /usr/bin/vmmap 24373: exit status 255
    vminfo_darwin_test.go:79: retrying vmmap after error: exit status 255
    vminfo_darwin_test.go:97: vmmap output: 
    vminfo_darwin_test.go:99: /usr/bin/vmmap 24373: exit status 255
        vmmap[25679]: [fatal] Failed to generate corpse from the process: 6 ((os/kern) resource shortage), exiting
    vminfo_darwin_test.go:105: /usr/bin/vmmap 24373: exit status 255
...
    vminfo_darwin_test.go:105: /usr/bin/vmmap 24373: exit status 255
    vminfo_darwin_test.go:79: retrying vmmap after error: exit status 255
    vminfo_darwin_test.go:97: vmmap output: 
    vminfo_darwin_test.go:99: /usr/bin/vmmap 24373: exit status 255
        vmmap[31676]: [fatal] Failed to generate corpse from the process: 6 ((os/kern) resource shortage), exiting
    vminfo_darwin_test.go:105: /usr/bin/vmmap 24373: exit status 255
    vminfo_darwin_test.go:79: retrying vmmap after error: exit status 255
    vminfo_darwin_test.go:86: vmmap taking too long
    exec.go:230: command was started, but test did not wait for it to complete: /usr/bin/vmmap 24373
--- FAIL: TestVMInfo (60.00s)

watchflakes

@github-project-automation github-project-automation bot moved this from Done to In Progress in Go Compiler / Runtime Dec 19, 2024
@github-project-automation github-project-automation bot moved this from Done to Active in Test Flakes Dec 19, 2024
@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/637995 mentions this issue: runtime/pprof: continued attempt to deflake the VMInfo test.

@github-project-automation github-project-automation bot moved this from In Progress to Done in Go Compiler / Runtime Dec 20, 2024
@github-project-automation github-project-automation bot moved this from Active to Done in Test Flakes Dec 20, 2024
wyf9661 pushed a commit to wyf9661/go that referenced this issue Jan 21, 2025
This change catches an additional error message to trigger skipping
the test when the underlying system is failing.

Fixes golang#62352

Change-Id: I5c12b20f3e9023597ff89fc905c0646a80ec4811
Reviewed-on: https://go-review.googlesource.com/c/go/+/637995
Reviewed-by: Cherry Mui <cherryyz@google.com>
Auto-Submit: Michael Pratt <mpratt@google.com>
Reviewed-by: Michael Pratt <mpratt@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsFix The path to resolution is known, but the work has not been done.
Projects
Archived in project
Development

No branches or pull requests

6 participants