From 69a519be754a46ecf12b94a8cfe065706c1e1825 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 4 Aug 2026 13:36:47 +0000 Subject: [PATCH] =?UTF-8?q?Observation:=20se=20var=20tiden=20g=C3=A5r,=20u?= =?UTF-8?q?tan=20ett=20enda=20nytt=20beroende?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit CloudWatch gav loggar och mätvärden men svarade inte på frågan man faktiskt har när något är långsamt: var tog tiden vägen. Tjänsterna har medvetet nästan inga beroenden — plattformen har pg-drivrutinen, orkestern har Claude-klienten. Att dra in ett OpenTelemetry-SDK med trettio paket för att mäta fyra saker vore fel avvägning. I stället två standarder som båda bara är text på stdout: W3C Trace Context. Klienten startar spåret och traceparent följer med genom plattformen till orkestern, så en teknikers handling går att följa hela vägen till modellsvaret i stället för att bli två orelaterade spår. CloudWatch EMF. Strukturerad JSON som CloudWatch själv extraherar mätvärden ur — ingen agent, ingen SDK, inget som kan sluta fungera tyst. Varje anrop ger en loggrad med nedbrytning av tiden per del: databasen, modellanropet, objektlagringen, kundens leverantör. Det svarar direkt på om ett långsamt ärende beror på S3 eller på Opus-granskningen, i stället för att någon ska korrelera fem loggrader. Vägen normaliseras innan den blir dimension, och organisation, ärende-id och spår-id blir aldrig dimensioner — varje unik kombination är en egen tidsserie som kostar. De ligger som vanliga fält, sökbara i Logs Insights. Ett test låser det, eftersom det är precis den sortens sak som smyger in senare. Tre larm på det teknikern märker: svarstid p95 över tre sekunder (medelvärdet döljer att var tjugonde tekniker väntar orimligt länge), serverfel med spår-id i loggraden, och att modellen avböjer — det senare tyder på att underlaget innehåller något oväntat, inte på ett driftfel. Modulen är delad mellan tjänsterna i stället för duplicerad. Byggkontexten flyttas därför till felsokning/services, och en symlänk gör att testerna och integrationstestet kör mot samma fil som bilderna. Verifierat: 106 vitest-tester (10 nya för spårning, EMF-format och att dimensionerna hålls få), typkontroll, eslint på klient och tjänster, rotens CI, terraform fmt och referenskontroll på båda lagren, samt integrationstest mot riktig Postgres där spårraderna syns live. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012EQg3rJsrQ1ZNTvkzmQAtt --- .gitea/workflows/felsokning.yml | 8 +- .../felsokning/__tests__/observation.test.ts | 149 ++++++++++++++++ felsokning/app/src/felsokning/ai.ts | 3 + felsokning/app/src/felsokning/plattform.ts | 14 ++ felsokning/docs/DRIFT.md | 54 ++++++ felsokning/docs/MVP.md | 1 + felsokning/infra/aws/50-doman-observation.tf | 101 +++++++++++ felsokning/infra/aws/outputs.tf | 3 + felsokning/services/ai-orkester/Dockerfile | 7 +- .../services/ai-orkester/observation.mjs | 1 + felsokning/services/ai-orkester/server.mjs | 46 ++++- felsokning/services/gemensam/observation.mjs | 166 ++++++++++++++++++ felsokning/services/plattform/Dockerfile | 7 +- felsokning/services/plattform/observation.mjs | 1 + felsokning/services/plattform/server.mjs | 46 ++++- 15 files changed, 591 insertions(+), 16 deletions(-) create mode 100644 felsokning/app/src/felsokning/__tests__/observation.test.ts create mode 120000 felsokning/services/ai-orkester/observation.mjs create mode 100644 felsokning/services/gemensam/observation.mjs create mode 120000 felsokning/services/plattform/observation.mjs diff --git a/.gitea/workflows/felsokning.yml b/.gitea/workflows/felsokning.yml index 0afef76..b772e4b 100644 --- a/.gitea/workflows/felsokning.yml +++ b/.gitea/workflows/felsokning.yml @@ -94,8 +94,12 @@ jobs: --build-arg VITE_PLATTFORM_URL="https://${{ vars.DOMAN }}" \ --build-arg VITE_AI_ORKESTER_URL="https://${{ vars.DOMAN }}" \ felsokning/app - docker build -t "$REGISTER/guidad-felsokning-plattform:$TAGG" felsokning/services/plattform - docker build -t "$REGISTER/guidad-felsokning-ai-orkester:$TAGG" felsokning/services/ai-orkester + # Byggkontexten är felsokning/services så båda tjänsterna når + # den delade observationsmodulen utan att den dupliceras. + docker build -t "$REGISTER/guidad-felsokning-plattform:$TAGG" \ + -f felsokning/services/plattform/Dockerfile felsokning/services + docker build -t "$REGISTER/guidad-felsokning-ai-orkester:$TAGG" \ + -f felsokning/services/ai-orkester/Dockerfile felsokning/services for bild in web plattform ai-orkester; do docker push "$REGISTER/guidad-felsokning-$bild:$TAGG" done diff --git a/felsokning/app/src/felsokning/__tests__/observation.test.ts b/felsokning/app/src/felsokning/__tests__/observation.test.ts new file mode 100644 index 0000000..f3a19e6 --- /dev/null +++ b/felsokning/app/src/felsokning/__tests__/observation.test.ts @@ -0,0 +1,149 @@ +// @vitest-environment node +// Observationen får aldrig bli det som gör systemet långsamt eller +// läckande. Testerna låser tre saker: spåret följer med, mätvärdena har +// format CloudWatch faktiskt förstår, och inget känsligt hamnar i +// dimensionerna. +import { afterEach, describe, expect, it, vi } from "vitest"; +import { + NAMNRYMD, + avsluta, + logga, + mätvärde, + spårFrån, + starta, + traceparent, +} from "../../../../services/gemensam/observation.mjs"; + +function fånga(arbete: () => void): Record[] { + const rader: Record[] = []; + const spion = vi.spyOn(process.stdout, "write").mockImplementation((rad) => { + rader.push(JSON.parse(String(rad))); + return true; + }); + try { + arbete(); + } finally { + spion.mockRestore(); + } + return rader; +} + +afterEach(() => vi.restoreAllMocks()); + +describe("spårning", () => { + it("tar emot ett inkommande spår och behåller spår-id:t", () => { + const spår = spårFrån("00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"); + expect(spår.spårId).toBe("4bf92f3577b34da6a3ce929d0e0e4736"); + expect(spår.förälder).toBe("00f067aa0ba902b7"); + // Eget spann-id: vi är ett nytt steg i kedjan, inte samma. + expect(spår.spanId).not.toBe("00f067aa0ba902b7"); + expect(spår.spanId).toMatch(/^[0-9a-f]{16}$/); + }); + + it("startar ett nytt spår när huvudet saknas eller är trasigt", () => { + for (const huvud of [undefined, "", "skräp", "00-kort-00f067aa0ba902b7-01", "99-…"]) { + const spår = spårFrån(huvud as string); + expect(spår.spårId, String(huvud)).toMatch(/^[0-9a-f]{32}$/); + expect(spår.förälder, String(huvud)).toBeNull(); + } + }); + + it("skickar vidare ett huvud nästa tjänst kan läsa", () => { + const spår = spårFrån(undefined); + const vidare = spårFrån(traceparent(spår)); + expect(vidare.spårId).toBe(spår.spårId); + expect(vidare.förälder).toBe(spår.spanId); + }); +}); + +describe("nedbrytning av tiden", () => { + it("slår ihop upprepade delar till antal och summa", async () => { + const spann = starta("plattform", spårFrån(undefined)); + await spann.mät("databas", async () => {}); + await spann.mät("databas", async () => {}); + await spann.mät("modell", async () => {}); + + const delar = spann.delar(); + expect(Object.keys(delar).sort()).toEqual(["databas", "modell"]); + expect(delar.databas.antal).toBe(2); + expect(delar.modell.antal).toBe(1); + expect(delar.databas.ms).toBeGreaterThanOrEqual(0); + }); + + it("mäter även när arbetet kastar — annars ser fel ut som noll tid", async () => { + const spann = starta("plattform", spårFrån(undefined)); + await expect( + spann.mät("databas", async () => { + throw new Error("nej"); + }), + ).rejects.toThrow("nej"); + expect(spann.delar().databas.antal).toBe(1); + }); +}); + +describe("mätvärden i EMF", () => { + it("har den struktur CloudWatch extraherar mätvärden ur", () => { + const [rad] = fånga(() => mätvärde("Svarstid", 42, "Milliseconds", { Tjänst: "plattform" })); + const meta = (rad._aws as { CloudWatchMetrics: { Namespace: string; Dimensions: string[][]; Metrics: { Name: string; Unit: string }[] }[] }) + .CloudWatchMetrics[0]; + + expect(meta.Namespace).toBe(NAMNRYMD); + expect(meta.Dimensions).toEqual([["Tjänst"]]); + expect(meta.Metrics).toEqual([{ Name: "Svarstid", Unit: "Milliseconds" }]); + // Värdet måste ligga på toppnivå under sitt eget namn. + expect(rad.Svarstid).toBe(42); + expect(rad["Tjänst"]).toBe("plattform"); + }); + + it("dimensionerna hålls få — varje kombination är en egen tidsserie", () => { + const rader = fånga(() => { + const spann = starta("plattform", spårFrån(undefined)); + avsluta(spann, { status: 200, väg: "/api/arenden/:id/handelser", extra: { metod: "POST" } }); + }); + + const dimensioner = rader + .filter((r) => r._aws) + .flatMap((r) => (r._aws as { CloudWatchMetrics: { Dimensions: string[][] }[] }).CloudWatchMetrics[0].Dimensions.flat()); + + // Organisation, ärende och spår-id får aldrig bli dimensioner: + // kostnaden växer med en tidsserie per värde. + for (const förbjuden of ["org", "organisation", "arende", "spårId", "anvandare"]) { + expect(dimensioner, förbjuden).not.toContain(förbjuden); + } + expect(new Set(dimensioner)).toEqual(new Set(["Tjänst", "Väg"])); + }); + + it("fel får en egen serie så larmet kan larma på en summa", () => { + const rader = fånga(() => { + const spann = starta("plattform", spårFrån(undefined)); + avsluta(spann, { status: 500, väg: "/api/arenden" }); + }); + + const namn = rader + .filter((r) => r._aws) + .map((r) => (r._aws as { CloudWatchMetrics: { Metrics: { Name: string }[] }[] }).CloudWatchMetrics[0].Metrics[0].Name); + expect(namn).toContain("Fel"); + + // Och loggraden ska vara märkt som fel, inte info. + expect(rader.find((r) => r.nivå)).toMatchObject({ nivå: "fel", status: 500 }); + }); + + it("lyckade anrop skapar ingen felserie", () => { + const rader = fånga(() => { + const spann = starta("plattform", spårFrån(undefined)); + avsluta(spann, { status: 200, väg: "/halsa" }); + }); + const namn = rader + .filter((r) => r._aws) + .map((r) => (r._aws as { CloudWatchMetrics: { Metrics: { Name: string }[] }[] }).CloudWatchMetrics[0].Metrics[0].Name); + expect(namn).not.toContain("Fel"); + }); +}); + +describe("loggrader", () => { + it("är en rad JSON med spår-id, så Logs Insights kan fråga på fält", () => { + const [rad] = fånga(() => logga("info", "hej", { spårId: "abc", väg: "/api/arenden" })); + expect(rad).toMatchObject({ nivå: "info", meddelande: "hej", spårId: "abc" }); + expect(typeof rad.tid).toBe("string"); + }); +}); diff --git a/felsokning/app/src/felsokning/ai.ts b/felsokning/app/src/felsokning/ai.ts index 6f70a8a..11def88 100644 --- a/felsokning/app/src/felsokning/ai.ts +++ b/felsokning/app/src/felsokning/ai.ts @@ -247,6 +247,9 @@ async function anropa( method: "POST", headers: { "Content-Type": "application/json", + // Samma spårformat som plattformen: ett långsamt modellsvar går + // att hitta i loggen utifrån teknikerns anrop. + traceparent: (await import("./plattform")).nyttSpar(), Authorization: `Bearer ${token}`, }, body: JSON.stringify({ uppgift, prompt, ...extra }), diff --git a/felsokning/app/src/felsokning/plattform.ts b/felsokning/app/src/felsokning/plattform.ts index 94348f8..bb89326 100644 --- a/felsokning/app/src/felsokning/plattform.ts +++ b/felsokning/app/src/felsokning/plattform.ts @@ -264,6 +264,19 @@ export async function gorUppslag( return data.fordon ?? {}; } +// W3C Trace Context. Klienten startar spåret så att en teknikers +// handling går att följa hela vägen — via plattformen till modellsvaret +// — i stället för att bli två orelaterade spår i loggen. +function slumphex(byte: number): string { + return Array.from(crypto.getRandomValues(new Uint8Array(byte)), (b) => + b.toString(16).padStart(2, "0"), + ).join(""); +} + +export function nyttSpar(): string { + return `00-${slumphex(16)}-${slumphex(8)}-01`; +} + // Autentiserat anrop mot plattformen. En utgången token rensas (401) så // att appen faller tillbaka till lokalt läge tills nästa inloggning. export async function plattformFetch(vag: string, init?: RequestInit): Promise { @@ -273,6 +286,7 @@ export async function plattformFetch(vag: string, init?: RequestInit): Promise 1000 | sort ms desc | limit 20 + +# Hela kedjan för ett spår — plattform och orkester i samma vy +fields tid, meddelande, väg, ms, status | filter spårId = "fd5dec…" | sort tid + +# Vilka modellanrop kostar mest? +stats sum(ut) as ut_tokens, avg(ms) as snitt by Uppgift, Modell +``` + +### Larm + +Utöver infrastrukturlarmen finns tre på applikationens egna mätvärden: +svarstid **p95** över tre sekunder (medelvärdet döljer att var tjugonde +tekniker väntar orimligt länge), serverfel, och att modellen avböjer — +det senare tyder på att underlaget innehåller något oväntat, inte på ett +driftfel. + ## Multi-tenant och roller Enligt Master Prompt: varje kund är en egen tenant, ingen data blandas mellan kunder. diff --git a/felsokning/docs/MVP.md b/felsokning/docs/MVP.md index f7004c2..4716bd0 100644 --- a/felsokning/docs/MVP.md +++ b/felsokning/docs/MVP.md @@ -57,6 +57,7 @@ Demomanus för visning: [DEMO.md](DEMO.md). Knappen **Skapa demoärende** på st | Märkesspecifika kopplingar | ✅ Verkstaden konfigurerar sina egna OEM-/fordonsdataleverantörer under Inställningar med sina egna credentials ([moduler/markesspecifika-kopplingar.md](moduler/markesspecifika-kopplingar.md)): uppgifterna krypteras med AES-256-GCM i vila, returneras alltid maskerade (`••••3456`) och **alla uppslag görs av servern** — leverantörsnycklar når aldrig webbläsaren. Endast systemadministratören hanterar dem, kopplingarna är organisationsknutna och saknas krypteringsnyckeln sparas ingenting alls (fail closed). Leverantörer är data, inte kod: URL-mall, autentiseringstyp (bearer/header/basic/query) och svarsmappning beskrivs i `integrationer.json` (ConfigMap-utbytbar via `INTEGRATIONER_FIL`) — nya märken läggs till utan ombyggnad. Varje uppslag loggar teststatus, så ett utgånget abonnemang syns i inställningarna i stället för att ge tysta tomma svar. Verifierat i integrationstestet (rollstyrning, maskering, kryptering i databasen, organisationsisolering, fail closed). | | Bilagor | ✅ Foton, video och instrumentbilder ligger **utanför händelsen**; loggen bär en referens med innehållets SHA-256. Det stärker bevisvärdet: hashen står i den append-only-skyddade loggen, så en utbytt bild går att upptäcka — och innehållet kontrolleras mot hashen varje gång det lämnas ut (409 i stället för att visa bilden). Innehållsadresserat, så samma foto lagras en gång. Två lägen: `databas` (bytea, fungerar överallt) och `s3` (AWS/MinIO/Ceph) med egen SigV4-signering som korsverifieras bit för bit mot botocore i testerna. Delningsgränsen gäller även bilagor — den skannade arbetsordern nås aldrig via kundlänken. Äldre händelser med inbäddad data-URL fortsätter fungera för alltid, och lokalt läge bäddar in som förut så dokumentation aldrig går förlorad utan nät. | | Åtkomstkontroll | ✅ **Återkallelse är omedelbar**: varje autentiserat anrop kontrollerar att kontot är aktivt och att token-versionen stämmer, i stället för att en avstängning börjar gälla när token går ut. Administratören stänger av och öppnar konton i användarlistan (kan inte stänga av sig själv, aldrig över organisationsgränsen), och var och en kan logga ut på alla enheter när en telefon tappats bort. **Takt-begränsning på inloggning** ligger i databasen och håller därför bakom flera repliker: 10 försök per konto och 30 per källadress inom 15 minuter, och spärren gäller kontot även vid rätt lösenord. Samtliga gränser verifierade i integrationstestet. | +| Observation | ✅ **Noll nya beroenden**: W3C Trace Context (`traceparent` från klienten genom plattformen till orkestern) och CloudWatch EMF — strukturerad JSON på stdout som CloudWatch extraherar mätvärden ur, utan agent eller SDK. Varje anrop ger en loggrad med **nedbrytning av tiden** per del (databas, modellanrop, objektlagring, leverantörsuppslag), så frågan "var tog tiden vägen" besvaras av en rad i stället för av gissningar. Vägen normaliseras innan den blir dimension och organisation/ärende/spår blir aldrig dimensioner — låst av test, eftersom varje unik kombination är en tidsserie som kostar. Tre larm på det teknikern märker: svarstid p95, serverfel och att modellen avböjer. | | Drift på AWS | ✅ Allt eget, inget GitHub: **Gitea med egna Actions-runners** i samma kluster, **ECR** med oföränderliga taggar, **EKS** med noder utan publika adresser, **Aurora PostgreSQL** i ett subnätlager utan routing ut, **S3** för bilagor och **Secrets Manager** som sanningskälla för hemligheter — speglade av External Secrets, aldrig synliga för Terraform. Åtkomst via IRSA där varje roll är bunden till exakt ett tjänstekonto i en namnrymd; bygge och drift har skilda roller så ett komprometterat bygge inte kan driftsätta. **Observation**: CloudWatch med Container Insights, instrumentpanel och fyra larm — varav ett larmar på *saknad* data, eftersom en backup man tror finns är värre än ingen. | | Infrastruktur som kod | ✅ `infra/terraform` är systemets definition ([README](../infra/terraform/README.md)): `karta.tf` beskriver hela systemet en gång som data — tjänster, portar, routing, hemligheter per tjänst, dataflöden och gränser — och `terraform output karta` skriver ut samma sak i klartext. Namnrymden är stängd med nätverkspolicyer (bara ingress→tjänster, plattform→postgres, HTTPS ut utom privata nät), Postgres kör med säkerhetskontext, hemligheter kan genereras eller komma från en secrets-hanterare. Två lager i ordning: `infra/aws` (VPC, EKS, Aurora, S3, ECR, Secrets Manager, Route 53/ACM, CloudWatch) och `infra/terraform` (arbetslasten), där det andra läser det förstas utdata så inget anges två gånger. Uppdelningen är inte smak — en apply som både skapar ett kluster och schemalägger in i det är en känd Terraform-fälla. | | Öppet API | ✅ Plattforms-API:t är dokumenterat med OpenAPI 3.0 (`services/plattform/openapi.yaml`) — auth, användare, ärenden/händelser (append-only), översikt, publik delning och AI-orkestern, med scheman för alla händelsetyper. Specen valideras maskinellt, paritetstestas mot serverns rutter och serveras live på `GET /api/openapi.yaml`. | diff --git a/felsokning/infra/aws/50-doman-observation.tf b/felsokning/infra/aws/50-doman-observation.tf index 9607579..f9c0825 100644 --- a/felsokning/infra/aws/50-doman-observation.tf +++ b/felsokning/infra/aws/50-doman-observation.tf @@ -164,6 +164,72 @@ resource "aws_cloudwatch_metric_alarm" "noder" { } } +# ---- Larm på applikationens egna mätvärden ------------------------------ +# +# Tjänsterna skriver CloudWatch EMF på stdout, så mätvärdena finns utan +# agent eller SDK. Larmen nedan är på det som teknikern faktiskt märker. + +resource "aws_cloudwatch_metric_alarm" "svarstid" { + alarm_name = "${local.namn}-svarstid" + comparison_operator = "GreaterThanThreshold" + evaluation_periods = 3 + threshold = 3000 + alarm_description = "Plattformen svarar långsamt i tre perioder — p95 över tre sekunder märks i verkstaden." + alarm_actions = [aws_sns_topic.larm.arn] + ok_actions = [aws_sns_topic.larm.arn] + treat_missing_data = "notBreaching" + + metric_query { + id = "p95" + return_data = true + + metric { + metric_name = "Svarstid" + namespace = "GuidadFelsokning" + period = 300 + # p95, inte medelvärde: medelvärdet döljer att var tjugonde + # tekniker väntar orimligt länge. + stat = "p95" + + dimensions = { + "Tjänst" = "plattform" + } + } + } +} + +resource "aws_cloudwatch_metric_alarm" "fel" { + alarm_name = "${local.namn}-fel" + comparison_operator = "GreaterThanThreshold" + evaluation_periods = 2 + metric_name = "Fel" + namespace = "GuidadFelsokning" + period = 300 + statistic = "Sum" + threshold = 5 + alarm_description = "Serverfel. Loggraden bär spår-id — sök på det i Logs Insights för hela kedjan." + alarm_actions = [aws_sns_topic.larm.arn] + treat_missing_data = "notBreaching" + + dimensions = { + "Tjänst" = "plattform" + } +} + +resource "aws_cloudwatch_metric_alarm" "modell_avbojd" { + alarm_name = "${local.namn}-modell-avbojd" + comparison_operator = "GreaterThanThreshold" + evaluation_periods = 1 + metric_name = "ModellAvbojd" + namespace = "GuidadFelsokning" + period = 900 + statistic = "Sum" + threshold = 3 + alarm_description = "Modellen avböjer förfrågningar — tyder på att underlaget innehåller något oväntat, inte på ett driftfel." + alarm_actions = [aws_sns_topic.larm.arn] + treat_missing_data = "notBreaching" +} + # ---- Instrumentpanel ---------------------------------------------------- resource "aws_cloudwatch_dashboard" "denna" { @@ -201,6 +267,41 @@ resource "aws_cloudwatch_dashboard" "denna" { }, { type = "metric", x = 0, y = 6, width = 12, height = 6 + properties = { + title = "Svarstid — där teknikern märker det" + region = var.region + metrics = [ + ["GuidadFelsokning", "Svarstid", "Tjänst", "plattform", { stat = "p50", label = "median" }], + ["...", { stat = "p95", label = "p95" }], + ["...", { stat = "p99", label = "p99" }], + ] + period = 300 + yAxis = { left = { label = "ms" } } + } + }, + { + type = "metric", x = 12, y = 6, width = 12, height = 6 + properties = { + title = "Modellanrop per uppgift" + region = var.region + metrics = [ + ["GuidadFelsokning", "Svarstid", "Tjänst", "ai-orkester", { stat = "p95" }], + ["GuidadFelsokning", "ModellTokens", "Uppgift", "handledning", "Modell", "claude-sonnet-5", { stat = "Sum", yAxis = "right" }], + ["...", "granskning", ".", "claude-opus-5", { stat = "Sum", yAxis = "right" }], + ] + period = 300 + } + }, + { + type = "log", x = 0, y = 12, width = 24, height = 6 + properties = { + title = "Långsammaste anropen — med nedbrytning av tiden" + region = var.region + query = "SOURCE '${aws_cloudwatch_log_group.applikation.name}' | fields tid, väg, ms, delar.databas.ms as databas, delar.modell_handledning.ms as modell, spårId | filter ms > 1000 | sort ms desc | limit 20" + } + }, + { + type = "metric", x = 0, y = 18, width = 12, height = 6 properties = { title = "Bilagor i objektlagringen" region = var.region diff --git a/felsokning/infra/aws/outputs.tf b/felsokning/infra/aws/outputs.tf index efb5c32..0294778 100644 --- a/felsokning/infra/aws/outputs.tf +++ b/felsokning/infra/aws/outputs.tf @@ -68,6 +68,9 @@ output "karta" { instrumentpanel = "https://${var.region}.console.aws.amazon.com/cloudwatch/home?region=${var.region}#dashboards:name=${aws_cloudwatch_dashboard.denna.dashboard_name}" larm = var.larm_epost != "" ? "till ${var.larm_epost}" : "INGEN mottagare satt — larm går ingenstans" flodesloggar = "avvisad trafik, 30 dagar" + sparning = "W3C traceparent genom hela kedjan; varje anrop loggas som en JSON-rad med nedbrytning av tiden" + matvarden = "CloudWatch EMF från tjänsterna själva — ingen agent, ingen SDK" + larm_pa_app = "svarstid p95 > 3 s, serverfel, modellen avböjer" } kvar_att_gora = compact([ diff --git a/felsokning/services/ai-orkester/Dockerfile b/felsokning/services/ai-orkester/Dockerfile index 2b63f02..0e879e4 100644 --- a/felsokning/services/ai-orkester/Dockerfile +++ b/felsokning/services/ai-orkester/Dockerfile @@ -2,9 +2,12 @@ FROM node:22-alpine WORKDIR /app -COPY package.json ./ +COPY ai-orkester/package.json ./ RUN npm install --omit=dev --no-audit --no-fund && npm cache clean --force -COPY server.mjs ./ +# Byggkontexten är felsokning/services, så den delade +# observationsmodulen kan hämtas utan att dupliceras. +COPY gemensam/observation.mjs ./ +COPY ai-orkester/server.mjs ./ ENV NODE_ENV=production PORT=8080 USER node diff --git a/felsokning/services/ai-orkester/observation.mjs b/felsokning/services/ai-orkester/observation.mjs new file mode 120000 index 0000000..63282cd --- /dev/null +++ b/felsokning/services/ai-orkester/observation.mjs @@ -0,0 +1 @@ +../gemensam/observation.mjs \ No newline at end of file diff --git a/felsokning/services/ai-orkester/server.mjs b/felsokning/services/ai-orkester/server.mjs index 141009f..9281a40 100644 --- a/felsokning/services/ai-orkester/server.mjs +++ b/felsokning/services/ai-orkester/server.mjs @@ -14,6 +14,7 @@ import { createServer } from "node:http"; import { createHmac, timingSafeEqual } from "node:crypto"; import Anthropic from "@anthropic-ai/sdk"; +import { avsluta, logga, mätvärde, spårFrån, starta } from "./observation.mjs"; const PORT = Number(process.env.PORT ?? 8080); const MAX_PROMPT_LANGD = 40000; @@ -249,6 +250,14 @@ async function lasKropp(req) { export function skapaServer() { return createServer(async (req, res) => { + // Spåret kommer från plattformen, så ett långsamt teknikeranrop går + // att följa hela vägen till modellsvaret. + res.spår = spårFrån(req.headers.traceparent); + res.spann = starta("ai-orkester", res.spår); + res.on("finish", () => + avsluta(res.spann, { status: res.statusCode, väg: req.url ?? "/", extra: { metod: req.method } }), + ); + if (req.method === "OPTIONS") { res.writeHead(204, { "Access-Control-Allow-Origin": "*", @@ -309,7 +318,8 @@ export function skapaServer() { try { const klient = new Anthropic({ apiKey: apiNyckel }); - const svar = await klient.beta.messages.create({ + const svar = await res.spann.mät(`modell_${uppgift}`, () => + klient.beta.messages.create({ model: konfig.modell, max_tokens: konfig.maxTokens, output_config: { @@ -318,9 +328,30 @@ export function skapaServer() { }, betas: ["server-side-fallback-2026-07-01"], fallbacks: "default", - system: [{ type: "text", text: konfig.system, cache_control: { type: "ephemeral" } }], - messages: [{ role: "user", content: innehall }], - }); + system: [{ type: "text", text: konfig.system, cache_control: { type: "ephemeral" } }], + messages: [{ role: "user", content: innehall }], + }), + ); + // Modellval, token och latens per uppgift. Det är den här + // uppdelningen som svarar på om en långsam session beror på + // granskningen (Opus, hög effort) eller på något annat. + mätvärde( + "ModellTokens", + (svar.usage?.input_tokens ?? 0) + (svar.usage?.output_tokens ?? 0), + "Count", + { Uppgift: uppgift, Modell: konfig.modell }, + { + in: svar.usage?.input_tokens ?? 0, + ut: svar.usage?.output_tokens ?? 0, + cache_las: svar.usage?.cache_read_input_tokens ?? 0, + spårId: res.spår.spårId, + }, + ); + + if (svar.stop_reason === "refusal") { + logga("varning", "modellen avböjde", { uppgift, modell: konfig.modell, spårId: res.spår.spårId }); + mätvärde("ModellAvbojd", 1, "Count", { Uppgift: uppgift, Modell: konfig.modell }); + } if (svar.stop_reason === "refusal") { return svara(res, 502, { error: "AI-tjänsten avböjde förfrågan." }); } @@ -328,7 +359,12 @@ export function skapaServer() { if (!textBlock) return svara(res, 502, { error: "AI-svaret saknade innehåll." }); return svara(res, 200, { modell: konfig.modell, svar: JSON.parse(textBlock.text) }); } catch (fel) { - console.error("ai-orkester:", fel); + logga("fel", "AI-anropet misslyckades", { + uppgift, + modell: konfig.modell, + spårId: res.spår.spårId, + orsak: fel?.message ?? String(fel), + }); return svara(res, 500, { error: "AI-anropet misslyckades." }); } }); diff --git a/felsokning/services/gemensam/observation.mjs b/felsokning/services/gemensam/observation.mjs new file mode 100644 index 0000000..83be12e --- /dev/null +++ b/felsokning/services/gemensam/observation.mjs @@ -0,0 +1,166 @@ +// Observation — spårning och mätvärden utan nya beroenden. +// +// Tjänsterna har medvetet nästan inga beroenden: plattformen har +// pg-drivrutinen, orkestern har Claude-klienten. Att dra in ett +// OpenTelemetry-SDK med trettio paket för att mäta fyra saker vore fel +// avvägning. +// +// I stället två standarder som båda bara är text på stdout: +// +// W3C Trace Context traceparent-huvudet följer med genom hela +// kedjan, så en teknikers anrop går att följa +// från klienten via plattformen till orkestern. +// +// CloudWatch EMF strukturerad JSON som CloudWatch själv plockar +// mätvärden ur. Ingen agent, ingen SDK, inget +// som kan sluta fungera tyst. +// +// Det som mäts är valt efter en fråga: vad vill man veta klockan tre på +// natten när något är långsamt? Svaret är var tiden gick — inte hur +// många anrop som skett. + +import { randomBytes } from "node:crypto"; + +export const NAMNRYMD = "GuidadFelsokning"; + +const TRACEPARENT = /^00-([0-9a-f]{32})-([0-9a-f]{16})-([0-9a-f]{2})$/; + +/** + * Läser inkommande traceparent eller startar ett nytt spår. + * Ett anrop utan huvud är inte ett fel — de flesta kommer utifrån. + */ +export function spårFrån(huvud) { + const träff = typeof huvud === "string" ? huvud.trim().match(TRACEPARENT) : null; + return { + spårId: träff ? träff[1] : randomBytes(16).toString("hex"), + förälder: träff ? träff[2] : null, + spanId: randomBytes(8).toString("hex"), + }; +} + +// Skickas vidare till nästa tjänst i kedjan. +export function traceparent(spår) { + return `00-${spår.spårId}-${spår.spanId}-01`; +} + +/** + * Ett spann. Mäter tid och samlar barn, så att en logg-rad kan svara på + * "var tog tiden vägen" utan att någon behöver korrelera flera rader. + */ +export function starta(namn, spår) { + const början = process.hrtime.bigint(); + const barn = []; + + return { + namn, + spår, + + // Tidtagning på det som faktiskt kan vara långsamt: databasen, + // modellanropet, objektlagringen, kundens leverantör. + async mät(delnamn, arbete) { + const start = process.hrtime.bigint(); + try { + return await arbete(); + } finally { + barn.push({ namn: delnamn, ms: Number(process.hrtime.bigint() - start) / 1e6 }); + } + }, + + ms() { + return Number(process.hrtime.bigint() - början) / 1e6; + }, + + delar() { + // Samma delnamn flera gånger (t.ex. tre databasfrågor) slås ihop: + // antalet och summan säger mer än en lista. + const summa = {}; + for (const d of barn) { + summa[d.namn] ??= { antal: 0, ms: 0 }; + summa[d.namn].antal += 1; + summa[d.namn].ms += d.ms; + } + for (const d of Object.values(summa)) d.ms = Math.round(d.ms * 100) / 100; + return summa; + }, + }; +} + +// En rad JSON per händelse. CloudWatch Logs Insights kan fråga på +// vilket fält som helst utan att någon behöver skriva ett regex. +export function logga(nivå, meddelande, fält = {}) { + process.stdout.write( + `${JSON.stringify({ + nivå, + meddelande, + tid: new Date().toISOString(), + ...fält, + })}\n`, + ); +} + +/** + * Mätvärden i CloudWatch Embedded Metric Format. + * + * Formatet är en logg-rad som CloudWatch känner igen och extraherar + * mätvärden ur. Poängen är att mätvärdet och sammanhanget står i samma + * rad: när latensen är hög går det att gå direkt till anropen som + * orsakade den, i stället för att gissa utifrån en graf. + * + * Dimensioner hålls medvetet få. Varje unik kombination är en egen + * tidsserie som kostar, så organisation eller ärende-id får aldrig bli + * en dimension — de ligger som vanliga fält. + */ +export function mätvärde(namn, värde, enhet, dimensioner = {}, extra = {}) { + const nycklar = Object.keys(dimensioner); + + process.stdout.write( + `${JSON.stringify({ + _aws: { + Timestamp: Date.now(), + CloudWatchMetrics: [ + { + Namespace: NAMNRYMD, + Dimensions: nycklar.length > 0 ? [nycklar] : [[]], + Metrics: [{ Name: namn, Unit: enhet }], + }, + ], + }, + ...dimensioner, + [namn]: värde, + ...extra, + })}\n`, + ); +} + +/** + * Avslutar ett spann: en strukturerad logg-rad med hela nedbrytningen, + * och ett mätvärde för latensen. + * + * Fel loggas som fel men mäts på samma ställe — annars syns inte att + * felen är snabba och de lyckade anropen långsamma, vilket är precis + * den sortens sak som förvirrar en felsökning. + */ +export function avsluta(spann, { status, väg, extra = {} }) { + const ms = spann.ms(); + const delar = spann.delar(); + + logga(status >= 500 ? "fel" : "info", spann.namn, { + spårId: spann.spår.spårId, + spanId: spann.spår.spanId, + väg, + status, + ms: Math.round(ms * 100) / 100, + delar, + ...extra, + }); + + mätvärde("Svarstid", ms, "Milliseconds", { Tjänst: spann.namn, Väg: väg }, { status }); + + // En egen serie för fel gör larmet enkelt: larma på summan, inte på + // ett förhållande som måste räknas ut. + if (status >= 500) { + mätvärde("Fel", 1, "Count", { Tjänst: spann.namn, Väg: väg }, { spårId: spann.spår.spårId }); + } + + return ms; +} diff --git a/felsokning/services/plattform/Dockerfile b/felsokning/services/plattform/Dockerfile index 8a9b967..5a4cd84 100644 --- a/felsokning/services/plattform/Dockerfile +++ b/felsokning/services/plattform/Dockerfile @@ -2,9 +2,12 @@ FROM node:22-alpine WORKDIR /app -COPY package.json ./ +COPY plattform/package.json ./ RUN npm install --omit=dev --no-audit --no-fund && npm cache clean --force -COPY server.mjs bilagor.mjs openapi.yaml ecm-regler.json integrationer.json ./ +# Byggkontexten är felsokning/services, så den delade +# observationsmodulen kan hämtas utan att dupliceras. +COPY gemensam/observation.mjs ./ +COPY plattform/server.mjs plattform/bilagor.mjs plattform/openapi.yaml plattform/ecm-regler.json plattform/integrationer.json ./ ENV NODE_ENV=production PORT=8080 USER node diff --git a/felsokning/services/plattform/observation.mjs b/felsokning/services/plattform/observation.mjs new file mode 120000 index 0000000..63282cd --- /dev/null +++ b/felsokning/services/plattform/observation.mjs @@ -0,0 +1 @@ +../gemensam/observation.mjs \ No newline at end of file diff --git a/felsokning/services/plattform/server.mjs b/felsokning/services/plattform/server.mjs index 8581683..fbb86ee 100644 --- a/felsokning/services/plattform/server.mjs +++ b/felsokning/services/plattform/server.mjs @@ -26,6 +26,7 @@ import { fileURLToPath } from "node:url"; import { dirname, join } from "node:path"; import pg from "pg"; import { innehallsHash, mediatypGiltig, valjLager } from "./bilagor.mjs"; +import { avsluta, logga, mätvärde, spårFrån, starta, traceparent } from "./observation.mjs"; // API-first: OpenAPI-specen är en versionerad artefakt och serveras live. const OPENAPI = readFileSync(join(dirname(fileURLToPath(import.meta.url)), "openapi.yaml"), "utf8"); @@ -59,6 +60,15 @@ const ROLLER = ["tekniker", "arbetsledare", "admin"]; const pool = new pg.Pool({ connectionString: process.env.DATABASE_URL, max: 10 }); +// Poolens uttömning är den vanligaste orsaken till att allt blir +// långsamt samtidigt utan att någon enskild fråga är långsam. +setInterval(() => { + mätvärde("Databaskopplingar", pool.totalCount, "Count", { Tjänst: "plattform" }, { + lediga: pool.idleCount, + väntande: pool.waitingCount, + }); +}, 60_000).unref(); + // Var bilagornas innehåll hamnar. Felkonfigurerat s3-läge failar här, // vid start, i stället för vid första uppladdningen. const BILAGELAGER = valjLager(process.env, pool); @@ -427,10 +437,10 @@ export async function gorUppslag(def, uppgifter, identifierare, hamtare = fetch) // hashen i loggen. Stämmer det inte säger vi det rakt ut i stället för // att visa en bild som kan ha bytts ut. async function skickaBilaga(res, rad) { - const data = await BILAGELAGER.hamta(rad.hash); + const data = await res.spann.mät("bilaga_las", () => BILAGELAGER.hamta(rad.hash)); if (!data) return svara(res, 404, { error: "Innehållet saknas i lagringen." }); if (innehallsHash(data) !== rad.hash) { - console.error("bilaga: innehållet stämmer inte med hashen i loggen", rad.hash); + logga("fel", "bilagans innehåll stämmer inte med hashen i loggen", { hash: rad.hash }); return svara(res, 409, { error: "Innehållet stämmer inte med det som dokumenterades." }); } res.writeHead(200, { @@ -465,6 +475,22 @@ export function skapaServer() { return createServer(async (req, res) => { res.ursprung = ursprungFor(req); + + // Spåret följer med genom hela kedjan. Kommer inget huvud in startar + // vi ett nytt — de flesta anrop kommer utifrån. + res.spår = spårFrån(req.headers.traceparent); + res.spann = starta("plattform", res.spår); + res.setHeader("traceparent", traceparent(res.spår)); + + res.on("finish", () => { + avsluta(res.spann, { + status: res.statusCode, + // Ärende- och bilage-id ersätts så att vägen blir en dimension + // med rimligt antal värden i stället för en per ärende. + väg: (req.url ?? "/").split("?")[0].replace(/\/[A-Za-z0-9_-]{8,}/g, "/:id"), + extra: { metod: req.method }, + }); + }); if (req.method === "OPTIONS") { res.writeHead(204, { "Access-Control-Allow-Origin": res.ursprung, @@ -787,7 +813,7 @@ export function skapaServer() { if (data.length === 0) return svara(res, 400, { error: "Bilagan är tom." }); const hash = innehallsHash(data); - await BILAGELAGER.spara(hash, data); + await res.spann.mät("bilaga_skriv", () => BILAGELAGER.spara(hash, data)); const id = `bil-${nyKod()}`; await pool.query( `insert into bilagor (id, organisation_id, arende_id, hash, mediatyp, storlek, laddad_av) @@ -937,7 +963,9 @@ export function skapaServer() { return svara(res, 500, { error: "Uppgifterna kunde inte läsas — spara om kopplingen." }); } - const resultat = await gorUppslag(def, uppgifter, identifierare.trim().toUpperCase()); + const resultat = await res.spann.mät("leverantorsuppslag", () => + gorUppslag(def, uppgifter, identifierare.trim().toUpperCase()), + ); await pool.query( `update integrationer set senast_testad = now(), senaste_status = $3 where organisation_id = $1 and leverantor = $2`, @@ -1143,6 +1171,7 @@ export function skapaServer() { if (!Array.isArray(handelser) || handelser.length > 500) { return svara(res, 400, { error: "Ogiltig händelselista." }); } + res.spann.spår.antalHandelser = handelser.length; for (const post of handelser) { if (typeof post?.id !== "string" || !post.tidpunkt || typeof post.anvandare !== "string" || !post.handelse) { return svara(res, 400, { error: "Ogiltig händelse." }); @@ -1161,7 +1190,14 @@ export function skapaServer() { return svara(res, 404, { error: "Okänd resurs." }); } catch (fel) { - console.error("plattform:", fel); + // Spår-id:t i raden gör att hela kedjan går att hitta i Logs + // Insights utifrån larmet. + logga("fel", "förfrågan misslyckades", { + spårId: res.spår.spårId, + väg: vag, + metod: req.method, + orsak: fel?.message ?? String(fel), + }); return svara(res, 500, { error: "Förfrågan misslyckades." }); } });