diff --git a/AGENTS.md b/AGENTS.md index 56d3769f84..fd76b2f91b 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -28,8 +28,10 @@ npm ci ### Dev servers ```bash +npm run dev # builds shared once, then runs api/app/web npm run dev --workspace @doenet-tools/api # Express API on port 3000 npm run dev --workspace @doenet-tools/app # Vite dev server on port 8000 (proxies /api to port 3000) +npm run watch --workspace @doenet-tools/shared # shared TypeScript watcher when needed ``` ### Build diff --git a/README.md b/README.md index 4ea46e0dd3..4ea8c8391c 100644 --- a/README.md +++ b/README.md @@ -19,28 +19,21 @@ We would love to hear from you! Join our [Discord](https://discord.gg/PUduwtKJ5h ### Steps -**1. Clone the repository** - -```bash -git clone https://github.com/Doenet/DoenetTools.git -cd DoenetTools -``` - -**2. Install dependencies** +**1. Install dependencies** ```bash npm install ``` -**3. Create the `.env` file** +**2. Create the un-tracked `.env` file** ```bash npm run setup ``` -This copies `apps/api/.env.example` to `apps/api/.env`. The defaults work for local development, but edit as needed (e.g. change `DATABASE_HOST`, `DATABASE_PORT`, or `DATABASE_PASSWORD` if your MySQL setup differs — and update `DATABASE_URL` to match). +This file (`apps/api/.env`) contains secrets like the database password and database url. -**4. Start the database** +**3. Start the database** ```bash docker compose --env-file apps/api/.env up -d @@ -48,7 +41,7 @@ docker compose --env-file apps/api/.env up -d Wait until the MySQL container shows `(healthy)` in `docker container ls` before continuing. -**5. Setup the database tables** +**4. Setup the database tables** ```bash npm run db:setup @@ -56,9 +49,9 @@ npm run db:setup This creates the required database tables and seeds them with minimal data. -**6. Start the dev servers** +**5. Start the dev servers** -All dev processes can be started together with a single command: +The main dev processes can be started together with a single command: ```bash npm run dev @@ -66,25 +59,20 @@ npm run dev This starts: -- Shared package watcher - Express API → http://localhost:3000 - React SPA → http://localhost:8000 (proxies `/api/*` to the API) - Astro site → http://localhost:4321 -This command first builds `shared` once, then starts its watch process alongside -the app, API, and web dev servers. - Alternatively, run each in a separate terminal if needed: ```bash -npm run dev --workspace @doenet-tools/shared # Shared package watcher +npm run build --workspace @doenet-tools/shared # Do this first npm run dev --workspace @doenet-tools/api # Express API npm run dev --workspace @doenet-tools/app # React SPA npm run dev --workspace @doenet-tools/web # Astro site +npm run watch --workspace @doenet-tools/shared # if making edits to this package ``` ---- - ## Repository Structure This repository is an npm workspace monorepo. Packages are organized into two directories: diff --git a/apps/api/.env.example b/apps/api/.env.example index f4ccf2c862..1b759e5c5b 100644 --- a/apps/api/.env.example +++ b/apps/api/.env.example @@ -1,12 +1,28 @@ +# ________________________________________________________ +# +# This is an example .env setup for local development. +# You can copy this to `.env` and edit values as needed. +# _________________________________________________________ +# +# To edit values for the production site, see +# `/infra/cloudformation/prod-doenet-taskdef-includes.yml` +# +# To edit values for deployed dev site (dev3), see +# `/infra/cloudformation/dev3-doenet-taskdef-includes.yml` + + + #General PORT="3000" -# Base URL of the frontend app -APP_URL="http://localhost:8000" +APP_URL="http://localhost:8000" # Base URL of the frontend app +LOG_LEVEL="info" #Flags +# Dev flags (only enable for local dev, not production) ENABLE_TEST_AUTH_BYPASS="true" ENABLE_TEST_ROUTES="true" MOCK_SIGNIN_EMAIL="true" +PRETTY_LOGS="true" #Database # DATABASE_URL must match the individual vars below. Update both if you change any connection details. @@ -33,4 +49,4 @@ MAGIC_LINK_SECRET="mysecret" DISCOURSE_URL="https://community.example.com" DISCOURSE_SSO_SECRET="mysecret" DISCOURSE_API_KEY="mysecret" -DISCOURSE_API_USERNAME="system" \ No newline at end of file +DISCOURSE_API_USERNAME="system" diff --git a/apps/api/package.json b/apps/api/package.json index 9aeaeda023..bd3c6d0e02 100644 --- a/apps/api/package.json +++ b/apps/api/package.json @@ -45,6 +45,7 @@ "passport-local": "^1.0.0", "passport-magic-link": "^2.1.1", "passport-strategy": "^1.0.0", + "pino-http": "^11.0.0", "prisma": "6.4.1", "short-uuid": "^5.2.0", "zod": "^4.0.14" @@ -59,6 +60,7 @@ "@types/passport-google-oauth20": "^2.0.16", "@types/passport-local": "^1.0.38", "@types/passport-strategy": "^0.2.38", + "pino-pretty": "^13.1.3", "vitest": "^3.2.4" }, "optionalDependencies": { diff --git a/apps/api/src/index.ts b/apps/api/src/index.ts index 4a1f0ddaaa..eeea4ab040 100644 --- a/apps/api/src/index.ts +++ b/apps/api/src/index.ts @@ -18,6 +18,7 @@ import { SESClient, SendEmailCommand } from "@aws-sdk/client-ses"; import { nanoid } from "nanoid"; import * as fs from "fs/promises"; import { fromUUID, toUUID } from "./utils/uuid"; +import { formatApiReadyMessage } from "./utils/cli"; import { UserInfo, UserInfoWithEmail } from "./types"; import { findOrCreateUser, @@ -49,6 +50,7 @@ import { generateHandle } from "./utils/names"; import { codeRouter } from "./routes/code"; import { metricsRouter } from "./routes/metricsRoutes"; import { contentRouter } from "./routes/content.route"; +import { initRequestLogger } from "./middleware/requestLogger"; // Type assertion to work around passport type declaration issues // eslint-disable-next-line @typescript-eslint/no-explicit-any @@ -394,6 +396,7 @@ app.use( app.use(passport.initialize()); app.use(passport.session()); +app.use("/api", initRequestLogger()); const port = process.env.PORT || 3000; @@ -473,5 +476,6 @@ app.post( // ); app.listen(port, () => { - console.log(`[server]: Server is running at http://localhost:${port}`); + const localUrl = `http://localhost:${port}`; + console.log(formatApiReadyMessage(localUrl)); }); diff --git a/apps/api/src/logging/loggerConfig.ts b/apps/api/src/logging/loggerConfig.ts new file mode 100644 index 0000000000..0778d54508 --- /dev/null +++ b/apps/api/src/logging/loggerConfig.ts @@ -0,0 +1,88 @@ +export type LogLevel = + | "trace" + | "debug" + | "info" + | "warn" + | "error" + | "fatal" + | "silent"; + +export type LoggerConfigOptions = { + prettyIgnore?: string[]; + stream?: NodeJS.WritableStream; +}; + +const sensitiveHeaderPaths = [ + "req.headers.cookie", + "req.headers.authorization", + 'req.headers["proxy-authorization"]', + 'req.headers["x-api-key"]', + 'req.headers["x-auth-token"]', + 'req.headers["x-csrf-token"]', + 'req.headers["csrf-token"]', + 'res.headers["set-cookie"]', +]; + +/** + * Shared pino configuration for logs + */ +export function getApiLoggerOptions(options: LoggerConfigOptions = {}) { + const logLevel = getLogLevel(); + + return { + level: logLevel, + redact: { + paths: sensitiveHeaderPaths, + remove: true, + }, + stream: options.stream, + ...(shouldUsePrettyLogs(options) + ? getPrettyTransportOptions(logLevel, options.prettyIgnore) + : {}), + }; +} + +function getLogLevel(): LogLevel { + const logLevel = process.env.LOG_LEVEL?.trim().toLowerCase(); + return isLogLevel(logLevel) ? logLevel : "info"; +} + +function isLogLevel(logLevel: string | undefined): logLevel is LogLevel { + return ( + logLevel === "trace" || + logLevel === "debug" || + logLevel === "info" || + logLevel === "warn" || + logLevel === "error" || + logLevel === "fatal" || + logLevel === "silent" + ); +} + +function shouldUsePrettyLogs(options: LoggerConfigOptions) { + if (options.stream) { + return false; + } + + return process.env.PRETTY_LOGS?.trim().toLowerCase() === "true"; +} + +function getPrettyTransportOptions( + logLevel: LogLevel, + prettyIgnore: string[] | undefined, +) { + return { + transport: { + target: "pino-pretty", + options: { + colorize: true, + hideObject: true, + messageFormat: "{msg}", + timestampKey: "__pretty_timestamp_disabled__", + translateTime: "SYS:standard", + ...(logLevel === "silent" ? {} : { minimumLevel: logLevel }), + ...(prettyIgnore?.length ? { ignore: prettyIgnore.join(",") } : {}), + }, + }, + }; +} diff --git a/apps/api/src/middleware/requestLogger.ts b/apps/api/src/middleware/requestLogger.ts new file mode 100644 index 0000000000..a1909e2724 --- /dev/null +++ b/apps/api/src/middleware/requestLogger.ts @@ -0,0 +1,254 @@ +import type { NextFunction, Request, Response } from "express"; +import pinoHttp from "pino-http"; +import { + getApiLoggerOptions, + type LoggerConfigOptions, + type LogLevel, +} from "../logging/loggerConfig"; +import { fromUUID } from "../utils/uuid"; + +type LoggableObject = Record; +type SerializedRequest = { + headers?: Record; +} & Record; +type RequestWithLogger = Request & { + log: { + debug: (object: Record, message: string) => void; + }; +}; + +const noisyRequestHeaders = new Set([ + "accept", + "accept-encoding", + "accept-language", + "connection", + "dnt", + "sec-ch-ua", + "sec-ch-ua-mobile", + "sec-ch-ua-platform", + "sec-fetch-dest", + "sec-fetch-mode", + "sec-fetch-site", + "sec-gpc", + "user-agent", +]); + +/** + * Initialize the pino-http middleware for logging API requests. + * + * The middleware logs two events per API call + * 1) a start event as soon as a request enters the API (level: debug) + * 2) a completion event when the response ends (level: info/warn/error) + * + * Each log entry includes only the metadata fields we want. No sensitive data. + * LOG_LEVEL controls the minimum emitted log level in both local dev and prod. + */ +export function initRequestLogger(options: LoggerConfigOptions = {}) { + const httpLogger = pinoHttp({ + ...getApiLoggerOptions({ + ...options, + prettyIgnore: ["pid", "hostname"], + }), + customErrorMessage( + req: Request, + res: Response, + _err: Error, + responseTime?: number, + ) { + return getRequestCompletionMessage(req, res, responseTime); + }, + customErrorObject( + req: Request, + res: Response, + _err: Error, + loggableObject: LoggableObject, + ) { + return getRequestCompletionObject(req, res, loggableObject); + }, + customSuccessMessage(req: Request, res: Response, responseTime?: number) { + return getRequestCompletionMessage(req, res, responseTime); + }, + customSuccessObject( + req: Request, + res: Response, + loggableObject: LoggableObject, + ) { + return getRequestCompletionObject(req, res, loggableObject); + }, + customLogLevel(_req: Request, res: Response, err?: Error) { + return getRequestCompletionLogLevel(res, err); + }, + quietReqLogger: true, + serializers: { + req: sanitizeSerializedRequest, + }, + }); + + return (req: Request, res: Response, next: NextFunction) => { + httpLogger(req, res); + logRequestStart(req); + next(); + }; +} + +/** + * Pulls the safe request fields that we want to include in every lifecycle log. + */ +function getRequestMetadata(req: Request) { + const userId = getLoggedUserId(req); + + return { + anonymous: req.user?.isAnonymous ?? false, + authenticated: req.user !== undefined, + method: req.method, + route: getRequestRoute(req) ?? getRequestPath(req), + path: getRequestPath(req), + ...(userId ? { userId } : {}), + }; +} + +function getDurationMs(loggableObject: LoggableObject) { + const responseTime = loggableObject.responseTime; + + return typeof responseTime === "number" ? responseTime : undefined; +} + +function getRequestPath(req: Request) { + if (req.baseUrl || req.path) { + return `${req.baseUrl}${req.path}`; + } + + return (req.originalUrl || req.url).split("?")[0]; +} + +function getRequestRoute(req: Request) { + if (!req.route) { + return undefined; + } + + const routePath = req.route.path; + if (typeof routePath === "string") { + return `${req.baseUrl}${routePath}`; + } + + if (Array.isArray(routePath)) { + return routePath + .filter((path): path is string => typeof path === "string") + .map((path) => `${req.baseUrl}${path}`) + .join("|"); + } + + return undefined; +} + +function getRequestStartMessage(req: Request) { + return `START: ${req.method} ${getRequestPath(req)}`; +} + +function getRequestCompletionMessage( + req: Request, + res: Response, + responseTime?: number, +) { + const baseMessage = `${res.statusCode} ${req.method} ${getRequestPath(req)}`; + + if (responseTime === undefined) { + return baseMessage; + } + + return `${baseMessage} (${Math.round(responseTime)}ms)`; +} + +function getRequestCompletionLogLevel(res: Response, err?: Error): LogLevel { + if (res.statusCode >= 500 || err) { + return "error"; + } + + if (res.statusCode >= 400) { + return "warn"; + } + + return "info"; +} + +function sanitizeSerializedRequest(req: SerializedRequest) { + const { + params: _params, + query: _query, + remotePort: _remotePort, + ...rest + } = req; + + return { + ...rest, + ...(req.headers ? { headers: sanitizeRequestHeaders(req.headers) } : {}), + }; +} + +function sanitizeRequestHeaders(headers: Record) { + const sanitizedHeaders: Record = {}; + + for (const [headerName, value] of Object.entries(headers)) { + if (noisyRequestHeaders.has(headerName)) { + continue; + } + + if (headerName === "referer") { + const refererOrigin = getRefererOrigin(value); + + if (refererOrigin) { + sanitizedHeaders.referer = refererOrigin; + } + continue; + } + + sanitizedHeaders[headerName] = value; + } + + return sanitizedHeaders; +} + +function getRefererOrigin(referer: string) { + if (!URL.canParse(referer)) { + return undefined; + } + + return new URL(referer).origin; +} + +function getLoggedUserId(req: Request) { + const userId = req.user?.userId; + + if (typeof userId === "string") { + return userId; + } + + if (userId instanceof Uint8Array) { + return fromUUID(userId); + } + + return undefined; +} + +function logRequestStart(req: Request) { + (req as RequestWithLogger).log.debug( + { + ...getRequestMetadata(req), + event: "request_start", + }, + getRequestStartMessage(req), + ); +} + +function getRequestCompletionObject( + req: Request, + res: Response, + loggableObject: LoggableObject, +) { + return { + ...getRequestMetadata(req), + durationMs: getDurationMs(loggableObject), + event: "request_end", + statusCode: res.statusCode, + }; +} diff --git a/apps/api/src/test/loggerConfig.test.ts b/apps/api/src/test/loggerConfig.test.ts new file mode 100644 index 0000000000..fb200fe28b --- /dev/null +++ b/apps/api/src/test/loggerConfig.test.ts @@ -0,0 +1,50 @@ +import { afterEach, describe, expect, test } from "vitest"; +import { getApiLoggerOptions } from "../logging/loggerConfig"; + +const originalPrettyLogs = process.env.PRETTY_LOGS; + +describe("getApiLoggerOptions", () => { + afterEach(() => { + if (originalPrettyLogs === undefined) { + delete process.env.PRETTY_LOGS; + return; + } + + process.env.PRETTY_LOGS = originalPrettyLogs; + }); + + test("does not enable pretty logs by default", () => { + delete process.env.PRETTY_LOGS; + + const loggerOptions = getApiLoggerOptions(); + + expect(loggerOptions.transport).toBeUndefined(); + }); + + test("enables pretty logs only when PRETTY_LOGS=true", () => { + process.env.PRETTY_LOGS = "true"; + + const loggerOptions = getApiLoggerOptions({ + prettyIgnore: ["pid", "hostname"], + }); + + expect(loggerOptions.transport).toMatchObject({ + options: { + hideObject: true, + ignore: "pid,hostname", + messageFormat: "{msg}", + }, + target: "pino-pretty", + }); + }); + + test("keeps pretty logs disabled when a custom stream is provided", () => { + process.env.PRETTY_LOGS = "true"; + + const loggerOptions = getApiLoggerOptions({ + stream: process.stdout, + }); + + expect(loggerOptions.transport).toBeUndefined(); + }); +}); diff --git a/apps/api/src/test/requestLogger.test.ts b/apps/api/src/test/requestLogger.test.ts new file mode 100644 index 0000000000..f49dfbea11 --- /dev/null +++ b/apps/api/src/test/requestLogger.test.ts @@ -0,0 +1,274 @@ +import { EventEmitter } from "node:events"; +import { Writable } from "node:stream"; +import type { Request, Response } from "express"; +import { afterEach, describe, expect, test } from "vitest"; +import { initRequestLogger } from "../middleware/requestLogger"; +import { fromUUID, newUUID } from "../utils/uuid"; + +class MockResponse extends EventEmitter { + err?: Error; + headers: Record = {}; + headersSent = true; + statusCode = 200; + writableEnded = false; + + getHeaders() { + return this.headers; + } +} + +const originalLogLevel = process.env.LOG_LEVEL; + +function createMockRequest(overrides: Partial = {}) { + return { + baseUrl: "/api", + method: "GET", + originalUrl: "/api/health", + path: "/health", + url: "/health", + ...overrides, + } as Request; +} + +function createLogCapture() { + const lines: string[] = []; + const stream = new Writable({ + write(chunk, _encoding, callback) { + lines.push(chunk.toString()); + callback(); + }, + }); + + return { lines, stream }; +} + +function parseLogs(lines: string[]) { + return lines.map((line) => JSON.parse(line)); +} + +describe("initRequestLogger", () => { + afterEach(() => { + if (originalLogLevel === undefined) { + delete process.env.LOG_LEVEL; + return; + } + + process.env.LOG_LEVEL = originalLogLevel; + }); + + test("defaults to info and suppresses the debug start log", () => { + delete process.env.LOG_LEVEL; + + const { lines, stream } = createLogCapture(); + const middleware = initRequestLogger({ stream }); + const req = createMockRequest(); + const mockResponse = new MockResponse(); + const res = mockResponse as unknown as Response; + + middleware(req, res, () => {}); + + mockResponse.statusCode = 204; + mockResponse.writableEnded = true; + mockResponse.emit("finish"); + + const [endLog] = parseLogs(lines); + + expect(lines).toHaveLength(1); + expect(endLog).toMatchObject({ + event: "request_end", + level: 30, + route: "/api/health", + statusCode: 204, + }); + expect(endLog.durationMs).toBeGreaterThanOrEqual(0); + expect(endLog.msg).toBe( + `204 GET /api/health (${Math.round(endLog.durationMs)}ms)`, + ); + }); + + test("emits the request start log when LOG_LEVEL=debug", () => { + process.env.LOG_LEVEL = "debug"; + + const { lines, stream } = createLogCapture(); + const middleware = initRequestLogger({ stream }); + const userId = newUUID(); + const req = createMockRequest({ + method: "POST", + originalUrl: "/api/login/anonymous?token=secret", + path: "/login/anonymous", + url: "/login/anonymous?token=secret", + user: { + email: null, + firstNames: null, + isAnonymous: true, + lastNames: "", + userId, + } as unknown as Request["user"], + }); + const mockResponse = new MockResponse(); + const res = mockResponse as unknown as Response; + + middleware(req, res, () => {}); + + mockResponse.statusCode = 200; + mockResponse.writableEnded = true; + mockResponse.emit("finish"); + + const [startLog, endLog] = parseLogs(lines); + + expect(startLog).toMatchObject({ + anonymous: true, + authenticated: true, + event: "request_start", + method: "POST", + path: "/api/login/anonymous", + route: "/api/login/anonymous", + userId: fromUUID(userId), + }); + expect(endLog).toMatchObject({ + anonymous: true, + authenticated: true, + event: "request_end", + level: 30, + method: "POST", + path: "/api/login/anonymous", + route: "/api/login/anonymous", + statusCode: 200, + userId: fromUUID(userId), + }); + expect(endLog.msg).toBe( + `200 POST /api/login/anonymous (${Math.round(endLog.durationMs)}ms)`, + ); + }); + + test("logs 4xx responses at warn", () => { + delete process.env.LOG_LEVEL; + + const { lines, stream } = createLogCapture(); + const middleware = initRequestLogger({ stream }); + const req = createMockRequest({ + originalUrl: "/api/content/not-found?token=super-secret", + path: "/content/not-found", + url: "/content/not-found?token=super-secret", + }); + const mockResponse = new MockResponse(); + const res = mockResponse as unknown as Response; + + middleware(req, res, () => {}); + + Object.assign(req, { + baseUrl: "/api/content", + path: "/not-found", + route: { path: "/:contentId" } as Request["route"], + }); + mockResponse.statusCode = 404; + mockResponse.writableEnded = true; + mockResponse.emit("finish"); + + const [endLog] = parseLogs(lines); + + expect(lines).toHaveLength(1); + expect(endLog).toMatchObject({ + event: "request_end", + level: 40, + route: "/api/content/:contentId", + path: "/api/content/not-found", + statusCode: 404, + }); + expect(endLog.msg).toBe( + `404 GET /api/content/not-found (${Math.round(endLog.durationMs)}ms)`, + ); + }); + + test("uses a failure-specific completion message for errored requests", () => { + delete process.env.LOG_LEVEL; + + const { lines, stream } = createLogCapture(); + const middleware = initRequestLogger({ stream }); + const req = createMockRequest({ + originalUrl: "/api/login/magic?token=super-secret", + path: "/login/magic", + url: "/login/magic?token=super-secret", + }); + const mockResponse = new MockResponse(); + const res = mockResponse as unknown as Response; + + middleware(req, res, () => {}); + + mockResponse.err = new Error("boom"); + mockResponse.statusCode = 500; + mockResponse.writableEnded = true; + mockResponse.emit("finish"); + + const [endLog] = parseLogs(lines); + + expect(endLog).toMatchObject({ + event: "request_end", + level: 50, + path: "/api/login/magic", + statusCode: 500, + }); + expect(endLog.msg).toBe( + `500 GET /api/login/magic (${Math.round(endLog.durationMs)}ms)`, + ); + }); + + test("sanitizes request headers and redacts sensitive ones", () => { + delete process.env.LOG_LEVEL; + + const { lines, stream } = createLogCapture(); + const middleware = initRequestLogger({ stream }); + const req = createMockRequest({ + headers: { + accept: "application/json", + "accept-encoding": "gzip, br", + authorization: "Bearer secret-token", + connection: "close", + cookie: "session=top-secret", + referer: "http://localhost:8000/library?token=secret", + "sec-fetch-mode": "cors", + "user-agent": "Mozilla/5.0", + "x-api-key": "key-123", + }, + params: { ownerId: "abc123" }, + query: { parentId: "folder1" }, + // pino-http request serializer includes remotePort + socket: { + remoteAddress: "::1", + remotePort: 62051, + } as Request["socket"], + }); + const mockResponse = new MockResponse(); + mockResponse.headers = { + "content-type": "application/json", + "set-cookie": ["session=top-secret"], + }; + const res = mockResponse as unknown as Response; + + middleware(req, res, () => {}); + + mockResponse.writableEnded = true; + mockResponse.emit("finish"); + + const [endLog] = parseLogs(lines); + + expect(endLog.req.headers).toMatchObject({ + referer: "http://localhost:8000", + }); + expect(endLog.req).toMatchObject({ + remoteAddress: "::1", + }); + expect(endLog.req).not.toHaveProperty("params"); + expect(endLog.req).not.toHaveProperty("query"); + expect(endLog.req).not.toHaveProperty("remotePort"); + expect(endLog.req.headers).not.toHaveProperty("accept"); + expect(endLog.req.headers).not.toHaveProperty("accept-encoding"); + expect(endLog.req.headers).not.toHaveProperty("authorization"); + expect(endLog.req.headers).not.toHaveProperty("connection"); + expect(endLog.req.headers).not.toHaveProperty("cookie"); + expect(endLog.req.headers).not.toHaveProperty("sec-fetch-mode"); + expect(endLog.req.headers).not.toHaveProperty("user-agent"); + expect(endLog.req.headers).not.toHaveProperty("x-api-key"); + expect(endLog.res?.headers?.["set-cookie"]).toBeUndefined(); + }); +}); diff --git a/apps/api/src/utils/cli.ts b/apps/api/src/utils/cli.ts new file mode 100644 index 0000000000..bac48894dc --- /dev/null +++ b/apps/api/src/utils/cli.ts @@ -0,0 +1,28 @@ +const ansiReset = "\x1b[0m"; +const shouldUseAnsiColors = + process.env.NO_COLOR === undefined && process.env.FORCE_COLOR !== "0"; + +const ansiStyles = { + bold: "\x1b[1m", + dim: "\x1b[2m", + green: "\x1b[32m", + cyan: "\x1b[36m", +} as const; + +function styleCli(text: string, ...codes: string[]) { + if (!shouldUseAnsiColors) { + return text; + } + + return `${codes.join("")}${text}${ansiReset}`; +} + +export function formatApiReadyMessage(localUrl: string) { + return [ + "", + ` ${styleCli("API", ansiStyles.bold, ansiStyles.green)} ${styleCli("ready", ansiStyles.dim)}`, + "", + ` ${styleCli("Local:", ansiStyles.dim)} ${styleCli(localUrl, ansiStyles.cyan)}`, + "", + ].join("\n"); +} diff --git a/infra/cloudformation/dev3-doenet-taskdef-includes.yml b/infra/cloudformation/dev3-doenet-taskdef-includes.yml index ecdb49d498..0cb4d99b8e 100644 --- a/infra/cloudformation/dev3-doenet-taskdef-includes.yml +++ b/infra/cloudformation/dev3-doenet-taskdef-includes.yml @@ -3,6 +3,8 @@ Environment: Value: 3000 - Name: APP_URL Value: "https://dev3.doenet.org" + - Name: LOG_LEVEL + Value: "info" - Name: DATABASE_PORT Value: 3306 - Name: DATABASE_NAME @@ -19,6 +21,8 @@ Environment: Value: "false" - Name: MOCK_SIGNIN_EMAIL Value: "false" + - Name: PRETTY_LOGS + Value: "false" - Name: NODE_OPTIONS Value: "--max-old-space-size=1950" # - Name: DISCOURSE_API_USERNAME diff --git a/infra/cloudformation/prod-doenet-taskdef-includes.yml b/infra/cloudformation/prod-doenet-taskdef-includes.yml index 6930f5d2ba..a17dd4955c 100644 --- a/infra/cloudformation/prod-doenet-taskdef-includes.yml +++ b/infra/cloudformation/prod-doenet-taskdef-includes.yml @@ -3,6 +3,8 @@ Environment: Value: 3000 - Name: APP_URL Value: "https://beta.doenet.org" + - Name: LOG_LEVEL + Value: "info" - Name: DATABASE_PORT Value: 3306 - Name: DATABASE_NAME @@ -19,6 +21,8 @@ Environment: Value: "false" - Name: MOCK_SIGNIN_EMAIL Value: "false" + - Name: PRETTY_LOGS + Value: "false" - Name: NODE_OPTIONS Value: "--max-old-space-size=1950" - Name: DISCOURSE_API_USERNAME diff --git a/package-lock.json b/package-lock.json index 96b8e30835..90c29fb4cf 100644 --- a/package-lock.json +++ b/package-lock.json @@ -38,7 +38,7 @@ "wick-a11y": "^2.5.0" }, "engines": { - "node": "24.15" + "node": "~24.15.0" } }, "apps/api": { @@ -67,6 +67,7 @@ "passport-local": "^1.0.0", "passport-magic-link": "^2.1.1", "passport-strategy": "^1.0.0", + "pino-http": "^11.0.0", "prisma": "6.4.1", "short-uuid": "^5.2.0", "zod": "^4.0.14" @@ -81,6 +82,7 @@ "@types/passport-google-oauth20": "^2.0.16", "@types/passport-local": "^1.0.38", "@types/passport-strategy": "^0.2.38", + "pino-pretty": "^13.1.3", "vitest": "^3.2.4" }, "optionalDependencies": { @@ -4028,6 +4030,12 @@ "@noble/hashes": "^1.1.5" } }, + "node_modules/@pinojs/redact": { + "version": "0.4.0", + "resolved": "https://registry.npmjs.org/@pinojs/redact/-/redact-0.4.0.tgz", + "integrity": "sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==", + "license": "MIT" + }, "node_modules/@pkgjs/parseargs": { "version": "0.11.0", "resolved": "https://registry.npmjs.org/@pkgjs/parseargs/-/parseargs-0.11.0.tgz", @@ -7930,6 +7938,15 @@ "node": ">= 4.5.0" } }, + "node_modules/atomic-sleep": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz", + "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==", + "license": "MIT", + "engines": { + "node": ">=8.0.0" + } + }, "node_modules/available-typed-arrays": { "version": "1.0.7", "resolved": "https://registry.npmjs.org/available-typed-arrays/-/available-typed-arrays-1.0.7.tgz", @@ -10268,6 +10285,16 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/dateformat": { + "version": "4.6.3", + "resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz", + "integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==", + "dev": true, + "license": "MIT", + "engines": { + "node": "*" + } + }, "node_modules/dayjs": { "version": "1.11.19", "resolved": "https://registry.npmjs.org/dayjs/-/dayjs-1.11.19.tgz", @@ -12036,6 +12063,13 @@ ], "license": "MIT" }, + "node_modules/fast-copy": { + "version": "4.0.3", + "resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.0.3.tgz", + "integrity": "sha512-58apWr0GUiDFM8+3afrO6eYwJBn9ZAhDOzG3L+/9llab/haCARS2UIfffmOurYLwbgDRs8n0rfr6qAAPEAuAQw==", + "dev": true, + "license": "MIT" + }, "node_modules/fast-deep-equal": { "version": "3.1.3", "resolved": "https://registry.npmjs.org/fast-deep-equal/-/fast-deep-equal-3.1.3.tgz", @@ -12094,6 +12128,13 @@ "dev": true, "license": "MIT" }, + "node_modules/fast-safe-stringify": { + "version": "2.1.1", + "resolved": "https://registry.npmjs.org/fast-safe-stringify/-/fast-safe-stringify-2.1.1.tgz", + "integrity": "sha512-W+KJc2dmILlPplD/H4K9l9LcAHAfPtP6BY84uVLXQ6Evcz9Lcg33Y2z1IVblT6xdY54PXYVHEv+0Wpq8Io6zkA==", + "dev": true, + "license": "MIT" + }, "node_modules/fast-uri": { "version": "3.1.0", "resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.0.tgz", @@ -12688,7 +12729,6 @@ "version": "2.0.5", "resolved": "https://registry.npmjs.org/get-caller-file/-/get-caller-file-2.0.5.tgz", "integrity": "sha512-DyFP3BM/3YHTQOCUL/w0OZHR0lpKeGrxotcHWcqNEdnltqFwXVfhEBQ94eIo34AfQpo0rGki4cyIiftY06h2Fg==", - "dev": true, "license": "ISC", "engines": { "node": "6.* || 8.* || >= 10.*" @@ -13545,6 +13585,13 @@ "he": "bin/he" } }, + "node_modules/help-me": { + "version": "5.0.0", + "resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz", + "integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==", + "dev": true, + "license": "MIT" + }, "node_modules/hoist-non-react-statics": { "version": "3.3.2", "resolved": "https://registry.npmjs.org/hoist-non-react-statics/-/hoist-non-react-statics-3.3.2.tgz", @@ -14608,6 +14655,16 @@ "dev": true, "license": "MIT" }, + "node_modules/joycon": { + "version": "3.1.1", + "resolved": "https://registry.npmjs.org/joycon/-/joycon-3.1.1.tgz", + "integrity": "sha512-34wB/Y7MW7bzjKRjUKTa46I2Z7eV62Rkhva+KkopW7Qvv/OSWBqvkSY7vusOPrNuZcUG3tApvdVgNB8POj3SPw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/js-sha3": { "version": "0.8.0", "resolved": "https://registry.npmjs.org/js-sha3/-/js-sha3-0.8.0.tgz", @@ -17612,6 +17669,15 @@ "integrity": "sha512-RdR9FQrFwNBNXAr4GixM8YaRZRJ5PUWbKYbE5eOsrwAjJW0q2REGcf79oYPsLyskQCZG1PLN+S/K1V00joZAoQ==", "license": "MIT" }, + "node_modules/on-exit-leak-free": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz", + "integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==", + "license": "MIT", + "engines": { + "node": ">=14.0.0" + } + }, "node_modules/on-finished": { "version": "2.4.1", "resolved": "https://registry.npmjs.org/on-finished/-/on-finished-2.4.1.tgz", @@ -18149,6 +18215,93 @@ "node": ">=0.10.0" } }, + "node_modules/pino": { + "version": "10.3.1", + "resolved": "https://registry.npmjs.org/pino/-/pino-10.3.1.tgz", + "integrity": "sha512-r34yH/GlQpKZbU1BvFFqOjhISRo1MNx1tWYsYvmj6KIRHSPMT2+yHOEb1SG6NMvRoHRF0a07kCOox/9yakl1vg==", + "license": "MIT", + "dependencies": { + "@pinojs/redact": "^0.4.0", + "atomic-sleep": "^1.0.0", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^5.0.0", + "quick-format-unescaped": "^4.0.3", + "real-require": "^0.2.0", + "safe-stable-stringify": "^2.3.1", + "sonic-boom": "^4.0.1", + "thread-stream": "^4.0.0" + }, + "bin": { + "pino": "bin.js" + } + }, + "node_modules/pino-abstract-transport": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz", + "integrity": "sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==", + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-http": { + "version": "11.0.0", + "resolved": "https://registry.npmjs.org/pino-http/-/pino-http-11.0.0.tgz", + "integrity": "sha512-wqg5XIAGRRIWtTk8qPGxkbrfiwEWz1lgedVLvhLALudKXvg1/L2lTFgTGPJ4Z2e3qcRmxoFxDuSdMdMGNM6I1g==", + "license": "MIT", + "dependencies": { + "get-caller-file": "^2.0.5", + "pino": "^10.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^5.0.0" + } + }, + "node_modules/pino-pretty": { + "version": "13.1.3", + "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.1.3.tgz", + "integrity": "sha512-ttXRkkOz6WWC95KeY9+xxWL6AtImwbyMHrL1mSwqwW9u+vLp/WIElvHvCSDg0xO/Dzrggz1zv3rN5ovTRVowKg==", + "dev": true, + "license": "MIT", + "dependencies": { + "colorette": "^2.0.7", + "dateformat": "^4.6.3", + "fast-copy": "^4.0.0", + "fast-safe-stringify": "^2.1.1", + "help-me": "^5.0.0", + "joycon": "^3.1.1", + "minimist": "^1.2.6", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pump": "^3.0.0", + "secure-json-parse": "^4.0.0", + "sonic-boom": "^4.0.1", + "strip-json-comments": "^5.0.2" + }, + "bin": { + "pino-pretty": "bin.js" + } + }, + "node_modules/pino-pretty/node_modules/strip-json-comments": { + "version": "5.0.3", + "resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-5.0.3.tgz", + "integrity": "sha512-1tB5mhVo7U+ETBKNf92xT4hrQa3pm0MZ0PQvuDnWgAAGHDsfp4lPSpiS6psrSiet87wyGPh9ft6wmhOMQ0hDiw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=14.16" + }, + "funding": { + "url": "https://github.com/sponsors/sindresorhus" + } + }, + "node_modules/pino-std-serializers": { + "version": "7.1.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz", + "integrity": "sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==", + "license": "MIT" + }, "node_modules/pkg-types": { "version": "2.3.0", "resolved": "https://registry.npmjs.org/pkg-types/-/pkg-types-2.3.0.tgz", @@ -18355,6 +18508,22 @@ "node": ">= 0.6.0" } }, + "node_modules/process-warning": { + "version": "5.0.0", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-5.0.0.tgz", + "integrity": "sha512-a39t9ApHNx2L4+HBnQKqxxHNs1r7KF+Intd8Q/g1bUh6q0WIp9voPXJ/x0j+ZL45KF1pJd9+q2jLIRMfvEshkA==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "MIT" + }, "node_modules/prompts": { "version": "2.4.2", "resolved": "https://registry.npmjs.org/prompts/-/prompts-2.4.2.tgz", @@ -18512,6 +18681,12 @@ ], "license": "MIT" }, + "node_modules/quick-format-unescaped": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz", + "integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==", + "license": "MIT" + }, "node_modules/quick-lru": { "version": "4.0.1", "resolved": "https://registry.npmjs.org/quick-lru/-/quick-lru-4.0.1.tgz", @@ -18965,6 +19140,15 @@ "url": "https://paulmillr.com/funding/" } }, + "node_modules/real-require": { + "version": "0.2.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz", + "integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==", + "license": "MIT", + "engines": { + "node": ">= 12.13.0" + } + }, "node_modules/recharts": { "version": "2.15.4", "resolved": "https://registry.npmjs.org/recharts/-/recharts-2.15.4.tgz", @@ -19877,6 +20061,15 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", @@ -19898,6 +20091,23 @@ "integrity": "sha512-eNv+WrVbKu1f3vbYJT/xtiF5syA5HPIMtf9IgY/nKg0sWqzAUEvqY/xm7OcZc/qafLx/iO9FgOmeSAp4v5ti/Q==", "license": "MIT" }, + "node_modules/secure-json-parse": { + "version": "4.1.0", + "resolved": "https://registry.npmjs.org/secure-json-parse/-/secure-json-parse-4.1.0.tgz", + "integrity": "sha512-l4KnYfEyqYJxDwlNVyRfO2E4NTHfMKAWdUuA8J0yve2Dz/E/PdBepY03RvyJpssIpRFwJoCD55wA+mEDs6ByWA==", + "dev": true, + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "BSD-3-Clause" + }, "node_modules/seedrandom": { "version": "3.0.5", "resolved": "https://registry.npmjs.org/seedrandom/-/seedrandom-3.0.5.tgz", @@ -20541,6 +20751,15 @@ "integrity": "sha512-Tpp60P6IUJDTuOq/5Z8cdskzJujfwqfOTkrwIwj7IRISpnkJnT6SyJ4PCPnGMoFjC9ddhal5KVIYtAt97ix05A==", "license": "MIT" }, + "node_modules/sonic-boom": { + "version": "4.2.1", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.1.tgz", + "integrity": "sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q==", + "license": "MIT", + "dependencies": { + "atomic-sleep": "^1.0.0" + } + }, "node_modules/sort-keys": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/sort-keys/-/sort-keys-2.0.0.tgz", @@ -20683,6 +20902,15 @@ "node": ">=0.10.0" } }, + "node_modules/split2": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/split2/-/split2-4.2.0.tgz", + "integrity": "sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==", + "license": "ISC", + "engines": { + "node": ">= 10.x" + } + }, "node_modules/sprintf-js": { "version": "1.0.3", "resolved": "https://registry.npmjs.org/sprintf-js/-/sprintf-js-1.0.3.tgz", @@ -21195,6 +21423,18 @@ "url": "https://opencollective.com/webpack" } }, + "node_modules/thread-stream": { + "version": "4.0.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-4.0.0.tgz", + "integrity": "sha512-4iMVL6HAINXWf1ZKZjIPcz5wYaOdPhtO8ATvZ+Xqp3BTdaqtAwQkNmKORqcIo5YkQqGXq5cwfswDwMqqQNrpJA==", + "license": "MIT", + "dependencies": { + "real-require": "^0.2.0" + }, + "engines": { + "node": ">=20" + } + }, "node_modules/throttleit": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/throttleit/-/throttleit-1.0.1.tgz", diff --git a/package.json b/package.json index 6b113cf3cc..c9ce98d5a9 100644 --- a/package.json +++ b/package.json @@ -13,7 +13,7 @@ "postinstall": "npm run prisma:generate --workspace @doenet-tools/api", "setup": "node scripts/setup.js", "db:setup": "npm run prisma:migrate-dev --workspace @doenet-tools/api && npm run prisma:seed --workspace @doenet-tools/api", - "dev": "npm run build --workspace @doenet-tools/shared -- --force && concurrently \"npm run dev --workspace @doenet-tools/shared\" \"npm run dev --workspace @doenet-tools/api\" \"npm run dev --workspace @doenet-tools/app\" \"npm run dev --workspace @doenet-tools/web\"", + "dev": "npm run build --workspace @doenet-tools/shared && node scripts/dev.js", "format": "prettier . --write", "format:check": "prettier . --check", "lint": "npm run lint --workspaces --if-present", diff --git a/packages/shared/package.json b/packages/shared/package.json index f16876ea5b..9360eee945 100644 --- a/packages/shared/package.json +++ b/packages/shared/package.json @@ -16,7 +16,7 @@ } }, "scripts": { - "dev": "tsc --build --watch --preserveWatchOutput --force", + "watch": "tsc --build --watch --preserveWatchOutput", "lint": "eslint --fix", "lint:check": "eslint", "build": "tsc --build" diff --git a/scripts/dev.js b/scripts/dev.js new file mode 100644 index 0000000000..4b36be87de --- /dev/null +++ b/scripts/dev.js @@ -0,0 +1,76 @@ +/* + * This wrapper exists so the root `npm run dev` command can orchestrate the app, + * api, and web dev servers with a bit of custom behavior. It starts each workspace + * through the npm CLI, keeps the usual prefixed output from `concurrently`, and + * makes Ctrl+C shutdown less noisy without hiding real failures. + */ +/* global process */ +import concurrently, { Logger } from "concurrently"; +import path from "path"; + +const npmExecPath = process.env.npm_execpath; + +if (!npmExecPath) { + throw new Error( + "npm_execpath is not set. Run this script through `npm run dev`.", + ); +} + +function quoteCliArgument(argument) { + return JSON.stringify(argument); +} + +let interrupted = false; + +for (const signal of ["SIGINT", "SIGTERM"]) { + process.on(signal, () => { + interrupted = true; + }); +} + +class DevLogger extends Logger { + logCommandEvent(text, command) { + if ( + interrupted && + / exited with code (1|null|SIGINT|SIGTERM)$/.test(text) + ) { + return; + } + + super.logCommandEvent(text, command); + } +} + +const npmRunDevCommand = `${quoteCliArgument(process.execPath)} ${quoteCliArgument(npmExecPath)} run dev`; +const root = path.join(import.meta.dirname, ".."); + +const { result } = concurrently( + [ + { + command: npmRunDevCommand, + cwd: path.join(root, "apps", "api"), + name: "API", + }, + { + command: npmRunDevCommand, + cwd: path.join(root, "apps", "app"), + name: "APP", + }, + { + command: npmRunDevCommand, + cwd: path.join(root, "apps", "web"), + name: "WEB", + }, + ], + { + logger: new DevLogger({ prefixFormat: "name" }), + prefix: "name", + prefixColors: "auto", + }, +); + +try { + await result; +} catch { + process.exitCode = interrupted ? 0 : 1; +}