From 3d2fc0e56a38c04436981d56a39483552d973919 Mon Sep 17 00:00:00 2001 From: Ofer <12687466+CptSchnitz@users.noreply.github.com> Date: Mon, 28 Oct 2024 13:06:37 +0200 Subject: [PATCH] feat: logs pass (#57) * refactor: added many logs * feat: added operationId to http log --- package-lock.json | 243 ++++++++++++++----- package.json | 4 +- src/common/logger.ts | 60 +++++ src/configs/controllers/configController.ts | 3 + src/configs/models/configManager.ts | 23 ++ src/configs/models/configValidator.ts | 10 +- src/configs/repositories/configRepository.ts | 13 +- src/configs/routes/configRouter.ts | 4 + src/containerConfig.ts | 16 +- src/index.ts | 2 +- src/schemas/controllers/schemaController.ts | 2 + src/schemas/models/schemaManager.ts | 3 +- src/serverBuilder.ts | 14 +- tests/unit/config/configManager.spec.ts | 4 +- tests/unit/config/configValidator.spec.ts | 3 +- tsconfig.json | 1 + 16 files changed, 325 insertions(+), 80 deletions(-) create mode 100644 src/common/logger.ts diff --git a/package-lock.json b/package-lock.json index 189f231..7a74772 100644 --- a/package-lock.json +++ b/package-lock.json @@ -13,7 +13,7 @@ "@apidevtools/json-schema-ref-parser": "^11.5.4", "@godaddy/terminus": "^4.12.1", "@map-colonies/error-express-handler": "^2.1.0", - "@map-colonies/express-access-log-middleware": "^2.0.1", + "@map-colonies/express-access-log-middleware": "^2.1.0", "@map-colonies/js-logger": "^1.0.1", "@map-colonies/openapi-express-viewer": "^3.0.0", "@map-colonies/read-pkg": "0.0.1", @@ -36,6 +36,7 @@ "express-openapi-validator": "^5.0.4", "http-status-codes": "^2.2.0", "json-pointer": "0.6.2", + "lodash": "^4.17.21", "pg": "^8.11.5", "reflect-metadata": "^0.1.13", "tsyringe": "^4.8.0" @@ -54,6 +55,7 @@ "@types/express": "^4.17.17", "@types/jest": "^29.5.2", "@types/json-pointer": "^1.0.34", + "@types/lodash": "^4.17.12", "@types/multer": "^1.4.7", "@types/pg": "^8.11.5", "@types/supertest": "^2.0.12", @@ -4884,15 +4886,15 @@ } }, "node_modules/@map-colonies/express-access-log-middleware": { - "version": "2.0.1", - "resolved": "https://registry.npmjs.org/@map-colonies/express-access-log-middleware/-/express-access-log-middleware-2.0.1.tgz", - "integrity": "sha512-n3m96LEl/P77LOWU/E67b4H72Kn52QQJoQyOAWcNdsw0ABpWzkzO++qiy/Djhnv6PaS0xYGPrTr061U3SBazgg==", + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/@map-colonies/express-access-log-middleware/-/express-access-log-middleware-2.1.0.tgz", + "integrity": "sha512-3jYPG5hl56WjzpRwY9Tvb2HXk3sq95CCfdoQsdFfhlp16LofEXtlANDOE1lOW9yBntGy76adnqYSsF2ElbHRUA==", "dependencies": { - "http-status-codes": "^2.1.4", - "pino-http": "^8.3.3" + "http-status-codes": "^2.3.0", + "pino-http": "^10.3.0" }, "engines": { - "node": ">=12.0.0" + "node": ">=20" } }, "node_modules/@map-colonies/js-logger": { @@ -4956,6 +4958,7 @@ "version": "8.0.0", "resolved": "https://registry.npmjs.org/@map-colonies/telemetry/-/telemetry-8.0.0.tgz", "integrity": "sha512-+f+8nGEBDO/ZsXjDytMFYQgvtbWFvX66TIHx8pvptatu2MTkZ4RmCpetQK9fzI6V0wH861JC+GP683um7Viasw==", + "license": "ISC", "dependencies": { "@apideck/better-ajv-errors": "^0.3.6", "@map-colonies/read-pkg": "^0.0.1", @@ -7875,6 +7878,12 @@ "@types/koa": "*" } }, + "node_modules/@types/lodash": { + "version": "4.17.12", + "resolved": "https://registry.npmjs.org/@types/lodash/-/lodash-4.17.12.tgz", + "integrity": "sha512-sviUmCE8AYdaF/KIHLDJBQgeYzPBI0vf/17NaYehBJfYD1j6/L95Slh07NlyK2iNyBNaEkb3En2jRt+a8y3xZQ==", + "dev": true + }, "node_modules/@types/memcached": { "version": "2.2.10", "resolved": "https://registry.npmjs.org/@types/memcached/-/memcached-2.2.10.tgz", @@ -14111,9 +14120,9 @@ } }, "node_modules/http-status-codes": { - "version": "2.2.0", - "resolved": "https://registry.npmjs.org/http-status-codes/-/http-status-codes-2.2.0.tgz", - "integrity": "sha512-feERVo9iWxvnejp3SEfm/+oNG517npqL2/PIA8ORjyOZjGC7TwCRQsZylciLS64i6pJ0wRYz3rkXLRwbtFa8Ng==" + "version": "2.3.0", + "resolved": "https://registry.npmjs.org/http-status-codes/-/http-status-codes-2.3.0.tgz", + "integrity": "sha512-RJ8XvFvpPM/Dmc5SV+dC4y5PCeOhT3x1Hq0NU3rjGeg5a/CqlhZ7uudknPwZFz4aeAXDcbAyaeP7GAo9lvngtA==" }, "node_modules/http2-client": { "version": "1.3.5", @@ -18202,6 +18211,14 @@ "resolved": "https://registry.npmjs.org/obuf/-/obuf-1.1.2.tgz", "integrity": "sha512-PX1wu0AmAdPqOL1mWhqmlOd8kOIZQwGZw6rh7uby9fTc5lhaOWFLX3I6R1hrF9k3zUY40e6igsLGkDXK92LJNg==" }, + "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==", + "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", @@ -18889,17 +18906,56 @@ "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==", + "dependencies": { + "split2": "^4.0.0" + } + }, "node_modules/pino-http": { - "version": "8.3.3", - "resolved": "https://registry.npmjs.org/pino-http/-/pino-http-8.3.3.tgz", - "integrity": "sha512-p4umsNIXXVu95HD2C8wie/vXH7db5iGRpc+yj1/ZQ3sRtTQLXNjoS6Be5+eI+rQbqCRxen/7k/KSN+qiZubGDw==", + "version": "10.3.0", + "resolved": "https://registry.npmjs.org/pino-http/-/pino-http-10.3.0.tgz", + "integrity": "sha512-kaHQqt1i5S9LXWmyuw6aPPqYW/TjoDPizPs4PnDW4hSpajz2Uo/oisNliLf7We1xzpiLacdntmw8yaZiEkppQQ==", "dependencies": { "get-caller-file": "^2.0.5", - "pino": "^8.0.0", - "pino-std-serializers": "^6.0.0", - "process-warning": "^2.0.0" + "pino": "^9.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^4.0.0" + } + }, + "node_modules/pino-http/node_modules/pino": { + "version": "9.5.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-9.5.0.tgz", + "integrity": "sha512-xSEmD4pLnV54t0NOUN16yCl7RIB1c5UUOse5HSyEXtBp+FgFQyPeDutc+Q2ZO7/22vImV7VfEjH/1zV2QuqvYw==", + "dependencies": { + "atomic-sleep": "^1.0.0", + "fast-redact": "^3.1.1", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^2.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^4.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-http/node_modules/pino-std-serializers": { + "version": "7.0.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.0.0.tgz", + "integrity": "sha512-e906FRY0+tV27iq4juKzSYPbUj2do2X2JX4EzSca1631EB2QJQUqGbDuERal7LCtOpxl6x3+nvo9NPZcmjkiFA==" + }, + "node_modules/pino-http/node_modules/process-warning": { + "version": "4.0.0", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-4.0.0.tgz", + "integrity": "sha512-/MyYDxttz7DfGMMHiysAsFE4qF+pQYAA8ziO/3NcRVrQ5fSk+Mns4QZA/oRPFzvcqNoVJXQNWNAsdwBXLUkQKw==" + }, "node_modules/pino-pretty": { "version": "10.0.0", "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-10.0.0.tgz", @@ -18947,11 +19003,6 @@ "ieee754": "^1.2.1" } }, - "node_modules/pino-pretty/node_modules/on-exit-leak-free": { - "version": "2.1.0", - "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.0.tgz", - "integrity": "sha512-VuCaZZAjReZ3vUwgOB8LxAosIurDiAW0s13rI1YwmaP++jvcxP77AWoQvenZebpCA2m8WC1/EosPYPMjnRAp/w==" - }, "node_modules/pino-pretty/node_modules/pino-abstract-transport": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-1.0.0.tgz", @@ -19011,11 +19062,6 @@ "ieee754": "^1.2.1" } }, - "node_modules/pino/node_modules/on-exit-leak-free": { - "version": "2.1.0", - "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.0.tgz", - "integrity": "sha512-VuCaZZAjReZ3vUwgOB8LxAosIurDiAW0s13rI1YwmaP++jvcxP77AWoQvenZebpCA2m8WC1/EosPYPMjnRAp/w==" - }, "node_modules/pino/node_modules/pino-abstract-transport": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-1.0.0.tgz", @@ -19039,14 +19085,6 @@ "node": "^12.22.0 || ^14.17.0 || >=16.0.0" } }, - "node_modules/pino/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==", - "engines": { - "node": ">= 12.13.0" - } - }, "node_modules/pino/node_modules/sonic-boom": { "version": "3.3.0", "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-3.3.0.tgz", @@ -19868,6 +19906,14 @@ "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==", + "engines": { + "node": ">= 12.13.0" + } + }, "node_modules/redent": { "version": "3.0.0", "resolved": "https://registry.npmjs.org/redent/-/redent-3.0.0.tgz", @@ -20706,6 +20752,14 @@ "node": ">=8.0.0" } }, + "node_modules/sonic-boom": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.0.tgz", + "integrity": "sha512-INb7TM37/mAcsGmc9hyyI6+QR3rR1zVRu36B0NeGXKnOOLiZOfER5SA+N7X7k3yUYRzLWafduTDvJAfDswwEww==", + "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", @@ -21378,6 +21432,14 @@ "integrity": "sha1-f17oI66AUgfACvLfSoTsP8+lcLQ=", "dev": true }, + "node_modules/thread-stream": { + "version": "3.1.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-3.1.0.tgz", + "integrity": "sha512-OqyPZ9u96VohAyMfJykzmivOrY2wfMSf3C5TtFJVgN+Hm6aj+voFhlK+kZEIv2FBh1X6Xp3DlnCOfEQ3B2J86A==", + "dependencies": { + "real-require": "^0.2.0" + } + }, "node_modules/through": { "version": "2.3.8", "resolved": "https://registry.npmjs.org/through/-/through-2.3.8.tgz", @@ -25640,12 +25702,12 @@ } }, "@map-colonies/express-access-log-middleware": { - "version": "2.0.1", - "resolved": "https://registry.npmjs.org/@map-colonies/express-access-log-middleware/-/express-access-log-middleware-2.0.1.tgz", - "integrity": "sha512-n3m96LEl/P77LOWU/E67b4H72Kn52QQJoQyOAWcNdsw0ABpWzkzO++qiy/Djhnv6PaS0xYGPrTr061U3SBazgg==", + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/@map-colonies/express-access-log-middleware/-/express-access-log-middleware-2.1.0.tgz", + "integrity": "sha512-3jYPG5hl56WjzpRwY9Tvb2HXk3sq95CCfdoQsdFfhlp16LofEXtlANDOE1lOW9yBntGy76adnqYSsF2ElbHRUA==", "requires": { - "http-status-codes": "^2.1.4", - "pino-http": "^8.3.3" + "http-status-codes": "^2.3.0", + "pino-http": "^10.3.0" } }, "@map-colonies/js-logger": { @@ -27696,6 +27758,12 @@ "@types/koa": "*" } }, + "@types/lodash": { + "version": "4.17.12", + "resolved": "https://registry.npmjs.org/@types/lodash/-/lodash-4.17.12.tgz", + "integrity": "sha512-sviUmCE8AYdaF/KIHLDJBQgeYzPBI0vf/17NaYehBJfYD1j6/L95Slh07NlyK2iNyBNaEkb3En2jRt+a8y3xZQ==", + "dev": true + }, "@types/memcached": { "version": "2.2.10", "resolved": "https://registry.npmjs.org/@types/memcached/-/memcached-2.2.10.tgz", @@ -32317,9 +32385,9 @@ } }, "http-status-codes": { - "version": "2.2.0", - "resolved": "https://registry.npmjs.org/http-status-codes/-/http-status-codes-2.2.0.tgz", - "integrity": "sha512-feERVo9iWxvnejp3SEfm/+oNG517npqL2/PIA8ORjyOZjGC7TwCRQsZylciLS64i6pJ0wRYz3rkXLRwbtFa8Ng==" + "version": "2.3.0", + "resolved": "https://registry.npmjs.org/http-status-codes/-/http-status-codes-2.3.0.tgz", + "integrity": "sha512-RJ8XvFvpPM/Dmc5SV+dC4y5PCeOhT3x1Hq0NU3rjGeg5a/CqlhZ7uudknPwZFz4aeAXDcbAyaeP7GAo9lvngtA==" }, "http2-client": { "version": "1.3.5", @@ -35338,6 +35406,11 @@ "resolved": "https://registry.npmjs.org/obuf/-/obuf-1.1.2.tgz", "integrity": "sha512-PX1wu0AmAdPqOL1mWhqmlOd8kOIZQwGZw6rh7uby9fTc5lhaOWFLX3I6R1hrF9k3zUY40e6igsLGkDXK92LJNg==" }, + "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==" + }, "on-finished": { "version": "2.4.1", "resolved": "https://registry.npmjs.org/on-finished/-/on-finished-2.4.1.tgz", @@ -35871,11 +35944,6 @@ "ieee754": "^1.2.1" } }, - "on-exit-leak-free": { - "version": "2.1.0", - "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.0.tgz", - "integrity": "sha512-VuCaZZAjReZ3vUwgOB8LxAosIurDiAW0s13rI1YwmaP++jvcxP77AWoQvenZebpCA2m8WC1/EosPYPMjnRAp/w==" - }, "pino-abstract-transport": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-1.0.0.tgz", @@ -35896,11 +35964,6 @@ "process": "^0.11.10" } }, - "real-require": { - "version": "0.2.0", - "resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz", - "integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==" - }, "sonic-boom": { "version": "3.3.0", "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-3.3.0.tgz", @@ -35919,15 +35982,53 @@ } } }, + "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==", + "requires": { + "split2": "^4.0.0" + } + }, "pino-http": { - "version": "8.3.3", - "resolved": "https://registry.npmjs.org/pino-http/-/pino-http-8.3.3.tgz", - "integrity": "sha512-p4umsNIXXVu95HD2C8wie/vXH7db5iGRpc+yj1/ZQ3sRtTQLXNjoS6Be5+eI+rQbqCRxen/7k/KSN+qiZubGDw==", + "version": "10.3.0", + "resolved": "https://registry.npmjs.org/pino-http/-/pino-http-10.3.0.tgz", + "integrity": "sha512-kaHQqt1i5S9LXWmyuw6aPPqYW/TjoDPizPs4PnDW4hSpajz2Uo/oisNliLf7We1xzpiLacdntmw8yaZiEkppQQ==", "requires": { "get-caller-file": "^2.0.5", - "pino": "^8.0.0", - "pino-std-serializers": "^6.0.0", - "process-warning": "^2.0.0" + "pino": "^9.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^4.0.0" + }, + "dependencies": { + "pino": { + "version": "9.5.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-9.5.0.tgz", + "integrity": "sha512-xSEmD4pLnV54t0NOUN16yCl7RIB1c5UUOse5HSyEXtBp+FgFQyPeDutc+Q2ZO7/22vImV7VfEjH/1zV2QuqvYw==", + "requires": { + "atomic-sleep": "^1.0.0", + "fast-redact": "^3.1.1", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^2.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^4.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" + } + }, + "pino-std-serializers": { + "version": "7.0.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.0.0.tgz", + "integrity": "sha512-e906FRY0+tV27iq4juKzSYPbUj2do2X2JX4EzSca1631EB2QJQUqGbDuERal7LCtOpxl6x3+nvo9NPZcmjkiFA==" + }, + "process-warning": { + "version": "4.0.0", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-4.0.0.tgz", + "integrity": "sha512-/MyYDxttz7DfGMMHiysAsFE4qF+pQYAA8ziO/3NcRVrQ5fSk+Mns4QZA/oRPFzvcqNoVJXQNWNAsdwBXLUkQKw==" + } } }, "pino-pretty": { @@ -35960,11 +36061,6 @@ "ieee754": "^1.2.1" } }, - "on-exit-leak-free": { - "version": "2.1.0", - "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.0.tgz", - "integrity": "sha512-VuCaZZAjReZ3vUwgOB8LxAosIurDiAW0s13rI1YwmaP++jvcxP77AWoQvenZebpCA2m8WC1/EosPYPMjnRAp/w==" - }, "pino-abstract-transport": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-1.0.0.tgz", @@ -36581,6 +36677,11 @@ "picomatch": "^2.2.1" } }, + "real-require": { + "version": "0.2.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz", + "integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==" + }, "redent": { "version": "3.0.0", "resolved": "https://registry.npmjs.org/redent/-/redent-3.0.0.tgz", @@ -37224,6 +37325,14 @@ "integrity": "sha512-tf+h5W1IrjNm/9rKKj0JU2MDMruiopx0jjVA5zCdBtcGjfp0+c5rHw/zADLC3IeKlGHtVbHtpfzvYA0OYT+HKg==", "dev": true }, + "sonic-boom": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.0.tgz", + "integrity": "sha512-INb7TM37/mAcsGmc9hyyI6+QR3rR1zVRu36B0NeGXKnOOLiZOfER5SA+N7X7k3yUYRzLWafduTDvJAfDswwEww==", + "requires": { + "atomic-sleep": "^1.0.0" + } + }, "source-map": { "version": "0.6.1", "resolved": "https://registry.npmjs.org/source-map/-/source-map-0.6.1.tgz", @@ -37731,6 +37840,14 @@ "integrity": "sha1-f17oI66AUgfACvLfSoTsP8+lcLQ=", "dev": true }, + "thread-stream": { + "version": "3.1.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-3.1.0.tgz", + "integrity": "sha512-OqyPZ9u96VohAyMfJykzmivOrY2wfMSf3C5TtFJVgN+Hm6aj+voFhlK+kZEIv2FBh1X6Xp3DlnCOfEQ3B2J86A==", + "requires": { + "real-require": "^0.2.0" + } + }, "through": { "version": "2.3.8", "resolved": "https://registry.npmjs.org/through/-/through-2.3.8.tgz", diff --git a/package.json b/package.json index fbfe5f7..53011fa 100644 --- a/package.json +++ b/package.json @@ -46,7 +46,7 @@ "@apidevtools/json-schema-ref-parser": "^11.5.4", "@godaddy/terminus": "^4.12.1", "@map-colonies/error-express-handler": "^2.1.0", - "@map-colonies/express-access-log-middleware": "^2.0.1", + "@map-colonies/express-access-log-middleware": "^2.1.0", "@map-colonies/js-logger": "^1.0.1", "@map-colonies/openapi-express-viewer": "^3.0.0", "@map-colonies/read-pkg": "0.0.1", @@ -69,6 +69,7 @@ "express-openapi-validator": "^5.0.4", "http-status-codes": "^2.2.0", "json-pointer": "0.6.2", + "lodash": "^4.17.21", "pg": "^8.11.5", "reflect-metadata": "^0.1.13", "tsyringe": "^4.8.0" @@ -87,6 +88,7 @@ "@types/express": "^4.17.17", "@types/jest": "^29.5.2", "@types/json-pointer": "^1.0.34", + "@types/lodash": "^4.17.12", "@types/multer": "^1.4.7", "@types/pg": "^8.11.5", "@types/supertest": "^2.0.12", diff --git a/src/common/logger.ts b/src/common/logger.ts new file mode 100644 index 0000000..1ce91fe --- /dev/null +++ b/src/common/logger.ts @@ -0,0 +1,60 @@ +import { AsyncLocalStorage } from 'node:async_hooks'; +import type { IncomingMessage, ServerResponse } from 'node:http'; +import { get } from 'lodash'; +import jsLogger, { Logger, LoggerOptions } from '@map-colonies/js-logger'; +import { getOtelMixin } from '@map-colonies/telemetry'; +import { NextFunction, Request, Response } from 'express'; +import { DependencyContainer } from 'tsyringe'; +import { SERVICES } from './constants'; +import { IConfig } from './interfaces'; + +const logContext = new AsyncLocalStorage(); + +export function addOperationIdToLog(req: IncomingMessage, res: ServerResponse, loggableObject: Record): unknown { + const operationId = get(req, 'openapi.schema.operationId') as string | undefined; + if (operationId !== undefined) { + loggableObject['operationId'] = operationId; + } + return loggableObject; +} + +export function enrichLogContext(values: object): void { + const store = logContext.getStore(); + if (store) { + Object.assign(store, values); + } +} + +export function loggerFactory(container: DependencyContainer): Logger { + const config = container.resolve(SERVICES.CONFIG); + const loggerConfig = config.get('telemetry.logger'); + + const logger = jsLogger({ + ...loggerConfig, + mixin: (mergeObj, level) => { + const otelMixin = getOtelMixin(); + const store = logContext.getStore(); + return { ...otelMixin(mergeObj, level), ...store }; + }, + }); + + return logger; +} + +export function logContextInjectionMiddleware(req: Request, res: Response, next: NextFunction): void { + logContext.run({}, () => { + next(); + }); +} + +export function logEnrichmentParamMiddlewareFactory( + logEntry: string +): (req: Request, res: Response, next: NextFunction, paramValue: unknown) => void { + return function (req: Request, res: Response, next: NextFunction, paramValue: unknown): void { + // eslint-disable-next-line @typescript-eslint/strict-boolean-expressions + if (paramValue) { + enrichLogContext({ [logEntry]: paramValue }); + } + next(); + }; +} diff --git a/src/configs/controllers/configController.ts b/src/configs/controllers/configController.ts index f56438f..ac2e6ff 100644 --- a/src/configs/controllers/configController.ts +++ b/src/configs/controllers/configController.ts @@ -16,6 +16,7 @@ import { SortQueryRepeatError, } from '../models/errors'; import { SchemaNotFoundError } from '../../schemas/models/errors'; +import { enrichLogContext } from '../../common/logger'; function configMapper(config: Config): components['schemas']['config'] { return { @@ -111,6 +112,8 @@ export class ConfigController { public postConfig: TypedRequestHandler<'/config', 'post'> = async (req, res, next) => { try { + enrichLogContext({ configName: req.body.configName, version: req.body.version, schemaId: req.body.schemaId }); + await this.manager.createConfig(req.body); return res.status(httpStatus.CREATED).json(); } catch (error) { diff --git a/src/configs/models/configManager.ts b/src/configs/models/configManager.ts index 0b0e0e7..e6f9bc2 100644 --- a/src/configs/models/configManager.ts +++ b/src/configs/models/configManager.ts @@ -6,6 +6,7 @@ import { parseISO } from 'date-fns'; import type { Prettify } from '../../common/interfaces'; import { ConfigRepository, ConfigSearchParams, SqlPaginationParams } from '../repositories/configRepository'; import { SERVICES } from '../../common/constants'; +import { enrichLogContext } from '../../common/logger'; import { paths, components } from '../../openapiTypes'; import { Config, SortOption } from './config'; import { Validator } from './configValidator'; @@ -24,22 +25,30 @@ export class ConfigManager { public async getConfig(name: string, version?: number, shouldDereferenceConfig?: boolean): Promise { if (shouldDereferenceConfig !== true) { + this.logger.debug('Retrieving config from the database with unresolved refs'); const config = await this.configRepository.getConfig(name, version); if (!config) { throw new ConfigNotFoundError('Config not found'); } + + enrichLogContext({ resolvedConfigVersion: config.version }); return config; } + this.logger.debug('Retrieving config from the database with resolved refs'); + const res = await this.configRepository.getConfigRecursive(name, version); if (!res) { throw new ConfigNotFoundError('Config not found'); } + enrichLogContext({ resolvedConfigVersion: res[0].version }); + const [config, refs] = res; if (refs.length > 0) { + this.logger.debug('Resolving refs for config', { refCount: refs.length }); this.replaceRefs(config.config, refs); } @@ -47,6 +56,8 @@ export class ConfigManager { } public async getConfigs(options?: GetConfigOptions): Promise<{ configs: Config[]; totalCount: number }> { + this.logger.debug('Preparing search params and retrieving configs from the database'); + const searchParams: ConfigSearchParams = {}; let paginationParams: SqlPaginationParams = {}; let sortParams: SortOption[] = []; @@ -75,6 +86,9 @@ export class ConfigManager { } public async createConfig(config: Omit): Promise { + this.logger.debug('Creating a new config'); + + this.logger.debug('fetching latest config with same name for validations'); const latestConfig = await this.configRepository.getConfig(config.configName); if (!latestConfig && config.version !== 1) { @@ -106,6 +120,7 @@ export class ConfigManager { } if (latestConfig !== undefined) { + this.logger.debug('a config with the same name already exists, incrementing version'); config.version++; } @@ -119,6 +134,7 @@ export class ConfigManager { * @throws {ConfigValidationError} If the config reference is not valid. */ private listConfigRefs(config: components['schemas']['config']['config']): ConfigReference[] { + this.logger.debug('Listing all the config references in the config object'); const refs: ConfigReference[] = []; pointer.walk(config, (val, key) => { @@ -143,19 +159,24 @@ export class ConfigManager { * @throws {ConfigValidationError} If the configuration is not valid. */ private replaceRefs(obj: JsonObject, refs: Awaited>): void { + this.logger.debug('Replacing all the references in the object with the corresponding values'); + // the input is not an object or an array so we don't need to do anything if (!Array.isArray(obj) && typeof obj !== 'object') { + this.logger.debug('The object is not an object or an array, skipping'); return; } const paths = new Map(); + this.logger.debug('Finding all the references in the object'); // find all the references in the object pointer.walk(obj, (val, key) => { if (key.endsWith('$ref/configName')) { const refPath = key.slice(0, key.lastIndexOf('/')); const ref = pointer.get(obj, refPath) as unknown; if (!this.configValidator.validateRef(ref)) { + this.logger.debug('The reference in the following path is not valid', { refPath }); throw new ConfigValidationError(`The reference in the following path ${refPath} is not valid`); } @@ -164,6 +185,7 @@ export class ConfigManager { }); for (const [path, ref] of paths) { + this.logger.debug('Replacing the reference in the object', { refPath: path, referenceObject: ref }); const config = refs.find((r) => r.configName === ref.configName && (ref.version === 'latest' || r.version === ref.version)); if (!config) { throw new Error(`could not find ref in db: ${JSON.stringify(ref)}`); @@ -182,6 +204,7 @@ export class ConfigManager { } if (path === '') { + this.logger.debug('The reference is in the root of the object, replacing the object with the reference'); Object.assign(obj, replacementValue); return; } diff --git a/src/configs/models/configValidator.ts b/src/configs/models/configValidator.ts index 1a44eb0..0d5b904 100644 --- a/src/configs/models/configValidator.ts +++ b/src/configs/models/configValidator.ts @@ -1,9 +1,11 @@ import { readFileSync } from 'node:fs'; import Ajv, { AnySchemaObject, ErrorObject, ValidateFunction } from 'ajv/dist/2019'; -import { injectable } from 'tsyringe'; +import { inject, injectable } from 'tsyringe'; import addFormats from 'ajv-formats'; +import { Logger } from '@map-colonies/js-logger'; import betterAjvErrors, { type IOutputError } from '@sidvind/better-ajv-errors'; import { SchemaManager } from '../../schemas/models/schemaManager'; +import { SERVICES } from '../../common/constants'; import { ConfigReference, configReferenceSchema } from './configReference'; @injectable() @@ -11,7 +13,10 @@ export class Validator { private readonly ajv: Ajv; private readonly ajvRefValidator: ValidateFunction; - public constructor(private readonly schemaManager: SchemaManager) { + public constructor( + private readonly schemaManager: SchemaManager, + @inject(SERVICES.LOGGER) private readonly logger: Logger + ) { const draft7MetaSchema = JSON.parse( readFileSync(require.resolve('ajv/dist/refs/json-schema-draft-07.json'), { encoding: 'utf-8' }) ) as AnySchemaObject; @@ -31,6 +36,7 @@ export class Validator { } public async isValid(schemaId: string, data: unknown): Promise<[boolean, IOutputError[]?]> { + this.logger.info('Validating config data', { schemaId }); const validate = await this.ajv.compileAsync(await this.schemaManager.getSchema(schemaId)); const valid = validate(data); diff --git a/src/configs/repositories/configRepository.ts b/src/configs/repositories/configRepository.ts index 39cea0b..0da182f 100644 --- a/src/configs/repositories/configRepository.ts +++ b/src/configs/repositories/configRepository.ts @@ -1,6 +1,7 @@ -import { Logger, SQL, SQLWrapper, and, asc, desc, eq, gt, isNull, lt, or, sql } from 'drizzle-orm'; +import { SQL, SQLWrapper, and, asc, desc, eq, gt, isNull, lt, or, sql } from 'drizzle-orm'; import { inject, scoped, Lifecycle } from 'tsyringe'; import { toDate } from 'date-fns-tz'; +import { Logger } from '@map-colonies/js-logger'; import { SERVICES } from '../../common/constants'; import type { Drizzle } from '../../db/createConnection'; import { type Config, type NewConfig, type NewConfigRef, configs, configsRefs, SortOption } from '../models/config'; @@ -70,6 +71,7 @@ export class ConfigRepository { ) {} public async getAllConfigRefs(refs: ConfigReference[]): Promise { + this.logger.debug('Retrieving all config references', { refCount: refs.length }); const refsForSql = refs.map((ref) => ({ configName: ref.configName, version: ref.version === 'latest' ? null : ref.version })); // query to transform the input into a postgresql recordset so it can be joined with the data const inputCTE = sql` @@ -153,17 +155,20 @@ export class ConfigRepository { })); await this.drizzle.transaction(async (tx) => { + this.logger.debug('Inserting the config into the database'); await tx .insert(configs) .values({ ...configData, isLatest: true }) .execute(); if (dbRefs.length > 0) { + this.logger.debug('Inserting the config references into the database'); await tx.insert(configsRefs).values(dbRefs).execute(); } // set the previous version of the config to not be the latest if a previous version exists if (config.version !== 1) { + this.logger.debug('Setting the previous version of the config to not be the latest'); await tx .update(configs) .set({ isLatest: false }) @@ -181,6 +186,7 @@ export class ConfigRepository { * @returns A Promise that resolves to the retrieved configuration, or undefined if not found. */ public async getConfig(name: string, version?: number): Promise { + this.logger.debug('Retrieving the config from the database without resolving references'); const comparators = [eq(configs.configName, name)]; if (version !== undefined) { @@ -208,6 +214,7 @@ export class ConfigRepository { * @returns A promise that resolves to an array containing the configuration and its references, or undefined if not found. */ public async getConfigRecursive(name: string, version?: number): Promise<[Config, ConfigRefResponse[]] | undefined> { + this.logger.debug('Retrieving config and its references from the database'); // const maxVersion = maxVersionQueryBuilder(this.drizzle, name); const versionOperator = version !== undefined ? eq(configs.version, version) : eq(configs.isLatest, true); @@ -246,6 +253,7 @@ export class ConfigRepository { const configResult = res.rows.shift(); if (!configResult) { + this.logger.debug('No config found with the specified name and version'); return undefined; } @@ -274,6 +282,7 @@ export class ConfigRepository { paginationParams: SqlPaginationParams = { limit: 1, offset: 0 }, sortingParams: SortOption[] = [] ): Promise<{ configs: Config[]; totalCount: number }> { + this.logger.debug('Retrieving configs with filters from the database'); const filterParams: SQLWrapper[] = this.getFilterParams(searchParams); const orderByParams = sortingParams.map((sort) => (sort.order === 'asc' ? asc(configs[sort.field]) : desc(configs[sort.field]))); @@ -298,6 +307,7 @@ export class ConfigRepository { const configsResult = await configsQuery.execute(); if (configsResult.length === 0) { + this.logger.debug('No configs found with the specified filters'); return { configs: [], totalCount: 0 }; } @@ -317,6 +327,7 @@ export class ConfigRepository { } private getFilterParams(searchParams: ConfigSearchParams): SQLWrapper[] { + this.logger.debug('Building SQL filter params for the config search'); const filterParams: SQLWrapper[] = []; if (searchParams.q !== undefined && searchParams.q !== '') { diff --git a/src/configs/routes/configRouter.ts b/src/configs/routes/configRouter.ts index ef423b7..9792c9c 100644 --- a/src/configs/routes/configRouter.ts +++ b/src/configs/routes/configRouter.ts @@ -1,11 +1,15 @@ import { Router } from 'express'; import { FactoryFunction } from 'tsyringe'; import { ConfigController } from '../controllers/configController'; +import { logEnrichmentParamMiddlewareFactory } from '../../common/logger'; export const configRouterFactory: FactoryFunction = (dependencyContainer) => { const router = Router(); const controller = dependencyContainer.resolve(ConfigController); + router.param('name', logEnrichmentParamMiddlewareFactory('configName')); + router.param('version', logEnrichmentParamMiddlewareFactory('version')); + router.get('/', controller.getConfigs); router.post('/', controller.postConfig); router.get('/:name', controller.getConfigByName); diff --git a/src/containerConfig.ts b/src/containerConfig.ts index 28f8b1c..101f7e9 100644 --- a/src/containerConfig.ts +++ b/src/containerConfig.ts @@ -1,9 +1,8 @@ import config from 'config'; -import { getOtelMixin } from '@map-colonies/telemetry'; import { trace, metrics as OtelMetrics } from '@opentelemetry/api'; import { DependencyContainer } from 'tsyringe/dist/typings/types'; -import jsLogger, { LoggerOptions } from '@map-colonies/js-logger'; import { instancePerContainerCachingFactory } from 'tsyringe'; +import type { Pool } from 'pg'; import { Metrics } from '@map-colonies/telemetry'; import { SERVICES, SERVICE_NAME } from './common/constants'; import { tracing } from './common/tracing'; @@ -12,6 +11,7 @@ import { InjectionObject, registerDependencies } from './common/dependencyRegist import { CAPABILITIES_ROUTER_SYMBOL, capabilitiesRouterFactory } from './capabilities/routes/capabilitiesRouter'; import { CONFIG_ROUTER_SYMBOL, configRouterFactory } from './configs/routes/configRouter'; import { initConnection, createDrizzle, createConnectionOptions, DbConfig } from './db/createConnection'; +import { loggerFactory } from './common/logger'; export interface RegisterOptions { override?: InjectionObject[]; @@ -19,20 +19,22 @@ export interface RegisterOptions { } export async function registerExternalValues(options?: RegisterOptions): Promise { - const loggerConfig = config.get('telemetry.logger'); - const logger = jsLogger({ ...loggerConfig, prettyPrint: loggerConfig.prettyPrint, mixin: getOtelMixin() }); - const metrics = new Metrics(); metrics.start(); tracing.start(); const tracer = trace.getTracer(SERVICE_NAME); - const pool = await initConnection(createConnectionOptions(config.get('db'))); + let pool: Pool; + try { + pool = await initConnection(createConnectionOptions(config.get('db'))); + } catch (error) { + throw new Error(`Failed to connect to the database`, { cause: error }); + } const dependencies: InjectionObject[] = [ { token: SERVICES.CONFIG, provider: { useValue: config } }, - { token: SERVICES.LOGGER, provider: { useValue: logger } }, + { token: SERVICES.LOGGER, provider: { useFactory: instancePerContainerCachingFactory(loggerFactory) } }, { token: SERVICES.TRACER, provider: { useValue: tracer } }, { token: SERVICES.METER, provider: { useValue: OtelMetrics.getMeterProvider().getMeter(SERVICE_NAME) } }, { token: SCHEMA_ROUTER_SYMBOL, provider: { useFactory: schemaRouterFactory } }, diff --git a/src/index.ts b/src/index.ts index b88423b..133b40c 100644 --- a/src/index.ts +++ b/src/index.ts @@ -27,6 +27,6 @@ void getApp() }) .catch((error: Error) => { console.error('😢 - failed initializing the server'); - console.error(error.message); + console.error(error); process.exit(1); }); diff --git a/src/schemas/controllers/schemaController.ts b/src/schemas/controllers/schemaController.ts index b70f998..04041db 100644 --- a/src/schemas/controllers/schemaController.ts +++ b/src/schemas/controllers/schemaController.ts @@ -6,6 +6,7 @@ import { SERVICES } from '../../common/constants'; import { SchemaManager } from '../models/schemaManager'; import { SchemaNotFoundError, SchemaPathIsInvalidError } from '../models/errors'; import { TypedRequestHandler } from '../../common/interfaces'; +import { enrichLogContext } from '../../common/logger'; @injectable() export class SchemaController { @@ -16,6 +17,7 @@ export class SchemaController { public getSchema: TypedRequestHandler<'/schema', 'get'> = async (req, res, next) => { try { + enrichLogContext({ schemaId: req.query.id }); const schema = await this.manager.getSchema(req.query.id, req.query.shouldDereference); return res.status(httpStatus.OK).json(schema as unknown as Record); diff --git a/src/schemas/models/schemaManager.ts b/src/schemas/models/schemaManager.ts index 400da49..6166729 100644 --- a/src/schemas/models/schemaManager.ts +++ b/src/schemas/models/schemaManager.ts @@ -83,13 +83,14 @@ export class SchemaManager { const cacheKey = String(isDereferenced) + ':' + relativePath; if (this.schemaMap.has(cacheKey)) { + this.logger.debug('schema loaded from cache'); return this.schemaMap.get(cacheKey) as JSONSchema; } const fullPath = path.join(schemasBasePath, relativePath + '.schema.json'); if (!fs.existsSync(fullPath)) { - this.logger.error({ msg: 'schema not found', path: fullPath }); + this.logger.warn({ msg: 'schema not found', path: fullPath }); throw new SchemaNotFoundError(); } diff --git a/src/serverBuilder.ts b/src/serverBuilder.ts index e786e77..948fef1 100644 --- a/src/serverBuilder.ts +++ b/src/serverBuilder.ts @@ -14,6 +14,7 @@ import { IConfig } from './common/interfaces'; import { SCHEMA_ROUTER_SYMBOL } from './schemas/routes/schemaRouter'; import { CAPABILITIES_ROUTER_SYMBOL } from './capabilities/routes/capabilitiesRouter'; import { CONFIG_ROUTER_SYMBOL } from './configs/routes/configRouter'; +import { addOperationIdToLog, logContextInjectionMiddleware } from './common/logger'; @injectable() export class ServerBuilder { @@ -42,6 +43,8 @@ export class ServerBuilder { } private buildDocsRoutes(): void { + this.logger.info('Building docs routes'); + const openapiRouter = new OpenapiViewerRouter({ ...this.config.get('openapiConfig'), filePathOrSpec: this.openapiFilePath, @@ -59,10 +62,19 @@ export class ServerBuilder { } private registerPreRoutesMiddleware(): void { + this.serverInstance.use(logContextInjectionMiddleware); + this.buildDocsRoutes(); this.serverInstance.use(new RegExp(`(/metrics)|${this.apiPrefix}.*`), collectMetricsExpressMiddleware({})); - this.serverInstance.use(httpLogger({ logger: this.logger, ignorePaths: ['/metrics'] })); + this.serverInstance.use( + httpLogger({ + logger: this.logger, + ignorePaths: ['/metrics'], + customSuccessObject: addOperationIdToLog, + customErrorObject: (req, res, err, val) => addOperationIdToLog(req, res, val as Record), + }) + ); if (this.config.get('server.response.compression.enabled')) { this.serverInstance.use(compression(this.config.get('server.response.compression.options'))); diff --git a/tests/unit/config/configManager.spec.ts b/tests/unit/config/configManager.spec.ts index 938f9f8..babcff7 100644 --- a/tests/unit/config/configManager.spec.ts +++ b/tests/unit/config/configManager.spec.ts @@ -1,4 +1,4 @@ -import { Logger } from '@map-colonies/js-logger'; +import jsLogger, { Logger } from '@map-colonies/js-logger'; import { ConfigManager } from '../../../src/configs/models/configManager'; import { ConfigRefResponse, ConfigRepository } from '../../../src/configs/repositories/configRepository'; import { Validator } from '../../../src/configs/models/configValidator'; @@ -16,7 +16,7 @@ describe('ConfigManager', () => { let logger: Logger; beforeEach(() => { - logger = {} as Logger; + logger = jsLogger({ enabled: false }); configRepository = {} as ConfigRepository; configValidator = {} as Validator; configManager = new ConfigManager(logger, configRepository, configValidator); diff --git a/tests/unit/config/configValidator.spec.ts b/tests/unit/config/configValidator.spec.ts index a78b698..129299e 100644 --- a/tests/unit/config/configValidator.spec.ts +++ b/tests/unit/config/configValidator.spec.ts @@ -1,4 +1,5 @@ import betterAjvErrors from '@sidvind/better-ajv-errors'; +import jsLogger from '@map-colonies/js-logger'; import { Validator } from '../../../src/configs/models/configValidator'; import { SchemaManager } from '../../../src/schemas/models/schemaManager'; @@ -10,7 +11,7 @@ describe('Validator', () => { beforeEach(() => { schemaManager = {} as SchemaManager; - validator = new Validator(schemaManager); + validator = new Validator(schemaManager, jsLogger({ enabled: false })); }); describe('isValid', () => { diff --git a/tsconfig.json b/tsconfig.json index df0b2e1..9bea821 100644 --- a/tsconfig.json +++ b/tsconfig.json @@ -1,6 +1,7 @@ { "compilerOptions": { "target": "es2021", + "lib": ["ES2022"], "module": "NodeNext", "declaration": true, "outDir": "dist",