feat(freight-api): enrich canonical request log line

Emit the request line as raw JSON on stdout (level/time/logger as fields)
instead of through Nest's console logger, whose prefix made it unparsable.

Collect data points via logCtx at the flow chokepoints: BaseRepository
writes (status changes, creates, deletes), invoice transitions, payment
intent lifecycle + outbound payment-service calls, booking/contract entry
state, review-note reasons, signatures and OTP verify outcomes.

apps/edr-freight-api/src/common/request-log-context.spec.ts

@@ -1,5 +1,7 @@
 import { Logger } from "@nestjs/common";
+import type { Repository } from "typeorm";
 import {
+  BaseRepository,
   RequestLogMiddleware,
   getLogContext,
   logCtx,
@@ -47,10 +49,13 @@ describe("logCtx", () => {
 
 describe("RequestLogMiddleware", () => {
   it("emits one canonical JSON line carrying the collected context", () => {
+    // Raw stdout, not the Nest logger — the line must be parsable JSON with no
+    // "[Nest] … LOG [request]" prefix in front of it.
     const lines: string[] = [];
-    jest
-      .spyOn(Logger.prototype, "warn")
-      .mockImplementation((m) => lines.push(String(m)));
+    jest.spyOn(process.stdout, "write").mockImplementation((chunk) => {
+      lines.push(String(chunk));
+      return true;
+    });
     jest.spyOn(Logger.prototype, "log").mockImplementation(() => undefined);
 
     const listeners: Record<string, () => void> = {};
@@ -82,7 +87,11 @@ describe("RequestLogMiddleware", () => {
     listeners.close(); // aborts/close after finish must not double-log
 
     expect(lines).toHaveLength(1);
+    expect(lines[0].endsWith("\n")).toBe(true);
+    expect(lines[0].startsWith("{")).toBe(true);
     expect(JSON.parse(lines[0])).toMatchObject({
+      level: "warn",
+      logger: "request",
       type: "http_request",
       requestId: "req-42",
       method: "POST",
@@ -100,3 +109,38 @@ describe("RequestLogMiddleware", () => {
     jest.restoreAllMocks();
   });
 });
+
+describe("BaseRepository write trail", () => {
+  class TestRepo extends BaseRepository<{ id: string; status?: string }> {
+    constructor(repo: Repository<{ id: string; status?: string }>) {
+      super(repo);
+    }
+  }
+
+  const typeormRepo = {
+    metadata: { tableName: "booking" },
+    create: (data: unknown) => data,
+    save: async (data: unknown) => data,
+    update: async () => undefined,
+    findOne: async () => ({ id: "b-1", status: "SUBMITTED" }),
+    softDelete: async () => undefined,
+    delete: async () => undefined,
+  } as unknown as Repository<{ id: string; status?: string }>;
+
+  it("records creates, status changes and deletes without any service opting in", async () => {
+    const ctx = await runWithLogContext({}, async () => {
+      const repo = new TestRepo(typeormRepo);
+      await repo.create({ id: "b-1" });
+      await repo.update("b-1", { status: "SUBMITTED" });
+      await repo.update("b-1", { id: "b-1" }); // no status → no transition entry
+      await repo.softDelete("b-1");
+      return getLogContext();
+    });
+
+    expect(ctx).toEqual({
+      db: { created: { booking: 1 }, updated: { booking: 2 } },
+      statusChanges: [{ entity: "booking", id: "b-1", status: "SUBMITTED" }],
+      deleted: [{ entity: "booking", id: "b-1" }],
+    });
+  });
+});

apps/edr-freight-api/src/modules/billing/billing.service.ts

@@ -8,6 +8,7 @@ import {
   NotFoundException,
 } from "@nestjs/common";
 import { EventEmitter2 } from "@nestjs/event-emitter";
+import { logCtx } from "@edr/api-common";
 import { DataSource, EntityManager, In } from "typeorm";
 
 import { Booking } from "../bookings/entities/booking.entity";
@@ -951,6 +952,24 @@ export class BillingService {
 
       await mg.update(Invoice, { id: invoice.id }, { status, ...extra });
 
+      // Every invoice status move in the app funnels through here — money
+      // changing state is the single most-asked question in support.
+      logCtx(
+        {
+          invoiceId: invoice.id,
+          invoiceNumber: invoice.invoiceNumber,
+          source: invoice.source,
+          sourceId: invoice.sourceId,
+          from: invoice.status,
+          to: status,
+          event,
+          amount: Number(invoice.totalAmount),
+          currency: invoice.currency,
+          paymentId: extra.paymentId ?? invoice.paymentId ?? undefined,
+        },
+        { path: "invoiceTransitions", mode: "push" },
+      );
+
       const updated = { ...invoice, ...extra, status } as Invoice;
       return {
         result: updated,
@@ -1320,6 +1339,21 @@ export class BillingService {
       throw new BadRequestException("Invoice has no outstanding balance.");
     }
 
+    logCtx(
+      {
+        invoiceId: invoice.id,
+        invoiceNumber: invoice.invoiceNumber,
+        source: invoice.source,
+        sourceId: invoice.sourceId,
+        companyId: invoice.companyId,
+        amountDue,
+        currency: invoice.currency,
+        method: opts.method ?? "TELEBIRR",
+        platform: opts.platform,
+      },
+      { path: "payment.payInvoice" },
+    );
+
     // CAC Bank is an OTP debit — the bank SMSes the code to this number, so it is
     // required up front (the payment service rejects it otherwise, as a 502 here).
     if (
@@ -1443,7 +1477,24 @@ export class BillingService {
       // first on DESC, which would hand back an unissued invoice.
       order: { issuedAt: { direction: "DESC", nulls: "LAST" } },
     });
-    if (!invoice) return null;
+    if (!invoice) {
+      logCtx(
+        { paymentId, outcome: "no-invoice-for-payment" },
+        { path: "payment.settleInvoice" },
+      );
+      return null;
+    }
+
+    logCtx(
+      {
+        paymentId,
+        providerTxnId,
+        invoiceId: invoice.id,
+        invoiceNumber: invoice.invoiceNumber,
+        invoiceStatus: invoice.status,
+      },
+      { path: "payment.settleInvoice" },
+    );
 
     const settleable: Freight.InvoiceStatus[] = [
       ...OPEN_STATUSES,
@@ -1453,6 +1504,12 @@ export class BillingService {
       // Already PAID is the ordinary idempotent no-op (redelivery, or settled
       // inline by payInvoice). Anything else means money was captured with
       // nowhere to land — that needs a person, so say so loudly.
+      logCtx(
+        invoice.status === Freight.InvoiceStatus.Paid
+          ? "already-paid"
+          : "captured-with-nowhere-to-land",
+        { path: "payment.settleInvoice.outcome", mode: "set" },
+      );
       if (invoice.status !== Freight.InvoiceStatus.Paid) {
         this.logger.error(
           `Payment ${paymentId} succeeded but invoice ${invoice.invoiceNumber} ` +

apps/edr-freight-api/src/modules/bookings/bookings.repository.ts

@@ -1,4 +1,4 @@
-import { BaseRepository } from '@edr/api-common';
+import { BaseRepository, logCtx } from '@edr/api-common';
 import { SchedulingStatus } from '@edr/types';
 import { ConflictException, Injectable } from '@nestjs/common';
 import { InjectRepository } from '@nestjs/typeorm';
@@ -631,6 +631,13 @@ export class BookingsRepository extends BaseRepository<Booking> {
     authorId?: string,
   ): Promise<BookingReviewNote> {
     const repo = this.dataSource.getRepository(BookingReviewNote);
+    // Every rejection/cancellation/change-request reason in the booking flow is
+    // written through here — the "why" behind the status change on the same log
+    // line as the status change itself.
+    logCtx(
+      { bookingId, type, note, authorId },
+      { path: 'reviewNotes', mode: 'push' },
+    );
     return repo.save(
       repo.create({ bookingId, note, type, authorId: authorId ?? null }),
     );

apps/edr-freight-api/src/modules/bookings/bookings.service.ts

@@ -9,7 +9,7 @@ import {
   NotFoundException,
 } from '@nestjs/common';
 import { Freight, SchedulingStatus } from '@edr/types';
-import { insertWithGeneratedReference } from '@edr/api-common';
+import { insertWithGeneratedReference, logCtx } from '@edr/api-common';
 // import { CustomersService } from '../customers/customers.service';
 import { CompaniesService } from '../companies/companies.service';
 import { CompanyKind, CompanyStatus } from '../companies/entities/company.entity';
@@ -2115,6 +2115,21 @@ export class BookingsService {
       throw new NotFoundException(`Booking ${id} not found`);
     }
 
+    // Nearly every booking flow loads the booking through here, so this one
+    // call puts the human-searchable reference + entry state on the request log
+    // line for all of them. Entry state only — the write trail (statusChanges)
+    // shows where it ended up.
+    logCtx(
+      {
+        id: booking.id,
+        reference: booking.reference,
+        statusAtEntry: booking.status,
+        companyId: booking.companyId,
+        contractId: booking.contractId ?? undefined,
+      },
+      { path: "booking" },
+    );
+
     if (booking.files && booking.files.length > 0) {
       booking.files = await Promise.all(
         booking.files.map(async (file: FileRecord) => {

apps/edr-freight-api/src/modules/contracts/contract-transition.service.ts

@@ -9,7 +9,7 @@ import { InjectDataSource } from '@nestjs/typeorm';
 import { DataSource } from 'typeorm';
 import { randomUUID } from 'node:crypto';
 import { Readable } from 'stream';
-import { insertWithGeneratedReference } from '@edr/api-common';
+import { insertWithGeneratedReference, logCtx } from '@edr/api-common';
 import type { TCurrentUser } from '@tria-plc/api-common/modules/auth/types/current-user.type';
 
 import { ContractDocumentViewModelBuilder } from '../../contracts/contract-document-view-model.builder';
@@ -1084,6 +1084,19 @@ export class ContractTransitionService {
   ): Promise<void> {
     const role = dto.role as ContractSignerRole;
 
+    // Both sign() and counterSign() land here — who signed what, and whether the
+    // ink came from the request or the signer's saved profile signature.
+    logCtx(
+      {
+        contractId: contract.id,
+        reference: contract.reference,
+        role,
+        signerUserId: options.signerUserId,
+        usedDrawnImage: Boolean(dto.signatureImageBase64),
+      },
+      { path: "contractSignatures", mode: "push" },
+    );
+
     // Resolve the signature image. The client may send a freshly-drawn image, or
     // omit it to reuse the signer's saved profile signature. Fall back to the
     // saved one whenever no image is supplied.

apps/edr-freight-api/src/modules/contracts/contracts.service.ts

@@ -7,7 +7,7 @@ import {
 } from '@nestjs/common';
 import { InjectDataSource } from '@nestjs/typeorm';
 import { DataSource } from 'typeorm';
-import { insertWithGeneratedReference } from '@edr/api-common';
+import { insertWithGeneratedReference, logCtx } from '@edr/api-common';
 
 import { YardCountry } from '@edr/types';
 //
@@ -811,6 +811,18 @@ export class ContractsService {
       throw new NotFoundException(`Contract ${id} not found`);
     }
 
+    // Entry state for every contract flow (submit, approve, sign, suspend…) —
+    // see the equivalent in BookingsService.findById.
+    logCtx(
+      {
+        id: contract.id,
+        reference: contract.reference,
+        statusAtEntry: contract.status,
+        companyId: contract.companyId,
+      },
+      { path: "contract" },
+    );
+
     if (contract.files && contract.files.length > 0) {
       contract.files = await Promise.all(
         contract.files.map(async (file: FileRecord) => {

apps/edr-freight-api/src/modules/otp/otp.service.ts

@@ -1,6 +1,7 @@
 // otp.service.ts
 
 import { BadRequestException, Injectable, Logger } from "@nestjs/common";
+import { logCtx } from "@edr/api-common";
 import { randomInt } from "node:crypto";
 
 import { OtpRepository } from "./otp.repository";
@@ -317,6 +318,13 @@ export class OtpService {
       }`;
     if (result === "ok") this.logger.log(line);
     else this.logger.warn(line);
+
+    // Outcome only — the target is a phone number / email address and stays out
+    // of the canonical line. Channels are safe and say which one was used.
+    logCtx(
+      { mode, result, channels: channelsOf(target) },
+      { path: "otp.verify", mode: "push" },
+    );
   }
 
   /**

apps/edr-freight-api/src/modules/payment/payment-client.service.ts

@@ -7,6 +7,7 @@ import {
 import { HttpService } from "@nestjs/axios";
 import { AxiosError } from "axios";
 import { firstValueFrom } from "rxjs";
+import { logCtx } from "@edr/api-common";
 import {
   InitiatePaymentRequest,
   PaymentIntentSnapshot,
@@ -111,6 +112,16 @@ export class PaymentClientService {
     body?: unknown,
   ): Promise<T> {
     const url = `${this.baseUrl}${path}`;
+    // Every hop to the payment service lands on the request log line: which
+    // call, how slow, and what it answered. A settle that never happened is
+    // almost always one of these coming back 4xx/5xx or timing out.
+    const startedAt = Date.now();
+    const trace = (extra: Record<string, unknown>) =>
+      logCtx(
+        { method, path, ms: Date.now() - startedAt, ...extra },
+        { path: "outbound.payment", mode: "push" },
+      );
+
     try {
       const response = await firstValueFrom(
         this.http.request<T>({
@@ -122,9 +133,11 @@ export class PaymentClientService {
             : {},
         }),
       );
+      trace({ status: response.status });
       return response.data;
     } catch (err) {
       if (err instanceof AxiosError && err.response) {
+        trace({ status: err.response.status });
         if (err.response.status === 404) throw err;
         const detail =
           (err.response.data as { message?: string | string[] })?.message ??
@@ -136,6 +149,7 @@ export class PaymentClientService {
       }
       const message =
         err instanceof Error && err.message ? err.message : String(err);
+      trace({ unreachable: true, error: message });
       this.logger.error(
         `payment service unreachable (${method} ${path}): ${message}`,
       );

apps/edr-freight-api/src/modules/payment/payment.service.ts

@@ -7,6 +7,7 @@ import {
   Logger,
   NotFoundException,
 } from "@nestjs/common";
+import { logCtx } from "@edr/api-common";
 import { applyBookingRefDirectionScope } from "../user-trade-access/trade-scope.util";
 import { PaymentEntity } from "./entities/payment.entity";
 import { PaymentRepository } from "./payment.repository";
@@ -214,8 +215,16 @@ export class PaymentService {
         PaymentReferenceType.SHIPMENT,
         referenceId,
       );
+      logCtx(
+        { referenceId, paid: result.paid, unverifiable: result.unverifiable },
+        { path: "payment.reconcile" },
+      );
       return { paid: result.paid, unverifiable: result.unverifiable };
     } catch (err) {
+      logCtx(
+        { referenceId, unverifiable: true, error: (err as Error).message },
+        { path: "payment.reconcile" },
+      );
       this.logger.warn(
         `Reconcile for shipment ${referenceId} failed: ${(err as Error).message}`,
       );
@@ -224,6 +233,18 @@ export class PaymentService {
   }
 
   async initiate(input: InitiateIntentInput): Promise<InitiateIntentResult> {
+    logCtx(
+      {
+        referenceId: input.referenceId,
+        source: input.source,
+        orderRef: input.orderRef,
+        method: input.method,
+        amountMinor: input.amountMinor,
+        currency: input.currency,
+        platform: input.platform,
+      },
+      { path: "payment.initiate" },
+    );
     try {
       const isCbeBill = input.method === ProviderMethod.CBE_BILL;
       // CBE settles ETB only (docs/cbe/CBE_IMPLEMENTATION_PLAN.md D8).
@@ -268,6 +289,17 @@ export class PaymentService {
 
       const intent = await this.upsertIntent(input, snapshot);
 
+      logCtx(
+        {
+          intentId: intent.id,
+          providerStatus: snapshot.status,
+          providerTxnId: snapshot.providerTxnId,
+          merchantOrderId: snapshot.merchantOrderId,
+          immediateSuccess,
+        },
+        { path: "payment.initiate" },
+      );
+
       if (immediateSuccess) {
         // Settle the projection but DO NOT notify billing — billing settles
         // inline once it has stored intentId on the invoice (see payInvoice),
@@ -428,6 +460,17 @@ export class PaymentService {
       otp,
     );
 
+    logCtx(
+      {
+        intentId: local.id,
+        refId: local.refId,
+        gatewayIntentId: snapshot.intentId,
+        providerStatus: confirmed.status,
+        failureCode: confirmed.failureCode,
+      },
+      { path: "payment.confirmOtp" },
+    );
+
     if (confirmed.status === ProviderPaymentStatus.SUCCEEDED) {
       await this.markIntentSucceeded(local.id, {
         providerTxnId: confirmed.providerTxnId,
@@ -460,6 +503,16 @@ export class PaymentService {
   ): Promise<{ alreadyFinalized: boolean }> {
     const intent = await this.paymentRepo.findOneBy({ id: intentId });
     if (!intent) throw new NotFoundException("PaymentIntent not found");
+    logCtx(
+      {
+        intentId,
+        refId: intent.refId,
+        priorStatus: intent.status,
+        providerTxnId: opts.providerTxnId,
+        notifyBilling: opts.notify !== false,
+      },
+      { path: "payment.settle" },
+    );
     if (intent.status === "success") {
       // Still notify billing: a prior delivery may have flipped the intent to
       // success and then died before the invoice settled (the two steps are not
@@ -471,6 +524,7 @@ export class PaymentService {
           opts.paidAt ?? intent.paidAt ?? undefined,
         );
       }
+      logCtx(true, { path: "payment.settle.alreadyFinalized", mode: "set" });
       return { alreadyFinalized: true };
     }
 
@@ -507,6 +561,15 @@ export class PaymentService {
     referenceId: string,
   ): Promise<{ acknowledged: boolean }> {
     const intent = await this.paymentRepo.findOneBy({ refId: referenceId });
+    logCtx(
+      {
+        referenceId,
+        intentId: intent?.id,
+        intentStatus: intent?.status ?? "none",
+        method: intent?.method,
+      },
+      { path: "payment.successRedirect" },
+    );
     if (!intent || intent.method === "cbe-bill") {
       return { acknowledged: false };
     }
@@ -533,6 +596,16 @@ export class PaymentService {
   }): Promise<void> {
     const intent = await this.paymentRepo.findOneBy({ id: input.intentId });
     if (!intent) throw new NotFoundException("PaymentIntent not found");
+    logCtx(
+      {
+        intentId: intent.id,
+        refId: intent.refId,
+        priorStatus: intent.status,
+        failureCode: input.failureCode,
+        failureMessage: input.failureMessage,
+      },
+      { path: "payment.failed" },
+    );
     if (intent.status === "success" || intent.status === "canceled") return;
 
     await this.paymentRepo.update(