Saturday, March 23, 2024

Golang gripes: net/http doesn't log certain errors

I just spent like 40 minutes trying to fix an issue where Cloudflare TLS proxying was working for all TLS ports (e.g. port 2087, 2083 and so on) EXCEPT for port 443. That was driving me nuts.

Context: So I had this Origin Rule which says that when request hostname is a certain value, change destination port to 12345.

Of course, since my server serves TLS on that port, this means normal HTTP traffic to that port won't work. So if you tried visiting that site on plain HTTP, you will get "Client sent an HTTP request to an HTTPS server." which makes sense and is fine.

But here's the problem: If you tried accessing https://mywebsite.com:2083 from a web browser, it would work just fine, but if you tried visiting https://mywebsite.com:443 from a web browser, then you would see error 400.

So, port 443 was special, somehow. But where was the special-case handling for port 443? Was it in Cloudflare or was it in my server? I had a separate process running on my server that received traffic on port 443, but in theory it shouldn't have mattered because the Origin Rule should have been rewriting the destination port to 12345, so none of the traffic would ever even hit port 443 on my server. 

Anyway, I killed that process (that was listening on port 443)  and it made no difference. 

I also killed my process that was listening on port 12345, and that DID make a difference - instead of returning 400, Cloudflare began returning the "server is down" error as soon as I killed the process listening on port 12345. Thus, I know the Origin Rule is working and that all traffic - including traffic to port 443 - was being redirected to port 12345.

So then I thought: Okay, maybe there was some kind of TLS handshake error on my server that only shows up when users connect to the Cloudflare proxy via port 443.

But I was literally not seeing any TLS handshake errors on my server process. But if I killed my server process then Cloudflare would return the "server is down" error message, which means that Cloudflare MUST HAVE BEEN GETTING SOME KIND OF RESPONSE FROM my server process, which resulted in a 400. Later on, when I restarted the server, the error message changed to some bad SSL encryption error - the fact that I couldn't get a useful or even consistent error message drove me crazy. I began Googling for this: I searched for Cloudflare origin rule fails error 400 but only on port 443 - no useful results.

But then for some reason, I thought of using curl instead of my web browser. And hey, whaddayaknow? Instead of returning error 400, curl actually returned an useful error message: "Client sent an HTTP request to an HTTPS server."

This error message shows up when I try to connect to https://mywebsite.com:443 but NOT when I try to connect to https://mywebsite.com:2083

This immediately gave me the hint that Cloudflare was decrypting the traffic. When TLS traffic goes to a Cloudflare proxy on port 443, Cloudflare decrypts it and forwards it to my server IN PLAINTEXT HTTP, BUT ONLY WHEN THE CLIENT SENT IT TO PORT 443 ON THE PROXY.

Anyway, so I simply switched my TLS setting on Cloudflare from Flexible to Full. And that made the error go away - now port 443 works just the same as port 2083.

Thinking about it, it kinda makes sense. Cloudflare does explicitly say that they decrypt TLS traffic and send it to your server via plain HTTP on the Flexible setting. But the fact that this DOESN'T happen for port 2083 is what threw me - Cloudflare didn't explicitly say that their TLS decryption ONLY happens for port 443 and not for the other TLS ports.

Anyway, I'm not sure what I learned from this, but I guess I understand how the Cloudflare Flexible vs Full encryption works a little bit better now.

Also, relevant meme:



EDIT: It now strikes me that the REAL problem was the lack of debugging error messages from the ListenAndServeTLS function.

It seems that by default, it only prints some TLS handshake errors. 

Not sure why it doesn't print anything when it responds with that "Client sent an HTTP request to an HTTPS server." error. 

I need to figure out how to make it log those errors.

I added logging in the handler function but the handler clearly wasn't getting called.

EDIT: It seems that there is no way to intercept those errors at present: https://stackoverflow.com/questions/45802492/how-can-i-customize-http-400-responses-for-parse-errors/45802962#45802962

See:

https://github.com/golang/go/blob/c2c4a32f9e57ac9f7102deeba8273bcd2b205d3c/src/net/http/server.go#L1927

 

I'm surprised that it still isn't possible to log such errors, even despite issues being raised about this from as far back as 2016:

https://github.com/golang/go/issues/12745 

 

I guess this is one of my gripes about Go's net/http - that it doesn't log some 400 errors and there is no way for the user to add logging for those errors.

 

EDIT: Actually, fuck it. I'll just make a PR for this and see what they say.

No comments:

Post a Comment