From 460f20b2eeecb7bd92184c396430c91056ea4ef7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Edgar=20Bellot=20Mic=C3=B3?= Date: Tue, 1 Sep 2026 09:11:57 +0200 Subject: [PATCH] MM-70227: Adjust error detail formatting in session and OAuth flows (#37915) * MM-70207: Adjust error detail formatting in session and OAuth flows See MM-70207. * Decode parameter names before masking token values in OAuth response details * Simplify OAuth token redaction to single regex * Redact token in cloud and remote cluster session log warnings --------- Co-authored-by: Bill Gardner --- server/channels/app/oauth.go | 20 ++- server/channels/app/oauth_test.go | 188 ++++++++++++++++++++++++++- server/channels/web/handlers.go | 21 ++- server/channels/web/handlers_test.go | 128 ++++++++++++++++++ 4 files changed, 347 insertions(+), 10 deletions(-) diff --git a/server/channels/app/oauth.go b/server/channels/app/oauth.go index d85c6e982f3e..b0573e297abe 100644 --- a/server/channels/app/oauth.go +++ b/server/channels/app/oauth.go @@ -11,6 +11,7 @@ import ( "io" "net/http" "net/url" + "regexp" "strconv" "strings" "time" @@ -33,6 +34,19 @@ const ( OpenIDScope = "openid" ) +const oauthTokenRedacted = "[REDACTED]" + +// oauthTokenPattern matches an access_token, refresh_token, or id_token field name (in JSON or +// form-encoded format, with literal, percent-encoded, or JSON-unicode-escaped underscores) followed +// by its value. Group 1 captures everything up to and including the value's opening delimiter so it +// can be preserved in the replacement; group 2 captures the value itself. +var oauthTokenPattern = regexp.MustCompile(`(?i)((?:^|[^0-9a-z_])(?:access|refresh|id)(?:_|%5[Ff]|\\u005[Ff])token\s*"?\s*[=:]\s*"?)((?:[^&;,"'\s}\\]|\\.)*)`) + +// redactOAuthTokenResponse masks token values in a token endpoint response body so it can be used in error details. +func redactOAuthTokenResponse(body string) string { + return oauthTokenPattern.ReplaceAllString(body, "${1}"+oauthTokenRedacted) +} + func (a *App) CreateOAuthApp(app *model.OAuthApp) (*model.OAuthApp, *model.AppError) { // Public method for plugin API - always generates secrets for backward compatibility return a.CreateOAuthAppInternal(app, true) @@ -1111,15 +1125,15 @@ func (a *App) AuthorizeOAuthUser(rctx request.CTX, w http.ResponseWriter, r *htt var ar *model.AccessResponse err = json.NewDecoder(tee).Decode(&ar) if err != nil || resp.StatusCode != http.StatusOK { - return nil, stateProps, nil, model.NewAppError("AuthorizeOAuthUser", "api.user.authorize_oauth_user.bad_response.app_error", nil, fmt.Sprintf("response_body=%s, status_code=%d, error=%v", buf.String(), resp.StatusCode, err), http.StatusInternalServerError).Wrap(err) + return nil, stateProps, nil, model.NewAppError("AuthorizeOAuthUser", "api.user.authorize_oauth_user.bad_response.app_error", nil, fmt.Sprintf("response_body=%s, status_code=%d, error=%v", redactOAuthTokenResponse(buf.String()), resp.StatusCode, err), http.StatusInternalServerError).Wrap(err) } if strings.ToLower(ar.TokenType) != model.AccessTokenType { - return nil, stateProps, nil, model.NewAppError("AuthorizeOAuthUser", "api.user.authorize_oauth_user.bad_token.app_error", nil, "token_type="+ar.TokenType+", response_body="+buf.String(), http.StatusInternalServerError) + return nil, stateProps, nil, model.NewAppError("AuthorizeOAuthUser", "api.user.authorize_oauth_user.bad_token.app_error", nil, "token_type="+ar.TokenType+", response_body="+redactOAuthTokenResponse(buf.String()), http.StatusInternalServerError) } if ar.AccessToken == "" { - return nil, stateProps, nil, model.NewAppError("AuthorizeOAuthUser", "api.user.authorize_oauth_user.missing.app_error", nil, "response_body="+buf.String(), http.StatusInternalServerError) + return nil, stateProps, nil, model.NewAppError("AuthorizeOAuthUser", "api.user.authorize_oauth_user.missing.app_error", nil, "response_body="+redactOAuthTokenResponse(buf.String()), http.StatusInternalServerError) } p = url.Values{} diff --git a/server/channels/app/oauth_test.go b/server/channels/app/oauth_test.go index 5bcfc25d6090..6903c21f6616 100644 --- a/server/channels/app/oauth_test.go +++ b/server/channels/app/oauth_test.go @@ -493,9 +493,11 @@ func TestAuthorizeOAuthUser(t *testing.T) { }) t.Run("with an invalid token type", func(t *testing.T) { + accessToken := model.NewId() + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { err := json.NewEncoder(w).Encode(&model.AccessResponse{ - AccessToken: model.NewId(), + AccessToken: accessToken, TokenType: "", }) require.NoError(t, err) @@ -511,6 +513,59 @@ func TestAuthorizeOAuthUser(t *testing.T) { _, _, _, err := th.App.AuthorizeOAuthUser(th.Context, &httptest.ResponseRecorder{}, request, model.ServiceGitlab, "", state, "") require.NotNil(t, err) assert.Equal(t, "api.user.authorize_oauth_user.bad_token.app_error", err.Id) + assert.NotContains(t, err.DetailedError, accessToken) + assert.NotContains(t, err.Error(), accessToken) + assert.Contains(t, err.DetailedError, `"access_token":"[REDACTED]"`) + }) + + t.Run("with a JSON error token response containing a token", func(t *testing.T) { + accessToken := model.NewId() + + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusTeapot) + _, err := w.Write([]byte(`{"access_token": "` + accessToken + `", "error": "teapot"}`)) + require.NoError(t, err) + })) + defer server.Close() + + th := setup(t, true, true, true, server.URL) + + cookie := model.NewId() + request := makeRequest(cookie) + state := makeState(makeToken(th, cookie)) + + _, _, _, err := th.App.AuthorizeOAuthUser(th.Context, &httptest.ResponseRecorder{}, request, model.ServiceGitlab, "", state, "") + require.NotNil(t, err) + assert.Equal(t, "api.user.authorize_oauth_user.bad_response.app_error", err.Id) + assert.NotContains(t, err.DetailedError, accessToken) + assert.NotContains(t, err.Error(), accessToken) + assert.Contains(t, err.DetailedError, "status_code=418") + assert.Contains(t, err.DetailedError, "teapot") + }) + + t.Run("with a form encoded token response", func(t *testing.T) { + accessToken := model.NewId() + + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/x-www-form-urlencoded") + _, err := w.Write([]byte("access_token=" + accessToken + "&token_type=bearer&scope=read")) + require.NoError(t, err) + })) + defer server.Close() + + th := setup(t, true, true, true, server.URL) + + cookie := model.NewId() + request := makeRequest(cookie) + state := makeState(makeToken(th, cookie)) + + _, _, _, err := th.App.AuthorizeOAuthUser(th.Context, &httptest.ResponseRecorder{}, request, model.ServiceGitlab, "", state, "") + require.NotNil(t, err) + assert.Equal(t, "api.user.authorize_oauth_user.bad_response.app_error", err.Id) + assert.NotContains(t, err.DetailedError, accessToken) + assert.NotContains(t, err.Error(), accessToken) + assert.Contains(t, err.DetailedError, "access_token=[REDACTED]") + assert.Contains(t, err.DetailedError, "scope=read") }) t.Run("with an empty token response", func(t *testing.T) { @@ -2088,3 +2143,134 @@ func TestLoginByIntune_TokenValidationFailure(t *testing.T) { mockIntune.AssertExpectations(t) } + +func TestRedactOAuthTokenResponse(t *testing.T) { + testCases := []struct { + Description string + Body string + Expected string + }{ + { + "empty body", + "", + "", + }, + { + "body without any token", + `{"error":"invalid_grant","error_description":"code expired"}`, + `{"error":"invalid_grant","error_description":"code expired"}`, + }, + { + "json access token", + `{"access_token":"abcd1234","token_type":"bearer"}`, + `{"access_token":"[REDACTED]","token_type":"bearer"}`, + }, + { + "json access token with whitespace", + `{"access_token" : "abcd1234"}`, + `{"access_token" : "[REDACTED]"}`, + }, + { + "json access token with mixed case key", + `{"Access_Token":"abcd1234"}`, + `{"Access_Token":"[REDACTED]"}`, + }, + { + "json refresh and id tokens", + `{"access_token":"a","refresh_token":"b","id_token":"c","expires_in":3600}`, + `{"access_token":"[REDACTED]","refresh_token":"[REDACTED]","id_token":"[REDACTED]","expires_in":3600}`, + }, + { + "form encoded tokens", + "access_token=abcd1234&scope=read&refresh_token=efgh5678", + "access_token=[REDACTED]&scope=read&refresh_token=[REDACTED]", + }, + { + "truncated json body", + `{"access_token":"abcd1234`, + `{"access_token":"[REDACTED]`, + }, + { + "json access token containing an escaped quote", + `{"access_token":"abc\"def","token_type":"bearer"}`, + `{"access_token":"[REDACTED]","token_type":"bearer"}`, + }, + { + "json access token ending with an escaped backslash", + `{"access_token":"abc\\","token_type":"bearer"}`, + `{"access_token":"[REDACTED]","token_type":"bearer"}`, + }, + { + "json access token containing escaped quotes and backslashes", + `{"refresh_token":"a\\b\"c\\\"d","expires_in":3600}`, + `{"refresh_token":"[REDACTED]","expires_in":3600}`, + }, + { + "truncated json body ending with a lone backslash", + `{"access_token":"abcd1234\`, + `{"access_token":"[REDACTED]\`, + }, + { + "json member name with escaped underscore", + `{"access\u005ftoken":"abcd1234","token_type":"bearer"}`, + `{"access\u005ftoken":"[REDACTED]","token_type":"bearer"}`, + }, + { + "json member name with escaped underscore and mixed case", + `{"Refresh\u005FTOKEN":"abcd1234"}`, + `{"Refresh\u005FTOKEN":"[REDACTED]"}`, + }, + { + "form field name with percent encoded underscore", + "access%5Ftoken=abcd1234&scope=read", + "access%5Ftoken=[REDACTED]&scope=read", + }, + { + "form field name with lowercase percent encoded underscore", + "scope=read&id%5ftoken=abcd1234", + "scope=read&id%5ftoken=[REDACTED]", + }, + { + "form encoded body inside a json error field", + `{"error":"access_token=abcd1234"}`, + `{"error":"access_token=[REDACTED]"}`, + }, + { + "form encoded token in json error field preceded by field with = in its value", + `{"error_uri":"https://provider.com/help?code=42","error_description":"access_token=SECRET"}`, + `{"error_uri":"https://provider.com/help?code=42","error_description":"access_token=[REDACTED]"}`, + }, + { + "json member name that merely ends with a token name", + `{"my_access_token_hint":"abcd1234"}`, + `{"my_access_token_hint":"abcd1234"}`, + }, + { + "form field name that merely contains a token name", + "xaccess_token=abcd1234", + "xaccess_token=abcd1234", + }, + } + + for _, tc := range testCases { + t.Run(tc.Description, func(t *testing.T) { + assert.Equal(t, tc.Expected, redactOAuthTokenResponse(tc.Body)) + }) + } + + t.Run("no part of a token value survives redaction", func(t *testing.T) { + for _, body := range []string{ + `{"access_token":"abc\"def","token_type":"bearer"}`, + `{"access_token":"abc\\","token_type":"bearer"}`, + `{"refresh_token":"a\\b\"c\\\"def","expires_in":3600}`, + `{"id_token":"abc\"def"}`, + "access_token=abc%22def&scope=read", + `{"access\u005ftoken":"abcdef"}`, + "access%5Ftoken=abcdef&scope=read", + } { + actual := redactOAuthTokenResponse(body) + assert.NotContains(t, actual, "abc") + assert.NotContains(t, actual, "def") + } + }) +} diff --git a/server/channels/web/handlers.go b/server/channels/web/handlers.go index 25ce33079507..d4622600ece0 100644 --- a/server/channels/web/handlers.go +++ b/server/channels/web/handlers.go @@ -25,6 +25,15 @@ import ( "github.com/mattermost/mattermost/server/v8/channels/utils" ) +// tokenDigest returns a stable, non-reversible identifier for a token, usable for correlation. +func tokenDigest(token string) string { + if token == "" { + return "" + } + + return utils.HashSha256(token)[:16] +} + func GetHandlerName(h func(*Context, http.ResponseWriter, *http.Request)) string { handlerName := runtime.FuncForPC(reflect.ValueOf(h).Pointer()).Name() pos := strings.LastIndex(handlerName, ".") @@ -271,15 +280,15 @@ func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) { session, err := c.App.GetSession(token) if err != nil { - c.Logger.Info("Invalid session", mlog.Err(err)) + c.Logger.Info("Invalid session", mlog.String("error", strings.ReplaceAll(err.Error(), token, tokenDigest(token)))) if err.StatusCode == http.StatusInternalServerError { c.Err = err } else if h.RequireSession { c.RemoveSessionCookie(w, r) - c.Err = model.NewAppError("ServeHTTP", "api.context.session_expired.app_error", nil, "token="+token, http.StatusUnauthorized) + c.Err = model.NewAppError("ServeHTTP", "api.context.session_expired.app_error", nil, "token_sha256="+tokenDigest(token), http.StatusUnauthorized) } } else if !session.IsOAuth && tokenLocation == app.TokenLocationQueryString { - c.Err = model.NewAppError("ServeHTTP", "api.context.token_provided.app_error", nil, "token="+token, http.StatusUnauthorized) + c.Err = model.NewAppError("ServeHTTP", "api.context.token_provided.app_error", nil, "token_sha256="+tokenDigest(token), http.StatusUnauthorized) } else { c.AppContext = c.AppContext.WithSession(session) } @@ -296,13 +305,13 @@ func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) { if csrfChecked && !csrfPassed { c.AppContext = c.AppContext.WithSession(&model.Session{}) c.RemoveSessionCookie(w, r) - c.Err = model.NewAppError("ServeHTTP", "api.context.session_expired.app_error", nil, "token="+token+" Appears to be a CSRF attempt", http.StatusUnauthorized) + c.Err = model.NewAppError("ServeHTTP", "api.context.session_expired.app_error", nil, "token_sha256="+tokenDigest(token)+" Appears to be a CSRF attempt", http.StatusUnauthorized) } } else if token != "" && c.App.Channels().License().IsCloud() && tokenLocation == app.TokenLocationCloudHeader { // Check to see if this provided token matches our CWS Token session, err := c.App.GetCloudSession(token) if err != nil { - c.Logger.Warn("Invalid CWS token", mlog.Err(err)) + c.Logger.Warn("Invalid CWS token", mlog.String("error", strings.ReplaceAll(err.Error(), token, tokenDigest(token)))) c.Err = err } else { c.AppContext = c.AppContext.WithSession(session) @@ -316,7 +325,7 @@ func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) { // Check the token is correct for the remote cluster id. session, err := c.App.GetRemoteClusterSession(token, remoteId) if err != nil { - c.Logger.Warn("Invalid remote cluster token", mlog.Err(err)) + c.Logger.Warn("Invalid remote cluster token", mlog.String("error", strings.ReplaceAll(err.Error(), token, tokenDigest(token)))) c.Err = err } else { c.AppContext = c.AppContext.WithSession(session) diff --git a/server/channels/web/handlers_test.go b/server/channels/web/handlers_test.go index 05ae978d2362..86a161cd7d12 100644 --- a/server/channels/web/handlers_test.go +++ b/server/channels/web/handlers_test.go @@ -1259,3 +1259,131 @@ func TestHandleContextErrorZeroStatusCode(t *testing.T) { assert.Equal(t, http.StatusBadRequest, response.Code) }) } + +func TestTokenDigest(t *testing.T) { + token := model.NewId() + digest := tokenDigest(token) + + assert.NotEmpty(t, digest) + assert.NotContains(t, digest, token) + assert.Equal(t, digest, tokenDigest(token), "should be stable for the same input") + assert.NotEqual(t, digest, tokenDigest(model.NewId()), "should differ for different inputs") + assert.Equal(t, "", tokenDigest("")) +} + +func TestHandlerServeDoesNotLogRawToken(t *testing.T) { + newHandler := func(th *TestHelper) Handler { + web := New(th.Server) + + return Handler{ + Srv: web.srv, + HandleFunc: handlerForCSRFToken, + RequireSession: true, + TrustRequester: false, + RequireMfa: false, + IsStatic: false, + } + } + + newSession := func(t *testing.T, th *TestHelper, isOAuth bool) *model.Session { + session := &model.Session{ + UserId: th.BasicUser.Id, + CreateAt: model.GetMillis(), + Roles: model.SystemUserRoleId, + IsOAuth: isOAuth, + } + session.GenerateCSRF() + th.App.SetSessionExpireInHours(session, 24) + + session, appErr := th.App.CreateSession(th.Context, session) + require.Nil(t, appErr) + + return session + } + + captureLogs := func(t *testing.T, th *TestHelper) *mlog.Buffer { + buffer := &mlog.Buffer{} + require.NoError(t, mlog.AddWriterTarget(th.TestLogger, buffer, true, mlog.StdAll...)) + + return buffer + } + + t.Run("expired or unknown session token", func(t *testing.T) { + th := Setup(t).InitBasic(t) + buffer := captureLogs(t, th) + + token := model.NewId() + handler := newHandler(th) + + request := httptest.NewRequest("GET", "/api/v4/test", nil) + request.AddCookie(&http.Cookie{Name: model.SessionCookieToken, Value: token}) + response := httptest.NewRecorder() + handler.ServeHTTP(response, request) + + require.Equal(t, http.StatusUnauthorized, response.Code) + require.NoError(t, th.TestLogger.Flush()) + + logs := buffer.String() + assert.NotContains(t, logs, token) + assert.Contains(t, logs, tokenDigest(token)) + }) + + t.Run("session token provided in the query string", func(t *testing.T) { + th := Setup(t).InitBasic(t) + buffer := captureLogs(t, th) + + session := newSession(t, th, false) + handler := newHandler(th) + + request := httptest.NewRequest("GET", "/api/v4/test?access_token="+session.Token, nil) + response := httptest.NewRecorder() + handler.ServeHTTP(response, request) + + require.Equal(t, http.StatusUnauthorized, response.Code) + require.NoError(t, th.TestLogger.Flush()) + + logs := buffer.String() + assert.NotContains(t, logs, session.Token) + assert.Contains(t, logs, tokenDigest(session.Token)) + }) + + t.Run("failed CSRF check", func(t *testing.T) { + th := Setup(t).InitBasic(t) + buffer := captureLogs(t, th) + + session := newSession(t, th, false) + handler := newHandler(th) + + request := httptest.NewRequest("POST", "/api/v4/test", nil) + request.AddCookie(&http.Cookie{Name: model.SessionCookieToken, Value: session.Token}) + response := httptest.NewRecorder() + handler.ServeHTTP(response, request) + + require.Equal(t, http.StatusUnauthorized, response.Code) + require.NoError(t, th.TestLogger.Flush()) + + logs := buffer.String() + assert.NotContains(t, logs, session.Token) + assert.Contains(t, logs, "Appears to be a CSRF attempt") + assert.Contains(t, logs, tokenDigest(session.Token)) + }) + + t.Run("valid session is served without logging the token", func(t *testing.T) { + th := Setup(t).InitBasic(t) + buffer := captureLogs(t, th) + + session := newSession(t, th, false) + handler := newHandler(th) + + request := httptest.NewRequest("POST", "/api/v4/test", nil) + request.AddCookie(&http.Cookie{Name: model.SessionCookieToken, Value: session.Token}) + request.Header.Set(model.HeaderCsrfToken, session.GetCSRF()) + response := httptest.NewRecorder() + handler.ServeHTTP(response, request) + + require.Equal(t, http.StatusOK, response.Code) + require.NoError(t, th.TestLogger.Flush()) + + assert.NotContains(t, buffer.String(), session.Token) + }) +}