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/telemetry/internal/counter: TestNewFile persistently failing on linux-amd64-wsl using Go 1.20 and Go tip #60966

Closed
dmitshur opened this issue Jun 23, 2023 · 12 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. telemetry x/telemetry issues
Milestone

Comments

@dmitshur
Copy link
Contributor

dmitshur commented Jun 23, 2023

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`

The linux-amd64-wsl builder is persistently failing on TestNewFile in this package on Go 1.20 release branch and Go tip. Example failure:

--- FAIL: TestNewFile (0.00s)
    counter_test.go:164: GOOS linux GARCH amd64
    counter_test.go:220: 5: days = 7, want 7 < days <= 14
2023/06/23 21:08:22 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate813491770/001/local/counter.test-devel-linux-amd64-2023-06-23.v1.count
FAIL
FAIL	golang.org/x/telemetry/internal/counter	0.128s

See https://build.golang.org/log/b96749f3606ddcbb735661cd819ea69e2dc17fb4 for an example log. More are visible at https://build.golang.org/?repo=golang.org%2fx%2ftelemetry.

Very similar to #60970.

CC @mengzhuo.

@dmitshur dmitshur added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. telemetry x/telemetry issues labels Jun 23, 2023
@dmitshur dmitshur added this to the Unreleased milestone Jun 23, 2023
@bcmills
Copy link
Contributor

bcmills commented Jun 23, 2023

It is worth noting that this builder is passing reliably on release-branch.go1.19. 🤔

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-16 01:40 linux-amd64-wsl telemetry@e57d97b5 go@bc21d6a4 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:164: GOOS linux GARCH amd64
    counter_test.go:220: 0: days = 7, want 7 < days <= 14
    counter_test.go:220: 1: days = 7, want 7 < days <= 14
    counter_test.go:220: 7: days = 7, want 7 < days <= 14
    counter_test.go:220: 10: days = 7, want 7 < days <= 14
    counter_test.go:220: 12: days = 7, want 7 < days <= 14
    counter_test.go:220: 16: days = 7, want 7 < days <= 14
2023/06/20 05:15:28 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate3292186188/001/local/counter.test-devel-linux-amd64-2023-06-20.v1.count
2023-06-23 12:10 linux-amd64-wsl telemetry@09c2e0cd go@6dce882b x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:164: GOOS linux GARCH amd64
    counter_test.go:220: 0: days = 7, want 7 < days <= 14
    counter_test.go:220: 17: days = 7, want 7 < days <= 14
2023/06/23 23:46:21 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2270949139/001/local/counter.test-devel-linux-amd64-2023-06-23.v1.count
2023-06-23 12:10 linux-amd64-wsl telemetry@09c2e0cd go@164aceea x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:164: GOOS linux GARCH amd64
    counter_test.go:220: 5: days = 7, want 7 < days <= 14
2023/06/23 21:08:22 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate813491770/001/local/counter.test-devel-linux-amd64-2023-06-23.v1.count
2023-06-23 17:01 linux-amd64-wsl telemetry@de303cde go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 8: days = 7, want 7 < days <= 14
    counter_test.go:234: 15: days = 7, want 7 < days <= 14
2023/06/24 01:25:10 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate362138651/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count
2023-06-23 17:01 linux-amd64-wsl telemetry@de303cde go@48dbb622 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 8: days = 7, want 7 < days <= 14
2023/06/24 01:18:41 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2676844194/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count
2023-06-23 17:33 linux-amd64-wsl telemetry@fba892ad go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 7: days = 7, want 7 < days <= 14
2023/06/24 01:44:05 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2506632963/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count
2023-06-23 17:33 linux-amd64-wsl telemetry@fba892ad go@48dbb622 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 2: days = 7, want 7 < days <= 14
    counter_test.go:234: 9: days = 7, want 7 < days <= 14
    counter_test.go:234: 14: days = 7, want 7 < days <= 14
2023/06/24 01:37:04 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate1874827188/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count
2023-06-23 18:00 linux-amd64-wsl telemetry@b6b6ba5c go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 0: days = 7, want 7 < days <= 14
    counter_test.go:234: 6: days = 7, want 7 < days <= 14
    counter_test.go:234: 7: days = 7, want 7 < days <= 14
    counter_test.go:234: 15: days = 7, want 7 < days <= 14
2023/06/24 02:22:07 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate1892278530/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count
2023-06-23 18:00 linux-amd64-wsl telemetry@b6b6ba5c go@48dbb622 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 1: days = 7, want 7 < days <= 14
    counter_test.go:234: 10: days = 7, want 7 < days <= 14
2023/06/24 02:15:31 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate567826073/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count

watchflakes

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-23 12:10 linux-amd64-wsl telemetry@09c2e0cd go@3adcce5a x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:164: GOOS linux GARCH amd64
    counter_test.go:220: 1: days = 7, want 7 < days <= 14
    counter_test.go:220: 12: days = 7, want 7 < days <= 14
    counter_test.go:220: 15: days = 7, want 7 < days <= 14
2023/06/24 03:19:23 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2182872623/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count

watchflakes

@hyangah
Copy link
Contributor

hyangah commented Jun 23, 2023

It is worth noting that this builder is passing reliably on release-branch.go1.19. 🤔

The test has build tag go1.20 :-P Sent https://go-review.googlesource.com/c/telemetry/+/505722 to remove the build tag.

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-23 18:00 linux-amd64-wsl telemetry@b6b6ba5c go@36192557 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GARCH amd64
    counter_test.go:234: 7: days = 7, want 7 < days <= 14
2023/06/24 05:12:26 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2890117628/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count
2023-06-23 21:36 linux-amd64-wsl telemetry@5a4cd7a1 go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GOARCH amd64
    counter_test.go:234: 0: days = 7, want 7 < days <= 14
    counter_test.go:234: 6: days = 7, want 7 < days <= 14
2023/06/24 05:45:35 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2218765962/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count
2023-06-23 21:36 linux-amd64-wsl telemetry@5a4cd7a1 go@36192557 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.01s)
    counter_test.go:178: GOOS linux GOARCH amd64
    counter_test.go:234: 3: days = 7, want 7 < days <= 14
    counter_test.go:234: 5: days = 7, want 7 < days <= 14
    counter_test.go:234: 7: days = 7, want 7 < days <= 14
    counter_test.go:234: 9: days = 7, want 7 < days <= 14
2023/06/24 05:42:18 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2101387774/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count

watchflakes

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-23 22:16 linux-amd64-wsl telemetry@4221be31 go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GOARCH amd64
    counter_test.go:234: 1: days = 7, want 7 < days <= 14
2023/06/24 06:37:24 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate626649526/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count
2023-06-23 22:16 linux-amd64-wsl telemetry@4221be31 go@36192557 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:178: GOOS linux GOARCH amd64
    counter_test.go:234: 10: days = 7, want 7 < days <= 14
    counter_test.go:234: 16: days = 7, want 7 < days <= 14
2023/06/24 06:20:29 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate13331636/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count
2023-06-23 22:17 linux-amd64-wsl telemetry@6635316a go@36192557 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:179: GOOS linux GOARCH amd64
    counter_test.go:235: 8: days = 7, want 7 < days <= 14
2023/06/24 06:24:24 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate2287065937/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count

watchflakes

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-23 22:17 linux-amd64-wsl telemetry@6635316a go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:179: GOOS linux GOARCH amd64
    counter_test.go:235: 8: days = 7, want 7 < days <= 14
    counter_test.go:235: 11: days = 7, want 7 < days <= 14
2023/06/24 06:30:55 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate1941359715/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count
2023-06-23 22:42 linux-amd64-wsl telemetry@e5af7fd1 go@36192557 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:179: GOOS linux GOARCH amd64
    counter_test.go:235: 5: days = 7, want 7 < days <= 14
    counter_test.go:235: 7: days = 7, want 7 < days <= 14
    counter_test.go:235: 13: days = 7, want 7 < days <= 14
    counter_test.go:235: 15: days = 7, want 7 < days <= 14
2023/06/24 06:48:21 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate3176586082/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count

watchflakes

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-23 22:42 linux-amd64-wsl telemetry@e5af7fd1 go@ea927e56 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:179: GOOS linux GOARCH amd64
    counter_test.go:235: 3: days = 7, want 7 < days <= 14
    counter_test.go:235: 7: days = 7, want 7 < days <= 14
2023/06/24 09:36:49 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate72750334/001/local/counter.test-devel-linux-amd64-2023-06-24.v1.count
2023-06-23 22:42 linux-amd64-wsl telemetry@e5af7fd1 go@bca81759 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:179: GOOS linux GOARCH amd64
    counter_test.go:235: 0: days = 7, want 7 < days <= 14
    counter_test.go:235: 1: days = 7, want 7 < days <= 14
    counter_test.go:235: 15: days = 7, want 7 < days <= 14
2023/06/24 06:54:51 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate3470210639/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count

watchflakes

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-23 22:42 linux-amd64-wsl telemetry@e5af7fd1 go@65092835 x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:179: GOOS linux GOARCH amd64
    counter_test.go:235: 4: days = 7, want 7 < days <= 14
    counter_test.go:235: 13: days = 7, want 7 < days <= 14
    counter_test.go:235: 19: days = 7, want 7 < days <= 14
2023/06/24 12:08:17 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate4258632655/001/local/counter.test-go1.20.5-linux-amd64-2023-06-24.v1.count

watchflakes

@dmitshur dmitshur moved this to Active in Test Flakes Jun 24, 2023
@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/telemetry/internal/counter" && test == "TestNewFile" && builder == "linux-amd64-wsl" && `days = 7`
2023-06-29 17:56 linux-amd64-wsl telemetry@2375252a go@d3d78b4b x/telemetry/internal/counter.TestNewFile (log)
--- FAIL: TestNewFile (0.00s)
    counter_test.go:177: GOOS linux GOARCH amd64
    counter_test.go:233: 1: days = 7, want 7 < days <= 14
    counter_test.go:233: 6: days = 7, want 7 < days <= 14
    counter_test.go:233: 15: days = 7, want 7 < days <= 14
2023/07/08 00:00:05 closing /tmp/workdir-host-linux-amd64-wsl/tmp/TestRotate4127987706/001/local/counter.test-devel-linux-amd64-2023-07-08.v1.count

watchflakes

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/508499 mentions this issue: internal/counter: add test logging to debug TestNewFile flakiness

gopherbot pushed a commit to golang/telemetry that referenced this issue Jul 8, 2023
TestNewFile is flakay and consistently failing on linux-amd64-wsl.
The test checks if the end timestamp in the counter file's metadata
is within a reasonable range by computing the time since a test
reference timestamp ('now').

Log all involved timestamps for investigation.

WSL https://build.golang.org/log/fd86b72f06c8291187d0a30c41d24ddb9e959207
RISCV64 https://build.golang.org/log/3392c1e69a53dd6adf359de10923a771ef77b488
Solaris https://build.golang.org/log/466ee94eb52ce64476d1b75d9a3fc1c26f4a9094

For golang/go#60970
For golang/go#60966

Change-Id: I0a9060cee524761245c7f470938f63c1b6717d1f
Reviewed-on: https://go-review.googlesource.com/c/telemetry/+/508499
TryBot-Result: Gopher Robot <[email protected]>
Reviewed-by: Peter Weinberger <[email protected]>
Run-TryBot: Hyang-Ah Hana Kim <[email protected]>
@gopherbot
Copy link
Contributor

Change https://go.dev/cl/508501 mentions this issue: internal/counter: fix TestNewFile test

@github-project-automation github-project-automation bot moved this from Active to Done in Test Flakes Jul 10, 2023
@golang golang locked and limited conversation to collaborators Jul 9, 2024
Pinkle-pash added a commit to Pinkle-pash/telemetry that referenced this issue Dec 4, 2024
The test checks whether a newly created counter file has
the TimeEnd metadata value within expected range, by computing
the time difference between the TimeEnd value and a test reference
time computed at the beginning of the test.
Unfortunately, the reference timestamp calculation used a different
time zone than what's used in computing TimeEnd, and caused the
test failure on some builders with some probabilities depending on
builders' time zones.

Here is the log from the test failure that shows this issue.


--- FAIL: TestNewFile (0.00s)
    counter_test.go:177: GOOS linux GOARCH amd64
    counter_test.go:233: now: 2023-07-08 00:00:00 +0000 UTC file: counter.test-go1.19.10-linux-amd64-2023-07-08.v1.count TimeBegin: 2023-07-08 00:00:00 +0800 CST TimeEnd: 2023-07-16 00:00:00 +0800 CST
    counter_test.go:234: 0: days = 7, want 7 < days <= 14
    counter_test.go:233: now: 2023-07-08 00:00:00 +0000 UTC file: counter.test-go1.19.10-linux-amd64-2023-07-08.v1.count TimeBegin: 2023-07-08 00:00:00 +0800 CST TimeEnd: 2023-07-16 00:00:00 +0800 CST
    counter_test.go:234: 13: days = 7, want 7 < days <= 14
    counter_test.go:233: now: 2023-07-08 00:00:00 +0000 UTC file: counter.test-go1.19.10-linux-amd64-2023-07-08.v1.count TimeBegin: 2023-07-08 00:00:00 +0800 CST TimeEnd: 2023-07-16 00:00:00 +0800 CST
    counter_test.go:234: 15: days = 7, want 7 < days <= 14

For golang/go#60970
Fixes golang/go#60966

Change-Id: I52936f5fe12c13f7ccf3c052cbbb9b403fcad332
Reviewed-on: https://go-review.googlesource.com/c/telemetry/+/508501
Run-TryBot: Hyang-Ah Hana Kim <[email protected]>
Reviewed-by: Peter Weinberger <[email protected]>
Run-TryBot: Heschi Kreinick <[email protected]>
TryBot-Result: Gopher Robot <[email protected]>
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. telemetry x/telemetry issues
Projects
Archived in project
Development

No branches or pull requests

4 participants