Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[solved] Intermittent tls failures when sharing tls data between caddy and caddy-l4 #293

Closed
blob42 opened this issue Jan 28, 2025 · 7 comments

Comments

@blob42
Copy link

blob42 commented Jan 28, 2025

I am using caddy (caddy docker proxy) + caddy-l4 with dnscrypt-server to do dns over https.

The caddy-l4 captures all https traffic and redirects it to dnscrypt-server to do the DoH splitting, which then forwards https traffic to the caddy proxy that handles all sites.

Both caddy-l4 and caddy-proxy run on their own docker container. I mounted the same /data/ dir for both containers, thinking that the certificates can be reused for the tls handshake.

I am building caddy-l4 with xcaddy.

Problem:

Connecting to my websites over https intermittently fails in a random way. It seems that sometimes the certificate is indeed retrieved from the /data/ directory where they are stored and the tls handshake succeeds. Half the time the tls connection fails without much details in the logs.

HTTPS Traffic ---> L4(443) ---> dnscrypt-server (Forward HTTPS) -----> Caddy Proxy

  • Automatic HTTPS works perfectly if I let the proxy handle the https traffic directly.

  • All websites with automatic https are handled on the main caddy proxy and I am only using l4 to catch https traffic and redirect it to dnscrypt-server and doing some custom sni matching to filter traffic.

My L4 Caddyfile

{
    log {
        level DEBUG
    }

    admin 0.0.0.0:2019


    layer4 {
                # git traffic to gitea, rest to dnscrypt server
		# I needed this to filter out crawlers from my git instance
                :443 {
                    @tls_nogit not tls sni git.blob42.xyz

                    route @tls_nogit {
                        proxy dnscrypt-server:443
                    }
                }
    }
}

git.blob42.xyz {
    @bot <<CEL
        header({'Accept-Language': 'zh-CN'})
        || header_regexp('User-Agent', '(?i:(.*bot.*|.*crawler.*|.*meta.*|.*google.*|.*microsoft.*|.*spider.*))')
    CEL

    abort @bot

    reverse_proxy gitea:3000

}

LOGS

curl -L git.blob42.xyz randomly fails or succeeds

Successful connection

l4-tls-1    | {"level":"debug","ts":1738064324.6655343,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"172.18.0.1","remote_port":"60230","subjects":["git.blob42.xyz"],"managed":true,"expiration":1742166222,"hash":"ee10ee910c1e347ba75703bf51fcf1da5d87bf0d8a451477096473178964b91e"}
l4-tls-1    | {"level":"debug","ts":1738064324.7323978,"logger":"http.handlers.reverse_proxy","msg":"selected upstream","dial":"gitea:3000","total_upstreams":1}
l4-tls-1    | {"level":"debug","ts":1738064324.745922,"logger":"layer4","msg":"connection stats","remote":"105.100.116.238:43588","read":3835,"written":13185,"duration":10.057577493}
l4-tls-1    | {"level":"debug","ts":1738064324.7784443,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"gitea:3000","duration":0.045979605,"request":{"remote_ip":"172.18.0.1","remote_port":"60230","client_ip":"172.18.0.1","proto":"HTTP/2.0","method":"GET","host":"git.blob42.xyz","uri":"/","headers":{"X-Forwarded-Proto":["https"],"X-Forwarded-Host":["git.blob42.xyz"],"Accept":["*/*"],"User-Agent":["curl/8.11.1"],"X-Forwarded-For":["172.18.0.1"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"git.blob42.xyz"}},"headers":{"Set-Cookie":["REDACTED"],"X-Frame-Options":["SAMEORIGIN"],"Date":["Tue, 28 Jan 2025 11:38:44 GMT"],"Cache-Control":["max-age=0, private, must-revalidate, no-transform"],"Content-Type":["text/html; charset=utf-8"]},"status":200}
l4-tls-1    | {"level":"debug","ts":1738064324.809119,"logger":"events","msg":"event","name":"tls_get_certificate","id":"a44ede7d-3391-44ef-a33e-8f8869d959f6","origin":"tls","data":{"client_hello":{"CipherSuites":[49195,49199,49196,49200,52393,52392,49161,49171,49162,49172,4865,4866,4867],"ServerName":"somehost.blob42.xyz","SupportedCurves":[25497,29,23,24,25],"SupportedPoints":"AA==","SignatureSchemes":[2052,1027,2055,2053,2054,1025,1281,1537,1283,1539,513,515],"SupportedProtos":null,"SupportedVersions":[772,771],"RemoteAddr":{"IP":"105.100.116.238","Port":53748,"Zone":""},"LocalAddr":{"IP":"172.18.0.18","Port":443,"Zone":""}}}}

Failing connection

l4-tls-1    | {"level":"debug","ts":1738065199.3366153,"logger":"layer4","msg":"matching","remote":"172.18.0.1:49962","error":"consumed all prefetched bytes","matcher":"layer4.matchers.tls","matched":false}
l4-tls-1    | {"level":"debug","ts":1738065199.3366385,"logger":"layer4","msg":"matching","remote":"172.18.0.1:49962","error":"consumed all prefetched bytes","matcher":"layer4.matchers.not","matched":false}
l4-tls-1    | {"level":"debug","ts":1738065199.3413408,"logger":"layer4","msg":"prefetched","remote":"172.18.0.1:49962","bytes":517}
l4-tls-1    | {"level":"debug","ts":1738065199.3413734,"logger":"layer4.matchers.tls","msg":"matched","remote":"172.18.0.1:49962","server_name":"git.blob42.xyz"}
l4-tls-1    | {"level":"debug","ts":1738065199.3414297,"logger":"layer4","msg":"matching","remote":"172.18.0.1:49962","matcher":"layer4.matchers.tls","matched":true}
l4-tls-1    | {"level":"debug","ts":1738065199.341437,"logger":"layer4","msg":"matching","remote":"172.18.0.1:49962","matcher":"layer4.matchers.not","matched":false}
l4-tls-1    | {"level":"debug","ts":1738065199.3414423,"logger":"layer4","msg":"connection stats","remote":"172.18.0.1:49962","read":517,"written":0,"duration":0.004859197}

Let me know how I can help provide more relevant logs or details.

@colrack
Copy link

colrack commented Jan 29, 2025

I'm experiencing similar issues here, even though my reverse proxy is shared with an SSH backend.

Here is my config:

{
        log { level DEBUG }
        layer4 {
        0.0.0.0:443 {
                        @route tls sni ssh.host1.mydomain.com
                        route @route {
                                tls
                                proxy 10.0.2.5:22
                        }
                }
        }
}

https://host1.mydomain.com:443 {
        reverse_proxy http://10.0.2.5
}

https://ssh.host1.mydomain.com:443 {}

Here is the output; some data, such as hostname and IP, have been redacted.

curl output working:

curl -v https://host1.mydomain.com
* Host host1.mydomain.com:443 was resolved.
* IPv6: (none)
* IPv4: 91.X.Y.Z
*   Trying 91.X.Y.Z:443...
* Connected to host1.mydomain.com (91.X.Y.Z) port 443
* ALPN: curl offers h2,http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/cert.pem
*  CApath: none
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-CHACHA20-POLY1305-SHA256 / [blank] / UNDEF
* ALPN: server accepted h2
* Server certificate:
*  subject: CN=host1.mydomain.com
*  start date: Jan 27 21:21:00 2025 GMT
*  expire date: Apr 27 21:20:59 2025 GMT
*  subjectAltName: host "host1.mydomain.com" matched cert's "host1.mydomain.com"
*  issuer: C=US; O=Let's Encrypt; CN=E5
*  SSL certificate verify ok.
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://host1.mydomain.com/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: host1.mydomain.com]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.7.1]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: host1.mydomain.com
> User-Agent: curl/8.7.1
> Accept: */*
>
* Request completely sent off
< HTTP/2 200
< alt-svc: h3=":443"; ma=2592000
< content-type: text/html
< date: Wed, 29 Jan 2025 14:27:31 GMT
< etag: "2a6-30c-64a170e1"
< last-modified: Sun, 02 Jul 2023 12:43:13 GMT
< server: Caddy
< content-length: 780
<
--- cut ----
* Connection #0 to host host1.mydomain.com left intact

caddy logs, working:

Jan 29 14:27:31 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160851.4576678,"logger":"events","msg":"event","name":"tls_get_certificate","id":"e4aec7c1-85f4-4d90-8664-83925f05fca5","origin":"tls","data":{"client_hello":{"CipherSuites":[4867,4866,4865,52393,52392,52394,49200,49196,49192,49188,49172,49162,159,107,57,65413,196,136,129,157,61,53,192,132,49199,49195,49191,49187,49171,49161,158,103,51,190,69,156,60,47,186,65,49169,49159,5,4,49170,49160,22,10,255],"ServerName":"host1.mydomain.com","SupportedCurves":[29,23,24,25],"SupportedPoints":"AA==","SignatureSchemes":[2054,1537,1539,2053,1281,1283,2052,1025,1027,513,515],"SupportedProtos":["h2","http/1.1"],"SupportedVersions":[772,771,770,769],"RemoteAddr":{"IP":"151.X.Y.Z","Port":60717,"Zone":""},"LocalAddr":{"IP":"192.168.2.10","Port":443,"Zone":""}}}}
Jan 29 14:27:31 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160851.4577236,"logger":"tls.handshake","msg":"choosing certificate","identifier":"host1.mydomain.com","num_choices":1}
Jan 29 14:27:31 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160851.4577343,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"host1.mydomain.com","subjects":["host1.mydomain.com"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"dce64d9adda5cef110d8b4fcb992772a31bb1a039cbbcf23bf447000ebf60844"}
Jan 29 14:27:31 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160851.4577432,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"151.X.Y.Z","remote_port":"60717","subjects":["host1.mydomain.com"],"managed":true,"expiration":1745788860,"hash":"dce64d9adda5cef110d8b4fcb992772a31bb1a039cbbcf23bf447000ebf60844"}
Jan 29 14:27:31 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160851.5126693,"logger":"http.handlers.reverse_proxy","msg":"selected upstream","dial":"10.0.2.5:80","total_upstreams":1}
Jan 29 14:27:31 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160851.5607574,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"10.0.2.5:80","duration":0.048053614,"request":{"remote_ip":"151.X.Y.Z","remote_port":"60717","client_ip":"151.X.Y.Z","proto":"HTTP/2.0","method":"GET","host":"host1.mydomain.com","uri":"/","headers":{"X-Forwarded-Host":["host1.mydomain.com"],"User-Agent":["curl/8.7.1"],"Accept":["*/*"],"X-Forwarded-For":["151.X.Y.Z"],"X-Forwarded-Proto":["https"]},"tls":{"resumed":false,"version":772,"cipher_suite":4867,"proto":"h2","server_name":"host1.mydomain.com"}},"headers":{"Content-Length":["780"],"Connection":["Keep-Alive"],"Keep-Alive":["timeout=20"],"Etag":["\"2a6-30c-64a170e1\""],"Last-Modified":["Sun, 02 Jul 2023 12:43:13 GMT"],"Date":["Wed, 29 Jan 2025 14:27:31 GMT"],"Content-Type":["text/html"]},"status":200}

curl output NOT working:

curl -v https://host1.mydomain.com
* Host host1.mydomain.com:443 was resolved.
* IPv6: (none)
* IPv4: 91.X.Y.Z
*   Trying 91.X.Y.Z:443...
* Connected to host1.mydomain.com (91.X.Y.Z) port 443
* ALPN: curl offers h2,http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/cert.pem
*  CApath: none
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-CHACHA20-POLY1305-SHA256 / [blank] / UNDEF
* ALPN: server accepted h2
* Server certificate:
*  subject: CN=host1.mydomain.com
*  start date: Jan 27 21:21:00 2025 GMT
*  expire date: Apr 27 21:20:59 2025 GMT
*  subjectAltName: host "host1.mydomain.com" matched cert's "host1.mydomain.com"
*  issuer: C=US; O=Let's Encrypt; CN=E5
*  SSL certificate verify ok.
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://host1.mydomain.com/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: host1.mydomain.com]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.7.1]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: host1.mydomain.com
> User-Agent: curl/8.7.1
> Accept: */*
>
* Request completely sent off
* Remote peer returned unexpected data while we expected SETTINGS frame.  Perhaps, peer does not support HTTP/2 properly.
* Closing connection
curl: (16) Remote peer returned unexpected data while we expected SETTINGS frame.  Perhaps, peer does not support HTTP/2 properly.

caddy logs for the above, NOT working:

Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1775427,"logger":"layer4","msg":"matching","remote":"151.X.Y.Z:60718","error":"consumed all prefetched bytes","matcher":"layer4.matchers.tls","matched":false}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.182298,"logger":"layer4","msg":"prefetched","remote":"151.X.Y.Z:60718","bytes":334}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1824121,"logger":"layer4","msg":"matching","remote":"151.X.Y.Z:60718","matcher":"layer4.matchers.tls","matched":false}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1824315,"logger":"layer4.matchers.tls","msg":"matched","remote":"151.X.Y.Z:60718","server_name":"host1.mydomain.com"}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1824384,"logger":"layer4","msg":"matching","remote":"151.X.Y.Z:60718","matcher":"layer4.matchers.tls","matched":true}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1827748,"logger":"events","msg":"event","name":"tls_get_certificate","id":"76f85ef0-86e1-480b-895f-a36e7c480f6f","origin":"tls","data":{"client_hello":{"CipherSuites":[4867,4866,4865,52393,52392,52394,49200,49196,49192,49188,49172,49162,159,107,57,65413,196,136,129,157,61,53,192,132,49199,49195,49191,49187,49171,49161,158,103,51,190,69,156,60,47,186,65,49169,49159,5,4,49170,49160,22,10,255],"ServerName":"host1.mydomain.com","SupportedCurves":[29,23,24,25],"SupportedPoints":"AA==","SignatureSchemes":[2054,1537,1539,2053,1281,1283,2052,1025,1027,513,515],"SupportedProtos":["h2","http/1.1"],"SupportedVersions":[772,771,770,769],"RemoteAddr":{"IP":"151.X.Y.Z","Port":60718,"Zone":""},"LocalAddr":{"IP":"192.168.2.10","Port":443,"Zone":""}}}}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1828198,"logger":"tls.handshake","msg":"choosing certificate","identifier":"host1.mydomain.com","num_choices":1}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1828504,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"host1.mydomain.com","subjects":["host1.mydomain.com"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"dce64d9adda5cef110d8b4fcb992772a31bb1a039cbbcf23bf447000ebf60844"}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.1828585,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"151.X.Y.Z","remote_port":"60718","subjects":["host1.mydomain.com"],"managed":true,"expiration":1745788860,"hash":"dce64d9adda5cef110d8b4fcb992772a31bb1a039cbbcf23bf447000ebf60844"}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.232822,"logger":"layer4.handlers.tls","msg":"terminated TLS","remote":"151.X.Y.Z:60718","server_name":"host1.mydomain.com"}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.26547,"logger":"layer4.handlers.proxy","msg":"dial upstream","remote":"151.X.Y.Z:60718","upstream":"10.0.2.5:80"}
Jan 29 14:27:35 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738160855.342702,"logger":"layer4","msg":"connection stats","remote":"151.X.Y.Z:60718","read":633,"written":2571,"duration":0.165174498}

Same issue with my SSH backend.
working:

ssh -v [email protected]
OpenSSH_9.7p1, LibreSSL 3.3.6
debug1: Reading configuration data /Users/user/.ssh/config
debug1: /Users/user/.ssh/config line 11: Applying options for *.mydomain.com
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 21: include /etc/ssh/ssh_config.d/* matched no files
debug1: /etc/ssh/ssh_config line 54: Applying options for *
debug1: Authenticator provider $SSH_SK_PROVIDER did not resolve; disabling
debug1: Executing proxy command: exec openssl s_client -verify_quiet -quiet -servername ssh.host1.mydomain.com -connect host1.mydomain.com:443
debug1: identity file /Users/user/.ssh/id_rsa type 0
debug1: identity file /Users/user/.ssh/id_rsa-cert type -1
debug1: identity file /Users/user/.ssh/id_ecdsa type -1
debug1: identity file /Users/user/.ssh/id_ecdsa-cert type -1
debug1: identity file /Users/user/.ssh/id_ecdsa_sk type -1
debug1: identity file /Users/user/.ssh/id_ecdsa_sk-cert type -1
debug1: identity file /Users/user/.ssh/id_ed25519 type -1
debug1: identity file /Users/user/.ssh/id_ed25519-cert type -1
debug1: identity file /Users/user/.ssh/id_ed25519_sk type -1
debug1: identity file /Users/user/.ssh/id_ed25519_sk-cert type -1
debug1: identity file /Users/user/.ssh/id_xmss type -1
debug1: identity file /Users/user/.ssh/id_xmss-cert type -1
debug1: identity file /Users/user/.ssh/id_dsa type -1
debug1: identity file /Users/user/.ssh/id_dsa-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_9.7
Connecting to 91.X.Y.Z
debug1: Remote protocol version 2.0, remote software version dropbear
debug1: compat_banner: no match: dropbear
debug1: Authenticating to host1.mydomain.com:22 as 'root'
debug1: load_hostkeys: fopen /Users/user/.ssh/known_hosts2: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: [email protected] MAC: <implicit> compression: none
debug1: kex: client->server cipher: [email protected] MAC: <implicit> compression: none
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: SSH2_MSG_KEX_ECDH_REPLY received
debug1: Server host key: ssh-ed25519 SHA256:jEtxIW8y2Cq8vHwaWti5H0WlzPz94TuLJWm/td1CWvQ
debug1: load_hostkeys: fopen /Users/user/.ssh/known_hosts2: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: Host 'host1.mydomain.com' is known and matches the ED25519 host key.
debug1: Found key in /Users/user/.ssh/known_hosts:1652
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: rekey in after 134217728 blocks
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_ext_info_client_parse: server-sig-algs=<ssh-ed25519,[email protected],rsa-sha2-256,ssh-rsa>
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: get_agent_identities: bound agent to hostkey
debug1: get_agent_identities: agent returned 3 keys
debug1: Will attempt key: /Users/user/.ssh/id_rsa RSA SHA256:5jamXWiwZO8TvN.../I agent
debug1: Will attempt key: .ssh/id_rsa_user RSA SHA256:f5hOcjW+aZjUynH5q9AukIH3Pvu+htDjUPKdYK+0IUI agent
debug1: Will attempt key: ubuntu@superpc RSA SHA256:9XJKU52vzNNlx5Ya8xVMQjPIgtJytsAmLi08U7Pj6sE agent
debug1: Will attempt key: /Users/user/.ssh/id_ecdsa
debug1: Will attempt key: /Users/user/.ssh/id_ecdsa_sk
debug1: Will attempt key: /Users/user/.ssh/id_ed25519
debug1: Will attempt key: /Users/user/.ssh/id_ed25519_sk
debug1: Will attempt key: /Users/user/.ssh/id_xmss
debug1: Will attempt key: /Users/user/.ssh/id_dsa
debug1: Offering public key: /Users/user/.ssh/id_rsa RSA SHA256:5jamXWiwZO8TvN.../I agent
debug1: Server accepts key: /Users/user/.ssh/id_rsa RSA SHA256:5jamXWiwZO8TvN.../I agent
Authenticated to host1.mydomain.com (via proxy) using "publickey".
debug1: channel 0: new session [client-session] (inactive timeout: 0)
debug1: Entering interactive session.
debug1: pledge: filesystem
debug1: Sending environment.
debug1: channel 0: setting env LC_TERMINAL_VERSION = "3.5.11"
debug1: channel 0: setting env LANG = "it_IT.UTF-8"
debug1: channel 0: setting env LC_TERMINAL = "iTerm2"


BusyBox v1.35.0 (2023-04-27 20:28:15 UTC) built-in shell (ash)

root@host1:~# exit
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: channel 0: free: client-session, nchannels 1
Connection to host1.mydomain.com closed.
Transferred: sent 3408, received 1936 bytes, in 3.3 seconds
Bytes per second: sent 1030.4, received 585.4
debug1: Exit status 0

caddy logs:

Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0074992,"logger":"layer4","msg":"matching","remote":"151.X.Y.Z:60810","error":"consumed all prefetched bytes","matcher":"layer4.matchers.tls","matched":false}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0123997,"logger":"layer4","msg":"prefetched","remote":"151.X.Y.Z:60810","bytes":339}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.012439,"logger":"layer4.matchers.tls","msg":"matched","remote":"151.X.Y.Z:60810","server_name":"ssh.host1.mydomain.com"}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0124483,"logger":"layer4","msg":"matching","remote":"151.X.Y.Z:60810","matcher":"layer4.matchers.tls","matched":true}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0126631,"logger":"events","msg":"event","name":"tls_get_certificate","id":"b92252be-18e5-421c-b246-67f6474fe6e2","origin":"tls","data":{"client_hello":{"CipherSuites":[4866,4867,4865,49196,49200,159,52393,52392,52394,49195,49199,158,49188,49192,107,49187,49191,103,49162,49172,57,49161,49171,51,157,156,61,60,53,47],"ServerName":"ssh.host1.mydomain.com","SupportedCurves":[29,23,30,25,24,256,257,258,259,260],"SupportedPoints":"AAEC","SignatureSchemes":[1027,1283,1539,2055,2056,2074,2075,2076,2057,2058,2059,2052,2053,2054,1025,1281,1537,771,769,770,1026,1282,1538],"SupportedProtos":null,"SupportedVersions":[772,771],"RemoteAddr":{"IP":"151.X.Y.Z","Port":60810,"Zone":""},"LocalAddr":{"IP":"192.168.2.10","Port":443,"Zone":""}}}}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.012701,"logger":"tls.handshake","msg":"choosing certificate","identifier":"ssh.host1.mydomain.com","num_choices":1}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0127282,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"ssh.host1.mydomain.com","subjects":["ssh.host1.mydomain.com"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"1dcf7c1326c8966fca25b900998e7fef401de308144ac8a0e848ccf60f8a191b"}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0127368,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"151.X.Y.Z","remote_port":"60810","subjects":["ssh.host1.mydomain.com"],"managed":true,"expiration":1745879343,"hash":"1dcf7c1326c8966fca25b900998e7fef401de308144ac8a0e848ccf60f8a191b"}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.0628526,"logger":"layer4.handlers.tls","msg":"terminated TLS","remote":"151.X.Y.Z:60810","server_name":"ssh.host1.mydomain.com"}
Jan 29 14:39:36 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161576.093671,"logger":"layer4.handlers.proxy","msg":"dial upstream","remote":"151.X.Y.Z:60810","upstream":"10.0.2.5:22"}
Jan 29 14:39:39 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161579.9530303,"logger":"layer4","msg":"connection stats","remote":"151.X.Y.Z:60810","read":4494,"written":5237,"duration":3.945543076}

NOT working:

ssh -v [email protected]
OpenSSH_9.7p1, LibreSSL 3.3.6
debug1: Reading configuration data /Users/user/.ssh/config
debug1: /Users/user/.ssh/config line 11: Applying options for *.mydomain.com
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 21: include /etc/ssh/ssh_config.d/* matched no files
debug1: /etc/ssh/ssh_config line 54: Applying options for *
debug1: Authenticator provider $SSH_SK_PROVIDER did not resolve; disabling
debug1: Executing proxy command: exec openssl s_client -verify_quiet -quiet -servername ssh.host1.mydomain.com -connect host1.mydomain.com:443
debug1: identity file /Users/user/.ssh/id_rsa type 0
debug1: identity file /Users/user/.ssh/id_rsa-cert type -1
debug1: identity file /Users/user/.ssh/id_ecdsa type -1
debug1: identity file /Users/user/.ssh/id_ecdsa-cert type -1
debug1: identity file /Users/user/.ssh/id_ecdsa_sk type -1
debug1: identity file /Users/user/.ssh/id_ecdsa_sk-cert type -1
debug1: identity file /Users/user/.ssh/id_ed25519 type -1
debug1: identity file /Users/user/.ssh/id_ed25519-cert type -1
debug1: identity file /Users/user/.ssh/id_ed25519_sk type -1
debug1: identity file /Users/user/.ssh/id_ed25519_sk-cert type -1
debug1: identity file /Users/user/.ssh/id_xmss type -1
debug1: identity file /Users/user/.ssh/id_xmss-cert type -1
debug1: identity file /Users/user/.ssh/id_dsa type -1
debug1: identity file /Users/user/.ssh/id_dsa-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_9.7
Connecting to 91.X.Y.Z
debug1: kex_exchange_identification: banner line 0: HTTP/1.1 400 Bad Request
debug1: kex_exchange_identification: banner line 1: Content-Type: text/plain; charset=utf-8
debug1: kex_exchange_identification: banner line 2: Connection: close
debug1: kex_exchange_identification: banner line 3:
kex_exchange_identification: Connection closed by remote host
Connection closed by UNKNOWN port 65535

caddy logs:

Jan 29 14:39:43 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161583.4827466,"logger":"events","msg":"event","name":"tls_get_certificate","id":"8697e24f-542d-495a-a4d4-1c72994e1103","origin":"tls","data":{"client_hello":{"CipherSuites":[4866,4867,4865,49196,49200,159,52393,52392,52394,49195,49199,158,49188,49192,107,49187,49191,103,49162,49172,57,49161,49171,51,157,156,61,60,53,47],"ServerName":"ssh.host1.mydomain.com","SupportedCurves":[29,23,30,25,24,256,257,258,259,260],"SupportedPoints":"AAEC","SignatureSchemes":[1027,1283,1539,2055,2056,2074,2075,2076,2057,2058,2059,2052,2053,2054,1025,1281,1537,771,769,770,1026,1282,1538],"SupportedProtos":null,"SupportedVersions":[772,771],"RemoteAddr":{"IP":"151.X.Y.Z","Port":60811,"Zone":""},"LocalAddr":{"IP":"192.168.2.10","Port":443,"Zone":""}}}}
Jan 29 14:39:43 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161583.4828045,"logger":"tls.handshake","msg":"choosing certificate","identifier":"ssh.host1.mydomain.com","num_choices":1}
Jan 29 14:39:43 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161583.4828115,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"ssh.host1.mydomain.com","subjects":["ssh.host1.mydomain.com"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"1dcf7c1326c8966fca25b900998e7fef401de308144ac8a0e848ccf60f8a191b"}
Jan 29 14:39:43 caddy-web-s1 caddy[18370]: {"level":"debug","ts":1738161583.4828205,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"151.X.Y.Z","remote_port":"60811","subjects":["ssh.host1.mydomain.com"],"managed":true,"expiration":1745879343,"hash":"1dcf7c1326c8966fca25b900998e7fef401de308144ac8a0e848ccf60f8a191b"}

I tried building from source with different versions of Caddy (e.g., v2.8 and v2.9) and even rolling back several commits in this repo, but the result remains the same.
Any suggestions? What am I doing wrong?

@vnxme
Copy link
Collaborator

vnxme commented Jan 30, 2025

with dnscrypt-server to do dns over https

@blob42 First of all, if you are only interested in DoH, you don't need caddy-l4 at all. As per RFC 8484, DoH provides for pure GET/POST requests to https://example.com/dns-query. And Caddy has all the required features to catch such requests and reverse proxy them to whatever backend you like.

My L4 Caddyfile

Secondly, the config you provided makes Caddy and caddy-l4 listen to tcp/443. I guess it may be the reason for your config working half of the time. The basic principle is only one service should be listening to a protocol/port at a time. And if you insist on using caddy-l4 (in case you would like to multiplex non-https traffic on the same port, it's the only way currently possible), you need a listener wrapper.

Any suggestions? What am I doing wrong?

@colrack Same for you. Caddy and caddy-l4 can't listen to tcp/443 at the same time. Please use the listener wrapper mode instead.

For both of you, this is what works fine in your cases:

{
    servers {
        listener_wrappers {
            layer4 {
                @one tls sni one.example.com
                route @one {
                    proxy one.machine.local:443
                }
                @two tls sni two.example.com
                route @two {
                    tls
                    proxy two.machine.local:80
                }
            }
            tls
        }
    }
}

*.example.com {
    respond OK 200
}

Last but not least, please, be advised that there is no listener wrapper for UDP (yet), so HTTP3 a.k.a QUIC connections will always return OK in the example above.

@blob42
Copy link
Author

blob42 commented Jan 30, 2025

@vnxme Thanks for the reply.

I will try the listener wrapper way and update the issue if I can solve it.

For more context to your reply:

If I dont use caddy-l4 and pass the traffic directly to dnscrypt-server + DoH I loose all spam control capabilities on the original connection. I cannot see the origin IP in the filter that you see on my l4 Caddyfile. My downstream caddy only sees connections from DoH.

For info the whole https traffic has to pass through dnscrypt server

See my issue on dnscrypt-server here
DNSCrypt/encrypted-dns-server#296 (comment)

@colrack
Copy link

colrack commented Jan 30, 2025

Now it works for me.
What misled me was that my previous configuration seemed to work, which made me think it was a bug rather than a configuration issue.
Thanks a lot @vnxme

@blob42
Copy link
Author

blob42 commented Jan 31, 2025

Thanks @vnxme I can confirm the listener_wrapper it solved the problem for me as. well.

I couldn't find much details in the docs about what listener_wrapper really does, is there a documentation somewhere that explains what the directive does and how to use ?

@vnxme
Copy link
Collaborator

vnxme commented Feb 1, 2025

@blob42 Well, I agree that there could be more documentation, and we welcome any related PRs.

You can find a general description of listener wrappers here. If you compile Caddy with caddy-l4, you have layer4 as another listener_wrappers option. The layer4 config section doesn't provide for listening to any protocols or ports (it is Caddy that creates listeners instead), but it fully supports all matchers and handlers, and some additional details and examples can be found here. Moreover, you can also read the sources, e.g. starting from here.

@blob42
Copy link
Author

blob42 commented Feb 1, 2025

@vnxme Many thanks.

@blob42 blob42 closed this as completed Feb 1, 2025
@blob42 blob42 changed the title Intermittent tls failures when sharing tls data between caddy and caddy-l4 [solved] Intermittent tls failures when sharing tls data between caddy and caddy-l4 Feb 1, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants