My stupid mistake about goroutine/defer

mattn

Yasuhiro Matsumoto

Posted on January 24, 2018

My stupid mistake about goroutine/defer

Today, I found small program that can be show colors like green or red from output of go test (ex: PASS/FAIL).

https://github.com/rakyll/gotest

gotest

This is good to see easily pass or fail of the test. After playing with this for a while, I met a strange behavior of gotest. The part of output often was not displayed. But I could figure out cause in soon.

func main() {
    setPalette()
    enableOnCI()
    gotest(os.Args[1:])
}

func gotest(args []string) {
    r, w := io.Pipe()
    defer w.Close()

    args = append([]string{"test"}, args...)
    cmd := exec.Command("go", args...)
    cmd.Stderr = w
    cmd.Stdout = w
    cmd.Env = os.Environ()

    go consume(r)

    if err := cmd.Run(); err != nil {
        if ws, ok := cmd.ProcessState.Sys().(syscall.WaitStatus); ok {
            os.Exit(ws.ExitStatus())
        }
        os.Exit(1)
    }
}

func consume(r io.Reader) {
    reader := bufio.NewReader(r)
    for {
        l, _, err := reader.ReadLine()
        if err == io.EOF {
            return
        }
        if err != nil {
            log.Fatal(err)
        }
        parse(string(l))
    }
}
Enter fullscreen mode Exit fullscreen mode

When external command is exited, and finish to call cmd.Run(), goroutine consume must be finished to read until calling os.Exit(). So I patched like below.

func main() {
    setPalette()
    enableOnCI()
    os.Exit(gotest(os.Args[1:]))
}

func gotest(args []string) int {
    r, w := io.Pipe()
    defer w.Close()

    args = append([]string{"test"}, args...)
    cmd := exec.Command("go", args...)
    cmd.Stderr = w
    cmd.Stdout = w
    cmd.Env = os.Environ()

    var wg sync.WaitGroup
    wg.Add(1)
    defer wg.Wait()

    go consume(&wg, r)

    if err := cmd.Run(); err != nil {
        if ws, ok := cmd.ProcessState.Sys().(syscall.WaitStatus); ok {
            return ws.ExitStatus()
        }
        return 1
    }
    return 0
}

func consume(wg *sync.WaitGroup, r io.Reader) {
    defer wg.Done()
    reader := bufio.NewReader(r)
    for {
        l, _, err := reader.ReadLine()
        if err == io.EOF {
            return
        }
        if err != nil {
            log.Print(err)
            return
        }
        parse(string(l))
    }
}
Enter fullscreen mode Exit fullscreen mode

Added sync.WaitGroup to wait groutine consume, and return with exit code. I expected this should work as intended. But this goes panic.

fatal error: all goroutines are asleep - deadlock!

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc0420083fc)
        c:/go/src/runtime/sema.go:56 +0x40
sync.(*WaitGroup).Wait(0xc0420083f0)
        c:/go/src/sync/waitgroup.go:129 +0x79
main.gotest(0xc04203e260, 0x0, 0x0, 0x1)
        c:/dev/go/src/github.com/rakyll/gotest/main.go:54 +0x3bf
main.main()
        c:/dev/go/src/github.com/rakyll/gotest/main.go:33 +0x74
Enter fullscreen mode Exit fullscreen mode

At the first, I thought this is a bug of Go. So I was going to file this issue on GitHub. But this was simply my fault. wg.Wait() is called at exiting function gotest. And w which is opened by io.Pipe() is closed at the next. But reader.ReadLine() is blocking until w.Close() is called. So this is cleanly deadlock (as the message says above). Correct fixes must be below.

func main() {
    setPalette()
    enableOnCI()
    os.Exit(gotest(os.Args[1:]))
}

func gotest(args []string) int {
    var wg sync.WaitGroup
    wg.Add(1)
    defer wg.Wait()

    r, w := io.Pipe()
    defer w.Close()

    args = append([]string{"test"}, args...)
    cmd := exec.Command("go", args...)
    cmd.Stderr = w
    cmd.Stdout = w
    cmd.Env = os.Environ()

    go consume(&wg, r)

    if err := cmd.Run(); err != nil {
        if ws, ok := cmd.ProcessState.Sys().(syscall.WaitStatus); ok {
            return ws.ExitStatus()
        }
        return 1
    }
    return 0
}

func consume(wg *sync.WaitGroup, r io.Reader) {
    defer wg.Done()
    reader := bufio.NewReader(r)
    for {
        l, _, err := reader.ReadLine()
        if err == io.EOF {
            return
        }
        if err != nil {
            log.Print(err)
            return
        }
        parse(string(l))
    }
}
Enter fullscreen mode Exit fullscreen mode

The teachings of Gopher.

Read the error message well.

💖 💪 🙅 🚩
mattn
Yasuhiro Matsumoto

Posted on January 24, 2018

Join Our Newsletter. No Spam, Only the good stuff.

Sign up to receive the latest update from our blog.

Related