From 758464b33efd03b03ec852b3b3b5d4dd04e5c50a Mon Sep 17 00:00:00 2001 From: M7FZ <75252008+Zyprus@users.noreply.github.com> Date: Thu, 25 Jun 2026 18:16:28 +0400 Subject: [PATCH 1/4] feat(logger): add human-readable logging format and enhance LoggerService (#469) --- .env.example | 3 + CHANGELOG.md | 4 + package-lock.json | 78 +++++++-------- src/common/services/logger.service.spec.ts | 50 +++++++++- src/common/services/logger.service.ts | 110 ++++++++++++++++++++- 5 files changed, 196 insertions(+), 49 deletions(-) diff --git a/.env.example b/.env.example index fb56ee1f3..4c16267eb 100644 --- a/.env.example +++ b/.env.example @@ -10,6 +10,9 @@ NODE_ENV=production API_PORT=2785 LOG_LEVEL=info # error | warn | info | debug +# Console output format. Default: json in production (containers, log aggregators), +# human-readable pretty otherwise. Force one with: json | pretty +# LOG_FORMAT=pretty # Auto-start previously authenticated sessions on server boot AUTO_START_SESSIONS=false diff --git a/CHANGELOG.md b/CHANGELOG.md index 274a68f0e..916f21e68 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added + +- Human-readable console logs: the `LoggerService` now renders a colorized, NestJS-style line (`[OpenWA] - [Context] ` with dimmed `key=value` metadata and stack traces on their own line) instead of always emitting raw JSON, so application logs line up visually with NestJS's own framework logs. The format defaults to structured JSON in production (`NODE_ENV=production`, for containers and log aggregators) and human-readable pretty everywhere else, and can be pinned with `LOG_FORMAT=pretty|json`. `NO_COLOR` / `FORCE_COLOR` are honored. JSON output is byte-for-byte unchanged when selected. + ### Fixed - WebSocket events are now delivered exactly once to a client subscribed to overlapping rooms (for example both a specific event and the `*` wildcard for the same session). The real-time fan-out previously sent one copy per matching room, so such a client could receive the same event two to four times. The bundled dashboard was unaffected (its pages subscribe to disjoint rooms); this fixes duplicate delivery for custom WebSocket clients. diff --git a/package-lock.json b/package-lock.json index 02867a9da..44171e19e 100644 --- a/package-lock.json +++ b/package-lock.json @@ -767,7 +767,6 @@ "integrity": "sha512-CGOfOJqWjg2qW/Mb6zNsDm+u5vFQ8DxXfbM09z69p5Z6+mE1ikP2jUXw+j42Pf1XTYED2Rni5f95npYeuwMDQA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@babel/code-frame": "^7.29.0", "@babel/generator": "^7.29.0", @@ -1273,7 +1272,6 @@ "resolved": "https://registry.npmjs.org/@bull-board/api/-/api-8.0.1.tgz", "integrity": "sha512-7FELJHRQPtjH9+r/DUArr4pDVU8r1yeDS9azQUzFtIbsUT5xGjyg5R1RB0I/RfwFfK5bqho/4cpzxJ/UnQjSKA==", "license": "MIT", - "peer": true, "dependencies": { "redis-info": "^3.1.0" }, @@ -1312,7 +1310,6 @@ "resolved": "https://registry.npmjs.org/@bull-board/ui/-/ui-8.0.1.tgz", "integrity": "sha512-gKEGSD8dlUoWFGJJ4I4Q5bDtfB7yJwGfpgA2DVn1G1TzlUSN5n4fzzcGpLf5fS+QhR7tB/niydUiFRQ2zrjVrQ==", "license": "MIT", - "peer": true, "dependencies": { "@bull-board/api": "8.0.1" } @@ -1350,7 +1347,6 @@ "resolved": "https://registry.npmjs.org/keyv/-/keyv-5.6.0.tgz", "integrity": "sha512-CYDD3SOtsHtyXeEORYRx2qBtpDJFjRTGXUtmNEMGyzYOKj1TE3tycdlho7kA1Ufx9OYWZzg52QFBGALTirzDSw==", "license": "MIT", - "peer": true, "dependencies": { "@keyv/serialize": "^1.1.1" } @@ -1681,7 +1677,6 @@ "resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.14.4.tgz", "integrity": "sha512-k9Dj3DV/itK9D06Y8f190Qgop7/Ui+D0njFV3LHMPwPT75DpXLQohE9Wmz0QElrJnzsjB7KPWiKJbOl7IPDArQ==", "license": "Apache-2.0", - "peer": true, "dependencies": { "@grpc/proto-loader": "^0.8.0", "@js-sdsl/ordered-map": "^4.4.2" @@ -1713,7 +1708,6 @@ "resolved": "https://registry.npmjs.org/@grpc/proto-loader/-/proto-loader-0.7.15.tgz", "integrity": "sha512-tMXdRCfYVixjuFK+Hk0Q1s38gV9zDiDJfWL3h1rv4Qc39oILCu1TRTDt7+fGUI8K4G1Fj125Hx/ru3azECWTyQ==", "license": "Apache-2.0", - "peer": true, "dependencies": { "lodash.camelcase": "^4.3.0", "long": "^5.0.0", @@ -1825,6 +1819,7 @@ "resolved": "https://registry.npmjs.org/@img/colour/-/colour-1.1.0.tgz", "integrity": "sha512-Td76q7j57o/tLVdgS746cYARfSyxk8iEfRxewL9h4OMzYhbW4TAcppl0mT4eyqXddh6L/jwoM75mo7ixa/pCeQ==", "license": "MIT", + "peer": true, "engines": { "node": ">=18" } @@ -1841,6 +1836,7 @@ "os": [ "darwin" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -1863,6 +1859,7 @@ "os": [ "darwin" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -1882,6 +1879,7 @@ "os": [ "freebsd" ], + "peer": true, "dependencies": { "@img/sharp-wasm32": "0.35.1" }, @@ -1904,6 +1902,7 @@ "os": [ "darwin" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -1920,6 +1919,7 @@ "os": [ "darwin" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -1936,6 +1936,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -1952,6 +1953,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -1968,6 +1970,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -1984,6 +1987,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -2000,6 +2004,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -2016,6 +2021,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -2032,6 +2038,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -2048,6 +2055,7 @@ "os": [ "linux" ], + "peer": true, "funding": { "url": "https://opencollective.com/libvips" } @@ -2064,6 +2072,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2086,6 +2095,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2108,6 +2118,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2130,6 +2141,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2152,6 +2164,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2174,6 +2187,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2196,6 +2210,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2218,6 +2233,7 @@ "os": [ "linux" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2234,6 +2250,7 @@ "integrity": "sha512-PCQUoQdZyE8tp3HpbevuihfUmgSP4qWI0FGEPWoeXqaS+cUrFfemabHQiebUmUmlUhCuNnQMxGrQ+CPqK4hnxg==", "license": "Apache-2.0 AND LGPL-3.0-or-later AND MIT", "optional": true, + "peer": true, "dependencies": { "@emnapi/runtime": "^1.11.0" }, @@ -2253,6 +2270,7 @@ ], "license": "Apache-2.0", "optional": true, + "peer": true, "dependencies": { "@img/sharp-wasm32": "0.35.1" }, @@ -2275,6 +2293,7 @@ "os": [ "win32" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -2294,6 +2313,7 @@ "os": [ "win32" ], + "peer": true, "engines": { "node": "^20.9.0" }, @@ -2313,6 +2333,7 @@ "os": [ "win32" ], + "peer": true, "engines": { "node": ">=20.9.0" }, @@ -3576,7 +3597,6 @@ "resolved": "https://registry.npmjs.org/@nestjs/bull-shared/-/bull-shared-11.0.4.tgz", "integrity": "sha512-VBJcDHSAzxQnpcDfA0kt9MTGUD1XZzfByV70su0W0eDCQ9aqIEBlzWRW21tv9FG9dIut22ysgDidshdjlnczLw==", "license": "MIT", - "peer": true, "dependencies": { "tslib": "2.8.1" }, @@ -3731,7 +3751,6 @@ "resolved": "https://registry.npmjs.org/@nestjs/common/-/common-11.1.27.tgz", "integrity": "sha512-kEGSzqM2lWr4whh4Ubflw+oPZSEzxvRMu9WL+LveZploJWTjec5bBlCiRVlVzTPg2kIwBiLwWSvCCW7Wnin1gg==", "license": "MIT", - "peer": true, "dependencies": { "file-type": "21.3.4", "iterare": "1.2.1", @@ -3778,7 +3797,6 @@ "resolved": "https://registry.npmjs.org/@nestjs/core/-/core-11.1.27.tgz", "integrity": "sha512-K6DX7hcqmZdeXkv7tsPakKBRCgqL19a4mtbX4FluY0hWtFdtPKp6lbe+lb8gWPfvLdbOWr/CPScn7BSjBX+Ecg==", "license": "MIT", - "peer": true, "dependencies": { "fast-safe-stringify": "2.1.1", "iterare": "1.2.1", @@ -3838,7 +3856,6 @@ "resolved": "https://registry.npmjs.org/@nestjs/platform-express/-/platform-express-11.1.27.tgz", "integrity": "sha512-0ZFhz6H6EdGh4xQVbUNwjoAwBuz73P7FvUAl67h9CTdMqQlJDaQYJApBv8pKfVZ1fGjMCbl0m9DcC6pXaZPWSQ==", "license": "MIT", - "peer": true, "dependencies": { "cors": "2.8.6", "express": "5.2.1", @@ -3860,7 +3877,6 @@ "resolved": "https://registry.npmjs.org/@nestjs/platform-socket.io/-/platform-socket.io-11.1.27.tgz", "integrity": "sha512-xgpLzaIDGOCC6xOAtHnRAz8sqieFgGxxu3MN5ID026Jt6oeL3efp29N5QHhPr7UlqBfy/Jd02uj0POkZq6Au3Q==", "license": "MIT", - "peer": true, "dependencies": { "socket.io": "4.8.3", "tslib": "2.8.1" @@ -4073,7 +4089,6 @@ "resolved": "https://registry.npmjs.org/@nestjs/typeorm/-/typeorm-11.0.2.tgz", "integrity": "sha512-KQsmOKqIbfq+I1fe88rDq8QNfTU3C4b8MA2qOImhvIbIDOStcC+m+z2itf7vnWGQK0LZBFjWlYdRBID12qgZeg==", "license": "MIT", - "peer": true, "peerDependencies": { "@nestjs/common": "^10.0.0 || ^11.0.0", "@nestjs/core": "^10.0.0 || ^11.0.0", @@ -4664,7 +4679,6 @@ "integrity": "sha512-FXx2pKgId/WyYo2jXw63kk7/+TY7u7AziEJxJAnSFzHlqTAS3Ync6SvgYAN/k4/PQpnnVuzoMuVnByKK2qp0ag==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@types/estree": "*", "@types/json-schema": "*" @@ -4794,7 +4808,6 @@ "resolved": "https://registry.npmjs.org/@types/node/-/node-26.0.0.tgz", "integrity": "sha512-vf2YFi1iY9lHGwNJMs01biZFbKJkrZR1T6/MlzjhJLPdntOHLhTrDSnSVcdtvjihi4VQNlrFRIxLsDBlQpAipA==", "license": "MIT", - "peer": true, "dependencies": { "undici-types": "~8.3.0" } @@ -5020,7 +5033,6 @@ "integrity": "sha512-PJ5vePq5/ognBbrIcoC5+SHO5dfpeLPzP9FpLkzWrguoYQEeeSjlJpVwOpo1JRSTEi7dRcwNy4h4dzV70PqHcg==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@typescript-eslint/scope-manager": "8.61.1", "@typescript-eslint/types": "8.61.1", @@ -5772,7 +5784,6 @@ "integrity": "sha512-UVJyE9MttOsBQIDKw1skb9nAwQuR5wuGD3+82K6JgJlm/Y+KI92oNsMNGZCYdDsVtRHSak0pcV5Dno5+4jh9sw==", "devOptional": true, "license": "MIT", - "peer": true, "bin": { "acorn": "bin/acorn" }, @@ -5870,7 +5881,6 @@ "integrity": "sha512-fgFx7Hfoq60ytK2c7DhnF8jIvzYgOMxfugjLOSMHjLIPgenqa7S7oaagATUq99mV6IYvN2tRmC0wnTYX6iPbMw==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "fast-deep-equal": "^3.1.1", "fast-json-stable-stringify": "^2.0.0", @@ -6465,7 +6475,6 @@ "resolved": "https://registry.npmjs.org/bare-events/-/bare-events-2.8.2.tgz", "integrity": "sha512-riJjyv1/mHLIPX4RwiK+oW9/4c3TEUeORHKefKAKnZ5kyslbN+HXowtbaVEqt4IMUB7OXlfixcs6gsFeo/jhiQ==", "license": "Apache-2.0", - "peer": true, "peerDependencies": { "bare-abort-controller": "*" }, @@ -6755,7 +6764,6 @@ } ], "license": "MIT", - "peer": true, "dependencies": { "baseline-browser-mapping": "^2.10.12", "caniuse-lite": "^1.0.30001782", @@ -6846,7 +6854,6 @@ "resolved": "https://registry.npmjs.org/bullmq/-/bullmq-5.79.1.tgz", "integrity": "sha512-cteoHRr1FGOTUgzFrnMyBNGtQhNeVR8Ej6nImNSHQDJi4tj6GMD0p9ZG65ZsTnvR9RVf18dhRxWu4kFl634QGA==", "license": "MIT", - "peer": true, "dependencies": { "cron-parser": "4.9.0", "ioredis": "5.10.1", @@ -7164,7 +7171,6 @@ "integrity": "sha512-Qgzu8kfBvo+cA4962jnP1KkS6Dop5NS6g7R5LFYJr4b8Ub94PPQXUksCw9PvXoeXPRRddRNC5C1JQUR2SMGtnA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "readdirp": "^4.0.1" }, @@ -7243,15 +7249,13 @@ "version": "0.5.1", "resolved": "https://registry.npmjs.org/class-transformer/-/class-transformer-0.5.1.tgz", "integrity": "sha512-SQa1Ws6hUbfC98vKGxZH3KFY0Y1lm5Zm0SY8XX9zbK7FJCyVEac3ATW0RIpwzW+oOfmHE5PMPufDG9hCfoEOMw==", - "license": "MIT", - "peer": true + "license": "MIT" }, "node_modules/class-validator": { "version": "0.15.1", "resolved": "https://registry.npmjs.org/class-validator/-/class-validator-0.15.1.tgz", "integrity": "sha512-LqoS80HBBSCVhz/3KloUly0ovokxpdOLR++Al3J3+dHXWt9sTKlKd4eYtoxhxyUjoe5+UcIM+5k9MIxyBWnRTw==", "license": "MIT", - "peer": true, "dependencies": { "@types/validator": "^13.15.3", "libphonenumber-js": "^1.11.1", @@ -8104,8 +8108,7 @@ "version": "0.0.1581282", "resolved": "https://registry.npmjs.org/devtools-protocol/-/devtools-protocol-0.0.1581282.tgz", "integrity": "sha512-nv7iKtNZQshSW2hKzYNr46nM/Cfh5SEvE2oV0/SEGgc9XupIY5ggf84Cz8eJIkBce7S3bmTAauFD6aysMpnqsQ==", - "license": "BSD-3-Clause", - "peer": true + "license": "BSD-3-Clause" }, "node_modules/dezalgo": { "version": "1.0.4", @@ -8603,7 +8606,6 @@ "integrity": "sha512-1y+7C+vi12bUK1IpZeaV3gsH9fHLBmPvYmPx42pvT/E9yG0IC8g3PUZZgp0+JLJl7ZDK0flc2gc+Aw9dpCvIsQ==", "dev": true, "license": "MIT", - "peer": true, "workspaces": [ "packages/*" ], @@ -8663,7 +8665,6 @@ "integrity": "sha512-82GZUjRS0p/jganf6q1rEO25VSoHH0hKPCTrgillPjdI/3bgBhAE1QzHrHTizjpRvy6pGAvKjDJtk2pF9NDq8w==", "dev": true, "license": "MIT", - "peer": true, "bin": { "eslint-config-prettier": "bin/cli.js" }, @@ -9012,7 +9013,6 @@ "resolved": "https://registry.npmjs.org/express/-/express-5.2.1.tgz", "integrity": "sha512-hIS4idWWai69NezIdRt2xFVofaF4j+6INOpJlVOLDO8zXGpUVEVzIYk12UUi2JzjEzWL3IOAxcTubgz9Po0yXw==", "license": "MIT", - "peer": true, "dependencies": { "accepts": "^2.0.0", "body-parser": "^2.2.1", @@ -9979,7 +9979,6 @@ "resolved": "https://registry.npmjs.org/hono/-/hono-4.12.27.tgz", "integrity": "sha512-1yrb/+w6HWQJrUCLkJ2IF5jNIPvvFkblV5RNOYl6bV+OA6p9GLcMpHFFGTosSvHvcAUibuUukRqhlYI4z32C7Q==", "license": "MIT", - "peer": true, "engines": { "node": ">=16.9.0" } @@ -10210,7 +10209,6 @@ "resolved": "https://registry.npmjs.org/ioredis/-/ioredis-5.11.1.tgz", "integrity": "sha512-ehuGcf94bQXhfagULNXrJdfnWO38v070jxSx/qE87Kjzmu2fU7ro5EFAb+OPituLqgfyuQaym5DlrNydW2sJ9A==", "license": "MIT", - "peer": true, "dependencies": { "@ioredis/commands": "1.10.0", "cluster-key-slot": "1.1.1", @@ -10483,7 +10481,6 @@ "integrity": "sha512-Yi1jqNC/Oq0N4hBgNH/YvBpP1P57QqundgytzYqy3yqAa7NZPNjSoi4SGbRAXDMdBzNE6xBCi5U7RgfrvMEUVQ==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@jest/core": "30.4.2", "@jest/types": "30.4.1", @@ -12463,6 +12460,7 @@ "resolved": "https://registry.npmjs.org/object-hash/-/object-hash-3.0.0.tgz", "integrity": "sha512-RSn9F68PjH9HqtltsSnqYC1XXoWe9Bju5+213R98cNGttag9q9yAOTzdbsqvIa7aNm5WffBZFpWYr2aWrklWAw==", "license": "MIT", + "peer": true, "engines": { "node": ">= 6" } @@ -12851,7 +12849,6 @@ "resolved": "https://registry.npmjs.org/pg/-/pg-8.22.0.tgz", "integrity": "sha512-8wih1vVIBMxoUM2oB4soJsD9tDnDpLv4OXBJ+EJzFsvycD+lfyIreC2gGHq78f8jbLLt+bvlPTFdFZfJkOuzAA==", "license": "MIT", - "peer": true, "dependencies": { "pg-connection-string": "^2.14.0", "pg-pool": "^3.14.0", @@ -13190,7 +13187,6 @@ "integrity": "sha512-N2MylSdi48+5N/6S5j+maeHbUSIzzZ5uOcX5Hm4QpV8Dkb1HFjfAKTKX6yNPJQD9AhcT3ifHNB66tWTTJDi11Q==", "dev": true, "license": "MIT", - "peer": true, "bin": { "prettier": "bin/prettier.cjs" }, @@ -13906,8 +13902,7 @@ "version": "0.2.2", "resolved": "https://registry.npmjs.org/reflect-metadata/-/reflect-metadata-0.2.2.tgz", "integrity": "sha512-urBwgfrvVP/eAyXx4hluJivBKzuEbSQs9rKWCrCkbSxNv8mxPcUZKeuoF3Uy4mJl3Lwprp6yy5/39VWigZ4K6Q==", - "license": "Apache-2.0", - "peer": true + "license": "Apache-2.0" }, "node_modules/require-directory": { "version": "2.1.1", @@ -14056,7 +14051,6 @@ "resolved": "https://registry.npmjs.org/rxjs/-/rxjs-7.8.2.tgz", "integrity": "sha512-dhKf903U/PQZY6boNNtAGdWbG85WAbjT/1xYoZIC7FAY0yWapOBQVsVrDl58W86//e1VpMNBtRV4MaXfdMySFA==", "license": "Apache-2.0", - "peer": true, "dependencies": { "tslib": "^2.1.0" } @@ -14226,6 +14220,7 @@ "resolved": "https://registry.npmjs.org/sharp/-/sharp-0.35.1.tgz", "integrity": "sha512-lW979AMi+ESidzMv/Lnv+F9bknzLyxLqFI05Sm433vOeRcltgxQmXpnfOOFIAlKtwXU/ksupm2srQoFCkR214g==", "license": "Apache-2.0", + "peer": true, "dependencies": { "@img/colour": "^1.1.0", "detect-libc": "^2.1.2", @@ -14270,6 +14265,7 @@ "resolved": "https://registry.npmjs.org/semver/-/semver-7.8.4.tgz", "integrity": "sha512-rUCObTnP32Q08R2uuIrt7r9PlEonuTmtuXYcW6s5kjdlj3xbnwe+21yXptAUYcMAABLkYYTtnmzb3w3EDZfueA==", "license": "ISC", + "peer": true, "bin": { "semver": "bin/semver.js" }, @@ -14657,7 +14653,6 @@ "integrity": "sha512-GGIyOiFaG+TUra3JIfkI/zGP8yZYLPQ0pl1bH+ODjiX57sPhrLU5sQJn1y9bDKZUFYkX1crlrPfSYt0BKKdkog==", "hasInstallScript": true, "license": "BSD-3-Clause", - "peer": true, "dependencies": { "bindings": "^1.5.0", "node-addon-api": "^7.0.0", @@ -15183,7 +15178,6 @@ "integrity": "sha512-Thbli+OlOj+iMPYFBVBfJ3OmCAnaSyNn4M1vz9T6Gka5Jt9ba/HIR56joy65tY6kx/FCF5VXNB819Y7/GUrBGA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "fast-deep-equal": "^3.1.3", "fast-uri": "^3.0.1", @@ -15537,7 +15531,6 @@ "integrity": "sha512-f0FFpIdcHgn8zcPSbf1dRevwt047YMnaiJM3u2w2RewrB+fob/zePZcrOyQoLMMO7aBIddLcQIEK5dYjkLnGrQ==", "devOptional": true, "license": "MIT", - "peer": true, "dependencies": { "@cspotcode/source-map-support": "^0.8.0", "@tsconfig/node10": "^1.0.7", @@ -15722,7 +15715,6 @@ "resolved": "https://registry.npmjs.org/typeorm/-/typeorm-0.3.30.tgz", "integrity": "sha512-8T35PzjefOdqc2ZR9mwLQj0pUGp6lQhMbK2EvVMwJVJWlaoHm0v/Q6dThNOZkFchD+0yMg8gwjKM28ePiLSXSQ==", "license": "MIT", - "peer": true, "dependencies": { "@sqltools/formatter": "^1.2.5", "ansis": "^4.2.0", @@ -15942,7 +15934,6 @@ "integrity": "sha512-jl1vZzPDinLr9eUt3J/t7V6FgNEw9QjvBPdysz9KfQDD41fQrC2Y4vKQdiaUpFT4bXlb1RHhLpp8wtm6M5TgSw==", "devOptional": true, "license": "Apache-2.0", - "peer": true, "bin": { "tsc": "bin/tsc", "tsserver": "bin/tsserver" @@ -16283,7 +16274,6 @@ "integrity": "sha512-wGN3qcrBQIFmQ/c0AiOAQBvrZ5lmY8vbbMv4Mxfgzqd/B6+9pXtLo73WuS1dSGXM5QYY3hZnIbvx+K1xxe6FyA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@types/eslint-scope": "^3.7.7", "@types/estree": "^1.0.8", @@ -16352,7 +16342,6 @@ "integrity": "sha512-Thbli+OlOj+iMPYFBVBfJ3OmCAnaSyNn4M1vz9T6Gka5Jt9ba/HIR56joy65tY6kx/FCF5VXNB819Y7/GUrBGA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "fast-deep-equal": "^3.1.3", "fast-uri": "^3.0.1", @@ -16904,7 +16893,6 @@ "resolved": "https://registry.npmjs.org/zod/-/zod-4.4.3.tgz", "integrity": "sha512-ytENFjIJFl2UwYglde2jchW2Hwm4GJFLDiSXWdTrJQBIN9Fcyp7n4DhxJEiWNAJMV1/BqWfW/kkg71UDcHJyTQ==", "license": "MIT", - "peer": true, "funding": { "url": "https://github.com/sponsors/colinhacks" } diff --git a/src/common/services/logger.service.spec.ts b/src/common/services/logger.service.spec.ts index bcc68eeef..154da06f2 100644 --- a/src/common/services/logger.service.spec.ts +++ b/src/common/services/logger.service.spec.ts @@ -1,4 +1,4 @@ -import { LoggerService, LogLevel, createLogger } from './logger.service'; +import { LoggerService, LogLevel, LogFormat, createLogger } from './logger.service'; interface LogEntry { timestamp: string; @@ -16,6 +16,12 @@ function getLogOutput(spy: jest.SpyInstance): LogEntry { return JSON.parse(calls[0][0]) as LogEntry; } +// Helper to read the raw (unparsed) string a spy was called with. +function getRawOutput(spy: jest.SpyInstance): string { + const calls = spy.mock.calls as string[][]; + return calls[0][0]; +} + describe('LoggerService', () => { let logger: LoggerService; let consoleSpy: jest.SpyInstance; @@ -23,6 +29,8 @@ describe('LoggerService', () => { beforeEach(() => { logger = new LoggerService(); logger.setContext('TestContext'); + // Pin JSON so structured-output assertions are deterministic regardless of TTY/LOG_FORMAT. + LoggerService.setLogFormat(LogFormat.JSON); consoleSpy = jest.spyOn(console, 'log').mockImplementation(); jest.spyOn(console, 'warn').mockImplementation(); jest.spyOn(console, 'error').mockImplementation(); @@ -30,6 +38,8 @@ describe('LoggerService', () => { afterEach(() => { jest.restoreAllMocks(); + LoggerService.setLogFormat(null); + LoggerService.setLogLevel(LogLevel.INFO); }); describe('log', () => { @@ -94,6 +104,44 @@ describe('LoggerService', () => { }); }); + describe('pretty format', () => { + beforeEach(() => { + LoggerService.setLogFormat(LogFormat.PRETTY); + }); + + it('should render a NestJS-style human-readable line instead of JSON', () => { + logger.log('Test message'); + + const output = getRawOutput(consoleSpy); + // Not JSON. + expect(() => { + JSON.parse(output); + }).toThrow(); + // NestJS-style prefix, level label, context and message all present. + expect(output).toContain('[OpenWA]'); + expect(output).toContain('LOG'); + expect(output).toContain('[TestContext]'); + expect(output).toContain('Test message'); + }); + + it('should append metadata as key=value pairs', () => { + logger.log('Test message', { sessionId: '123', action: 'test' }); + + const output = getRawOutput(consoleSpy); + expect(output).toContain('sessionId=123'); + expect(output).toContain('action=test'); + }); + + it('should append the stack trace on a new line for errors', () => { + const errorSpy = jest.spyOn(console, 'error'); + logger.error('Error message', 'stack trace line'); + + const output = getRawOutput(errorSpy); + expect(output).toContain('Error message'); + expect(output).toContain('\nstack trace line'); + }); + }); + describe('createLogger', () => { it('should create logger with context', () => { const testLogger = createLogger('MyContext'); diff --git a/src/common/services/logger.service.ts b/src/common/services/logger.service.ts index 0f4e02916..8ed1f33f2 100644 --- a/src/common/services/logger.service.ts +++ b/src/common/services/logger.service.ts @@ -8,6 +8,11 @@ export enum LogLevel { VERBOSE = 'verbose', } +export enum LogFormat { + JSON = 'json', + PRETTY = 'pretty', +} + export interface LogContext { sessionId?: string; messageId?: string; @@ -17,15 +22,54 @@ export interface LogContext { [key: string]: unknown; } +// ANSI color codes — mirrors the palette NestJS's built-in ConsoleLogger uses so our +// pretty output blends in with the framework's own `[Nest] … LOG [Context]` lines. +const ANSI = { + reset: '\x1b[0m', + dim: '\x1b[2m', + red: '\x1b[31m', + green: '\x1b[32m', + yellow: '\x1b[33m', + magenta: '\x1b[35m', + cyan: '\x1b[36m', +} as const; + +const LEVEL_COLOR: Record = { + [LogLevel.ERROR]: ANSI.red, + [LogLevel.WARN]: ANSI.yellow, + [LogLevel.INFO]: ANSI.green, + [LogLevel.DEBUG]: ANSI.magenta, + [LogLevel.VERBOSE]: ANSI.cyan, +}; + +// NestJS prints `info` as `LOG`; match its labels so both log sources line up. +const LEVEL_LABEL: Record = { + [LogLevel.ERROR]: 'ERROR', + [LogLevel.WARN]: 'WARN', + [LogLevel.INFO]: 'LOG', + [LogLevel.DEBUG]: 'DEBUG', + [LogLevel.VERBOSE]: 'VERBOSE', +}; + +// Keys that are rendered in the line prefix rather than the trailing metadata. +const STRUCTURAL_KEYS = new Set(['timestamp', 'level', 'context', 'message', 'trace']); + @Injectable({ scope: Scope.TRANSIENT }) export class LoggerService implements NestLoggerService { private context: string = 'Application'; private static logLevel: LogLevel = LogLevel.INFO; + private static logFormat: LogFormat | null = null; static setLogLevel(level: LogLevel): void { LoggerService.logLevel = level; } + // Explicitly pin the output format. When unset, the format is resolved from + // LOG_FORMAT / TTY detection (see resolveFormat). + static setLogFormat(format: LogFormat | null): void { + LoggerService.logFormat = format; + } + setContext(context: string): void { this.context = context; } @@ -56,7 +100,7 @@ export class LoggerService implements NestLoggerService { const timestamp = new Date().toISOString(); const contextName = typeof context === 'string' ? context : this.context; - const metadata = typeof context === 'object' ? context : {}; + const metadata = typeof context === 'object' && context !== null ? context : {}; const logEntry = { timestamp, @@ -66,8 +110,10 @@ export class LoggerService implements NestLoggerService { ...metadata, }; - // Output as JSON for structured logging (easy to parse by log aggregators) - const output = JSON.stringify(logEntry); + const output = + LoggerService.resolveFormat() === LogFormat.PRETTY + ? this.formatPretty(level, logEntry) + : JSON.stringify(logEntry); switch (level) { case LogLevel.ERROR: @@ -81,6 +127,64 @@ export class LoggerService implements NestLoggerService { } } + // Render a single entry as a human-readable line in the same shape NestJS's ConsoleLogger uses + // (so it lines up with the framework's own output), but tagged honestly as [OpenWA]: + // [OpenWA] 1896 - 25/06/2026, 4:59:22 PM LOG [AuthService] API Docs: … sessionId=abc + private formatPretty(level: LogLevel, entry: Record): string { + const useColor = LoggerService.colorEnabled(); + const paint = (code: string, text: string): string => (useColor ? `${code}${text}${ANSI.reset}` : text); + + const levelColor = LEVEL_COLOR[level]; + const label = LEVEL_LABEL[level].padStart(7); + const timestamp = new Date(String(entry.timestamp)).toLocaleString(); + const contextName = String(entry.context); + const message = String(entry.message); + + // Trailing structured metadata (sessionId, action, duration, …) shown dimmed as key=value pairs. + const formatValue = (value: unknown): string => (typeof value === 'string' ? value : (JSON.stringify(value) ?? '')); + const meta = Object.entries(entry) + .filter(([key, value]) => !STRUCTURAL_KEYS.has(key) && value !== undefined) + .map(([key, value]) => `${key}=${formatValue(value)}`) + .join(' '); + + let line = + `${paint(levelColor, `[OpenWA] ${process.pid} -`)} ${timestamp} ` + + `${paint(levelColor, label)} ${paint(ANSI.yellow, `[${contextName}]`)} ${paint(levelColor, message)}`; + + if (meta) { + line += ` ${paint(ANSI.dim, meta)}`; + } + + // Error stack traces print on their own line(s), like NestJS. + if (typeof entry.trace === 'string' && entry.trace) { + line += `\n${paint(levelColor, entry.trace)}`; + } + + return line; + } + + private static resolveFormat(): LogFormat { + if (LoggerService.logFormat) return LoggerService.logFormat; + + const explicit = process.env.LOG_FORMAT?.trim().toLowerCase(); + if (explicit === LogFormat.JSON || explicit === LogFormat.PRETTY) { + return explicit; + } + + // No explicit choice: structured JSON in production (containers, log aggregators), + // human-readable pretty everywhere else. This mirrors NestJS's own logger, which + // always prints its text format — and unlike a TTY check it stays correct when + // stdout is piped through a dev runner (e.g. `concurrently` in `npm run dev`). + return process.env.NODE_ENV === 'production' ? LogFormat.JSON : LogFormat.PRETTY; + } + + private static colorEnabled(): boolean { + // Honor the de-facto NO_COLOR / FORCE_COLOR conventions; otherwise colorize only a real TTY. + if (process.env.NO_COLOR) return false; + if (process.env.FORCE_COLOR) return true; + return Boolean(process.stdout.isTTY); + } + private shouldLog(level: LogLevel): boolean { const levels = [LogLevel.ERROR, LogLevel.WARN, LogLevel.INFO, LogLevel.DEBUG, LogLevel.VERBOSE]; const currentIndex = levels.indexOf(LoggerService.logLevel); From b17d050d65a99c69a53353ea4492e62021ce6145 Mon Sep 17 00:00:00 2001 From: M7FZ <75252008+Zyprus@users.noreply.github.com> Date: Thu, 25 Jun 2026 18:16:28 +0400 Subject: [PATCH 2/4] feat(logger): add human-readable logging format and enhance LoggerService (#469) --- .env.example | 3 + CHANGELOG.md | 4 + src/common/services/logger.service.spec.ts | 50 +++++++++- src/common/services/logger.service.ts | 110 ++++++++++++++++++++- 4 files changed, 163 insertions(+), 4 deletions(-) diff --git a/.env.example b/.env.example index fb56ee1f3..4c16267eb 100644 --- a/.env.example +++ b/.env.example @@ -10,6 +10,9 @@ NODE_ENV=production API_PORT=2785 LOG_LEVEL=info # error | warn | info | debug +# Console output format. Default: json in production (containers, log aggregators), +# human-readable pretty otherwise. Force one with: json | pretty +# LOG_FORMAT=pretty # Auto-start previously authenticated sessions on server boot AUTO_START_SESSIONS=false diff --git a/CHANGELOG.md b/CHANGELOG.md index 19299a3ca..1c116a4e0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added + +- Human-readable console logs: the `LoggerService` now renders a colorized, NestJS-style line (`[OpenWA] - [Context] ` with dimmed `key=value` metadata and stack traces on their own line) instead of always emitting raw JSON, so application logs line up visually with NestJS's own framework logs. The format defaults to structured JSON in production (`NODE_ENV=production`, for containers and log aggregators) and human-readable pretty everywhere else, and can be pinned with `LOG_FORMAT=pretty|json`. `NO_COLOR` / `FORCE_COLOR` are honored. JSON output is byte-for-byte unchanged when selected. (#469) + ## [0.7.4] - 2026-06-25 ### Fixed diff --git a/src/common/services/logger.service.spec.ts b/src/common/services/logger.service.spec.ts index bcc68eeef..154da06f2 100644 --- a/src/common/services/logger.service.spec.ts +++ b/src/common/services/logger.service.spec.ts @@ -1,4 +1,4 @@ -import { LoggerService, LogLevel, createLogger } from './logger.service'; +import { LoggerService, LogLevel, LogFormat, createLogger } from './logger.service'; interface LogEntry { timestamp: string; @@ -16,6 +16,12 @@ function getLogOutput(spy: jest.SpyInstance): LogEntry { return JSON.parse(calls[0][0]) as LogEntry; } +// Helper to read the raw (unparsed) string a spy was called with. +function getRawOutput(spy: jest.SpyInstance): string { + const calls = spy.mock.calls as string[][]; + return calls[0][0]; +} + describe('LoggerService', () => { let logger: LoggerService; let consoleSpy: jest.SpyInstance; @@ -23,6 +29,8 @@ describe('LoggerService', () => { beforeEach(() => { logger = new LoggerService(); logger.setContext('TestContext'); + // Pin JSON so structured-output assertions are deterministic regardless of TTY/LOG_FORMAT. + LoggerService.setLogFormat(LogFormat.JSON); consoleSpy = jest.spyOn(console, 'log').mockImplementation(); jest.spyOn(console, 'warn').mockImplementation(); jest.spyOn(console, 'error').mockImplementation(); @@ -30,6 +38,8 @@ describe('LoggerService', () => { afterEach(() => { jest.restoreAllMocks(); + LoggerService.setLogFormat(null); + LoggerService.setLogLevel(LogLevel.INFO); }); describe('log', () => { @@ -94,6 +104,44 @@ describe('LoggerService', () => { }); }); + describe('pretty format', () => { + beforeEach(() => { + LoggerService.setLogFormat(LogFormat.PRETTY); + }); + + it('should render a NestJS-style human-readable line instead of JSON', () => { + logger.log('Test message'); + + const output = getRawOutput(consoleSpy); + // Not JSON. + expect(() => { + JSON.parse(output); + }).toThrow(); + // NestJS-style prefix, level label, context and message all present. + expect(output).toContain('[OpenWA]'); + expect(output).toContain('LOG'); + expect(output).toContain('[TestContext]'); + expect(output).toContain('Test message'); + }); + + it('should append metadata as key=value pairs', () => { + logger.log('Test message', { sessionId: '123', action: 'test' }); + + const output = getRawOutput(consoleSpy); + expect(output).toContain('sessionId=123'); + expect(output).toContain('action=test'); + }); + + it('should append the stack trace on a new line for errors', () => { + const errorSpy = jest.spyOn(console, 'error'); + logger.error('Error message', 'stack trace line'); + + const output = getRawOutput(errorSpy); + expect(output).toContain('Error message'); + expect(output).toContain('\nstack trace line'); + }); + }); + describe('createLogger', () => { it('should create logger with context', () => { const testLogger = createLogger('MyContext'); diff --git a/src/common/services/logger.service.ts b/src/common/services/logger.service.ts index 0f4e02916..8ed1f33f2 100644 --- a/src/common/services/logger.service.ts +++ b/src/common/services/logger.service.ts @@ -8,6 +8,11 @@ export enum LogLevel { VERBOSE = 'verbose', } +export enum LogFormat { + JSON = 'json', + PRETTY = 'pretty', +} + export interface LogContext { sessionId?: string; messageId?: string; @@ -17,15 +22,54 @@ export interface LogContext { [key: string]: unknown; } +// ANSI color codes — mirrors the palette NestJS's built-in ConsoleLogger uses so our +// pretty output blends in with the framework's own `[Nest] … LOG [Context]` lines. +const ANSI = { + reset: '\x1b[0m', + dim: '\x1b[2m', + red: '\x1b[31m', + green: '\x1b[32m', + yellow: '\x1b[33m', + magenta: '\x1b[35m', + cyan: '\x1b[36m', +} as const; + +const LEVEL_COLOR: Record = { + [LogLevel.ERROR]: ANSI.red, + [LogLevel.WARN]: ANSI.yellow, + [LogLevel.INFO]: ANSI.green, + [LogLevel.DEBUG]: ANSI.magenta, + [LogLevel.VERBOSE]: ANSI.cyan, +}; + +// NestJS prints `info` as `LOG`; match its labels so both log sources line up. +const LEVEL_LABEL: Record = { + [LogLevel.ERROR]: 'ERROR', + [LogLevel.WARN]: 'WARN', + [LogLevel.INFO]: 'LOG', + [LogLevel.DEBUG]: 'DEBUG', + [LogLevel.VERBOSE]: 'VERBOSE', +}; + +// Keys that are rendered in the line prefix rather than the trailing metadata. +const STRUCTURAL_KEYS = new Set(['timestamp', 'level', 'context', 'message', 'trace']); + @Injectable({ scope: Scope.TRANSIENT }) export class LoggerService implements NestLoggerService { private context: string = 'Application'; private static logLevel: LogLevel = LogLevel.INFO; + private static logFormat: LogFormat | null = null; static setLogLevel(level: LogLevel): void { LoggerService.logLevel = level; } + // Explicitly pin the output format. When unset, the format is resolved from + // LOG_FORMAT / TTY detection (see resolveFormat). + static setLogFormat(format: LogFormat | null): void { + LoggerService.logFormat = format; + } + setContext(context: string): void { this.context = context; } @@ -56,7 +100,7 @@ export class LoggerService implements NestLoggerService { const timestamp = new Date().toISOString(); const contextName = typeof context === 'string' ? context : this.context; - const metadata = typeof context === 'object' ? context : {}; + const metadata = typeof context === 'object' && context !== null ? context : {}; const logEntry = { timestamp, @@ -66,8 +110,10 @@ export class LoggerService implements NestLoggerService { ...metadata, }; - // Output as JSON for structured logging (easy to parse by log aggregators) - const output = JSON.stringify(logEntry); + const output = + LoggerService.resolveFormat() === LogFormat.PRETTY + ? this.formatPretty(level, logEntry) + : JSON.stringify(logEntry); switch (level) { case LogLevel.ERROR: @@ -81,6 +127,64 @@ export class LoggerService implements NestLoggerService { } } + // Render a single entry as a human-readable line in the same shape NestJS's ConsoleLogger uses + // (so it lines up with the framework's own output), but tagged honestly as [OpenWA]: + // [OpenWA] 1896 - 25/06/2026, 4:59:22 PM LOG [AuthService] API Docs: … sessionId=abc + private formatPretty(level: LogLevel, entry: Record): string { + const useColor = LoggerService.colorEnabled(); + const paint = (code: string, text: string): string => (useColor ? `${code}${text}${ANSI.reset}` : text); + + const levelColor = LEVEL_COLOR[level]; + const label = LEVEL_LABEL[level].padStart(7); + const timestamp = new Date(String(entry.timestamp)).toLocaleString(); + const contextName = String(entry.context); + const message = String(entry.message); + + // Trailing structured metadata (sessionId, action, duration, …) shown dimmed as key=value pairs. + const formatValue = (value: unknown): string => (typeof value === 'string' ? value : (JSON.stringify(value) ?? '')); + const meta = Object.entries(entry) + .filter(([key, value]) => !STRUCTURAL_KEYS.has(key) && value !== undefined) + .map(([key, value]) => `${key}=${formatValue(value)}`) + .join(' '); + + let line = + `${paint(levelColor, `[OpenWA] ${process.pid} -`)} ${timestamp} ` + + `${paint(levelColor, label)} ${paint(ANSI.yellow, `[${contextName}]`)} ${paint(levelColor, message)}`; + + if (meta) { + line += ` ${paint(ANSI.dim, meta)}`; + } + + // Error stack traces print on their own line(s), like NestJS. + if (typeof entry.trace === 'string' && entry.trace) { + line += `\n${paint(levelColor, entry.trace)}`; + } + + return line; + } + + private static resolveFormat(): LogFormat { + if (LoggerService.logFormat) return LoggerService.logFormat; + + const explicit = process.env.LOG_FORMAT?.trim().toLowerCase(); + if (explicit === LogFormat.JSON || explicit === LogFormat.PRETTY) { + return explicit; + } + + // No explicit choice: structured JSON in production (containers, log aggregators), + // human-readable pretty everywhere else. This mirrors NestJS's own logger, which + // always prints its text format — and unlike a TTY check it stays correct when + // stdout is piped through a dev runner (e.g. `concurrently` in `npm run dev`). + return process.env.NODE_ENV === 'production' ? LogFormat.JSON : LogFormat.PRETTY; + } + + private static colorEnabled(): boolean { + // Honor the de-facto NO_COLOR / FORCE_COLOR conventions; otherwise colorize only a real TTY. + if (process.env.NO_COLOR) return false; + if (process.env.FORCE_COLOR) return true; + return Boolean(process.stdout.isTTY); + } + private shouldLog(level: LogLevel): boolean { const levels = [LogLevel.ERROR, LogLevel.WARN, LogLevel.INFO, LogLevel.DEBUG, LogLevel.VERBOSE]; const currentIndex = levels.indexOf(LoggerService.logLevel); From 8a57b5c72cd6dd823bfd41e806fb193b1af5f7cc Mon Sep 17 00:00:00 2001 From: M7FZ <75252008+Zyprus@users.noreply.github.com> Date: Fri, 26 Jun 2026 13:38:56 +0400 Subject: [PATCH 3/4] fix(changelog): remove duplicate entry for human-readable console logs --- CHANGELOG.md | 4 ---- 1 file changed, 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d6f011ffd..1c116a4e0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,10 +9,6 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added -- Human-readable console logs: the `LoggerService` now renders a colorized, NestJS-style line (`[OpenWA] - [Context] ` with dimmed `key=value` metadata and stack traces on their own line) instead of always emitting raw JSON, so application logs line up visually with NestJS's own framework logs. The format defaults to structured JSON in production (`NODE_ENV=production`, for containers and log aggregators) and human-readable pretty everywhere else, and can be pinned with `LOG_FORMAT=pretty|json`. `NO_COLOR` / `FORCE_COLOR` are honored. JSON output is byte-for-byte unchanged when selected. - -### Added - - Human-readable console logs: the `LoggerService` now renders a colorized, NestJS-style line (`[OpenWA] - [Context] ` with dimmed `key=value` metadata and stack traces on their own line) instead of always emitting raw JSON, so application logs line up visually with NestJS's own framework logs. The format defaults to structured JSON in production (`NODE_ENV=production`, for containers and log aggregators) and human-readable pretty everywhere else, and can be pinned with `LOG_FORMAT=pretty|json`. `NO_COLOR` / `FORCE_COLOR` are honored. JSON output is byte-for-byte unchanged when selected. (#469) ## [0.7.4] - 2026-06-25 From 7973be97ec5c5113e29c8784887891851de72cd8 Mon Sep 17 00:00:00 2001 From: M7FZ <75252008+Zyprus@users.noreply.github.com> Date: Sun, 5 Jul 2026 18:35:11 +0400 Subject: [PATCH 4/4] fix(session): use forceDestroy() to reap orphaned Chromium on init failure start()'s crash-recovery path tore down a half-built engine with a graceful destroy(), but a failed engine.initialize() usually means the underlying browser/CDP connection is already broken (e.g. a TargetCloseError: Target closed mid script-injection). destroy() has nothing live to talk to in that case, so it can only time out via teardownEngineSafely's 10s race, leaving the Chromium process alive and orphaned. Every such crash left one more process behind, eventually starving the host of memory. Use forceDestroy() instead, the same SIGKILL-the-process recovery POST /:id/force-kill already uses for a wedged engine -- the exact state this catch block is handling. --- CHANGELOG.md | 4 ++++ src/modules/session/session.service.spec.ts | 8 +++++++- src/modules/session/session.service.ts | 9 ++++++++- 3 files changed, 19 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d1124f3e0..35acf37e9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **Native WhatsApp polls** via `POST /api/sessions/:sessionId/messages/send-poll`: question, 2–12 options and an optional `allowMultipleAnswers` flag (default single choice), implemented on both engines (whatsapp-web.js `Poll`, Baileys `poll` content with `selectableCount` 1/0). The message history stores the poll question as the body so the log stays readable. Polls are a first-class `poll` message type end to end — both engines map incoming poll messages to it, so the websocket/webhook events, persisted rows, and dashboard all report `poll` consistently. Thanks @alejo117. +### Fixed + +- **A session whose `engine.initialize()` fails no longer orphans its browser process.** The crash-recovery path in `SessionService.start()` was tearing down the half-built engine with a graceful `destroy()`, but a failed `initialize()` usually means the underlying browser/CDP connection is already broken (e.g. a `TargetCloseError: Target closed` mid-injection) — `destroy()` has nothing live to talk to, so it could only time out after 10s via `teardownEngineSafely`'s race, leaving the Chromium process alive and orphaned. Every such crash left one more orphaned process behind, eventually starving the host of memory. It now uses `forceDestroy()` (the same SIGKILL-the-process recovery `POST /:id/force-kill` uses), since a failed initialize is the same "possibly-unreachable engine" state that exists for. + ## [0.8.7] - 2026-07-03 ### Added diff --git a/src/modules/session/session.service.spec.ts b/src/modules/session/session.service.spec.ts index 9af3388bd..c9c316bd6 100644 --- a/src/modules/session/session.service.spec.ts +++ b/src/modules/session/session.service.spec.ts @@ -80,6 +80,7 @@ describe('SessionService', () => { mockEngine = { initialize: jest.fn().mockResolvedValue(undefined), destroy: jest.fn().mockResolvedValue(undefined), + forceDestroy: jest.fn().mockResolvedValue(undefined), disconnect: jest.fn().mockResolvedValue(undefined), getQRCode: jest.fn().mockReturnValue(null), getGroups: jest.fn().mockResolvedValue([]), @@ -375,7 +376,12 @@ describe('SessionService', () => { const engines = (service as unknown as { engines: Map }).engines; expect(engines.has('sess-uuid-1')).toBe(false); // not left orphaned → session can be started again - expect(mockEngine.destroy).toHaveBeenCalled(); // half-built engine torn down + // forceDestroy(), not destroy(): initialize() failing usually means the browser/CDP + // connection is already broken, so only a direct SIGKILL (forceDestroy) reliably reaps the + // OS-level Chromium process — a graceful destroy() has nothing live to talk to and can only + // time out, leaving the process orphaned (the actual bug this test now guards against). + expect(mockEngine.forceDestroy).toHaveBeenCalled(); + expect(mockEngine.destroy).not.toHaveBeenCalled(); }); it('allows a fresh start after the previous one completed (reservation is cleared)', async () => { diff --git a/src/modules/session/session.service.ts b/src/modules/session/session.service.ts index 74115ef70..f06f76081 100644 --- a/src/modules/session/session.service.ts +++ b/src/modules/session/session.service.ts @@ -457,11 +457,18 @@ export class SessionService implements OnModuleDestroy, OnModuleInit, OnApplicat // initializing). Evict + tear it down so the session doesn't wedge at "already started" with a // leaked Chromium/socket permanently holding a concurrency slot. initializingSessions serializes // start(), so the engine in the map here is the one this start just created. + // + // Use forceDestroy(), not destroy(): initialize() failing usually means the underlying + // browser/CDP connection is already broken (e.g. a "Target closed" crash mid-injection), so + // a graceful destroy() has nothing live to talk to — it can only time out via + // teardownEngineSafely's race, after which the orphaned Chromium process is never actually + // killed. forceDestroy() SIGKILLs the OS process directly, the same recovery force-kill uses + // for a wedged engine, which is exactly the state this catch block is handling. const orphan = this.engines.get(id); if (orphan) { this.engines.delete(id); this.sessionErrors.set(id, err instanceof Error ? err.message : String(err)); - await this.destroyEngineSafely(id, orphan); + await this.teardownEngineSafely(id, orphan, e => e.forceDestroy(), 'force-destroy'); await this.updateStatus(id, SessionStatus.FAILED).catch(() => undefined); } throw err;