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

os: TestChtimes failures #68687

Closed
gopherbot opened this issue Jul 31, 2024 · 11 comments
Closed

os: TestChtimes failures #68687

gopherbot opened this issue Jul 31, 2024 · 11 comments
Labels
FixPending Issues that have a fix which has not yet been reviewed or submitted. NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone

Comments

@gopherbot
Copy link
Contributor

#!watchflakes
default <- pkg == "os" && test == "TestChtimes"

Issue created automatically to collect these failures.

Example (log):

=== RUN   TestChtimes
=== PAUSE TestChtimes
=== CONT  TestChtimes
    os_test.go:1539: AccessTime didn't go backwards; was=2024-07-31 20:45:53.390326147 +0000 UTC, after=2024-07-31 20:45:53.394326118 +0000 UTC
--- FAIL: TestChtimes (0.00s)

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 Jul 31, 2024
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "os" && test == "TestChtimes"
2024-07-31 19:54 gotip-linux-arm go@ab7435ab os.TestChtimes (log)
=== RUN   TestChtimes
=== PAUSE TestChtimes
=== CONT  TestChtimes
    os_test.go:1539: AccessTime didn't go backwards; was=2024-07-31 20:45:53.390326147 +0000 UTC, after=2024-07-31 20:45:53.394326118 +0000 UTC
--- FAIL: TestChtimes (0.00s)

watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "os" && test == "TestChtimes"
2024-08-02 14:33 gotip-linux-arm go@e7619216 os.TestChtimes (log)
=== RUN   TestChtimes
=== PAUSE TestChtimes
=== CONT  TestChtimes
    os_test.go:1539: AccessTime didn't go backwards; was=2024-08-02 19:24:19.187745351 +0000 UTC, after=2024-08-02 19:24:19.191745319 +0000 UTC
--- FAIL: TestChtimes (0.00s)

watchflakes

@kolyshkin
Copy link
Contributor

This seems like the same issue as #68663, which started happening on ARM since 2024-07-30.

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/604155 mentions this issue: [DO NOT MERGE] test chtimes failures on gotip-linux-arm

@dmitshur
Copy link
Contributor

dmitshur commented Aug 8, 2024

The linux-arm builder had a change in its environment on 2024-07-29, which coincidences with the timing of this test becoming flaky on that builder. The host VM started running additional security software in the background. The intent was not not affect the signal the builder provides, but it is possible that this test becoming flaky is related to that environment change rather than a change in the Go tree itself.

@kolyshkin
Copy link
Contributor

The linux-arm builder had a change in its environment on 2024-07-29, which coincidences with the timing of this test becoming flaky on that builder. The host VM started running additional security software in the background. The intent was not not affect the signal the builder provides, but it is possible that this test becoming flaky is related to that environment change rather than a change in the Go tree itself.

So basically someone else is reading the file, which changes its atime.

This can probably be mitigated by having an empty file. inode(7) says:

Last access timestamp (atime)
stat.st_atime; statx.stx_atime

This is the file's last access timestamp. It is changed by file accesses, for example, by
execve(2), mknod(2), pipe(2), utime(2), and read(2) (of more than zero bytes). Other interfaces,
such as mmap(2), may or may not update the atime timestamp

If we make a file of 0 bytes, no one can read more than 0 bytes from it,
and the problem will disappear. Let me try that.

The alternative is to use a different location which is guaranteed to not be touched by the above mentioned security software (although that could defeat the purpose of that software).

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/604315 mentions this issue: os: fix Chtimes test flakes

@dmitshur dmitshur added the FixPending Issues that have a fix which has not yet been reviewed or submitted. label Aug 8, 2024
@dmitshur dmitshur added this to the Go1.24 milestone Aug 8, 2024
@dmitshur dmitshur moved this to Active in Test Flakes Aug 8, 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 Aug 8, 2024
@github-project-automation github-project-automation bot moved this from Active to Done in Test Flakes Aug 8, 2024
@gopherbot
Copy link
Contributor Author

gopherbot commented Aug 8, 2024

Change https://go.dev/cl/604196 mentions this issue: [release-branch.go1.23] os: fix Chtimes test flakes

@dmitshur dmitshur added the Testing An issue that has been verified to require only test changes, not just a test failure. label Aug 9, 2024
@dmitshur
Copy link
Contributor

dmitshur commented Aug 9, 2024

@gopherbot Please backport to Go 1.23 and 1.22. This is a test-only fix that makes a test more resilient against other programs possibly reading files in the background. It's also needed to fix test flakiness on the linux/arm builder where this started happening after a builder environment change.

@gopherbot
Copy link
Contributor Author

Backport issue(s) opened: #68811 (for 1.22), #68812 (for 1.23).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://go.dev/wiki/MinorReleases.

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/605375 mentions this issue: [release-branch.go1.22] os: fix Chtimes test flakes

gopherbot pushed a commit that referenced this issue Aug 14, 2024
It appears that some builders (notably, linux-arm) have some additional
security software installed, which apparently reads the files created by
tests. As a result, test file atime is changed, making the test fail
like these:

=== RUN   TestChtimesOmit
    ...
    os_test.go:1475: atime mismatch, got: "2024-07-30 18:42:03.450932494 +0000 UTC", want: "2024-07-30 18:42:02.450932494 +0000 UTC"

=== RUN   TestChtimes
    ...
    os_test.go:1539: AccessTime didn't go backwards; was=2024-07-31 20:45:53.390326147 +0000 UTC, after=2024-07-31 20:45:53.394326118 +0000 UTC

According to inode(7), atime is changed when more than 0 bytes are read
from the file. So, one possible solution to these flakes is to make the
test files empty, so no one can read more than 0 bytes from them.

For #68687
For #68663
Fixes #68812

Change-Id: Ib9234567883ef7b16ff8811e3360cd26c2d6bdab
Reviewed-on: https://go-review.googlesource.com/c/go/+/604315
LUCI-TryBot-Result: Go LUCI <[email protected]>
Reviewed-by: Kirill Kolyshkin <[email protected]>
Reviewed-by: Robert Griesemer <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>
Commit-Queue: Ian Lance Taylor <[email protected]>
Auto-Submit: Ian Lance Taylor <[email protected]>
(cherry picked from commit 84266e1)
Reviewed-on: https://go-review.googlesource.com/c/go/+/604196
gopherbot pushed a commit that referenced this issue Aug 14, 2024
It appears that some builders (notably, linux-arm) have some additional
security software installed, which apparently reads the files created by
tests. As a result, test file atime is changed, making the test fail
like these:

=== RUN   TestChtimesOmit
    ...
    os_test.go:1475: atime mismatch, got: "2024-07-30 18:42:03.450932494 +0000 UTC", want: "2024-07-30 18:42:02.450932494 +0000 UTC"

=== RUN   TestChtimes
    ...
    os_test.go:1539: AccessTime didn't go backwards; was=2024-07-31 20:45:53.390326147 +0000 UTC, after=2024-07-31 20:45:53.394326118 +0000 UTC

According to inode(7), atime is changed when more than 0 bytes are read
from the file. So, one possible solution to these flakes is to make the
test files empty, so no one can read more than 0 bytes from them.

For #68687
For #68663
Fixes #68811

Change-Id: Ib9234567883ef7b16ff8811e3360cd26c2d6bdab
Reviewed-on: https://go-review.googlesource.com/c/go/+/604315
LUCI-TryBot-Result: Go LUCI <[email protected]>
Reviewed-by: Kirill Kolyshkin <[email protected]>
Reviewed-by: Robert Griesemer <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>
Commit-Queue: Ian Lance Taylor <[email protected]>
Auto-Submit: Ian Lance Taylor <[email protected]>
(cherry picked from commit 84266e1)
Reviewed-on: https://go-review.googlesource.com/c/go/+/605375
Reviewed-by: Carlos Amedee <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
FixPending Issues that have a fix which has not yet been reviewed or submitted. NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
Archived in project
Development

No branches or pull requests

3 participants