feat: Auth check log

.gitignore

@@ -1,4 +1,10 @@
 .idea/
-test-out/
-/testconf/
+/authaus.out
 /log/
+/testconf/
+test-out/
+/out
+/test.log
+/test-2025-08-07T06-17-16.613.log
+/test-2025-08-07T06-18-32.789.log
+/TestAuthRoleDB_MissingGroups_in_github_com_IMQS_authaus.test.exe

all_test.go

@@ -199,7 +199,7 @@ func getCentral(t *testing.T) *Central {
 		userStore = newDummyUserStore()
 	}
 
-	c := NewCentral(log.Stdout, nil, nil, userStore, permitDB, sessionDB, roleDB)
+	c := NewCentral(log.Stdout, nil, nil, userStore, permitDB, sessionDB, roleDB, nil)
 	c.Auditor = &dummyAuditor{}
 	if isBackendPostgresTest() {
 		c.DB = sqlDB
@@ -371,6 +371,8 @@ func sqlDeleteAllTables(db *sql.DB) error {
 		"DROP TABLE IF EXISTS oauthchallenge CASCADE",
 		"DROP TABLE IF EXISTS oauthsession CASCADE",
 		"DROP TABLE IF EXISTS migration_version CASCADE",
+		"DROP TABLE IF EXISTS authuserstats CASCADE",
+		"DROP TABLE IF EXISTS session_check_logs CASCADE",
 	}
 	for _, st := range statements {
 		if _, err := db.Exec(st); err != nil {

auth.go

@@ -313,6 +313,7 @@ type Central struct {
 	permitDB                    PermitDB
 	sessionDB                   SessionDB
 	roleGroupDB                 RoleGroupDB
+	UsageTracker                *CheckUsageTracker
 	renameLock                  sync.Mutex
 	loginDelayMS                uint64 // Number of milliseconds by which we increase the delay login every time the user enters invalid credentials
 	shuttingDown                uint32
@@ -326,7 +327,7 @@ type Central struct {
 
 // Create a new Central object from the specified pieces.
 // roleGroupDB may be nil
-func NewCentral(logfile string, ldap LDAP, msaad MSAADInterface, userStore UserStore, permitDB PermitDB, sessionDB SessionDB, roleGroupDB RoleGroupDB) *Central {
+func NewCentral(logfile string, ldap LDAP, msaad MSAADInterface, userStore UserStore, permitDB PermitDB, sessionDB SessionDB, roleGroupDB RoleGroupDB, usageTracker *CheckUsageTracker) *Central {
 	c := &Central{}
 
 	c.OAuth.Initialize(c)
@@ -361,6 +362,10 @@ func NewCentral(logfile string, ldap LDAP, msaad MSAADInterface, userStore UserS
 		}
 	}
 
+	if usageTracker != nil {
+		c.UsageTracker = usageTracker
+		c.UsageTracker.Initialize(c.Log)
+	}
 	c.Log.Infof("Authaus successfully started up\n")
 
 	return c
@@ -369,13 +374,14 @@ func NewCentral(logfile string, ldap LDAP, msaad MSAADInterface, userStore UserS
 // Create a new 'Central' object from a Config.
 func NewCentralFromConfig(config *Config) (central *Central, err error) {
 	var (
-		db          *sql.DB
-		ldap        LDAP
-		msaad       MSAADInterface
-		userStore   UserStore
-		permitDB    PermitDB
-		sessionDB   SessionDB
-		roleGroupDB RoleGroupDB
+		db                *sql.DB
+		ldap              LDAP
+		msaad             MSAADInterface
+		userStore         UserStore
+		permitDB          PermitDB
+		sessionDB         SessionDB
+		roleGroupDB       RoleGroupDB
+		checkUsageTracker *CheckUsageTracker
 	)
 	msaadUsed := config.MSAAD.ClientID != ""
 	ldapUsed := len(config.LDAP.LdapHost) > 0
@@ -460,8 +466,9 @@ func NewCentralFromConfig(config *Config) (central *Central, err error) {
 		oldPasswordHistorySize = defaultOldPasswordHistorySize
 	}
 	userStore.SetConfig(time.Duration(config.UserStore.PasswordExpirySeconds)*time.Second, oldPasswordHistorySize, config.UserStore.UsersExemptFromExpiring)
+	checkUsageTracker = NewCheckUsageTracker(config.UsageTracking, nil, db)
 
-	c := NewCentral(config.Log.Filename, ldap, msaad, userStore, permitDB, sessionDB, roleGroupDB)
+	c := NewCentral(config.Log.Filename, ldap, msaad, userStore, permitDB, sessionDB, roleGroupDB, checkUsageTracker)
 	c.DB = db
 	c.MaxActiveSessions = config.SessionDB.MaxActiveSessions
 	if config.SessionDB.SessionExpirySeconds != 0 {
@@ -1197,6 +1204,10 @@ func (x *Central) Close() {
 		x.roleGroupDB.Close()
 		x.roleGroupDB = nil
 	}
+	if x.UsageTracker != nil {
+		x.UsageTracker.Stop()
+		x.UsageTracker = nil
+	}
 	if x.DB != nil {
 		x.DB.Close()
 	}

config.go

@@ -166,6 +166,23 @@ type ConfigUserStoreDB struct {
 	UsersExemptFromExpiring []string // List of users that are not subject to password expiry. Username will be used for comparison.
 }
 
+// UsageTrackingConfig controls session check usage tracking
+type ConfigUsageTracking struct {
+	Enabled              bool `json:"enabled"`                // Enable/disable usage tracking
+	FlushIntervalSeconds int  `json:"flush_interval_seconds"` // Flush interval in seconds (default: 60)
+	MaxEntries           int  `json:"max_entries"`            // Maximum number of entries to keep in memory before flushing (default: 1000)
+	Test_MemDump         bool `json:"test___mem_dump"`        // If true, dump memory usage statistics to log on flush
+}
+
+func (x *ConfigUsageTracking) SetDefaults() {
+	if x.FlushIntervalSeconds <= 0 {
+		x.FlushIntervalSeconds = 60 // Default to 1 minute
+	}
+	if x.MaxEntries <= 0 {
+		x.MaxEntries = 10000 // Default to 10000 entries
+	}
+}
+
 /*
 Configuration information. This is typically loaded from a .json config file.
 */
@@ -178,6 +195,7 @@ type Config struct {
 	UserStore              ConfigUserStoreDB
 	OAuth                  ConfigOAuth
 	MSAAD                  ConfigMSAAD
+	UsageTracking          ConfigUsageTracking
 	AuditServiceUrl        string
 	EnableAccountLocking   bool
 	MaxFailedLoginAttempts int

docs/changelog.md

@@ -2,6 +2,8 @@
 
 ## Current
 
+* feat : Auth-check logger (ASG-4837)
+
 ## v1.3.8
 
 * fix : Add fetch-all for UserStats to combat performance issues 

go.mod

@@ -11,6 +11,7 @@ require (
 	github.com/stretchr/testify v1.9.0
 	github.com/wI2L/jsondiff v0.6.1
 	golang.org/x/crypto v0.31.0
+	golang.org/x/text v0.21.0
 )
 
 require (

go.sum

@@ -30,6 +30,8 @@ github.com/wI2L/jsondiff v0.6.1 h1:ISZb9oNWbP64LHnu4AUhsMF5W0FIj5Ok3Krip9Shqpw=
 github.com/wI2L/jsondiff v0.6.1/go.mod h1:KAEIojdQq66oJiHhDyQez2x+sRit0vIzC9KeK0yizxM=
 golang.org/x/crypto v0.31.0 h1:ihbySMvVjLAeSH1IbfcRTkD/iNscyz8rGzjF/E5hV6U=
 golang.org/x/crypto v0.31.0/go.mod h1:kDsLvtWBEx7MV9tJOj9bnXsPbxwJQ6csT/x4KIN4Ssk=
+golang.org/x/text v0.21.0 h1:zyQAAkrwaneQ066sspRyJaG9VNi/YJ1NfzcGB3hZ/qo=
+golang.org/x/text v0.21.0/go.mod h1:4IBbMaMmOPCJ8SecivzSH54+73PCFmPWxNTLm+vZkEQ=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
 gopkg.in/natefinch/lumberjack.v2 v2.2.1 h1:bBRl1b0OH9s/DuPhuXpNl+VtCaJXFZ5/uEFST95x9zc=

migrations.go

@@ -282,6 +282,9 @@ func createMigrations() []migration.Migrator {
 
 		// 16. Add authuserstats table that will record user_id, enabled_date, disabled_date, last_login_date
 		simple(`CREATE TABLE authuserstats (user_id BIGINT PRIMARY KEY, enabled_date TIMESTAMP, disabled_date TIMESTAMP, last_login_date TIMESTAMP);`),
+
+		// 17. Add: session_check_logs
+		simple(`CREATE TABLE session_check_logs (id bigserial PRIMARY KEY, ts TIMESTAMP WITH TIME ZONE NOT NULL, session_token VARCHAR NOT NULL, user_id BIGINT NOT NULL);`),
 	}
 }
 

msaad_test.go

@@ -178,7 +178,7 @@ func getCentralMSAAD(t *testing.T) *Central {
 	p.Roles = EncodePermit(groupIds)
 	permitDB.SetPermit(user.UserId, &p)
 
-	c := NewCentral(log.Stdout, nil, &msaad, userStore, permitDB, sessionDB, roleDB)
+	c := NewCentral(log.Stdout, nil, &msaad, userStore, permitDB, sessionDB, roleDB, nil)
 	da := &dummyAuditor{}
 	da.messages = []string{}
 	da.testing = t

permitchecklog.go

@@ -0,0 +1,204 @@
+package authaus
+
+import (
+	"database/sql"
+	"fmt"
+	"github.com/IMQS/log"
+	"sync"
+	"time"
+)
+
+// CheckLogEntry represents a single session check log entry
+type CheckLogEntry struct {
+	Timestamp    time.Time `json:"timestamp"`
+	SessionToken string    `json:"session_token"`
+	UserId       UserId    `json:"user_id"`
+}
+
+// CheckUsageTracker manages in-memory storage and periodic flushing of session check logs
+type CheckUsageTracker struct {
+	config           ConfigUsageTracking
+	log              *log.Logger
+	logs             []CheckLogEntry
+	mutex            sync.RWMutex
+	stopChan         chan struct{}
+	doneChan         chan struct{}
+	flushDoneChan    chan struct{}
+	stopOnce         sync.Once
+	flushTicker      *time.Ticker
+	flushing         bool // Track if a flush is in progress
+	db               *sql.DB
+	droppedLogsCount int64
+	memDump          []string // For testing purposes
+}
+
+// NewCheckUsageTracker creates a new usage tracker instance
+func NewCheckUsageTracker(c ConfigUsageTracking, log *log.Logger, db *sql.DB) *CheckUsageTracker {
+	c.SetDefaults()
+	tracker := &CheckUsageTracker{
+		config:        c,
+		log:           log,
+		logs:          make([]CheckLogEntry, 0),
+		stopChan:      make(chan struct{}),
+		doneChan:      make(chan struct{}),
+		flushDoneChan: make(chan struct{}, 1),
+		db:            db, // Database connection will be set later
+	}
+	if tracker.config.Test_MemDump {
+		tracker.memDump = make([]string, 0)
+	}
+	return tracker
+}
+
+func (t *CheckUsageTracker) Initialize(logger *log.Logger) {
+	if logger != nil {
+		t.log = logger
+
+		if t.config.Enabled {
+			t.start()
+		}
+
+		if t.db == nil {
+			t.log.Warn("CheckUsageTracker initialized without a database connection, logs will not be persisted")
+		} else {
+			t.log.Info("CheckUsageTracker initialized with database connection")
+		}
+	}
+}
+
+// LogCheck adds a check request to the in-memory log
+func (t *CheckUsageTracker) LogCheck(sessionToken string, token *Token) {
+	if !t.config.Enabled {
+		return
+	}
+
+	entry := CheckLogEntry{
+		Timestamp:    time.Now().UTC(),
+		SessionToken: sessionToken,
+		UserId:       token.UserId,
+	}
+
+	t.mutex.Lock()
+	if len(t.logs) >= t.config.MaxEntries {
+		t.droppedLogsCount++
+		// drop entry
+	} else {
+		t.logs = append(t.logs, entry)
+	}
+	t.mutex.Unlock()
+}
+
+// start begins the periodic flush process
+func (t *CheckUsageTracker) start() {
+	flushInterval := time.Duration(t.config.FlushIntervalSeconds) * time.Second
+	if flushInterval <= 0 {
+		flushInterval = 60 * time.Second // Default to 1 minute
+	}
+
+	t.flushTicker = time.NewTicker(flushInterval)
+
+	go func() {
+		defer close(t.doneChan)
+		for {
+			select {
+			case <-t.flushTicker.C:
+				t.flush()
+			case <-t.stopChan:
+				t.flushTicker.Stop()
+				t.flush() // Final flush before stopping
+				return
+			}
+		}
+	}()
+}
+
+// Stop gracefully shuts down the usage tracker
+func (t *CheckUsageTracker) Stop() {
+	t.stopOnce.Do(func() {
+		if t.flushTicker != nil && t.stopChan != nil {
+			close(t.stopChan)
+			<-t.doneChan      // Wait for main flush management goroutine to finish
+			<-t.flushDoneChan // Wait for any ongoing flush operation to complete
+		}
+	})
+}
+
+// flush writes the in-memory logs to persistent storage and clears the memory
+// TODO : Implement a more generic persistence abstraction (e.g. Provider pattern)
+func (t *CheckUsageTracker) flush() {
+	t.mutex.Lock()
+
+	if len(t.logs) == 0 || t.flushing {
+		t.mutex.Unlock()
+		return
+	}
+
+	// Create a copy of logs to persist
+	logsToPersist := make([]CheckLogEntry, len(t.logs))
+	copy(logsToPersist, t.logs)
+	logsCount := len(t.logs)
+
+	// Mark that we're flushing to prevent concurrent flushes
+	t.flushing = true
+	t.mutex.Unlock()
+
+	// Persist logs in a separate goroutine to avoid blocking
+	go func() {
+		err := t.persistLogs(logsToPersist)
+
+		// Handle the result of persistence
+		t.mutex.Lock()
+		t.flushing = false
+
+		if err != nil {
+			t.log.Errorf("Failed to persist check usage logs: %v", err)
+			// Keep the logs in memory for retry - don't clear them
+		} else {
+			// Only clear logs after successful persistence
+			// Check if new logs were added during persistence
+			if len(t.logs) >= logsCount {
+				// Remove the persisted logs (first logsCount entries)
+				t.logs = t.logs[logsCount:]
+			} else {
+				// Shouldn't happen, but clear all if somehow we have fewer logs
+				t.logs = t.logs[:0]
+			}
+		}
+		t.mutex.Unlock()
+		t.flushDoneChan <- struct{}{}
+	}()
+}
+
+// persistLogs writes logs to persistent storage using authaus persistence abstraction
+func (t *CheckUsageTracker) persistLogs(logs []CheckLogEntry) error {
+	if t.db != nil {
+		// Example SQL insert statement, assuming a table structure exists
+		stmt, err := t.db.Prepare("INSERT INTO session_check_logs (ts, session_token, user_id) VALUES ($1, $2, $3)")
+		if err != nil {
+			return err
+		}
+		defer stmt.Close()
+
+		for _, entry := range logs {
+			_, err = stmt.Exec(entry.Timestamp, entry.SessionToken, entry.UserId)
+			if err != nil {
+				return err
+			}
+		}
+	} else {
+		// this is for testing, NOT production
+		if t.config.Test_MemDump {
+			// If no database connection, just clear
+			for _, entry := range logs {
+				t.memDump = append(t.memDump, checkLogString(entry))
+			}
+		}
+	}
+	return nil
+}
+
+func checkLogString(entry CheckLogEntry) string {
+	return "Persisting CheckUsage: time=" + entry.Timestamp.Format(time.RFC3339) +
+		" token=" + entry.SessionToken +
+		" userId=" + fmt.Sprint(entry.UserId)
+}