package audit import ( "database/sql" "errors" "fmt" "net/url" "os" "path/filepath" "strconv" "strings" "sync" "time" "github.com/rs/zerolog/log" sqlite "modernc.org/sqlite" ) // SQLiteLoggerConfig configures the SQLite audit logger. type SQLiteLoggerConfig struct { DataDir string // Base data directory; audit data is stored in /audit. AuditDir string // Optional exact audit directory, overriding DataDir. CryptoMgr CryptoEncryptor // For encrypting the signing key (optional). SigningKey []byte // Optional externally managed HMAC key. RetentionDays int // Days to keep events. RetentionConfigured bool // Treat RetentionDays=0 as an explicit forever setting. CleanupInterval time.Duration // Retention cleanup cadence (default: 24 hours). } // SQLiteLogger implements Logger with persistent SQLite storage and HMAC signing. type SQLiteLogger struct { mu sync.RWMutex db *sql.DB dbPath string signer *Signer webhookDelivery *WebhookDelivery retentionDays int cleanupInterval time.Duration stopChan chan struct{} wg sync.WaitGroup closeOnce sync.Once closeErr error } var retentionStartupCleanupDelay = 5 * time.Minute var retentionStartupCleanup = func(l *SQLiteLogger) { l.cleanupOldEvents() } const ( sqliteCodeBusy = 5 sqliteCodeLocked = 6 sqliteCodeReadonly = 8 sqliteCodeIOErr = 10 sqliteCodeCorrupt = 11 sqliteCodeCantOpen = 14 sqliteCodeNotADB = 26 sqliteCodeBusyRecovery = sqliteCodeBusy | (1 << 8) sqliteCodeBusySnapshot = sqliteCodeBusy | (2 << 8) sqliteCodeBusyTimeout = sqliteCodeBusy | (3 << 8) sqliteCodeLockedSharedCache = sqliteCodeLocked | (1 << 8) sqliteCodeLockedVTab = sqliteCodeLocked | (2 << 8) ) var auditSQLiteRetryDelays = []time.Duration{25 * time.Millisecond, 75 * time.Millisecond} var auditSQLiteRetrySleep = time.Sleep const ( auditSchemaVersion = 2 auditTimestampMigrationBatchSize = 512 defaultAuditCleanupInterval = 24 * time.Hour ) type auditStoreDataError struct { field string } func (e *auditStoreDataError) Error() string { return "audit store contains an invalid " + e.field + " encoding" } // IsStoreBusyError reports whether an audit store error is a transient SQLite lock. func IsStoreBusyError(err error) bool { if err == nil { return false } var sqliteErr *sqlite.Error if errors.As(err, &sqliteErr) { switch sqliteErr.Code() { case sqliteCodeBusy, sqliteCodeLocked, sqliteCodeBusyRecovery, sqliteCodeBusySnapshot, sqliteCodeBusyTimeout, sqliteCodeLockedSharedCache, sqliteCodeLockedVTab: return true } } message := strings.ToLower(err.Error()) return strings.Contains(message, "sqlite_busy") || strings.Contains(message, "sqlite_locked") || strings.Contains(message, "database is locked") || strings.Contains(message, "database table is locked") } // IsStoreUnavailableError reports whether an audit store error means the // backing database is missing, corrupt, unreadable, or not initialized. func IsStoreUnavailableError(err error) bool { if err == nil { return false } if IsStoreBusyError(err) { return false } var dataErr *auditStoreDataError if errors.As(err, &dataErr) { return true } var sqliteErr *sqlite.Error if errors.As(err, &sqliteErr) { switch sqliteErr.Code() { case sqliteCodeReadonly, sqliteCodeIOErr, sqliteCodeCorrupt, sqliteCodeCantOpen, sqliteCodeNotADB: return true } } message := strings.ToLower(err.Error()) return strings.Contains(message, "database disk image is malformed") || strings.Contains(message, "file is not a database") || strings.Contains(message, "unable to open database file") || strings.Contains(message, "attempt to write a readonly database") || strings.Contains(message, "no such table: audit_events") || strings.Contains(message, "no such table: schema_version") } func withSQLiteRetry(operation string, run func() error) error { var err error for attempt := 0; ; attempt++ { err = run() if err == nil || !IsStoreBusyError(err) || attempt >= len(auditSQLiteRetryDelays) { return err } delay := auditSQLiteRetryDelays[attempt] log.Warn(). Err(err). Str("operation", operation). Int("attempt", attempt+1). Dur("retryIn", delay). Msg("Audit SQLite store busy; retrying") auditSQLiteRetrySleep(delay) } } // NewSQLiteLogger creates a new SQLite-backed audit logger. func NewSQLiteLogger(cfg SQLiteLoggerConfig) (*SQLiteLogger, error) { if cfg.DataDir == "" && cfg.AuditDir == "" { return nil, fmt.Errorf("data directory is required") } // Ensure directory exists auditDir := cfg.AuditDir if auditDir == "" { auditDir = filepath.Join(cfg.DataDir, "audit") } if err := os.MkdirAll(auditDir, 0700); err != nil { return nil, fmt.Errorf("failed to create audit directory: %w", err) } dbPath := filepath.Join(auditDir, "audit.db") // Open database with pragmas in DSN so every pool connection is configured dsn := dbPath + "?" + url.Values{ "_pragma": []string{ "busy_timeout(30000)", "journal_mode(WAL)", "synchronous(NORMAL)", "foreign_keys(ON)", "cache_size(-64000)", }, }.Encode() db, err := sql.Open("sqlite", dsn) if err != nil { return nil, fmt.Errorf("failed to open audit database: %w", err) } // SQLite works best with a single writer connection db.SetMaxOpenConns(1) db.SetMaxIdleConns(1) db.SetConnMaxLifetime(0) // Initialize signer var signer *Signer if len(cfg.SigningKey) > 0 { signer, err = NewSignerWithKey(cfg.SigningKey) } else { signer, err = NewSigner(auditDir, cfg.CryptoMgr) } if err != nil { db.Close() return nil, fmt.Errorf("failed to initialize audit signer: %w", err) } retentionDays := cfg.RetentionDays if retentionDays == 0 && !cfg.RetentionConfigured { retentionDays = 90 // Default } cleanupInterval := cfg.CleanupInterval if cleanupInterval <= 0 { cleanupInterval = defaultAuditCleanupInterval } l := &SQLiteLogger{ db: db, dbPath: dbPath, signer: signer, retentionDays: retentionDays, cleanupInterval: cleanupInterval, stopChan: make(chan struct{}), } // Initialize schema if err := l.initSchema(); err != nil { db.Close() return nil, fmt.Errorf("failed to initialize schema: %w", err) } if cfg.RetentionDays == 0 && !cfg.RetentionConfigured { if persisted, ok := l.loadRetentionDays(); ok { l.retentionDays = persisted retentionDays = persisted } } l.migrateAutoVacuum() // Load webhook URLs from config table urls := l.loadWebhookURLs() if len(urls) > 0 { l.webhookDelivery = NewWebhookDelivery(urls) l.webhookDelivery.Start() } // Start retention worker if retention is enabled if retentionDays > 0 { l.wg.Add(1) go l.retentionWorker() } log.Info(). Str("dbPath", dbPath). Int("retentionDays", retentionDays). Bool("signingEnabled", signer.SigningEnabled()). Msg("SQLite audit logger initialized") return l, nil } // IsPersistentAuditLogger reports that SQLite provides queryable audit storage. func (l *SQLiteLogger) IsPersistentAuditLogger() bool { return l != nil } // initSchema creates the database tables and runs migrations. func (l *SQLiteLogger) initSchema() error { schema := ` CREATE TABLE IF NOT EXISTS audit_events ( id TEXT PRIMARY KEY, timestamp INTEGER NOT NULL, event_type TEXT NOT NULL, user TEXT, ip TEXT, path TEXT, success INTEGER NOT NULL, details TEXT, signature TEXT NOT NULL ); CREATE INDEX IF NOT EXISTS idx_audit_timestamp ON audit_events(timestamp); CREATE INDEX IF NOT EXISTS idx_audit_timestamp_id ON audit_events(timestamp DESC, id DESC); CREATE INDEX IF NOT EXISTS idx_audit_event_type ON audit_events(event_type); CREATE INDEX IF NOT EXISTS idx_audit_user ON audit_events(user) WHERE user != ''; CREATE INDEX IF NOT EXISTS idx_audit_success ON audit_events(success); CREATE TABLE IF NOT EXISTS audit_config ( key TEXT PRIMARY KEY, value TEXT NOT NULL, updated_at INTEGER NOT NULL ); CREATE TABLE IF NOT EXISTS schema_version ( version INTEGER PRIMARY KEY, applied_at INTEGER NOT NULL ); ` var err error err = withSQLiteRetry("init_schema", func() error { _, err = l.db.Exec(schema) return err }) if err != nil { return fmt.Errorf("failed to create schema: %w", err) } // Record schema version err = withSQLiteRetry("record_schema_version", func() error { _, err = l.db.Exec(`INSERT OR IGNORE INTO schema_version (version, applied_at) VALUES (1, ?)`, time.Now().Unix()) return err }) if err != nil { return err } return l.migrateLegacyTimestamps() } type canonicalAuditRow struct { rowID int64 id string timestamp int64 eventType string user sql.NullString ip sql.NullString path sql.NullString success int details sql.NullString signature sql.NullString } func (l *SQLiteLogger) migrateLegacyTimestamps() error { var migrated int err := withSQLiteRetry("migrate_audit_timestamps", func() error { tx, err := l.db.Begin() if err != nil { return err } defer func() { _ = tx.Rollback() }() needsRebuild, err := auditEventsNeedRebuild(tx) if err != nil { return err } if !needsRebuild { if _, err := tx.Exec( `INSERT OR IGNORE INTO schema_version (version, applied_at) VALUES (?, ?)`, auditSchemaVersion, time.Now().Unix(), ); err != nil { return err } return tx.Commit() } if err := tx.QueryRow( `SELECT COUNT(*) FROM audit_events WHERE typeof(timestamp) != 'integer'`, ).Scan(&migrated); err != nil { return err } if _, err := tx.Exec(`DROP TABLE IF EXISTS audit_events_v2`); err != nil { return err } if _, err := tx.Exec(` CREATE TABLE audit_events_v2 ( id TEXT PRIMARY KEY, timestamp INTEGER NOT NULL, event_type TEXT NOT NULL, user TEXT, ip TEXT, path TEXT, success INTEGER NOT NULL, details TEXT, signature TEXT NOT NULL )`); err != nil { return err } lastRowID := int64(-1 << 63) for { rows, err := tx.Query(` SELECT rowid, id, timestamp, event_type, user, ip, path, success, details, signature FROM audit_events WHERE rowid > ? ORDER BY rowid LIMIT ?`, lastRowID, auditTimestampMigrationBatchSize) if err != nil { return err } batch := make([]canonicalAuditRow, 0, auditTimestampMigrationBatchSize) for rows.Next() { var item canonicalAuditRow var value any if err := rows.Scan( &item.rowID, &item.id, &value, &item.eventType, &item.user, &item.ip, &item.path, &item.success, &item.details, &item.signature, ); err != nil { rows.Close() return &auditStoreDataError{field: "row"} } timestamp, err := parseAuditTimestamp(value) if err != nil { rows.Close() return &auditStoreDataError{field: "timestamp"} } if item.id == "" || item.eventType == "" || (item.success != 0 && item.success != 1) { rows.Close() return &auditStoreDataError{field: "row"} } item.timestamp = timestamp.Unix() batch = append(batch, item) } if err := rows.Err(); err != nil { rows.Close() return err } if err := rows.Close(); err != nil { return err } if len(batch) == 0 { break } for _, item := range batch { if _, err := tx.Exec( `INSERT INTO audit_events_v2 (id, timestamp, event_type, user, ip, path, success, details, signature) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)`, item.id, item.timestamp, item.eventType, item.user, item.ip, item.path, item.success, item.details, item.signature.String, ); err != nil { return err } } lastRowID = batch[len(batch)-1].rowID } if _, err := tx.Exec(`DROP TABLE audit_events`); err != nil { return err } if _, err := tx.Exec(`ALTER TABLE audit_events_v2 RENAME TO audit_events`); err != nil { return err } if _, err := tx.Exec(` CREATE INDEX idx_audit_timestamp ON audit_events(timestamp); CREATE INDEX idx_audit_timestamp_id ON audit_events(timestamp DESC, id DESC); CREATE INDEX idx_audit_event_type ON audit_events(event_type); CREATE INDEX idx_audit_user ON audit_events(user) WHERE user != ''; CREATE INDEX idx_audit_success ON audit_events(success); `); err != nil { return err } if _, err := tx.Exec( `INSERT OR REPLACE INTO schema_version (version, applied_at) VALUES (?, ?)`, auditSchemaVersion, time.Now().Unix(), ); err != nil { return err } return tx.Commit() }) if err != nil { return fmt.Errorf("normalize audit timestamp storage: %w", err) } if migrated > 0 { log.Info(). Int("rows", migrated). Msg("Normalized legacy audit timestamp storage") } return nil } func auditEventsNeedRebuild(tx *sql.Tx) (bool, error) { rows, err := tx.Query(`PRAGMA table_info(audit_events)`) if err != nil { return false, err } defer rows.Close() columns := make(map[string]struct { columnType string notNull bool }) for rows.Next() { var position int var name, columnType string var notNull, primaryKey int var defaultValue any if err := rows.Scan( &position, &name, &columnType, ¬Null, &defaultValue, &primaryKey, ); err != nil { return false, &auditStoreDataError{field: "schema"} } columns[name] = struct { columnType string notNull bool }{columnType: strings.ToUpper(columnType), notNull: notNull != 0} } if err := rows.Err(); err != nil { return false, err } timestamp, timestampOK := columns["timestamp"] signature, signatureOK := columns["signature"] if !timestampOK || !signatureOK { return false, &auditStoreDataError{field: "schema"} } if timestamp.columnType != "INTEGER" || !timestamp.notNull || !signature.notNull { return true, nil } var hasNonInteger int if err := tx.QueryRow( `SELECT EXISTS(SELECT 1 FROM audit_events WHERE typeof(timestamp) != 'integer')`, ).Scan(&hasNonInteger); err != nil { return false, err } return hasNonInteger != 0, nil } // Log records an audit event with HMAC signature. func (l *SQLiteLogger) Record(event Event) error { // Sign the event event.Signature = l.signer.Sign(event) // Insert into database success := 0 if event.Success { success = 1 } var err error err = withSQLiteRetry("insert_audit_event", func() error { l.mu.Lock() defer l.mu.Unlock() _, err = l.db.Exec(` INSERT INTO audit_events (id, timestamp, event_type, user, ip, path, success, details, signature) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)`, event.ID, event.Timestamp.Unix(), event.EventType, event.User, event.IP, event.Path, success, event.Details, event.Signature, ) return err }) if err != nil { return fmt.Errorf("failed to insert audit event: %w", err) } // Also log to zerolog for real-time visibility logContext := log.With(). Str("audit_id", event.ID). Str("event", event.EventType). Time("timestamp", event.Timestamp) logContext = appendRealtimeAuditIdentityFields(logContext, event) logEvent := appendRealtimeAuditDetailFields(logContext, event.Details).Logger() if event.Success { logEvent.Info().Msg("Audit event") } else { logEvent.Warn().Msg("Audit event - FAILED") } // Send to webhooks if configured if l.webhookDelivery != nil { l.webhookDelivery.Enqueue(event) } return nil } // Query retrieves audit events matching the filter. func (l *SQLiteLogger) Query(filter QueryFilter) ([]Event, error) { var events []Event err := withSQLiteRetry("query_audit_events", func() error { l.mu.RLock() defer l.mu.RUnlock() result, err := l.queryLocked(filter) if err != nil { return err } events = result return nil }) if err != nil { return nil, err } return events, nil } func (l *SQLiteLogger) queryLocked(filter QueryFilter) ([]Event, error) { return queryAuditEvents(l.db, filter) } type auditSQLReader interface { Query(query string, args ...any) (*sql.Rows, error) QueryRow(query string, args ...any) *sql.Row } func queryAuditEvents(reader auditSQLReader, filter QueryFilter) ([]Event, error) { query := "SELECT id, timestamp, event_type, user, ip, path, success, details, signature FROM audit_events WHERE 1=1" args := []interface{}{} if filter.ID != "" { query += " AND id = ?" args = append(args, filter.ID) } if filter.StartTime != nil { query += " AND timestamp >= ?" args = append(args, filter.StartTime.Unix()) } if filter.EndTime != nil { query += " AND timestamp <= ?" args = append(args, filter.EndTime.Unix()) } if filter.EventType != "" { query += " AND event_type = ?" args = append(args, filter.EventType) } if filter.User != "" { query += " AND user = ?" args = append(args, filter.User) } if filter.Success != nil { success := 0 if *filter.Success { success = 1 } query += " AND success = ?" args = append(args, success) } query += " ORDER BY timestamp DESC, id DESC" if filter.Limit > 0 { query += " LIMIT ?" args = append(args, filter.Limit) } if filter.Offset > 0 { // SQLite requires LIMIT when OFFSET is present. if filter.Limit <= 0 { query += " LIMIT -1" } query += " OFFSET ?" args = append(args, filter.Offset) } rows, err := reader.Query(query, args...) if err != nil { return nil, fmt.Errorf("failed to query audit events: %w", err) } defer rows.Close() events := make([]Event, 0) for rows.Next() { var e Event var timestampValue any var success int var user, ip, path, details, signature sql.NullString err := rows.Scan(&e.ID, ×tampValue, &e.EventType, &user, &ip, &path, &success, &details, &signature) if err != nil { return nil, fmt.Errorf("failed to scan audit event: %w", err) } timestamp, err := parseAuditTimestamp(timestampValue) if err != nil { return nil, fmt.Errorf("failed to scan audit event: %w", err) } e.Timestamp = timestamp e.Success = success == 1 e.User = user.String e.IP = ip.String e.Path = path.String e.Details = details.String e.Signature = signature.String events = append(events, e) } return events, rows.Err() } // QueryPage reads events and their matching count from one SQLite snapshot. func (l *SQLiteLogger) QueryPage(filter QueryFilter) ([]Event, int, error) { var events []Event var total int err := withSQLiteRetry("query_audit_page", func() error { l.mu.RLock() defer l.mu.RUnlock() tx, err := l.db.Begin() if err != nil { return err } defer func() { _ = tx.Rollback() }() events, err = queryAuditEvents(tx, filter) if err != nil { return err } countFilter := filter countFilter.Limit = 0 countFilter.Offset = 0 total, err = countAuditEvents(tx, countFilter) if err != nil { return err } return tx.Commit() }) if err != nil { return nil, 0, err } return events, total, nil } func parseAuditTimestamp(value any) (time.Time, error) { switch v := value.(type) { case time.Time: return v, nil case int64: return time.Unix(v, 0), nil case int: return time.Unix(int64(v), 0), nil case int32: return time.Unix(int64(v), 0), nil case float64: return time.Unix(int64(v), 0), nil case []byte: return parseAuditTimestampString(string(v)) case string: return parseAuditTimestampString(v) case nil: return time.Time{}, errors.New("timestamp is null") default: return time.Time{}, fmt.Errorf("unsupported timestamp type %T", value) } } func parseAuditTimestampString(raw string) (time.Time, error) { raw = strings.TrimSpace(raw) if raw == "" { return time.Time{}, errors.New("timestamp is empty") } if unix, err := strconv.ParseInt(raw, 10, 64); err == nil { return time.Unix(unix, 0), nil } if monotonicIndex := strings.LastIndex(raw, " m="); monotonicIndex > 0 && monotonicIndex+3 < len(raw) { sign := raw[monotonicIndex+3] if sign == '+' || sign == '-' { raw = strings.TrimSpace(raw[:monotonicIndex]) } } layouts := []string{ time.RFC3339Nano, time.RFC3339, "2006-01-02 15:04:05.999999999Z07:00", "2006-01-02 15:04:05.999999Z07:00", "2006-01-02 15:04:05Z07:00", "2006-01-02 15:04:05.999999999-07:00", "2006-01-02 15:04:05.999999-07:00", "2006-01-02 15:04:05-07:00", "2006-01-02 15:04:05.999999999 -0700 MST", "2006-01-02 15:04:05.999999 -0700 MST", "2006-01-02 15:04:05 -0700 MST", "2006-01-02 15:04:05.999999999", "2006-01-02 15:04:05.999999", "2006-01-02 15:04:05", } for _, layout := range layouts { if timestamp, err := time.Parse(layout, raw); err == nil { return timestamp, nil } } return time.Time{}, errors.New("unsupported timestamp encoding") } // Count returns the number of events matching the filter. func (l *SQLiteLogger) Count(filter QueryFilter) (int, error) { var count int err := withSQLiteRetry("count_audit_events", func() error { l.mu.RLock() defer l.mu.RUnlock() result, err := l.countLocked(filter) if err != nil { return err } count = result return nil }) if err != nil { return 0, err } return count, nil } func (l *SQLiteLogger) countLocked(filter QueryFilter) (int, error) { return countAuditEvents(l.db, filter) } func countAuditEvents(reader auditSQLReader, filter QueryFilter) (int, error) { query := "SELECT COUNT(*) FROM audit_events WHERE 1=1" args := []interface{}{} if filter.ID != "" { query += " AND id = ?" args = append(args, filter.ID) } if filter.StartTime != nil { query += " AND timestamp >= ?" args = append(args, filter.StartTime.Unix()) } if filter.EndTime != nil { query += " AND timestamp <= ?" args = append(args, filter.EndTime.Unix()) } if filter.EventType != "" { query += " AND event_type = ?" args = append(args, filter.EventType) } if filter.User != "" { query += " AND user = ?" args = append(args, filter.User) } if filter.Success != nil { success := 0 if *filter.Success { success = 1 } query += " AND success = ?" args = append(args, success) } var count int err := reader.QueryRow(query, args...).Scan(&count) if err != nil { return 0, fmt.Errorf("failed to count audit events: %w", err) } return count, nil } // GetWebhookURLs returns the configured webhook URLs. func (l *SQLiteLogger) GetWebhookURLs() []string { if l.webhookDelivery != nil { return l.webhookDelivery.GetURLs() } return l.loadWebhookURLs() } // UpdateWebhookURLs updates the webhook configuration. func (l *SQLiteLogger) UpdateWebhookURLs(urls []string) error { // Save to config table value := strings.Join(urls, ",") var err error err = withSQLiteRetry("update_webhook_urls", func() error { l.mu.Lock() defer l.mu.Unlock() _, err = l.db.Exec(` INSERT INTO audit_config (key, value, updated_at) VALUES ('webhook_urls', ?, ?) ON CONFLICT(key) DO UPDATE SET value = excluded.value, updated_at = excluded.updated_at`, value, time.Now().Unix()) return err }) if err != nil { return fmt.Errorf("failed to save webhook URLs: %w", err) } // Update delivery worker if len(urls) > 0 { if l.webhookDelivery == nil { l.webhookDelivery = NewWebhookDelivery(urls) l.webhookDelivery.Start() } else { l.webhookDelivery.UpdateURLs(urls) } } else if l.webhookDelivery != nil { l.webhookDelivery.Stop() l.webhookDelivery = nil } return nil } // VerifySignature checks if an event's signature is valid. func (l *SQLiteLogger) VerifySignature(event Event) bool { return l.signer.Verify(event) } // Close gracefully shuts down the logger. func (l *SQLiteLogger) Close() error { l.closeOnce.Do(func() { close(l.stopChan) if l.webhookDelivery != nil { l.webhookDelivery.Stop() } l.wg.Wait() if err := l.db.Close(); err != nil { l.closeErr = fmt.Errorf("failed to close audit database: %w", err) return } log.Info().Msg("SQLite audit logger closed") }) return l.closeErr } // loadWebhookURLs loads webhook URLs from the config table. func (l *SQLiteLogger) loadWebhookURLs() []string { var value string err := l.db.QueryRow(`SELECT value FROM audit_config WHERE key = 'webhook_urls'`).Scan(&value) if err != nil || value == "" { return nil } return strings.Split(value, ",") } func (l *SQLiteLogger) loadRetentionDays() (int, bool) { var value string if err := l.db.QueryRow( `SELECT value FROM audit_config WHERE key = 'retention_days'`, ).Scan(&value); err != nil { return 0, false } days, err := strconv.Atoi(value) if err != nil || days < 0 { return 0, false } return days, true } // retentionWorker runs periodically to clean up old events. func (l *SQLiteLogger) retentionWorker() { defer l.wg.Done() // Run at 3 AM daily ticker := time.NewTicker(l.cleanupInterval) defer ticker.Stop() // Also run once at startup after a short delay. Keep timer stoppable // so Close() can cancel it and avoid cleanup callbacks after shutdown. startupTimer := time.NewTimer(retentionStartupCleanupDelay) startupTimerCh := startupTimer.C defer func() { if !startupTimer.Stop() { select { case <-startupTimerCh: default: } } }() for { select { case <-l.stopChan: return case <-startupTimerCh: retentionStartupCleanup(l) startupTimerCh = nil case <-ticker.C: l.cleanupOldEvents() } } } // maxAuditReclaimPages caps how many freelist pages a single retention cycle // returns to the OS, so a large backlog drains over successive daily cycles // instead of holding the write lock in one long incremental_vacuum. const maxAuditReclaimPages = 50000 // migrateAutoVacuum ensures the database uses incremental auto-vacuum so // retention deletes can return pages to the OS. Without it the deletes free // pages internally but audit.db never shrinks, the same bloat class fixed for // unified_resources.db under #1496. Set once at startup rather than in the // DSN: as a per-connection pragma it replays as a header write on every new // pool connection (#1601). func (l *SQLiteLogger) migrateAutoVacuum() { var mode int if err := l.db.QueryRow("PRAGMA auto_vacuum").Scan(&mode); err != nil { log.Error().Err(err).Msg("Failed to check audit auto_vacuum mode") return } if mode == 2 { return } log.Info().Msg("Converting audit database to incremental auto-vacuum (one-time migration)") start := time.Now() if _, err := l.db.Exec("PRAGMA auto_vacuum = INCREMENTAL"); err != nil { log.Error().Err(err).Msg("Failed to set audit auto_vacuum mode") return } if _, err := l.db.Exec("VACUUM"); err != nil { log.Error().Err(err).Msg("Audit auto-vacuum migration VACUUM failed (will retry next restart)") return } log.Info().Dur("took", time.Since(start)).Msg("Audit auto-vacuum migration complete") } // reclaimFreePages returns freed pages to the OS after retention deletes. // Callers must hold l.mu. func (l *SQLiteLogger) reclaimFreePages() { var freelist int64 if err := l.db.QueryRow(`PRAGMA freelist_count`).Scan(&freelist); err != nil { log.Error().Err(err).Msg("Failed to read audit freelist_count") return } if freelist == 0 { return } pages := freelist if pages > maxAuditReclaimPages { pages = maxAuditReclaimPages } if _, err := l.db.Exec(fmt.Sprintf(`PRAGMA incremental_vacuum(%d)`, pages)); err != nil { log.Error().Err(err).Msg("Audit incremental vacuum failed") return } if _, err := l.db.Exec(`PRAGMA wal_checkpoint(TRUNCATE)`); err != nil { log.Error().Err(err).Msg("Audit WAL checkpoint failed") } } // cleanupOldEvents deletes events older than the retention period. func (l *SQLiteLogger) cleanupOldEvents() { var deleted int64 var retentionDays int err := withSQLiteRetry("cleanup_audit_events", func() error { l.mu.Lock() defer l.mu.Unlock() retentionDays = l.retentionDays if retentionDays <= 0 { return nil } cutoff := time.Now().AddDate(0, 0, -retentionDays).Unix() tx, err := l.db.Begin() if err != nil { return err } defer func() { _ = tx.Rollback() }() result, err := tx.Exec(`DELETE FROM audit_events WHERE timestamp < ?`, cutoff) if err != nil { return err } deleted, err = result.RowsAffected() if err != nil { return err } if deleted > 0 { now := time.Now().UTC().Truncate(time.Second) event := Event{ ID: fmt.Sprintf("cleanup-%d", now.UnixNano()), Timestamp: now, EventType: "audit_cleanup", User: "system", Success: true, Details: fmt.Sprintf("Deleted %d events older than %d days", deleted, retentionDays), } event.Signature = l.signer.Sign(event) if _, err := tx.Exec(` INSERT INTO audit_events (id, timestamp, event_type, user, ip, path, success, details, signature) VALUES (?, ?, ?, ?, ?, ?, 1, ?, ?)`, event.ID, event.Timestamp.Unix(), event.EventType, event.User, event.IP, event.Path, event.Details, event.Signature, ); err != nil { return err } } if err := tx.Commit(); err != nil { return err } l.reclaimFreePages() return nil }) if err != nil { log.Error().Err(err).Msg("Failed to cleanup old audit events") return } if deleted > 0 { log.Info(). Int64("deleted", deleted). Int("retentionDays", retentionDays). Msg("Cleaned up old audit events") } } // GetRetentionDays returns the current retention period. func (l *SQLiteLogger) GetRetentionDays() int { l.mu.RLock() defer l.mu.RUnlock() return l.retentionDays } // SetRetentionDays updates the retention period. func (l *SQLiteLogger) SetRetentionDays(days int) { l.mu.Lock() defer l.mu.Unlock() l.retentionDays = days // Save to config _, _ = l.db.Exec(` INSERT INTO audit_config (key, value, updated_at) VALUES ('retention_days', ?, ?) ON CONFLICT(key) DO UPDATE SET value = excluded.value, updated_at = excluded.updated_at`, fmt.Sprintf("%d", days), time.Now().Unix()) }