Inconsistent proxying to another Caddy instance (curl)

Help
1

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
2

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
3

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?

4

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
5

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}
6

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
7

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:

8

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
9

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
10

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
11 
✦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
12

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
13 
❯ 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)
14

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
15

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
16

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