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

x/build/internal/task: TestTagSingleRepo failures with context deadline exceeded on darwin #63731

Closed
gopherbot opened this issue Oct 25, 2023 · 8 comments
Labels
Builders x/build issues (builders, bots, dashboards) NeedsFix The path to resolution is known, but the work has not been done. OS-Darwin Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone

Comments

@gopherbot
Copy link

gopherbot commented Oct 25, 2023

#!watchflakes
post <- goos == "darwin" && pkg == "golang.org/x/build/internal/task" && test == "TestTagSingleRepo" && `context deadline exceeded`

Issue created automatically to collect these failures.

Example (log):

--- FAIL: TestTagSingleRepo (75.05s)
    --- FAIL: TestTagSingleRepo/with_post-submit_check (67.83s)
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-13 14:32:57.943484 -0400 EDT m=+33.101469599	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc000134be8]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: wait for green post-submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_47cda033de1c1ecb1e1bdfbf79caec0ba063adfe
        tagx_test.go:565: context deadline exceeded

watchflakes

@gopherbot gopherbot added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Builders x/build issues (builders, bots, dashboards) labels Oct 25, 2023
@gopherbot gopherbot added this to the Unreleased milestone Oct 25, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "golang.org/x/build/internal/task" && test == "TestTagSingleRepo"
2023-10-13 18:22 darwin-amd64-13 build@f5e0fb4e go@d4863909 x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (75.05s)
    --- FAIL: TestTagSingleRepo/with_post-submit_check (67.83s)
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-13 14:32:57.943484 -0400 EDT m=+33.101469599	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc000134be8]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: wait for green post-submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_47cda033de1c1ecb1e1bdfbf79caec0ba063adfe
        tagx_test.go:565: context deadline exceeded
2023-10-14 00:37 darwin-amd64-12_0 build@49880869 go@c75a617a x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (91.35s)
    --- FAIL: TestTagSingleRepo/without_post-submit_check (86.74s)
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-20 17:53:58.15064 -0700 PDT m=+61.019222299	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc00064b2f0]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_d84b81ea96b5b6d6776d505ae8040565a027fde5
        tagx_test.go:565: context deadline exceeded
2023-10-14 00:37 darwin-amd64-12_0 build@49880869 go@d580460f x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (100.26s)
    --- FAIL: TestTagSingleRepo/without_post-submit_check (95.01s)
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-18 12:23:56.747321 -0700 PDT m=+107.656931551	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc00077e120]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:565: context deadline exceeded
2023-10-14 00:37 darwin-amd64-13 build@49880869 go@566d94fe x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (79.21s)
    --- FAIL: TestTagSingleRepo/without_post-submit_check (74.21s)
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-20 17:04:22.78323 -0400 EDT m=+44.808534174	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc0003c30c8]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_5bd9cf78d42e1fbc180f05f686da064fb93c310b
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:622: 2023-10-20 17:05:18.361834 -0400 EDT m=+100.387139544	task foo: wait for submit: LOG: Awaiting review/submit of (unparseable change ID "cl_5bd9cf78d42e1fbc180f05f686da064fb93c310b")
        tagx_test.go:604: task foo: wait for submit: done: 5bd9cf78d42e1fbc180f05f686da064fb93c310b
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:622: 2023-10-20 17:05:21.827831 -0400 EDT m=+103.853136475	task foo: tag if appropriate: LOG: Tagging foo at 5bd9cf78d42e1fbc180f05f686da064fb93c310b as v1.2.0
        tagx_test.go:604: task foo: tag if appropriate: done: {foo golang.org/x/foo [0xc00011cb28]  v1.1.5 v1.2.0}
        tagx_test.go:570: foo should have been tagged with v1.2.0: git command failed: context deadline exceeded, stderr 
2023-10-14 00:37 darwin-amd64-13 build@49880869 go@144252d2 x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (69.34s)
    --- FAIL: TestTagSingleRepo/with_post-submit_check (63.44s)
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-18 11:43:22.910383 -0400 EDT m=+63.327431755	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc0007aa7f8]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: wait for green post-submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_be6a00fe7e0fa5c224ce8146ce9f4df77afb7c9d
        tagx_test.go:565: context deadline exceeded
2023-10-14 00:37 darwin-amd64-13 build@49880869 go@fb726698 x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (70.62s)
    --- FAIL: TestTagSingleRepo/without_post-submit_check (66.24s)
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-17 23:16:07.676382 -0400 EDT m=+64.729840059	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc000b1a5a0]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_e635514d8021171b268e3b990d163d0cbd6e7e95
        tagx_test.go:565: context deadline exceeded
2023-10-24 17:53 darwin-amd64-13 build@a966970d go@f9a31cda x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (89.14s)
    --- FAIL: TestTagSingleRepo/with_post-submit_check (82.63s)
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-10-24 14:01:42.887343 -0400 EDT m=+69.593814980	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc0005b9128]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: mail go.mod: started
...
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_7980548793978b0973e5233cd7a6b23e902b52cb
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:622: 2023-10-24 14:02:33.211424 -0400 EDT m=+119.917896620	task foo: wait for submit: LOG: Awaiting review/submit of (unparseable change ID "cl_7980548793978b0973e5233cd7a6b23e902b52cb")
        tagx_test.go:604: task foo: wait for submit: done: 7980548793978b0973e5233cd7a6b23e902b52cb
        tagx_test.go:600: task foo: wait for green post-submit: started
        tagx_test.go:622: 2023-10-24 14:02:43.317282 -0400 EDT m=+130.023754115	task foo: wait for green post-submit: LOG: task failed, will retry (1 of 3): git command failed: signal: killed, stderr 
        tagx_test.go:600: task foo: wait for green post-submit: started
        tagx_test.go:565: context deadline exceeded

watchflakes

@bcmills bcmills changed the title x/build/internal/task: TestTagSingleRepo failures x/build/internal/task: TestTagSingleRepo failures with context deadline exceeded on darwin Oct 25, 2023
@bcmills
Copy link
Contributor

bcmills commented Oct 25, 2023

See previously #56231, #63258.

As noted in #56231 (comment), this may be part of a cluster of failures specific to macOS (see #54461 (comment)).

@bcmills
Copy link
Contributor

bcmills commented Oct 31, 2023

Looks like this particular timeout comes from here:
https://cs.opensource.google/go/x/build/+/master:internal/task/tagx_test.go;l=548;drc=96b29b7b0576775bbb2848637290d4e03aae1022

(I guess we missed one in https://go.dev/cl/533098? CC @heschi @dmitshur)

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- goos == "darwin" && pkg == "golang.org/x/build/internal/task" && test == "TestTagSingleRepo" && `context deadline exceeded`
2023-10-31 15:30 darwin-amd64-13 build@3403d10e go@23711f8e x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (72.62s)
    --- FAIL: TestTagSingleRepo/without_post-submit_check (65.84s)
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-11-01 16:07:48.336748 -0400 EDT m=+49.947276402	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc000114708]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_1d3c9cbcc5f001de2fb316d3b0bca4bd91f39842
        tagx_test.go:565: context deadline exceeded

watchflakes

@dmitshur
Copy link
Contributor

dmitshur commented Nov 2, 2023

It does seem that way, thanks for looking at this. I can send a CL.

@dmitshur dmitshur 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. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Nov 2, 2023
@gopherbot
Copy link
Author

Change https://go.dev/cl/538678 mentions this issue: internal/task: delete constant timeout in TestTagSingleRepo

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- goos == "darwin" && pkg == "golang.org/x/build/internal/task" && test == "TestTagSingleRepo" && `context deadline exceeded`
2023-11-02 20:01 darwin-amd64-13 build@ea2ff87a go@998fdce3 x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (81.24s)
    --- FAIL: TestTagSingleRepo/with_post-submit_check (73.79s)
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-11-02 21:37:27.646821 -0400 EDT m=+39.432211545	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc0005d93e0]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: wait for green post-submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_302d4d6a4c5682bc402a0da8bf3ae71066199daf
        tagx_test.go:565: context deadline exceeded

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- goos == "darwin" && pkg == "golang.org/x/build/internal/task" && test == "TestTagSingleRepo" && `context deadline exceeded`
2023-11-02 20:01 darwin-amd64-13 build@ea2ff87a go@450f469c x/build/internal/task.TestTagSingleRepo (log)
--- FAIL: TestTagSingleRepo (71.62s)
    --- FAIL: TestTagSingleRepo/without_post-submit_check (66.10s)
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:600: task Load all repositories: started
        tagx_test.go:622: 2023-11-02 18:28:16.856136 -0400 EDT m=+116.892591914	task Load all repositories: LOG: Examining repositories [mod foo]
        tagx_test.go:604: task Load all repositories: done: [{mod golang.org/x/mod []  v1.1.0 } {foo golang.org/x/foo [0xc0007a2870]  v1.1.5 }]
        tagx_test.go:600: task Create single-repo plan: started
        tagx_test.go:604: task Create single-repo plan: done: <nil>
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:600: task foo: wait for submit: started
        tagx_test.go:600: task foo: tag if appropriate: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:600: task foo: generate go.mod: started
        tagx_test.go:604: task foo: generate go.mod: done: map[go.mod:module golang.org/x/foo
            require golang.org/x/mod v1.0.0
            // pretend we've upgraded to golang.org/x/mod@v1.1.0
            tidied! mod tidy
             go.sum:
            golang.org/x/mod v1.1.0 h1:asdasd
            ]
        tagx_test.go:600: task foo: mail go.mod: started
        tagx_test.go:604: task foo: mail go.mod: done: cl_a8a215cef5d866ffa57328209e5c85402573ff47
        tagx_test.go:565: context deadline exceeded

watchflakes

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Builders x/build issues (builders, bots, dashboards) NeedsFix The path to resolution is known, but the work has not been done. OS-Darwin Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
Archived in project
Status: Done
Development

No branches or pull requests

3 participants