Files
felhom.eu/hub/internal/store/telemetry_test.go
T
admin c084046af0 hub v0.43.0: remote app-log diagnostics — copyable issues + context + on-demand log tails + range/dismissal fixes
- store: app_log_issues gains context/context_customer (first capture wins) + dismissed_at (resurface only on last_seen > dismissed_at); log_tail_requests (pending operator intents, consume-once) + app_log_tails (transient, keep last 2 per app)
- api: /report ingests log_tails (stores + clears the request); ACK advertises log_tail_requests (same additive omit-when-empty pattern as escrow)
- web: Known Issues rows click-to-expand (full copyable message + context with provenance + explicit affected-customers list); Dismiss replaces Delete; period selector now filters issues (F); ?customer= filtered view + customer-page drill-down links (H); per-app Request-log-tail button + pending badge + App Log Tails section + ordered tail view with line numbers + .log download; customer-visible log_tail_requested event
- tests: store (context first-capture/late-adopt, range filter, dismissal old-window vs new-occurrence, tail request/fulfill/prune/scoping), api ACK round-trip, web render (expanded row, customer page sections, tail view + download + cross-customer 404)

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01PSK5g6qYLknKj8u3QAFEr6
2026-07-10 16:03:32 +02:00

261 lines
9.9 KiB
Go

package store
import (
"encoding/json"
"io"
"log"
"path/filepath"
"testing"
"time"
)
func newTelemetryTestStore(t *testing.T) *Store {
t.Helper()
s, err := New(filepath.Join(t.TempDir(), "telemetry.db"), log.New(io.Discard, "", 0))
if err != nil {
t.Fatalf("store.New: %v", err)
}
t.Cleanup(func() { s.Close() })
return s
}
// mkTelemetryRecord builds an AppTelemetryRecord through JSON — the same path a real
// controller report takes (also proves nil-safety when context is absent entirely).
func mkTelemetryRecord(t *testing.T, appName, severity, message string, lastSeen time.Time, context []string) AppTelemetryRecord {
t.Helper()
issue := map[string]interface{}{
"severity": severity,
"message": message,
"count": 1,
"last_seen": lastSeen.UTC().Format(time.RFC3339),
}
if context != nil {
issue["context"] = context
}
b, _ := json.Marshal(map[string]interface{}{
"app_name": appName,
"issues": []interface{}{issue},
})
var rec AppTelemetryRecord
if err := json.Unmarshal(b, &rec); err != nil {
t.Fatalf("unmarshal record: %v", err)
}
return rec
}
func saveIssue(t *testing.T, s *Store, customer, app, severity, msg string, lastSeen time.Time, context []string) {
t.Helper()
rec := mkTelemetryRecord(t, app, severity, msg, lastSeen, context)
if err := s.SaveAppTelemetry(customer, time.Now(), []AppTelemetryRecord{rec}); err != nil {
t.Fatalf("SaveAppTelemetry: %v", err)
}
}
func getOneIssue(t *testing.T, s *Store, app string, since time.Time, includeDismissed bool) *AppIssue {
t.Helper()
issues, err := s.GetAppIssues(app, since, includeDismissed, 20)
if err != nil {
t.Fatalf("GetAppIssues: %v", err)
}
if len(issues) == 0 {
return nil
}
return &issues[0]
}
var longAgo = time.Now().Add(-365 * 24 * time.Hour)
// Part C — context stored on INSERT with provenance; a later empty-context upsert does
// not clobber; a later DIFFERENT context does not churn it (first capture wins).
func TestUpsertIssue_ContextFirstCaptureWins(t *testing.T) {
s := newTelemetryTestStore(t)
msg := "ERROR: nfs mount /mnt/media lost"
now := time.Now()
saveIssue(t, s, "cust-a", "cwa", "error", msg, now, []string{"before line", "ERROR: nfs mount /mnt/media lost", "after line"})
is := getOneIssue(t, s, "cwa", longAgo, false)
if is == nil {
t.Fatalf("issue not stored")
}
if len(is.Context) != 3 || is.Context[0] != "before line" {
t.Fatalf("context not stored on insert: %#v", is.Context)
}
if is.ContextCustomer != "cust-a" {
t.Fatalf("provenance = %q, want cust-a", is.ContextCustomer)
}
// A pre-v0.111 controller (no context field) re-reports the same issue: must not clobber.
saveIssue(t, s, "cust-b", "cwa", "error", msg, now.Add(time.Minute), nil)
is = getOneIssue(t, s, "cwa", longAgo, false)
if len(is.Context) != 3 {
t.Fatalf("empty-context upsert clobbered the stored context: %#v", is.Context)
}
if is.ContextCustomer != "cust-a" {
t.Fatalf("provenance churned to %q", is.ContextCustomer)
}
// both customers recorded
if len(is.AffectedCustomers) != 2 {
t.Fatalf("affected customers = %v, want both", is.AffectedCustomers)
}
// A different context from another box: first capture still wins (no churn).
saveIssue(t, s, "cust-b", "cwa", "error", msg, now.Add(2*time.Minute), []string{"other box context"})
is = getOneIssue(t, s, "cwa", longAgo, false)
if is.Context[0] != "before line" || is.ContextCustomer != "cust-a" {
t.Fatalf("first-capture-wins violated: ctx=%#v from %q", is.Context, is.ContextCustomer)
}
}
// Part C — an issue first seen WITHOUT context (old controller) adopts the first
// context that arrives later.
func TestUpsertIssue_LateContextAdopted(t *testing.T) {
s := newTelemetryTestStore(t)
msg := "ERROR: db locked"
saveIssue(t, s, "cust-a", "gokapi", "error", msg, time.Now(), nil)
is := getOneIssue(t, s, "gokapi", longAgo, false)
if len(is.Context) != 0 {
t.Fatalf("expected no context yet, got %#v", is.Context)
}
saveIssue(t, s, "cust-b", "gokapi", "error", msg, time.Now().Add(time.Minute), []string{"ctx line"})
is = getOneIssue(t, s, "gokapi", longAgo, false)
if len(is.Context) != 1 || is.Context[0] != "ctx line" || is.ContextCustomer != "cust-b" {
t.Fatalf("late context not adopted: %#v from %q", is.Context, is.ContextCustomer)
}
}
// Part F — the time-range filter: a 10-day-old issue is absent from the 24h view,
// present in the 30d view. Red-proof target: drop the last_seen >= since predicate →
// the 24h view shows the old row → this fails.
func TestGetAppIssues_RangeFilter(t *testing.T) {
s := newTelemetryTestStore(t)
tenDaysAgo := time.Now().Add(-10 * 24 * time.Hour)
saveIssue(t, s, "cust-a", "vault", "error", "ERROR: smtp down", tenDaysAgo, nil)
if got := getOneIssue(t, s, "vault", time.Now().Add(-24*time.Hour), false); got != nil {
t.Fatalf("10d-old issue visible in the 24h view (last_seen=%s)", got.LastSeen)
}
if got := getOneIssue(t, s, "vault", time.Now().Add(-30*24*time.Hour), false); got == nil {
t.Fatalf("10d-old issue missing from the 30d view")
}
}
// Part G — dismissal semantics: a re-sent OLD window (last_seen <= dismissed_at) stays
// hidden; a genuinely NEW occurrence (last_seen > dismissed_at) resurfaces the row.
// Red-proof: drop the `excluded.last_seen > dismissed_at` guard in upsertAppIssue (make
// the conflict always clear dismissed_at) → the old-window re-report resurrects → FAIL.
func TestDismiss_OldWindowHidden_NewOccurrenceResurfaces(t *testing.T) {
s := newTelemetryTestStore(t)
msg := "ERROR: cwa nfs stale handle"
oldSeen := time.Now().Add(-time.Hour)
saveIssue(t, s, "cust-a", "cwa", "error", msg, oldSeen, nil)
if n, err := s.DismissAppIssues("cwa"); err != nil || n != 1 {
t.Fatalf("DismissAppIssues = %d/%v, want 1", n, err)
}
if got := getOneIssue(t, s, "cwa", longAgo, false); got != nil {
t.Fatalf("dismissed issue still in the default view")
}
// visible with the toggle, flagged
if got := getOneIssue(t, s, "cwa", longAgo, true); got == nil || got.DismissedAt == nil {
t.Fatalf("show-dismissed view must expose the row with DismissedAt set")
}
// Old-window re-report (controller re-sends its rolling window with the SAME last_seen).
saveIssue(t, s, "cust-a", "cwa", "error", msg, oldSeen, nil)
if got := getOneIssue(t, s, "cwa", longAgo, false); got != nil {
t.Fatalf("old-window re-report RESURRECTED the dismissed issue (last_seen=%s)", got.LastSeen)
}
// A genuinely NEW occurrence — recurrence must never be silently swallowed.
newSeen := time.Now().Add(time.Minute)
saveIssue(t, s, "cust-a", "cwa", "error", msg, newSeen, nil)
got := getOneIssue(t, s, "cwa", longAgo, false)
if got == nil {
t.Fatalf("NEW occurrence did not resurface the dismissed issue")
}
if got.DismissedAt != nil {
t.Fatalf("resurfaced issue still flagged dismissed")
}
}
// Part D (store half) — request → pending; tail arrival stores, prunes to 2, and clears
// the request (consume-once). Red-proof: remove the request-DELETE in SaveAppLogTail →
// the pending request survives fulfillment → this fails.
func TestLogTail_RequestFulfillConsumeOnce(t *testing.T) {
s := newTelemetryTestStore(t)
if err := s.RequestLogTail("cust-a", "gokapi"); err != nil {
t.Fatalf("RequestLogTail: %v", err)
}
// re-click refreshes, still one request
if err := s.RequestLogTail("cust-a", "gokapi"); err != nil {
t.Fatalf("RequestLogTail re-click: %v", err)
}
apps, err := s.GetPendingLogTailRequests("cust-a")
if err != nil || len(apps) != 1 || apps[0] != "gokapi" {
t.Fatalf("pending = %v/%v, want [gokapi]", apps, err)
}
// another customer sees nothing
if other, _ := s.GetPendingLogTailRequests("cust-b"); len(other) != 0 {
t.Fatalf("cross-customer pending leak: %v", other)
}
lines := []string{"first line", "second line", "third line"}
if err := s.SaveAppLogTail("cust-a", "gokapi", time.Now(), lines); err != nil {
t.Fatalf("SaveAppLogTail: %v", err)
}
// consume-once: fulfilled request cleared
if apps, _ := s.GetPendingLogTailRequests("cust-a"); len(apps) != 0 {
t.Fatalf("request survived fulfillment: %v — the ACK would re-request every cycle", apps)
}
tails, err := s.GetCustomerLogTails("cust-a")
if err != nil || len(tails) != 1 {
t.Fatalf("tails = %d/%v, want 1", len(tails), err)
}
if len(tails[0].Lines) != 3 || tails[0].Lines[0] != "first line" || tails[0].Lines[2] != "third line" {
t.Fatalf("tail lines lost order: %#v", tails[0].Lines)
}
// keep-last-2 pruning
s.SaveAppLogTail("cust-a", "gokapi", time.Now(), []string{"tail-2"})
s.SaveAppLogTail("cust-a", "gokapi", time.Now(), []string{"tail-3"})
tails, _ = s.GetCustomerLogTails("cust-a")
if len(tails) != 2 {
t.Fatalf("keep-last-2 violated: %d tails stored", len(tails))
}
if tails[0].Lines[0] != "tail-3" || tails[1].Lines[0] != "tail-2" {
t.Fatalf("pruning kept the wrong tails: %v / %v", tails[0].Lines, tails[1].Lines)
}
// customer-scoped single read
if tail, _ := s.GetLogTail(tails[0].ID, "cust-b"); tail != nil {
t.Fatalf("cross-customer tail read must return nil")
}
if tail, _ := s.GetLogTail(tails[0].ID, "cust-a"); tail == nil || tail.AppName != "gokapi" {
t.Fatalf("scoped tail read failed: %+v", tail)
}
}
// Warn issues ride with no context and stay message-only end-to-end (nil-safe).
func TestUpsertIssue_WarnNoContext(t *testing.T) {
s := newTelemetryTestStore(t)
saveIssue(t, s, "cust-a", "app", "warn", "WARN: slow disk", time.Now(), nil)
is := getOneIssue(t, s, "app", longAgo, false)
if is == nil || len(is.Context) != 0 {
t.Fatalf("warn issue context = %#v, want none", is)
}
}
// Occurrence counting still works with the new upsert (regression guard).
func TestUpsertIssue_OccurrenceCount(t *testing.T) {
s := newTelemetryTestStore(t)
msg := "ERROR: boom"
for i := 0; i < 3; i++ {
saveIssue(t, s, "cust-a", "app", "error", msg, time.Now().Add(time.Duration(i)*time.Minute), nil)
}
is := getOneIssue(t, s, "app", longAgo, false)
if is.OccurrenceCount != 3 {
t.Fatalf("occurrence_count = %d, want 3", is.OccurrenceCount)
}
}