PR: Jobberknoll logging, environment and infrastructure improvements (#…

…52)

* Document Jobberknoll progress

* Improve logging and environment reading

* Redact data in prod

* Move requestId override to a middleware

* Add logging middleware to the API layer

* Add instrumentation to AccountRepo

* Refactor Logger

* Simplify LogMethod registration

* Simplify hooks.ts

* Add safety notices to all casts

* Expand safety notice for authorization

* Add missing comments

* Fix lint errors

implementation/jobberknoll/README.md

@@ -0,0 +1,53 @@
+# Jobberknoll
+
+## Requirements
+
+| **Requirement** | **Status** |
+| --------------- | ---------- |
+| `ACC/01`        | 🟥         |
+| `ACC/02`        | 🟥         |
+| `ACC/04`        | 🟥         |
+| `ACC/05`        | 🟥         |
+| `ACC/06`        | 🟥         |
+| `ACC/10`        | 🟥         |
+| `ACC/11`        | 🟨         |
+| `ACC/12`        | 🟨         |
+| `ACC/13`        | 🟥         |
+| `ACC/14`        | 🟩         |
+| `ACC/15`        | 🟩         |
+| `ACC/16`        | 🟥         |
+
+## API
+
+| **Endpoint**                   | **Status** |
+| ------------------------------ | ---------- |
+| `POST   /ext/v1/register`      | 🟥         |
+| `POST   /ext/v1/login`         | 🟥         |
+| `POST   /ext/v1/refresh`       | 🟥         |
+| `POST   /ext/v1/revoke`        | 🟥         |
+| `GET    /ext/v1/self`          | 🟥         |
+| `PUT    /ext/v1/self/name`     | 🟥         |
+| `PUT    /ext/v1/self/password` | 🟥         |
+| `PUT    /ext/v1/self/phone`    | 🟥         |
+| `DELETE /ext/v1/self`          | 🟥         |
+| `POST   /ext/v1/accounts`      | 🟨         |
+| `GET    /ext/v1/accounts`      | 🟥         |
+| `GET    /ext/v1/accounts/:id`  | 🟩         |
+| `DELETE /ext/v1/accounts/:id`  | 🟩         |
+| `GET    /int/v1/health`        | 🟩         |
+| `GET    /int/v1/endpoints`     | 🟥         |
+| `GET    /int/v1/accounts/:id`  | 🟩         |
+| `GET    /int/v1/jwks`          | 🟥         |
+
+## Infrastructure
+
+| **Integration**                 | **Status** |
+| ------------------------------- | ---------- |
+| Account Repository (PostgreSQL) | 🟩         |
+| Email Sending Service (AWS SQS) | 🟥         |
+| Logging                         | 🟨         |
+
+## ADRs
+
+- [ADR/001: Vertical partitioning of the Jobberknoll API package structure](../../documentation/adrs/001-jobberknoll-api-structure.md)
+- [ADR/002: Domain model and database schema changes for Jobberknoll](../../documentation/adrs/002-jobberknoll-domain-model.md)

implementation/jobberknoll/api/ext/authorization.ts

@@ -3,7 +3,7 @@ import { USER_ROLES, type UserRole } from "@jobberknoll/app";
 import type { UserUnauthorizedDto } from "~/ext/contracts/mod.ts";
 
 function isValid(expectedRole: UserRole | "member", userRole: string | undefined): boolean {
-  if (!USER_ROLES.includes(userRole as UserRole)) return false;
+  if (!USER_ROLES.includes(userRole as UserRole)) return false; // SAFETY: even if userRole is not a valid UserRole, the check will fail and will never throw (https://github.com/microsoft/TypeScript/issues/26255)
   if (expectedRole === "member") return userRole !== "guest";
   return userRole === expectedRole;
 }
@@ -23,8 +23,8 @@ export function authorize<R extends RouteConfig>(
         kind: "user-unauthorized",
         messageEn: "The user does not have access to the resource.",
         messagePl: "Użytkownik nie ma dostępu do tego zasobu.",
-      } as UserUnauthorizedDto,
+      } satisfies UserUnauthorizedDto,
       401,
-    ) as unknown as ReturnType<RouteHandler<R>>;
+    ) as unknown as ReturnType<RouteHandler<R>>; // SAFETY: the callers of authorize are expected to add UserUnauthorizedDto to the response, even if they don't, it won't ever throw, but the OpenAPI spec will be incomplete
   };
 }

implementation/jobberknoll/api/ext/ext-controller.ts

@@ -1,20 +1,18 @@
-import { OpenAPIHono } from "@hono/zod-openapi";
+import type { OpenAPIHono } from "@hono/zod-openapi";
 import type { Logger, Service } from "@jobberknoll/app";
 import { SERVICE_VERSION } from "@jobberknoll/core/shared";
 import type { Controller } from "~/shared/controller.ts";
 import { configureDocs } from "~/shared/docs.ts";
-import { configureErrorHandler, defaultHook } from "~/shared/hooks.ts";
+import { createOpenAPIHono } from "~/shared/hooks.ts";
 import * as r from "./routes/mod.ts";
 
 export class ExtController implements Controller {
   public constructor(private readonly service: Service, private readonly logger: Logger) {}
 
-  public get prefix(): string {
-    return "/ext/v1";
-  }
+  public readonly prefix = "/ext/v1";
 
   public get routes(): OpenAPIHono {
-    const app = new OpenAPIHono({ defaultHook })
+    const app = createOpenAPIHono(this.logger)
       .openapi(
         r.createAccountRoute,
         r.createAccountHandler(this.service.createAccount),
@@ -28,8 +26,6 @@ export class ExtController implements Controller {
         r.deleteAccountHandler(this.service.deleteAccount),
       );
 
-    configureErrorHandler(app, this.logger);
-
     configureDocs(app, {
       path: this.prefix,
       title: "Jobberknoll External API",

implementation/jobberknoll/api/int/int-controller.ts

@@ -1,20 +1,18 @@
-import { OpenAPIHono } from "@hono/zod-openapi";
+import type { OpenAPIHono } from "@hono/zod-openapi";
 import type { Logger, Service } from "@jobberknoll/app";
 import { SERVICE_VERSION } from "@jobberknoll/core/shared";
 import type { Controller } from "~/shared/controller.ts";
 import { configureDocs } from "~/shared/docs.ts";
-import { configureErrorHandler, defaultHook } from "~/shared/hooks.ts";
+import { createOpenAPIHono } from "~/shared/hooks.ts";
 import * as r from "./routes/mod.ts";
 
 export class IntController implements Controller {
   public constructor(private readonly service: Service, private readonly logger: Logger) {}
 
-  public get prefix(): string {
-    return "/int/v1";
-  }
+  public readonly prefix = "/int/v1";
 
   public get routes(): OpenAPIHono {
-    const app = new OpenAPIHono({ defaultHook })
+    const app = createOpenAPIHono(this.logger)
       .openapi(
         r.getHealthRoute,
         r.getHealthHandler(this.service.getHealth),
@@ -24,8 +22,6 @@ export class IntController implements Controller {
         r.getAccountByIdHandler(this.service.getAccountById),
       );
 
-    configureErrorHandler(app, this.logger);
-
     configureDocs(app, {
       path: this.prefix,
       title: "Jobberknoll Internal API",

implementation/jobberknoll/api/shared/hooks.ts

@@ -1,9 +1,13 @@
-import type { Hook, OpenAPIHono } from "@hono/zod-openapi";
+import { type Hook, OpenAPIHono } from "@hono/zod-openapi";
 import type { Logger } from "@jobberknoll/app";
+import { expect } from "@jobberknoll/core/shared";
+import { pick } from "@std/collections";
 import type { Env } from "hono";
+import { createMiddleware } from "hono/factory";
+import { isNone, uuid } from "../../core/shared/mod.ts";
 import { type SchemaMismatchDto, ServerFailureDto } from "./contracts/mod.ts";
 
-export const defaultHook: Hook<unknown, Env, string, unknown> = (res, c) => {
+const defaultHook: Hook<unknown, Env, string, unknown> = (res, c) => {
   if (!res.success) {
     return c.json(
       {
@@ -17,7 +21,41 @@ export const defaultHook: Hook<unknown, Env, string, unknown> = (res, c) => {
   }
 };
 
-export function configureErrorHandler(app: OpenAPIHono, logger: Logger) {
+const requestIdMiddleware = createMiddleware(async (c, next) => {
+  const HEADER_NAME = "jp-request-id";
+  const requestId = c.req.header(HEADER_NAME);
+  if (!requestId || isNone(uuid(requestId))) {
+    const headers = new Headers(c.req.raw.headers);
+    headers.set(HEADER_NAME, uuid());
+    c.req.raw = new Request(c.req.raw, { headers });
+  }
+  await next();
+});
+
+function loggingMiddlewareFactory(logger: Logger) {
+  const extractBody = (r: Request | Response): Promise<unknown | undefined> => r.clone().json().catch(() => undefined);
+  return createMiddleware(async (c, next) => {
+    const requestId = expect(
+      uuid(c.req.header("jp-request-id") ?? ""),
+      "requestId should be always set by requestIdMiddleware",
+    );
+    logger.debug(requestId, "http request - start", {
+      method: c.req.method,
+      route: c.req.routePath,
+      url: new URL(c.req.url).pathname + new URL(c.req.url).search,
+      headers: pick(c.req.header(), ["jp-request-id", "jp-user-id", "jp-user-role", "user-agent", "content-type"]),
+      body: await extractBody(c.req.raw),
+    });
+    await next();
+    logger.debug(requestId, "http request - end", {
+      status: c.res.status,
+      headers: pick(Object.fromEntries(c.res.headers.entries()), ["content-type"]),
+      body: await extractBody(c.res),
+    });
+  });
+}
+
+function configureErrorHandler(app: OpenAPIHono, logger: Logger) {
   app.openAPIRegistry.register("ServerFailureDto", ServerFailureDto);
   app.onError((err, c) => {
     logger.error(null, "onError", { err: err.message });
@@ -32,3 +70,11 @@ export function configureErrorHandler(app: OpenAPIHono, logger: Logger) {
     );
   });
 }
+
+export function createOpenAPIHono(logger: Logger): OpenAPIHono {
+  const app = new OpenAPIHono({ defaultHook });
+  app.use(requestIdMiddleware);
+  app.use(loggingMiddlewareFactory(logger));
+  configureErrorHandler(app, logger);
+  return app;
+}

implementation/jobberknoll/api/shared/openapi.ts

@@ -39,7 +39,9 @@ export const UuidSchema = z.string().uuid().transform((id, ctx) => {
   return option.value;
 });
 
-export const RequestIdSchema = UuidSchema.optional().transform((id) => id ?? uuid())
+export const RequestIdSchema = UuidSchema
+  .optional()
+  .transform((id) => id!) // SAFETY: requestId is defined as long as requestIdMiddleware is used (so in all requests)
   .openapi({ description: "Request ID as UUIDv7.", examples: [uuid()] });
 
 export const UserAgentSchema = z.string().optional().openapi({

implementation/jobberknoll/app/interfaces/account-repo.ts

@@ -1,9 +1,45 @@
 import type { Account, AccountNotFoundError } from "@jobberknoll/core/domain";
 import type { Option, Result, UUID } from "@jobberknoll/core/shared";
+import type { Logger } from "./logger.ts";
 
-export type AccountRepo = {
-  createAccount(account: Account): Promise<void>;
-  isEmailTaken(email: string): Promise<boolean>;
-  getAccountById(id: UUID): Promise<Result<Account, AccountNotFoundError>>;
-  deleteAccount(id: UUID): Promise<Option<AccountNotFoundError>>;
-};
+export abstract class AccountRepo {
+  public constructor(private readonly logger: Logger) {}
+
+  // TODO: Currently, requestId is not passed to the AccountRepo, because UseCase discards it :(
+  // TODO: Also, this can be moved to a separate class, so that it can be reused by other infra classes
+  private instrument<A extends unknown[], R>(name: string, handler: (...a: A) => Promise<R>): (...a: A) => Promise<R> {
+    const method = `${this.constructor.name}#${name}`;
+    return async (...args) => {
+      this.logger.debug(null, `${method} - start`, { args });
+
+      const res = await handler.bind(this)(...args);
+
+      this.logger.debug(null, `${method} - end`, { res });
+      return res;
+    };
+  }
+
+  protected abstract handleCreateAccount(account: Account): Promise<void>;
+  public createAccount: (account: Account) => Promise<void> = this.instrument(
+    "createAccount",
+    this.handleCreateAccount,
+  );
+
+  protected abstract handleIsEmailTaken(email: string): Promise<boolean>;
+  public isEmailTaken: (email: string) => Promise<boolean> = this.instrument(
+    "isEmailTaken",
+    this.handleIsEmailTaken,
+  );
+
+  protected abstract handleGetAccountById(id: UUID): Promise<Result<Account, AccountNotFoundError>>;
+  public getAccountById: (id: UUID) => Promise<Result<Account, AccountNotFoundError>> = this.instrument(
+    "getAccountById",
+    this.handleGetAccountById,
+  );
+
+  protected abstract handleDeleteAccount(id: UUID): Promise<Option<AccountNotFoundError>>;
+  public deleteAccount: (id: UUID) => Promise<Option<AccountNotFoundError>> = this.instrument(
+    "deleteAccount",
+    this.handleDeleteAccount,
+  );
+}

implementation/jobberknoll/app/interfaces/logger.ts

@@ -0,0 +1,55 @@
+import type { UUID } from "@jobberknoll/core/shared";
+import { SERVICE_AGENT } from "@jobberknoll/core/shared";
+
+export type LogLevel = "debug" | "info" | "warn" | "error";
+
+type LogTags = Record<string, unknown>;
+
+export type LogData = {
+  service: string;
+  requestId: UUID | null;
+  time: number;
+  level: LogLevel;
+  event: string;
+  tags: LogTags;
+};
+
+type LogMethod = (
+  requestId: UUID | null,
+  event: string,
+  tags?: LogTags,
+) => void;
+
+// NOTE: Taken from https://github.com/pinojs/pino/blob/main/docs/api.md#levels
+const LEVELS = {
+  debug: 20,
+  info: 30,
+  warn: 40,
+  error: 50,
+};
+
+export abstract class Logger {
+  protected abstract get level(): LogLevel;
+
+  protected abstract handle(data: LogData): void | Promise<void>;
+
+  private logMethod(level: LogLevel): LogMethod {
+    return (requestId, event, tags = {}) => {
+      if (LEVELS[this.level] <= LEVELS[level]) {
+        void this.handle({
+          service: SERVICE_AGENT,
+          requestId,
+          time: Date.now(),
+          level,
+          event,
+          tags,
+        });
+      }
+    };
+  }
+
+  public debug: LogMethod = this.logMethod("debug");
+  public info: LogMethod = this.logMethod("info");
+  public warn: LogMethod = this.logMethod("warn");
+  public error: LogMethod = this.logMethod("error");
+}

implementation/jobberknoll/app/interfaces/mod.ts

@@ -1,2 +1,2 @@
 export * from "./account-repo.ts";
-export * from "./logging.ts";
+export * from "./logger.ts";

implementation/jobberknoll/app/mod.ts

@@ -1,4 +1,5 @@
 export * from "./interfaces/mod.ts";
+export * from "./security/mod.ts";
 export * from "./service.ts";
 export * from "./shared/mod.ts";
 export * from "./use-cases/mod.ts";

implementation/jobberknoll/app/security/hash.ts

@@ -0,0 +1,8 @@
+import { encodeHex } from "@std/encoding";
+
+export async function sha256(input: string): Promise<string> {
+  const encoder = new TextEncoder();
+  const data = encoder.encode(input);
+  const buffer = await crypto.subtle.digest("SHA-256", data);
+  return encodeHex(buffer);
+}

implementation/jobberknoll/app/security/mod.ts

@@ -0,0 +1,2 @@
+export * from "./hash.ts";
+export * from "./redaction.ts";