reverseproxy: Wait for both ends of websocket connections to close

[WeidiDeng]

Related to 6173.

Websockets will show size 0 even if there are data written because the hijacked connection implements both WriterTo and ReaderFrom, and stats are only updated when the copying is done.

A log entry is like this:

{"level":"info","ts":1710675070.8584435,"logger":"http.log.access","msg":"handled request","request":{"remote_ip":"111.181.20.83","remote_port":"12070","client_ip":"111.181.20.83","proto":"HTTP/1.1","method":"GET","host":"example.com","uri":"/random_path","headers":{"Accept-Language":["zh-CN,zh;q=0.9,en-US;q=0.8,en;q=0.7,zh-TW;q=0.6"],"Connection":["Upgrade"],"Pragma":["no-cache"],"Cache-Control":["no-cache"],"User-Agent":["Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"],"Upgrade":["websocket"],"Accept-Encoding":["gzip, deflate, br, zstd"],"Sec-Websocket-Extensions":["permessage-deflate; client_max_window_bits"],"Origin":["null"],"Sec-Websocket-Version":["13"],"Sec-Websocket-Key":["/8yHPgBZyvYC8CD39WeZRA=="]},"tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"http/1.1","server_name":"example.com"}},"bytes_read":3092,"user_id":"","duration":4.455078925,"size":0,"status":101,"resp_headers":{"Upgrade":["websocket"],"Connection":["Upgrade"],"Sec-Websocket-Accept":["GZiqDfESG0QwR+aK3v0Cqop5BR4="],"Server":["Caddy"],"Alt-Svc":["h3=\":63933\"; ma=2592000,h3=\":443\"; ma=2592000"],"Strict-Transport-Security":["max-age=31536000;"]}}

Wait outside the function so connection cleanup is not affected.

[francislavoie]

LGTM, but concurrency stuff like this isn't one of my strengths. Maybe @mholt should take a look before merging.

[mholt]

The logic looks sound. But before I totally approve it, I have a concern about the implications of blocking in finalizeResponse(). I think this blocks the entire HTTP request. (But just this request.) Wouldn't that be problematic?

[mholt]

This blocks -- not sure if that's actually a good idea?

[WeidiDeng]

This adds a little bit of delay so that statistics are properly updated. Both ends of the connection are closed when handleUpgradeResponse returns. If this blocks, go has a serious issue where net.Conn.Close doesn't unblock Read or Write.

[mholt]

Ah, so you're saying that h.handleUpgradeResponse() was already blocking, and wg.Wait() waits until the actual conns are Close()ed, but otherwise it's basically the same amount of blocking.

In that case, this LGTM.

I just couldn't remember if this goroutine was returning while the hijacked connection kept running to do its copy, or if we blocked in there, but it looks like handleUpgradeResponse has a select that blocks at least for most of the time.

So yeah, if this patch works, and doesn't block much longer, then I think we can merge it.

Thanks!!

[mholt]

To clarify, does the size still log as 0, with this patch?

[WeidiDeng]

Before this patch, sometimes size logs as 0. After this, none does.