Caddy logging zero status on response_header_timeout

[betelgeuse]

Issue Details

I am testing reverse_proxy with a destination that just sleeps. Relevant configuration:

  log
  reverse_proxy localhost:4000 {
    transport http {
      response_header_timeout 300s
    }    
  }

I am getting the following log entry:

{"level":"info","ts":1765606291.589831,"logger":"http.log.access","msg":"handled request","request":{"remote_ip":"x.x.x.x","remote_port":"23018","client_ip":"x.x.x.x","proto":"HTTP/1.1","method":"GET","host":"xxx","uri":"/sleep?seconds=305","headers":{"Accept-Encoding":["identity"],"User-Agent":["ansible-httpget"],"Connection":["close"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"","server_name":"xxx"}},"bytes_read":0,"user_id":"","duration":284.237173119,"size":0,"status":0,"resp_headers":{"Server":["Caddy"],"Alt-Svc":["h3=\":443\"; ma=2592000"]}}

Expected results:

Status 504 Gateway Timeout instead of "status":0

Caddy version:

docker.io/caddy:2.10.2

Assistance Disclosure

AI not used

If AI was used, describe the extent to which it was used.

No response

[francislavoie]

And what does it look like when you make the request with curl -v, what does the actual response from Caddy look like?

[betelgeuse]

And what does it look like when you make the request with curl -v, what does the actual response from Caddy look like?

The same issue does not reproduce with curl to the logs:

{
    "level": "info",
    "ts": 1765703659.216192,
    "logger": "http.log.access",
    "msg": "handled request",
    "request": {
        "remote_ip": "x.x.x.x",
        "remote_port": "7492",
        "client_ip": "x.x.x.x",
        "proto": "HTTP/2.0",
        "method": "GET",
        "host": "xxxx",
        "uri": "/sleep?seconds=305",
        "headers": {
            "Accept": ["*/*"],
            "User-Agent": ["curl/8.12.1"]
        },
        "tls": {
            "resumed": false,
            "version": 772,
            "cipher_suite": 4865,
            "proto": "h2",
            "server_name": "xxxx"
        }
    },
    "bytes_read": 0,
    "user_id": "",
    "duration": 305.017367043,
    "size": 8,
    "status": 200,
    "resp_headers": {
        "xxx"
    }
}

This produces a different issue since status 200 is not correct either.

curl from the client side outputs:

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
r  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
* Host xxxx:443 was resolved.
* IPv6: xxxx
* IPv4: xxxx
*   Trying [xxxx]:443...
* Immediate connect fail for xxxx: Network is unreachable
*   Trying xxxx:443...
* ALPN: curl offers h2,http/1.1
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
*  CAfile: files/letsencrypt-stg-root-x1.pem
*  CApath: /etc/ssl/certs
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Server

The original log issue comes with ansible.builtin.uri making the request:

"Status code was -1 and not [504]: Connection failure: [Errno 104] Connection reset by peer"

[WeidiDeng]

Does your caddy use plugins? With the minimal caddy config like yours, I can't replicate your behavior.

http://127.0.0.1 {
   log
   reverse_proxy localhost:4000 {
     transport http {
        response_header_timeout 5s
    }    
  }
}

I reduced the timeout for convenience.

The backend is simple enough,

package main

import (
	"net/http"
	"time"
)

func main() {
	panic(http.ListenAndServe("127.0.0.1:4000", http.HandlerFunc(func(writer http.ResponseWriter, request *http.Request) {
		time.Sleep(10 * time.Second)
		panic(http.ErrAbortHandler)
	})))
}

Use curl 127.0.0.1 -v, The output is

*   Trying 127.0.0.1:80...
* Connected to 127.0.0.1 (127.0.0.1) port 80
> GET / HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/8.5.0
> Accept: */*
> 
< HTTP/1.1 504 Gateway Timeout
< Server: Caddy
< Date: Mon, 15 Dec 2025 01:02:16 GMT
< Content-Length: 0
< 
* Connection #0 to host 127.0.0.1 left intact

Caddy log

http.log.error  net/http: timeout awaiting response headers     {"request": {"remote_ip": "127.0.0.1", "remote_port": "59826", "client_ip": "127.0.0.1", "proto": "HTTP/1.1", "method": "GET", "host": "127.0.0.1", "uri": "/", "headers": {"User-Agent": ["curl/8.5.0"], "Accept": ["*/*"]}}, "duration": 5.001204277, "status": 504, "err_id": "gdpz1pp6i", "err_trace": "reverseproxy.statusError (reverseproxy.go:1390)"}
http.log.access handled request {"request": {"remote_ip": "127.0.0.1", "remote_port": "59826", "client_ip": "127.0.0.1", "proto": "HTTP/1.1", "method": "GET", "host": "127.0.0.1", "uri": "/", "headers": {"User-Agent": ["curl/8.5.0"], "Accept": ["*/*"]}}, "bytes_read": 0, "user_id": "", "duration": 5.001204277, "size": 0, "status": 504, "resp_headers": {"Server": ["Caddy"]}}

[betelgeuse]

Does your caddy use plugins?

Here's a more full Caddyfile example from a failing run (domain changed):

{
  default_bind fd/4 {
    protocols h1 h2
  }

  default_bind fdgram/5 {
    protocols h3
  }

  acme_ca https://acme-staging-v02.api.letsencrypt.org/directory
}

http:// {
	# 1st socket in the file container-caddy.socket
	bind fd/3 {
		protocols h1
	}
	redir https://{host}{uri}
}

test.example.com {
  log
  reverse_proxy localhost:4000 {
    header_up +X-Real-IP {http.request.remote.host}
    header_up +X-Forwarded-For {http.request.remote.host}
    header_up +X-Queue-Start t={time.now.unix_ms}
    header_up +X-Forwarded-Proto https
    header_down +Strict-Transport-Security "max-age=31536000"
    transport http {
      response_header_timeout 300s
    }
  }
}

I am using TLS. Could that make a difference?

The socket configuration is for podman socket activation https://github.com/eriksjolund/podman-caddy-socket-activation/blob/a181eca7e0f2d16b11515d9a87beb1f956b2cd61/examples/example4/Caddyfile

[betelgeuse]

"duration":284.237173119

In my original log this puzzles me that the timeout happens at 284 seconds. This is quite a lot sooner than the configuration for 300s.

[WeidiDeng]

I can replicate this behavior if I ctrl+c curl before the timeout. I changed the backend to sleep based on the parameter of the url.

INFO    http.log.access handled request {"request": {"remote_ip": "127.0.0.1", "remote_port": "36014", "client_ip": "127.0.0.1", "proto": "HTTP/1.1", "method": "GET", "host": "127.0.0.1", "uri": "/?sec=20s", "headers": {"User-Agent": ["curl/8.5.0"], "Accept": ["*/*"]}}, "bytes_read": 0, "user_id": "", "duration": 1.977647271, "size": 0, "status": 0, "resp_headers": {"Server": ["Caddy"]}}

But if I wait for the timeout to occur, the status is 504. Maybe we should log that the client disconnected instead of the misleading 0 status code?

"duration":284.237173119

In my original log this puzzles me that the timeout happens at 284 seconds. This is quite a lot sooner than the configuration for 300s.

I'm not familiar with how docker handles network timeouts. And I guess "Status code was -1 and not [504]: Connection failure: [Errno 104] Connection reset by peer" means the connection was closed without a response.

[betelgeuse]

But if I wait for the timeout to occur, the status is 504. Maybe we should log that the client disconnected instead of the misleading 0 status code?

This would be desired behaviour from my part. The log line shouldn't look like Caddy replied with a HTTP response at all if the client has disconnected before writing a status code.

A quick look with GitHub source code search does not provide any hits for ECONNRESET and no relevant hits for reset. Seems like something that benefits from a test case.

I'm not familiar with how docker handles network timeouts.

Did you mean podman? The client ansible does run inside docker though that wasn't previously disclosed.