Caddy reverse_proxy always returns size 0 and status 0

1. Output of caddy version:

v2.6.2 h1:wKoFIxpmOJLGl3QXoo6PNbYvGW4xLEgo32GPBEjWL8o=

2. How I run Caddy:

./caddy run --config Caddyfile.dingyu --watch

a. System environment:

Ubuntu 20.04.5 LTS (Focal Fossa)

b. Command:

./caddy run --config Caddyfile.dingyu  --watch

c. Service/unit/compose file:

Paste full file contents here.
Make sure backticks stay on their own lines,
and the post looks nice in the preview pane. -->

d. My complete Caddy config:

v.dingyu.me {
	tls felixding@gmail.com
	#reverse_proxy /contact localhost:446
	handle_path /contact {
		reverse_proxy localhost:446
	}

	log {
		level INFO
	}
}

3. The problem I’m having:

I’m trying to use Caddy as a reverse proxy. All is fine except one thing: the size and status in the response headers are always 0, even though the traffic was successfully tunneled by Caddy and the upstream proxy server.

I need to know the correct status and size for my app to work, therefore this is a critical issue for me.

4. Error messages and/or full log output:

2022/11/20 10:28:59.935	INFO	http.log.access.log0	handled request	"2022/11/20 10":"28":59.935	INFO	http.log.access.log0	handled request{
   "request":{
      "remote_ip":"27.141.195.16",
      "remote_port":"53393",
      "proto":"HTTP/1.1",
      "method":"GET",
      "host":"v.dingyu.me",
      "uri":"/contact",
      "headers":{
         "Sec-Websocket-Key":[
            "6+aYCXzXqLVLWpO7rv3S7Q=="
         ],
         "Sec-Websocket-Version":[
            "13"
         ],
         "Upgrade":[
            "websocket"
         ],
         "User-Agent":[
            "Go-http-client/1.1"
         ],
         "Connection":[
            "Upgrade"
         ]
      },
      "tls":{
         "resumed":false,
         "version":772,
         "cipher_suite":4865,
         "proto":"http/1.1",
         "server_name":"v.dingyu.me"
      }
   },
   "user_id":"",
   "duration":1.082072341,
   "size":0,
   "status":0,
   "resp_headers":{
      "Server":[
         "Caddy"
      ],
      "Alt-Svc":[
         "h3=\":443\"; ma=2592000"
      ],
      "Connection":[
         "Upgrade"
      ],
      "Sec-Websocket-Accept":[
         "nuPVZTIVT4AqyTXk9ahp7jnp/Ns="
      ],
      "Upgrade":[
         "websocket"
      ]
   }
}

5. What I already tried:

I tried adding header_up Host {upstream_hostport}, header_up Host {http.reverse_proxy.upstream.host} and header_up Host {http.reverse_proxy.upstream.hostport} to reverse_proxy but nothing worked.

I tried Nginx which can return the correct status and size from the upstream proxy server so I think the upstream settings are fine.

I tried Caddy → (reverse proxy) → Nginx → (reverse proxy) → the upstream proxy server. Strangely this time it returned 0 both size and status.

6. Links to relevant resources:

I have read this thread a few times and tried everything I could think of but got nowhere.

This is normal for websocket requests, because it’s a long-running request. Since the connection gets upgraded, technically there’s no size or status to report.

There is an open PR to make it report the size, but we’re not sure if we’ll merge it because it has some caveats

1 Like

What caveats? I have been running caddy with this patch for months and haven’t noticed any error. The patch has been upgraded and will correctly report size when using returned bufio.Writer and net.Conn.

1 Like

I haven’t gotten around to reviewing it yet (sorry :disappointed:) but I am leaning toward accepting it.

Can you remind me what the caveats are?

We discussed it on Slack. It moves the log to the end of the connection, instead of at the start. So IMO, it makes it invisible that a websocket connection is currently in progress from the perspective of the logs (unless you turn on debug logs I guess, since reverse_proxy will log)

1 Like

But aren’t all http loggged at the end when servehttp returns, that’s also true for large file downloads.

1 Like

Thank you.

@WeidiDeng 's PR indeed returns the correct size, which is super helpful for me.
It however always returns 101 as the status code but I can live with that.

101 is the status code for websocket, there is no alternative status code for websocket.

1 Like

Yeah, that’s true. I think we can emit debug logs if admins want to know when a connection is upgraded to websocket before the connection closes. (We might already do this, I don’t recall.)

I think in this case it’s just a little tricky to determine when the HTTP request ends. Usually we write logs after each request finishes, not after the whole connection is done. Connection upgrades kind of do both (they end the HTTP request and then own the rest of the connection) which is why I haven’t merged your PR yet. I think I just need a good way to justify logging the request well after the request finishes…

Perhaps it can be done in response recorder hijack method. Just emit the log when hijack is called and emit different log when servehttp returns and hijack is called?