net/http/fcgi: resets connection with GOMAXPROCS > 1

[gopherbot]

by ledangster:

When runtime.GOMAXPROCS(>1), Go's FCGI results in a "Connection reset"
during the web server. It runs fine with not forcing multi-processor.

Go:    go version go1.0.2
Linux: Linux machine 3.2.0-2-amd64 #1 SMP Sun Mar 4 22:48:17 UTC 2012 x86_64 GNU/Linux

nginx: 1.3.3

Shell-script:

 while [ 1 ]; do
  curl -v -d '{"Id":123456}' http://10.10.10.100/fcgi/test;
  echo; echo;
 done

nginx error log:
2012/10/02 18:34:49 [error] 30107#0: *110295 readv() failed (104: Connection reset by
peer) while reading upstream, client: 10.10.10.100, server: localhost, request:
"POST /fcgi/test HTTP/1.1", upstream: "fastcgi://127.0.0.1:19111",
host: "10.10.10.100"

Attachments:

1. fcgisrvtest.go (1752 bytes)

[gopherbot]

Comment 1 by ledangster:

What steps will reproduce the problem?
If possible, include a link to a program on play.golang.org.
1. Compile attached fcgisrvtest.go which has runtime.GOMAXPROCS(2). It listens to port
localhost:19111
2. Setup nginx/web server to forward fcgi to :19111
2. Run the fcgisrvtest service.
2. Run a continuous request to call the fcgi service:
    while [ 1 ]; do
       curl -v -d '{"Id":123456}' http://10.10.10.100/fcgi/test;
       echo; echo;
    done
What is the expected output?
No errors in nginx (or the webserver) due to Connection reset by the Go fcgi service.
What do you see instead?
nginx log shows: 
2012/10/02 18:34:49 [error] 30107#0: *110295 readv() failed (104: Connection reset by
peer) while reading upstream, client: 10.10.10.100, server: localhost, request: "POST
/fcgi/test HTTP/1.1", upstream: "fastcgi://127.0.0.1:19111", host: "10.10.10.100"
Which compiler are you using (5g, 6g, 8g, gccgo)?
go build fcgisrvtest.go
Which operating system are you using?
Linux machine 3.2.0-2-amd64 #1 SMP Sun Mar 4 22:48:17 UTC 2012 x86_64 GNU/Linux
Which version are you using?  (run 'go version')
go version go1.0.3
Please provide any additional information below.
The error is due to possible synchronisation issues in multiprocessor, when forcing
runtime.GOMAXPROCS(2) or more. It works fine in single processor mode.

[rsc]

Comment 2:

Labels changed: added priority-later, go1.1, removed priority-triage.

Status changed to Accepted.

[rsc]

Comment 3:

Labels changed: added size-l.

[rsc]

Comment 4:

Labels changed: added suggested.

[rsc]

Comment 5:

Labels changed: added go1.1maybe, removed go1.1.

[bradfitz]

Comment 6:

I can't reproduce.
Here's what I tried
nginx 1.1.19-1ubuntu0.1
daemon off;                                                                             
 
error_log stderr debug;
server {
  ...
  location ~ /app.* {
        root           html;
        fastcgi_pass   127.0.0.1:9000;
        include        fastcgi_params;
  }
}
Go program was:
$ cat fcgi.go
package main
import (
        "log"
        "net"
        "net/http"
        "net/http/fcgi"
        "io"
        "io/ioutil"
        "time"
        "os"
)
func main() {
        log.Printf("Starting server")
        http.HandleFunc("/", func(w http.ResponseWriter, req *http.Request) {
                io.Copy(ioutil.Discard, req.Body)
                for i := 0; i < 50; i++ {
                        w.Write([]byte("This is an example server.\n"))
                        w.(http.Flusher).Flush()
                }
        })
        l, err := net.Listen("tcp", "127.0.0.1:9000")
        if err != nil {
                log.Fatal(err)
        }
        time.AfterFunc(10 * time.Second, func () {
                os.Exit(0)
        })
        log.Fatal(fcgi.Serve(l, nil))
}
bradfitz@bradfitz:~$ 
Ran it like:
$ GOMAXPROCS=10 go run -race fcgi.go 
(with and without -race, and various lengths of exit times)
Then attacked it with multiple shells looping this:
$ while curl -f -v -d '{"Id":123456}' -o /dev/null http://localhost:9999/app; do echo
pass; done
(The -f to curl makes it return a failure on non-2xx status, such as a 5xx from nginx
when fcgi fails)
No race errors from Go.
No non-2xx errors.
No output from nginx.
And this works:
$ GOMAXPROCS=10 go test -race net/http/fcgi
ok      net/http/fcgi   1.025s
I don't know what else to try.
Waiting for reply, and removing the Go1.1 label.

Labels changed: removed go1.1maybe.

Status changed to WaitingForReply.

[gopherbot]

Comment 7 by ledangster:

Your code didn't expose the problem. Think I've nailed it down to the symptom:
req.Body.Read()
You're using io.Copy(ioutil.Discard, req.Body)
However when I changed that to using Read(), it triggers the problem (tried raising the
buffer size to 2*contentLength also, but made no difference)
   buffer := make([]byte, req.ContentLength)
   req.Body.Read(buffer)

[bradfitz]

Comment 8:

io.Copy calls Read.

[gopherbot]

Comment 9 by ledangster:

Not sure where the difference is but it triggered the problem when I changed your sample
code to not use io but use the req's Read as above.

[bradfitz]

Comment 10:

To save me some time, what is the value of req.ContentLength, and what (n, err) does
Read return for the different []byte Read sizes?

[gopherbot]

Comment 11 by ledangster:

for both make([]byte, req.ContentLength) and 2*req.ContentLength:
  req.ContentLength: 13 , nRead: 13 , err: <nil>
The fcgi-handler doesn't seem to see a problem with the read nor w.Write() calls (which
doesn't show any errors either). However, somehow the connection is killed off deep down
below Write layers. Not sure why having io.Copy vs req.Body.Read had different results
though.
So far, I've resorted to using uwsgi as a snap-in replacement.

[gopherbot]

Comment 12 by ledangster:

Also, reconfiguring nginx to keep connection stops it from happening.
    location ~ /app.* {
          ...
          fastcgi_keep_conn on;
    }
Could this mean that somehow the connection got closed before the the write completed?

[bradfitz]

Comment 13:

I still can't reproduce, even with Read instead of io.Copy.
Please include your version of nginx, Go, your nginx config file, your GOMAXPROCS, and
your complete Go server using net/http/fcgi, etc.

[gopherbot]

Comment 14 by ledangster:

I've attached the binaries:
   * nginx was built from source into --prefix=/opt/nginx
I had thought it was only happening on my laptop (Thinkpad X220 with Intel i5) running
Linux Mint Debian 64-bit because I had some sysctl tunings that might trigger it.
However, I've just tested it inside VMWare Workstation on Win7-AMD Phenom II and it
still had the same problem. Used linuxmint-201204-mate-cinnamon-dvd-64bit.iso and simply
ran it as a Live image, no tuning. VMWare virtual machine setup:
  * 1GB
  * 2 Processors, 2 Cores/processor (total cores: 4)
  * HDD: 20GB
note that curl will get HTTP 200 OK, but when the problem arises, it gets no body back.
nginx log will show intermittent Connection reset by peer errors. Sometimes longer
slightly longer than 10s, but usually with 20s.
I ran the fcgi handler with: GOMAXPROCS=2 ./fcgi3

Attachments:

1. go-fcgi-nginx.tgz (5288306 bytes)

[gopherbot]

Comment 15 by ledangster:

Problem also on linuxmint-14.1-mate-dvd-64bit.iso in same VMware VM.