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

time: TestOverflowRuntimeTimer fails on freebsd/amd64 #6874

Closed
davecheney opened this issue Dec 2, 2013 · 14 comments
Closed

time: TestOverflowRuntimeTimer fails on freebsd/amd64 #6874

davecheney opened this issue Dec 2, 2013 · 14 comments
Milestone

Comments

@davecheney
Copy link
Contributor

What steps will reproduce the problem?

> --- FAIL: TestOverflowRuntimeTimer (0.10 seconds)
>         sleep_test.go:402: runtime timer stuck: overflow in addtimer
> FAIL
> FAIL    time    5.529s

This test fails frequently on our freebsd/amd64 builder. This may be a visualization
related issue, or a real problem lurking below the surface.

http://build.golang.org/log/578b35028f3e8262df6520fcb9eec7f1865148d3
@ality
Copy link
Member

ality commented Dec 2, 2013

Comment 1:

Very likely an artifact of virtualization. We should probably just
bump up the timeout by default. Windows had to be special cased for
the same reason.
I should have listened to Rob when he suggested making the timeout
very long "like a second"­ (https://golang.org/cl/9035047).

@minux
Copy link
Member

minux commented Dec 2, 2013

Comment 2:

yeah, i also remember that i saw the same failure on other virtualized builders,
but couldn't find the link.

@rsc
Copy link
Contributor

rsc commented Dec 4, 2013

Comment 3:

Labels changed: added release-none, removed go1.3maybe.

@rsc
Copy link
Contributor

rsc commented Dec 4, 2013

Comment 4:

Labels changed: added repo-main.

@davecheney
Copy link
Contributor Author

Comment 5:

I ran this test on real hardware in a loop and it failed.
--- FAIL: TestOverflowRuntimeTimer (0.10 seconds)
        sleep_test.go:402: runtime timer stuck: overflow in addtimer
FAIL
FAIL    time    7.448s
I think the theory that the failures we have seen in CI is not correct. This is a real
problem.

Labels changed: added release-go1.3, removed priority-soon, release-none.

@ality
Copy link
Member

ality commented Jan 31, 2014

Comment 6:

Dave,
Can you please apply https://golang.org/cl/58880043/ and run
the tests for the time package?
The log might be quite long so you might want to send it to golang-dev.
Thanks.

@davecheney
Copy link
Contributor Author

Comment 7:

Thanks, i'll try this tonight.

@davecheney
Copy link
Contributor Author

Comment 8:

Hmm, I ran the test in a loop overnight and could not generate a failure.
http://paste.ubuntu.com/6852101/
I don't know if this was due to the logging altering the timing issues in the test, or
because I was not running the full test suite now (the additional output causes other
tests to fail)

@davecheney
Copy link
Contributor Author

Comment 9:

Issue #6437 has been merged into this issue.

@davecheney
Copy link
Contributor Author

Comment 10:

I think I have an idea what is going wrong. Applying this diff
diff -r d2e78612ed03 src/pkg/time/internal_test.go
--- a/src/pkg/time/internal_test.go     Fri Jan 31 17:43:46 2014 +1100
+++ b/src/pkg/time/internal_test.go     Sat Feb 01 13:44:06 2014 +1100
@@ -70,6 +70,10 @@
        // any more timers (they might hang due to the same bug we're
        // now testing).
        stop := Now().Add(timeout)
+       var count int
+       defer func() {
+               print("count "); println(count)
+       }()
        for {
                select {
                case <-t.C:
@@ -78,6 +82,7 @@
                        if Now().After(stop) {
                                return errors.New("runtime timer stuck: overflow in addtimer")
                        }
+                       count++
                        runtime.Gosched()
                }
        }
Then observing the value of count
deadwood(~/go/src/pkg/time) % while ./time.test ; do true ; done
count 19
PASS
count 18
PASS
count 18
PASS
We see that runtime.Gosched() does not yield to the timer goroutine immediately. However
18 iterations of the loop is sufficient to get the timer goroutine on the scheduler and
send the value down t.C.
However if the machine is loaded, as it will be by default when go test -short std runs,
the results become unpredictable.
^Cdeadwood(~/go/src/pkg/time) % while ./time.test ; do true ; done
count 614
PASS
count 1
PASS
count 860
PASS
count 343
PASS
count 2
I don't believe runtime.Gosched is yielding to the waiting goroutine.

@davecheney
Copy link
Contributor Author

Comment 11:

Owner changed to @davecheney.

Status changed to Started.

@davecheney
Copy link
Contributor Author

Comment 12:

Here is a possible fix, https://golang.org/cl/56540046

@davecheney
Copy link
Contributor Author

Comment 13:

This issue was closed by revision d98b3a7.

Status changed to Fixed.

@gpaul
Copy link
Contributor

gpaul commented May 27, 2014

Comment 14:

This test is failing quite often on our build server. The last failure was on
4b3cdcb02f2d38cb59a5e738c79100e91572809e.

@rsc rsc added this to the Go1.3 milestone Apr 14, 2015
@rsc rsc removed the release-go1.3 label Apr 14, 2015
@golang golang locked and limited conversation to collaborators Jun 25, 2016
This issue was closed.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

6 participants