Inconsistent proxying to another Caddy instance (curl)

1. The problem I’m having:

I have set up two Caddy instances. Caddy A and Caddy B. Caddy A reverse proxies to Caddy B, and B simply responds with “hello!”. I have come up to a very strange behavior where when I curl -v caddy-a it will only sometimes get the response from Caddy B. Could this be a curl issue, I don’t seem to have any issues accessing the :8080 one through the browser?

2. Error messages and/or full log output:

The following log is the run of a couple consecutive curl -vL https://localhost:8080 commands. As you see we sometimes get the response and sometimes not. I really can’t find a specific pattern. In the following logs, only the last one showed the expected “hello!” response.

~
❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul  9 08:24:31 2024 GMT
*  expire date: Jul  9 20:24:31 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 502
< alt-svc: h3=":8080"; ma=2592000
< server: Caddy
< content-length: 0
< date: Tue, 09 Jul 2024 11:30:47 GMT
<
* Connection #0 to host localhost left intact

~
✦ ❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul  9 08:24:31 2024 GMT
*  expire date: Jul  9 20:24:31 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 502
< alt-svc: h3=":8080"; ma=2592000
< server: Caddy
< content-length: 0
< date: Tue, 09 Jul 2024 11:30:50 GMT
<
* Connection #0 to host localhost left intact

~
✦ ❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul  9 08:24:31 2024 GMT
*  expire date: Jul  9 20:24:31 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 200
< alt-svc: h3=":8080"; ma=2592000
< content-type: text/plain; charset=utf-8
< date: Tue, 09 Jul 2024 11:30:52 GMT
< server: Caddy
< server: Caddy
< content-length: 6
<
* Connection #0 to host localhost left intact

~
❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul  9 08:24:31 2024 GMT
*  expire date: Jul  9 20:24:31 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 502
< alt-svc: h3=":8080"; ma=2592000
< server: Caddy
< content-length: 0
< date: Tue, 09 Jul 2024 11:30:57 GMT
<
* Connection #0 to host localhost left intact

~
✦ ❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul  9 08:24:31 2024 GMT
*  expire date: Jul  9 20:24:31 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 200
< alt-svc: h3=":8080"; ma=2592000
< content-type: text/plain; charset=utf-8
< date: Tue, 09 Jul 2024 11:30:58 GMT
< server: Caddy
< server: Caddy
< content-length: 6
<
* Connection #0 to host localhost left intact
hello!⏎

From Caddy A (the front facing one) I don’t get any DEBUG Logs, when there is no response in the reply, but if we have the “hello!” reply these are usually the logs:

Caddy A debug logs

❯ sudo caddy run --config Caddyfile
2024/07/09 11:30:27.235 INFO    using provided configuration    {"config_file": "Caddyfile", "config_adapter": ""}
2024/07/09 11:30:27.238 INFO    admin   admin endpoint started  {"address": "localhost:2019", "enforce_origin": false, "origins": ["//localhost:2019", "//[::1]:2019", "//127.0.0.1:2019"]}
2024/07/09 11:30:27.238 INFO    http.auto_https enabling automatic HTTP->HTTPS redirects        {"server_name": "srv0"}
2024/07/09 11:30:27.238 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc00004dd00"}
2024/07/09 11:30:27.240 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{"subjects":["localhost"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}]},"srv0":{"listen":[":8080"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"reverse_proxy","upstreams":[{"dial":"localhost:8000"}]}]}]}]}]}],"terminal":true}],"tls_connection_policies":[{}],"automatic_https":{}}}}}
2024/07/09 11:30:27.243 WARN    tls     storage cleaning happened too recently; skipping for now        {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/10 11:30:27.243", "try_again_in": 86399.999999047}
2024/07/09 11:30:27.243 INFO    tls     finished cleaning storage units
2024/07/09 11:30:27.255 INFO    pki.ca.local    root certificate is already trusted by system   {"path": "storage:pki/authorities/local/root.crt"}
2024/07/09 11:30:27.255 DEBUG   http    starting server loop    {"address": "[::]:80", "tls": false, "http3": false}
2024/07/09 11:30:27.255 INFO    http.log        server running  {"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/07/09 11:30:27.255 INFO    http    enabling HTTP/3 listener        {"addr": ":8080"}
2024/07/09 11:30:27.255 DEBUG   http    starting server loop    {"address": "[::]:8080", "tls": true, "http3": true}
2024/07/09 11:30:27.255 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/07/09 11:30:27.255 INFO    http    enabling automatic TLS certificate management   {"domains": ["localhost"]}
2024/07/09 11:30:27.256 WARN    tls     stapling OCSP   {"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/07/09 11:30:27.256 DEBUG   tls.cache       added certificate to cache      {"subjects": ["localhost"], "expiration": "2024/07/09 20:24:32.000", "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944", "cache_size": 1, "cache_capacity": 10000}
2024/07/09 11:30:27.256 DEBUG   events  event   {"name": "cached_managed_cert", "id": "8080d32d-6819-43ee-8369-7569e94c6793", "origin": "tls", "data": {"sans":["localhost"]}}
2024/07/09 11:30:27.256 INFO    autosaved config (load with --resume flag)      {"file": "/root/.local/share/caddy/autosave.json"}
2024/07/09 11:30:27.256 INFO    serving initial configuration
2024/07/09 11:30:52.075 DEBUG   events  event   {"name": "tls_get_certificate", "id": "9c84a548-329d-4f29-b4b7-7ef6a4aa6fd5", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":39514,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/09 11:30:52.075 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/09 11:30:52.075 DEBUG   tls.handshake   default certificate selection results   {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 11:30:52.075 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "39514", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/09 20:24:32.000", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 11:30:52.085 DEBUG   http.handlers.reverse_proxy     selected upstream       {"dial": "localhost:8000", "total_upstreams": 1}
2024/07/09 11:30:52.087 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "localhost:8000", "duration": 0.001510775, "request": {"remote_ip": "::1", "remote_port": "39514", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"X-Forwarded-For": ["::1"], "X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"], "User-Agent": ["curl/8.8.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"], "Date": ["Tue, 09 Jul 2024 11:30:52 GMT"], "Content-Length": ["6"]}, "status": 200}
2024/07/09 11:30:58.823 DEBUG   events  event   {"name": "tls_get_certificate", "id": "c23552fd-6867-458d-aec8-25fde18b00b9", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":54824,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/09 11:30:58.824 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/09 11:30:58.824 DEBUG   tls.handshake   default certificate selection results   {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 11:30:58.824 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "54824", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/09 20:24:32.000", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 11:30:58.830 DEBUG   http.handlers.reverse_proxy     selected upstream       {"dial": "localhost:8000", "total_upstreams": 1}
2024/07/09 11:30:58.831 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "localhost:8000", "duration": 0.001059749, "request": {"remote_ip": "::1", "remote_port": "54824", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"], "User-Agent": ["curl/8.8.0"], "Accept": ["*/*"], "X-Forwarded-For": ["::1"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Date": ["Tue, 09 Jul 2024 11:30:58 GMT"], "Content-Length": ["6"], "Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"]}, "status": 200}

Caddy B debug logs

❯ sudo caddy run --config Caddyfile
2024/07/09 11:45:01.644 INFO    using provided configuration    {"config_file": "Caddyfile", "config_adapter": ""}
2024/07/09 11:45:01.645 INFO    admin   admin endpoint started  {"address": ":2020", "enforce_origin": false, "origins": ["//:2020"]}
2024/07/09 11:45:01.645 WARN    admin   admin endpoint on open interface; host checking disabled        {"address": ":2020"}
2024/07/09 11:45:01.645 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{}]}}, "http": {"servers":{"srv0":{"listen":[":8000"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"body":"hello!","handler":"static_response"}]}]}],"terminal":true}],"automatic_https":{"skip":["localhost"]},"trusted_proxies":{"ranges":["192.168.0.0/16","172.16.0.0/12","10.0.0.0/8","127.0.0.1/8","fd00::/8","::1"],"source":"static"}}}}}
2024/07/09 11:45:01.645 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc0001a5200"}
2024/07/09 11:45:01.645 DEBUG   http    starting server loop    {"address": "[::]:8000", "tls": false, "http3": false}
2024/07/09 11:45:01.645 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/07/09 11:45:01.645 INFO    autosaved config (load with --resume flag)      {"file": "/root/.local/share/caddy/autosave.json"}
2024/07/09 11:45:01.645 INFO    serving initial configuration
2024/07/09 11:45:01.648 WARN    tls     storage cleaning happened too recently; skipping for now        {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/10 11:45:01.648", "try_again_in": 86399.999999251}
2024/07/09 11:45:01.648 INFO    tls     finished cleaning storage units

3. Caddy version:

Logs in this post are from 2.7.6, although 2.8.4 produces the same for me

4. How I installed and ran Caddy:

From the AUR

a. System environment:

OS: EndeavourOS Linux on Windows (under WSL2)

b. Command:

Caddy A

> caddy run --config Caddyfile

Caddy B

> caddy run --config Caddyfile

Of course, these are run in separate directories.

c. Service/unit/compose file:

d. My complete Caddy config:

Caddyfile A

{
	debug
}

localhost:8080 {
	route {
		reverse_proxy {
			to localhost:8000
		}
	}
}

Caddyfile B

{
        admin :2020
        debug
        servers {
                trusted_proxies static private_ranges
        }
}

http://localhost:8000 {
        respond "hello!"
}

5. Links to relevant resources:

1 Like

I added the -I flag to curl to check status codes and it seems, whenever there is no response back from upstream I get 502.

caddy-shield-2 on  main [✘!] via 🐹 v1.22.4
❯ curl -I https://localhost:8080
HTTP/2 502
alt-svc: h3=":8080"; ma=2592000
server: Caddy
date: Tue, 09 Jul 2024 12:07:37 GMT


caddy-shield-2 on  main [✘!] via 🐹 v1.22.4
✦ ❯ curl -I https://localhost:8080
HTTP/2 200
alt-svc: h3=":8080"; ma=2592000
content-type: text/plain; charset=utf-8
date: Tue, 09 Jul 2024 12:07:39 GMT
server: Caddy
server: Caddy
content-length: 6
1 Like

Could it be a problem with the fact that both Caddy instances share the same FileStorage

Caddy A on startup reports:

2024/07/09 12:06:09.641 WARN    tls     storage cleaning happened too recently; skipping for now        {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/10 12:06:09.641", "try_again_in": 86399.999999463}

and Caddy B:

2024/07/09 12:11:35.759 WARN    tls     storage cleaning happened too recently; skipping for now        {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/10 12:11:35.759", "try_again_in": 86399.999999411}

If so, what are my options?

No. This is not impacting the request processing.

Is this the actual and running Caddyfile at the time of testing?

Usually when we see intermittent 502 with a proxying instance, it means the reverse_proxy directive was misconfigured with an improper upstream that is not really an address.

Enable access logs by adding the log directive inside the site block to have more data.

2 Likes

Yes, this is indeed the Caddyfile of the front facing instance, also here is a video proof + adding the log directive Watch Recording 2024-07-09 160121 | Streamable (this video will probably expire, but I also added logs for future reference). Whenever the response is empty from curl there are no logs to the front facing caddy as well.

The logs from the video:

caddy-shield-2 on  main [✘!] via 🐹 v1.22.4 took 42s
❯ cat Caddyfile
{
        debug
}

localhost:8080 {
        log
        route {
                reverse_proxy {
                        to localhost:8000
                }
        }
}

caddy-shield-2 on  main [✘!] via 🐹 v1.22.4
✦ ❯ sudo caddy run --config Caddyfile
2024/07/09 13:59:16.249 INFO    using provided configuration    {"config_file": "Caddyfile", "config_adapter": ""}
2024/07/09 13:59:16.252 INFO    admin   admin endpoint started  {"address": "localhost:2019", "enforce_origin": false, "origins": ["//[::1]:2019", "//127.0.0.1:2019", "//localhost:2019"]}
2024/07/09 13:59:16.253 INFO    http.auto_https enabling automatic HTTP->HTTPS redirects {"server_name": "srv0"}
2024/07/09 13:59:16.253 INFO    tls.cache.maintenance   started background certificate maintenance       {"cache": "0xc000429480"}
2024/07/09 13:59:16.253 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{"subjects":["localhost"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}],"logs":{"logger_names":{"localhost":""}}},"srv0":{"listen":[":8080"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"reverse_proxy","upstreams":[{"dial":"localhost:8000"}]}]}]}]}]}],"terminal":true}],"tls_connection_policies":[{}],"automatic_https":{},"logs":{"logger_names":{"localhost":""}}}}}}
2024/07/09 13:59:16.261 WARN    tls     storage cleaning happened too recently; skipping for now {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/10 13:59:16.261", "try_again_in": 86399.999999273}
2024/07/09 13:59:16.261 INFO    tls     finished cleaning storage units
2024/07/09 13:59:16.282 INFO    pki.ca.local    root certificate is already trusted by system    {"path": "storage:pki/authorities/local/root.crt"}
2024/07/09 13:59:16.283 INFO    http    enabling HTTP/3 listener        {"addr": ":8080"}
2024/07/09 13:59:16.283 DEBUG   http    starting server loop    {"address": "[::]:8080", "tls": true, "http3": true}
2024/07/09 13:59:16.283 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/07/09 13:59:16.283 DEBUG   http    starting server loop    {"address": "[::]:80", "tls": false, "http3": false}
2024/07/09 13:59:16.283 INFO    http.log        server running  {"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/07/09 13:59:16.283 INFO    http    enabling automatic TLS certificate management    {"domains": ["localhost"]}
2024/07/09 13:59:16.283 WARN    tls     stapling OCSP   {"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/07/09 13:59:16.283 DEBUG   tls.cache       added certificate to cache      {"subjects": ["localhost"], "expiration": "2024/07/09 20:24:32.000", "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944", "cache_size": 1, "cache_capacity": 10000}
2024/07/09 13:59:16.283 DEBUG   events  event   {"name": "cached_managed_cert", "id": "bef8f32f-c26d-4e9f-83e6-f7a257c031ed", "origin": "tls", "data": {"sans":["localhost"]}}
2024/07/09 13:59:16.284 INFO    autosaved config (load with --resume flag)      {"file": "/root/.local/share/caddy/autosave.json"}
2024/07/09 13:59:16.284 INFO    serving initial configuration
2024/07/09 13:59:22.835 DEBUG   events  event   {"name": "tls_get_certificate", "id": "a121ddd1-a361-4cc9-8446-958012e975bd", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":60112,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/09 13:59:22.835 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/09 13:59:22.835 DEBUG   tls.handshake   default certificate selection results    {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 13:59:22.835 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "60112", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/09 20:24:32.000", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 13:59:22.841 DEBUG   http.handlers.reverse_proxy     selected upstream{"dial": "localhost:8000", "total_upstreams": 1}
2024/07/09 13:59:22.842 DEBUG   http.handlers.reverse_proxy     upstream roundtrip       {"upstream": "localhost:8000", "duration": 0.000732252, "request": {"remote_ip": "::1", "remote_port": "60112", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"], "X-Forwarded-For": ["::1"], "X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Date": ["Tue, 09 Jul 2024 13:59:22 GMT"], "Content-Length": ["6"], "Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"]}, "status": 200}
2024/07/09 13:59:22.842 INFO    http.log.access handled request {"request": {"remote_ip": "::1", "remote_port": "60112", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "bytes_read": 0, "user_id": "", "duration": 0.001031407, "size": 6, "status": 200, "resp_headers": {"Server": ["Caddy", "Caddy"], "Alt-Svc": ["h3=\":8080\"; ma=2592000"], "Content-Type": ["text/plain; charset=utf-8"], "Date": ["Tue, 09 Jul 2024 13:59:22 GMT"], "Content-Length": ["6"]}}
2024/07/09 13:59:27.870 DEBUG   events  event   {"name": "tls_get_certificate", "id": "a86e7fe9-269a-45b3-96df-b31bf33f9d17", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":60126,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/09 13:59:27.870 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/09 13:59:27.870 DEBUG   tls.handshake   default certificate selection results    {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 13:59:27.870 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "60126", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/09 20:24:32.000", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 13:59:27.880 DEBUG   http.handlers.reverse_proxy     selected upstream{"dial": "localhost:8000", "total_upstreams": 1}
2024/07/09 13:59:27.881 DEBUG   http.handlers.reverse_proxy     upstream roundtrip       {"upstream": "localhost:8000", "duration": 0.001098451, "request": {"remote_ip": "::1", "remote_port": "60126", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"X-Forwarded-For": ["::1"], "X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"], "User-Agent": ["curl/8.8.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"], "Date": ["Tue, 09 Jul 2024 13:59:27 GMT"], "Content-Length": ["6"]}, "status": 200}
2024/07/09 13:59:27.881 INFO    http.log.access handled request {"request": {"remote_ip": "::1", "remote_port": "60126", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"Accept": ["*/*"], "User-Agent": ["curl/8.8.0"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "bytes_read": 0, "user_id": "", "duration": 0.001449369, "size": 6, "status": 200, "resp_headers": {"Alt-Svc": ["h3=\":8080\"; ma=2592000"], "Content-Type": ["text/plain; charset=utf-8"], "Date": ["Tue, 09 Jul 2024 13:59:27 GMT"], "Content-Length": ["6"], "Server": ["Caddy", "Caddy"]}}
2024/07/09 13:59:29.397 DEBUG   events  event   {"name": "tls_get_certificate", "id": "61fdb896-d932-4d3e-905d-282ff39ace87", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":60136,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/09 13:59:29.397 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/09 13:59:29.397 DEBUG   tls.handshake   default certificate selection results    {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 13:59:29.397 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "60136", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/09 20:24:32.000", "hash": "2d27a7880841414b49bd73939bb6aadd0392bd6ce77a9a50393b04cfcd08a944"}
2024/07/09 13:59:29.404 DEBUG   http.handlers.reverse_proxy     selected upstream{"dial": "localhost:8000", "total_upstreams": 1}
2024/07/09 13:59:29.404 DEBUG   http.handlers.reverse_proxy     upstream roundtrip       {"upstream": "localhost:8000", "duration": 0.000575473, "request": {"remote_ip": "::1", "remote_port": "60136", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"], "User-Agent": ["curl/8.8.0"], "Accept": ["*/*"], "X-Forwarded-For": ["::1"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"], "Date": ["Tue, 09 Jul 2024 13:59:29 GMT"], "Content-Length": ["6"]}, "status": 200}
2024/07/09 13:59:29.405 INFO    http.log.access handled request {"request": {"remote_ip": "::1", "remote_port": "60136", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "bytes_read": 0, "user_id": "", "duration": 0.000987311, "size": 6, "status": 200, "resp_headers": {"Content-Type": ["text/plain; charset=utf-8"], "Date": ["Tue, 09 Jul 2024 13:59:29 GMT"], "Content-Length": ["6"], "Server": ["Caddy", "Caddy"], "Alt-Svc": ["h3=\":8080\"; ma=2592000"]}}
^C2024/07/09 13:59:34.861       INFO    shutting down   {"signal": "SIGINT"}
2024/07/09 13:59:34.862 WARN    exiting; byeee!! 👋     {"signal": "SIGINT"}
2024/07/09 13:59:34.862 INFO    http    servers shutting down with eternal grace period
2024/07/09 13:59:34.863 INFO    admin   stopped previous server {"address": "localhost:2019"}
2024/07/09 13:59:34.863 INFO    shutdown complete       {"signal": "SIGINT", "exit_code": 0}

Based on those logs, it looks like Caddy is successfully proxying and responding to every request it receives.

What happens when you run curl -v (you can keep using -L too)?

2 Likes

Yes, when curl gets a “hello!” response from the reversed proxy server the logs are printed and indeed look normal. But if you pay attention during the video while I am making the request which doesn’t get a response you will see that there are also no logs printed. The -v logs are also already provided in the first post above. :crossed_fingers:t3:

Please use curl -v, not curl -L or curl -I. We need to see the full output from curl to understand why it shows an empty response.

2 Likes

Thanks, now I see them.

It’s weird to me that in some cases the response is HTTP 200 but the body isn’t downloaded, despite a Content-Length of 6.

You say this doesn’t happen at all in a browser, just curl? What curl version is it?

2 Likes

Hey, sorry for the late reply. Although the logs are the same from what I have provided in the first post (where I already used curl -v, and only for the video purpose I used the other curl flag (for easier reading)), I just tried again to verify with the -v flag.

the curl requests, where first two requests get a reply “hello!” and the third does not (as I mentioned this is not the pattern).

~
❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul 10 08:54:10 2024 GMT
*  expire date: Jul 10 20:54:10 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 200
< alt-svc: h3=":8080"; ma=2592000
< content-type: text/plain; charset=utf-8
< date: Wed, 10 Jul 2024 08:58:51 GMT
< server: Caddy
< server: Caddy
< content-length: 6
<
* Connection #0 to host localhost left intact
hello!⏎

~
✦ ❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul 10 08:54:10 2024 GMT
*  expire date: Jul 10 20:54:10 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 200
< alt-svc: h3=":8080"; ma=2592000
< content-type: text/plain; charset=utf-8
< date: Wed, 10 Jul 2024 08:58:51 GMT
< server: Caddy
< server: Caddy
< content-length: 6
<
* Connection #0 to host localhost left intact
hello!⏎

~
✦2 ❯ curl -vL https://localhost:8080
* Host localhost:8080 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:8080...
* Connected to localhost (::1) port 8080
* ALPN: curl 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 handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 / x25519 / id-ecPublicKey
* ALPN: server accepted h2
* Server certificate:
*  subject: [NONE]
*  start date: Jul 10 08:54:10 2024 GMT
*  expire date: Jul 10 20:54:10 2024 GMT
*  subjectAltName: host "localhost" matched cert's "localhost"
*  issuer: CN=Caddy Local Authority - ECC Intermediate
*  SSL certificate verify ok.
*   Certificate level 0: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 1: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
*   Certificate level 2: Public key type EC/prime256v1 (256/128 Bits/secBits), signed using ecdsa-with-SHA256
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://localhost:8080/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: localhost:8080]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.8.0]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: localhost:8080
> User-Agent: curl/8.8.0
> Accept: */*
>
* Request completely sent off
< HTTP/2 502
< alt-svc: h3=":8080"; ma=2592000
< server: Caddy
< content-length: 0
< date: Wed, 10 Jul 2024 08:58:53 GMT
<
* Connection #0 to host localhost left intact

Caddy A logs (the front facing caddy instance)

❯ sudo caddy run --config Caddyfile
2024/07/10 08:58:41.164 INFO    using provided configuration    {"config_file": "Caddyfile", "config_adapter": ""}
2024/07/10 08:58:41.166 INFO    admin   admin endpoint started  {"address": "localhost:2019", "enforce_origin": false, "origins": ["//localhost:2019", "//[::1]:2019", "//127.0.0.1:2019"]}
2024/07/10 08:58:41.167 INFO    http.auto_https enabling automatic HTTP->HTTPS redirects        {"server_name": "srv0"}
2024/07/10 08:58:41.167 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc0004c8f00"}
2024/07/10 08:58:41.167 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{"subjects":["localhost"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}],"logs":{"logger_names":{"localhost":""}}},"srv0":{"listen":[":8080"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"reverse_proxy","upstreams":[{"dial":"localhost:8000"}]}]}]}]}]}],"terminal":true}],"tls_connection_policies":[{}],"automatic_https":{},"logs":{"logger_names":{"localhost":""}}}}}}
2024/07/10 08:58:41.171 WARN    tls     storage cleaning happened too recently; skipping for now        {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/11 08:58:41.171", "try_again_in": 86399.999999407}
2024/07/10 08:58:41.171 INFO    tls     finished cleaning storage units
2024/07/10 08:58:41.185 INFO    pki.ca.local    root certificate is already trusted by system   {"path": "storage:pki/authorities/local/root.crt"}
2024/07/10 08:58:41.185 INFO    http    enabling HTTP/3 listener        {"addr": ":8080"}
2024/07/10 08:58:41.185 DEBUG   http    starting server loop    {"address": "[::]:8080", "tls": true, "http3": true}
2024/07/10 08:58:41.185 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/07/10 08:58:41.185 DEBUG   http    starting server loop    {"address": "[::]:80", "tls": false, "http3": false}
2024/07/10 08:58:41.185 INFO    http.log        server running  {"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/07/10 08:58:41.185 INFO    http    enabling automatic TLS certificate management   {"domains": ["localhost"]}
2024/07/10 08:58:41.186 WARN    tls     stapling OCSP   {"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/07/10 08:58:41.186 DEBUG   tls.cache       added certificate to cache      {"subjects": ["localhost"], "expiration": "2024/07/10 20:54:11.000", "managed": true, "issuer_key": "local", "hash": "bf2308177f14be12003e07fe3737ff459b1eb922d669385d861e5c10b3991e0e", "cache_size": 1, "cache_capacity": 10000}
2024/07/10 08:58:41.186 DEBUG   events  event   {"name": "cached_managed_cert", "id": "f77ab5af-a96a-4f8d-8fbf-471b304b3b3e", "origin": "tls", "data": {"sans":["localhost"]}}
2024/07/10 08:58:41.186 INFO    autosaved config (load with --resume flag)      {"file": "/root/.local/share/caddy/autosave.json"}
2024/07/10 08:58:41.186 INFO    serving initial configuration
2024/07/10 08:58:51.087 DEBUG   events  event   {"name": "tls_get_certificate", "id": "76f078f6-f3b5-4419-bfe9-d62fb8b15f5a", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":55760,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/10 08:58:51.087 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/10 08:58:51.087 DEBUG   tls.handshake   default certificate selection results   {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "bf2308177f14be12003e07fe3737ff459b1eb922d669385d861e5c10b3991e0e"}
2024/07/10 08:58:51.087 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "55760", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/10 20:54:11.000", "hash": "bf2308177f14be12003e07fe3737ff459b1eb922d669385d861e5c10b3991e0e"}
2024/07/10 08:58:51.096 DEBUG   http.handlers.reverse_proxy     selected upstream       {"dial": "localhost:8000", "total_upstreams": 1}
2024/07/10 08:58:51.099 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "localhost:8000", "duration": 0.001642888, "request": {"remote_ip": "::1", "remote_port": "55760", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"], "X-Forwarded-For": ["::1"], "X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"], "Date": ["Wed, 10 Jul 2024 08:58:51 GMT"], "Content-Length": ["6"]}, "status": 200}
2024/07/10 08:58:51.100 INFO    http.log.access handled request {"request": {"remote_ip": "::1", "remote_port": "55760", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "bytes_read": 0, "user_id": "", "duration": 0.003771523, "size": 6, "status": 200, "resp_headers": {"Alt-Svc": ["h3=\":8080\"; ma=2592000"], "Content-Type": ["text/plain; charset=utf-8"], "Date": ["Wed, 10 Jul 2024 08:58:51 GMT"], "Content-Length": ["6"], "Server": ["Caddy", "Caddy"]}}
2024/07/10 08:58:51.865 DEBUG   events  event   {"name": "tls_get_certificate", "id": "60d25229-304b-4069-a58b-77524f76fccc", "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,255],"ServerName":"localhost","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":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"::1","Port":55772,"Zone":""},"LocalAddr":{"IP":"::1","Port":8080,"Zone":""}}}}
2024/07/10 08:58:51.865 DEBUG   tls.handshake   choosing certificate    {"identifier": "localhost", "num_choices": 1}
2024/07/10 08:58:51.866 DEBUG   tls.handshake   default certificate selection results   {"identifier": "localhost", "subjects": ["localhost"], "managed": true, "issuer_key": "local", "hash": "bf2308177f14be12003e07fe3737ff459b1eb922d669385d861e5c10b3991e0e"}
2024/07/10 08:58:51.866 DEBUG   tls.handshake   matched certificate in cache    {"remote_ip": "::1", "remote_port": "55772", "subjects": ["localhost"], "managed": true, "expiration": "2024/07/10 20:54:11.000", "hash": "bf2308177f14be12003e07fe3737ff459b1eb922d669385d861e5c10b3991e0e"}
2024/07/10 08:58:51.884 DEBUG   http.handlers.reverse_proxy     selected upstream       {"dial": "localhost:8000", "total_upstreams": 1}
2024/07/10 08:58:51.884 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "localhost:8000", "duration": 0.000471431, "request": {"remote_ip": "::1", "remote_port": "55772", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"], "X-Forwarded-For": ["::1"], "X-Forwarded-Proto": ["https"], "X-Forwarded-Host": ["localhost:8080"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Content-Length": ["6"], "Content-Type": ["text/plain; charset=utf-8"], "Server": ["Caddy"], "Date": ["Wed, 10 Jul 2024 08:58:51 GMT"]}, "status": 200}
2024/07/10 08:58:51.884 INFO    http.log.access handled request {"request": {"remote_ip": "::1", "remote_port": "55772", "client_ip": "::1", "proto": "HTTP/2.0", "method": "GET", "host": "localhost:8080", "uri": "/", "headers": {"User-Agent": ["curl/8.8.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "bytes_read": 0, "user_id": "", "duration": 0.000659366, "size": 6, "status": 200, "resp_headers": {"Date": ["Wed, 10 Jul 2024 08:58:51 GMT"], "Content-Length": ["6"], "Server": ["Caddy", "Caddy"], "Alt-Svc": ["h3=\":8080\"; ma=2592000"], "Content-Type": ["text/plain; charset=utf-8"]}}
^C2024/07/10 09:02:46.464       INFO    shutting down   {"signal": "SIGINT"}
2024/07/10 09:02:46.464 WARN    exiting; byeee!! 👋     {"signal": "SIGINT"}
2024/07/10 09:02:46.464 INFO    http    servers shutting down with eternal grace period
2024/07/10 09:02:46.464 INFO    admin   stopped previous server {"address": "localhost:2019"}
2024/07/10 09:02:46.465 INFO    shutdown complete       {"signal": "SIGINT", "exit_code": 0}

caddy-shield-2 on  main [✘!] via 🐹 v1.22.4 took 4m5s
❯ cat Caddyfile
{
        debug
}

localhost:8080 {
        log
        route {
                reverse_proxy {
                        to localhost:8000
                }
        }
}

Caddy B:

❯ cat Caddyfile
{
        debug
        admin :2020
        servers {
                trusted_proxies static private_ranges
        }
}

http://localhost:8000 {
        respond "hello!"
}

~/Temp/caddy-test
✦ ❯ sudo caddy run --config Caddyfile
[sudo] password for lyubo:
2024/07/10 08:54:49.083 INFO    using provided configuration    {"config_file": "Caddyfile", "config_adapter": ""}
2024/07/10 08:54:49.084 INFO    admin   admin endpoint started  {"address": ":2020", "enforce_origin": false, "origins": ["//:2020"]}
2024/07/10 08:54:49.084 WARN    admin   admin endpoint on open interface; host checking disabled        {"address": ":2020"}
2024/07/10 08:54:49.085 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc00016b380"}
2024/07/10 08:54:49.085 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{}]}}, "http": {"servers":{"srv0":{"listen":[":8000"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"body":"hello!","handler":"static_response"}]}]}],"terminal":true}],"automatic_https":{"skip":["localhost"]},"trusted_proxies":{"ranges":["192.168.0.0/16","172.16.0.0/12","10.0.0.0/8","127.0.0.1/8","fd00::/8","::1"],"source":"static"}}}}}
2024/07/10 08:54:49.085 DEBUG   http    starting server loop    {"address": "[::]:8000", "tls": false, "http3": false}
2024/07/10 08:54:49.085 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/07/10 08:54:49.085 INFO    autosaved config (load with --resume flag)      {"file": "/root/.local/share/caddy/autosave.json"}
2024/07/10 08:54:49.085 INFO    serving initial configuration
2024/07/10 08:54:49.088 WARN    tls     storage cleaning happened too recently; skipping for now        {"storage": "FileStorage:/root/.local/share/caddy", "instance": "ecd77583-7859-44f5-bf0b-baf6fe1d24c0", "try_again": "2024/07/11 08:54:49.088", "try_again_in": 86399.999999673}
2024/07/10 08:54:49.088 INFO    tls     finished cleaning storage units
✦3 ❯ curl --version
curl 8.8.0 (x86_64-pc-linux-gnu) libcurl/8.8.0 OpenSSL/3.3.1 zlib/1.3.1 brotli/1.1.0 zstd/1.5.6 libidn2/2.3.7 libpsl/0.21.5 libssh2/1.11.0 nghttp2/1.62.1 nghttp3/1.3.0
Release-Date: 2024-05-22
Protocols: dict file ftp ftps gopher gophers http https imap imaps ipfs ipns mqtt pop3 pop3s rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTP3 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM PSL SPNEGO SSL threadsafe TLS-SRP UnixSockets zstd

The request having 502 responses isn’t present in the shared logs of Caddy A. I wonder if you have multiple processes listening on the same port. We set the SO_REUSEPORT option, so there may be some older Caddy process that you may have launched and forgotten.

https://lwn.net/Articles/542629/

Try the command lsof -ni tcp:443 to see what processes are listening on 443.

2 Likes
❯ lsof -ni tcp:443
COMMAND      PID  USER FD   TYPE   DEVICE SIZE/OFF NODE NAME
flyctl    688032 lyubo 11u  IPv4 11010808      0t0  TCP 172.28.85.117:33412->176.58.93.206:https (ESTABLISHED)
wakatime- 737246 lyubo  3u  IPv4 11254559      0t0  TCP 172.28.85.117:60276->143.244.210.202:https (SYN_SENT)

and with sudo:

❯ sudo lsof -ni tcp:443
[sudo] password for lyubo:
COMMAND      PID  USER FD   TYPE   DEVICE SIZE/OFF NODE NAME
tailscale    135  root 27u  IPv4 10979991      0t0  TCP 172.28.85.117:57232->54.161.152.147:https (ESTABLISHED)
tailscale    135  root 33u  IPv4 11189480      0t0  TCP 172.28.85.117:46646->176.58.93.147:https (ESTABLISHED)
flyctl    688032 lyubo 11u  IPv4 11010808      0t0  TCP 172.28.85.117:33412->176.58.93.206:https (ESTABLISHED)

Update

I rebooted wsl, and now I always get a response. Could it be a leftover process @Mohammed90, it is strange to me because I don’t see it in the lsof logs I provided above.

Also now that I rebooted, I run the curl request 10 000 times of which 0 times I got an empty response.

~/Temp/caddy-test
✦2 ❯ nvim check_resp.sh

~/Temp/caddy-test took 20s
❯ chmod +x check_resp.sh

~/Temp/caddy-test
✦ ❯ cat check_resp.sh
#!/bin/bash

non_hello_count=0

for i in {1..10000}
do
  response=$(curl -L -s https://localhost:8080)

  if [[ "$response" != *"hello!"* ]]; then
    ((non_hello_count++))
  fi
done

echo "Number of requests that did not return 'hello!': $non_hello_count"

~/Temp/caddy-test
✦ ❯ ./check_resp.sh
Number of requests that did not return 'hello!': 0

~/Temp/caddy-test took 3m24s
❯
1 Like

The interfaces listed in the lsof results are all IPv4, while the debug logs of curl requests show they’re reaching Caddy on the IPv6. The lsof command I shared may be missing some flags to check for IPv6 :thinking:

Anyways, glad it’s resolved now.

2 Likes

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.