diff --git a/corpwiki/docs/people-portal-dev-guide/deployment/environment-variables.md b/corpwiki/docs/people-portal-dev-guide/deployment/environment-variables.md index 4fa8fd5..a69f171 100644 --- a/corpwiki/docs/people-portal-dev-guide/deployment/environment-variables.md +++ b/corpwiki/docs/people-portal-dev-guide/deployment/environment-variables.md @@ -39,6 +39,7 @@ A present-but-empty value counts as missing. |---|---| | `NODE_ENV` | `development`, `test` or `production`. Anything else throws. Default `development` | | `PORT` | Listen port. Default `3000` | +| `LOG_LEVEL` | `trace`, `debug`, `info`, `warn`, `error`, `fatal` or `silent`. Default `info` (`silent` under `NODE_ENV=test`). Production logs one JSON object per line; other environments get readable output. Every line written during a request carries its `requestId` and `userId` | | `PEOPLEPORTAL_BASE_URL` | Public origin. Builds the OIDC redirect and post-logout URLs | | `PEOPLEPORTAL_WEBHOOK_URL` | Origin Gitea calls back on. Usually the same as above | | `PEOPLEPORTAL_MONGO_URL` | MongoDB connection string | diff --git a/peopleportal/server/.env.example b/peopleportal/server/.env.example index cfa0d92..6127be3 100644 --- a/peopleportal/server/.env.example +++ b/peopleportal/server/.env.example @@ -56,3 +56,6 @@ PEOPLEPORTAL_WEBHOOK_URL=http://localhost:3000 # that container is actually running, or every upload is waved through. PHOTO_CHECK_ENABLED=false PHOTO_CHECK_URL=http://localhost:8001 + +# Log verbosity: trace, debug, info (default), warn, error, fatal or silent. +# LOG_LEVEL=info diff --git a/peopleportal/server/package-lock.json b/peopleportal/server/package-lock.json index 0b7a73b..1fcd9e8 100644 --- a/peopleportal/server/package-lock.json +++ b/peopleportal/server/package-lock.json @@ -43,6 +43,7 @@ "nodemailer": "^9.0.3", "nodemailer-express-handlebars": "^7.0.0", "openid-client": "^6.7.1", + "pino": "^9.14.0", "redis": "^6.0.1", "tsoa": "^6.6.0", "zxcvbn": "^4.4.2" @@ -58,6 +59,7 @@ "cpx": "^1.5.0", "mongodb-memory-server": "^11.2.0", "nodemon": "^3.1.10", + "pino-pretty": "^13.2.0", "supertest": "^7.2.2", "ts-node": "^10.9.2", "tsx": "^4.23.13", @@ -1818,6 +1820,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", @@ -3121,6 +3129,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/axios": { "version": "1.16.1", "resolved": "https://registry.npmjs.org/axios/-/axios-1.16.1.tgz", @@ -3702,6 +3719,13 @@ "integrity": "sha512-dOy+3AuW3a2wNbZHIuMZpTcgjGuLU/uBL/ubcZF9OXbDo8ff4O8yVp5Bf0efS8uEoYo5q4Fx7dY9OgQGXgAsQA==", "license": "MIT" }, + "node_modules/colorette": { + "version": "2.0.20", + "resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz", + "integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==", + "dev": true, + "license": "MIT" + }, "node_modules/combined-stream": { "version": "1.0.8", "resolved": "https://registry.npmjs.org/combined-stream/-/combined-stream-1.0.8.tgz", @@ -4327,6 +4351,18 @@ "node": ">= 8" } }, + "node_modules/data-uri-to-buffer": { + "version": "4.0.1", + "resolved": "https://registry.npmjs.org/data-uri-to-buffer/-/data-uri-to-buffer-4.0.1.tgz", + "integrity": "sha512-0R9ikRb668HB7QDxT1vkpuUBtqc53YyAwMwGeUFKRojY/NWKvdZ+9UYtRfGmhqNbRkTSVpMbmyhXipFFv2cb/A==", + "dev": true, + "license": "MIT", + "optional": true, + "peer": true, + "engines": { + "node": ">= 12" + } + }, "node_modules/date.js": { "version": "0.3.3", "resolved": "https://registry.npmjs.org/date.js/-/date.js-0.3.3.tgz", @@ -4351,6 +4387,16 @@ "integrity": "sha512-Tpp60P6IUJDTuOq/5Z8cdskzJujfwqfOTkrwIwj7IRISpnkJnT6SyJ4PCPnGMoFjC9ddhal5KVIYtAt97ix05A==", "license": "MIT" }, + "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/debug": { "version": "4.4.3", "resolved": "https://registry.npmjs.org/debug/-/debug-4.4.3.tgz", @@ -4553,6 +4599,16 @@ "node": ">= 0.8" } }, + "node_modules/end-of-stream": { + "version": "1.4.5", + "resolved": "https://registry.npmjs.org/end-of-stream/-/end-of-stream-1.4.5.tgz", + "integrity": "sha512-ooEGc6HP26xXq/N+GCGOT0JKCLDGrq2bQUZrQ7gyrJiZANJ/8YDTxTpQBXGMn+WbIQXNVpyWymm7KYVICQnyOg==", + "dev": true, + "license": "MIT", + "dependencies": { + "once": "^1.4.0" + } + }, "node_modules/entities": { "version": "4.5.0", "resolved": "https://registry.npmjs.org/entities/-/entities-4.5.0.tgz", @@ -5008,6 +5064,13 @@ "node": ">=0.10.0" } }, + "node_modules/fast-copy": { + "version": "4.3.1", + "resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.3.1.tgz", + "integrity": "sha512-CRzQaTFOFUs6PuhsAq7lk9Zqr995soJBcFNZlfJS/5keTSl1awREV9dZW4xS2nX4pWbhIIR0xp4h+J8PQxCkvg==", + "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", @@ -5071,6 +5134,32 @@ "fxparser": "src/cli/cli.js" } }, + "node_modules/fetch-blob": { + "version": "3.2.0", + "resolved": "https://registry.npmjs.org/fetch-blob/-/fetch-blob-3.2.0.tgz", + "integrity": "sha512-7yAQpD2UMJzLi1Dqv7qFYnPbaPx7ZfFK6PiIxQ4PfkGPyNyl2Ugx+a/umUonmKqjhM4DnfbMvdX6otXq83soQQ==", + "dev": true, + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/jimmywarting" + }, + { + "type": "paypal", + "url": "https://paypal.me/jimmywarting" + } + ], + "license": "MIT", + "optional": true, + "peer": true, + "dependencies": { + "node-domexception": "^1.0.0", + "web-streams-polyfill": "^3.0.3" + }, + "engines": { + "node": "^12.20 || >= 14.13" + } + }, "node_modules/file-uri-to-path": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/file-uri-to-path/-/file-uri-to-path-1.0.0.tgz", @@ -5254,6 +5343,21 @@ "node": ">= 0.6" } }, + "node_modules/formdata-polyfill": { + "version": "4.0.10", + "resolved": "https://registry.npmjs.org/formdata-polyfill/-/formdata-polyfill-4.0.10.tgz", + "integrity": "sha512-buewHzMvYL29jdeQTVILecSaZKnt/RJWjoZCF5OW60Z67/GmSLBkOFM7qh1PI3zFNtJbaZL5eQu1vLfazOwj4g==", + "dev": true, + "license": "MIT", + "optional": true, + "peer": true, + "dependencies": { + "fetch-blob": "^3.1.2" + }, + "engines": { + "node": ">=12.20.0" + } + }, "node_modules/formidable": { "version": "3.5.4", "resolved": "https://registry.npmjs.org/formidable/-/formidable-3.5.4.tgz", @@ -5602,6 +5706,18 @@ "node": ">=10" } }, + "node_modules/google-logging-utils": { + "version": "1.2.0", + "resolved": "https://registry.npmjs.org/google-logging-utils/-/google-logging-utils-1.2.0.tgz", + "integrity": "sha512-WE9av4wKDZgRjBwgVUabocx8T6/7o3Ca1Fat46FXDhXVAFibzNadedcOXrdgd1Kzmk8tsk/9ZH89Wyf/SqeZ3A==", + "dev": true, + "license": "Apache-2.0", + "optional": true, + "peer": true, + "engines": { + "node": ">=18" + } + }, "node_modules/google-p12-pem": { "version": "4.0.1", "resolved": "https://registry.npmjs.org/google-p12-pem/-/google-p12-pem-4.0.1.tgz", @@ -5849,6 +5965,13 @@ "node": ">= 0.4" } }, + "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/http-errors": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/http-errors/-/http-errors-2.0.0.tgz", @@ -6263,6 +6386,16 @@ "url": "https://github.com/sponsors/panva" } }, + "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/json-bigint": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/json-bigint/-/json-bigint-1.0.0.tgz", @@ -6993,6 +7126,40 @@ "node": ">=20.19.0" } }, + "node_modules/mongodb-memory-server-core/node_modules/gaxios": { + "version": "7.3.1", + "resolved": "https://registry.npmjs.org/gaxios/-/gaxios-7.3.1.tgz", + "integrity": "sha512-kB3rzJV7d9juLZh8/56QTXCwQfxyhdOMdyYk1HdQKFtF8TJTDTZQJtixWIwXdE9Jji91mC41DUNpjleo4L4eAQ==", + "dev": true, + "license": "Apache-2.0", + "optional": true, + "peer": true, + "dependencies": { + "extend": "^3.0.2", + "https-proxy-agent": "^7.0.1", + "node-fetch": "^3.3.2" + }, + "engines": { + "node": ">=18" + } + }, + "node_modules/mongodb-memory-server-core/node_modules/gcp-metadata": { + "version": "7.0.1", + "resolved": "https://registry.npmjs.org/gcp-metadata/-/gcp-metadata-7.0.1.tgz", + "integrity": "sha512-UcO3kefx6dCcZkgcTGgVOTFb7b1LlQ02hY1omMjjrrBzkajRMCFgYOjs7J71WqnuG1k2b+9ppGL7FsOfhZMQKQ==", + "dev": true, + "license": "Apache-2.0", + "optional": true, + "peer": true, + "dependencies": { + "gaxios": "^7.0.0", + "google-logging-utils": "^1.0.0", + "json-bigint": "^1.0.0" + }, + "engines": { + "node": ">=18" + } + }, "node_modules/mongodb-memory-server-core/node_modules/https-proxy-agent": { "version": "7.0.6", "resolved": "https://registry.npmjs.org/https-proxy-agent/-/https-proxy-agent-7.0.6.tgz", @@ -7068,6 +7235,27 @@ "node": ">=20.19.0" } }, + "node_modules/mongodb-memory-server-core/node_modules/node-fetch": { + "version": "3.3.2", + "resolved": "https://registry.npmjs.org/node-fetch/-/node-fetch-3.3.2.tgz", + "integrity": "sha512-dRB78srN/l6gqWulah9SrxeYnxeddIG30+GOqK/9OlLVyLg3HPnr6SqOWTWOXKRwC2eGYCkZ59NNuSgvSrpgOA==", + "dev": true, + "license": "MIT", + "optional": true, + "peer": true, + "dependencies": { + "data-uri-to-buffer": "^4.0.0", + "fetch-blob": "^3.1.4", + "formdata-polyfill": "^4.0.10" + }, + "engines": { + "node": "^12.20.0 || ^14.13.1 || >=16.0.0" + }, + "funding": { + "type": "opencollective", + "url": "https://opencollective.com/node-fetch" + } + }, "node_modules/mongoose": { "version": "8.24.0", "resolved": "https://registry.npmjs.org/mongoose/-/mongoose-8.24.0.tgz", @@ -7233,6 +7421,29 @@ "node": ">=20" } }, + "node_modules/node-domexception": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/node-domexception/-/node-domexception-1.0.0.tgz", + "integrity": "sha512-/jKZoMpw0F8GRwl4/eLROPA3cfcXtLApP0QzLmUT/HuPCZWyB7IY9ZrMeKw2O/nFIqPQB3PVM9aYm0F312AXDQ==", + "deprecated": "Use your platform's native DOMException instead", + "dev": true, + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/jimmywarting" + }, + { + "type": "github", + "url": "https://paypal.me/jimmywarting" + } + ], + "license": "MIT", + "optional": true, + "peer": true, + "engines": { + "node": ">=10.5.0" + } + }, "node_modules/node-fetch": { "version": "2.7.0", "resolved": "https://registry.npmjs.org/node-fetch/-/node-fetch-2.7.0.tgz", @@ -7483,6 +7694,15 @@ "node": ">=0.10.0" } }, + "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", @@ -7798,6 +8018,88 @@ "url": "https://github.com/sponsors/jonschlinkert" } }, + "node_modules/pino": { + "version": "9.14.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-9.14.0.tgz", + "integrity": "sha512-8OEwKp5juEvb/MjpIc4hjqfgCNysrS94RIOMXYvpYCdm/jglrKEiAYmiumbmGhCvs+IcInsphYDFwqrjr7398w==", + "license": "MIT", + "dependencies": { + "@pinojs/redact": "^0.4.0", + "atomic-sleep": "^1.0.0", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^2.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": "^3.0.0" + }, + "bin": { + "pino": "bin.js" + } + }, + "node_modules/pino-abstract-transport": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-2.0.0.tgz", + "integrity": "sha512-F63x5tizV6WCh4R6RHyi2Ml+M70DNRXt/+HANowMflpgGFMAym/VKm6G7ZOQRjqN7XbGxK1Lg9t6ZrtzOaivMw==", + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-pretty": { + "version": "13.2.0", + "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.2.0.tgz", + "integrity": "sha512-jjghD1ML+Di/WxjJDz6j6Y4FT7hIXOlb8h27AyJ+ohtAXJXH4PS/xkv7si+RCCIW59HMgZsMKTDgzdr0RhuRrg==", + "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.2", + "pino-abstract-transport": "^3.0.0", + "pump": "^3.0.3", + "secure-json-parse": "^4.1.0", + "sonic-boom": "^5.0.0", + "strip-json-comments": "^5.0.3" + }, + "bin": { + "pino-pretty": "bin.js" + } + }, + "node_modules/pino-pretty/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==", + "dev": true, + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-pretty/node_modules/sonic-boom": { + "version": "5.0.2", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-5.0.2.tgz", + "integrity": "sha512-/JEruzo6yhNVhsLblTRchgTQHIt7SsdJP0YyrfWaNKjIOQDfrdZv9gwYraYCAsmKV39/LAdV31FLL5NCDpoL/A==", + "dev": true, + "license": "MIT", + "dependencies": { + "atomic-sleep": "^1.0.0" + } + }, + "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-dir": { "version": "4.2.0", "resolved": "https://registry.npmjs.org/pkg-dir/-/pkg-dir-4.2.0.tgz", @@ -7838,6 +8140,22 @@ "dev": true, "license": "MIT" }, + "node_modules/process-warning": { + "version": "5.1.1", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-5.1.1.tgz", + "integrity": "sha512-oCkNVj4OKnKEcocVBcDfiIugN1/cE6rgfT3nCtzeqZPA8+rIxMaQ0xXzIkGP8Gj2qUaP1UR7uhJ1VD8lUCpzCg==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "MIT" + }, "node_modules/proxy-addr": { "version": "2.0.7", "resolved": "https://registry.npmjs.org/proxy-addr/-/proxy-addr-2.0.7.tgz", @@ -7867,6 +8185,17 @@ "dev": true, "license": "MIT" }, + "node_modules/pump": { + "version": "3.0.4", + "resolved": "https://registry.npmjs.org/pump/-/pump-3.0.4.tgz", + "integrity": "sha512-VS7sjc6KR7e1ukRFhQSY5LM2uBWAUPiOPa/A3mkKmiMwSmRFUITt0xuj+/lesgnCv+dPIEYlkzrcyXgquIHMcA==", + "dev": true, + "license": "MIT", + "dependencies": { + "end-of-stream": "^1.1.0", + "once": "^1.3.1" + } + }, "node_modules/punycode": { "version": "2.3.1", "resolved": "https://registry.npmjs.org/punycode/-/punycode-2.3.1.tgz", @@ -7900,6 +8229,12 @@ "url": "https://github.com/sponsors/ljharb" } }, + "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/random-bytes": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/random-bytes/-/random-bytes-1.0.0.tgz", @@ -8024,6 +8359,15 @@ "node": ">=8.10.0" } }, + "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/redis": { "version": "6.2.1", "resolved": "https://registry.npmjs.org/redis/-/redis-6.2.1.tgz", @@ -8210,12 +8554,38 @@ "ret": "~0.1.10" } }, + "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", "integrity": "sha512-YZo3K82SD7Riyi0E1EQPojLz7kpepnSQI9IyPbHHg1XXXevb5dJI7tpyN2ADxGcQbHG7vcyRHk0cbwqcQriUtg==", "license": "MIT" }, + "node_modules/secure-json-parse": { + "version": "4.1.1", + "resolved": "https://registry.npmjs.org/secure-json-parse/-/secure-json-parse-4.1.1.tgz", + "integrity": "sha512-lnd81MQEZKjhW/Gd2TQqdd4XP6QYNdDW/EP+I7nTrFHP9y2LmaGPIHk9xsnzcOiEr1c39c/e84xFgGviQKBTRw==", + "dev": true, + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "BSD-3-Clause" + }, "node_modules/semver": { "version": "7.8.5", "resolved": "https://registry.npmjs.org/semver/-/semver-7.8.5.tgz", @@ -8581,6 +8951,15 @@ "node": ">=0.10.0" } }, + "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/source-map": { "version": "0.6.1", "resolved": "https://registry.npmjs.org/source-map/-/source-map-0.6.1.tgz", @@ -8635,6 +9014,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/static-extend": { "version": "0.1.2", "resolved": "https://registry.npmjs.org/static-extend/-/static-extend-0.1.2.tgz", @@ -8810,6 +9198,19 @@ "node": ">=8" } }, + "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/strnum": { "version": "2.3.0", "resolved": "https://registry.npmjs.org/strnum/-/strnum-2.3.0.tgz", @@ -8952,6 +9353,15 @@ "b4a": "^1.6.4" } }, + "node_modules/thread-stream": { + "version": "3.2.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-3.2.0.tgz", + "integrity": "sha512-zLBvqpwr4Esa0kRjcrzGU6zL25lePWaCLMx0RQFrmteozIfeNdaMLpG5U7PeHzvlFkAWaRKA9/KVW4F60iB+qw==", + "license": "MIT", + "dependencies": { + "real-require": "^0.2.0" + } + }, "node_modules/to-object-path": { "version": "0.3.0", "resolved": "https://registry.npmjs.org/to-object-path/-/to-object-path-0.3.0.tgz", @@ -9396,6 +9806,18 @@ "node": ">= 0.8" } }, + "node_modules/web-streams-polyfill": { + "version": "3.3.3", + "resolved": "https://registry.npmjs.org/web-streams-polyfill/-/web-streams-polyfill-3.3.3.tgz", + "integrity": "sha512-d2JWLCivmZYTSIoge9MsgFCZrt571BikcWGYkjC1khllbTeDlGqZ2D8vD8E/lJa8WGWbb7Plm8/XJYV7IJHZZw==", + "dev": true, + "license": "MIT", + "optional": true, + "peer": true, + "engines": { + "node": ">= 8" + } + }, "node_modules/webidl-conversions": { "version": "7.0.0", "resolved": "https://registry.npmjs.org/webidl-conversions/-/webidl-conversions-7.0.0.tgz", diff --git a/peopleportal/server/package.json b/peopleportal/server/package.json index b58d67b..926b7fd 100644 --- a/peopleportal/server/package.json +++ b/peopleportal/server/package.json @@ -41,6 +41,7 @@ "nodemailer": "^9.0.3", "nodemailer-express-handlebars": "^7.0.0", "openid-client": "^6.7.1", + "pino": "^9.14.0", "redis": "^6.0.1", "tsoa": "^6.6.0", "zxcvbn": "^4.4.2" @@ -56,9 +57,10 @@ "cpx": "^1.5.0", "mongodb-memory-server": "^11.2.0", "nodemon": "^3.1.10", + "pino-pretty": "^13.2.0", "supertest": "^7.2.2", "ts-node": "^10.9.2", "tsx": "^4.23.13", "typescript": "^5.9.2" } -} \ No newline at end of file +} diff --git a/peopleportal/server/src/app.ts b/peopleportal/server/src/app.ts index 9873d5d..a7e1aac 100644 --- a/peopleportal/server/src/app.ts +++ b/peopleportal/server/src/app.ts @@ -41,15 +41,13 @@ import { AuthentikClient } from "./clients/AuthentikClient"; import { RedisClient } from "./clients/RedisClient"; import { CustomValidationError, ResourceAccessError } from "./utils/errors"; import { ENABLED_SHARED_RESOURCES } from "./config"; -import log from "loglevel"; +import { logger, requestLogger } from "./utils/logger"; import { agendaClient } from "./clients/AgendaClient"; import { authenticateGiteaWebhook } from "./utils/gitea-webhook-auth"; import { describeUnknownError } from "./utils/errors"; -log.setLevel("info"); - assertRequiredEnvironment(); -log.info( +logger.info( `Environment: ${ENVIRONMENT}${loadedEnvFiles.length ? ` (loaded ${loadedEnvFiles.join(", ")})` : ""}`, ); @@ -60,7 +58,7 @@ if (!process.env.PEOPLEPORTAL_TOKEN_SECRET) { throw new Error("PEOPLEPORTAL_TOKEN_SECRET must be set in production"); process.env.PEOPLEPORTAL_TOKEN_SECRET = generateSecureRandomString(16); - log.warn( + logger.warn( "PEOPLEPORTAL_TOKEN_SECRET is unset; generated an ephemeral one. Sessions will not survive a restart.", ); } @@ -68,6 +66,9 @@ if (!process.env.PEOPLEPORTAL_TOKEN_SECRET) { const app = express(); const PORT = envInt("PORT", 3000); +/* First, so request timing and the request id cover every other middleware. */ +app.use(requestLogger); + app.use(express.urlencoded({ extended: true })); app.use(express.json()); @@ -163,7 +164,20 @@ app.use(function errorHandler( } if (err instanceof ValidateError) { - console.warn(`Caught Validation Error for ${req.path}:`, err.fields); + /* Log which fields failed and why, never the submitted values: a + rejected login or signup body would otherwise put passwords in logs. */ + logger.warn( + { + route: req.path, + fields: Object.fromEntries( + Object.entries(err.fields).map(([name, f]) => [ + name, + f.message, + ]), + ), + }, + "Request validation failed", + ); return res.status(422).json({ message: "Validation Failed", details: err?.fields, @@ -180,7 +194,7 @@ app.use(function errorHandler( } if (err instanceof Error) { - console.error(err); + logger.error({ err, route: req.path }, "Unhandled error in request"); return res.status(500).json({ message: err.message ?? "Unknown Internal Server Error", }); @@ -220,30 +234,30 @@ async function startup(): Promise { try { await authentikClient.validateServiceExistance(); } catch (e: unknown) { - log.error( - "Service team validation failed; executive and events features may be unavailable:", - describeUnknownError(e), + logger.error( + { err: describeUnknownError(e) }, + "Service team validation failed; executive and events features may be unavailable", ); } /* Initialize Shared Resource Clients. One integration failing to start must not stop the server from serving, so each is isolated. */ for (const client in ENABLED_SHARED_RESOURCES) { - log.info(`Initializing Shared Resource Client: ${client}`); + logger.info({ client }, "Initializing shared resource client"); const clientInstance = ENABLED_SHARED_RESOURCES[client]!; try { await clientInstance.init(); } catch (e: unknown) { - log.error( - `Failed to initialize shared resource client "${client}", continuing without it:`, - describeUnknownError(e), + logger.error( + { client, err: describeUnknownError(e) }, + "Failed to initialize shared resource client, continuing without it", ); } } /* Validate Database Connection */ await mongoose.connect(process.env.PEOPLEPORTAL_MONGO_URL!); - log.info(`Server running at http://localhost:${PORT}`); + logger.info({ port: PORT }, "Server running"); // Agenda Client Singleton await agendaClient.initialize(); @@ -255,8 +269,10 @@ app.listen(PORT, () => { discovery, Redis, Mongo, the job scheduler) did not come up. Exit deliberately with a readable reason rather than dying on an unhandled rejection halfway through boot. */ - log.error("Fatal error during startup:", describeUnknownError(e)); - if (e instanceof Error && e.stack) log.error(e.stack); + logger.fatal( + { err: e instanceof Error ? e : describeUnknownError(e) }, + "Fatal error during startup", + ); process.exit(1); }); }); diff --git a/peopleportal/server/src/utils/logger.ts b/peopleportal/server/src/utils/logger.ts new file mode 100644 index 0000000..f57509b --- /dev/null +++ b/peopleportal/server/src/utils/logger.ts @@ -0,0 +1,194 @@ +/** + People Portal Server + Copyright (C) 2026 Atheesh Thirumalairajan + + This program is free software: you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation, either version 3 of the License, or + (at your option) any later version. + + This program is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with this program. If not, see . +*/ + +import { AsyncLocalStorage } from "async_hooks"; +import { randomUUID } from "crypto"; +import type { NextFunction, Request, Response } from "express"; +import loglevel from "loglevel"; +import pino, { type DestinationStream, type Logger } from "pino"; +import { + ENVIRONMENT, + isProduction, + isTest, + loadEnvironmentFiles, +} from "../config/environment"; + +/* Imports are hoisted above app.ts's own env loading, so make sure LOG_LEVEL + from the .env files is visible before we read it. Loading is idempotent. */ +loadEnvironmentFiles(); + +const LEVELS = ["trace", "debug", "info", "warn", "error", "fatal", "silent"]; + +/** + * LOG_LEVEL picks how chatty the server is. Unset means "info", except under + * test where the default is "silent" so test output stays readable. + */ +export function resolveLogLevel(raw = process.env.LOG_LEVEL): string { + const wanted = raw?.trim().toLowerCase(); + if (wanted && LEVELS.includes(wanted)) return wanted; + return isTest ? "silent" : "info"; +} + +/** + * Production writes one JSON object per line so logs can be searched and + * filtered by field. Everywhere else gets readable, colourised output through + * pino-pretty (a devDependency, so it is simply skipped if absent). + */ +function createDestination(): DestinationStream | undefined { + if (isProduction || isTest) return undefined; + try { + // eslint-disable-next-line @typescript-eslint/no-require-imports + const pretty = require("pino-pretty"); + return pretty({ colorize: true, ignore: "pid,hostname" }); + } catch { + return undefined; + } +} + +/** + * Errors are logged as type, message, stack and (for HTTP failures) the status. + * Axios and similar errors also carry the whole request - headers with bearer + * tokens, bodies with passwords - so those properties are dropped, not logged. + */ +export function serializeError(err: unknown): unknown { + const base = pino.stdSerializers.err(err as Error) as Record< + string, + unknown + >; + if (!base || typeof base !== "object") return base; + for (const key of ["config", "request", "response", "headers", "toJSON"]) + delete base[key]; + const status = (err as { response?: { status?: number } })?.response + ?.status; + if (typeof status === "number") base.status = status; + return base; +} + +/* Each key is covered at the top level and one level down: pino's "*.x" only + matches nested keys, so a bare { password } would otherwise slip through. */ +const SENSITIVE_KEYS = [ + "token", + "accessToken", + "refreshToken", + "secret", + "password", +]; +export const REDACT = { + paths: [ + "req.headers.authorization", + "req.headers.cookie", + ...SENSITIVE_KEYS, + ...SENSITIVE_KEYS.map((key) => `*.${key}`), + ], + censor: "[redacted]", +}; + +const level = resolveLogLevel(); + +/** The request currently being served, so any log line can be tied back to it. */ +const requestContext = new AsyncLocalStorage<{ id: string; req: Request }>(); + +export const logger: Logger = pino( + { + level, + base: { env: ENVIRONMENT }, + /* Anything logged while a request is in flight (controllers, clients, + the error handler) automatically carries its request id and user. */ + mixin() { + const ctx = requestContext.getStore(); + if (!ctx) return {}; + return { + requestId: ctx.id, + userId: ctx.req.session?.authorizedUser?.pk, + }; + }, + /* Errors passed as { err } are expanded into type, message and stack. */ + serializers: { err: serializeError }, + /* Never let credentials reach a log line, whatever gets logged. */ + redact: REDACT, + }, + createDestination(), +); + +/* A few clients still log through loglevel. Drive it from the same LOG_LEVEL so + there is a single knob, instead of a hardcoded level in app.ts. */ +loglevel.setLevel( + (level === "fatal" + ? "error" + : level) as loglevel.LogLevelDesc /* pino and loglevel share names */, +); + +/** Request augmentation: every request carries an id. */ +declare module "express-serve-static-core" { + interface Request { + id: string; + } +} + +/** + * Logs one line per request when it finishes: method, route, status, duration + * and user id. The route is the matched pattern (/teams/:teamId), not the raw + * URL, so query strings and ids never end up in the message and the field + * stays searchable. The request id is returned in X-Request-Id and is added to + * every log line written while the request is in flight, which ties error lines + * to the request that produced them. + * + * Register this before every other middleware so timing covers all of them. + */ +export function requestLogger( + req: Request, + res: Response, + next: NextFunction, +): void { + const start = process.hrtime.bigint(); + req.id = randomUUID(); + res.setHeader("X-Request-Id", req.id); + + res.on("finish", () => { + const route = req.route?.path + ? `${req.baseUrl}${req.route.path}` + : undefined; + const fields = { + requestId: req.id, + method: req.method, + route: route ?? "(unmatched)", + status: res.statusCode, + durationMs: Number(process.hrtime.bigint() - start) / 1e6, + userId: req.session?.authorizedUser?.pk, + }; + + /* Static assets and the SPA fallback match no API route; keep their + successful hits out of the way at debug. */ + if (res.statusCode >= 500) logger.error(fields, "request failed"); + else if (res.statusCode >= 400) logger.warn(fields, "request rejected"); + else if (!route) logger.debug(fields, "request completed"); + else logger.info(fields, "request completed"); + }); + + requestContext.run({ id: req.id, req }, next); +} + +/** + * Flattens a Map of named failures into { name: message } so it logs as + * structured fields rather than an opaque Map dump. + */ +export function errorMap(errors: Map): Record { + return Object.fromEntries( + [...errors].map(([name, error]) => [name, error.message]), + ); +} diff --git a/peopleportal/server/test/unit/logger.test.js b/peopleportal/server/test/unit/logger.test.js new file mode 100644 index 0000000..bf608cf --- /dev/null +++ b/peopleportal/server/test/unit/logger.test.js @@ -0,0 +1,76 @@ +/** + * The logger is the one place every server log line goes through, so these pin + * the behaviours the rest of the codebase relies on: LOG_LEVEL is honoured, + * errors are serialised without leaking request secrets, and each request logs + * one structured line carrying its id. + */ +const assert = require("node:assert/strict"); +const test = require("node:test"); +const pino = require("pino"); +const { EventEmitter } = require("node:events"); +const { + resolveLogLevel, + serializeError, + errorMap, + requestLogger, + REDACT, +} = require("../../dist/utils/logger.js"); + +test("LOG_LEVEL is honoured, case-insensitively, and bad values fall back", () => { + assert.equal(resolveLogLevel("debug"), "debug"); + assert.equal(resolveLogLevel(" WARN "), "warn"); + /* NODE_ENV is "test" here, where the default is silent. */ + assert.equal(resolveLogLevel(undefined), "silent"); + assert.equal(resolveLogLevel("loud"), "silent"); +}); + +test("serialised errors keep message and stack but drop the request", () => { + const err = new Error("Request failed with status code 401"); + err.config = { headers: { Authorization: "Bearer super-secret" } }; + err.request = { _header: "Authorization: Bearer super-secret" }; + err.response = { status: 401, data: { token: "super-secret" } }; + + const out = serializeError(err); + assert.equal(out.message, "Request failed with status code 401"); + assert.ok(out.stack); + assert.equal(out.status, 401); + assert.equal(out.config, undefined); + assert.equal(out.request, undefined); + assert.equal(out.response, undefined); + assert.doesNotMatch(JSON.stringify(out), /super-secret/); +}); + +test("errorMap flattens named failures to messages", () => { + const errors = new Map([ + ["aws", new Error("denied")], + ["slack", new Error("rate limited")], + ]); + assert.deepEqual(errorMap(errors), { aws: "denied", slack: "rate limited" }); +}); + +test("a request gets an id header, and the id is passed along", () => { + const req = { method: "GET", baseUrl: "/api", route: { path: "/teams/:teamId" }, session: {} }; + const res = new EventEmitter(); + res.statusCode = 200; + const headers = {}; + res.setHeader = (k, v) => (headers[k] = v); + + let called = false; + requestLogger(req, res, () => { + called = true; + }); + assert.ok(called, "next() must be called"); + assert.match(req.id, /^[0-9a-f-]{36}$/); + assert.equal(headers["X-Request-Id"], req.id); + + /* Finishing must not throw even with no session user. */ + res.emit("finish"); +}); + +test("credentials are redacted at the top level and one level down", () => { + let line = ""; + const log = pino({ redact: REDACT }, { write: (chunk) => (line += chunk) }); + log.info({ password: "hunter2", token: "t0p", user: { secret: "s3", refreshToken: "r3" } }); + assert.doesNotMatch(line, /hunter2|t0p|s3|r3/); + assert.match(line, /\[redacted\]/); +});