Fixes crash if logging error is not HandlerError

[kkroo]

Fixes a crash at caddy/modules/caddyhttp/server.go:394

[mholt]

Do you have more information? What is the crash? (Full or nearly the full output please)

[kkroo]

I ran into this when using the reverse proxy programmatically with a cancel context ie. http.NewRequestWithContext
The jump to nil causes a SIGBUS and corrupts the stack trace, so I don't have the full picture myself.

On a related note, is there a reason to not copy the original request context in reverseproxy.go cloneRequest it can help to reproduce this bug easier if you change the return to return req.WithContext(origReq.Context()) wanted to see if that's intentional or not and can open a PR for it

Probably not many ways to get here otherwise, but was pretty difficult to track this thought i'd spare the next person's night of sleep

[mholt]

Thanks; but what's the crash exactly? I just want to make sure I understand what is broken and what this fixes. I know you say the stack trace gets corrupted, but I'm not sure how that happens with a Go program. What's the output you see?

On a related note, is there a reason to not copy the original request context in reverseproxy.go cloneRequest it can help to reproduce this bug easier if you change the return to return req.WithContext(origReq.Context()) wanted to see if that's intentional or not and can open a PR for it

I think because the request could potentially be used in a goroutine and the request context is not thread-safe.

[kkroo]

i got it to panic cleanly this time with curl:

001b8a80}, 0xc000024000)\n\t/golang.org/x/net/http2/h2c/h2c.go:125 +0xd7f\nnet/http.serverHandler.ServeHTTP({0xc000b7ab40}, {0x3d75a80, 0xc0001b8a80}, 0xc000024000)\n\t/go/pkg/mod/golang.org/toolchain@v0[0/1227]
.23.2.darwin-amd64/src/net/http/server.go:3210 +0x257\nnet/http.(conn).serve(0xc000c2a240, {0x3d7aef8, 0xc000bca0f0})\n\t/go/pkg/mod/golang.org/[email protected]/src/net/http/server.go:2092 +0x1ab5\ncreated by net/http.(Server).Serve in goroutine 413\n\
t/go/pkg/mod/golang.org/[email protected]/src/net/http/server.go:3360 +0xa9a"}
{"level":"debug","ts":1736582563.0847015,"logger":"http.stdlib","msg":"http: panic serving 127.0.0.1:36436: runtime error: invalid memory address or nil pointer dereference\ngoroutine 389 [running]:\nnet/http.(conn).serve.func1()\n\t/go/pkg/mod/golang.org/[email protected]
go1.23.2.darwin-amd64/src/net/http/server.go:1947 +0x13f\npanic({0x2dd30a0?, 0x4de7430?})\n\t/go/pkg/mod/golang.org/[email protected]/src/runtime/panic.go:785 +0x136\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.(Server).ServeHTTP(0xc000cd6708, {0x7
f3a8cd050b8, 0xc00042c240}, 0xc00002e640)\n\t/github.com/caddyserver/caddy/v2/modules/caddyhttp/server.go:445 +0x1cd1\ngolang.org/x/net/http2/h2c.h2cHandler.ServeHTTP({{0x3d5fae0, 0xc000cd6708}, 0xc00029ee70}, {0x3d75a80, 0xc0
0084c620}, 0xc000859a40)\n\t/golang.org/x/net/http2/h2c/h2c.go:125 +0xd7f\nnet/http.serverHandler.ServeHTTP({0xc000b7ab40}, {0x3d75a80, 0xc00084c620}, 0xc000859a40)\n\t/go/pkg/mod/golang.org/[email protected]
.23.2.darwin-amd64/src/net/http/server.go:3210 +0x257\nnet/http.(conn).serve(0xc0009f6000, {0x3d7aef8, 0xc000ab4000})\n\t/go/pkg/mod/golang.org/[email protected]/src/net/http/server.go:2092 +0x1ab5\ncreated by net/http.(Server).Serve in goroutine 413\n\
t/go/pkg/mod/golang.org/[email protected]/src/net/http/server.go:3360 +0xa9a"}
    ```
    
    vs what i was getting before in tests:
    
    ```
    fatal error: fault
[signal SIGBUS: bus error code=0x2 addr=0xc000e80970 pc=0xc000e80970]
goroutine 733 gp=0xc0018bf500 m=20 mp=0xc000181808 [running]:
runtime.throw({0x1066f4aa5?, 0xc000e80980?})
    /go/pkg/mod/golang.org/[email protected]/src/runtime/panic.go:1067 +0x48 fp=0xc0019e3b88 sp=0xc0019e3b58 pc=0x103e6e1a8
runtime.sigpanic()
    /go/pkg/mod/golang.org/[email protected]/src/runtime/signal_unix.go:914 +0x125 fp=0xc0019e3bb8 sp=0xc0019e3b88 pc=0x103e70625
runtime: g 733: unexpected return pc for runtime.sigpanic called from 0xc000e80970
stack: frame={sp:0xc0019e3b88, fp:0xc0019e3bb8} stack=[0xc0019e2000,0xc0019ea000)
0x000000c0019e3a88:  0x0000000103e734da <runtime.write+0x000000000000005a>  0x0000000000000002 
0x000000c0019e3a98:  0x00000001072e4840  0x000000c000000001 
0x000000c0019e3aa8:  0x0000000000000001  0x000000c0019e3ad8 
0x000000c0019e3ab8:  0x0000000103e45ae5 <runtime.writeErrData+0x0000000000000025>  0x000000c0019e3af8 
0x000000c0019e3ac8:  0x0000000103e348ee <runtime.recordForPanic+0x000000000000004e>  0x000000000000000c 
0x000000c0019e3ad8:  0x000000c0019e3af8  0x0000000103e64eb7 <runtime.writeErr+0x0000000000000017> 
0x000000c0019e3ae8:  0x00000001072e4840  0x0000000000000001 
0x000000c0019e3af8:  0x000000c0019e3b30  0x0000000103e753d2 <runtime.systemstack+0x0000000000000032> 
0x000000c0019e3b08:  0x000000c0019e3b48  0x0000000103e32938 <runtime.fatalthrow+0x0000000000000058> 
0x000000c0019e3b18:  0x000000c0019e3b28  0x000000c0018bf500 
0x000000c0019e3b28:  0x0000000103e32960 <runtime.fatalthrow.func1+0x0000000000000000>  0x000000c0018bf500 
0x000000c0019e3b38:  0x0000000103e6e1a8 <runtime.throw+0x0000000000000048>  0x000000c0019e3b58 
0x000000c0019e3b48:  0x000000c0019e3b78  0x0000000103e6e1a8 <runtime.throw+0x0000000000000048> 
0x000000c0019e3b58:  0x000000c0019e3b60  0x0000000103e324c0 <runtime.throw.func1+0x0000000000000000> 
0x000000c0019e3b68:  0x00000001066f4aa5  0x0000000000000005 
0x000000c0019e3b78:  0x000000c0019e3ba8  0x0000000103e70625 <runtime.sigpanic+0x0000000000000125> 
0x000000c0019e3b88: <0x00000001066f4aa5  0x000000c000e80980 
0x000000c0019e3b98:  0x000000c000e80970  0x000000c0018bf500 
0x000000c0019e3ba8:  0x000000c0019e3ce0  0x000000c000e80970 
0x000000c0019e3bb8: >0x000000c0019e3ca0  0x000000c00007e678 
0x000000c0019e3bc8:  0x000000c0019e3ca8  0x000000c000e80978 
0x000000c0019e3bd8:  0x0000000107680000  0x000000c0019e3bb0 
0x000000c0019e3be8:  0x000000010599ccb2  0x00000001078ae570 
0x000000c0019e3bf8:  0x000000c0019e3fe8  0x0000000000000000 
0x000000c0019e3c08:  0x0000000000000000  0x0000000000000000 
0x000000c0019e3c18:  0x0000000000000000  0x0000000103dffda5 <runtime.convT+0x0000000000000045> 
0x000000c0019e3c28:  0x000000010768a720  0x000000c000e80970 
0x000000c0019e3c38:  0x000000c0019e3ca0  0x000000c000e80970 
0x000000c0019e3c48:  0x000000c0019e3ce0  0x0000000103edb83b <io.NopCloser+0x00000000000000db> 
0x000000c0019e3c58:  0x000000010768a720  0x000000c0019e3ca0 
0x000000c0019e3c68:  0x0000000000000000  0x010101c0018bf500 
0x000000c0019e3c78:  0x00000001078c9e40  0x000000c000e80970 
0x000000c0019e3c88:  0x000000c000e80970  0x0000000103e028e5 <runtime.newobject+0x0000000000000025> 
0x000000c0019e3c98:  0x0000000000000028  0x00068d3da90649cf 
0x000000c0019e3ca8:  0x00074ad23b8f4010  0x0002c2d94c0b6e78 
created by golang.org/x/net/http2.(*serverConn).scheduleHandler in goroutine 526
    /go/pkg/mod/github.com/x/[email protected]/http2/server.go:2409 +0x1e5

[kkroo]

why is the request's context not thread safe?

from go docs, it should be used instead of Cancel channels with RoundTripper across routines

type Request struct {
...
	// Cancel is an optional channel whose closure indicates that the client
	// request should be regarded as canceled. Not all implementations of
	// RoundTripper may support Cancel.
	//
	// For server requests, this field is not applicable.
	//
	// Deprecated: Set the Request's context with NewRequestWithContext
	// instead. If a Request's Cancel field and context are both
	// set, it is undefined whether Cancel is respected.
	Cancel <-chan struct{}

[mholt]

why is the request's context not thread safe?

I think it's more that the specific use of context by various Caddy modules may not be thread safe -- I seem to recall vaguely some issue there years ago, that we since overcame, but it can be something to consider.

Thanks!