net/http: on panic http.server re-runs the handler multiple times on Windows

[groenspans]

What version of Go are you using (go version)?

$ go version
go version go1.19.4 windows/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\Aljosja\AppData\Local\go-build
set GOENV=C:\Users\Aljosja\AppData\Roaming\go\env
set GOEXE=.exe
set GOEXPERIMENT=
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=C:\Users\Aljosja\go\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=C:\Users\Aljosja\go
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Program Files\Go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Program Files\Go\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=go1.19.4
set GCCGO=gccgo
set GOAMD64=v1
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=C:\Users\Aljosja\documents\code\u4tools\go.mod
set GOWORK=
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fno-caret-diagnostics -Qunused-arguments -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=C:\Users\Aljosja\AppData\Local\Temp\go-build1729482487=/tmp/go-build -gno-record-gcc-switches

What did you do?

In a simple HTTP server with a handler that panics (either through calling panic() or by dereferencing a nil pointer) on Windows, the server runs the handler again multiple times for the same request. On Linux, the handler runs only once.

package main

import (
	"fmt"
	"net/http"
)

func main() {
	mux := http.NewServeMux()
	mux.HandleFunc("/panic", func(w http.ResponseWriter, r *http.Request) {
		fmt.Println("hello world!")
		panic("damn")
	})
	mux.HandleFunc("/npe", func(w http.ResponseWriter, r *http.Request) {
		fmt.Println("hello world!")
		var err error
		fmt.Println("Error: %s", err.Error())
	})
	mux.HandleFunc("/success", func(w http.ResponseWriter, r *http.Request) {
		fmt.Println("hello world!")
	})

	http.ListenAndServe(":8080", mux)
}

What did you expect to see?

I expect the console log to show one stack trace indicating a panic, and the HTTP connection to close. (This is the behaviour on Linux.)

What did you see instead?

The HTTP connection remains open, and the console log shows several stack traces.

Example log file. This log file is for a single request.

$  go run cmd/main.go
hello world!
2023/01/04 21:31:18 http: panic serving [::1]:54121: runtime error: invalid memory address or nil pointer dereference
goroutine 6 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc00006faf0?, {0x7c8348?, 0xc0001a8000?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc0001a8000}, 0xc000142000)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc0001011a0?}, {0x7c8348, 0xc0001a8000}, 0xc000142000)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc000000be0, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
hello world!
2023/01/04 21:31:19 http: panic serving [::1]:54122: runtime error: invalid memory address or nil pointer dereference
goroutine 34 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc000097af0?, {0x7c8348?, 0xc000148000?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc000148000}, 0xc0000a8000)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc00008a090?}, {0x7c8348, 0xc000148000}, 0xc0000a8000)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc00008e000, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
hello world!
2023/01/04 21:31:19 http: panic serving [::1]:54124: runtime error: invalid memory address or nil pointer dereference
goroutine 35 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc000099af0?, {0x7c8348?, 0xc0001480e0?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc0001480e0}, 0xc0000a8100)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc00008a180?}, {0x7c8348, 0xc0001480e0}, 0xc0000a8100)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc00008e0a0, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
hello world!
2023/01/04 21:31:19 http: panic serving [::1]:54125: runtime error: invalid memory address or nil pointer dereference
goroutine 9 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc00005baf0?, {0x7c8348?, 0xc0001a80e0?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc0001a80e0}, 0xc0000a8200)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc00008a210?}, {0x7c8348, 0xc0001a80e0}, 0xc0000a8200)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc000000c80, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
hello world!
2023/01/04 21:31:24 http: panic serving [::1]:54134: runtime error: invalid memory address or nil pointer dereference
goroutine 20 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc00005baf0?, {0x7c8348?, 0xc0001a81c0?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc0001a81c0}, 0xc000184300)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc000186210?}, {0x7c8348, 0xc0001a81c0}, 0xc000184300)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc000218000, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
hello world!
2023/01/04 21:31:54 http: panic serving [::1]:54135: runtime error: invalid memory address or nil pointer dereference
goroutine 36 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc000093af0?, {0x7c8348?, 0xc0001a82a0?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc0001a82a0}, 0xc0000a8300)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc00008a2d0?}, {0x7c8348, 0xc0001a82a0}, 0xc0000a8300)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc00008e140, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
hello world!
2023/01/04 21:31:54 http: panic serving [::1]:54183: runtime error: invalid memory address or nil pointer dereference
goroutine 23 [running]:
net/http.(*conn).serve.func1()
        C:/Program Files/Go/src/net/http/server.go:1850 +0xbf
panic({0x718c00, 0x923ae0})
        C:/Program Files/Go/src/runtime/panic.go:890 +0x262
main.main.func2({0x3b?, 0xffffffffffffffff?}, 0x58eada?)
        C:/Users/Aljosja/documents/code/u4tools/cmd/main.go:17 +0x58
net/http.HandlerFunc.ServeHTTP(0xc000057af0?, {0x7c8348?, 0xc0001481c0?}, 0x0?)
        C:/Program Files/Go/src/net/http/server.go:2109 +0x2f
net/http.(*ServeMux).ServeHTTP(0x0?, {0x7c8348, 0xc0001481c0}, 0xc000184600)
        C:/Program Files/Go/src/net/http/server.go:2487 +0x149
net/http.serverHandler.ServeHTTP({0xc0001863f0?}, {0x7c8348, 0xc0001481c0}, 0xc000184600)
        C:/Program Files/Go/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc0002180a0, {0x7c8720, 0xc0001010b0})
        C:/Program Files/Go/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        C:/Program Files/Go/src/net/http/server.go:3102 +0x4db
exit status 0xc000013a

[heschi]

cc @neild

[seankhliao]

how are you making the requests?
The "http: panic serving [::1]:54122" lines each have a different port, pointing at separate requests / connections, which can't be from the same handler being run multiple times.

[groenspans]

Thanks for looking with me and very sharp observation about the different port numbers, I hadn't noticed that yet. The requests from the example log were made through Chrome, Firefox and Edge. I now tried a curl through Windows PowerShell which resulted in 2 retries, a curl from Git Bash gave the expected 1. Interestingly enough the devtools in the browsers don't seem to show they're making new requests, but apparently they are doing that silently (as is PowerShell doing once).

[antichris]

The Chromium family browsers automatically retry requests on certain errors (see bug 143425), and ERR_EMPTY_RESPONSE (which happens when a handler panics) is among those.