Implement user lockout log (#23140) (#23561)

* implement user lockout logger

* formatting

* make user lockout log interval configurable

* create func to get locked user count, and fix potential deadlock

* fix test

* fix test

* add changelog

Co-authored-by: davidadeleon <56207066+davidadeleon@users.noreply.github.com>

changelog/23140.txt

@@ -0,0 +1,3 @@
+```release-note:improvement
+core: emit logs when user(s) are locked out and when all lockouts have been cleared
+```

command/server.go

@@ -2749,6 +2749,7 @@ func createCoreConfig(c *ServerCommand, config *server.Config, backend physical.
 		DisableSSCTokens:               config.DisableSSCTokens,
 		Experiments:                    config.Experiments,
 		AdministrativeNamespacePath:    config.AdministrativeNamespacePath,
+		UserLockoutLogInterval:         config.UserLockoutLogInterval,
 	}
 
 	if c.flagDev {

command/server/config_test_helpers.go

@@ -773,6 +773,7 @@ func testConfig_Sanitized(t *testing.T) {
 		"enable_response_header_hostname":     false,
 		"enable_response_header_raft_node_id": false,
 		"log_requests_level":                  "basic",
+		"user_lockout_log_interval":           0 * time.Second,
 		"ha_storage": map[string]interface{}{
 			"cluster_addr":       "top_level_cluster_addr",
 			"disable_clustering": true,

http/sys_config_state_test.go

@@ -164,6 +164,7 @@ func TestSysConfigState_Sanitized(t *testing.T) {
 				"enable_response_header_hostname":     false,
 				"enable_response_header_raft_node_id": false,
 				"log_requests_level":                  "",
+				"user_lockout_log_interval":           json.Number("0"),
 				"listeners": []interface{}{
 					map[string]interface{}{
 						"config": nil,

internalshared/configutil/config.go

@@ -20,7 +20,9 @@ type SharedConfig struct {
 
 	Listeners []*Listener `hcl:"-"`
 
-	UserLockouts []*UserLockout `hcl:"-"`
+	UserLockouts              []*UserLockout `hcl:"-"`
+	UserLockoutLogInterval    time.Duration  `hcl:"-"`
+	UserLockoutLogIntervalRaw interface{}    `hcl:"user_lockout_log_interval"`
 
 	Seals   []*KMS   `hcl:"-"`
 	Entropy *Entropy `hcl:"-"`
@@ -84,6 +86,14 @@ func ParseConfig(d string) (*SharedConfig, error) {
 		result.DisableMlockRaw = nil
 	}
 
+	if result.UserLockoutLogIntervalRaw != nil {
+		if result.UserLockoutLogInterval, err = parseutil.ParseDurationSecond(result.UserLockoutLogIntervalRaw); err != nil {
+			return nil, err
+		}
+		result.FoundKeys = append(result.FoundKeys, "UserLockoutLogInterval")
+		result.UserLockoutLogIntervalRaw = nil
+	}
+
 	list, ok := obj.Node.(*ast.ObjectList)
 	if !ok {
 		return nil, fmt.Errorf("error parsing: file doesn't contain a root object")
@@ -173,6 +183,7 @@ func (c *SharedConfig) Sanitized() map[string]interface{} {
 		"pid_file":                      c.PidFile,
 		"cluster_name":                  c.ClusterName,
 		"administrative_namespace_path": c.AdministrativeNamespacePath,
+		"user_lockout_log_interval":     c.UserLockoutLogInterval,
 	}
 
 	// Optional log related settings

internalshared/configutil/merge.go

@@ -53,6 +53,11 @@ func (c *SharedConfig) Merge(c2 *SharedConfig) *SharedConfig {
 		result.DefaultMaxRequestDuration = c2.DefaultMaxRequestDuration
 	}
 
+	result.UserLockoutLogInterval = c.UserLockoutLogInterval
+	if c2.UserLockoutLogInterval > result.UserLockoutLogInterval {
+		result.UserLockoutLogInterval = c2.UserLockoutLogInterval
+	}
+
 	result.LogLevel = c.LogLevel
 	if c2.LogLevel != "" {
 		result.LogLevel = c2.LogLevel

vault/core.go

@@ -101,6 +101,11 @@ const (
 	// MfaAuthResponse when the value is not specified in the server config
 	defaultMFAAuthResponseTTL = 300 * time.Second
 
+	// defaultUserLockoutLogInterval is the default duration that Vault will
+	// emit a log informing that a user lockout is in effect when the value
+	// is not specified in the server config
+	defaultUserLockoutLogInterval = 1 * time.Minute
+
 	// defaultMaxTOTPValidateAttempts is the default value for the number
 	// of failed attempts to validate a request subject to TOTP MFA. If the
 	// number of failed totp passcode validations exceeds this max value, the
@@ -646,6 +651,9 @@ type Core struct {
 
 	updateLockedUserEntriesCancel context.CancelFunc
 
+	lockoutLoggerCancel    context.CancelFunc
+	userLockoutLogInterval time.Duration
+
 	// number of workers to use for lease revocation in the expiration manager
 	numExpirationWorkers int
 
@@ -853,6 +861,8 @@ type CoreConfig struct {
 	// AdministrativeNamespacePath is used to configure the administrative namespace, which has access to some sys endpoints that are
 	// only accessible in the root namespace, currently sys/audit-hash and sys/monitor.
 	AdministrativeNamespacePath string
+
+	UserLockoutLogInterval time.Duration
 }
 
 // SubloggerHook implements the SubloggerAdder interface. This implementation
@@ -900,6 +910,10 @@ func CreateCore(conf *CoreConfig) (*Core, error) {
 		return nil, fmt.Errorf("cannot have DefaultLeaseTTL larger than MaxLeaseTTL")
 	}
 
+	if conf.UserLockoutLogInterval == 0 {
+		conf.UserLockoutLogInterval = defaultUserLockoutLogInterval
+	}
+
 	// Validate the advertise addr if its given to us
 	if conf.RedirectAddr != "" {
 		u, err := url.Parse(conf.RedirectAddr)
@@ -1021,6 +1035,7 @@ func CreateCore(conf *CoreConfig) (*Core, error) {
 		disableSSCTokens:               conf.DisableSSCTokens,
 		effectiveSDKVersion:            effectiveSDKVersion,
 		userFailedLoginInfo:            make(map[FailedLoginUser]*FailedLoginInfo),
+		userLockoutLogInterval:         conf.UserLockoutLogInterval,
 		experiments:                    conf.Experiments,
 		pendingRemovalMountsAllowed:    conf.PendingRemovalMountsAllowed,
 		expirationRevokeRetryBase:      conf.ExpirationRevokeRetryBase,
@@ -3436,6 +3451,51 @@ func (c *Core) setupCachedMFAResponseAuth() {
 	return
 }
 
+func (c *Core) startLockoutLogger() {
+	// Are we already running a logger
+	if c.lockoutLoggerCancel != nil {
+		return
+	}
+
+	ctx, cancelFunc := context.WithCancel(c.activeContext)
+	c.lockoutLoggerCancel = cancelFunc
+
+	// Perform first check for lockout entries
+	lockedUserCount := c.getUserFailedLoginCount(ctx)
+
+	if lockedUserCount > 0 {
+		c.Logger().Warn("user lockout(s) in effect")
+	} else {
+		// We shouldn't end up here
+		return
+	}
+
+	// Start lockout watcher
+	go func() {
+		ticker := time.NewTicker(c.userLockoutLogInterval)
+		for {
+			select {
+			case <-ticker.C:
+				// Check for lockout entries
+				lockedUserCount := c.getUserFailedLoginCount(ctx)
+
+				if lockedUserCount > 0 {
+					c.Logger().Warn("user lockout(s) in effect")
+					break
+				}
+				c.Logger().Info("user lockout(s) cleared")
+				ticker.Stop()
+				c.lockoutLoggerCancel = nil
+				return
+			case <-ctx.Done():
+				ticker.Stop()
+				c.lockoutLoggerCancel = nil
+				return
+			}
+		}
+	}()
+}
+
 // updateLockedUserEntries runs every 15 mins to remove stale user entries from storage
 // it also updates the userFailedLoginInfo map with correct information for locked users if incorrect
 func (c *Core) updateLockedUserEntries() {
@@ -3464,7 +3524,13 @@ func (c *Core) updateLockedUserEntries() {
 			}
 		}
 	}()
-	return
+}
+
+func (c *Core) getUserFailedLoginCount(ctx context.Context) int {
+	c.userFailedLoginInfoLock.Lock()
+	defer c.userFailedLoginInfoLock.Unlock()
+
+	return len(c.userFailedLoginInfo)
 }
 
 // runLockedUserEntryUpdates runs updates for locked user storage entries and userFailedLoginInfo map

vault/logical_system_user_lockout.go

@@ -48,6 +48,16 @@ func unlockUser(ctx context.Context, core *Core, mountAccessor string, aliasName
 		return err
 	}
 
+	// Check if we have no more locked users and cancel any running lockout logger
+	core.userFailedLoginInfoLock.RLock()
+	numLockedUsers := len(core.userFailedLoginInfo)
+	core.userFailedLoginInfoLock.RUnlock()
+
+	if numLockedUsers == 0 {
+		core.Logger().Info("user lockout(s) cleared")
+		core.lockoutLoggerCancel()
+	}
+
 	return nil
 }
 

vault/request_handling.go

@@ -1447,6 +1447,7 @@ func (c *Core) handleLoginRequest(ctx context.Context, req *logical.Request) (re
 			return nil, nil, err
 		}
 		if isloginUserLocked {
+			c.startLockoutLogger()
 			return nil, nil, logical.ErrPermissionDenied
 		}
 	}
@@ -2262,6 +2263,8 @@ func (c *Core) LocalGetUserFailedLoginInfo(ctx context.Context, userKey FailedLo
 // LocalUpdateUserFailedLoginInfo updates the failed login information for a user based on alias name and mountAccessor
 func (c *Core) LocalUpdateUserFailedLoginInfo(ctx context.Context, userKey FailedLoginUser, failedLoginInfo *FailedLoginInfo, deleteEntry bool) error {
 	c.userFailedLoginInfoLock.Lock()
+	defer c.userFailedLoginInfoLock.Unlock()
+
 	switch deleteEntry {
 	case false:
 		// update entry in the map
@@ -2304,7 +2307,6 @@ func (c *Core) LocalUpdateUserFailedLoginInfo(ctx context.Context, userKey Faile
 		// delete the entry from the map, if no key exists it is no-op
 		delete(c.userFailedLoginInfo, userKey)
 	}
-	c.userFailedLoginInfoLock.Unlock()
 	return nil
 }