Files
pulse/pkg/audit/sqlite_logger.go
T
rcourtman c3fcddf94c sqlite: bound every store's page cache to SQLite's default
Five stores set private page caches of 16 to 64 MB per connection.
The modernc driver allocates that cache with anonymous mmap outside
the Go heap, so GC and GOMEMLIMIT never see it, and each page costs
about twice its size. Measured: reading a 107 MB database through a
64 MB cache_size added 117 MB of resident memory, against 6 MB at
SQLite's 2 MB default. On a long-running dogfood install about 165 MB
of 360 MB resident sat outside the Go heap, with a 126 MB audit
database behind a 64 MB cache (#1803).

Audit, RBAC, notification queue, unified resources and the alert
event log (writer and both readers) now take pdb.PageCachePragma.
Pages that miss it come from the kernel file cache, which the kernel
can reclaim. The audit suite, including its large legacy migration,
takes the same time as before (309 s on both trees).

pkg/db tests reject any other cache_size in production code and bound
the resident growth of a 30 MB scan. Each store's test pins its
effective value. Negative controls: restoring the audit cache fails
the source scan, and a 64 MB reader cache grows a scan by 55 MB
against a 16 MB budget. modernc sorts _pragma values before applying
them, so a second cache_size in one DSN cannot reliably override.

Related to #1803
2026-10-21 14:16:08 +01:00

1157 lines
29 KiB
Go

package audit
import (
"database/sql"
"errors"
"fmt"
"net/url"
"os"
"path/filepath"
"strconv"
"strings"
"sync"
"time"
pdb "github.com/rcourtman/pulse-go-rewrite/pkg/db"
"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 <DataDir>/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)",
pdb.PageCachePragma,
},
}.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,
&notNull,
&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, &timestampValue, &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())
}