net/http: add GODEBUG=http1debug

bradfitz commented 7 years ago

The GODEBUG knob for http2 debugging (e.g. GODEBUG=http2debug=2) has proven to be very useful and popular.

Unfortunately it only works for HTTP/2.

There is code in the net/http package to do a similar thing for HTTP/1, but it's not accessible via an environment variable. Should we make it accessible with GODEBUG=http1debug=...?

rsc commented 7 years ago

Seems OK to me (Go1.9Early)

gopherbot commented 7 years ago

CL https://golang.org/cl/36548 mentions this issue.

Sajmani commented 7 years ago

I've updated the commit message in my CL with sample debug output. This is a first cut; I'm happy to adjust the output, content, leveling, etc. as needed.

bradfitz commented 7 years ago

One of the nice things about http2 is that it has a per-request "streamid" which shows up on all request and response lines, making it easy to line things up. Unfortunately, the stream id is unique only to a connection, though, so it's not a unique identifier for debugging, but generally works.

What I'd like to see for http1 is for each conn to get its own incrementing number, and each request on a conn to also get its own incrementing number, and then make sure each line about data going out or in for a request says either the relevant conn=%d or conn=%d,req=%d pair.

Sajmani commented 7 years ago

Doc for output discussion: https://docs.google.com/document/d/10FdNIgIjIyv9zfwrC7jSfdgjuWAHs6MdIrqaiz32vJU/edit#

Sajmani commented 7 years ago

Unfortunately I've run out of time to contribute to this issue, so unassigning myself.

meirf commented 7 years ago

Requirements gleaned from this issue and the CL herein:

Enable debugging via environment variables GODEBUG=http1debug=1 (connections) and GODEBUG=http1debug=2 (connections and requests)
"make sure each line about data going out or in for a request says either the relevant conn=%d or conn=%d,req=%d pair"
Log at the wire level, i.e. before the data has been interpreted by go.

Question: @bradfitz comments in the CL:

... "type loggingConn" in server.go I wonder if we should just use that instead, extended a bit. When debugging is enabled, we wrap things in *loggingConn and extend it to tell it the state of things ...

Are you saying logging should be done on the server side or that we should use a similar paradigm on the client where we wrap things in a logging connection? HTTP/2 debug logging seems to be implemented on the client side only so the latter seems plausible. Or perhaps the former is correct since you're saying there's no other way to achieve requirement 3.

(I would like to work on this.)

bradfitz commented 7 years ago

Let's start with just http1 Transport (client) logging, and not server logging. I just meant that a net.Conn wrapper type (like loggingConn) might be helpful in implementing this. But feel free to ignore that too. Do whatever's easiest implementation-wise.

meirf commented 7 years ago

I've had a couple speed bumps (transport code took a while to digest/accounting for pipelining when determining request id). Hopefully will have a first draft within a week.

gopherbot commented 7 years ago

CL https://golang.org/cl/43534 mentions this issue.