3 second timeout for requests when using listener_wrappers tls sending requests to reverse_proxy

[Monviech]

Downstream report: opnsense/plugins#4384

The issue is, that when something is going through the layer4 listener_wrappers to the tls directive into the reverse proxy, there is a timeout of 3 seconds after which the context gets canceled.

• It does NOT happen with only the "reverse_proxy" proxying the request
• It does NOT happen with only the layer4 modules "proxy" proxying the request

As example, there is an API endpoint in OPNsense that could take anywhere from 10 to 30 seconds to respond, depending on different factors. After exactly 3 seconds this context gets canceled by the client (Caddy) using this Caddyfile:

{
	servers {
		protocols h1 h2 h3
		listener_wrappers {
			layer4 {
			}
			tls
		}
	}
}

:80 {
}
:443 {
}

opn.example.com {
	handle {
		reverse_proxy https://172.16.0.254:4444 {
			transport http {
				tls_insecure_skip_verify
			}
		}
	}
}

Relevant error can be seen in downstream report.
I have tested this and can reproduce it.

[mholt]

Hmm I'm wondering if there's a timer of 3 sec set anywhere in the code. Can look more into it soon!

[Monviech]

The only default I found with exactly 3 seconds was dial_timeout but that was a caddyserver directive in http_transport

(solely looking at the documentation)

[mohammed90]

It's this

caddy-l4/layer4/server.go

Line 33 in 3c6cc2c

const MatchingTimeoutDefault = 3 * time.Second

which is injected here

caddy-l4/layer4/listener.go

Line 57 in 3c6cc2c

lw.compiledRoute = lw.Routes.Compile(lw.logger, time.Duration(lw.MatchingTimeout), listenerHandler{})

and set here:

caddy-l4/layer4/routes.go

Lines 122 to 123 in 3c6cc2c

	// timeout matching to protect against malicious or very slow clients
	err := cx.Conn.SetReadDeadline(deadline)

[mholt]

Good find. Yeah, so it sounds like after 3 seconds, matchers are being cancelled. I wonder if that's because there are no matchers configured?

[mohammed90]

matchers are being cancelled. I wonder if that's because there are no matchers configured?

My understanding is the timeout of the matchers is wrongly passed to the connection read deadline. The timeout deadline isn't updated after matching.

[mohammed90]

I take it back. It's reset here.

caddy-l4/layer4/routes.go

Line 175 in 3c6cc2c

err = cx.Conn.SetReadDeadline(time.Time{})

I don't know why it isn't taking effect.