* feat(observability): OpenTelemetry logs+traces with secret redaction Part of #265. Adds opt-in OpenTelemetry (logs + traces) alongside the existing stderr + opslog pipeline, plus secret redaction on all sinks. Default-off: with no OTEL_* / SILO_OTEL_ENABLED config, behavior is unchanged. Bootstrap (internal/telemetry): - Setup() builds one shared resource, a TracerProvider (parent-based trace-id ratio sampler), a LoggerProvider, and the W3C TraceContext+Baggage propagator from env. It installs NO MeterProvider — metrics stay on Prometheus, and the built-in no-op global MeterProvider keeps the trace instrumentation libs from double-emitting. Shutdown is deferred with a flush timeout. - Logs are bridged via otelslog fan-out (slog.MultiHandler), level-gated by the shared LevelVar and best-effort so a failing collector can't break the console or DB branches. stderr + opslog stay untouched. Secret redaction (internal/logredact): - A slog.Handler masks secret-keyed attributes (password, token, api_key, authorization, cookie, ...) — including .With-bound attrs, nested groups, secret-keyed group subtrees, and values behind a LogValuer — on the console and OTLP sinks, with a no-op fast path when a record has no secret keys. opslog.shouldRedact delegates to logredact.SecretKey so all sinks share one marker list. Rotation is infra-managed (no custom file sink): container runtime for stderr, collector/backend for OTLP, opslog partition-pruning for the DB. Documented in docs/architecture/observability.md. Verification: go build ./..., go vet, gofmt -l — clean; go test ./internal/telemetry/ ./internal/logredact/ -race pass. AI-use disclosure: implemented with AI assistance (Claude Code), including adversarial reviews that hardened the bootstrap and fixed two redaction leak paths; reviewed by the author. * refactor(observability): slog context+component sweep, sloglint gate (phase 3) Part of #265. Builds on the OTel bootstrap + redaction commit. Standardizes every log call site onto the context-carrying slog variants so records correlate with the active OpenTelemetry trace, and locks the standard in with a machine gate so future code (human- or AI-authored) can't drift back. - Call-site sweep: converted the remaining slog.<Level>(...) calls to the slog.<Level>Context(ctx, ...) form wherever a context.Context is in scope (background/init calls with no ctx are left as-is), across 183 files. Applied via a type-aware AST codemod. Log levels and message strings are preserved verbatim; a component attr (canonical per-package name) is added to direct package-level slog calls. Bound-logger calls keep their existing .With bindings. The main.go and telemetry package conversions rode with their file in the previous commit to keep each file within a single commit. - Enforcement (.golangci.yml): enable sloglint with context=scope, static-msg, key-naming-case=snake, no-mixed-args. After the sweep all four report zero violations repo-wide (tests included), so make lint / CI now blocks any regression to the non-context form. The gate ships with the sweep because it cannot be green until the legacy sites are converted. Metrics remain on Prometheus; no behavior change to /metrics or Grafana. Verification: go build ./..., go vet ./..., gofmt -l — clean; sloglint (all 4 rules) 0 violations repo-wide; log levels verified unchanged. AI-use disclosure: implemented with AI assistance (Claude Code), including the codemod; reviewed by the author. * fix(observability): honor per-signal OTLP protocol and secret WithGroup names Two Codex review findings on PR #290: - telemetry: OTEL_EXPORTER_OTLP_{TRACES,LOGS}_PROTOCOL now override the generic OTEL_EXPORTER_OTLP_PROTOCOL per signal, so mixed collector setups (e.g. HTTP logs + gRPC traces) build the right exporter. - logredact: entering a group whose name is secret-bearing (e.g. WithGroup("authorization")) now masks every leaf in that subtree, matching how slog.Group("authorization", ...) is masked as a whole. * fix(observability): address review feedback on telemetry bootstrap - Telemetry setup failure no longer kills boot: Setup returns usable no-op providers alongside the error and main logs and continues with telemetry disabled, honoring the best-effort contract. - Honor OTEL_TRACES_SAMPLER (always_on/off, traceidratio, parentbased_* variants); unsupported values fall back to parentbased_traceidratio. - Attach node identity as semconv service.instance.id instead of the non-semconv node.name. - Rename opslog retention-scope log attrs to target_component/target_level so they no longer collide with the canonical component routing key, and tag those lines with component=opslog. - Fix stale levelGated comment casing; use WarnContext in the telemetry shutdown defer; document the LogValuer double-resolve on the redaction slow path. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> --------- Co-authored-by: Quick <31828688+Quick104@users.noreply.github.com> Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
205 lines
5.8 KiB
Go
205 lines
5.8 KiB
Go
package policy
|
|
|
|
import (
|
|
"context"
|
|
"log/slog"
|
|
"sync"
|
|
"testing"
|
|
"time"
|
|
|
|
"github.com/jackc/pgx/v5/pgxpool"
|
|
|
|
"github.com/Silo-Server/silo-server/internal/cache"
|
|
)
|
|
|
|
func TestSystemCrossNodeConvergenceEventAndPoll(t *testing.T) {
|
|
ctx := context.Background()
|
|
pool, storeA := newPolicyStoreTest(t, ctx)
|
|
storeB := NewPolicyStore(pool)
|
|
|
|
eventBus := newPolicyTestEventBus()
|
|
systemA := newStartedPolicySystem(t, ctx, storeA, eventBus, time.Hour)
|
|
systemB := newStartedPolicySystem(t, ctx, storeB, eventBus, time.Hour)
|
|
|
|
documentID, generation := activatePolicyVersion(t, ctx, storeA, 0, "sha-event")
|
|
if err := systemA.NotifyChanged(ctx); err != nil {
|
|
t.Fatalf("NotifyChanged(event) error: %v", err)
|
|
}
|
|
waitForPolicyRevision(t, systemB, generation)
|
|
|
|
systemA.Stop()
|
|
systemB.Stop()
|
|
|
|
droppingBus := newPolicyTestEventBus()
|
|
droppingBus.SetDrop(true)
|
|
pollSystemA := newStartedPolicySystem(t, ctx, storeA, droppingBus, 20*time.Millisecond)
|
|
pollSystemB := newStartedPolicySystem(t, ctx, storeB, droppingBus, 20*time.Millisecond)
|
|
defer pollSystemA.Stop()
|
|
defer pollSystemB.Stop()
|
|
|
|
_, generation = activatePolicyVersion(t, ctx, storeA, documentID, "sha-poll")
|
|
if err := pollSystemA.NotifyChanged(ctx); err != nil {
|
|
t.Fatalf("NotifyChanged(poll) error: %v", err)
|
|
}
|
|
waitForPolicyRevision(t, pollSystemB, generation)
|
|
}
|
|
|
|
func TestSystemDegradedBootUsesVendorPolicy(t *testing.T) {
|
|
ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
|
|
defer cancel()
|
|
|
|
pool, err := pgxpool.New(ctx, "postgres://silo:silo@127.0.0.1:1/silo?connect_timeout=1")
|
|
if err != nil {
|
|
t.Fatalf("create unreachable pool: %v", err)
|
|
}
|
|
defer pool.Close()
|
|
|
|
system := NewSystem(NewPolicyStore(pool), nil, policyTestLogger(), WithSystemPollInterval(time.Hour))
|
|
if err := system.Start(ctx); err != nil {
|
|
t.Fatalf("Start() error: %v", err)
|
|
}
|
|
defer system.Stop()
|
|
|
|
assertVendorScopeDecision(t, system)
|
|
|
|
degraded := system.DegradedState()
|
|
if !degraded.Degraded || degraded.Reason != DegradedReasonStoreUnavailable {
|
|
t.Fatalf("DegradedState() = %#v, want degraded with reason %q", degraded, DegradedReasonStoreUnavailable)
|
|
}
|
|
}
|
|
|
|
func TestSystemReloadFailureKeepsLastKnownGood(t *testing.T) {
|
|
ctx := context.Background()
|
|
pool, store := newPolicyStoreTest(t, ctx)
|
|
|
|
system := newStartedPolicySystem(t, ctx, store, &cache.NoopEventBus{}, time.Hour)
|
|
defer system.Stop()
|
|
|
|
_, generation := activatePolicyVersion(t, ctx, store, 0, "sha-good")
|
|
if err := system.NotifyChanged(ctx); err != nil {
|
|
t.Fatalf("NotifyChanged(good) error: %v", err)
|
|
}
|
|
waitForPolicyRevision(t, system, generation)
|
|
|
|
pool.Close()
|
|
if err := system.NotifyChanged(ctx); err == nil {
|
|
t.Fatal("NotifyChanged() error = nil, want closed pool error")
|
|
}
|
|
if got := system.engine.Revision(); got != generation {
|
|
t.Fatalf("revision after failed reload = %d, want %d", got, generation)
|
|
}
|
|
assertVendorScopeDecision(t, system)
|
|
}
|
|
|
|
type policyTestEventBus struct {
|
|
mu sync.Mutex
|
|
drop bool
|
|
handlers map[string][]cache.EventHandler
|
|
}
|
|
|
|
func newPolicyTestEventBus() *policyTestEventBus {
|
|
return &policyTestEventBus{handlers: make(map[string][]cache.EventHandler)}
|
|
}
|
|
|
|
func (b *policyTestEventBus) Publish(_ context.Context, channel string, event cache.Event) error {
|
|
b.mu.Lock()
|
|
drop := b.drop
|
|
handlers := append([]cache.EventHandler(nil), b.handlers[channel]...)
|
|
b.mu.Unlock()
|
|
if drop {
|
|
return nil
|
|
}
|
|
for _, handler := range handlers {
|
|
handler(event)
|
|
}
|
|
return nil
|
|
}
|
|
|
|
func (b *policyTestEventBus) Subscribe(_ context.Context, channel string, handler cache.EventHandler) error {
|
|
b.mu.Lock()
|
|
b.handlers[channel] = append(b.handlers[channel], handler)
|
|
b.mu.Unlock()
|
|
return nil
|
|
}
|
|
|
|
func (b *policyTestEventBus) Close() error { return nil }
|
|
|
|
func (b *policyTestEventBus) SetDrop(drop bool) {
|
|
b.mu.Lock()
|
|
b.drop = drop
|
|
b.mu.Unlock()
|
|
}
|
|
|
|
func newStartedPolicySystem(t *testing.T, ctx context.Context, store *PolicyStore, bus cache.EventBus, pollInterval time.Duration) *System {
|
|
t.Helper()
|
|
system := NewSystem(store, bus, policyTestLogger(), WithSystemPollInterval(pollInterval))
|
|
if err := system.Start(ctx); err != nil {
|
|
t.Fatalf("Start() error: %v", err)
|
|
}
|
|
return system
|
|
}
|
|
|
|
func policyTestLogger() *slog.Logger {
|
|
return slog.New(slog.DiscardHandler)
|
|
}
|
|
|
|
func activatePolicyVersion(t *testing.T, ctx context.Context, store *PolicyStore, documentID int64, sha string) (int64, int64) {
|
|
t.Helper()
|
|
if documentID == 0 {
|
|
document, err := store.CreateDocument(ctx, DomainScope, "household scope")
|
|
if err != nil {
|
|
t.Fatalf("CreateDocument() error: %v", err)
|
|
}
|
|
documentID = document.ID
|
|
}
|
|
version, err := store.CreateVersion(ctx, documentID, validStorePolicySource(), sha, true, nil, nil, "")
|
|
if err != nil {
|
|
t.Fatalf("CreateVersion() error: %v", err)
|
|
}
|
|
generation, err := store.Activate(ctx, documentID, version.ID)
|
|
if err != nil {
|
|
t.Fatalf("Activate() error: %v", err)
|
|
}
|
|
return documentID, generation
|
|
}
|
|
|
|
func waitForPolicyRevision(t *testing.T, system *System, generation int64) {
|
|
t.Helper()
|
|
deadline := time.After(3 * time.Second)
|
|
ticker := time.NewTicker(10 * time.Millisecond)
|
|
defer ticker.Stop()
|
|
for {
|
|
select {
|
|
case <-deadline:
|
|
t.Fatalf("policy revision = %d, want %d", system.engine.Revision(), generation)
|
|
case <-ticker.C:
|
|
if system.engine.Revision() == generation {
|
|
return
|
|
}
|
|
}
|
|
}
|
|
}
|
|
|
|
func assertVendorScopeDecision(t *testing.T, system *System) {
|
|
t.Helper()
|
|
pdp := system.PDP()
|
|
if pdp == nil {
|
|
t.Fatal("PDP() = nil")
|
|
}
|
|
decision, _, err := pdp.ResolveViewerScope(context.Background(), ScopeInput{
|
|
SchemaVersion: 1,
|
|
UserID: 42,
|
|
SessionID: "sess-1",
|
|
AccountRestricted: false,
|
|
AccessPolicyRevision: 9,
|
|
ProfileVerified: true,
|
|
RequestTime: "2026-07-02T12:00:00Z",
|
|
})
|
|
if err != nil {
|
|
t.Fatalf("ResolveViewerScope() error: %v", err)
|
|
}
|
|
if !decision.Unrestricted {
|
|
t.Fatalf("Unrestricted = false, want vendor-only unrestricted decision: %#v", decision)
|
|
}
|
|
}
|