themis/audit_log.go

package themis

import (
	"context"
	"database/sql"
	"fmt"
	"time"

	"github.com/rs/zerolog/log"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/codes"
	semconv "go.opentelemetry.io/otel/semconv/v1.24.0"
	"go.opentelemetry.io/otel/trace"
)

type EventType int

const (
	EventFlush EventType = iota
	EventClaim
	EventUnclaim
	EventAbsence
)

func (et EventType) String() string {
	switch et {
	case EventFlush:
		return "FLUSH"
	case EventClaim:
		return "CLAIM"
	case EventUnclaim:
		return "UNCLAIM"
	case EventAbsence:
		return "ABSENT"
	default:
		return ""
	}
}

func EventTypeFromString(ev string) (EventType, error) {
	switch ev {
	case "FLUSH":
		return EventFlush, nil
	case "CLAIM":
		return EventClaim, nil
	case "UNCLAIM":
		return EventUnclaim, nil
	case "ABSENT":
		return EventAbsence, nil
	default:
		return EventType(9999), fmt.Errorf("no such event type: %s", ev)
	}
}

type AuditableEvent struct {
	userId    string
	eventType EventType
	timestamp time.Time
	err       error
}

// Audit writes to the audit table, returns nothing because it is meant to be
// used in a defered statement on functions that write to the database.
func (s *Store) Audit(ctx context.Context, ev *AuditableEvent) {
	ctx, span := tracer.Start(ctx, "audit", trace.WithAttributes(
		semconv.DBSystemSqlite,
		semconv.DBSQLTable("audit_log"),
		semconv.DBOperation("insert"),
		attribute.String("user_id", ev.userId),
		attribute.Stringer("event_type", ev.eventType),
	))
	defer span.End()

	if ev.err == nil {
		log.Debug().Ctx(ctx).Str("event_type", ev.eventType.String()).Str("userid", ev.userId).Msg("recording audit log")
		ctx := context.Background()

		tx, err := s.db.Begin()
		if err != nil {
			span.RecordError(err)
			span.SetStatus(codes.Error, "failed to start transaction")
			log.Error().Ctx(ctx).Err(err).Msg("failed to start transaction")
		}
		defer tx.Commit() //nolint:errcheck

		stmt, err := s.db.PrepareContext(ctx, "INSERT INTO audit_log (userid, event_type, ts) VALUES (?, ?, ?)")
		if err != nil {
			span.RecordError(err)
			span.SetStatus(codes.Error, "failed to prepare audit log insert")
			log.Error().Ctx(ctx).Err(err).Msg("failed to prepare audit log insert")
		}

		if _, err := stmt.ExecContext(ctx, ev.userId, ev.eventType.String(), time.Now()); err != nil {
			span.RecordError(err)
			span.SetStatus(codes.Error, "failed to insert audit log")
			log.Error().Ctx(ctx).Err(err).Msg("failed to insert audit log")
		}
	}
}

type AuditEvent struct {
	Id        int
	UserId    string
	EventType EventType
	Timestamp time.Time
}

func (s *Store) LastOf(ctx context.Context, t EventType) (AuditEvent, error) {
	ctx, span := tracer.Start(ctx, "find_last_audit_log", trace.WithAttributes(
		semconv.DBSystemSqlite,
		semconv.DBSQLTable("audit_log"),
		semconv.DBOperation("select"),
		attribute.Stringer("event_type", t),
	))
	defer span.End()

	log.Debug().Ctx(ctx).Str("event_type", t.String()).Msg("finding last audit log")

	stmt, err := s.db.PrepareContext(ctx, `SELECT id, userid, event_type, ts FROM audit_log WHERE event_type = ? ORDER BY ts DESC LIMIT 1`)
	if err != nil {
		span.RecordError(err)
		span.SetStatus(codes.Error, "failed to get last event")
		return AuditEvent{}, fmt.Errorf("failed to get last event of type %s: %w", t.String(), err)
	}

	row := stmt.QueryRowContext(ctx, t.String())

	ev := AuditEvent{}
	var rawEventType string
	err = row.Scan(&ev.Id, &ev.UserId, &rawEventType, &ev.Timestamp)
	if err == sql.ErrNoRows {
		span.RecordError(ErrNever)
		return AuditEvent{}, ErrNever
	}
	if err != nil {
		span.RecordError(err)
		span.SetStatus(codes.Error, "failed to scan row")
		return AuditEvent{}, fmt.Errorf("failed to scan row: %w", err)
	}

	ev.EventType, err = EventTypeFromString(rawEventType)
	if err != nil {
		span.RecordError(err)
		span.SetStatus(codes.Error, "failed to parse event type")
		return AuditEvent{}, fmt.Errorf("failed to parse event type: %w", err)
	}

	return ev, nil
}