Caddy plugin: request crashes when 304 from upstream

[ishuvalov]

Hi, I'm trying to set up the souin cache as a Caddy plugin. All seem to work fine except one case:

If ETag was sent in the last response and if-none-match header (with the ETag value) is present in the current request, and the upstream answers with 304 status, the request crashes according to the Caddy log.
Could you please look into this? Thanks.

{"level":"debug","ts":1649168291.5120664,"logger":"http.stdlib","msg":"http2: panic serving 10.0.36.233:51994: runtime error: invalid memory address or nil pointer dereference\ngoroutine 380 [running]:\nnet/http.(*http2serverConn).runHandler.func1()\n\tnet/http/h2_bundle.go:5842 +0x125\npanic({0x17f86a0, 0x2ab97a0})\n\truntime/panic.go:1038 +0x215\nio.ReadAll({0x0, 0x0})\n\tio/io.go:633 +0xd4\nio/ioutil.ReadAll(...)\n\tio/ioutil/ioutil.go:27\ngithub.com/darkweak/souin/plugins.(*CustomWriter).Send(0xc00c0e2c80)\n\tgithub.com/darkweak/souin@v1.6.3/plugins/base.go:65 +0x1f1\ngithub.com/darkweak/souin/plugins/caddy.(*SouinCaddyPlugin).ServeHTTP.func1({0x17e9740, 0xc00c0df600}, 0x1a88d47)\n\tgithub.com/darkweak/souin/plugins/caddy@v0.0.0-20220322123629-896cb4660a81/httpcache.go:105 +0x10f\ngithub.com/darkweak/souin/plugins.DefaultSouinPluginCallback({0x1d5fb10, 0xc00c0e2c80}, 0xc00c1c1200, {0x1d97930, 0xc0004f47e0}, {0x0, 0x0}, 0xc00c2060f0)\n\tgithub.com/darkweak/souin@v1.6.3/plugins/base.go:174 +0x6df\ngithub.com/darkweak/souin/plugins/caddy.(*SouinCaddyPlugin).ServeHTTP(0xc00010e700, {0x7fe12dfaf258, 0xc00c1c56e0}, 0xc00c1c0c00, {0x1d4c600, 0xc00c0e2bc0})\n\tgithub.com/darkweak/souin/plugins/caddy@v0.0.0-20220322123629-896cb4660a81/httpcache.go:93 +0x7ce\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc00030b420, {0x7fe12dfaf258, 0xc00c1c5560}, 0xc00c1c0c00, {0x1d4c600, 0xc00c0e2bc0})\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/metrics.go:133 +0x51f\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1({0x7fe12dfaf258, 0xc00c1c5560}, 0xb)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/routes.go:272 +0x3b\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000293cb0, {0x7fe12dfaf258, 0xc00c1c5560}, 0x0)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/caddyhttp.go:58 +0x2f\ngithub.com/RussellLuo/caddy-ext/ratelimit.(*RateLimit).ServeHTTP(0xc000212be0, {0x7fe12dfaf258, 0xc00c1c5560}, 0x6, {0x1d4c600, 0xc00c0e2be0})\n\tgithub.com/RussellLuo/caddy-ext/ratelimit@v0.0.0-20220125104103-1c9850e9c2ae/ratelimit.go:156 +0x30a\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc00030b400, {0x7fe12dfaf258, 0xc00c1c52c0}, 0xc00c1c0c00, {0x1d4c600, 0xc00c0e2be0})\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/metrics.go:133 +0x51f\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1({0x7fe12dfaf258, 0xc00c1c52c0}, 0x1d4c600)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/routes.go:272 +0x3b\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x1d4c600, {0x7fe12dfaf258, 0xc00c1c52c0}, 0x1dad7e0)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/caddyhttp.go:58 +0x2f\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1({0x7fe12dfaf258, 0xc00c1c52c0}, 0xc00c1c0c00)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/routes.go:244 +0x322\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x8, {0x7fe12dfaf258, 0xc00c1c52c0}, 0x18)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/caddyhttp.go:58 +0x2f\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).enforcementHandler(0xc00c0df500, {0x7fe12dfaf258, 0xc00c1c52c0}, 0x0, {0x1d4c600, 0xc00030b4e0})\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/server.go:298 +0x252\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).wrapPrimaryRoute.func1({0x7fe12dfaf258, 0xc00c1c52c0}, 0x49b277)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/server.go:274 +0x3b\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000294bb0, {0x7fe12dfaf258, 0xc00c1c52c0}, 0xc00c1c0c00)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/caddyhttp.go:58 +0x2f\ngithub.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).ServeHTTP(0xc0002af7a0, {0x1d613d0, 0xc00000f050}, 0xc00c1c0c00)\n\tgithub.com/caddyserver/caddy/v2@v2.4.6/modules/caddyhttp/server.go:210 +0x846\nnet/http.serverHandler.ServeHTTP({0x441671}, {0x1d613d0, 0xc00000f050}, 0xc00c1c0900)\n\tnet/http/server.go:2879 +0x43b\nnet/http.initALPNRequest.ServeHTTP({{0x1d72e18, 0xc00c0d9140}, 0xc00c1a8e00, {0xc0004ea1c0}}, {0x1d613d0, 0xc00000f050}, 0xc00c1c0900)\n\tnet/http/server.go:3480 +0x245\nnet/http.(*http2serverConn).runHandler(0x1d4b8e0, 0xc00005b7d0, 0x6be046, 0xc00bd54cf0)\n\tnet/http/h2_bundle.go:5849 +0x78\ncreated by net/http.(*http2serverConn).processHeaders\n\tnet/http/h2_bundle.go:5579 +0x510"}

[ishuvalov]

UPD: Actually the requests crash every time the upstream answers with 304. With or without the ETag headers. Other statuses from the upstream works fine. I hope this helps.

[darkweak]

Hi @ishuvalov thank you for your report, I'll investigate on it.

[darkweak]

Can you post a reproducible minimal example ?

[darkweak]

Update I can reproduce with this snippet

func main() {
	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		w.Header().Set("ETag", `"MyCustomETagValueForThis"`)
		if r.Header.Get("If-None-Match") == `"MyCustomETagValueForThis"` {
			w.WriteHeader(http.StatusNotModified)
			return
		}
		w.Header().Set("ETag", `"MyCustomETagValueForThis"`)
		w.WriteHeader(http.StatusOK)
		w.Write([]byte("My content body."))
	})
	http.ListenAndServe(":9000", nil)
}

(to keep a trace about that).

[ishuvalov]

Thank you for the quick reply and for the fix!
By the way, I reproduce the issue with the pretty similar NodeJS snippet.

[darkweak]

The v1.6.4 should work as expected.