runtime: cpu-bound goroutine blocks finalization #1671
Labels
Milestone
Comments
Revenge of issue #631. Owner changed to @rsc. Status changed to Accepted. |
|
Comment 3 by webmaster@webmaster.ms: reproducible on Windows and Linux |
Variant showing progress:
package main
import (
"fmt"
"runtime"
)
type Foo bool
func main() {
for {
newFoo()
runtime.Gosched()
runtime.Gosched()
runtime.Gosched()
runtime.Gosched()
runtime.Gosched()
}
}
var count, ndone int
func newFoo() *Foo {
f := new(Foo)
this := count
runtime.SetFinalizer(f, func(_ *Foo) {
ndone++
fmt.Printf("finalizing #%d; total %d/%d\n", this, ndone, count)
})
count++
return f
}
Dmitriy, you were looking at finalizers recently. Any ideas?
|
The problem is with fmt.Printf() which does a blocking syscall (os.Write), which in turn causes goroutine rescheduling. So exactly 1 finalizer is run per GC. The problem does not show up if either: 1. fmt.Printf() is replaced with println() or 2. main goroutine outputs stats or 3. GOMAXPROCS=2 or 4. main goroutine episodically executes sleep So the issue is just an unfortunate interaction of several factor. I think we are closing it. |
|
Owner changed to builder@golang.org. |
package main
import (
"runtime"
"fmt"
"time"
)
type Foo bool
func main() {
for i := 0;; i++ {
newFoo()
if i%100 == 0 {
time.Sleep(100*time.Millisecond)
}
}
}
var count int
var nfin int
func newFoo() *Foo {
f := new(Foo)
this := count
runtime.SetFinalizer(f, func(_ *Foo) {
nfin++
fmt.Printf("finalized #%d %d/%d\n", this, nfin, count)
})
count++
return f
}
Sleeping every once in a while makes it work fine, so this only affects cpu-bound
programs. In that sense it is not much different from any other cpu-bound goroutine
starving the others. This won't be fixed for Go 1, but at least we understand it.
Labels changed: added priority-later, removed priority-go1. |
|
@aclements, I'll let you dup or close this one as appropriate. |
|
While it's still theoretically possible for us to fall behind on the finalizers queue since there's no backpressure on it, it looks like we keep up just fine now in practice, even without any sleeps or explicit Goscheds. I guess there have been some improvements to the scheduler in the past five years. :) |
|
I would guess that the relevant change was invoking the finalizer queue from the sysmon thread, in https://golang.org/cl/75960043. |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
When I run the following program, I get this output: finalizing 251; total 600 finalizing 250; total 602 finalizing 249; total 3997 finalizing 248; total 9501 finalizing 247; total 20908 finalizing 246; total 53407 finalizing 245; total 100954 finalizing 244; total 225684 finalizing 243; total 526626 finalizing 242; total 984099 finalizing 241; total 2116933 finalizing 240; total 4875429 Hardly any finalizers are called, even though there is evidently some garbage collection going on. 6g macos f618e5e0991d+ tip package main import ( "runtime" "fmt" ) type Foo bool func main() { for { newFoo() } } var count int func newFoo() *Foo { f := new(Foo) this := count runtime.SetFinalizer(f, func(_ *Foo) { fmt.Printf("finalizing %d; total %d\n", this, count) }) count++ return f }The text was updated successfully, but these errors were encountered: