diff --git a/internal/databroker/server.go b/internal/databroker/server.go index 962042618..2980f14bd 100644 --- a/internal/databroker/server.go +++ b/internal/databroker/server.go @@ -226,7 +226,7 @@ func (srv *Server) ReleaseLease(ctx context.Context, req *databroker.ReleaseLeas func (srv *Server) RenewLease(ctx context.Context, req *databroker.RenewLeaseRequest) (*emptypb.Empty, error) { _, span := trace.StartSpan(ctx, "databroker.grpc.RenewLease") defer span.End() - log.Info(ctx). + log.Debug(ctx). Str("peer", grpcutil.GetPeerAddr(ctx)). Str("name", req.GetName()). Str("id", req.GetId()). diff --git a/internal/directory/azure/azure.go b/internal/directory/azure/azure.go index ea22a8041..5e76c1b29 100644 --- a/internal/directory/azure/azure.go +++ b/internal/directory/azure/azure.go @@ -12,8 +12,10 @@ import ( "strings" "sync" + "github.com/rs/zerolog" "golang.org/x/oauth2" + "github.com/pomerium/pomerium/internal/httputil" "github.com/pomerium/pomerium/pkg/grpc/directory" ) @@ -55,7 +57,10 @@ func WithLoginURL(loginURL *url.URL) Option { // WithHTTPClient sets the http client to use for requests to the Azure APIs. func WithHTTPClient(httpClient *http.Client) Option { return func(cfg *config) { - cfg.httpClient = httpClient + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "azure") + }) } } diff --git a/internal/directory/github/github.go b/internal/directory/github/github.go index 77cd69fe8..b39ef9f3f 100644 --- a/internal/directory/github/github.go +++ b/internal/directory/github/github.go @@ -16,6 +16,7 @@ import ( "github.com/rs/zerolog" "github.com/tomnomnom/linkheader" + "github.com/pomerium/pomerium/internal/httputil" "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/pkg/grpc/directory" ) @@ -47,7 +48,10 @@ func WithServiceAccount(serviceAccount *ServiceAccount) Option { // WithHTTPClient sets the http client option. func WithHTTPClient(httpClient *http.Client) Option { return func(cfg *config) { - cfg.httpClient = httpClient + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "github") + }) } } diff --git a/internal/directory/gitlab/gitlab.go b/internal/directory/gitlab/gitlab.go index b4573a8eb..d217d920e 100644 --- a/internal/directory/gitlab/gitlab.go +++ b/internal/directory/gitlab/gitlab.go @@ -14,6 +14,7 @@ import ( "github.com/rs/zerolog" "github.com/tomnomnom/linkheader" + "github.com/pomerium/pomerium/internal/httputil" "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/pkg/grpc/directory" ) @@ -45,7 +46,10 @@ func WithServiceAccount(serviceAccount *ServiceAccount) Option { // WithHTTPClient sets the http client option. func WithHTTPClient(httpClient *http.Client) Option { return func(cfg *config) { - cfg.httpClient = httpClient + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "azure") + }) } } diff --git a/internal/directory/google/google.go b/internal/directory/google/google.go index f8d2d78a4..2f8ac8955 100644 --- a/internal/directory/google/google.go +++ b/internal/directory/google/google.go @@ -17,6 +17,7 @@ import ( "google.golang.org/api/googleapi" "google.golang.org/api/option" + "github.com/pomerium/pomerium/internal/httputil" "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/pkg/grpc/directory" ) @@ -33,6 +34,7 @@ const ( ) type config struct { + httpClient *http.Client serviceAccount *ServiceAccount url string } @@ -40,6 +42,16 @@ type config struct { // An Option changes the configuration for the Google directory provider. type Option func(cfg *config) +// WithHTTPClient sets the http client option. +func WithHTTPClient(httpClient *http.Client) Option { + return func(cfg *config) { + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "google") + }) + } +} + // WithServiceAccount sets the service account in the Google configuration. func WithServiceAccount(serviceAccount *ServiceAccount) Option { return func(cfg *config) { @@ -56,6 +68,7 @@ func WithURL(url string) Option { func getConfig(options ...Option) *config { cfg := new(config) + WithHTTPClient(http.DefaultClient)(cfg) WithURL(defaultProviderURL)(cfg) for _, option := range options { option(cfg) @@ -241,7 +254,10 @@ func (p *Provider) getAPIClient(ctx context.Context) (*admin.Service, error) { ts := config.TokenSource(ctx) - p.apiClient, err = admin.NewService(ctx, option.WithTokenSource(ts), option.WithEndpoint(p.cfg.url)) + p.apiClient, err = admin.NewService(ctx, + option.WithTokenSource(ts), + option.WithEndpoint(p.cfg.url), + option.WithHTTPClient(p.cfg.httpClient)) if err != nil { return nil, fmt.Errorf("google: failed creating admin service %w", err) } diff --git a/internal/directory/okta/okta.go b/internal/directory/okta/okta.go index c2a477fe9..5fc1c050e 100644 --- a/internal/directory/okta/okta.go +++ b/internal/directory/okta/okta.go @@ -18,6 +18,7 @@ import ( "github.com/rs/zerolog" "github.com/tomnomnom/linkheader" + "github.com/pomerium/pomerium/internal/httputil" "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/pkg/grpc/directory" ) @@ -61,7 +62,10 @@ func WithBatchSize(batchSize int) Option { // WithHTTPClient sets the http client option. func WithHTTPClient(httpClient *http.Client) Option { return func(cfg *config) { - cfg.httpClient = httpClient + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "okta") + }) } } diff --git a/internal/directory/onelogin/onelogin.go b/internal/directory/onelogin/onelogin.go index a572b4f09..b967acd1a 100644 --- a/internal/directory/onelogin/onelogin.go +++ b/internal/directory/onelogin/onelogin.go @@ -16,6 +16,7 @@ import ( "github.com/rs/zerolog" "golang.org/x/oauth2" + "github.com/pomerium/pomerium/internal/httputil" "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/pkg/grpc/directory" ) @@ -43,7 +44,10 @@ func WithBatchSize(batchSize int) Option { // WithHTTPClient sets the http client option. func WithHTTPClient(httpClient *http.Client) Option { return func(cfg *config) { - cfg.httpClient = httpClient + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "onelogin") + }) } } diff --git a/internal/directory/ping/config.go b/internal/directory/ping/config.go index b1be48450..0c42b5394 100644 --- a/internal/directory/ping/config.go +++ b/internal/directory/ping/config.go @@ -6,7 +6,10 @@ import ( "net/url" "strings" + "github.com/rs/zerolog" + "github.com/pomerium/pomerium/internal/encoding" + "github.com/pomerium/pomerium/internal/httputil" ) type config struct { @@ -44,7 +47,10 @@ func WithEnvironmentID(environmentID string) Option { // WithHTTPClient sets the http client option. func WithHTTPClient(httpClient *http.Client) Option { return func(cfg *config) { - cfg.httpClient = httpClient + cfg.httpClient = httputil.NewLoggingClient(httpClient, + func(evt *zerolog.Event) *zerolog.Event { + return evt.Str("provider", "ping") + }) } } diff --git a/internal/httputil/client.go b/internal/httputil/client.go index eb1b04eba..3b6f3fd28 100644 --- a/internal/httputil/client.go +++ b/internal/httputil/client.go @@ -12,14 +12,61 @@ import ( "net/url" "time" + "github.com/rs/zerolog" + + "github.com/pomerium/pomerium/internal/log" "github.com/pomerium/pomerium/internal/telemetry/metrics" "github.com/pomerium/pomerium/internal/telemetry/requestid" "github.com/pomerium/pomerium/internal/tripper" ) -// ErrTokenRevoked signifies a token revokation or expiration error +// ErrTokenRevoked signifies a token revocation or expiration error var ErrTokenRevoked = errors.New("token expired or revoked") +type loggingRoundTripper struct { + base http.RoundTripper + customize []func(event *zerolog.Event) *zerolog.Event +} + +func (l loggingRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) { + start := time.Now() + res, err := l.base.RoundTrip(req) + statusCode := http.StatusInternalServerError + if res != nil { + statusCode = res.StatusCode + } + evt := log.Debug(req.Context()). + Str("method", req.Method). + Str("authority", req.URL.Host). + Str("path", req.URL.Path). + Dur("duration", time.Since(start)). + Int("response-code", statusCode) + for _, f := range l.customize { + f(evt) + } + evt.Msg("outbound http-request") + return res, err +} + +// NewLoggingRoundTripper creates a http.RoundTripper that will log requests. +func NewLoggingRoundTripper(base http.RoundTripper, customize ...func(event *zerolog.Event) *zerolog.Event) http.RoundTripper { + if base == nil { + base = http.DefaultTransport + } + return loggingRoundTripper{base: base, customize: customize} +} + +// NewLoggingClient creates a new http.Client that will log requests. +func NewLoggingClient(base *http.Client, customize ...func(event *zerolog.Event) *zerolog.Event) *http.Client { + if base == nil { + base = http.DefaultClient + } + newClient := new(http.Client) + *newClient = *base + newClient.Transport = NewLoggingRoundTripper(newClient.Transport, customize...) + return newClient +} + type httpClient struct { *http.Client requestIDTripper http.RoundTripper @@ -33,14 +80,14 @@ func (c *httpClient) Do(req *http.Request) (*http.Response, error) { return c.Client.Do(req) } -// DefaultClient avoids leaks by setting an upper limit for timeouts. -var DefaultClient = &httpClient{ +// defaultClient avoids leaks by setting an upper limit for timeouts. +var defaultClient = &httpClient{ &http.Client{Timeout: 1 * time.Minute}, requestid.NewRoundTripper(http.DefaultTransport), } -// Client provides a simple helper interface to make HTTP requests -func Client(ctx context.Context, method, endpoint, userAgent string, headers map[string]string, params url.Values, response interface{}) error { +// Do provides a simple helper interface to make HTTP requests +func Do(ctx context.Context, method, endpoint, userAgent string, headers map[string]string, params url.Values, response interface{}) error { var body io.Reader switch method { case http.MethodPost: @@ -66,7 +113,7 @@ func Client(ctx context.Context, method, endpoint, userAgent string, headers map req.Header.Set(k, v) } - resp, err := DefaultClient.Do(req) + resp, err := defaultClient.Do(req) if err != nil { return err } diff --git a/internal/httputil/client_test.go b/internal/httputil/client_test.go index b5fd6211b..7bcdb1f12 100644 --- a/internal/httputil/client_test.go +++ b/internal/httputil/client_test.go @@ -21,5 +21,5 @@ func TestDefaultClient(t *testing.T) { defer ts.Close() req, _ := http.NewRequest(http.MethodGet, ts.URL, nil) req = req.WithContext(requestid.WithValue(context.Background(), "foo")) - _, _ = DefaultClient.Do(req) + _, _ = defaultClient.Do(req) } diff --git a/internal/identity/oauth/github/github.go b/internal/identity/oauth/github/github.go index 8ab1a59fc..e86fac835 100644 --- a/internal/identity/oauth/github/github.go +++ b/internal/identity/oauth/github/github.go @@ -134,7 +134,7 @@ func (p *Provider) userEmail(ctx context.Context, t *oauth2.Token, v interface{} } headers := map[string]string{"Authorization": fmt.Sprintf("token %s", t.AccessToken)} emailURL := githubAPIURL + emailPath - err := httputil.Client(ctx, http.MethodGet, emailURL, version.UserAgent(), headers, nil, &response) + err := httputil.Do(ctx, http.MethodGet, emailURL, version.UserAgent(), headers, nil, &response) if err != nil { return err } @@ -169,7 +169,7 @@ func (p *Provider) userInfo(ctx context.Context, t *oauth2.Token, v interface{}) "Authorization": fmt.Sprintf("token %s", t.AccessToken), "Accept": "application/vnd.github.v3+json", } - err := httputil.Client(ctx, http.MethodGet, p.userEndpoint, version.UserAgent(), headers, nil, &response) + err := httputil.Do(ctx, http.MethodGet, p.userEndpoint, version.UserAgent(), headers, nil, &response) if err != nil { return err } diff --git a/internal/identity/oidc/oidc.go b/internal/identity/oidc/oidc.go index 9ffd7cb31..2ea0484f2 100644 --- a/internal/identity/oidc/oidc.go +++ b/internal/identity/oidc/oidc.go @@ -251,7 +251,7 @@ func (p *Provider) Revoke(ctx context.Context, t *oauth2.Token) error { params.Add("client_id", oa.ClientID) params.Add("client_secret", oa.ClientSecret) - err = httputil.Client(ctx, http.MethodPost, p.RevocationURL, version.UserAgent(), nil, params, nil) + err = httputil.Do(ctx, http.MethodPost, p.RevocationURL, version.UserAgent(), nil, params, nil) if err != nil && errors.Is(err, httputil.ErrTokenRevoked) { return fmt.Errorf("internal/oidc: unexpected revoke error: %w", err) } diff --git a/pkg/grpc/databroker/leaser.go b/pkg/grpc/databroker/leaser.go index 5f4519da9..3a35c70d8 100644 --- a/pkg/grpc/databroker/leaser.go +++ b/pkg/grpc/databroker/leaser.go @@ -97,7 +97,7 @@ func (locker *Leaser) runOnce(ctx context.Context, resetBackoff func()) error { resetBackoff() leaseID := res.Id - log.Info(ctx). + log.Debug(ctx). Str("lease_name", locker.leaseName). Str("lease_id", leaseID). Msg("leaser: lease acquired") @@ -136,7 +136,7 @@ func (locker *Leaser) withLease(ctx context.Context, leaseID string) error { Duration: durationpb.New(locker.ttl), }) if status.Code(err) == codes.AlreadyExists { - log.Info(ctx). + log.Debug(ctx). Str("lease_name", locker.leaseName). Str("lease_id", leaseID). Msg("leaser: lease lost")