feat(regulator): enhance authentication logs (#2622)

This adds additional logging to the authentication logs such as type, remote IP, request method, redirect URL, and if the attempt was done during a ban. This also means we log attempts that occur when the attempt was blocked by the regulator for record keeping purposes, as well as record 2FA attempts which can be used to inform admins and later to regulate based on other factors.

Fixes #116, Fixes #1293.

internal/handlers/const.go

@@ -45,6 +45,17 @@ const (
 	messageMFAValidationFailed             = "Authentication failed, please retry later."
 )
 
+const (
+	logFmtErrParseRequestBody     = "Failed to parse %s request body: %+v"
+	logFmtErrWriteResponseBody    = "Failed to write %s response body for user '%s': %+v"
+	logFmtErrRegulationFail       = "Failed to perform %s authentication regulation for user '%s': %+v"
+	logFmtErrSessionRegenerate    = "Could not regenerate session during %s authentication for user '%s': %+v"
+	logFmtErrSessionReset         = "Could not reset session during %s authentication for user '%s': %+v"
+	logFmtErrSessionSave          = "Could not save session with the %s during %s authentication for user '%s': %+v"
+	logFmtErrObtainProfileDetails = "Could not obtain profile details during %s authentication for user '%s': %+v"
+	logFmtTraceProfileDetails     = "Profile details for user '%s' => groups: %s, emails %s"
+)
+
 const (
 	testInactivity     = "10"
 	testRedirectionURL = "http://redirection.local"

internal/handlers/handler_firstfactor.go

@@ -1,7 +1,7 @@
 package handlers
 
 import (
-	"fmt"
+	"errors"
 	"math"
 	"math/rand"
 	"sync"
@@ -70,78 +70,72 @@ func FirstFactorPost(msInitialDelay time.Duration, delayEnabled bool) middleware
 		}
 
 		bodyJSON := firstFactorRequestBody{}
-		err := ctx.ParseBody(&bodyJSON)
 
-		if err != nil {
+		if err := ctx.ParseBody(&bodyJSON); err != nil {
-			handleAuthenticationUnauthorized(ctx, err, messageAuthenticationFailed)
+			ctx.Logger.Errorf(logFmtErrParseRequestBody, regulation.AuthType1FA, err)
+
+			respondUnauthorized(ctx, messageAuthenticationFailed)
+
 			return
 		}
 
-		bannedUntil, err := ctx.Providers.Regulator.Regulate(ctx, bodyJSON.Username)
+		if bannedUntil, err := ctx.Providers.Regulator.Regulate(ctx, bodyJSON.Username); err != nil {
+			if errors.Is(err, regulation.ErrUserIsBanned) {
+				_ = markAuthenticationAttempt(ctx, false, &bannedUntil, bodyJSON.Username, regulation.AuthType1FA, nil)
+
+				respondUnauthorized(ctx, messageAuthenticationFailed)
 
-		if err != nil {
-			if err == regulation.ErrUserIsBanned {
-				handleAuthenticationUnauthorized(ctx, fmt.Errorf("user %s is banned until %s", bodyJSON.Username, bannedUntil), messageAuthenticationFailed)
 				return
 			}
 
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to regulate authentication: %s", err.Error()), messageAuthenticationFailed)
+			ctx.Logger.Errorf(logFmtErrRegulationFail, regulation.AuthType1FA, bodyJSON.Username, err)
+
+			respondUnauthorized(ctx, messageAuthenticationFailed)
 
 			return
 		}
 
 		userPasswordOk, err := ctx.Providers.UserProvider.CheckUserPassword(bodyJSON.Username, bodyJSON.Password)
-
 		if err != nil {
-			ctx.Logger.Debugf("Mark authentication attempt made by user %s", bodyJSON.Username)
+			_ = markAuthenticationAttempt(ctx, false, nil, bodyJSON.Username, regulation.AuthType1FA, err)
 
-			if err := ctx.Providers.Regulator.Mark(ctx, bodyJSON.Username, false); err != nil {
+			respondUnauthorized(ctx, messageAuthenticationFailed)
-				ctx.Logger.Errorf("Unable to mark authentication: %s", err.Error())
-			}
-
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("error while checking password for user %s: %s", bodyJSON.Username, err.Error()), messageAuthenticationFailed)
 
 			return
 		}
 
 		if !userPasswordOk {
-			ctx.Logger.Debugf("Mark authentication attempt made by user %s", bodyJSON.Username)
+			_ = markAuthenticationAttempt(ctx, false, nil, bodyJSON.Username, regulation.AuthType1FA, nil)
 
-			if err := ctx.Providers.Regulator.Mark(ctx, bodyJSON.Username, false); err != nil {
+			respondUnauthorized(ctx, messageAuthenticationFailed)
-				ctx.Logger.Errorf("Unable to mark authentication: %s", err.Error())
-			}
-
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("credentials are wrong for user %s", bodyJSON.Username), messageAuthenticationFailed)
 
 			return
 		}
 
-		ctx.Logger.Debugf("Mark authentication attempt made by user %s", bodyJSON.Username)
+		if err = markAuthenticationAttempt(ctx, true, nil, bodyJSON.Username, regulation.AuthType1FA, nil); err != nil {
-		err = ctx.Providers.Regulator.Mark(ctx, bodyJSON.Username, true)
+			respondUnauthorized(ctx, messageAuthenticationFailed)
 
-		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to mark authentication: %s", err.Error()), messageAuthenticationFailed)
 			return
 		}
 
-		ctx.Logger.Debugf("Credentials validation of user %s is ok", bodyJSON.Username)
-
 		userSession := ctx.GetSession()
 		newSession := session.NewDefaultUserSession()
 		newSession.OIDCWorkflowSession = userSession.OIDCWorkflowSession
 
 		// Reset all values from previous session except OIDC workflow before regenerating the cookie.
-		err = ctx.SaveSession(newSession)
+		if err = ctx.SaveSession(newSession); err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionReset, regulation.AuthType1FA, bodyJSON.Username, err)
+
+			respondUnauthorized(ctx, messageAuthenticationFailed)
 
-		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to reset the session for user %s: %s", bodyJSON.Username, err.Error()), messageAuthenticationFailed)
 			return
 		}
 
-		err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx)
+		if err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx); err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionRegenerate, regulation.AuthType1FA, bodyJSON.Username, err)
+
+			respondUnauthorized(ctx, messageAuthenticationFailed)
 
-		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to regenerate session for user %s: %s", bodyJSON.Username, err.Error()), messageAuthenticationFailed)
 			return
 		}
 
@@ -152,20 +146,25 @@ func FirstFactorPost(msInitialDelay time.Duration, delayEnabled bool) middleware
 		if keepMeLoggedIn {
 			err = ctx.Providers.SessionProvider.UpdateExpiration(ctx.RequestCtx, ctx.Providers.SessionProvider.RememberMe)
 			if err != nil {
-				handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to update expiration timer for user %s: %s", bodyJSON.Username, err.Error()), messageAuthenticationFailed)
+				ctx.Logger.Errorf(logFmtErrSessionSave, "updated expiration", regulation.AuthType1FA, bodyJSON.Username, err)
+
+				respondUnauthorized(ctx, messageAuthenticationFailed)
+
 				return
 			}
 		}
 
 		// Get the details of the given user from the user provider.
 		userDetails, err := ctx.Providers.UserProvider.GetDetails(bodyJSON.Username)
-
 		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("error while retrieving details from user %s: %s", bodyJSON.Username, err.Error()), messageAuthenticationFailed)
+			ctx.Logger.Errorf(logFmtErrObtainProfileDetails, regulation.AuthType1FA, bodyJSON.Username, err)
+
+			respondUnauthorized(ctx, messageAuthenticationFailed)
+
 			return
 		}
 
-		ctx.Logger.Tracef("Details for user %s => groups: %s, emails %s", bodyJSON.Username, userDetails.Groups, userDetails.Emails)
+		ctx.Logger.Tracef(logFmtTraceProfileDetails, bodyJSON.Username, userDetails.Groups, userDetails.Emails)
 
 		userSession.SetOneFactor(ctx.Clock.Now(), userDetails, keepMeLoggedIn)
 
@@ -173,9 +172,11 @@ func FirstFactorPost(msInitialDelay time.Duration, delayEnabled bool) middleware
 			userSession.RefreshTTL = ctx.Clock.Now().Add(refreshInterval)
 		}
 
-		err = ctx.SaveSession(userSession)
+		if err = ctx.SaveSession(userSession); err != nil {
-		if err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionSave, "updated profile", regulation.AuthType1FA, bodyJSON.Username, err)
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to save session of user %s", bodyJSON.Username), messageAuthenticationFailed)
+
+			respondUnauthorized(ctx, messageAuthenticationFailed)
+
 			return
 		}
 

internal/handlers/handler_firstfactor_test.go

@@ -15,6 +15,7 @@ import (
 	"github.com/authelia/authelia/v4/internal/configuration/schema"
 	"github.com/authelia/authelia/v4/internal/mocks"
 	"github.com/authelia/authelia/v4/internal/models"
+	"github.com/authelia/authelia/v4/internal/regulation"
 )
 
 type FirstFactorSuite struct {
@@ -35,7 +36,7 @@ func (s *FirstFactorSuite) TestShouldFailIfBodyIsNil() {
 	FirstFactorPost(0, false)(s.mock.Ctx)
 
 	// No body
-	assert.Equal(s.T(), "Unable to parse body: unexpected end of JSON input", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "Failed to parse 1FA request body: unable to parse body: unexpected end of JSON input", s.mock.Hook.LastEntry().Message)
 	s.mock.Assert401KO(s.T(), "Authentication failed. Check your credentials.")
 }
 
@@ -46,7 +47,7 @@ func (s *FirstFactorSuite) TestShouldFailIfBodyIsInBadFormat() {
 	}`)
 	FirstFactorPost(0, false)(s.mock.Ctx)
 
-	assert.Equal(s.T(), "Unable to validate body: password: non zero value required", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "Failed to parse 1FA request body: unable to validate body: password: non zero value required", s.mock.Hook.LastEntry().Message)
 	s.mock.Assert401KO(s.T(), "Authentication failed. Check your credentials.")
 }
 
@@ -54,14 +55,17 @@ func (s *FirstFactorSuite) TestShouldFailIfUserProviderCheckPasswordFail() {
 	s.mock.UserProviderMock.
 		EXPECT().
 		CheckUserPassword(gomock.Eq("test"), gomock.Eq("hello")).
-		Return(false, fmt.Errorf("Failed"))
+		Return(false, fmt.Errorf("failed"))
 
 	s.mock.StorageProviderMock.
 		EXPECT().
 		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
 			Username:   "test",
 			Successful: false,
+			Banned:     false,
 			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthType1FA,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
 		}))
 
 	s.mock.Ctx.Request.SetBodyString(`{
@@ -71,22 +75,51 @@ func (s *FirstFactorSuite) TestShouldFailIfUserProviderCheckPasswordFail() {
 	}`)
 	FirstFactorPost(0, false)(s.mock.Ctx)
 
-	assert.Equal(s.T(), "error while checking password for user test: Failed", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "Unsuccessful 1FA authentication attempt by user 'test': failed", s.mock.Hook.LastEntry().Message)
 	s.mock.Assert401KO(s.T(), "Authentication failed. Check your credentials.")
 }
 
-func (s *FirstFactorSuite) TestShouldCheckAuthenticationIsMarkedWhenInvalidCredentials() {
+func (s *FirstFactorSuite) TestShouldCheckAuthenticationIsNotMarkedWhenProviderCheckPasswordError() {
 	s.mock.UserProviderMock.
 		EXPECT().
 		CheckUserPassword(gomock.Eq("test"), gomock.Eq("hello")).
-		Return(false, fmt.Errorf("Invalid credentials"))
+		Return(false, fmt.Errorf("invalid credentials"))
 
 	s.mock.StorageProviderMock.
 		EXPECT().
 		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
 			Username:   "test",
 			Successful: false,
+			Banned:     false,
 			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthType1FA,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
+	s.mock.Ctx.Request.SetBodyString(`{
+		"username": "test",
+		"password": "hello",
+		"keepMeLoggedIn": true
+	}`)
+
+	FirstFactorPost(0, false)(s.mock.Ctx)
+}
+
+func (s *FirstFactorSuite) TestShouldCheckAuthenticationIsMarkedWhenInvalidCredentials() {
+	s.mock.UserProviderMock.
+		EXPECT().
+		CheckUserPassword(gomock.Eq("test"), gomock.Eq("hello")).
+		Return(false, nil)
+
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "test",
+			Successful: false,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthType1FA,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
 		}))
 
 	s.mock.Ctx.Request.SetBodyString(`{
@@ -112,7 +145,7 @@ func (s *FirstFactorSuite) TestShouldFailIfUserProviderGetDetailsFail() {
 	s.mock.UserProviderMock.
 		EXPECT().
 		GetDetails(gomock.Eq("test")).
-		Return(nil, fmt.Errorf("Failed"))
+		Return(nil, fmt.Errorf("failed"))
 
 	s.mock.Ctx.Request.SetBodyString(`{
 		"username": "test",
@@ -121,7 +154,7 @@ func (s *FirstFactorSuite) TestShouldFailIfUserProviderGetDetailsFail() {
 	}`)
 	FirstFactorPost(0, false)(s.mock.Ctx)
 
-	assert.Equal(s.T(), "error while retrieving details from user test: Failed", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "Could not obtain profile details during 1FA authentication for user 'test': failed", s.mock.Hook.LastEntry().Message)
 	s.mock.Assert401KO(s.T(), "Authentication failed. Check your credentials.")
 }
 
@@ -143,7 +176,7 @@ func (s *FirstFactorSuite) TestShouldFailIfAuthenticationMarkFail() {
 	}`)
 	FirstFactorPost(0, false)(s.mock.Ctx)
 
-	assert.Equal(s.T(), "unable to mark authentication: failed", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "Unable to mark 1FA authentication attempt by user 'test': failed", s.mock.Hook.LastEntry().Message)
 	s.mock.Assert401KO(s.T(), "Authentication failed. Check your credentials.")
 }
 

internal/handlers/handler_sign_duo.go

@@ -6,26 +6,29 @@ import (
 
 	"github.com/authelia/authelia/v4/internal/duo"
 	"github.com/authelia/authelia/v4/internal/middlewares"
+	"github.com/authelia/authelia/v4/internal/regulation"
 )
 
 // SecondFactorDuoPost handler for sending a push notification via duo api.
 func SecondFactorDuoPost(duoAPI duo.API) middlewares.RequestHandler {
 	return func(ctx *middlewares.AutheliaCtx) {
 		var requestBody signDuoRequestBody
-		err := ctx.ParseBody(&requestBody)
 
-		if err != nil {
+		if err := ctx.ParseBody(&requestBody); err != nil {
-			handleAuthenticationUnauthorized(ctx, err, messageMFAValidationFailed)
+			ctx.Logger.Errorf(logFmtErrParseRequestBody, regulation.AuthTypeDUO, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
 		userSession := ctx.GetSession()
 		remoteIP := ctx.RemoteIP().String()
 
-		ctx.Logger.Debugf("Starting Duo Push Auth Attempt for %s from IP %s", userSession.Username, remoteIP)
+		ctx.Logger.Debugf("Starting Duo Push Auth Attempt for user '%s' with IP '%s'", userSession.Username, remoteIP)
 
 		values := url.Values{}
-		// { username, ipaddr: clientIP, factor: "push", device: "auto", pushinfo: `target%20url=${targetURL}`}
+
 		values.Set("username", userSession.Username)
 		values.Set("ipaddr", remoteIP)
 		values.Set("factor", "push")
@@ -37,7 +40,10 @@ func SecondFactorDuoPost(duoAPI duo.API) middlewares.RequestHandler {
 
 		duoResponse, err := duoAPI.Call(values, ctx)
 		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("Duo API errored: %s", err), messageMFAValidationFailed)
+			ctx.Logger.Errorf("Failed to perform DUO call for user '%s': %+v", userSession.Username, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
@@ -53,14 +59,25 @@ func SecondFactorDuoPost(duoAPI duo.API) middlewares.RequestHandler {
 		}
 
 		if duoResponse.Response.Result != testResultAllow {
-			ctx.ReplyUnauthorized()
+			_ = markAuthenticationAttempt(ctx, false, nil, userSession.Username, regulation.AuthTypeDUO,
+				fmt.Errorf("result: %s, code: %d, message: %s (%s)", duoResponse.Response.Result, duoResponse.Code,
+					duoResponse.Message, duoResponse.MessageDetail))
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
-		err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx)
+		if err = markAuthenticationAttempt(ctx, true, nil, userSession.Username, regulation.AuthTypeDUO, nil); err != nil {
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+			return
+		}
+
+		if err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx); err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionRegenerate, regulation.AuthTypeDUO, userSession.Username, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
 
-		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to regenerate session for user %s: %s", userSession.Username, err), messageMFAValidationFailed)
 			return
 		}
 
@@ -68,7 +85,10 @@ func SecondFactorDuoPost(duoAPI duo.API) middlewares.RequestHandler {
 
 		err = ctx.SaveSession(userSession)
 		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to update authentication level with Duo: %s", err), messageMFAValidationFailed)
+			ctx.Logger.Errorf(logFmtErrSessionSave, "authentication time", regulation.AuthTypeTOTP, userSession.Username, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 

internal/handlers/handler_sign_duo_test.go

@@ -14,6 +14,8 @@ import (
 
 	"github.com/authelia/authelia/v4/internal/duo"
 	"github.com/authelia/authelia/v4/internal/mocks"
+	"github.com/authelia/authelia/v4/internal/models"
+	"github.com/authelia/authelia/v4/internal/regulation"
 )
 
 type SecondFactorDuoPostSuite struct {
@@ -47,6 +49,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldCallDuoAPIAndAllowAccess() {
 	response := duo.Response{}
 	response.Response.Result = testResultAllow
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	duoMock.EXPECT().Call(gomock.Eq(values), s.mock.Ctx).Return(&response, nil)
 
 	s.mock.Ctx.Request.SetBodyString("{\"targetURL\": \"https://target.example.com\"}")
@@ -69,6 +82,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldCallDuoAPIAndDenyAccess() {
 	response := duo.Response{}
 	response.Response.Result = "deny"
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: false,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	duoMock.EXPECT().Call(gomock.Eq(values), s.mock.Ctx).Return(&response, nil)
 
 	s.mock.Ctx.Request.SetBodyString("{\"targetURL\": \"https://target.example.com\"}")
@@ -88,7 +112,7 @@ func (s *SecondFactorDuoPostSuite) TestShouldCallDuoAPIAndFail() {
 	values.Set("device", "auto")
 	values.Set("pushinfo", "target%20url=https://target.example.com")
 
-	duoMock.EXPECT().Call(gomock.Eq(values), s.mock.Ctx).Return(nil, fmt.Errorf("Connnection error"))
+	duoMock.EXPECT().Call(gomock.Eq(values), s.mock.Ctx).Return(nil, fmt.Errorf("connnection error"))
 
 	s.mock.Ctx.Request.SetBodyString("{\"targetURL\": \"https://target.example.com\"}")
 
@@ -105,6 +129,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldRedirectUserToDefaultURL() {
 
 	duoMock.EXPECT().Call(gomock.Any(), s.mock.Ctx).Return(&response, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	s.mock.Ctx.Configuration.DefaultRedirectionURL = testRedirectionURL
 
 	bodyBytes, err := json.Marshal(signDuoRequestBody{})
@@ -125,6 +160,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldNotReturnRedirectURL() {
 
 	duoMock.EXPECT().Call(gomock.Any(), s.mock.Ctx).Return(&response, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signDuoRequestBody{})
 	s.Require().NoError(err)
 	s.mock.Ctx.Request.SetBody(bodyBytes)
@@ -141,6 +187,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldRedirectUserToSafeTargetURL() {
 
 	duoMock.EXPECT().Call(gomock.Any(), s.mock.Ctx).Return(&response, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signDuoRequestBody{
 		TargetURL: "https://mydomain.local",
 	})
@@ -161,6 +218,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldNotRedirectToUnsafeURL() {
 
 	duoMock.EXPECT().Call(gomock.Any(), s.mock.Ctx).Return(&response, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signDuoRequestBody{
 		TargetURL: "http://mydomain.local",
 	})
@@ -179,6 +247,17 @@ func (s *SecondFactorDuoPostSuite) TestShouldRegenerateSessionForPreventingSessi
 
 	duoMock.EXPECT().Call(gomock.Any(), s.mock.Ctx).Return(&response, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeDUO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signDuoRequestBody{
 		TargetURL: "http://mydomain.local",
 	})

internal/handlers/handler_sign_totp.go

@@ -1,19 +1,20 @@
 package handlers
 
 import (
-	"fmt"
-
 	"github.com/authelia/authelia/v4/internal/middlewares"
+	"github.com/authelia/authelia/v4/internal/regulation"
 )
 
 // SecondFactorTOTPPost validate the TOTP passcode provided by the user.
 func SecondFactorTOTPPost(totpVerifier TOTPVerifier) middlewares.RequestHandler {
 	return func(ctx *middlewares.AutheliaCtx) {
 		requestBody := signTOTPRequestBody{}
-		err := ctx.ParseBody(&requestBody)
 
-		if err != nil {
+		if err := ctx.ParseBody(&requestBody); err != nil {
-			handleAuthenticationUnauthorized(ctx, err, messageMFAValidationFailed)
+			ctx.Logger.Errorf(logFmtErrParseRequestBody, regulation.AuthTypeTOTP, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
@@ -21,33 +22,50 @@ func SecondFactorTOTPPost(totpVerifier TOTPVerifier) middlewares.RequestHandler
 
 		config, err := ctx.Providers.StorageProvider.LoadTOTPConfiguration(ctx, userSession.Username)
 		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to load TOTP secret: %s", err), messageMFAValidationFailed)
+			ctx.Logger.Errorf("Failed to load TOTP configuration: %+v", err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
 		isValid, err := totpVerifier.Verify(config, requestBody.Token)
 		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("error occurred during OTP validation for user %s: %s", userSession.Username, err), messageMFAValidationFailed)
+			ctx.Logger.Errorf("Failed to perform TOTP verification: %+v", err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
 		if !isValid {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("wrong passcode during TOTP validation for user %s", userSession.Username), messageMFAValidationFailed)
+			_ = markAuthenticationAttempt(ctx, false, nil, userSession.Username, regulation.AuthTypeTOTP, nil)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
-		err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx)
+		if err = markAuthenticationAttempt(ctx, true, nil, userSession.Username, regulation.AuthTypeTOTP, nil); err != nil {
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+			return
+		}
+
+		if err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx); err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionRegenerate, regulation.AuthTypeTOTP, userSession.Username, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
 
-		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to regenerate session for user %s: %s", userSession.Username, err), messageMFAValidationFailed)
 			return
 		}
 
 		userSession.SetTwoFactor(ctx.Clock.Now())
 
-		err = ctx.SaveSession(userSession)
+		if err = ctx.SaveSession(userSession); err != nil {
-		if err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionSave, "authentication time", regulation.AuthTypeTOTP, userSession.Username, err)
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to update the authentication level with TOTP: %s", err), messageMFAValidationFailed)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 

internal/handlers/handler_sign_totp_test.go

@@ -12,6 +12,7 @@ import (
 
 	"github.com/authelia/authelia/v4/internal/mocks"
 	"github.com/authelia/authelia/v4/internal/models"
+	"github.com/authelia/authelia/v4/internal/regulation"
 	"github.com/authelia/authelia/v4/internal/session"
 )
 
@@ -44,6 +45,17 @@ func (s *HandlerSignTOTPSuite) TestShouldRedirectUserToDefaultURL() {
 		LoadTOTPConfiguration(s.mock.Ctx, gomock.Any()).
 		Return(&config, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeTOTP,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	verifier.EXPECT().
 		Verify(gomock.Eq(&config), gomock.Eq("abc")).
 		Return(true, nil)
@@ -71,6 +83,17 @@ func (s *HandlerSignTOTPSuite) TestShouldNotReturnRedirectURL() {
 		LoadTOTPConfiguration(s.mock.Ctx, gomock.Any()).
 		Return(&config, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeTOTP,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	verifier.EXPECT().
 		Verify(gomock.Eq(&config), gomock.Eq("abc")).
 		Return(true, nil)
@@ -94,6 +117,17 @@ func (s *HandlerSignTOTPSuite) TestShouldRedirectUserToSafeTargetURL() {
 		LoadTOTPConfiguration(s.mock.Ctx, gomock.Any()).
 		Return(&config, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeTOTP,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	verifier.EXPECT().
 		Verify(gomock.Eq(&config), gomock.Eq("abc")).
 		Return(true, nil)
@@ -118,6 +152,17 @@ func (s *HandlerSignTOTPSuite) TestShouldNotRedirectToUnsafeURL() {
 		LoadTOTPConfiguration(s.mock.Ctx, gomock.Any()).
 		Return(&models.TOTPConfiguration{Secret: []byte("secret")}, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeTOTP,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	verifier.EXPECT().
 		Verify(gomock.Eq(&models.TOTPConfiguration{Secret: []byte("secret")}), gomock.Eq("abc")).
 		Return(true, nil)
@@ -142,6 +187,17 @@ func (s *HandlerSignTOTPSuite) TestShouldRegenerateSessionForPreventingSessionFi
 		LoadTOTPConfiguration(s.mock.Ctx, gomock.Any()).
 		Return(&config, nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeTOTP,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	verifier.EXPECT().
 		Verify(gomock.Eq(&config), gomock.Eq("abc")).
 		Return(true, nil)

internal/handlers/handler_sign_u2f_step1.go

@@ -1,12 +1,14 @@
 package handlers
 
 import (
+	"crypto/ecdsa"
 	"crypto/elliptic"
 	"fmt"
 
 	"github.com/tstranex/u2f"
 
 	"github.com/authelia/authelia/v4/internal/middlewares"
+	"github.com/authelia/authelia/v4/internal/regulation"
 	"github.com/authelia/authelia/v4/internal/session"
 	"github.com/authelia/authelia/v4/internal/storage"
 )
@@ -23,55 +25,69 @@ func SecondFactorU2FSignGet(ctx *middlewares.AutheliaCtx) {
 		return
 	}
 
+	userSession := ctx.GetSession()
+
 	appID := fmt.Sprintf("%s://%s", ctx.XForwardedProto(), ctx.XForwardedHost())
 
 	var trustedFacets = []string{appID}
-	challenge, err := u2f.NewChallenge(appID, trustedFacets)
 
+	challenge, err := u2f.NewChallenge(appID, trustedFacets)
 	if err != nil {
-		handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to create U2F challenge: %s", err), messageMFAValidationFailed)
+		ctx.Logger.Errorf("Unable to create %s challenge for user '%s': %+v", regulation.AuthTypeFIDO, userSession.Username, err)
+
+		respondUnauthorized(ctx, messageMFAValidationFailed)
+
 		return
 	}
 
-	userSession := ctx.GetSession()
 	device, err := ctx.Providers.StorageProvider.LoadU2FDevice(ctx, userSession.Username)
-
 	if err != nil {
+		respondUnauthorized(ctx, messageMFAValidationFailed)
+
 		if err == storage.ErrNoU2FDeviceHandle {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("no device handle found for user %s", userSession.Username), messageMFAValidationFailed)
+			_ = markAuthenticationAttempt(ctx, false, nil, userSession.Username, regulation.AuthTypeFIDO, fmt.Errorf("no registered U2F device"))
 			return
 		}
 
-		handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to retrieve U2F device handle: %s", err), messageMFAValidationFailed)
+		ctx.Logger.Errorf("Could not load %s devices for user '%s': %+v", regulation.AuthTypeFIDO, userSession.Username, err)
 
 		return
 	}
 
-	var registration u2f.Registration
-	registration.KeyHandle = device.KeyHandle
 	x, y := elliptic.Unmarshal(elliptic.P256(), device.PublicKey)
-	registration.PubKey.Curve = elliptic.P256()
+
-	registration.PubKey.X = x
+	registration := u2f.Registration{
-	registration.PubKey.Y = y
+		KeyHandle: device.KeyHandle,
+		PubKey: ecdsa.PublicKey{
+			Curve: elliptic.P256(),
+			X:     x,
+			Y:     y,
+		},
+	}
 
 	// Save the challenge and registration for use in next request
 	userSession.U2FRegistration = &session.U2FRegistration{
 		KeyHandle: device.KeyHandle,
 		PublicKey: device.PublicKey,
 	}
-	userSession.U2FChallenge = challenge
-	err = ctx.SaveSession(userSession)
 
-	if err != nil {
+	userSession.U2FChallenge = challenge
-		handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to save U2F challenge and registration in session: %s", err), messageMFAValidationFailed)
+
+	if err = ctx.SaveSession(userSession); err != nil {
+		ctx.Logger.Errorf(logFmtErrSessionSave, "challenge and registration", regulation.AuthTypeFIDO, userSession.Username, err)
+
+		respondUnauthorized(ctx, messageMFAValidationFailed)
+
 		return
 	}
 
 	signRequest := challenge.SignRequest([]u2f.Registration{registration})
-	err = ctx.SetJSONBody(signRequest)
 
-	if err != nil {
+	if err = ctx.SetJSONBody(signRequest); err != nil {
-		handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to set sign request in body: %s", err), messageMFAValidationFailed)
+		ctx.Logger.Errorf(logFmtErrWriteResponseBody, regulation.AuthTypeFIDO, userSession.Username, err)
+
+		respondUnauthorized(ctx, messageMFAValidationFailed)
+
 		return
 	}
 }

internal/handlers/handler_sign_u2f_step2.go

@@ -1,48 +1,64 @@
 package handlers
 
 import (
-	"fmt"
+	"errors"
 
 	"github.com/authelia/authelia/v4/internal/middlewares"
+	"github.com/authelia/authelia/v4/internal/regulation"
 )
 
 // SecondFactorU2FSignPost handler for completing a signing request.
 func SecondFactorU2FSignPost(u2fVerifier U2FVerifier) middlewares.RequestHandler {
 	return func(ctx *middlewares.AutheliaCtx) {
-		var requestBody signU2FRequestBody
+		var (
-		err := ctx.ParseBody(&requestBody)
+			requestBody signU2FRequestBody
+			err         error
+		)
+
+		if err := ctx.ParseBody(&requestBody); err != nil {
+			ctx.Logger.Errorf(logFmtErrParseRequestBody, regulation.AuthTypeFIDO, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
 
-		if err != nil {
-			ctx.Error(err, messageMFAValidationFailed)
 			return
 		}
 
 		userSession := ctx.GetSession()
 		if userSession.U2FChallenge == nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("U2F signing has not been initiated yet (no challenge)"), messageMFAValidationFailed)
+			_ = markAuthenticationAttempt(ctx, false, nil, userSession.Username, regulation.AuthTypeFIDO, errors.New("session did not contain a challenge"))
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
 		if userSession.U2FRegistration == nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("U2F signing has not been initiated yet (no registration)"), messageMFAValidationFailed)
+			_ = markAuthenticationAttempt(ctx, false, nil, userSession.Username, regulation.AuthTypeFIDO, errors.New("session did not contain a registration"))
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 
-		err = u2fVerifier.Verify(
+		if err = u2fVerifier.Verify(userSession.U2FRegistration.KeyHandle, userSession.U2FRegistration.PublicKey,
-			userSession.U2FRegistration.KeyHandle,
+			requestBody.SignResponse, *userSession.U2FChallenge); err != nil {
-			userSession.U2FRegistration.PublicKey,
+			_ = markAuthenticationAttempt(ctx, false, nil, userSession.Username, regulation.AuthTypeFIDO, err)
-			requestBody.SignResponse,
+
-			*userSession.U2FChallenge)
+			respondUnauthorized(ctx, messageMFAValidationFailed)
 
-		if err != nil {
-			ctx.Error(err, messageMFAValidationFailed)
 			return
 		}
 
-		err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx)
+		if err = ctx.Providers.SessionProvider.RegenerateSession(ctx.RequestCtx); err != nil {
+			ctx.Logger.Errorf(logFmtErrSessionRegenerate, regulation.AuthTypeFIDO, userSession.Username, err)
 
-		if err != nil {
+			respondUnauthorized(ctx, messageMFAValidationFailed)
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to regenerate session for user %s: %s", userSession.Username, err), messageMFAValidationFailed)
+
+			return
+		}
+
+		if err = markAuthenticationAttempt(ctx, true, nil, userSession.Username, regulation.AuthTypeFIDO, nil); err != nil {
+			respondUnauthorized(ctx, messageMFAValidationFailed)
 			return
 		}
 
@@ -50,7 +66,10 @@ func SecondFactorU2FSignPost(u2fVerifier U2FVerifier) middlewares.RequestHandler
 
 		err = ctx.SaveSession(userSession)
 		if err != nil {
-			handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to update authentication level with U2F: %s", err), messageMFAValidationFailed)
+			ctx.Logger.Errorf(logFmtErrSessionSave, "authentication time", regulation.AuthTypeFIDO, userSession.Username, err)
+
+			respondUnauthorized(ctx, messageMFAValidationFailed)
+
 			return
 		}
 

internal/handlers/handler_sign_u2f_step2_test.go

@@ -11,6 +11,8 @@ import (
 	"github.com/tstranex/u2f"
 
 	"github.com/authelia/authelia/v4/internal/mocks"
+	"github.com/authelia/authelia/v4/internal/models"
+	"github.com/authelia/authelia/v4/internal/regulation"
 	"github.com/authelia/authelia/v4/internal/session"
 )
 
@@ -41,6 +43,17 @@ func (s *HandlerSignU2FStep2Suite) TestShouldRedirectUserToDefaultURL() {
 		Verify(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).
 		Return(nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeFIDO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	s.mock.Ctx.Configuration.DefaultRedirectionURL = testRedirectionURL
 
 	bodyBytes, err := json.Marshal(signU2FRequestBody{
@@ -62,6 +75,17 @@ func (s *HandlerSignU2FStep2Suite) TestShouldNotReturnRedirectURL() {
 		Verify(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).
 		Return(nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeFIDO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signU2FRequestBody{
 		SignResponse: u2f.SignResponse{},
 	})
@@ -79,6 +103,17 @@ func (s *HandlerSignU2FStep2Suite) TestShouldRedirectUserToSafeTargetURL() {
 		Verify(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).
 		Return(nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeFIDO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signU2FRequestBody{
 		SignResponse: u2f.SignResponse{},
 		TargetURL:    "https://mydomain.local",
@@ -99,6 +134,17 @@ func (s *HandlerSignU2FStep2Suite) TestShouldNotRedirectToUnsafeURL() {
 		Verify(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).
 		Return(nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeFIDO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signU2FRequestBody{
 		SignResponse: u2f.SignResponse{},
 		TargetURL:    "http://mydomain.local",
@@ -117,6 +163,17 @@ func (s *HandlerSignU2FStep2Suite) TestShouldRegenerateSessionForPreventingSessi
 		Verify(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).
 		Return(nil)
 
+	s.mock.StorageProviderMock.
+		EXPECT().
+		AppendAuthenticationLog(s.mock.Ctx, gomock.Eq(models.AuthenticationAttempt{
+			Username:   "john",
+			Successful: true,
+			Banned:     false,
+			Time:       s.mock.Clock.Now(),
+			Type:       regulation.AuthTypeFIDO,
+			RemoteIP:   models.NewIPAddressFromString("0.0.0.0"),
+		}))
+
 	bodyBytes, err := json.Marshal(signU2FRequestBody{
 		SignResponse: u2f.SignResponse{},
 	})

internal/handlers/handler_user_info_test.go

@@ -178,7 +178,7 @@ func (s *SaveSuite) TestShouldReturnError500WhenNoBodyProvided() {
 	MethodPreferencePost(s.mock.Ctx)
 
 	s.mock.Assert200KO(s.T(), "Operation failed.")
-	assert.Equal(s.T(), "Unable to parse body: unexpected end of JSON input", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "unable to parse body: unexpected end of JSON input", s.mock.Hook.LastEntry().Message)
 	assert.Equal(s.T(), logrus.ErrorLevel, s.mock.Hook.LastEntry().Level)
 }
 
@@ -187,7 +187,7 @@ func (s *SaveSuite) TestShouldReturnError500WhenMalformedBodyProvided() {
 	MethodPreferencePost(s.mock.Ctx)
 
 	s.mock.Assert200KO(s.T(), "Operation failed.")
-	assert.Equal(s.T(), "Unable to parse body: unexpected end of JSON input", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "unable to parse body: unexpected end of JSON input", s.mock.Hook.LastEntry().Message)
 	assert.Equal(s.T(), logrus.ErrorLevel, s.mock.Hook.LastEntry().Level)
 }
 
@@ -196,7 +196,7 @@ func (s *SaveSuite) TestShouldReturnError500WhenBadBodyProvided() {
 	MethodPreferencePost(s.mock.Ctx)
 
 	s.mock.Assert200KO(s.T(), "Operation failed.")
-	assert.Equal(s.T(), "Unable to validate body: method: non zero value required", s.mock.Hook.LastEntry().Message)
+	assert.Equal(s.T(), "unable to validate body: method: non zero value required", s.mock.Hook.LastEntry().Message)
 	assert.Equal(s.T(), logrus.ErrorLevel, s.mock.Hook.LastEntry().Level)
 }
 

internal/handlers/response.go

@@ -3,6 +3,7 @@ package handlers
 import (
 	"fmt"
 	"net/url"
+	"time"
 
 	"github.com/valyala/fasthttp"
 
@@ -24,8 +25,9 @@ func handleOIDCWorkflowResponse(ctx *middlewares.AutheliaCtx) {
 
 	uri, err := ctx.ExternalRootURL()
 	if err != nil {
-		ctx.Logger.Errorf("Unable to extract external root URL: %v", err)
+		ctx.Logger.Errorf("Unable to determine external Base URL: %v", err)
-		handleAuthenticationUnauthorized(ctx, fmt.Errorf("unable to get forward facing URI"), messageAuthenticationFailed)
+
+		respondUnauthorized(ctx, messageOperationFailed)
 
 		return
 	}
@@ -144,8 +146,33 @@ func Handle2FAResponse(ctx *middlewares.AutheliaCtx, targetURI string) {
 	}
 }
 
-// handleAuthenticationUnauthorized provides harmonized response codes for 1FA.
+func markAuthenticationAttempt(ctx *middlewares.AutheliaCtx, successful bool, bannedUntil *time.Time, username string, authType string, errAuth error) (err error) {
-func handleAuthenticationUnauthorized(ctx *middlewares.AutheliaCtx, err error, message string) {
+	// We only Mark if there was no underlying error.
-	ctx.SetStatusCode(fasthttp.StatusUnauthorized)
+	ctx.Logger.Debugf("Mark %s authentication attempt made by user '%s'", authType, username)
-	ctx.Error(err, message)
+
+	if err = ctx.Providers.Regulator.Mark(ctx, successful, bannedUntil != nil, username, string(ctx.RequestCtx.QueryArgs().Peek("rd")), string(ctx.RequestCtx.QueryArgs().Peek("rm")), authType, ctx.RemoteIP()); err != nil {
+		ctx.Logger.Errorf("Unable to mark %s authentication attempt by user '%s': %+v", authType, username, err)
+
+		return err
+	}
+
+	if successful {
+		ctx.Logger.Debugf("Successful %s authentication attempt made by user '%s'", authType, username)
+	} else {
+		switch {
+		case errAuth != nil:
+			ctx.Logger.Errorf("Unsuccessful %s authentication attempt by user '%s': %+v", authType, username, errAuth)
+		case bannedUntil != nil:
+			ctx.Logger.Errorf("Unsuccessful %s authentication attempt by user '%s' and they are banned until %s", authType, username, bannedUntil)
+		default:
+			ctx.Logger.Errorf("Unsuccessful %s authentication attempt by user '%s'", authType, username)
+		}
+	}
+
+	return nil
+}
+
+func respondUnauthorized(ctx *middlewares.AutheliaCtx, message string) {
+	ctx.SetStatusCode(fasthttp.StatusUnauthorized)
+	ctx.SetJSONError(message)
 }

internal/middlewares/authelia_context.go

@@ -55,6 +55,13 @@ func AutheliaMiddleware(configuration schema.Configuration, providers Providers)
 
 // Error reply with an error and display the stack trace in the logs.
 func (c *AutheliaCtx) Error(err error, message string) {
+	c.SetJSONError(message)
+
+	c.Logger.Error(err)
+}
+
+// SetJSONError sets the body of the response to an JSON error KO message.
+func (c *AutheliaCtx) SetJSONError(message string) {
 	b, marshalErr := json.Marshal(ErrorResponse{Status: "KO", Message: message})
 
 	if marshalErr != nil {
@@ -63,7 +70,6 @@ func (c *AutheliaCtx) Error(err error, message string) {
 
 	c.SetContentType(contentTypeApplicationJSON)
 	c.SetBody(b)
-	c.Logger.Error(err)
 }
 
 // ReplyError reply with an error but does not display any stack trace in the logs.
@@ -183,13 +189,13 @@ func (c *AutheliaCtx) ParseBody(value interface{}) error {
 	err := json.Unmarshal(c.PostBody(), &value)
 
 	if err != nil {
-		return fmt.Errorf("Unable to parse body: %s", err)
+		return fmt.Errorf("unable to parse body: %w", err)
 	}
 
 	valid, err := govalidator.ValidateStruct(value)
 
 	if err != nil {
-		return fmt.Errorf("Unable to validate body: %s", err)
+		return fmt.Errorf("unable to validate body: %w", err)
 	}
 
 	if !valid {
@@ -203,7 +209,7 @@ func (c *AutheliaCtx) ParseBody(value interface{}) error {
 func (c *AutheliaCtx) SetJSONBody(value interface{}) error {
 	b, err := json.Marshal(OKResponse{Status: "OK", Data: value})
 	if err != nil {
-		return fmt.Errorf("Unable to marshal JSON body")
+		return fmt.Errorf("unable to marshal JSON body: %w", err)
 	}
 
 	c.SetContentType(contentTypeApplicationJSON)

internal/models/model_authentication_attempt.go

@@ -9,6 +9,7 @@ type AuthenticationAttempt struct {
 	ID            int       `db:"id"`
 	Time          time.Time `db:"time"`
 	Successful    bool      `db:"successful"`
+	Banned        bool      `db:"banned"`
 	Username      string    `db:"username"`
 	Type          string    `db:"auth_type"`
 	RemoteIP      IPAddress `db:"remote_ip"`

internal/models/type_ipaddress.go

@@ -6,6 +6,12 @@ import (
 	"net"
 )
 
+// NewIPAddressFromString converts a string into an IPAddress.
+func NewIPAddressFromString(ip string) (ipAddress IPAddress) {
+	actualIP := net.ParseIP(ip)
+	return IPAddress{IP: &actualIP}
+}
+
 // IPAddress is a type specific for storage of a net.IP in the database.
 type IPAddress struct {
 	*net.IP

internal/regulation/const.go

@@ -4,3 +4,20 @@ import "fmt"
 
 // ErrUserIsBanned user is banned error message.
 var ErrUserIsBanned = fmt.Errorf("user is banned")
+
+const (
+	// AuthType1FA is the string representing an auth log for first-factor authentication.
+	AuthType1FA = "1FA"
+
+	// AuthTypeTOTP is the string representing an auth log for second-factor authentication via TOTP.
+	AuthTypeTOTP = "TOTP"
+
+	// AuthTypeFIDO is the string representing an auth log for second-factor authentication via FIDO/CTAP1/U2F.
+	AuthTypeFIDO = "FIDO"
+
+	// AuthTypeFIDO2 is the string representing an auth log for second-factor authentication via FIDO2/CTAP2/Webauthn.
+	// TODO: Add FIDO2.
+
+	// AuthTypeDUO is the string representing an auth log for second-factor authentication via DUO.
+	AuthTypeDUO = "DUO"
+)

internal/regulation/regulator.go

@@ -3,6 +3,7 @@ package regulation
 import (
 	"context"
 	"fmt"
+	"net"
 	"time"
 
 	"github.com/authelia/authelia/v4/internal/configuration/schema"
@@ -43,11 +44,16 @@ func NewRegulator(configuration *schema.RegulationConfiguration, provider storag
 
 // Mark an authentication attempt.
 // We split Mark and Regulate in order to avoid timing attacks.
-func (r *Regulator) Mark(ctx context.Context, username string, successful bool) error {
+func (r *Regulator) Mark(ctx context.Context, successful, banned bool, username, requestURI, requestMethod, authType string, remoteIP net.IP) error {
 	return r.storageProvider.AppendAuthenticationLog(ctx, models.AuthenticationAttempt{
-		Username:   username,
+		Time:          r.clock.Now(),
-		Successful: successful,
+		Successful:    successful,
-		Time:       r.clock.Now(),
+		Banned:        banned,
+		Username:      username,
+		Type:          authType,
+		RemoteIP:      models.IPAddress{IP: &remoteIP},
+		RequestURI:    requestURI,
+		RequestMethod: requestMethod,
 	})
 }
 

internal/session/encrypting_serializer_test.go

@@ -4,7 +4,6 @@ import (
 	"testing"
 
 	"github.com/fasthttp/session/v2"
-
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 )

internal/storage/migrations/V0001.Initial_Schema.mysql.up.sql

@@ -1,12 +1,18 @@
 CREATE TABLE IF NOT EXISTS authentication_logs (
     id INTEGER AUTO_INCREMENT,
     time TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,
-    successful BOOL NOT NULL,
+    successful BOOLEAN NOT NULL,
+    banned BOOLEAN NOT NULL DEFAULT FALSE,
     username VARCHAR(100) NOT NULL,
+    auth_type VARCHAR(5) NOT NULL DEFAULT '1FA',
+    remote_ip VARCHAR(47) NULL DEFAULT NULL,
+    request_uri TEXT NOT NULL,
+    request_method VARCHAR(4) NOT NULL DEFAULT '',
     PRIMARY KEY (id)
 );
 
-CREATE INDEX authentication_logs_username_idx ON authentication_logs (time, username);
+CREATE INDEX authentication_logs_username_idx ON authentication_logs (time, username, auth_type);
+CREATE INDEX authentication_logs_remote_ip_idx ON authentication_logs (time, remote_ip, auth_type);
 
 CREATE TABLE IF NOT EXISTS identity_verification_tokens (
     id INTEGER AUTO_INCREMENT,
@@ -19,6 +25,7 @@ CREATE TABLE IF NOT EXISTS identity_verification_tokens (
 CREATE TABLE IF NOT EXISTS totp_configurations (
     id INTEGER AUTO_INCREMENT,
     username VARCHAR(100) NOT NULL,
+    issuer VARCHAR(100),
     algorithm VARCHAR(6) NOT NULL DEFAULT 'SHA1',
     digits INTEGER NOT NULL DEFAULT 6,
     totp_period INTEGER NOT NULL DEFAULT 30,

internal/storage/migrations/V0001.Initial_Schema.postgres.up.sql

@@ -2,11 +2,17 @@ CREATE TABLE IF NOT EXISTS authentication_logs (
     id SERIAL,
     time TIMESTAMP WITH TIME ZONE NOT NULL DEFAULT CURRENT_TIMESTAMP,
     successful BOOLEAN NOT NULL,
+    banned BOOLEAN NOT NULL DEFAULT FALSE,
     username VARCHAR(100) NOT NULL,
+    auth_type VARCHAR(5) NOT NULL DEFAULT '1FA',
+    remote_ip VARCHAR(47) NULL DEFAULT NULL,
+    request_uri TEXT,
+    request_method VARCHAR(4) NOT NULL DEFAULT '',
     PRIMARY KEY (id)
 );
 
-CREATE INDEX authentication_logs_username_idx ON authentication_logs (time, username);
+CREATE INDEX authentication_logs_username_idx ON authentication_logs (time, username, auth_type);
+CREATE INDEX authentication_logs_remote_ip_idx ON authentication_logs (time, remote_ip, auth_type);
 
 CREATE TABLE IF NOT EXISTS identity_verification_tokens (
     id SERIAL,
@@ -19,6 +25,7 @@ CREATE TABLE IF NOT EXISTS identity_verification_tokens (
 CREATE TABLE IF NOT EXISTS totp_configurations (
     id SERIAL,
     username VARCHAR(100) NOT NULL,
+    issuer VARCHAR(100),
     algorithm VARCHAR(6) NOT NULL DEFAULT 'SHA1',
     digits INTEGER NOT NULL DEFAULT 6,
     totp_period INTEGER NOT NULL DEFAULT 30,

internal/storage/migrations/V0001.Initial_Schema.sqlite.up.sql

@@ -2,11 +2,17 @@ CREATE TABLE IF NOT EXISTS authentication_logs (
     id INTEGER,
     time TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,
     successful BOOLEAN NOT NULL,
+    banned BOOLEAN NOT NULL DEFAULT FALSE,
     username VARCHAR(100) NOT NULL,
+    auth_type VARCHAR(5) NOT NULL DEFAULT '1FA',
+    remote_ip VARCHAR(47) NULL DEFAULT NULL,
+    request_uri TEXT,
+    request_method VARCHAR(4) NOT NULL DEFAULT '',
     PRIMARY KEY (id)
 );
 
-CREATE INDEX authentication_logs_username_idx ON authentication_logs (time, username);
+CREATE INDEX authentication_logs_username_idx ON authentication_logs (time, username, auth_type);
+CREATE INDEX authentication_logs_remote_ip_idx ON authentication_logs (time, remote_ip, auth_type);
 
 CREATE TABLE IF NOT EXISTS identity_verification_tokens (
     id INTEGER,
@@ -19,8 +25,9 @@ CREATE TABLE IF NOT EXISTS identity_verification_tokens (
 CREATE TABLE IF NOT EXISTS totp_configurations (
     id INTEGER,
     username VARCHAR(100) NOT NULL,
+    issuer VARCHAR(100),
     algorithm VARCHAR(6) NOT NULL DEFAULT 'SHA1',
-    digits INTEGER(1) NOT NULL DEFAULT 6,
+    digits INTEGER NOT NULL DEFAULT 6,
     totp_period INTEGER NOT NULL DEFAULT 30,
     secret BLOB NOT NULL,
     PRIMARY KEY (id),

internal/storage/sql_provider.go

@@ -355,8 +355,10 @@ func (p *SQLProvider) LoadU2FDevice(ctx context.Context, username string) (devic
 
 // AppendAuthenticationLog append a mark to the authentication log.
 func (p *SQLProvider) AppendAuthenticationLog(ctx context.Context, attempt models.AuthenticationAttempt) (err error) {
-	if _, err = p.db.ExecContext(ctx, p.sqlInsertAuthenticationAttempt, attempt.Time, attempt.Successful, attempt.Username); err != nil {
+	if _, err = p.db.ExecContext(ctx, p.sqlInsertAuthenticationAttempt,
-		return fmt.Errorf("error inserting authentiation attempt: %w", err)
+		attempt.Time, attempt.Successful, attempt.Banned, attempt.Username,
+		attempt.Type, attempt.RemoteIP, attempt.RequestURI, attempt.RequestMethod); err != nil {
+		return fmt.Errorf("error inserting authentication attempt: %w", err)
 	}
 
 	return nil

internal/storage/sql_provider_queries.go

@@ -130,13 +130,13 @@ const (
 
 const (
 	queryFmtInsertAuthenticationLogEntry = `
-		INSERT INTO %s (time, successful, username)
+		INSERT INTO %s (time, successful, banned, username, auth_type, remote_ip, request_uri, request_method)
-		VALUES (?, ?, ?);`
+		VALUES (?, ?, ?, ?, ?, ?, ?, ?);`
 
 	queryFmtSelect1FAAuthenticationLogEntryByUsername = `
 		SELECT time, successful, username
 		FROM %s
-		WHERE time > ? AND username = ?
+		WHERE time > ? AND username = ? AND auth_type = '1FA' AND banned = 0
 		ORDER BY time DESC
 		LIMIT ?
 		OFFSET ?;`

internal/storage/sql_provider_queries_special.go

@@ -21,8 +21,8 @@ const (
 		LIMIT 100 OFFSET ?;`
 
 	queryFmtPre1To1InsertAuthenticationLogs = `
-		INSERT INTO %s (username, successful, time)
+		INSERT INTO %s (username, successful, time, request_uri)
-		VALUES (?, ?, ?);`
+		VALUES (?, ?, ?, '');`
 
 	queryFmtPre1InsertUserPreferencesFromSelect = `
 		INSERT INTO %s (username, second_factor_method)