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

goroutine hangs at runtime.Gosched() #12553

Closed
kingluo opened this issue Sep 9, 2015 · 10 comments
Closed

goroutine hangs at runtime.Gosched() #12553

kingluo opened this issue Sep 9, 2015 · 10 comments

Comments

@kingluo
Copy link

kingluo commented Sep 9, 2015

The go version is 1.5.1.

Here is the program:

package main

import (
    "fmt"
    "runtime"
    "time"
)

func test2() {
    for i := 1; ; i++ {
        fmt.Println(i, time.Now())
    }
}

func test() {
    a := 100
    for i := 1; i < 1000; i++ {
        a = i*100/i + a
    }
}

func main() {
    runtime.GOMAXPROCS(2)
    go test2()
    for {
        test()
    }
}

Note that I configure two threads to run goroutines.
The main goroutine would block one thread, while the test2() goroutine would run in another thread.
However, the result is that, the test2() runs a bit, but after some random interval, it hangs (do not output anything); the main goroutine continue to run test() without problem.

If I add some function call into the test(), e.g.

func test() {
    ...
    syscall.Getgid()
}

Then the test() and test2() would run in parallel as expected.

I try to do panic after some counts (estimated to be after the test2() hangs) within the loop to call test():

    for i := 1; i < 10000000000; i++ {
        if i == 1000000 {
            panic("hello")
        }
        test()
    }

Then it shows the backtrace:

goroutine 1 [running]:
main.main()
    /tmp/tmp.go:30 +0xb1

goroutine 5 [runnable]:
runtime.Gosched()
    /usr/local/go/src/runtime/proc.go:166 +0x14
time.Time.Format(0xecd820010, 0x37614ae4, 0x593740, 0x523840, 0x27, 0x0, 0x0)
    /usr/local/go/src/time/format.go:431 +0x135
time.Time.String(0xecd820010, 0x37614ae4, 0x593740, 0x0, 0x0)
    /usr/local/go/src/time/format.go:401 +0x54
time.(*Time).String(0xc8204977a0, 0x0, 0x0)
    <autogenerated>:1 +0xad
fmt.(*pp).handleMethods(0xc820068000, 0xc800000076, 0x0, 0xc820071c01)
    /usr/local/go/src/fmt/print.go:730 +0x633
fmt.(*pp).printArg(0xc820068000, 0x5024a0, 0xc8204977a0, 0x76, 0x0, 0xc81ffdb400)
    /usr/local/go/src/fmt/print.go:806 +0x4a5
fmt.(*pp).doPrint(0xc820068000, 0xc820071f78, 0x2, 0x2, 0x101)
    /usr/local/go/src/fmt/print.go:1254 +0x258
fmt.Fprintln(0x7f18e5d2f000, 0xc820026010, 0xc820071f78, 0x2, 0x2, 0x40b7f0, 0x0, 0x0)
    /usr/local/go/src/fmt/print.go:254 +0x67
fmt.Println(0xc820071f78, 0x2, 0x2, 0x5024a0, 0x0, 0x0)
    /usr/local/go/src/fmt/print.go:264 +0x73
main.test2()
    /tmp/tmp.go:12 +0x17f
created by main.main
    /tmp/tmp.go:27 +0x3c
exit status 2

So why test2() goroutine hangs?

@davecheney
Copy link
Contributor

My guess is your program is hanging because the garbage collector cannot run, and the garbage collector cannot run because all goroutines have not stopped.

@randall77
Copy link
Contributor

Dup of #10958

@kingluo
Copy link
Author

kingluo commented Sep 9, 2015

@randall77 Is this issue really duplicated with #10958? Here I'm wondering why it hangs, while in #10958, I doubt the precise preempt happens at the newstack() but not every function call.

@randall77
Copy link
Contributor

Yes. As Dave said, GC eventually tries to run, successfully stops the goroutine running test2, and then hangs forever trying to stop the goroutine that is doing for { test() }.

@kingluo
Copy link
Author

kingluo commented Sep 9, 2015

Why removing time.Now() from test2() works? Because then the whole program running would not trigger GC?
In other words, if the program has such infinite blocking loop, and if GC runs, then it would result in hanging?

@randall77
Copy link
Contributor

Removing time.Now() from test2 doesn't work for me. The program still hangs after a while (~250K iterations).

Bottom line, don't write loops like this. Add runtime.Gosched() if you don't have anything else significant in the loop.

@RLH
Copy link
Contributor

RLH commented Sep 9, 2015

If performance is a concern unroll the loop or add an inner loop. Until we
teach our compilers how to do this automatically this work around is the
best advice we can give.

On Wed, Sep 9, 2015 at 11:38 AM, Keith Randall notifications@github.com
wrote:

Removing time.Now() from test2 doesn't work for me. The program still
hangs after a while (~250K iterations).

Bottom line, don't write loops like this. Add runtime.Gosched() if you
don't have anything else significant in the loop.


Reply to this email directly or view it on GitHub
#12553 (comment).

@kingluo
Copy link
Author

kingluo commented Sep 10, 2015

Yes, removing the time.Now() doesn't work.
The go 1.5.1 would hangs the program at ~250K iteration, and the go 1.3.3 would hangs at ~12million.

Then the backtrace would be:

goroutine 1 [running]:
main.main()
    /tmp/tmp.go:29 +0xb1

goroutine 5 [runnable]:
fmt.Println(0xc82003af80, 0x1, 0x1, 0x4c0c00, 0xc820487020, 0x0)
    /usr/local/go/src/fmt/print.go:263
main.test2()
    /tmp/tmp.go:12 +0xc8
created by main.main
    /tmp/tmp.go:26 +0x3c

Thanks for your advises.

I'm still wondering, the preemption check only happens at newstack(), right?

@davecheney
Copy link
Contributor

@kingluo this issue is closed. If you want to discuss it further, please open a thread on the golang-nuts mailing list.

@randall77
Copy link
Contributor

Preemption checks happen at every function entry point, except those functions which don't have a preemption check (those with small stack frames, not recursive, ...).

The preemption check causes the function entry to call into morestack and then newstack where the preemption is processed.

@golang golang locked and limited conversation to collaborators Sep 22, 2016
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

5 participants