gitproto: add GITSYNC_HTTP_TRACE env var for connection diagnostics

9ac1a57→main·Soph·1mo ago·1 file·+69 added/-0 removed

Wires net/http/httptrace into RequestInfoRefs and PostRPCStreamBody, gated on GITSYNC_HTTP_TRACE so production runs pay zero overhead. When enabled, emits per-request connection lifecycle events (GetConn, GotConn with Reused/IdleTime, ConnectStart/Done, TLSHandshake*, WroteRequest, PutIdleConn) to stderr.

Motivated by diagnosing stale keep-alive pool connections against third-party Git HTTPS hosts (CDN edges, hosted git providers) that close idle TLS sockets faster than Go's transport assumes. Those failures surface as "use of closed network connection" on the next POST with no other signal — httptrace makes the pool reuse and idle duration explicit.

Sessions

d0bad48c086bView transcript

Changes

• internal/gitproto
  • Msmarthttp.go+69

// current git-sync stats phase for round-trip tracking.
const StatsPhaseHeader = "X-Git-Sync-Stats-Phase"

// HTTPTraceEnv enables verbose httptrace logging to stderr when set to any
// non-empty value other than "0" or "false". Diagnoses connection-pool
// behavior against hosts that close idle keep-alive connections more
// aggressively than Go's transport assumes (CDN edges, some hosted git
// providers) — a stale pooled connection surfaces as "use of closed network
// connection" on the next POST. Off by default; zero overhead unless set.
const HTTPTraceEnv = "GITSYNC_HTTP_TRACE"

func httpTraceEnabled() bool {
    v := os.Getenv(HTTPTraceEnv)
    if v == "" {
        return false
    }
    switch strings.ToLower(v) {
    case "0", "false", "no", "off":
        return false
    }
    return true
}

// withHTTPTrace returns ctx with a ClientTrace that logs connection lifecycle
// events for one request to stderr. label is prepended to every line so
// concurrent or interleaved requests stay readable. Returns ctx unchanged
// when GITSYNC_HTTP_TRACE is not enabled.
func withHTTPTrace(ctx context.Context, label string) context.Context {
    if !httpTraceEnabled() {
        return ctx
    }
    trace := &httptrace.ClientTrace{
        GetConn: func(hostPort string) {
            fmt.Fprintf(os.Stderr, "[httptrace] %s GetConn %s\n", label, hostPort)
        },
        GotConn: func(info httptrace.GotConnInfo) {
            fmt.Fprintf(os.Stderr,
                "[httptrace] %s GotConn reused=%v wasIdle=%v idle=%s local=%s remote=%s\n",
                label, info.Reused, info.WasIdle, info.IdleTime,
                info.Conn.LocalAddr(), info.Conn.RemoteAddr())
        },
        PutIdleConn: func(err error) {
            if err != nil {
                fmt.Fprintf(os.Stderr, "[httptrace] %s PutIdleConn err=%v\n", label, err)
            } else {
                fmt.Fprintf(os.Stderr, "[httptrace] %s PutIdleConn ok\n", label)
            }
        },
        ConnectStart: func(network, addr string) {
            fmt.Fprintf(os.Stderr, "[httptrace] %s ConnectStart %s %s\n", label, network, addr)
        },
        ConnectDone: func(network, addr string, err error) {
            fmt.Fprintf(os.Stderr, "[httptrace] %s ConnectDone %s %s err=%v\n", label, network, addr, err)
        },
        TLSHandshakeStart: func() {
            fmt.Fprintf(os.Stderr, "[httptrace] %s TLSHandshakeStart\n", label)
        },
        TLSHandshakeDone: func(state tls.ConnectionState, err error) {
            fmt.Fprintf(os.Stderr, "[httptrace] %s TLSHandshakeDone resumed=%v err=%v\n",
                label, state.DidResume, err)
        },
        WroteRequest: func(info httptrace.WroteRequestInfo) {
            fmt.Fprintf(os.Stderr, "[httptrace] %s WroteRequest err=%v\n", label, info.Err)
        },
    }
    return httptrace.WithClientTrace(ctx, trace)
}

// RequestInfoRefs fetches /info/refs for the given service.
func (c *HTTPConn) RequestInfoRefs(ctx context.Context, service string, gitProtocol string) ([]byte, error) {
    reqURL := fmt.Sprintf("%s/info/refs?service=%s", c.EndpointURL.String(), service)
    ctx = withHTTPTrace(ctx, "GET "+service+"/info/refs")
    req, err := http.NewRequestWithContext(ctx, http.MethodGet, reqURL, nil)
    if err != nil {
        return nil, fmt.Errorf("create info-refs request: %w", err)
    }
}

// Caller must close the returned ReadCloser.
func (c *HTTPConn) PostRPCStreamBody(ctx context.Context, service string, body io.Reader, v2 bool, phase string) (io.ReadCloser, error) {
    reqURL := fmt.Sprintf("%s/%s", c.EndpointURL.String(), service)
    ctx = withHTTPTrace(ctx, "POST "+service)
    req, err := http.NewRequestWithContext(ctx, http.MethodPost, reqURL, body)
    if err != nil {
        return nil, fmt.Errorf("create RPC request: %w", err)
    }
}