proposal: net/http: Transport tracing hooks

[krishna15898]

The current HTTP client instrumentation library httptrace tracks the life cycle of a single request with hooks present at different stages in the outgoing HTTP Request's journey. This limits the use of httptrace in many ways which we believe could be solved by having an instrumentation library which works at a “transport level”. This means instead of placing hooks in the request’s context, one defines these hooks for the Transport. This would also support the current functionality of httptrace.

Proposal

Here is a basic example of the proposed change. Let’s take the example of the GotConn hook in httptrace.ClientTrace. The current method for adding and using this hook is

req, _ := http.NewRequest("GET", "http://example.com", nil)
trace := &httptrace.ClientTrace{
	GotConn: func(connInfo httptrace.GotConnInfo) {
		fmt.Printf("Got Conn: %+v\n", connInfo)
	},
}
req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))
resp, _ := http.DefaultClient.Do(req)

We propose restructuring http.Transport to contain the hooks instead of ClientTrace. Transport contains a new struct Stats which contains the hooks and other data like counts of idle/active connections and waiting requests.

type Stats struct {
	GotConn func(connInfo GotConnInfo)
        
	// among other hooks and data
}

type Transport struct {
	Stats *Stats
	// and all other fields to stay the same
}

And one would make a request in the following way:-

req, _ := http.NewRequest("GET", "http://example.com", nil)
stats := &http.Stats{
	GotConn: func(connInfo http.GotConnInfo) {
		fmt.Printf("Got Conn: %+v\n", connInfo)
	},
}
transport := http.Transport{Stats: stats}
client := http.Client{Transport: transport}
resp, _ := client.Do(req)

Within Transport, when a request has received a connection, the GotConn hook would run as below. This is in contrast to extracting ClientTrace from the Request’s context and using its hooks.

func (t *Transport) methodName() {
    // a connection has been delivered to the request
    if t.Stats.GotConn != nil {
	  t.Stats.GotConn(GotConnInfo{…})
    }
…
}

The above basic proposal can be extended to all the hooks already present in httptrace. We propose the following additional hooks to be added to http.Stats above:-

1. IdleConnWaitIn, IdleConnWaitOut, ConnsPerHostWaitIn, and ConnsPerHostWaitOut - These hooks will be called when a request (wantConn) enters/exits the idleConnWait and connsPerHostWait queues. For example -

type IdleConnWaitInInfo struct {
    ConnectMethodKey string
    EventTime time.Time
    RemainingInQueue int
}
IdleConnWaitIn(info IdleConnWaitInInfo)

These hooks could take as parameters connectMethodKey of the queue, time of entry/exit, and the number of remaining active wantConns in the queues after the event (an active wantConnis one which has not been delivered a persistConn yet and its context has not exceeded its deadline. Note that this is not equal to the number of wantConns in the queues as some of them could have been delivered a persistConn in another goroutine or their context could have exceeded its deadline.) The IdleConnWaitOut and ConnsPerHostWaitOut hooks could also have an extra parameter error which is nil if the wantConns were removed from the queues because they were successfully delivered a persistConn. If not, error gives the reason for their removal from the queues, for example, if the request was cancelled or its context deadline expired.

2. IdleConnIn, IdleConnOut - IdleConnIn serves the same purpose as the existing PutIdleConn hook from the httptrace package. IdleConnOut is the related hook for when a connection is removed from the idleConn queue. These hooks could take as parameters connectMethodKey of the queue and time of entry/exit. IdleConnOut could take an additional parameter error which is nil if the idle connection was delivered to a wantConn. If not, it represents the reason it was removed from the queue, for example, being too old to be reused.

3. ConnReused - This hook is called after serving a request, if the connection is directly delivered to a wantConn waiting in idleConnWait instead of being added to the idleConn queue. Currently, there is only one hook related to connections, PutIdleConn, which records the latter. ConnReused could take as parameters connectMethodKey of the persistConn (cacheKey field) and time of delivery.

4. MaxIdleConnsHit, MaxIdleConnsPerHost, MaxConnsPerHostHit - When configured capacities of queues like MaxIdleConns, MaxIdleConnsPerHost, MaxConnsPerHost are hit, these hooks should be able to take a "snapshot of the state" of the HTTP Client. They could take as parameters the counts of active wantConns in idleConnWait and connsPerHostWait queues for each connectMethodKey and the length of idleConn queues for each connectMethodKey. They could also take as parameters the state of all active connections like their TCP connection state( this is an optional feature for which we may have to make external calls). These hooks are useful for the user to understand where their server's bottlenecks or the server they are connecting to.

Note: I have already implemented this during an internship.

[seankhliao]

cc @neild

[neild]

This proposal is for two unrelated things: A way to run per-request trace hooks for every request on an http.Transport, and a new set of per-request trace hooks that seem largely redundant with httptrace.ClientTrace.

You need to separate these parts. Do you want to propose a way to run ClientTrace hooks for every request on a connection? Or new ClientTrace hooks? Or hooks which aren't associated with requests at all?

We don't want to have two entirely different per-request tracing mechanisms. Any new tracing hooks need to fit in with what exists already.

[krishna15898]

Correct, this proposal was to introduce trace hooks that would run for all request (and connection) activities on an http.Transport. The hooks I have mentioned above are the new ones that are not already present in httptrace.ClientTrace but the proposal intends to continue the use of already existing per-request hooks in ClientTrace as well.

So basically I want to propose a way to run ClientTrace + other new hooks for all activities of the http.Transport with a single mechanism. These activities could be related to requests (as in existing hooks of ClientTrace) or connections (not supported by ClientTrace).

But I guess it is not possible to replace httptrace with the new mechanism as it is a part of the go library. And adding the remaining new hooks with an entirely new mechanism would leave us with two different mechanisms as you mentioned.

Parts of the proposal that still fits into what exists already are per-request hooks that can be added to ClientTrace which are in point 1. in the original post, i.e. IdleConnWaitIn, IdleConnWaitOut, ConnsPerHostWaitIn, and ConnsPerHostWaitOut which would

1. Add more information about the stages of a request's journey before it gets a connection - what were the blockers for the request from getting a connection right away
2. If the request does not get a connection, would give information as to why - whether its context exceeded its deadline or the request was canceled, etc. Currently, if a request does not get a connection, one needs to use the error from Transport.RoundTrip

PS. This is not a part of this proposal but the above hooks would also enable us to track the request's waiting time in i) getting a connection, ii) idleConnWait, and iii) connsPerHostWait. This could be done by adding a field entryTime to wantConn similar to persistConn.idleAt which gives the information of GotConnInfo.IdleTime.

[krishna15898]

@neild do the features mentioned later which adhere to the existing httptrace look worth adding to the library?

[rsc]

This proposal has been added to the active column of the proposals project
and will now be reviewed at the weekly proposal review meetings.
— rsc for the proposal review group

[rsc]

@neild any thoughts on the most recent messages?

[neild]

A mechanism to run the existing ClientTrace hooks for every request might be reasonable, although you can do this today by wrapping the Transport with a type that implements RoundTrip and adds the trace hooks to the request context.

The proposed new hooks (IdleConnIn, IdleConnOut, etc.) all revolve around connection lifetime management. These don't make sense as request-scoped hooks, since connection lifetimes span multiple requests and may experience events outside the context of any request. (For example, we might close an idle connection because no requests have used it in a sufficiently long time.)

It would be reasonable to provide more detailed tracing about connection lifetimes. I'd want to make sure that whatever trace events we support work for HTTP/1 and HTTP/2, as well as potentially HTTP/3 at some time in the future.

Before making any significant changes to HTTP tracing, I'd want to understand how this might interact with structured logging. If #56345 is accepted, we'll probably want to consider adding structured logging events to net/http. Would this supersede any other tracing mechanism, or are tracing and structured logging orthogonal?

[ChrisHines]

Would this supersede any other tracing mechanism, or are tracing and structured logging orthogonal?

In my opinion, the httptrace package and similar facilities are an enabler for structured logging. The events exposed can be implemented to write log events, or other things.

I spoke about this at the end of my Capital Go 2017 talk "Go Kit Log Package"

• video: https://youtu.be/ojhFQNgyZO4
• slides: https://speakerdeck.com/chrishines/go-kit-log-package).

[AndrewHarrisSPU]

are tracing and structured logging orthogonal?

ISTM they are not entirely orthogonal. Tracing accumulates structure, while logging takes a snapshot of structure, but the snapshot might not be computed at one precise moment in time and #56345 is amenable to a few different ways of doing things here - there are tradeoffs.