diff --git a/internal/oidc/auth/auth_handler.go b/internal/oidc/auth/auth_handler.go index d74ad094..7eb31e31 100644 --- a/internal/oidc/auth/auth_handler.go +++ b/internal/oidc/auth/auth_handler.go @@ -9,17 +9,17 @@ import ( "net/http" "time" + "go.pinniped.dev/internal/plog" + "github.com/ory/fosite" "github.com/ory/fosite/handler/openid" "github.com/ory/fosite/token/jwt" - "golang.org/x/oauth2" - "k8s.io/klog/v2" - "go.pinniped.dev/internal/httputil/httperr" "go.pinniped.dev/internal/oidc/provider" "go.pinniped.dev/internal/oidcclient/nonce" "go.pinniped.dev/internal/oidcclient/pkce" "go.pinniped.dev/internal/oidcclient/state" + "golang.org/x/oauth2" ) type IDPListGetter interface { @@ -44,14 +44,14 @@ func NewHandler( authorizeRequester, err := oauthHelper.NewAuthorizeRequest(r.Context(), r) if err != nil { - klog.InfoS("authorize request error", "err", err, "details", fosite.ErrorToRFC6749Error(err).ToValues()) + plog.Info("authorize request error", fositeErrorForLog(err)...) oauthHelper.WriteAuthorizeError(w, authorizeRequester, err) return nil } upstreamIDP, err := chooseUpstreamIDP(idpListGetter) if err != nil { - klog.InfoS("authorize request upstream selection error", "err", err) + plog.InfoErr("authorize request error", err) return err } @@ -72,14 +72,14 @@ func NewHandler( }, }) if err != nil { - klog.InfoS("authorize response error", "err", err, "details", fosite.ErrorToRFC6749Error(err).ToValues()) + plog.Info("authorize response error", fositeErrorForLog(err)...) oauthHelper.WriteAuthorizeError(w, authorizeRequester, err) return nil } stateValue, nonceValue, pkceValue, err := generateParams(generateState, generateNonce, generatePKCE) if err != nil { - klog.InfoS("authorize generate error", "err", err) + plog.InfoErr("authorize generate error", err) return err } @@ -130,18 +130,30 @@ func generateParams( ) (state.State, nonce.Nonce, pkce.Code, error) { stateValue, err := generateState() if err != nil { - klog.InfoS("error generating state param", "err", err) + plog.InfoErr("error generating state param", err) return "", "", "", httperr.Wrap(http.StatusInternalServerError, "error generating state param", err) } nonceValue, err := generateNonce() if err != nil { - klog.InfoS("error generating nonce param", "err", err) + plog.InfoErr("error generating nonce param", err) return "", "", "", httperr.Wrap(http.StatusInternalServerError, "error generating nonce param", err) } pkceValue, err := generatePKCE() if err != nil { - klog.InfoS("error generating PKCE param", "err", err) + plog.InfoErr("error generating PKCE param", err) return "", "", "", httperr.Wrap(http.StatusInternalServerError, "error generating PKCE param", err) } return stateValue, nonceValue, pkceValue, nil } + +func fositeErrorForLog(err error) []interface{} { + rfc6749Error := fosite.ErrorToRFC6749Error(err) + keysAndValues := make([]interface{}, 0) + keysAndValues = append(keysAndValues, "name") + keysAndValues = append(keysAndValues, rfc6749Error.Name) + keysAndValues = append(keysAndValues, "status") + keysAndValues = append(keysAndValues, rfc6749Error.Status()) + keysAndValues = append(keysAndValues, "description") + keysAndValues = append(keysAndValues, rfc6749Error.Description) + return keysAndValues +} diff --git a/internal/plog/plog.go b/internal/plog/plog.go index b22450fb..d3b6efa8 100644 --- a/internal/plog/plog.go +++ b/internal/plog/plog.go @@ -5,6 +5,7 @@ package plog import "k8s.io/klog/v2" +// Use Error to log an unexpected system error. func Error(err error, msg string, keysAndValues ...interface{}) { klog.ErrorS(err, msg, keysAndValues...) } @@ -22,6 +23,11 @@ func Info(msg string, keysAndValues ...interface{}) { klog.V(klogLevelInfo).InfoS(msg, keysAndValues...) } +// Use InfoErr to log an expected error, e.g. validation failure of an http parameter. +func InfoErr(msg string, err error, keysAndValues ...interface{}) { + klog.V(klogLevelInfo).InfoS(msg, append([]interface{}{"error", err}, keysAndValues)...) +} + func Debug(msg string, keysAndValues ...interface{}) { klog.V(klogLevelDebug).InfoS(msg, keysAndValues...) }