os.Read() appears to block other goroutines from executing #529

flimzy · 2016-09-29T15:50:39Z

In some situation I have yet to specifically identify, GopherJS hangs. I'm creating this issue to track my debugging progress.

I found, while working on #528, that the first example for the upstream 'html/template' package causes a freeze. I have narrowed this down to a stand-alone reproduction case below. But I still need to work on narrowing it down further.

When I execute the following code in Go:

$ go run jstest.go -test.v
=== RUN   Example
--- PASS: Example (0.00s)
PASS

Or in GopherJS:

$ gopherjs run jstest.go -- -test.v
=== RUN   Example

(and never exits)

package main

import (
    "html/template"
    "log"
    "os"

    "regexp"
    "testing"
)

var tests = []testing.InternalTest{}
var benchmarks = []testing.InternalBenchmark{}

var examples = []testing.InternalExample{
    {"Example", Example, "<!DOCTYPE html>\n<html>\n\t<head>\n\t\t<meta charset=\"UTF-8\">\n\t\t<title>My page</title>\n\t</head>\n\t<body>\n\t\t<div>My photos</div><div>My blog</div>\n\t</body>\n</html>\n<!DOCTYPE html>\n<html>\n\t<head>\n\t\t<meta charset=\"UTF-8\">\n\t\t<title>My another page</title>\n\t</head>\n\t<body>\n\t\t<div><strong>no rows</strong></div>\n\t</body>\n</html>\n", false},
}

var matchPat string
var matchRe *regexp.Regexp

func matchString(pat, str string) (result bool, err error) {
    if matchRe == nil || matchPat != pat {
        matchPat = pat
        matchRe, err = regexp.Compile(matchPat)
        if err != nil {
            return
        }
    }
    return matchRe.MatchString(str), nil
}

func main() {
    m := testing.MainStart(matchString, tests, benchmarks, examples)

    os.Exit(m.Run())
}

func Example() {
    const tpl = `
<!DOCTYPE html>
<html>
    <head>
        <meta charset="UTF-8">
        <title>{{.Title}}</title>
    </head>
    <body>
        {{range .Items}}<div>{{ . }}</div>{{else}}<div><strong>no rows</strong></div>{{end}}
    </body>
</html>`

    check := func(err error) {
        if err != nil {
            log.Fatal(err)
        }
    }
    t, err := template.New("webpage").Parse(tpl)
    check(err)

    data := struct {
        Title string
        Items []string
    }{
        Title: "My page",
        Items: []string{
            "My photos",
            "My blog",
        },
    }

    err = t.Execute(os.Stdout, data)
    check(err)

    noItems := struct {
        Title string
        Items []string
    }{
        Title: "My another page",
        Items: []string{},
    }

    err = t.Execute(os.Stdout, noItems)
    check(err)

    // Output:
    // <!DOCTYPE html>
    // <html>
    //  <head>
    //      <meta charset="UTF-8">
    //      <title>My page</title>
    //  </head>
    //  <body>
    //      <div>My photos</div><div>My blog</div>
    //  </body>
    // </html>
    // <!DOCTYPE html>
    // <html>
    //  <head>
    //      <meta charset="UTF-8">
    //      <title>My another page</title>
    //  </head>
    //  <body>
    //      <div><strong>no rows</strong></div>
    //  </body>
    // </html>
}

The text was updated successfully, but these errors were encountered:

flimzy · 2016-09-29T20:29:22Z

I have narrowed it down to an apparent deadlock between html/template.Parse() and io.Copy(). Tomorrow I'll dive further into html/template to see where specifically it's blocking there.

Go output:

$ go run hang.go
10
A
20

GopherJS output:

$ gopherjs run hang.go
10
A
(hang)

Reproduction case:

package main

import (
    "bytes"
    "fmt"
    "html/template"
    "io"
    "log"
    "os"
)

var l = log.New(os.Stderr, "", 0)

func main() {
    runExample(Example)
}

func Example() {
    w := template.New("webpage")
    l.Println("10")
    _, err := w.Parse("")
    l.Println("20")
    if err != nil {
        log.Fatal(err)
    }
}

func runExample(eg func()) bool {
    r, w, err := os.Pipe()
    if err != nil {
        fmt.Fprintln(os.Stderr, err)
        os.Exit(1)
    }
    go func() {
        var buf bytes.Buffer
        l.Println("A")
        _, err := io.Copy(&buf, r)
        l.Println("B")
        r.Close()
        if err != nil {
            fmt.Fprintf(os.Stderr, "testing: copying pipe: %v\n", err)
            os.Exit(1)
        }
    }()

    eg()
    w.Close()
    return true
}

flimzy · 2016-09-30T10:58:22Z

I have narrowed it down to this reproduction case:

package main

import (
    "fmt"
    "os"
    "sync"
)

func main() {
    go func() {
        r, _, _ := os.Pipe()
        //      r, _ := os.Open("/dev/null")
        //      r, _ := os.Open("/dev/urandom")
        buf := make([]byte, 50)
        fmt.Println("A")
        r.Read(buf)
        fmt.Println("B")
    }()

    var wg sync.WaitGroup
    wg.Add(1)
    go func() {
        fmt.Printf("in goroutine\n") // This line never prints in GopherJS
        wg.Done()
    }()
    fmt.Println("14")
    wg.Wait() // And this waits forever in GopherJS
    fmt.Println("15")
}

flimzy · 2016-09-30T11:00:00Z

It seems that os.Read() blocks other goroutines from executing. If I uncomment one of the os.Open lines, in place of the os.Pipe line, the code appears to behave as expected, seemingly because os.Read then doesn't block. But in the case of os.Pipe, the goroutine blocks, and so do other goroutines.

neelance · 2016-09-30T11:35:20Z

Yes, this is by the nature of the current implementation of syscalls. They are synchronous/blocking, which is enough for most tests to work fine.

flimzy · 2016-09-30T12:26:46Z

Is this by design, then, and should be closed?

Or is it a long-term to-do item (possibly being tracked elsewhere)?

neelance · 2016-09-30T12:36:33Z

It is by design in so far that the syscalls support is not intended for production, but just for being able to run tests. I personally will probably never work on this. However, someone else might.

We should mention this restriction on https://github.com/gopherjs/gopherjs/blob/master/doc/syscalls.md.

This change works around the issues discussed in #529 by using a temporary file for capturing the stdout of a runnable example, rather than os.Pipe. This allows examples to work in cases where they would previously stall. ioutil.ReadFile and its supporting functions are copied from ioutil into testing, in order to avoid having "testing" package import extra packages that the real "testing" package does not. gopherjs tool testFuncs.load does not take into account the overridden natives, see https://github.com/gopherjs/gopherjs/blob/b9bcb1da229a59cc1e1d168401662cb6450aae08/tool.go#L827. So we still need to print the expected output for the example to pass. Given there are only 2 disabled examples, it's easier to just do this in short term. But it might be good to eventually improve code for overriding natives so that examples are properly overridden as well. Regenerate compiler/natives.

flimzy mentioned this issue Sep 29, 2016

Add support for executing examples #528

Merged

flimzy changed the title ~~Undiagnosed hang of go routine in GopherJS~~ os.Read() appears to block other goroutines from executing Sep 30, 2016

flimzy mentioned this issue Sep 30, 2016

Document that system calls block other goroutines. #530

Merged

flimzy closed this as completed Sep 30, 2016

flimzy mentioned this issue Jan 2, 2017

Add support for GopherJS build target jtolio/gls#3

Merged

flimzy mentioned this issue Feb 17, 2017

Make runnable Examples work #590

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

os.Read() appears to block other goroutines from executing #529

os.Read() appears to block other goroutines from executing #529

flimzy commented Sep 29, 2016 •

edited

Loading

flimzy commented Sep 29, 2016 •

edited

Loading

Uh oh!

flimzy commented Sep 30, 2016 •

edited

Loading

Uh oh!

flimzy commented Sep 30, 2016

Uh oh!

neelance commented Sep 30, 2016

Uh oh!

flimzy commented Sep 30, 2016

Uh oh!

neelance commented Sep 30, 2016

Uh oh!

os.Read() appears to block other goroutines from executing #529

os.Read() appears to block other goroutines from executing #529

Comments

flimzy commented Sep 29, 2016 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

flimzy commented Sep 29, 2016 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

flimzy commented Sep 30, 2016 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

flimzy commented Sep 30, 2016

Uh oh!

neelance commented Sep 30, 2016

Uh oh!

flimzy commented Sep 30, 2016

Uh oh!

neelance commented Sep 30, 2016

Uh oh!

flimzy commented Sep 29, 2016 •

edited

Loading

flimzy commented Sep 29, 2016 •

edited

Loading

flimzy commented Sep 30, 2016 •

edited

Loading