invalid memory address or nil pointer dereference

[high3eam]

Recently upgraded Caddy webserver to version:

v2.7.0-beta.2.0.20230725185021-d7d16360d411 h1:Hq2Ph3i47imGFwMmyEb8g8ExG2G9ISJlQJ6R73ddb6E=

using xcaddy v0.3.4 on Debian 12.1 amd64 with this command:

./xcaddy build master --with github.com/caddy-dns/cloudflare@master

I use this config file:

hnrk.io, www.hnrk.io {
        root * /home/hnrk/caddy/html
        file_server
        tls henrik@hnrk.io
}

and this service file to run Caddy webserver:

[Unit]
Description=Caddy Webserver
Documentation=https://caddyserver.com/docs/
After=network.target

[Service]
User=zyma
Group=zyma
ExecStart=/usr/bin/v2caddy run --config /home/hnrk/caddy/Caddyfile
ExecReload=/usr/bin/v2caddy reload --config /home/hnrk/caddy/Caddyfile
TimeoutStopSec=5s
LimitNOFILE=1048576
LimitNPROC=4096
PrivateTmp=true
ProtectSystem=full
AmbientCapabilities=CAP_NET_BIND_SERVICE

[Install]
WantedBy=multi-user.target

After a few hours after starting the systemd service, Caddy crashes. These are the logs:

Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: panic: runtime error: invalid memory address or nil pointer dereference
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x30 pc=0x8d5d60]
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: goroutine 108749 [running]:
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: github.com/caddyserver/certmagic.(*Config).getCertDuringHandshake(0xc00137a5b0, {0x1e2ab90, 0x2ae9520}, _, _)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         github.com/caddyserver/certmagic@v0.19.1/handshake.go:378 +0x1340
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: github.com/caddyserver/certmagic.(*Config).GetCertificateWithContext(0xc00137a5b0, {0x1e2ab90, 0x2ae9520}, 0xc00137a4e0)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         github.com/caddyserver/certmagic@v0.19.1/handshake.go:84 +0xbc5
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: github.com/caddyserver/certmagic.(*Config).GetCertificate(...)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         github.com/caddyserver/certmagic@v0.19.1/handshake.go:50
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: github.com/caddyserver/caddy/v2/modules/caddytls.(*ConnectionPolicy).buildStandardTLSConfig.func1(0xc00137a4e0)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         github.com/caddyserver/caddy/v2@v2.7.0-beta.2.0.20230725185021-d7d16360d411/modules/caddytls/connpolicy.go:232 +>
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: crypto/tls.(*Config).getCertificate(0xc0008e8ea0, 0xc00137a4e0)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/common.go:1116 +0x3b
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: crypto/tls.(*serverHandshakeStateTLS13).pickCertificate(0xc0009d9bf8)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/handshake_server_tls13.go:435 +0x314
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: crypto/tls.(*serverHandshakeStateTLS13).handshake(0xc0009d9bf8)
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/handshake_server_tls13.go:59 +0x53
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: crypto/tls.(*Conn).serverHandshake(0xc000774380, {0x1e2aae8, 0xc00146e230})
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/handshake_server.go:53 +0x185
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: crypto/tls.(*Conn).handshakeContext(0xc000774380, {0x1e2aab0, 0xc0006fee40})
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/conn.go:1547 +0x3d3
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: crypto/tls.(*Conn).HandshakeContext(0xc000afafd0?, {0x1e2aab0?, 0xc0006fee40?})
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/conn.go:1487 +0x1d
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: created by crypto/tls.(*QUICConn).Start in goroutine 109988
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/quic.go:177 +0xc9
Jul 28 13:43:03 www.hnrk.io systemd[1]: v2caddy.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jul 28 13:43:03 www.hnrk.io systemd[1]: v2caddy.service: Failed with result 'exit-code'.
Jul 28 13:43:03 www.hnrk.io systemd[1]: v2caddy.service: Consumed 2min 26.066s CPU time.

[mholt]

Thanks for the report! Weird. If I'm reading the right version of the code (I think I am, as that's the latest commit currently), that's this line:

zap.String("remote", hello.Conn.RemoteAddr().String()),

(an argument to a log message function)

Apparently, hello.Conn() or hello.Conn().RemoteAddr() is nil.

This line is run when a TLS ServerName doesn't match one of the configured hostnames.

I just tried doing this with your site (sorry), and:

$ curl -v --connect-to foobar.com:443:hnrk.io:443 "https://foobar.com"
* Connecting to hostname: hnrk.io
* Connecting to port: 443
*   Trying 217.76.53.157:443...
* Connected to hnrk.io (217.76.53.157) port 443 (#0)
* ALPN: offers h2,http/1.1
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/certs/ca-certificates.crt
*  CApath: none
* TLSv1.3 (IN), TLS alert, internal error (592):
* OpenSSL/3.0.9: error:0A000438:SSL routines::tlsv1 alert internal error
* Closing connection 0
curl: (35) OpenSSL/3.0.9: error:0A000438:SSL routines::tlsv1 alert internal error

This is expected as it can't provide a certificate.

The site is still up though. Any idea what kind of request causes the bug?

[high3eam]

@mholt
Thanks for the quick response!
I've enabled access logging to keep track of it. Anything I could do to increase the panic logging level or is it enough output?
I'll get back to you once I encounter this issue again.
(Btw. feel free to test against my site, no worries :D)

[mholt]

Hey, I just noticed at the very bottom of the stack trace:

Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]: created by crypto/tls.(*QUICConn).Start in goroutine 109988
Jul 28 13:43:03 www.hnrk.io v2caddy[2690046]:         crypto/tls/quic.go:177 +0xc9

This is new!

Do you happen to be using a pre-release version of Go? 🤔

[high3eam]

@mholt
Ohh yes, forgot to mention.

$ go version
go version go1.21rc3 linux/amd64

[mholt]

Ah, that's the problem.

Can you open an issue with Go? Fill out their very simple bug report template (go env, etc) and show them this, and explain that the ClientHelloInfo.Conn field is nil (or maybe just the return value of RemoteAddr() is, but either way, something is nil).

If that value is nil, that'd constitute a breaking change, which I'm sure is not intentional.

[high3eam]

Sure, thanks for heading me to the right direction. :)

[mholt]

Sure. Thanks for trying the latest commits!!