Implementing more advanced feature: audit and more
This commit is contained in:
Martino Ferrari
@@ -0,0 +1,65 @@
|
||||
// Package audit records system-affecting actions (signal writes by users or the
|
||||
// control-logic engine, interface and control-logic mutations) to an append-only
|
||||
// SQLite log that audit staff can query later. It is enabled via [audit] in the
|
||||
// config; when disabled a no-op Recorder is used so call sites need no guards.
|
||||
package audit
|
||||
|
||||
import "time"
|
||||
|
||||
// Actor types distinguish human-initiated actions from automated ones.
|
||||
const (
|
||||
ActorUser = "user" // action attributed to an authenticated end-user
|
||||
ActorSystem = "system" // action performed by the control-logic engine
|
||||
)
|
||||
|
||||
// Outcomes record whether the action succeeded.
|
||||
const (
|
||||
OutcomeOK = "ok"
|
||||
OutcomeError = "error"
|
||||
)
|
||||
|
||||
// Event is a single audit record. Optional fields are omitted from the database
|
||||
// when empty. Time defaults to the current time when zero.
|
||||
type Event struct {
|
||||
Time time.Time `json:"time"`
|
||||
Actor string `json:"actor"` // username, or graph name for system actions
|
||||
ActorType string `json:"actorType"` // ActorUser | ActorSystem
|
||||
Action string `json:"action"` // e.g. "signal.write", "interface.update"
|
||||
DS string `json:"ds,omitempty"` // data source (signal writes)
|
||||
Signal string `json:"signal,omitempty"` // signal / target name
|
||||
Value string `json:"value,omitempty"` // serialised written value
|
||||
Detail string `json:"detail,omitempty"` // free-form context (id, graph, trigger)
|
||||
IP string `json:"ip,omitempty"` // client address (user actions)
|
||||
Outcome string `json:"outcome"` // OutcomeOK | OutcomeError
|
||||
Error string `json:"error,omitempty"` // message when Outcome==OutcomeError
|
||||
}
|
||||
|
||||
// Filter selects a subset of events for Query. Zero-valued fields are ignored.
|
||||
type Filter struct {
|
||||
Start time.Time
|
||||
End time.Time
|
||||
Actor string
|
||||
Action string
|
||||
DS string
|
||||
Signal string
|
||||
Limit int // <=0 means a default cap is applied
|
||||
}
|
||||
|
||||
// Recorder appends events and answers queries. Implementations must be safe for
|
||||
// concurrent use and Record must never block the caller for long.
|
||||
type Recorder interface {
|
||||
Record(Event)
|
||||
Query(Filter) ([]Event, error)
|
||||
Close() error
|
||||
}
|
||||
|
||||
// nopRecorder is used when auditing is disabled. It discards every event.
|
||||
type nopRecorder struct{}
|
||||
|
||||
func (nopRecorder) Record(Event) {}
|
||||
func (nopRecorder) Query(Filter) ([]Event, error) { return []Event{}, nil }
|
||||
func (nopRecorder) Close() error { return nil }
|
||||
|
||||
// Nop returns a Recorder that discards everything. Call sites can hold a Recorder
|
||||
// unconditionally and call Record without checking whether auditing is enabled.
|
||||
func Nop() Recorder { return nopRecorder{} }
|
||||
@@ -0,0 +1,183 @@
|
||||
package audit
|
||||
|
||||
import (
|
||||
"database/sql"
|
||||
"fmt"
|
||||
"log/slog"
|
||||
"strings"
|
||||
"sync"
|
||||
"time"
|
||||
|
||||
_ "modernc.org/sqlite" // pure-Go SQLite driver (no CGo, keeps the single static binary)
|
||||
)
|
||||
|
||||
// defaultQueryLimit caps how many rows Query returns when the filter does not
|
||||
// specify a smaller limit, protecting the API and UI from unbounded result sets.
|
||||
const defaultQueryLimit = 1000
|
||||
|
||||
// writeBuffer is the depth of the async insert queue. When full, Record falls
|
||||
// back to a synchronous insert so events are never silently dropped.
|
||||
const writeBuffer = 4096
|
||||
|
||||
// sqliteRecorder appends events to a SQLite database. Inserts are normally
|
||||
// handled by a background goroutine so Record does not block the calling write
|
||||
// path; the queue has a synchronous fallback to guarantee durability under load.
|
||||
type sqliteRecorder struct {
|
||||
db *sql.DB
|
||||
log *slog.Logger
|
||||
|
||||
ch chan Event
|
||||
wg sync.WaitGroup
|
||||
closed chan struct{}
|
||||
once sync.Once
|
||||
}
|
||||
|
||||
// NewSQLite opens (creating if needed) the audit database at path and starts the
|
||||
// background writer. The returned Recorder must be Closed on shutdown.
|
||||
func NewSQLite(path string, log *slog.Logger) (Recorder, error) {
|
||||
// WAL + a busy timeout let the async writer and synchronous query/fallback
|
||||
// paths share the file without "database is locked" errors.
|
||||
dsn := fmt.Sprintf("file:%s?_pragma=busy_timeout(5000)&_pragma=journal_mode(WAL)&_pragma=synchronous(NORMAL)", path)
|
||||
db, err := sql.Open("sqlite", dsn)
|
||||
if err != nil {
|
||||
return nil, fmt.Errorf("open audit db: %w", err)
|
||||
}
|
||||
if _, err := db.Exec(schema); err != nil {
|
||||
_ = db.Close()
|
||||
return nil, fmt.Errorf("init audit schema: %w", err)
|
||||
}
|
||||
r := &sqliteRecorder{
|
||||
db: db,
|
||||
log: log,
|
||||
ch: make(chan Event, writeBuffer),
|
||||
closed: make(chan struct{}),
|
||||
}
|
||||
r.wg.Add(1)
|
||||
go r.writeLoop()
|
||||
return r, nil
|
||||
}
|
||||
|
||||
const schema = `
|
||||
CREATE TABLE IF NOT EXISTS audit_log (
|
||||
id INTEGER PRIMARY KEY AUTOINCREMENT,
|
||||
ts_ns INTEGER NOT NULL,
|
||||
actor TEXT NOT NULL,
|
||||
actor_type TEXT NOT NULL,
|
||||
action TEXT NOT NULL,
|
||||
ds TEXT NOT NULL DEFAULT '',
|
||||
signal TEXT NOT NULL DEFAULT '',
|
||||
value TEXT NOT NULL DEFAULT '',
|
||||
detail TEXT NOT NULL DEFAULT '',
|
||||
ip TEXT NOT NULL DEFAULT '',
|
||||
outcome TEXT NOT NULL DEFAULT 'ok',
|
||||
error TEXT NOT NULL DEFAULT ''
|
||||
);
|
||||
CREATE INDEX IF NOT EXISTS idx_audit_ts ON audit_log(ts_ns);
|
||||
CREATE INDEX IF NOT EXISTS idx_audit_actor ON audit_log(actor);
|
||||
CREATE INDEX IF NOT EXISTS idx_audit_action ON audit_log(action);
|
||||
`
|
||||
|
||||
func (r *sqliteRecorder) Record(e Event) {
|
||||
if e.Time.IsZero() {
|
||||
e.Time = time.Now()
|
||||
}
|
||||
if e.Outcome == "" {
|
||||
e.Outcome = OutcomeOK
|
||||
}
|
||||
select {
|
||||
case <-r.closed:
|
||||
// Recorder is shutting down; best-effort synchronous insert.
|
||||
r.insert(e)
|
||||
case r.ch <- e:
|
||||
default:
|
||||
// Queue full: write synchronously rather than drop an audit record.
|
||||
r.insert(e)
|
||||
}
|
||||
}
|
||||
|
||||
func (r *sqliteRecorder) writeLoop() {
|
||||
defer r.wg.Done()
|
||||
for e := range r.ch {
|
||||
r.insert(e)
|
||||
}
|
||||
}
|
||||
|
||||
func (r *sqliteRecorder) insert(e Event) {
|
||||
_, err := r.db.Exec(
|
||||
`INSERT INTO audit_log (ts_ns, actor, actor_type, action, ds, signal, value, detail, ip, outcome, error)
|
||||
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)`,
|
||||
e.Time.UnixNano(), e.Actor, e.ActorType, e.Action,
|
||||
e.DS, e.Signal, e.Value, e.Detail, e.IP, e.Outcome, e.Error,
|
||||
)
|
||||
if err != nil {
|
||||
r.log.Error("audit: insert failed", "action", e.Action, "err", err)
|
||||
}
|
||||
}
|
||||
|
||||
func (r *sqliteRecorder) Query(f Filter) ([]Event, error) {
|
||||
var where []string
|
||||
var args []any
|
||||
if !f.Start.IsZero() {
|
||||
where = append(where, "ts_ns >= ?")
|
||||
args = append(args, f.Start.UnixNano())
|
||||
}
|
||||
if !f.End.IsZero() {
|
||||
where = append(where, "ts_ns <= ?")
|
||||
args = append(args, f.End.UnixNano())
|
||||
}
|
||||
if f.Actor != "" {
|
||||
where = append(where, "actor = ?")
|
||||
args = append(args, f.Actor)
|
||||
}
|
||||
if f.Action != "" {
|
||||
where = append(where, "action = ?")
|
||||
args = append(args, f.Action)
|
||||
}
|
||||
if f.DS != "" {
|
||||
where = append(where, "ds = ?")
|
||||
args = append(args, f.DS)
|
||||
}
|
||||
if f.Signal != "" {
|
||||
where = append(where, "signal LIKE ?")
|
||||
args = append(args, "%"+f.Signal+"%")
|
||||
}
|
||||
limit := f.Limit
|
||||
if limit <= 0 || limit > defaultQueryLimit {
|
||||
limit = defaultQueryLimit
|
||||
}
|
||||
|
||||
q := "SELECT ts_ns, actor, actor_type, action, ds, signal, value, detail, ip, outcome, error FROM audit_log"
|
||||
if len(where) > 0 {
|
||||
q += " WHERE " + strings.Join(where, " AND ")
|
||||
}
|
||||
q += " ORDER BY ts_ns DESC LIMIT ?"
|
||||
args = append(args, limit)
|
||||
|
||||
rows, err := r.db.Query(q, args...)
|
||||
if err != nil {
|
||||
return nil, fmt.Errorf("query audit log: %w", err)
|
||||
}
|
||||
defer rows.Close()
|
||||
|
||||
out := []Event{}
|
||||
for rows.Next() {
|
||||
var e Event
|
||||
var tsNs int64
|
||||
if err := rows.Scan(&tsNs, &e.Actor, &e.ActorType, &e.Action,
|
||||
&e.DS, &e.Signal, &e.Value, &e.Detail, &e.IP, &e.Outcome, &e.Error); err != nil {
|
||||
return nil, fmt.Errorf("scan audit row: %w", err)
|
||||
}
|
||||
e.Time = time.Unix(0, tsNs)
|
||||
out = append(out, e)
|
||||
}
|
||||
return out, rows.Err()
|
||||
}
|
||||
|
||||
func (r *sqliteRecorder) Close() error {
|
||||
r.once.Do(func() {
|
||||
close(r.closed)
|
||||
close(r.ch)
|
||||
})
|
||||
r.wg.Wait()
|
||||
return r.db.Close()
|
||||
}
|
||||
@@ -0,0 +1,68 @@
|
||||
package audit
|
||||
|
||||
import (
|
||||
"log/slog"
|
||||
"path/filepath"
|
||||
"testing"
|
||||
"time"
|
||||
)
|
||||
|
||||
func TestSQLiteRoundTrip(t *testing.T) {
|
||||
path := filepath.Join(t.TempDir(), "audit.db")
|
||||
rec, err := NewSQLite(path, slog.Default())
|
||||
if err != nil {
|
||||
t.Fatal("NewSQLite:", err)
|
||||
}
|
||||
defer rec.Close()
|
||||
|
||||
base := time.Now()
|
||||
rec.Record(Event{Time: base, Actor: "alice", ActorType: ActorUser, Action: "signal.write", DS: "epics", Signal: "PV:A", Value: "1.5"})
|
||||
rec.Record(Event{Time: base.Add(time.Second), Actor: "flow1", ActorType: ActorSystem, Action: "signal.write", DS: "epics", Signal: "PV:B", Value: "0"})
|
||||
rec.Record(Event{Time: base.Add(2 * time.Second), Actor: "bob", ActorType: ActorUser, Action: "interface.update", Detail: "panel-1", Outcome: OutcomeError, Error: "denied"})
|
||||
|
||||
// Flush the async writer.
|
||||
if err := rec.Close(); err != nil {
|
||||
t.Fatal("Close:", err)
|
||||
}
|
||||
rec, err = NewSQLite(path, slog.Default())
|
||||
if err != nil {
|
||||
t.Fatal("reopen:", err)
|
||||
}
|
||||
defer rec.Close()
|
||||
|
||||
all, err := rec.Query(Filter{})
|
||||
if err != nil {
|
||||
t.Fatal("Query:", err)
|
||||
}
|
||||
if len(all) != 3 {
|
||||
t.Fatalf("got %d events, want 3", len(all))
|
||||
}
|
||||
// Newest first.
|
||||
if all[0].Actor != "bob" {
|
||||
t.Errorf("first actor = %q, want bob", all[0].Actor)
|
||||
}
|
||||
|
||||
byActor, err := rec.Query(Filter{Actor: "alice"})
|
||||
if err != nil {
|
||||
t.Fatal("Query actor:", err)
|
||||
}
|
||||
if len(byActor) != 1 || byActor[0].Signal != "PV:A" {
|
||||
t.Errorf("actor filter = %+v, want one PV:A event", byActor)
|
||||
}
|
||||
|
||||
byAction, err := rec.Query(Filter{Action: "signal.write"})
|
||||
if err != nil {
|
||||
t.Fatal("Query action:", err)
|
||||
}
|
||||
if len(byAction) != 2 {
|
||||
t.Errorf("action filter returned %d, want 2", len(byAction))
|
||||
}
|
||||
|
||||
since, err := rec.Query(Filter{Start: base.Add(1500 * time.Millisecond)})
|
||||
if err != nil {
|
||||
t.Fatal("Query start:", err)
|
||||
}
|
||||
if len(since) != 1 || since[0].Actor != "bob" {
|
||||
t.Errorf("time filter = %+v, want one bob event", since)
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user