feat(014-full-observability): remaining business metrics (first response, resolution, SLA, errors, tools)

Completes User Story 4's eleven named metrics: first-response-time
(messages.service.ts's post(), guarded against double-counting a
ticket's second agent message), SLA compliance (sla.service.ts's
complete()/runBreachDetectionSweep(), with a guard so a run already
breached by the sweep is never also counted "met" when it later
resolves), most-common-errors (error-codes.service.ts, counted only
once a code is confirmed real), and tool-failure-rate/knowledge-
effectiveness (tools.service.ts's single executeTool call site).

Verified end-to-end against real Postgres/Redis by scraping the real
/metrics endpoint before and after driving each metric's actual
underlying event through the real service layer — including a genuine
tool-execution failure (a nonexistent ticket ID) rather than a
simulated one.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

src/modules/ai-support/knowledge/service/error-codes.service.ts

@@ -1,5 +1,6 @@
 import { ErrorCode, KnownIssue } from '@prisma/client';
 import { NotFoundError } from '@/common/errors';
+import { knownErrorLookupsCounter } from '@/infrastructure/observability';
 import {
   errorCodesRepository,
   ErrorCodesRepository,
@@ -26,6 +27,11 @@ export class ErrorCodesService {
   async findKnownIssuesByErrorCode(productId: string, code: string): Promise<KnownIssue[]> {
     const errorCode = await this.errorCodesRepo.findByCode(productId, code);
     if (!errorCode) throw new NotFoundError('Error code not found.');
+
+    // 014-full-observability data-model.md #9: "most common errors" — a raw counter, ranked by
+    // an external monitoring stack (FR-009), counted only once the code is confirmed real.
+    knownErrorLookupsCounter.inc({ code });
+
     return this.knownIssuesRepo.findByErrorCodeId(errorCode.id);
   }
 }

src/modules/ai-support/tools/service/tools.service.ts

@@ -1,4 +1,8 @@
 import Anthropic from '@anthropic-ai/sdk';
+import {
+  toolInvocationsCounter,
+  knowledgeRetrievalOutcomesCounter,
+} from '@/infrastructure/observability';
 import { actionRepository, ActionRepository } from '../repository';
 import { evaluateToolProposal } from './policy-gate';
 import { executeTool, ToolExecutionContext } from './tool-executor';
@@ -58,6 +62,15 @@ export class ToolsService {
       const result = await executeTool(block.name, block.input, context);
       await this.actions.createResult(action.id, result.output, result.status);
 
+      // 014-full-observability data-model.md #10/#11: the single choke point every tool
+      // invocation passes through — labeled by outcome, and (for the knowledge-search tool
+      // specifically) by whether it found anything.
+      toolInvocationsCounter.inc({ tool: block.name, outcome: result.status });
+      if (block.name === 'searchProductKnowledge') {
+        const matched = Array.isArray(result.output) && result.output.length > 0;
+        knowledgeRetrievalOutcomesCounter.inc({ matched: String(matched) });
+      }
+
       if (result.status === 'failed') anyFailed = true;
       if (block.name === 'escalateToHuman' && result.status === 'success') {
         const output = result.output as { reason?: string };

src/modules/orchestration/sla/service/sla.service.ts

@@ -3,6 +3,7 @@ import { NotFoundError, ValidationError } from '@/common/errors';
 import { ticketsService } from '@/modules/ticketing/tickets';
 import { messagesService } from '@/modules/ticketing/messages';
 import { escalationService, EscalationService } from '@/modules/orchestration/escalation';
+import { slaRunOutcomesCounter } from '@/infrastructure/observability';
 import {
   slaPolicyRepository,
   SlaPolicyRepository,
@@ -135,6 +136,14 @@ export class SlaService {
     const run = await this.runs.findByTicketId(ticketId);
     if (!run || run.status === 'completed') return;
 
+    // 014-full-observability data-model.md #6: read BEFORE the update below — a run already
+    // 'breached' by the time it resolves was already counted breached by the sweep and must
+    // never also be counted 'met' here, even though this update still (pre-existing behavior,
+    // unrelated to this feature — see research.md §5) overwrites its status to 'completed'.
+    if (run.status !== 'breached') {
+      slaRunOutcomesCounter.inc({ outcome: 'met' });
+    }
+
     await this.runs.update(run.id, { status: 'completed', completedAt: new Date() });
   }
 
@@ -151,6 +160,7 @@ export class SlaService {
     const resolutionBreaches = await this.runs.findRunningPastResolutionDueAt(now);
     for (const run of resolutionBreaches) {
       await this.runs.update(run.id, { status: 'breached', breachedAt: now });
+      slaRunOutcomesCounter.inc({ outcome: 'breached' });
       await this.escalation.handleBreach(run.ticketId, 'resolution_breach');
     }
 

src/modules/ticketing/messages/service/messages.service.ts

@@ -1,4 +1,6 @@
 import { TicketMessage } from '@prisma/client';
+import { ticketsRepository } from '@/modules/ticketing/tickets';
+import { ticketFirstResponseDurationHistogram } from '@/infrastructure/observability';
 import { messagesRepository, MessagesRepository } from '../repository';
 import { MessageType, isVisibleToCustomer } from '../mapper';
 
@@ -13,13 +15,32 @@ export class MessagesService {
     type: MessageType,
     body: string,
   ): Promise<TicketMessage> {
-    return this.repo.create({
+    // 014-full-observability data-model.md #5: checked BEFORE creating the new message, so it
+    // reflects "is there already an agent response" at the moment this one is being posted.
+    // Benign race (research.md §5/plan.md Constraint) — two concurrent first responses could
+    // both observe once — acceptable for a best-effort metric, not a business-correctness path.
+    const isFirstAgentMessage =
+      type === 'AGENT_MESSAGE' &&
+      !(await this.repo.findAll(ticketId)).some((m) => m.type === 'AGENT_MESSAGE');
+
+    const message = await this.repo.create({
       ticketId,
       authorRef,
       type,
       body,
       visibleToCustomer: isVisibleToCustomer(type),
     });
+
+    if (isFirstAgentMessage) {
+      const ticket = await ticketsRepository.findById(ticketId);
+      if (ticket) {
+        ticketFirstResponseDurationHistogram.observe(
+          (message.createdAt.getTime() - ticket.createdAt.getTime()) / 1000,
+        );
+      }
+    }
+
+    return message;
   }
 
   async listForCustomer(ticketId: string): Promise<TicketMessage[]> {

tests/integration/observability/business-metrics.test.ts

@@ -0,0 +1,359 @@
+import { describe, it, expect, beforeAll, afterAll } from 'vitest';
+import { buildApp } from '@/app';
+import { prismaClient } from '@/infrastructure/database';
+import { FastifyInstance } from 'fastify';
+import { loginAs, authHeader } from '../../helpers/auth';
+import {
+  encryptCredential,
+  generateCredentialSecret,
+  issueIntegrationToken,
+} from '@/modules/catalog/products';
+import { sessionsService, sessionRepository } from '@/modules/ai-support/sessions';
+import { ticketsService } from '@/modules/ticketing/tickets';
+import { messagesService } from '@/modules/ticketing/messages';
+import { resolutionRepository } from '@/modules/problem-management/resolutions';
+import { slaService, slaRunRepository } from '@/modules/orchestration/sla';
+import { escalationService } from '@/modules/orchestration/escalation';
+import { errorCodesService } from '@/modules/ai-support/knowledge';
+import { toolsService } from '@/modules/ai-support/tools';
+
+/**
+ * Covers specs/014-full-observability/quickstart.md Scenario 4 against a real Postgres/Redis —
+ * every named business-health metric, scraped from the real /metrics endpoint before and after
+ * driving its real underlying event through the real service layer (not mocked). Several flows
+ * (human resolution, SLA runs) create rows directly against the repositories that already own
+ * the relevant validation elsewhere in this codebase's own test suite — this file's job is only
+ * to prove the metric increments at the correct point, not to re-verify those modules' own
+ * business rules (already covered by problem-resolution-flow.test.ts / sla-escalation-flow.test.ts).
+ */
+describe('Business-health metrics (User Story 4)', () => {
+  let app: FastifyInstance;
+  let authToken: string;
+  const externalProductId = `TEST_BIZ_METRICS_PROD_${Date.now()}`;
+  let productId: string;
+  let secret: string;
+
+  beforeAll(async () => {
+    app = await buildApp();
+    authToken = await loginAs(app, 'ADMIN');
+
+    const product = await prismaClient.product.create({
+      data: { externalProductId, name: 'Business Metrics Test Product', status: 'active' },
+    });
+    productId = product.id;
+    secret = generateCredentialSecret();
+    await prismaClient.productIntegration.create({
+      data: {
+        productId,
+        credentialRef: encryptCredential(secret),
+        authMechanism: 'signed_token',
+        allowedScope: { tenantIds: ['tenant-1'] },
+        status: 'active',
+        rateLimitPerMinute: 1000,
+        rateLimitPerUserPerMinute: 1000,
+      },
+    });
+  });
+
+  afterAll(async () => {
+    await app.close();
+  });
+
+  async function createTicket(): Promise<string> {
+    const token = issueIntegrationToken(secret, {
+      externalProductId,
+      tenantId: 'tenant-1',
+      userId: 'user-1',
+    });
+    const created = await app.inject({
+      method: 'POST',
+      url: '/v1/support/requests',
+      headers: { authorization: `Bearer ${token}` },
+      payload: {
+        productId: externalProductId,
+        tenantId: 'tenant-1',
+        userId: 'user-1',
+        source: 'test',
+        problem: `Business metrics test ${Date.now()}-${Math.random()}`,
+      },
+    });
+    expect(created.statusCode).toBe(202);
+    return created.json().data.ticketId as string;
+  }
+
+  async function scrape(): Promise<string> {
+    const res = await app.inject({ method: 'GET', url: '/metrics' });
+    expect(res.statusCode).toBe(200);
+    return res.body;
+  }
+
+  function metricValue(body: string, name: string, labels?: Record<string, string>): number {
+    const labelPart = labels
+      ? `\\{${Object.entries(labels)
+          .map(([k, v]) => `${k}="${v}"`)
+          .join(',')}\\}`
+      : '(?:\\{\\})?';
+    const match = body.match(new RegExp(`${name}${labelPart}\\s+([0-9.]+)`));
+    return match?.[1] ? parseFloat(match[1]) : 0;
+  }
+
+  it('counts an AI session resolving without escalating', async () => {
+    const ticketId = await createTicket();
+    const session = await sessionRepository.create(ticketId);
+
+    const before = metricValue(await scrape(), 'supporthub_ai_session_outcomes_total', {
+      outcome: 'resolved',
+    });
+    await sessionRepository.updateStatus(session.id, 'resolved');
+    const after = metricValue(await scrape(), 'supporthub_ai_session_outcomes_total', {
+      outcome: 'resolved',
+    });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts an AI session escalating, and nothing for resolved', async () => {
+    const ticketId = await createTicket();
+    const session = await sessionRepository.create(ticketId);
+
+    const before = metricValue(await scrape(), 'supporthub_ai_session_outcomes_total', {
+      outcome: 'escalated',
+    });
+    await sessionsService.escalate(session, ticketId, 'Escalating for metrics test.');
+    const after = metricValue(await scrape(), 'supporthub_ai_session_outcomes_total', {
+      outcome: 'escalated',
+    });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts the first agent message on a ticket, observing first-response duration', async () => {
+    const ticketId = await createTicket();
+
+    const bodyBefore = await scrape();
+    const before = metricValue(
+      bodyBefore,
+      'supporthub_ticket_first_response_duration_seconds_count',
+    );
+
+    await messagesService.post(ticketId, 'agent-1', 'AGENT_MESSAGE', 'Hi, looking into this.');
+    // A second agent message must NOT observe again.
+    await messagesService.post(ticketId, 'agent-1', 'AGENT_MESSAGE', 'Following up.');
+
+    const after = metricValue(
+      await scrape(),
+      'supporthub_ticket_first_response_duration_seconds_count',
+    );
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts a human resolution and observes resolution duration when a ticket reaches RESOLVED', async () => {
+    const ticketId = await createTicket();
+
+    // Drive the state machine directly (NEW -> HUMAN_ESCALATION -> [maybe already
+    // auto-assigned to IN_PROGRESS by orchestration] -> RESOLUTION_PENDING_CUSTOMER ->
+    // RESOLVED) — the metric subscriber only cares about the final RESOLVED transition and the
+    // Resolution row's own resolvedBy, not how the ticket got to RESOLUTION_PENDING_CUSTOMER.
+    let ticket = await prismaClient.ticket.findUniqueOrThrow({ where: { id: ticketId } });
+    ticket = await ticketsService.updateStatus(
+      ticketId,
+      'HUMAN_ESCALATION',
+      ticket.version,
+      'agent-1',
+    );
+    ticket = await prismaClient.ticket.findUniqueOrThrow({ where: { id: ticketId } });
+    if (ticket.status !== 'IN_PROGRESS') {
+      ticket = await ticketsService.updateStatus(
+        ticketId,
+        'IN_PROGRESS',
+        ticket.version,
+        'agent-1',
+      );
+    }
+    ticket = await ticketsService.updateStatus(
+      ticketId,
+      'RESOLUTION_PENDING_CUSTOMER',
+      ticket.version,
+      'agent-1',
+    );
+    await resolutionRepository.create({ ticketId, outcome: 'fixed', resolvedBy: 'agent-1' });
+
+    const bodyBefore = await scrape();
+    const resolvedBefore = metricValue(bodyBefore, 'supporthub_ticket_resolutions_total', {
+      resolved_by: 'human',
+    });
+    const durationBefore = metricValue(
+      bodyBefore,
+      'supporthub_ticket_resolution_duration_seconds_count',
+    );
+
+    await ticketsService.updateStatus(ticketId, 'RESOLVED', ticket.version, 'agent-1');
+
+    const bodyAfter = await scrape();
+    expect(
+      metricValue(bodyAfter, 'supporthub_ticket_resolutions_total', { resolved_by: 'human' }),
+    ).toBe(resolvedBefore + 1);
+    expect(metricValue(bodyAfter, 'supporthub_ticket_resolution_duration_seconds_count')).toBe(
+      durationBefore + 1,
+    );
+  });
+
+  it('counts an SLA run completing on time as met', async () => {
+    const policy = await prismaClient.sLAPolicy.create({
+      data: {
+        name: `Metrics Policy ${Date.now()}`,
+        productId,
+        firstResponseMinutes: 30,
+        resolutionMinutes: 240,
+      },
+    });
+    const ticketId = await createTicket();
+    await slaRunRepository.create({
+      ticketId,
+      policyId: policy.id,
+      firstResponseDueAt: new Date(Date.now() + 30 * 60_000),
+      resolutionDueAt: new Date(Date.now() + 240 * 60_000),
+    });
+
+    const before = metricValue(await scrape(), 'supporthub_sla_run_outcomes_total', {
+      outcome: 'met',
+    });
+    await slaService.complete(ticketId);
+    const after = metricValue(await scrape(), 'supporthub_sla_run_outcomes_total', {
+      outcome: 'met',
+    });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts an overdue SLA run as breached via the sweep (at least once — a shared sweep may also catch unrelated overdue runs)', async () => {
+    const policy = await prismaClient.sLAPolicy.create({
+      data: {
+        name: `Metrics Breach Policy ${Date.now()}`,
+        productId,
+        firstResponseMinutes: 30,
+        resolutionMinutes: 1,
+      },
+    });
+    const ticketId = await createTicket();
+    await slaRunRepository.create({
+      ticketId,
+      policyId: policy.id,
+      firstResponseDueAt: new Date(Date.now() + 30 * 60_000),
+      resolutionDueAt: new Date(Date.now() - 60_000),
+    });
+
+    const before = metricValue(await scrape(), 'supporthub_sla_run_outcomes_total', {
+      outcome: 'breached',
+    });
+    await slaService.runBreachDetectionSweep();
+    const after = metricValue(await scrape(), 'supporthub_sla_run_outcomes_total', {
+      outcome: 'breached',
+    });
+
+    expect(after).toBeGreaterThanOrEqual(before + 1);
+  });
+
+  it('counts a manual escalation event by reason', async () => {
+    const node = await app.inject({
+      method: 'POST',
+      url: '/admin/hierarchy-nodes',
+      headers: authHeader(authToken),
+      payload: {
+        name: `Metrics Node ${Date.now()}`,
+        order: 0,
+        productScope: [externalProductId],
+        skills: [],
+        assignmentStrategy: 'ROUND_ROBIN',
+      },
+    });
+    const nodeId = node.json().data.id as string;
+    const ticketId = await createTicket();
+    const reason = `metrics-test-reason-${Date.now()}`;
+
+    const before = metricValue(await scrape(), 'supporthub_escalations_total', { reason });
+    await escalationService.escalateManually(ticketId, nodeId, 'admin-test', reason);
+    const after = metricValue(await scrape(), 'supporthub_escalations_total', { reason });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts a problem created, labeled by category (uncategorized here)', async () => {
+    const before = metricValue(await scrape(), 'supporthub_problems_created_total', {
+      category_id: 'uncategorized',
+    });
+    await createTicket();
+    const after = metricValue(await scrape(), 'supporthub_problems_created_total', {
+      category_id: 'uncategorized',
+    });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts a knowledge-search tool call that finds nothing as unmatched', async () => {
+    const ticketId = await createTicket();
+    const session = await sessionRepository.create(ticketId);
+
+    const before = metricValue(await scrape(), 'supporthub_knowledge_retrieval_outcomes_total', {
+      matched: 'false',
+    });
+    await toolsService.proposeAndEvaluate(
+      session.id,
+      [
+        {
+          type: 'tool_use',
+          caller: { type: 'direct' },
+          id: `toolu_${Date.now()}`,
+          name: 'searchProductKnowledge',
+          input: { feature: `nonexistent-feature-${Date.now()}` },
+        },
+      ],
+      { ticketId, productId },
+    );
+    const after = metricValue(await scrape(), 'supporthub_knowledge_retrieval_outcomes_total', {
+      matched: 'false',
+    });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts a tool invocation that fails at execution time', async () => {
+    const ticketId = await createTicket();
+    const session = await sessionRepository.create(ticketId);
+
+    const before = metricValue(await scrape(), 'supporthub_tool_invocations_total', {
+      tool: 'getTicketSnapshot',
+      outcome: 'failed',
+    });
+    await toolsService.proposeAndEvaluate(
+      session.id,
+      [
+        {
+          type: 'tool_use',
+          caller: { type: 'direct' },
+          id: `toolu_${Date.now()}`,
+          name: 'getTicketSnapshot',
+          input: {},
+        },
+      ],
+      { ticketId: 'nonexistent-ticket-id', productId },
+    );
+    const after = metricValue(await scrape(), 'supporthub_tool_invocations_total', {
+      tool: 'getTicketSnapshot',
+      outcome: 'failed',
+    });
+
+    expect(after).toBe(before + 1);
+  });
+
+  it('counts a valid known-error-code lookup', async () => {
+    const code = `METRICS-ERR-${Date.now()}`;
+    await errorCodesService.createErrorCode(productId, code, 'A test error for metrics.');
+
+    const before = metricValue(await scrape(), 'supporthub_known_error_lookups_total', { code });
+    await errorCodesService.findKnownIssuesByErrorCode(productId, code);
+    const after = metricValue(await scrape(), 'supporthub_known_error_lookups_total', { code });
+
+    expect(after).toBe(before + 1);
+  });
+});

tests/unit/observability/sla-compliance-metric.test.ts

@@ -0,0 +1,58 @@
+import { describe, it, expect, vi, beforeEach } from 'vitest';
+import { SlaService } from '@/modules/orchestration/sla/service/sla.service';
+import * as observability from '@/infrastructure/observability';
+
+function fakeRun(overrides: Partial<Record<string, unknown>> = {}) {
+  return {
+    id: 'run-1',
+    ticketId: 'ticket-1',
+    status: 'running',
+    ...overrides,
+  };
+}
+
+describe('SLA compliance metric (014-full-observability data-model.md #6)', () => {
+  beforeEach(() => {
+    vi.restoreAllMocks();
+  });
+
+  it('counts a run that completes while still running as met', async () => {
+    const incSpy = vi.spyOn(observability.slaRunOutcomesCounter, 'inc');
+    const runs = {
+      findByTicketId: vi.fn().mockResolvedValue(fakeRun({ status: 'running' })),
+      update: vi.fn().mockResolvedValue(undefined),
+    } as never;
+    const service = new SlaService(undefined, runs);
+
+    await service.complete('ticket-1');
+
+    expect(incSpy).toHaveBeenCalledWith({ outcome: 'met' });
+  });
+
+  it('does not double-count a run that was already breached before it resolved', async () => {
+    const incSpy = vi.spyOn(observability.slaRunOutcomesCounter, 'inc');
+    const runs = {
+      findByTicketId: vi.fn().mockResolvedValue(fakeRun({ status: 'breached' })),
+      update: vi.fn().mockResolvedValue(undefined),
+    } as never;
+    const service = new SlaService(undefined, runs);
+
+    await service.complete('ticket-1');
+
+    expect(incSpy).not.toHaveBeenCalledWith({ outcome: 'met' });
+  });
+
+  it('does not count anything for a run already completed', async () => {
+    const incSpy = vi.spyOn(observability.slaRunOutcomesCounter, 'inc');
+    const runs = {
+      findByTicketId: vi.fn().mockResolvedValue(fakeRun({ status: 'completed' })),
+      update: vi.fn().mockResolvedValue(undefined),
+    } as never;
+    const service = new SlaService(undefined, runs);
+
+    await service.complete('ticket-1');
+
+    expect(incSpy).not.toHaveBeenCalled();
+    expect((runs as unknown as { update: ReturnType<typeof vi.fn> }).update).not.toHaveBeenCalled();
+  });
+});