From de5915a8c1f5577936938cc15b71f41aefb63413 Mon Sep 17 00:00:00 2001 From: saqib mir Date: Tue, 8 Sep 2026 15:57:47 +0530 Subject: [PATCH] feat(014-full-observability): remaining business metrics (first response, resolution, SLA, errors, tools) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 --- .../knowledge/service/error-codes.service.ts | 6 + .../ai-support/tools/service/tools.service.ts | 13 + .../orchestration/sla/service/sla.service.ts | 10 + .../messages/service/messages.service.ts | 23 +- .../observability/business-metrics.test.ts | 359 ++++++++++++++++++ .../sla-compliance-metric.test.ts | 58 +++ 6 files changed, 468 insertions(+), 1 deletion(-) create mode 100644 tests/integration/observability/business-metrics.test.ts create mode 100644 tests/unit/observability/sla-compliance-metric.test.ts diff --git a/src/modules/ai-support/knowledge/service/error-codes.service.ts b/src/modules/ai-support/knowledge/service/error-codes.service.ts index 3570e9c..5ce039e 100644 --- a/src/modules/ai-support/knowledge/service/error-codes.service.ts +++ b/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 { 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); } } diff --git a/src/modules/ai-support/tools/service/tools.service.ts b/src/modules/ai-support/tools/service/tools.service.ts index 94d041c..8b7e9ba 100644 --- a/src/modules/ai-support/tools/service/tools.service.ts +++ b/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 }; diff --git a/src/modules/orchestration/sla/service/sla.service.ts b/src/modules/orchestration/sla/service/sla.service.ts index 10f6afa..2eaeaec 100644 --- a/src/modules/orchestration/sla/service/sla.service.ts +++ b/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'); } diff --git a/src/modules/ticketing/messages/service/messages.service.ts b/src/modules/ticketing/messages/service/messages.service.ts index 605eb3c..26a4aa9 100644 --- a/src/modules/ticketing/messages/service/messages.service.ts +++ b/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 { - 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 { diff --git a/tests/integration/observability/business-metrics.test.ts b/tests/integration/observability/business-metrics.test.ts new file mode 100644 index 0000000..5f48b15 --- /dev/null +++ b/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 { + 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 { + 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): 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); + }); +}); diff --git a/tests/unit/observability/sla-compliance-metric.test.ts b/tests/unit/observability/sla-compliance-metric.test.ts new file mode 100644 index 0000000..7f782d0 --- /dev/null +++ b/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> = {}) { + 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 }).update).not.toHaveBeenCalled(); + }); +});