From e6d29f76488a880c9f279f5c05d6988e40a72a99 Mon Sep 17 00:00:00 2001 From: Josh Deprez Date: Wed, 25 Sep 2024 14:07:11 +1000 Subject: [PATCH] Refactor various agent HTTP clients --- agent/ecs_meta_data.go | 16 +- agent/tags.go | 2 +- api/client.go | 224 ++------------------ clicommand/artifact_download.go | 4 + clicommand/artifact_upload.go | 14 +- {api => internal/agenthttp}/auth.go | 22 +- internal/agenthttp/client.go | 136 ++++++++++++ internal/agenthttp/do.go | 186 ++++++++++++++++ internal/artifact/artifactory_downloader.go | 11 +- internal/artifact/artifactory_uploader.go | 20 +- internal/artifact/azure_blob_downloader.go | 1 + internal/artifact/download.go | 18 +- internal/artifact/downloader.go | 16 +- internal/artifact/form_uploader.go | 86 +++----- internal/artifact/gs_downloader.go | 4 +- internal/artifact/gs_uploader.go | 20 +- internal/artifact/s3_downloader.go | 10 +- internal/artifact/s3_uploader.go | 3 - internal/artifact/uploader.go | 24 ++- internal/bkgql/client.go | 21 +- 20 files changed, 485 insertions(+), 353 deletions(-) rename {api => internal/agenthttp}/auth.go (70%) create mode 100644 internal/agenthttp/client.go create mode 100644 internal/agenthttp/do.go diff --git a/agent/ecs_meta_data.go b/agent/ecs_meta_data.go index ad969b048e..3a19fb9151 100644 --- a/agent/ecs_meta_data.go +++ b/agent/ecs_meta_data.go @@ -3,18 +3,24 @@ package agent import ( "context" "fmt" - metadata "github.com/brunoscheufler/aws-ecs-metadata-go" - "net/http" "strconv" + + metadata "github.com/brunoscheufler/aws-ecs-metadata-go" + "github.com/buildkite/agent/v3/internal/agenthttp" ) type ECSMetadata struct { + DisableHTTP2 bool } -func (e ECSMetadata) Get() (map[string]string, error) { +func (e ECSMetadata) Get(ctx context.Context) (map[string]string, error) { metaData := make(map[string]string) - taskMeta, err := metadata.GetTask(context.Background(), &http.Client{}) + client := agenthttp.NewClient( + agenthttp.WithAllowHTTP2(!e.DisableHTTP2), + ) + + taskMeta, err := metadata.GetTask(ctx, client) if err != nil { return metaData, err } @@ -46,7 +52,7 @@ func (e ECSMetadata) Get() (map[string]string, error) { return metaData, fmt.Errorf("ecs metadata returned unknown type %T", m) } - containerMeta, err := metadata.GetContainer(context.Background(), &http.Client{}) + containerMeta, err := metadata.GetContainer(ctx, client) if err != nil { return metaData, err } diff --git a/agent/tags.go b/agent/tags.go index f7dd535292..eb58e01fbf 100644 --- a/agent/tags.go +++ b/agent/tags.go @@ -49,7 +49,7 @@ func FetchTags(ctx context.Context, l logger.Logger, conf FetchTagsConfig) []str return EC2Tags{}.Get() }, ecsMetaDataDefault: func() (map[string]string, error) { - return ECSMetadata{}.Get() + return ECSMetadata{}.Get(ctx) }, gcpMetaDataDefault: func() (map[string]string, error) { return GCPMetaData{}.Get() diff --git a/api/client.go b/api/client.go index 13c891c941..9803437b2d 100644 --- a/api/client.go +++ b/api/client.go @@ -11,18 +11,15 @@ import ( "fmt" "io" "net/http" - "net/http/httptrace" - "net/http/httputil" - "net/textproto" "net/url" "reflect" "strconv" "strings" "time" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/logger" "github.com/google/go-querystring/query" - "golang.org/x/net/http2" ) const ( @@ -80,60 +77,22 @@ func NewClient(l logger.Logger, conf Config) *Client { conf.UserAgent = defaultUserAgent } - httpClient := conf.HTTPClient - - if httpClient != nil { + if conf.HTTPClient != nil { return &Client{ logger: l, - client: httpClient, + client: conf.HTTPClient, conf: conf, } } - // Base any modifications on the default transport. - transport := http.DefaultTransport.(*http.Transport).Clone() - // Allow override of TLSConfig. This must be set prior to calling - // http2.ConfigureTransports. - if conf.TLSConfig != nil { - transport.TLSClientConfig = conf.TLSConfig - } - - if conf.DisableHTTP2 { - transport.TLSNextProto = make(map[string]func(string, *tls.Conn) http.RoundTripper) - // The default TLSClientConfig has h2 in NextProtos, so the - // negotiated TLS connection will assume h2 support. - // see https://github.com/golang/go/issues/50571 - transport.TLSClientConfig.NextProtos = []string{"http/1.1"} - } else { - // There is a bug in http2 on Linux regarding using dead connections. - // This is a workaround. See https://github.com/golang/go/issues/59690 - // - // Note that http2.ConfigureTransports alters its argument in order to - // supply http2 functionality, and the http2.Transport does not support - // HTTP/1.1 as a protocol, so we get slightly odd-looking code where - // we use `transport` later on instead of the just-returned `tr2`. - // tr2 is needed merely to configure the http2 option. - tr2, err := http2.ConfigureTransports(transport) - if err != nil { - l.Warn("Failed to configure HTTP2 transports: %v", err) - } - if tr2 != nil { - tr2.ReadIdleTimeout = 30 * time.Second - } - } - - httpClient = &http.Client{ - Timeout: 60 * time.Second, - Transport: &authenticatedTransport{ - Token: conf.Token, - Delegate: transport, - }, - } - return &Client{ logger: l, - client: httpClient, - conf: conf, + client: agenthttp.NewClient( + agenthttp.WithAuthToken(conf.Token), + agenthttp.WithAllowHTTP2(!conf.DisableHTTP2), + agenthttp.WithTLSConfig(conf.TLSConfig), + ), + conf: conf, } } @@ -260,73 +219,20 @@ func newResponse(r *http.Response) *Response { // interface, the raw response body will be written to v, without attempting to // first decode it. func (c *Client) doRequest(req *http.Request, v any) (*Response, error) { - var err error - - if c.conf.DebugHTTP { - // If the request is a multi-part form, then it's probably a - // file upload, in which case we don't want to spewing out the - // file contents into the debug log (especially if it's been - // gzipped) - var requestDump []byte - if strings.Contains(req.Header.Get("Content-Type"), "multipart/form-data") { - requestDump, err = httputil.DumpRequestOut(req, false) - } else { - requestDump, err = httputil.DumpRequestOut(req, true) - } - - if err != nil { - c.logger.Debug("ERR: %s\n%s", err, string(requestDump)) - } else { - c.logger.Debug("%s", string(requestDump)) - } - } - - tracer := &tracer{Logger: c.logger} - if c.conf.TraceHTTP { - // Inject a custom http tracer - req = traceHTTPRequest(req, tracer) - tracer.Start() - } - - ts := time.Now() - - c.logger.Debug("%s %s", req.Method, req.URL) - - resp, err := c.client.Do(req) + resp, err := agenthttp.Do(c.logger, c.client, req, + agenthttp.WithDebugHTTP(c.conf.DebugHTTP), + agenthttp.WithTraceHTTP(c.conf.TraceHTTP), + ) if err != nil { - if c.conf.TraceHTTP { - tracer.EmitTraceToLog(logger.ERROR) - } return nil, err } - - c.logger.WithFields( - logger.StringField("proto", resp.Proto), - logger.IntField("status", resp.StatusCode), - logger.DurationField("Δ", time.Since(ts)), - ).Debug("↳ %s %s", req.Method, req.URL) - defer resp.Body.Close() defer io.Copy(io.Discard, resp.Body) response := newResponse(resp) - if c.conf.DebugHTTP { - responseDump, err := httputil.DumpResponse(resp, true) - if err != nil { - c.logger.Debug("\nERR: %s\n%s", err, string(responseDump)) - } else { - c.logger.Debug("\n%s", string(responseDump)) - } - } - - if c.conf.TraceHTTP { - tracer.EmitTraceToLog(logger.DEBUG) - } - - err = checkResponse(resp) - if err != nil { + if err := checkResponse(resp); err != nil { // even though there was an error, we still return the response // in case the caller wants to inspect it further return response, err @@ -346,107 +252,7 @@ func (c *Client) doRequest(req *http.Request, v any) (*Response, error) { } } - return response, err -} - -type traceEvent struct { - event string - since time.Duration -} - -type tracer struct { - startTime time.Time - logger.Logger -} - -func (t *tracer) Start() { - t.startTime = time.Now() -} - -func (t *tracer) LogTiming(event string) { - t.Logger = t.Logger.WithFields(logger.DurationField(event, time.Since(t.startTime))) -} - -func (t *tracer) LogField(key, value string) { - t.Logger = t.Logger.WithFields(logger.StringField(key, value)) -} - -func (t *tracer) LogDuration(event string, d time.Duration) { - t.Logger = t.Logger.WithFields(logger.DurationField(event, d)) -} - -// Currently logger.Logger doesn't give us a way to set the level we want to emit logs at dynamically -func (t *tracer) EmitTraceToLog(level logger.Level) { - msg := "HTTP Timing Trace" - switch level { - case logger.DEBUG: - t.Debug(msg) - case logger.INFO: - t.Info(msg) - case logger.WARN: - t.Warn(msg) - case logger.ERROR: - t.Error(msg) - } -} - -func traceHTTPRequest(req *http.Request, t *tracer) *http.Request { - trace := &httptrace.ClientTrace{ - GetConn: func(hostPort string) { - t.LogField("hostPort", hostPort) - t.LogTiming("getConn") - }, - GotConn: func(info httptrace.GotConnInfo) { - t.LogTiming("gotConn") - t.LogField("reused", strconv.FormatBool(info.Reused)) - t.LogField("idle", strconv.FormatBool(info.WasIdle)) - t.LogDuration("idleTime", info.IdleTime) - t.LogField("localAddr", info.Conn.LocalAddr().String()) - }, - PutIdleConn: func(err error) { - t.LogTiming("putIdleConn") - if err != nil { - t.LogField("putIdleConnectionError", err.Error()) - } - }, - GotFirstResponseByte: func() { - t.LogTiming("gotFirstResponseByte") - }, - Got1xxResponse: func(code int, header textproto.MIMEHeader) error { - t.LogTiming("got1xxResponse") - return nil - }, - DNSStart: func(_ httptrace.DNSStartInfo) { - t.LogTiming("dnsStart") - }, - DNSDone: func(_ httptrace.DNSDoneInfo) { - t.LogTiming("dnsDone") - }, - ConnectStart: func(network, addr string) { - t.LogTiming(fmt.Sprintf("connectStart.%s.%s", network, addr)) - }, - ConnectDone: func(network, addr string, _ error) { - t.LogTiming(fmt.Sprintf("connectDone.%s.%s", network, addr)) - }, - TLSHandshakeStart: func() { - t.LogTiming("tlsHandshakeStart") - }, - TLSHandshakeDone: func(_ tls.ConnectionState, _ error) { - t.LogTiming("tlsHandshakeDone") - }, - WroteHeaders: func() { - t.LogTiming("wroteHeaders") - }, - WroteRequest: func(_ httptrace.WroteRequestInfo) { - t.LogTiming("wroteRequest") - }, - } - - req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace)) - - t.LogField("uri", req.URL.String()) - t.LogField("method", req.Method) - return req + return response, nil } // ErrorResponse provides a message. diff --git a/clicommand/artifact_download.go b/clicommand/artifact_download.go index d6ecdc70dc..c865e3e683 100644 --- a/clicommand/artifact_download.go +++ b/clicommand/artifact_download.go @@ -62,6 +62,7 @@ type ArtifactDownloadConfig struct { // API config DebugHTTP bool `cli:"debug-http"` + TraceHTTP bool `cli:"trace-http"` AgentAccessToken string `cli:"agent-access-token" validate:"required"` Endpoint string `cli:"endpoint" validate:"required"` NoHTTP2 bool `cli:"no-http2"` @@ -94,6 +95,7 @@ var ArtifactDownloadCommand = cli.Command{ EndpointFlag, NoHTTP2Flag, DebugHTTPFlag, + TraceHTTPFlag, // Global flags NoColorFlag, @@ -118,6 +120,8 @@ var ArtifactDownloadCommand = cli.Command{ Step: cfg.Step, IncludeRetriedJobs: cfg.IncludeRetriedJobs, DebugHTTP: cfg.DebugHTTP, + TraceHTTP: cfg.TraceHTTP, + DisableHTTP2: cfg.NoHTTP2, }) // Download the artifacts diff --git a/clicommand/artifact_upload.go b/clicommand/artifact_upload.go index 73e3f1709b..1ee5c4c07c 100644 --- a/clicommand/artifact_upload.go +++ b/clicommand/artifact_upload.go @@ -81,6 +81,7 @@ type ArtifactUploadConfig struct { // API config DebugHTTP bool `cli:"debug-http"` + TraceHTTP bool `cli:"trace-http"` AgentAccessToken string `cli:"agent-access-token" validate:"required"` Endpoint string `cli:"endpoint" validate:"required"` NoHTTP2 bool `cli:"no-http2"` @@ -131,6 +132,7 @@ var ArtifactUploadCommand = cli.Command{ EndpointFlag, NoHTTP2Flag, DebugHTTPFlag, + TraceHTTPFlag, // Global flags NoColorFlag, @@ -149,11 +151,13 @@ var ArtifactUploadCommand = cli.Command{ // Setup the uploader uploader := artifact.NewUploader(l, client, artifact.UploaderConfig{ - JobID: cfg.Job, - Paths: cfg.UploadPaths, - Destination: cfg.Destination, - ContentType: cfg.ContentType, - DebugHTTP: cfg.DebugHTTP, + JobID: cfg.Job, + Paths: cfg.UploadPaths, + Destination: cfg.Destination, + ContentType: cfg.ContentType, + DebugHTTP: cfg.DebugHTTP, + TraceHTTP: cfg.TraceHTTP, + DisableHTTP2: cfg.NoHTTP2, // If the deprecated flag was set to true, pretend its replacement was set to true too // this works as long as the user only sets one of the two flags diff --git a/api/auth.go b/internal/agenthttp/auth.go similarity index 70% rename from api/auth.go rename to internal/agenthttp/auth.go index 2b9af46476..37eeba9d60 100644 --- a/api/auth.go +++ b/internal/agenthttp/auth.go @@ -1,16 +1,23 @@ -package api +package agenthttp import ( "fmt" "net/http" ) -// authenticatedTransport manages injection of the API token. +// authenticatedTransport manages injection of the API token into every request. +// Using a transport to inject credentials into every request like this is +// ugly because http.RoundTripper has specific requirements, but has +// precedent (e.g. https://github.com/golang/oauth2/blob/master/transport.go). type authenticatedTransport struct { - // The Token used for authentication. This can either the be - // organizations registration token, or the agents access token. + // If set, the header "Authorization: Token %s" will be added to all requests. + // Mutually incompatible with Bearer. Token string + // If set, the header "Authorization: Bearer %s" will be added to all requests. + // Mutually incompatible with Token. + Bearer string + // Delegate is the underlying HTTP transport Delegate http.RoundTripper } @@ -45,7 +52,12 @@ func (t authenticatedTransport) RoundTrip(req *http.Request) (*http.Response, er // req.Clone does a sufficiently deep clone (including Header which we // modify). req = req.Clone(req.Context()) - req.Header.Set("Authorization", fmt.Sprintf("Token %s", t.Token)) + switch { + case t.Token != "": + req.Header.Set("Authorization", "Token "+t.Token) + case t.Bearer != "": + req.Header.Set("Authorization", "Bearer "+t.Bearer) + } // req.Body is assumed to be closed by the delegate. reqBodyClosed = true diff --git a/internal/agenthttp/client.go b/internal/agenthttp/client.go new file mode 100644 index 0000000000..f1bea82d32 --- /dev/null +++ b/internal/agenthttp/client.go @@ -0,0 +1,136 @@ +// Package agenthttp creates standard Go [net/http.Client]s with common config +// options. +package agenthttp + +import ( + "crypto/tls" + "net/http" + "sync" + "time" + + "golang.org/x/net/http2" +) + +// NewClient creates a HTTP client. +func NewClient(opts ...ClientOption) *http.Client { + conf := clientConfig{ + // This spells out the defaults, even if some of them are zero values. + Bearer: "", + Token: "", + AllowHTTP2: true, + Timeout: 60 * time.Second, + TLSConfig: nil, + } + for _, opt := range opts { + opt(&conf) + } + + cacheKey := transportCacheKey{ + AllowHTTP2: conf.AllowHTTP2, + TLSConfig: conf.TLSConfig, + } + + transportCacheMu.Lock() + transport := transportCache[cacheKey] + if transport == nil { + transport = newTransport(&conf) + transportCache[cacheKey] = transport + } + transportCacheMu.Unlock() + + if conf.Bearer == "" && conf.Token == "" { + // No credentials, no authenticatedTransport wrapper. + return &http.Client{ + Timeout: conf.Timeout, + Transport: transport, + } + } + + // Wrap the transport in authenticatedTransport. + return &http.Client{ + Timeout: conf.Timeout, + Transport: &authenticatedTransport{ + Bearer: conf.Bearer, + Token: conf.Token, + Delegate: transport, + }, + } +} + +// Various NewClient options. +func WithAuthBearer(b string) ClientOption { return func(c *clientConfig) { c.Bearer = b } } +func WithAuthToken(t string) ClientOption { return func(c *clientConfig) { c.Token = t } } +func WithAllowHTTP2(a bool) ClientOption { return func(c *clientConfig) { c.AllowHTTP2 = a } } +func WithTimeout(d time.Duration) ClientOption { return func(c *clientConfig) { c.Timeout = d } } +func WithTLSConfig(t *tls.Config) ClientOption { return func(c *clientConfig) { c.TLSConfig = t } } + +type ClientOption = func(*clientConfig) + +func newTransport(conf *clientConfig) *http.Transport { + // Base any modifications on the default transport. + transport := http.DefaultTransport.(*http.Transport).Clone() + // Allow override of TLSConfig. This must be set prior to calling + // http2.ConfigureTransports. + if conf.TLSConfig != nil { + transport.TLSClientConfig = conf.TLSConfig + } + + if conf.AllowHTTP2 { + // There is a bug in http2 on Linux regarding using dead connections. + // This is a workaround. See https://github.com/golang/go/issues/59690 + // + // Note that http2.ConfigureTransports alters its argument in order to + // supply http2 functionality, and the http2.Transport does not support + // HTTP/1.1 as a protocol, so we get slightly odd-looking code where + // we use `transport` later on instead of the just-returned `tr2`. + // tr2 is needed merely to configure the http2 option. + tr2, err := http2.ConfigureTransports(transport) + if err != nil { + // ConfigureTransports is documented to only return an error if + // the transport arg was already HTTP2-enabled, which it should not + // have been... + panic("http2.ConfigureTransports: " + err.Error()) + } + if tr2 != nil { + tr2.ReadIdleTimeout = 30 * time.Second + } + } else { + transport.TLSNextProto = make(map[string]func(string, *tls.Conn) http.RoundTripper) + // The default TLSClientConfig has h2 in NextProtos, so the + // negotiated TLS connection will assume h2 support. + // see https://github.com/golang/go/issues/50571 + transport.TLSClientConfig.NextProtos = []string{"http/1.1"} + } + + return transport +} + +type clientConfig struct { + // The authentication token/ bearer credential to use + // For agent API usage, Token is usually an agent registration or access token + // For GraphQL usage, Bearer is usually a user token + Token string + Bearer string + + // If false, HTTP2 is disabled + AllowHTTP2 bool + + // Timeout used as the client timeout. + Timeout time.Duration + + // optional TLS configuration primarily used for testing + TLSConfig *tls.Config +} + +// The underlying http.Transport is cached, mainly so that multiple clients with +// the same options can reuse connections. The options that affect the transport +// are also usually the same throughout the process. +type transportCacheKey struct { + AllowHTTP2 bool + TLSConfig *tls.Config +} + +var ( + transportCacheMu sync.Mutex + transportCache = make(map[transportCacheKey]*http.Transport) +) diff --git a/internal/agenthttp/do.go b/internal/agenthttp/do.go new file mode 100644 index 0000000000..6d60e2e26f --- /dev/null +++ b/internal/agenthttp/do.go @@ -0,0 +1,186 @@ +package agenthttp + +import ( + "crypto/tls" + "fmt" + "net/http" + "net/http/httptrace" + "net/http/httputil" + "net/textproto" + "strconv" + "strings" + "time" + + "github.com/buildkite/agent/v3/logger" +) + +// Do wraps the http.Client's Do method with debug logging and tracing options. +func Do(l logger.Logger, client *http.Client, req *http.Request, opts ...DoOption) (*http.Response, error) { + var cfg doConfig + for _, opt := range opts { + opt(&cfg) + } + + if cfg.debugHTTP { + // If the request is a multi-part form, then it's probably a + // file upload, in which case we don't want to spewing out the + // file contents into the debug log (especially if it's been + // gzipped) + dumpBody := !strings.Contains(req.Header.Get("Content-Type"), "multipart/form-data") + requestDump, err := httputil.DumpRequestOut(req, dumpBody) + if err != nil { + l.Debug("ERR: %s\n%s", err, string(requestDump)) + } else { + l.Debug("%s", string(requestDump)) + } + } + + tracer := &tracer{Logger: l} + if cfg.traceHTTP { + // Inject a custom http tracer + req = traceHTTPRequest(req, tracer) + tracer.Start() + } + + ts := time.Now() + + l.Debug("%s %s", req.Method, req.URL) + + resp, err := client.Do(req) + if err != nil { + if cfg.traceHTTP { + tracer.EmitTraceToLog(logger.ERROR) + } + return nil, err + } + + l.WithFields( + logger.StringField("proto", resp.Proto), + logger.IntField("status", resp.StatusCode), + logger.DurationField("Δ", time.Since(ts)), + ).Debug("↳ %s %s", req.Method, req.URL) + + if cfg.debugHTTP { + responseDump, err := httputil.DumpResponse(resp, true) + if err != nil { + l.Debug("\nERR: %s\n%s", err, string(responseDump)) + } else { + l.Debug("\n%s", string(responseDump)) + } + } + if cfg.traceHTTP { + tracer.EmitTraceToLog(logger.DEBUG) + } + + return resp, err +} + +type DoOption = func(*doConfig) + +type doConfig struct { + debugHTTP bool + traceHTTP bool +} + +func WithDebugHTTP(d bool) DoOption { return func(c *doConfig) { c.debugHTTP = d } } +func WithTraceHTTP(t bool) DoOption { return func(c *doConfig) { c.traceHTTP = t } } + +type traceEvent struct { + event string + since time.Duration +} + +type tracer struct { + startTime time.Time + logger.Logger +} + +func (t *tracer) Start() { + t.startTime = time.Now() +} + +func (t *tracer) LogTiming(event string) { + t.Logger = t.Logger.WithFields(logger.DurationField(event, time.Since(t.startTime))) +} + +func (t *tracer) LogField(key, value string) { + t.Logger = t.Logger.WithFields(logger.StringField(key, value)) +} + +func (t *tracer) LogDuration(event string, d time.Duration) { + t.Logger = t.Logger.WithFields(logger.DurationField(event, d)) +} + +// Currently logger.Logger doesn't give us a way to set the level we want to emit logs at dynamically +func (t *tracer) EmitTraceToLog(level logger.Level) { + msg := "HTTP Timing Trace" + switch level { + case logger.DEBUG: + t.Debug(msg) + case logger.INFO: + t.Info(msg) + case logger.WARN: + t.Warn(msg) + case logger.ERROR: + t.Error(msg) + } +} + +func traceHTTPRequest(req *http.Request, t *tracer) *http.Request { + trace := &httptrace.ClientTrace{ + GetConn: func(hostPort string) { + t.LogField("hostPort", hostPort) + t.LogTiming("getConn") + }, + GotConn: func(info httptrace.GotConnInfo) { + t.LogTiming("gotConn") + t.LogField("reused", strconv.FormatBool(info.Reused)) + t.LogField("idle", strconv.FormatBool(info.WasIdle)) + t.LogDuration("idleTime", info.IdleTime) + t.LogField("localAddr", info.Conn.LocalAddr().String()) + }, + PutIdleConn: func(err error) { + t.LogTiming("putIdleConn") + if err != nil { + t.LogField("putIdleConnectionError", err.Error()) + } + }, + GotFirstResponseByte: func() { + t.LogTiming("gotFirstResponseByte") + }, + Got1xxResponse: func(code int, header textproto.MIMEHeader) error { + t.LogTiming("got1xxResponse") + return nil + }, + DNSStart: func(_ httptrace.DNSStartInfo) { + t.LogTiming("dnsStart") + }, + DNSDone: func(_ httptrace.DNSDoneInfo) { + t.LogTiming("dnsDone") + }, + ConnectStart: func(network, addr string) { + t.LogTiming(fmt.Sprintf("connectStart.%s.%s", network, addr)) + }, + ConnectDone: func(network, addr string, _ error) { + t.LogTiming(fmt.Sprintf("connectDone.%s.%s", network, addr)) + }, + TLSHandshakeStart: func() { + t.LogTiming("tlsHandshakeStart") + }, + TLSHandshakeDone: func(_ tls.ConnectionState, _ error) { + t.LogTiming("tlsHandshakeDone") + }, + WroteHeaders: func() { + t.LogTiming("wroteHeaders") + }, + WroteRequest: func(_ httptrace.WroteRequestInfo) { + t.LogTiming("wroteRequest") + }, + } + + req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace)) + + t.LogField("uri", req.URL.String()) + t.LogField("method", req.Method) + return req +} diff --git a/internal/artifact/artifactory_downloader.go b/internal/artifact/artifactory_downloader.go index f750079631..d89bdefa42 100644 --- a/internal/artifact/artifactory_downloader.go +++ b/internal/artifact/artifactory_downloader.go @@ -5,12 +5,12 @@ import ( "encoding/base64" "errors" "fmt" - "net/http" "os" "path" "path/filepath" "strings" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/logger" ) @@ -29,7 +29,9 @@ type ArtifactoryDownloaderConfig struct { Retries int // If failed responses should be dumped to the log - DebugHTTP bool + DebugHTTP bool + TraceHTTP bool + DisableHTTP2 bool } type ArtifactoryDownloader struct { @@ -68,14 +70,17 @@ func (d ArtifactoryDownloader) Start(ctx context.Context) error { "Authorization": fmt.Sprintf("Basic %s", getBasicAuthHeader(username, password)), } + client := agenthttp.NewClient(agenthttp.WithAllowHTTP2(!d.conf.DisableHTTP2)) + // We can now cheat and pass the URL onto our regular downloader - return NewDownload(d.logger, http.DefaultClient, DownloadConfig{ + return NewDownload(d.logger, client, DownloadConfig{ URL: fullURL, Path: d.conf.Path, Destination: d.conf.Destination, Retries: d.conf.Retries, Headers: headers, DebugHTTP: d.conf.DebugHTTP, + TraceHTTP: d.conf.TraceHTTP, }).Start(ctx) } diff --git a/internal/artifact/artifactory_uploader.go b/internal/artifact/artifactory_uploader.go index d99ea29d73..5c0196ae3f 100644 --- a/internal/artifact/artifactory_uploader.go +++ b/internal/artifact/artifactory_uploader.go @@ -18,6 +18,7 @@ import ( "strings" "github.com/buildkite/agent/v3/api" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/logger" ) @@ -26,8 +27,10 @@ type ArtifactoryUploaderConfig struct { // e.g artifactory://my-repo-name/foo/bar Destination string - // Whether or not HTTP calls should be debugged - DebugHTTP bool + // Standard HTTP options + DebugHTTP bool + TraceHTTP bool + DisableHTTP2 bool } type ArtifactoryUploader struct { @@ -71,9 +74,11 @@ func NewArtifactoryUploader(l logger.Logger, c ArtifactoryUploaderConfig) (*Arti return nil, err } return &ArtifactoryUploader{ - logger: l, - conf: c, - client: &http.Client{}, + logger: l, + conf: c, + client: agenthttp.NewClient( + agenthttp.WithAllowHTTP2(!c.DisableHTTP2), + ), iURL: parsedURL, Path: path, Repository: repo, @@ -134,7 +139,10 @@ func (u *ArtifactoryUploader) Upload(_ context.Context, artifact *api.Artifact) } req.Header.Add("X-Checksum-SHA256", sha256Checksum) - res, err := u.client.Do(req) + res, err := agenthttp.Do(u.logger, u.client, req, + agenthttp.WithDebugHTTP(u.conf.DebugHTTP), + agenthttp.WithTraceHTTP(u.conf.TraceHTTP), + ) if err != nil { return err } diff --git a/internal/artifact/azure_blob_downloader.go b/internal/artifact/azure_blob_downloader.go index 39b8430448..cda2f5c03c 100644 --- a/internal/artifact/azure_blob_downloader.go +++ b/internal/artifact/azure_blob_downloader.go @@ -16,6 +16,7 @@ type AzureBlobDownloaderConfig struct { Destination string Retries int DebugHTTP bool + TraceHTTP bool } // AzureBlobDownloader downloads files from Azure Blob storage. diff --git a/internal/artifact/download.go b/internal/artifact/download.go index f071885b30..9555c5531e 100644 --- a/internal/artifact/download.go +++ b/internal/artifact/download.go @@ -7,12 +7,12 @@ import ( "fmt" "io" "net/http" - "net/http/httputil" "os" "path/filepath" "strings" "time" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/internal/experiments" "github.com/buildkite/agent/v3/logger" "github.com/buildkite/agent/v3/version" @@ -47,7 +47,9 @@ type DownloadConfig struct { WantSHA256 string // If failed responses should be dumped to the log + // Standard HTTP options. DebugHTTP bool + TraceHTTP bool } type Download struct { @@ -143,7 +145,10 @@ func (d Download) try(ctx context.Context) error { } // Start by downloading the file - response, err := d.client.Do(request) + response, err := agenthttp.Do(d.logger, d.client, request, + agenthttp.WithDebugHTTP(d.conf.DebugHTTP), + agenthttp.WithTraceHTTP(d.conf.TraceHTTP), + ) if err != nil { return fmt.Errorf("Error while downloading %s (%T: %w)", d.conf.URL, err, err) } @@ -151,15 +156,6 @@ func (d Download) try(ctx context.Context) error { // Double check the status if response.StatusCode/100 != 2 && response.StatusCode/100 != 3 { - if d.conf.DebugHTTP { - responseDump, err := httputil.DumpResponse(response, true) - if err != nil { - d.logger.Debug("\nERR: %s\n%s", err, string(responseDump)) - } else { - d.logger.Debug("\n%s", string(responseDump)) - } - } - return &downloadError{response.Status} } diff --git a/internal/artifact/downloader.go b/internal/artifact/downloader.go index 4b529e5051..6a4e53eed6 100644 --- a/internal/artifact/downloader.go +++ b/internal/artifact/downloader.go @@ -4,7 +4,6 @@ import ( "context" "errors" "fmt" - "net/http" "os" "path/filepath" "runtime" @@ -12,6 +11,7 @@ import ( "github.com/aws/aws-sdk-go/service/s3" "github.com/buildkite/agent/v3/api" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/logger" "github.com/buildkite/agent/v3/pool" ) @@ -32,8 +32,10 @@ type DownloaderConfig struct { // Where we'll be downloading artifacts to Destination string - // Whether to show HTTP debugging - DebugHTTP bool + // Standard HTTP options + DebugHTTP bool + TraceHTTP bool + DisableHTTP2 bool } type Downloader struct { @@ -162,6 +164,7 @@ func (a *Downloader) createDownloader(artifact *api.Artifact, path, destination Destination: destination, Retries: 5, DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, }) case strings.HasPrefix(artifact.UploadDestination, "gs://"): @@ -171,6 +174,7 @@ func (a *Downloader) createDownloader(artifact *api.Artifact, path, destination Destination: destination, Retries: 5, DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, }) case strings.HasPrefix(artifact.UploadDestination, "rt://"): @@ -180,6 +184,7 @@ func (a *Downloader) createDownloader(artifact *api.Artifact, path, destination Destination: destination, Retries: 5, DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, }) case IsAzureBlobPath(artifact.UploadDestination): @@ -189,15 +194,18 @@ func (a *Downloader) createDownloader(artifact *api.Artifact, path, destination Destination: destination, Retries: 5, DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, }) default: - return NewDownload(a.logger, http.DefaultClient, DownloadConfig{ + client := agenthttp.NewClient(agenthttp.WithAllowHTTP2(!a.conf.DisableHTTP2)) + return NewDownload(a.logger, client, DownloadConfig{ URL: artifact.URL, Path: path, Destination: destination, Retries: 5, DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, }) } } diff --git a/internal/artifact/form_uploader.go b/internal/artifact/form_uploader.go index 39a16aa1ed..eb01b3698b 100644 --- a/internal/artifact/form_uploader.go +++ b/internal/artifact/form_uploader.go @@ -8,10 +8,7 @@ import ( "io" "mime/multipart" "net/http" - "net/http/httptrace" - "net/http/httputil" "regexp" - "strings" // "net/http/httputil" "errors" @@ -19,6 +16,7 @@ import ( "os" "github.com/buildkite/agent/v3/api" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/logger" "github.com/buildkite/agent/v3/version" ) @@ -29,8 +27,10 @@ var ArtifactPathVariableRegex = regexp.MustCompile("\\$\\{artifact\\:path\\}") var maxFormUploadedArtifactSize = int64(5368709120) type FormUploaderConfig struct { - // Whether or not HTTP calls should be debugged - DebugHTTP bool + // Standard HTTP options + DebugHTTP bool + TraceHTTP bool + DisableHTTP2 bool } type FormUploader struct { @@ -65,70 +65,34 @@ func (u *FormUploader) Upload(_ context.Context, artifact *api.Artifact) error { return err } - if u.conf.DebugHTTP { - // If the request is a multi-part form, then it's probably a - // file upload, in which case we don't want to spewing out the - // file contents into the debug log (especially if it's been - // gzipped) - var requestDump []byte - if strings.Contains(request.Header.Get("Content-Type"), "multipart/form-data") { - requestDump, err = httputil.DumpRequestOut(request, false) - } else { - requestDump, err = httputil.DumpRequestOut(request, true) - } - - if err != nil { - u.logger.Debug("\nERR: %s\n%s", err, string(requestDump)) - } else { - u.logger.Debug("\n%s", string(requestDump)) - } - - // configure the HTTP request to log the server IP. The IPs for s3.amazonaws.com - // rotate every 5 seconds, and if one of them is misbehaving it may be helpful to - // know which one. - trace := &httptrace.ClientTrace{ - GotConn: func(connInfo httptrace.GotConnInfo) { - u.logger.Debug("artifact %s uploading to: %s", artifact.ID, connInfo.Conn.RemoteAddr()) - }, - } - request = request.WithContext(httptrace.WithClientTrace(request.Context(), trace)) - } - // Create the client - client := &http.Client{} + client := agenthttp.NewClient( + agenthttp.WithAllowHTTP2(!u.conf.DisableHTTP2), + ) // Perform the request - u.logger.Debug("%s %s", request.Method, request.URL) - response, err := client.Do(request) - - // Check for errors + response, err := agenthttp.Do(u.logger, client, request, + agenthttp.WithDebugHTTP(u.conf.DebugHTTP), + agenthttp.WithTraceHTTP(u.conf.TraceHTTP), + ) if err != nil { return err - } else { - // Be sure to close the response body at the end of - // this function - defer response.Body.Close() - - if u.conf.DebugHTTP { - responseDump, err := httputil.DumpResponse(response, true) - if err != nil { - u.logger.Debug("\nERR: %s\n%s", err, string(responseDump)) - } else { - u.logger.Debug("\n%s", string(responseDump)) - } - } + } - if response.StatusCode/100 != 2 { - body := &bytes.Buffer{} - _, err := body.ReadFrom(response.Body) - if err != nil { - return err - } + // Be sure to close the response body at the end of + // this function + defer response.Body.Close() - // Return a custom error with the response body from the page - message := fmt.Sprintf("%s (%d)", body, response.StatusCode) - return errors.New(message) + if response.StatusCode/100 != 2 { + body := &bytes.Buffer{} + _, err := body.ReadFrom(response.Body) + if err != nil { + return err } + + // Return a custom error with the response body from the page + message := fmt.Sprintf("%s (%d)", body, response.StatusCode) + return errors.New(message) } return nil diff --git a/internal/artifact/gs_downloader.go b/internal/artifact/gs_downloader.go index a9388863ca..0c9b2e3718 100644 --- a/internal/artifact/gs_downloader.go +++ b/internal/artifact/gs_downloader.go @@ -26,6 +26,7 @@ type GSDownloaderConfig struct { // If failed responses should be dumped to the log DebugHTTP bool + TraceHTTP bool } type GSDownloader struct { @@ -44,7 +45,7 @@ func NewGSDownloader(l logger.Logger, c GSDownloaderConfig) *GSDownloader { } func (d GSDownloader) Start(ctx context.Context) error { - client, err := newGoogleClient(storage.DevstorageReadOnlyScope) + client, err := newGoogleClient(ctx, storage.DevstorageReadOnlyScope) if err != nil { return errors.New(fmt.Sprintf("Error creating Google Cloud Storage client: %v", err)) } @@ -58,6 +59,7 @@ func (d GSDownloader) Start(ctx context.Context) error { Destination: d.conf.Destination, Retries: d.conf.Retries, DebugHTTP: d.conf.DebugHTTP, + TraceHTTP: d.conf.TraceHTTP, }).Start(ctx) } diff --git a/internal/artifact/gs_uploader.go b/internal/artifact/gs_uploader.go index 3938f19494..47c3a5f040 100644 --- a/internal/artifact/gs_uploader.go +++ b/internal/artifact/gs_uploader.go @@ -7,6 +7,7 @@ import ( "net/http" "net/url" "os" + "path" "path/filepath" "strings" @@ -15,6 +16,7 @@ import ( "golang.org/x/oauth2" "golang.org/x/oauth2/google" "google.golang.org/api/googleapi" + "google.golang.org/api/option" storage "google.golang.org/api/storage/v1" ) @@ -22,9 +24,6 @@ type GSUploaderConfig struct { // The destination which includes the GS bucket name and the path. // gs://my-bucket-name/foo/bar Destination string - - // Whether or not HTTP calls shoud be debugged - DebugHTTP bool } type GSUploader struct { @@ -44,12 +43,12 @@ type GSUploader struct { service *storage.Service } -func NewGSUploader(l logger.Logger, c GSUploaderConfig) (*GSUploader, error) { - client, err := newGoogleClient(storage.DevstorageFullControlScope) +func NewGSUploader(ctx context.Context, l logger.Logger, c GSUploaderConfig) (*GSUploader, error) { + client, err := newGoogleClient(ctx, storage.DevstorageFullControlScope) if err != nil { return nil, errors.New(fmt.Sprintf("Error creating Google Cloud Storage client: %v", err)) } - service, err := storage.New(client) + service, err := storage.NewService(ctx, option.WithHTTPClient(client)) if err != nil { return nil, err } @@ -78,18 +77,19 @@ func clientFromJSON(data []byte, scope string) (*http.Client, error) { return conf.Client(oauth2.NoContext), nil } -func newGoogleClient(scope string) (*http.Client, error) { +func newGoogleClient(ctx context.Context, scope string) (*http.Client, error) { if os.Getenv("BUILDKITE_GS_APPLICATION_CREDENTIALS_JSON") != "" { data := []byte(os.Getenv("BUILDKITE_GS_APPLICATION_CREDENTIALS_JSON")) return clientFromJSON(data, scope) - } else if os.Getenv("BUILDKITE_GS_APPLICATION_CREDENTIALS") != "" { + } + if os.Getenv("BUILDKITE_GS_APPLICATION_CREDENTIALS") != "" { data, err := os.ReadFile(os.Getenv("BUILDKITE_GS_APPLICATION_CREDENTIALS")) if err != nil { return nil, err } return clientFromJSON(data, scope) } - return google.DefaultClient(context.Background(), scope) + return google.DefaultClient(ctx, scope) } func (u *GSUploader) URL(artifact *api.Artifact) string { @@ -109,7 +109,7 @@ func (u *GSUploader) URL(artifact *api.Artifact) string { // Build the path from the prefix and the artifactPath // Also ensure that we always have exactly one / between prefix and artifactPath - path := fmt.Sprintf("%s/%s", strings.TrimSuffix(pathPrefix, "/"), u.artifactPath(artifact)) + path := path.Join(pathPrefix, u.artifactPath(artifact)) var artifactURL = &url.URL{ Scheme: "https", diff --git a/internal/artifact/s3_downloader.go b/internal/artifact/s3_downloader.go index b9e7ad251f..0c739945a1 100644 --- a/internal/artifact/s3_downloader.go +++ b/internal/artifact/s3_downloader.go @@ -3,12 +3,12 @@ package artifact import ( "context" "fmt" - "net/http" "strings" "time" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/s3" + "github.com/buildkite/agent/v3/internal/agenthttp" "github.com/buildkite/agent/v3/logger" ) @@ -30,7 +30,9 @@ type S3DownloaderConfig struct { Retries int // If failed responses should be dumped to the log - DebugHTTP bool + DebugHTTP bool + TraceHTTP bool + DisableHTTP2 bool } type S3Downloader struct { @@ -64,12 +66,14 @@ func (d S3Downloader) Start(ctx context.Context) error { } // We can now cheat and pass the URL onto our regular downloader - return NewDownload(d.logger, http.DefaultClient, DownloadConfig{ + client := agenthttp.NewClient(agenthttp.WithAllowHTTP2(!d.conf.DisableHTTP2)) + return NewDownload(d.logger, client, DownloadConfig{ URL: signedURL, Path: d.conf.Path, Destination: d.conf.Destination, Retries: d.conf.Retries, DebugHTTP: d.conf.DebugHTTP, + TraceHTTP: d.conf.TraceHTTP, }).Start(ctx) } diff --git a/internal/artifact/s3_uploader.go b/internal/artifact/s3_uploader.go index 3b9836bf2c..3215bf5905 100644 --- a/internal/artifact/s3_uploader.go +++ b/internal/artifact/s3_uploader.go @@ -18,9 +18,6 @@ type S3UploaderConfig struct { // The destination which includes the S3 bucket name and the path. // For example, s3://my-bucket-name/foo/bar Destination string - - // Whether or not HTTP calls should be debugged - DebugHTTP bool } type S3Uploader struct { diff --git a/internal/artifact/uploader.go b/internal/artifact/uploader.go index c4cfc00b35..831e57bf18 100644 --- a/internal/artifact/uploader.go +++ b/internal/artifact/uploader.go @@ -44,8 +44,10 @@ type UploaderConfig struct { // A specific Content-Type to use for all artifacts ContentType string - // Whether to show HTTP debugging - DebugHTTP bool + // Standard HTTP options. + DebugHTTP bool + TraceHTTP bool + DisableHTTP2 bool // Whether to follow symbolic links when resolving globs GlobResolveFollowSymlinks bool @@ -358,7 +360,7 @@ func (a *Uploader) build(path string, absolutePath string) (*api.Artifact, error // createUploader applies some heuristics to the destination to infer which // uploader to use. -func (a *Uploader) createUploader() (_ uploader, err error) { +func (a *Uploader) createUploader(ctx context.Context) (_ uploader, err error) { var dest string defer func() { if err != nil || dest == "" { @@ -371,28 +373,30 @@ func (a *Uploader) createUploader() (_ uploader, err error) { case a.conf.Destination == "": a.logger.Info("Uploading to default Buildkite artifact storage") return NewFormUploader(a.logger, FormUploaderConfig{ - DebugHTTP: a.conf.DebugHTTP, + DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, + DisableHTTP2: a.conf.DisableHTTP2, }), nil case strings.HasPrefix(a.conf.Destination, "s3://"): dest = "Amazon S3" return NewS3Uploader(a.logger, S3UploaderConfig{ Destination: a.conf.Destination, - DebugHTTP: a.conf.DebugHTTP, }) case strings.HasPrefix(a.conf.Destination, "gs://"): dest = "Google Cloud Storage" - return NewGSUploader(a.logger, GSUploaderConfig{ + return NewGSUploader(ctx, a.logger, GSUploaderConfig{ Destination: a.conf.Destination, - DebugHTTP: a.conf.DebugHTTP, }) case strings.HasPrefix(a.conf.Destination, "rt://"): dest = "Artifactory" return NewArtifactoryUploader(a.logger, ArtifactoryUploaderConfig{ - Destination: a.conf.Destination, - DebugHTTP: a.conf.DebugHTTP, + Destination: a.conf.Destination, + DebugHTTP: a.conf.DebugHTTP, + TraceHTTP: a.conf.TraceHTTP, + DisableHTTP2: a.conf.DisableHTTP2, }) case IsAzureBlobPath(a.conf.Destination): @@ -417,7 +421,7 @@ type uploader interface { func (a *Uploader) upload(ctx context.Context, artifacts []*api.Artifact) error { // Determine what uploader to use - uploader, err := a.createUploader() + uploader, err := a.createUploader(ctx) if err != nil { return fmt.Errorf("creating uploader: %w", err) } diff --git a/internal/bkgql/client.go b/internal/bkgql/client.go index 388a6a1a9b..fedb22c0b3 100644 --- a/internal/bkgql/client.go +++ b/internal/bkgql/client.go @@ -4,11 +4,10 @@ package bkgql //go:generate go run github.com/Khan/genqlient import ( - "fmt" - "net/http" "time" "github.com/Khan/genqlient/graphql" + "github.com/buildkite/agent/v3/internal/agenthttp" ) const ( @@ -17,18 +16,8 @@ const ( ) func NewClient(endpoint, token string) graphql.Client { - return graphql.NewClient(endpoint, &http.Client{ - Timeout: graphQLTimeout, - Transport: &authedTransport{token: token, wrapped: http.DefaultTransport}, - }) -} - -type authedTransport struct { - token string - wrapped http.RoundTripper -} - -func (t *authedTransport) RoundTrip(req *http.Request) (*http.Response, error) { - req.Header.Set("Authorization", fmt.Sprintf("Bearer %s", t.token)) - return t.wrapped.RoundTrip(req) + return graphql.NewClient(endpoint, agenthttp.NewClient( + agenthttp.WithAuthBearer(token), + agenthttp.WithTimeout(graphQLTimeout), + )) }