Merge pull request #424 from MadAppGang/featue/log-tokens

hummerdmag · web-flow · commit f6a061d55b11 · 2024-12-24T13:13:14.000+02:00
Log tokens for audit records
diff --git a/model/server_settings.go b/model/server_settings.go
@@ -27,6 +27,7 @@ type ServerSettings struct {
 	KeyStorage     FileStorageSettings    `yaml:"keyStorage" json:"key_storage"`
 	Config         FileStorageSettings    `yaml:"-" json:"config"`
 	Logger         LoggerSettings         `yaml:"logger" json:"logger"`
+	Audit          AuditSettings          `yaml:"audit" json:"audit"`
 	AdminPanel     AdminPanelSettings     `yaml:"adminPanel" json:"admin_panel"`
 	LoginWebApp    FileStorageSettings    `yaml:"loginWebApp" json:"login_web_app"`
 	EmailTemplates FileStorageSettings    `yaml:"emailTemplates" json:"email_templates"`
@@ -368,6 +369,7 @@ type LoggerSettings struct {
 	// Deprecated: User HTTPDetailing on module level.
 	DumpRequest      bool         `yaml:"dumpRequest" json:"dumpRequest"`
 	Format           string       `yaml:"format" json:"format"`
+	MaxBodySize      int          `yaml:"maxBodySize" json:"maxBodySize"`
 	LogSensitiveData bool         `yaml:"logSensitiveData" json:"logSensitiveData"`
 	Common           LoggerParams `yaml:"common" json:"common"`
 	API              LoggerParams `yaml:"api" json:"api"`
@@ -388,6 +390,18 @@ func HTTPLogDetailing(dumpRequest bool, logType HTTPDetailing) HTTPDetailing {
 	return logType
 }
 
+type TokenRecording string
+
+const (
+	TokenRecordingNone       TokenRecording = "none"
+	TokenRecordingObfuscated TokenRecording = "obfuscated"
+	TokenRecordingFull       TokenRecording = "full"
+)
+
+type AuditSettings struct {
+	TokenRecording TokenRecording `yaml:"tokenRecording" json:"tokenRecording"`
+}
+
 type AdminPanelSettings struct {
 	Enabled bool `json:"enabled" yaml:"enabled"`
 }
diff --git a/model/server_settings_validation.go b/model/server_settings_validation.go
@@ -1,6 +1,7 @@
 package model
 
 import (
+	"errors"
 	"fmt"
 	"net/url"
 	"os"
@@ -146,7 +147,7 @@ func (sss *SessionStorageSettings) Validate() []error {
 	result := []error{}
 
 	if len(sss.Type) == 0 {
-		result = append(result, fmt.Errorf("Empty session storage type"))
+		result = append(result, errors.New("empty session storage type"))
 	}
 	if sss.SessionDuration.Duration == 0 {
 		result = append(result, fmt.Errorf("%s. Session duration is 0 seconds", subject))
@@ -226,7 +227,7 @@ func (sss *SMSServiceSettings) Validate() []error {
 	subject := "SMSServiceSettings"
 	result := []error{}
 	if len(sss.Type) == 0 {
-		return []error{fmt.Errorf("Empty SMS service type")}
+		return []error{errors.New("empty SMS service type")}
 	}
 
 	switch sss.Type {
diff --git a/web/admin/router.go b/web/admin/router.go
@@ -57,6 +57,7 @@ func NewRouter(settings RouterSettings) (model.Router, error) {
 	ar.middleware = buildMiddleware(
 		settings.LoggerSettings.DumpRequest,
 		settings.LoggerSettings.Format,
+		settings.LoggerSettings.MaxBodySize,
 		settings.LoggerSettings.Admin,
 		settings.LoggerSettings.LogSensitiveData,
 		settings.Cors)
@@ -70,6 +71,7 @@ func NewRouter(settings RouterSettings) (model.Router, error) {
 func buildMiddleware(
 	dumpRequest bool,
 	format string,
+	maxBodySize int,
 	logParams model.LoggerParams,
 	logSensitiveData bool,
 	corsHandler *cors.Cors,
@@ -79,6 +81,7 @@ func buildMiddleware(
 	lm := middleware.NegroniHTTPLogger(
 		logging.ComponentAdmin,
 		format,
+		maxBodySize,
 		logParams,
 		model.HTTPLogDetailing(dumpRequest, logParams.HTTPDetailing),
 		!logSensitiveData,
diff --git a/web/api/2fa.go b/web/api/2fa.go
@@ -306,8 +306,9 @@ func (ar *Router) FinalizeTFA() http.HandlerFunc {
 			}
 		}
 
-		ar.journal(JournalOperationLoginWith2FA,
-			user.ID, app.ID, r.UserAgent(), user.AccessRole, scopes.Scopes())
+		ar.audit(AuditOperationLoginWith2FA,
+			user.ID, app.ID, r.UserAgent(), user.AccessRole, scopes.Scopes(),
+			result.AccessToken, result.RefreshToken)
 
 		ar.server.Storages().User.UpdateLoginMetadata(user.ID)
 		ar.ServeJSON(w, locale, http.StatusOK, result)
diff --git a/web/api/federated_login.go b/web/api/federated_login.go
@@ -212,8 +212,9 @@ func (ar *Router) FederatedLoginComplete() http.HandlerFunc {
 		authResult.CallbackUrl = fsess.CallbackUrl
 		authResult.Scopes = fsess.Scopes
 
-		ar.journal(JournalOperationFederatedLogin,
-			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes())
+		ar.audit(AuditOperationFederatedLogin,
+			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes(),
+			authResult.AccessToken, authResult.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, authResult)
 	}
diff --git a/web/api/federated_oidc_login.go b/web/api/federated_oidc_login.go
@@ -249,8 +249,9 @@ func (ar *Router) OIDCLoginComplete(useSession bool) http.HandlerFunc {
 		authResult.Scopes = resultScopes.Scopes()
 		authResult.ProviderData = *providerData
 
-		ar.journal(JournalOperationOIDCLogin,
-			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes())
+		ar.audit(AuditOperationOIDCLogin,
+			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes(),
+			authResult.AccessToken, authResult.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, authResult)
 	}
diff --git a/web/api/impersonate_as.go b/web/api/impersonate_as.go
@@ -77,8 +77,9 @@ func (ar *Router) ImpersonateAs() http.HandlerFunc {
 		// do not allow refresh for impersonated user
 		authResult.RefreshToken = ""
 
-		ar.journal(JournalOperationImpersonatedAs,
-			userID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes())
+		ar.audit(AuditOperationImpersonatedAs,
+			userID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes(),
+			authResult.AccessToken, authResult.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, authResult)
 	}
diff --git a/web/api/journal.go b/web/api/journal.go
@@ -2,29 +2,36 @@ package api
 
 import (
 	"github.com/madappgang/identifo/v2/logging"
+	"github.com/madappgang/identifo/v2/model"
 )
 
-type JournalOperation string
+type AuditOperation string
 
 const (
-	JournalOperationLoginWithPassword JournalOperation = "login_with_password"
-	JournalOperationLoginWithPhone    JournalOperation = "login_with_phone"
-	JournalOperationLoginWith2FA      JournalOperation = "login_with_2fa"
-	JournalOperationRefreshToken      JournalOperation = "refresh_token"
-	JournalOperationOIDCLogin         JournalOperation = "oidc_login"
-	JournalOperationFederatedLogin    JournalOperation = "federated_login"
-	JournalOperationRegistration      JournalOperation = "registration"
-	JournalOperationLogout            JournalOperation = "logout"
-	JournalOperationImpersonatedAs    JournalOperation = "impersonated_as"
+	AuditOperationLoginWithPassword AuditOperation = "login_with_password"
+	AuditOperationLoginWithPhone    AuditOperation = "login_with_phone"
+	AuditOperationLoginWith2FA      AuditOperation = "login_with_2fa"
+	AuditOperationRefreshToken      AuditOperation = "refresh_token"
+	AuditOperationOIDCLogin         AuditOperation = "oidc_login"
+	AuditOperationFederatedLogin    AuditOperation = "federated_login"
+	AuditOperationRegistration      AuditOperation = "registration"
+	AuditOperationLogout            AuditOperation = "logout"
+	AuditOperationImpersonatedAs    AuditOperation = "impersonated_as"
 )
 
-func (ar *Router) journal(
-	op JournalOperation,
+func (ar *Router) audit(
+	op AuditOperation,
 	userID, appID, device, accessRole string,
 	scopes []string,
+	accessToken, refreshToken string,
 ) {
 	iss := ar.server.Services().Token.Issuer()
 
+	auditSettings := ar.server.Settings().Audit
+
+	accessToken = maskToken(accessToken, auditSettings.TokenRecording)
+	refreshToken = maskToken(refreshToken, auditSettings.TokenRecording)
+
 	// TODO: Create an interface for the audit log
 	// Implement it for logging to stdout, a database, or a remote service
 	ar.logger.Info("audit_record",
@@ -35,5 +42,24 @@ func (ar *Router) journal(
 		"issuer", iss,
 		"accessRole", accessRole,
 		"scopes", scopes,
+		"accessToken", accessToken,
+		"refreshToken", refreshToken,
 	)
 }
+
+func maskToken(token string, tokenRecording model.TokenRecording) string {
+	switch tokenRecording {
+	case model.TokenRecordingNone:
+		return "<redacted>"
+	case model.TokenRecordingObfuscated:
+		if len(token) < 32 {
+			return "<short>"
+		}
+
+		return token[:6] + "..." + token[len(token)-6:]
+	case model.TokenRecordingFull:
+		return token
+	default:
+		return "<redacted>"
+	}
+}
diff --git a/web/api/login.go b/web/api/login.go
@@ -189,8 +189,9 @@ func (ar *Router) LoginWithPassword() http.HandlerFunc {
 			return
 		}
 
-		ar.journal(JournalOperationLoginWithPassword,
-			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes())
+		ar.audit(AuditOperationLoginWithPassword,
+			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes(),
+			authResult.AccessToken, authResult.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, authResult)
 	}
diff --git a/web/api/logout.go b/web/api/logout.go
@@ -64,8 +64,9 @@ func (ar *Router) Logout() http.HandlerFunc {
 			}
 		}
 
-		ar.journal(JournalOperationLogout,
-			accessToken.Subject(), accessToken.Audience(), r.UserAgent(), "", nil)
+		ar.audit(AuditOperationLogout,
+			accessToken.Subject(), accessToken.Audience(), r.UserAgent(), "", nil,
+			accessTokenString, d.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, result)
 	}
diff --git a/web/api/phone_login.go b/web/api/phone_login.go
@@ -169,8 +169,9 @@ func (ar *Router) PhoneLogin() http.HandlerFunc {
 			User:         user,
 		}
 
-		ar.journal(JournalOperationLoginWithPhone,
-			user.ID, app.ID, r.UserAgent(), user.AccessRole, scopes.Scopes())
+		ar.audit(AuditOperationLoginWithPhone,
+			user.ID, app.ID, r.UserAgent(), user.AccessRole, scopes.Scopes(),
+			result.AccessToken, result.RefreshToken)
 
 		ar.server.Storages().User.UpdateLoginMetadata(user.ID)
 
@@ -208,7 +209,7 @@ func (l *PhoneLogin) validateCodeAndPhone() error {
 
 func (l *PhoneLogin) validatePhone() error {
 	if !model.PhoneRegexp.MatchString(l.PhoneNumber) {
-		return errors.New("ohone number is not valid")
+		return errors.New("phone number is not valid")
 	}
 	return nil
 }
diff --git a/web/api/refresh_token.go b/web/api/refresh_token.go
@@ -89,8 +89,9 @@ func (ar *Router) RefreshTokens() http.HandlerFunc {
 		}
 
 		resultScopes := strings.Split(accessToken.Scopes(), " ")
-		ar.journal(JournalOperationRefreshToken,
-			oldRefreshToken.Subject(), app.ID, r.UserAgent(), "", resultScopes)
+		ar.audit(AuditOperationRefreshToken,
+			oldRefreshToken.Subject(), app.ID, r.UserAgent(), "", resultScopes,
+			result.AccessToken, result.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, result)
 	}
diff --git a/web/api/registration.go b/web/api/registration.go
@@ -179,8 +179,9 @@ func (ar *Router) RegisterWithPassword() http.HandlerFunc {
 			return
 		}
 
-		ar.journal(JournalOperationRegistration,
-			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes())
+		ar.audit(AuditOperationRegistration,
+			user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes(),
+			authResult.AccessToken, authResult.RefreshToken)
 
 		ar.ServeJSON(w, locale, http.StatusOK, authResult)
 	}
diff --git a/web/api/router.go b/web/api/router.go
@@ -1,6 +1,7 @@
 package api
 
 import (
+	"context"
 	"encoding/json"
 	"fmt"
 	"log/slog"
@@ -155,11 +156,20 @@ func (ar *Router) error(w http.ResponseWriter, callerDepth int, locale string, s
 	}
 	message := ar.ls.SL(locale, errID, details...)
 
-	ar.logger.Error("api error",
+	logLevel := slog.LevelWarn
+	if status >= 500 {
+		logLevel = slog.LevelError
+	}
+
+	ar.logger.Log(
+		context.Background(),
+		logLevel,
+		"api error",
 		logging.FieldErrorID, errID,
 		"status", status,
 		"details", message,
-		"where", fmt.Sprintf("%v:%d", file, no))
+		"where", fmt.Sprintf("%v:%d", file, no),
+	)
 
 	// Write generic error response.
 	w.Header().Set("Content-Type", "application/json")
diff --git a/web/api/routes.go b/web/api/routes.go
@@ -28,6 +28,7 @@ func (ar *Router) initRoutes(
 	baseMiddleware := buildBaseMiddleware(
 		loggerSettings.DumpRequest,
 		loggerSettings.Format,
+		loggerSettings.MaxBodySize,
 		loggerSettings.API,
 		loggerSettings.LogSensitiveData,
 		ar.cors,
@@ -58,6 +59,7 @@ func (ar *Router) initRoutes(
 func buildBaseMiddleware(
 	dumpRequest bool,
 	format string,
+	maxBodySize int,
 	logParams model.LoggerParams,
 	logSensitiveData bool,
 	cors *cors.Cors,
@@ -81,6 +83,7 @@ func buildBaseMiddleware(
 	lm := middleware.NegroniHTTPLogger(
 		logging.ComponentAPI,
 		format,
+		maxBodySize,
 		logParams,
 		model.HTTPLogDetailing(dumpRequest, logParams.HTTPDetailing),
 		!logSensitiveData,
diff --git a/web/management/routes.go b/web/management/routes.go
@@ -16,6 +16,7 @@ func (ar *Router) initRoutes(loggerSettings model.LoggerSettings) {
 	lm := imiddleware.HTTPLogger(
 		logging.ComponentAPI,
 		loggerSettings.Format,
+		loggerSettings.MaxBodySize,
 		loggerSettings.Management,
 		model.HTTPLogDetailing(loggerSettings.DumpRequest, loggerSettings.Management.HTTPDetailing),
 		!loggerSettings.LogSensitiveData,
diff --git a/web/middleware/logger.go b/web/middleware/logger.go
@@ -15,12 +15,13 @@ import (
 func NegroniHTTPLogger(
 	component string,
 	format string,
+	maxBodySize int,
 	logParams model.LoggerParams,
 	httpDetailing model.HTTPDetailing,
 	excludeAuth bool,
 	exclude ...string,
 ) negroni.Handler {
-	logger := HTTPLogger(component, format, logParams, httpDetailing, excludeAuth, exclude...)
+	logger := HTTPLogger(component, format, maxBodySize, logParams, httpDetailing, excludeAuth, exclude...)
 
 	return negroni.HandlerFunc(func(w http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
 		logger(next).ServeHTTP(w, r)
@@ -34,6 +35,7 @@ func emptyMiddleware(next http.Handler) http.Handler {
 func HTTPLogger(
 	component string,
 	format string,
+	maxBodySize int,
 	logParams model.LoggerParams,
 	httpDetailing model.HTTPDetailing,
 	excludeAuth bool,
@@ -96,6 +98,12 @@ func HTTPLogger(
 			return true, logBody(r.URL.Path)
 		}))
 
+		if maxBodySize <= 0 {
+			maxBodySize = httpdump.DefaultBodySize
+		}
+
+		opts = append(opts, httpdump.WithLimitedBody(maxBodySize))
+
 		hd := httpdump.NewMiddlewareWrapper(dumpReq, dumpResp, opts...)
 		return hd
 	}
diff --git a/web/spa/router.go b/web/spa/router.go
@@ -24,6 +24,7 @@ func NewRouter(setting SPASettings, middlewares []negroni.Handler) (model.Router
 		setting.Name,
 		setting.LoggerSettings.DumpRequest,
 		setting.LoggerSettings.Format,
+		setting.LoggerSettings.MaxBodySize,
 		setting.LoggerSettings.SPA,
 		!setting.LoggerSettings.LogSensitiveData,
 		middlewares,
@@ -50,13 +51,15 @@ func buildMiddleware(
 	settingName string,
 	dumpRequest bool,
 	format string,
+	maxBodySize int,
 	logParams model.LoggerParams,
 	logSensitiveData bool,
 	middlewares []negroni.Handler,
 ) *negroni.Negroni {
 	lm := middleware.NegroniHTTPLogger(
 		settingName,
 		format,
+		maxBodySize,
 		logParams,
 		model.HTTPLogDetailing(dumpRequest, logParams.HTTPDetailing),
 		!logSensitiveData,

Original file line number	Diff line number	Diff line change
`@@ -306,8 +306,9 @@ func (ar *Router) FinalizeTFA() http.HandlerFunc {`
`306`	`306`	`}`
`307`	`307`	`}`
`308`	`308`
`309`		`- ar.journal(JournalOperationLoginWith2FA,`
`310`		`- user.ID, app.ID, r.UserAgent(), user.AccessRole, scopes.Scopes())`
	`309`	`+ ar.audit(AuditOperationLoginWith2FA,`
	`310`	`+ user.ID, app.ID, r.UserAgent(), user.AccessRole, scopes.Scopes(),`
	`311`	`+ result.AccessToken, result.RefreshToken)`
`311`	`312`
`312`	`313`	`ar.server.Storages().User.UpdateLoginMetadata(user.ID)`
`313`	`314`	`ar.ServeJSON(w, locale, http.StatusOK, result)`
Original file line number	Diff line number	Diff line change
`@@ -189,8 +189,9 @@ func (ar *Router) LoginWithPassword() http.HandlerFunc {`
`189`	`189`	`return`
`190`	`190`	`}`
`191`	`191`
`192`		`- ar.journal(JournalOperationLoginWithPassword,`
`193`		`- user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes())`
	`192`	`+ ar.audit(AuditOperationLoginWithPassword,`
	`193`	`+ user.ID, app.ID, r.UserAgent(), user.AccessRole, resultScopes.Scopes(),`
	`194`	`+ authResult.AccessToken, authResult.RefreshToken)`
`194`	`195`
`195`	`196`	`ar.ServeJSON(w, locale, http.StatusOK, authResult)`
`196`	`197`	`}`
Original file line number	Diff line number	Diff line change
`@@ -64,8 +64,9 @@ func (ar *Router) Logout() http.HandlerFunc {`
`64`	`64`	`}`
`65`	`65`	`}`
`66`	`66`
`67`		`- ar.journal(JournalOperationLogout,`
`68`		`- accessToken.Subject(), accessToken.Audience(), r.UserAgent(), "", nil)`
	`67`	`+ ar.audit(AuditOperationLogout,`
	`68`	`+ accessToken.Subject(), accessToken.Audience(), r.UserAgent(), "", nil,`
	`69`	`+ accessTokenString, d.RefreshToken)`
`69`	`70`
`70`	`71`	`ar.ServeJSON(w, locale, http.StatusOK, result)`
`71`	`72`	`}`