From c2e70acc8446e9a9a2d1f1d32d54c6c47c8fed0f Mon Sep 17 00:00:00 2001 From: kaihere14 Date: Tue, 8 Sep 2026 15:25:29 +0530 Subject: [PATCH] feat: add Winston logging and Sarvam fallback provider Replace all 115 console.* calls with a tagged Winston logger and finish wiring Sarvam as the fallback provider across every LLM path. Logging (src/utils/logger.js): - One base logger with tagged children: server, github, ai, worker, queue, db, auth, email, convex, redis. The tag identifies the subsystem, so call sites no longer hand-write "[LLM]"-style prefixes into their messages. - AI lines carry the provider as a field (ai:Gemini, ai:Sarvam), so a fallback run reads as one provider failing and the other succeeding. - Structured meta instead of interpolated prose: repo, commit, path, provider, durationMs, status. - Readable lines in development, JSON in production, level via LOG_LEVEL. - Log uncaught exceptions and unhandled rejections. - Add per-request logging middleware (method, url, status, duration). - Drop the full completion dump in ai.sdk.js to debug level; it was printing every generated README to stdout. Sarvam fallback: - Route every Sarvam call through one method that checks for the API key, logs duration and failures, and rejects empty responses. - Add cleanup() to SarvamProvider and fall back in LlmService.cleanup(). - Pass a fallback provider into the patch pipeline, which previously had none and failed the run outright when Gemini was exhausted. - Log the reason on every fallback; the catch blocks were swallowing it. Live updates: - Rewrite the Convex live-update copy shown in the frontend: no vendor names, no internal mode jargon, present-tense steps. - Fire the patch pipeline's "rewriting sections" update before the model call rather than after it. --- server/package.json | 3 +- server/pnpm-lock.yaml | 191 ++++++++++++++++++++ server/src/controllers/email.controller.js | 11 +- server/src/controllers/github.controller.js | 88 +++++---- server/src/controllers/oauthcontroller.js | 24 ++- server/src/db/connectDB.js | 5 +- server/src/index.js | 33 ++-- server/src/llm/ai.sdk.js | 5 +- server/src/llm/llm.service.js | 19 +- server/src/llm/providers/gemini.provider.js | 11 +- server/src/llm/providers/sarvam.provider.js | 17 +- server/src/llm/readme.generate.js | 59 +++--- server/src/llm/readme.patch.js | 36 ++-- server/src/middlewares/auth.middleware.js | 6 +- server/src/services/convex.service.js | 13 +- server/src/services/email.queue.js | 3 +- server/src/services/github.service.js | 36 +++- server/src/utils/git.worker.js | 179 +++++++++++------- server/src/utils/logger.js | 132 ++++++++++++++ 19 files changed, 674 insertions(+), 197 deletions(-) create mode 100644 server/src/utils/logger.js diff --git a/server/package.json b/server/package.json index c80f694..e132d8e 100644 --- a/server/package.json +++ b/server/package.json @@ -29,7 +29,8 @@ "jsonwebtoken": "^9.0.3", "mongoose": "^9.1.2", "resend": "^6.9.4", - "sarvamai": "1.1.8-alpha.5" + "sarvamai": "1.1.8-alpha.5", + "winston": "^3.19.0" }, "devDependencies": { "@eslint/js": "^9.39.1", diff --git a/server/pnpm-lock.yaml b/server/pnpm-lock.yaml index 1d26dc0..c6e961e 100644 --- a/server/pnpm-lock.yaml +++ b/server/pnpm-lock.yaml @@ -50,6 +50,9 @@ importers: sarvamai: specifier: 1.1.8-alpha.5 version: 1.1.8-alpha.5 + winston: + specifier: ^3.19.0 + version: 3.19.0 devDependencies: '@eslint/js': specifier: ^9.39.1 @@ -88,6 +91,17 @@ packages: resolution: {integrity: sha512-6or44XprPzKbr8zkmzosowSE0pxkvJcoojBL+mCZvPUt3kvXp3XSNqeVun9golb1acEfSo6yaEBRT18h2VU+1Q==} engines: {node: '>=22'} + '@colors/colors@1.6.0': + resolution: {integrity: sha512-Ir+AOibqzrIsL6ajt3Rz3LskB7OiMVHqltZmspbW/TJuTVuyOMirVqAkjfY6JISiLHgyNqicAC8AyHHGzNd/dA==} + engines: {node: '>=0.1.90'} + + '@colors/colors@1.6.1': + resolution: {integrity: sha512-dTmUJzXSuayBK+hZydEaXd2mhx61qWQwkwaBBY6LyEOVx/L9aQU5ac8eFNEsd9nrD1+zb9zvDCphLSe8g1F4Qw==} + engines: {node: '>=0.1.90'} + + '@dabh/diagnostics@2.0.9': + resolution: {integrity: sha512-R6siwR65Hm+3yfgP7o8DKhNvputQAwfoz9zTc3kyDudnomj2/BcLmD+uGQQPICjuFUp8ounPBU+jmKsocwVVAg==} + '@esbuild/aix-ppc64@0.27.0': resolution: {integrity: sha512-KuZrd2hRjz01y5JK9mEBSD3Vj3mbCvemhT466rSuJYeE/hjuBrHfjjcjMdTm/sz7au+++sdbJZJmuBwQLuw68A==} engines: {node: '>=18'} @@ -338,6 +352,9 @@ packages: cpu: [x64] os: [win32] + '@so-ric/colorspace@1.1.6': + resolution: {integrity: sha512-/KiKkpHNOBgkFJwu9sh48LkHSMYGyuTcSFK/qMBdnOAlrRJzRSXAOFB5qwzaVQuDl8wAvHVMkaASQDReTahxuw==} + '@stablelib/base64@1.0.1': resolution: {integrity: sha512-1bnPQqSxSuc3Ii6MhBysoWCg58j97aUjuCSZrGSmDxNqtytIi0k8utUenAwTZN4V5mXXYGsVUI9zeBqy+jBOSQ==} @@ -350,6 +367,9 @@ packages: '@types/json-schema@7.0.15': resolution: {integrity: sha512-5+fP8P8MFNC+AyZCDxrB2pkZFPGzqQWUzpSeuuVLvm8VMcorNYavBqoFcxK8bQz4Qsbn4oUEEem4wDLfcysGHA==} + '@types/triple-beam@1.3.5': + resolution: {integrity: sha512-6WaYesThRMCl19iryMYP7/x2OVgCtbIVflDGFpWnb9irXI3UjYE4AzmYuiUKY1AJstGijoY+MgUszMgRxIYTYw==} + '@types/webidl-conversions@7.0.3': resolution: {integrity: sha512-CiJJvcRtIgzadHCYXw7dqEnMNRjhGZlYK05Mj9OyktqV8uVT8fD2BFOB7S1uwBE3Kj2Z+4UyPmFw/Ixgw/LAlA==} @@ -401,6 +421,9 @@ packages: argparse@2.0.1: resolution: {integrity: sha512-8+9WqebbFzpX9OR+Wa6O29asIogeRMzcGtAINdpMHHyAg10f05aSFVBbcEqGf/PXw1EjAZ+q2/bEBg3DvurK3Q==} + async@3.2.6: + resolution: {integrity: sha512-htCUDlxyyCLMgaM3xXg0C0LW2xqfuQ6p05pCEIsXuyQ+a1koYKTuBMzRNwmybfLgvJDMd0r1LTn4+E0Ti6C2AA==} + asynckit@0.4.0: resolution: {integrity: sha512-Oei9OH4tRh0YqU3GxhX79dM/mwVgvbZJaSNaRk+bshkj0S5cfHcgYakreBjrHwatXKbz+IoIdYLxrKim2MjW0Q==} @@ -476,9 +499,25 @@ packages: resolution: {integrity: sha512-RRECPsj7iu/xb5oKYcsFHSppFNnsj/52OVTRKb4zP5onXwVF3zVmmToNcOfGC+CRDpfK/U584fMg38ZHCaElKQ==} engines: {node: '>=7.0.0'} + color-convert@3.1.3: + resolution: {integrity: sha512-fasDH2ont2GqF5HpyO4w0+BcewlhHEZOFn9c1ckZdHpJ56Qb7MHhH/IcJZbBGgvdtwdwNbLvxiBEdg336iA9Sg==} + engines: {node: '>=14.6'} + color-name@1.1.4: resolution: {integrity: sha512-dOy+3AuW3a2wNbZHIuMZpTcgjGuLU/uBL/ubcZF9OXbDo8ff4O8yVp5Bf0efS8uEoYo5q4Fx7dY9OgQGXgAsQA==} + color-name@2.1.1: + resolution: {integrity: sha512-p2FdgwVx1a9yWBHP2wI0VgShkDpgN4kZISkxdNipGBJWpa5G6b04OINlVWCyJj0JmfvcPrgqt95E9k8yvaOJFg==} + engines: {node: '>=12.20'} + + color-string@2.1.4: + resolution: {integrity: sha512-Bb6Cq8oq0IjDOe8wJmi4JeNn763Xs9cfrBcaylK1tPypWzyoy2G3l90v9k64kjphl/ZJjPIShFztenRomi8WTg==} + engines: {node: '>=18'} + + color@5.0.3: + resolution: {integrity: sha512-ezmVcLR3xAVp8kYOm4GS45ZLLgIE6SPAFoduLr6hTDajwb3KZ2F46gulK3XpcwRFb5KKGCSezCBAY4Dw4HsyXA==} + engines: {node: '>=18'} + combined-stream@1.0.8: resolution: {integrity: sha512-FQN4MRfuJeHf7cBbBMJFXhKSDq+2kAArBlmRBvcvFE5BB1HZKXtSFASDhdlz9zOYwxh8lDdnvmMOe/+5cdoEdg==} engines: {node: '>= 0.8'} @@ -584,6 +623,9 @@ packages: ee-first@1.1.1: resolution: {integrity: sha512-WMwm9LhRUo+WUaRN+vRuETqG89IgZphVSNkdFgeb6sS/E4OrDIN7t48CAewSHXc6C8lefD8KKfr5vY61brQlow==} + enabled@2.0.0: + resolution: {integrity: sha512-AKrN98kuwOzMIdAizXGI86UFBoo26CL21UM763y1h/GMSJ4/OHU9k2YlsmBpyScFo/wbLzWQJBMCW4+IO3/+OQ==} + encodeurl@2.0.0: resolution: {integrity: sha512-Q0n9HRi4m6JuGIV1eFlmvJB7ZEVxu93IrMyiMsGC0lrMJMWzRgx6WGquyfQgZVb31vhGgXnfmPNNXmxnOkRBrg==} engines: {node: '>= 0.8'} @@ -683,6 +725,9 @@ packages: fast-sha256@1.3.0: resolution: {integrity: sha512-n11RGP/lrWEFI/bWdygLxhI+pVeo1ZYIVwvvPkW7azl/rOy+F3HYRZ2K5zeE9mmkhQppyv9sQFx0JM9UabnpPQ==} + fecha@4.2.3: + resolution: {integrity: sha512-OP2IUU6HeYKJi3i0z4A19kHMQoLVs4Hc+DPqqxI2h/DPZHTm/vjsfC6P0b4jCMy14XizLBqvndQ+UilD7707Jw==} + file-entry-cache@8.0.0: resolution: {integrity: sha512-XXTUwCvisa5oacNGRP9SfNtYBNAMi+RPwBFmblZEF7N7swHYQS6/Zfk7SRwx4D5j3CH211YNRco1DEMNVfZCnQ==} engines: {node: '>=16.0.0'} @@ -706,6 +751,9 @@ packages: flatted@3.4.4: resolution: {integrity: sha512-5+ybhBZANEJxaH3X5evAFatUxLfEHSr7n6kYJ+1Qd0mUqr4eu9gIf6GDbWHf8RJijHrjjO8G+la14SlL2SeS1Q==} + fn.name@1.1.0: + resolution: {integrity: sha512-GRnmB5gPyJpAhTQdSZTSp9uaPSvl09KoYcMQtsB9rQoOmzs9dH6ffeccH+Z+cv6P68Hu5bC6JjRh4Ah/mHSNRw==} + follow-redirects@1.16.0: resolution: {integrity: sha512-y5rN/uOsadFT/JfYwhxRS5R7Qce+g3zG97+JrtFZlC9klX/W5hD7iiLzScI4nZqUS7DNUdhPgw4xI8W2LuXlUw==} engines: {node: '>=4.0'} @@ -840,6 +888,10 @@ packages: is-promise@4.0.0: resolution: {integrity: sha512-hvpoI6korhJMnej285dSg6nu1+e6uxs7zG3BYAm5byqDsgJNWwxzM6z6iZiAgQR4TJ30JmBTOwqZUw3WlyH3AQ==} + is-stream@2.0.1: + resolution: {integrity: sha512-hFoiJiTl63nn+kstHGBtewWSKnQLpyb155KHheA1l39uvtO9nWIop1p3udqPcUd/xbF1VLMO4n7OI6p7RbngDg==} + engines: {node: '>=8'} + isexe@2.0.0: resolution: {integrity: sha512-RHxMLp9lnKHGHRng9QFhRCMbYAcVpn69smSGcq3f36xjgVVWThj4qqLbTLlq7Ssj8B+fIQ1EuCEGI2lKsyQeIw==} @@ -876,6 +928,9 @@ packages: keyv@4.5.4: resolution: {integrity: sha512-oxVHkHR/EJf2CNXnWxRLW6mg7JyCCUcG0DtEGmL2ctUo1PNTin1PUil+r/+4r5MpVgC/fn1kjsx7mjSujKqIpw==} + kuler@2.0.0: + resolution: {integrity: sha512-Xq9nH7KlWZmXAtodXDDRE7vs6DU1gTU8zYDHDiWLSip45Egwq3plLHzPn27NgvzL2r1LMPC1vdqh98sQxtqj4A==} + levn@0.4.1: resolution: {integrity: sha512-+bT2uH4E5LGE7h/n3evcS/sQlJXCpIp6ym8OWJ5eV6+67Dsql/LaaT7qJBAt2rzfoa/5QBGBhxDix1dMt2kQKQ==} engines: {node: '>= 0.8.0'} @@ -914,6 +969,10 @@ packages: lodash.once@4.1.1: resolution: {integrity: sha512-Sb487aTOCr9drQVL8pIxOzVhafOjZN9UU54hiN8PU3uAiSV7lx1yYNpbNmex2PK6dSJoNTSJUUswT651yww3Mg==} + logform@2.7.0: + resolution: {integrity: sha512-TFYA4jnP7PVbmlBIfhlSe+WKxs9dklXMTEGcBCIvLhE/Tn3H6Gk1norupVW7m5Cnd4bLcr08AytbyV/xj7f/kQ==} + engines: {node: '>= 12.0.0'} + luxon@3.7.2: resolution: {integrity: sha512-vtEhXh/gNjI9Yg1u4jX/0YVPMvxzHuGgCm6tC5kZyb08yjGWGnqAjGJvcXbqQR2P3MyMEFnRbpcdFS6PBcLqew==} engines: {node: '>=12'} @@ -1047,6 +1106,9 @@ packages: once@1.4.0: resolution: {integrity: sha512-lNaJgI+2Q5URQBkccEKHTQOPaXdUxnZZElQTZY0MFUAuaEqe1E+Nyvgdz/aIyNi6Z9MzO5dv1H8n58/GELp3+w==} + one-time@1.0.0: + resolution: {integrity: sha512-5DXOiRKwuSEcQ/l0kGCF6Q3jcADFv5tSmRaJck/OqkVFcOzutB134KRSfF0xDrL39MNnqxbHBbUUcjZIhTgb2g==} + optionator@0.9.4: resolution: {integrity: sha512-6IpQ7mKUxRcZNLIObR0hz7lxsapSSIYNZJwXPGeF0mTVqGKFIXj1DQcMoT22S3ROcLyY/rz0PWaWZ9ayWmad9g==} engines: {node: '>= 0.8.0'} @@ -1121,6 +1183,10 @@ packages: resolution: {integrity: sha512-K5zQjDllxWkf7Z5xJdV0/B0WTNqx6vxG70zJE4N0kBs4LovmEYWJzQGxC9bS9RAKu3bgM40lrd5zoLJ12MQ5BA==} engines: {node: '>= 0.10'} + readable-stream@3.6.2: + resolution: {integrity: sha512-9u/sniCrY3D5WdsERHzHE4G2YCXqoG5FTHUiCC4SIbr6XcLZBY05ya9EKjYek9O5xOAwjGq+1JdGBAS7Q9ScoA==} + engines: {node: '>= 6'} + readdirp@3.6.0: resolution: {integrity: sha512-hOS089on8RduqdbhvQ5Z37A0ESjsqz6qnRcffsMU3495FuTdqSm+7bhJ29JvIOsBDEEnan5DPu9t3To9VRlMzA==} engines: {node: '>=8.10.0'} @@ -1153,6 +1219,10 @@ packages: safe-buffer@5.2.1: resolution: {integrity: sha512-rp3So07KcdmmKbGvgaNxQSJr7bGVSVk5S9Eq1F+ppbRo70+YeaDxkw5Dd8NPN+GD6bjnYm2VuPuCXmpuYvmCXQ==} + safe-stable-stringify@2.5.0: + resolution: {integrity: sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==} + engines: {node: '>=10'} + safer-buffer@2.1.2: resolution: {integrity: sha512-YZo3K82SD7Riyi0E1EQPojLz7kpepnSQI9IyPbHHg1XXXevb5dJI7tpyN2ADxGcQbHG7vcyRHk0cbwqcQriUtg==} @@ -1210,6 +1280,9 @@ packages: sparse-bitfield@3.0.3: resolution: {integrity: sha512-kvzhi7vqKTfkh0PZU+2D2PIllw2ymqJKujUcyPMd9Y75Nv4nPbGJZXNhxsgdQab2BmlDct1YnfQCguEvHr7VsQ==} + stack-trace@0.0.10: + resolution: {integrity: sha512-KGzahc7puUKkzyMt+IqAep+TVNbKP+k2Lmwhub39m1AsTSkaDutx56aDCo+HLDzf/D26BIHTJWNiTG1KAJiQCg==} + standard-as-callback@2.1.0: resolution: {integrity: sha512-qoRRSyROncaz1z0mvYqIE4lCd9p2R90i6GxW3uZv5ucSu8tU7B5HXUP1gG8pVZsYNVaXjk8ClXHPttLyxAL48A==} @@ -1220,6 +1293,9 @@ packages: resolution: {integrity: sha512-DvEy55V3DB7uknRo+4iOGT5fP1slR8wQohVdknigZPMpMstaKJQWhwiYBACJE3Ul2pTnATihhBYnRhZQHGBiRw==} engines: {node: '>= 0.8'} + string_decoder@1.3.0: + resolution: {integrity: sha512-hkRX8U1WjJFd8LsDJ2yQ/wWWxaopEsABU1XfkM8A+j0+85JAGppt16cr1Whg6KIbb4okU6Mql6BOj+uup/wKeA==} + strip-json-comments@3.1.1: resolution: {integrity: sha512-6fPc+R4ihwqP6N/aIv2f1gMH8lOVtWQHoqC4yK6oSDVVocumAsfCqjkXnqiYMhmMwS/mEHLp7Vehlt3ql6lEig==} engines: {node: '>=8'} @@ -1235,6 +1311,9 @@ packages: svix@1.92.2: resolution: {integrity: sha512-ZmuA3UVvlnF9EgxlzmPtF7CKjQb64Z6OFlyfdDfU0sdcC7dJa+3aOYX5B9mA+RS6ch1AxBa4UP/l6KmqfGtWBQ==} + text-hex@1.0.0: + resolution: {integrity: sha512-uuVGNWzgJ4yhRaNSiubPY7OjISw4sw4E5Uv0wbjp+OzcbmVU/rsT8ujgcXJhn9ypzsgr5vlzpPqP+MBBKcGvbg==} + to-regex-range@5.0.1: resolution: {integrity: sha512-65P7iz6X5yEr1cwcgvQxbbIw7Uk3gOy5dIdtZ4rDveLqhrdJP+Li/Hx6tyK0NEb+2GCyneCMJiGqrADCSNk8sQ==} engines: {node: '>=8.0'} @@ -1251,6 +1330,10 @@ packages: resolution: {integrity: sha512-hdF5ZgjTqgAntKkklYw0R03MG2x/bSzTtkxmIRw/sTNV8YXsCJ1tfLAX23lhxhHJlEf3CRCOCGGWw3vI3GaSPw==} engines: {node: '>=18'} + triple-beam@1.4.1: + resolution: {integrity: sha512-aZbgViZrg1QNcG+LULa7nhZpJTZSLm/mXnHXnbAbjmN5aSa0y7V+wvv6+4WaBtpISJzThKy+PIPxc1Nq1EJ9mg==} + engines: {node: '>= 14.0.0'} + tslib@2.8.1: resolution: {integrity: sha512-oJFu94HQb+KVduSUQL7wnpmqnfmLsOA/nAh6b6EH0wCEoK0/mPeXU6c3wKDV83MkOuHPRHtSXKKU99IBazS/2w==} @@ -1276,6 +1359,9 @@ packages: uri-js@4.4.1: resolution: {integrity: sha512-7rKUyy33Q1yc98pQ1DAmLtwX109F7TIfWlW1Ydo8Wl1ii1SeHieeh0HHfPeL2fMXK6z0s8ecKs9frCuLJvndBg==} + util-deprecate@1.0.2: + resolution: {integrity: sha512-EPD5q1uXyFxJpCrLnCc1nHnq3gOa6DZBocAIiI2TaSCA7VCJ1UJDMagCzIkXNsUYfD1daK//LTEQ8xiIbrHtcw==} + vary@1.1.2: resolution: {integrity: sha512-BNGbWLfd0eUPabhkXUVm0j8uuvREyTh5ovRa/dyow/BqAbZJyC+5fU+IzQOzmAKzYqYRAISoRhdQr3eIZ/PXqg==} engines: {node: '>= 0.8'} @@ -1293,6 +1379,14 @@ packages: engines: {node: '>= 8'} hasBin: true + winston-transport@4.9.0: + resolution: {integrity: sha512-8drMJ4rkgaPo1Me4zD/3WLfI/zPdA9o2IipKODunnGDcuqbHwjsbB79ylv04LCGGzU0xQ6vTznOMpQGaLhhm6A==} + engines: {node: '>= 12.0.0'} + + winston@3.19.0: + resolution: {integrity: sha512-LZNJgPzfKR+/J3cHkxcpHKpKKvGfDZVPS4hfJCc4cCG0CgYzvlD6yE/S3CIL/Yt91ak327YCpiF/0MyeZHEHKA==} + engines: {node: '>= 12.0.0'} + word-wrap@1.2.5: resolution: {integrity: sha512-BN22B5eaMMI9UMtjrGd5g5eCYPpCPDUy0FJXbYsaT5zYxjFOckS53SQDE3pWkVoWpHXVb3BrYcEN4Twa55B5cA==} engines: {node: '>=0.10.0'} @@ -1347,6 +1441,16 @@ snapshots: dependencies: json-schema: 0.4.0 + '@colors/colors@1.6.0': {} + + '@colors/colors@1.6.1': {} + + '@dabh/diagnostics@2.0.9': + dependencies: + '@so-ric/colorspace': 1.1.6 + enabled: 2.0.0 + kuler: 2.0.0 + '@esbuild/aix-ppc64@0.27.0': optional: true @@ -1511,6 +1615,11 @@ snapshots: '@msgpackr-extract/msgpackr-extract-win32-x64@3.0.3': optional: true + '@so-ric/colorspace@1.1.6': + dependencies: + color: 5.0.3 + text-hex: 1.0.0 + '@stablelib/base64@1.0.1': {} '@standard-schema/spec@1.1.0': {} @@ -1519,6 +1628,8 @@ snapshots: '@types/json-schema@7.0.15': {} + '@types/triple-beam@1.3.5': {} + '@types/webidl-conversions@7.0.3': {} '@types/whatwg-url@13.0.0': @@ -1571,6 +1682,8 @@ snapshots: argparse@2.0.1: {} + async@3.2.6: {} + asynckit@0.4.0: {} axios@1.16.1: @@ -1668,8 +1781,23 @@ snapshots: dependencies: color-name: 1.1.4 + color-convert@3.1.3: + dependencies: + color-name: 2.1.1 + color-name@1.1.4: {} + color-name@2.1.1: {} + + color-string@2.1.4: + dependencies: + color-name: 2.1.1 + + color@5.0.3: + dependencies: + color-convert: 3.1.3 + color-string: 2.1.4 + combined-stream@1.0.8: dependencies: delayed-stream: 1.0.0 @@ -1743,6 +1871,8 @@ snapshots: ee-first@1.1.1: {} + enabled@2.0.0: {} + encodeurl@2.0.0: {} es-define-property@1.0.1: {} @@ -1904,6 +2034,8 @@ snapshots: fast-sha256@1.3.0: {} + fecha@4.2.3: {} + file-entry-cache@8.0.0: dependencies: flat-cache: 4.0.1 @@ -1935,6 +2067,8 @@ snapshots: flatted@3.4.4: {} + fn.name@1.1.0: {} + follow-redirects@1.16.0: {} form-data@4.0.5: @@ -2062,6 +2196,8 @@ snapshots: is-promise@4.0.0: {} + is-stream@2.0.1: {} + isexe@2.0.0: {} js-yaml@4.3.1: @@ -2106,6 +2242,8 @@ snapshots: dependencies: json-buffer: 3.0.1 + kuler@2.0.0: {} + levn@0.4.1: dependencies: prelude-ls: 1.2.1 @@ -2135,6 +2273,15 @@ snapshots: lodash.once@4.1.1: {} + logform@2.7.0: + dependencies: + '@colors/colors': 1.6.0 + '@types/triple-beam': 1.3.5 + fecha: 4.2.3 + ms: 2.1.3 + safe-stable-stringify: 2.5.0 + triple-beam: 1.4.1 + luxon@3.7.2: {} math-intrinsics@1.1.0: {} @@ -2253,6 +2400,10 @@ snapshots: dependencies: wrappy: 1.0.2 + one-time@1.0.0: + dependencies: + fn.name: 1.1.0 + optionator@0.9.4: dependencies: deep-is: 0.1.4 @@ -2314,6 +2465,12 @@ snapshots: iconv-lite: 0.7.2 unpipe: 1.0.0 + readable-stream@3.6.2: + dependencies: + inherits: 2.0.4 + string_decoder: 1.3.0 + util-deprecate: 1.0.2 + readdirp@3.6.0: dependencies: picomatch: 2.3.2 @@ -2343,6 +2500,8 @@ snapshots: safe-buffer@5.2.1: {} + safe-stable-stringify@2.5.0: {} + safer-buffer@2.1.2: {} sarvamai@1.1.8-alpha.5: @@ -2425,6 +2584,8 @@ snapshots: dependencies: memory-pager: 1.5.0 + stack-trace@0.0.10: {} + standard-as-callback@2.1.0: {} standardwebhooks@1.0.0: @@ -2434,6 +2595,10 @@ snapshots: statuses@2.0.2: {} + string_decoder@1.3.0: + dependencies: + safe-buffer: 5.2.1 + strip-json-comments@3.1.1: {} supports-color@5.5.0: @@ -2448,6 +2613,8 @@ snapshots: dependencies: standardwebhooks: 1.0.0 + text-hex@1.0.0: {} + to-regex-range@5.0.1: dependencies: is-number: 7.0.0 @@ -2460,6 +2627,8 @@ snapshots: dependencies: punycode: 2.3.1 + triple-beam@1.4.1: {} + tslib@2.8.1: {} type-check@0.4.0: @@ -2482,6 +2651,8 @@ snapshots: dependencies: punycode: 2.3.1 + util-deprecate@1.0.2: {} + vary@1.1.2: {} webidl-conversions@7.0.0: {} @@ -2495,6 +2666,26 @@ snapshots: dependencies: isexe: 2.0.0 + winston-transport@4.9.0: + dependencies: + logform: 2.7.0 + readable-stream: 3.6.2 + triple-beam: 1.4.1 + + winston@3.19.0: + dependencies: + '@colors/colors': 1.6.1 + '@dabh/diagnostics': 2.0.9 + async: 3.2.6 + is-stream: 2.0.1 + logform: 2.7.0 + one-time: 1.0.0 + readable-stream: 3.6.2 + safe-stable-stringify: 2.5.0 + stack-trace: 0.0.10 + triple-beam: 1.4.1 + winston-transport: 4.9.0 + word-wrap@1.2.5: {} wrappy@1.0.2: {} diff --git a/server/src/controllers/email.controller.js b/server/src/controllers/email.controller.js index 3040144..494c61f 100644 --- a/server/src/controllers/email.controller.js +++ b/server/src/controllers/email.controller.js @@ -3,6 +3,7 @@ import { getFeatureUpdateRecipientsList, getEmailQueueStats, } from "../services/email.queue.js"; +import { emailLog as log } from "../utils/logger.js"; export const sendFeatureUpdateEmail = async (req, res) => { const { subject, content, recipientUserIds } = req.body; @@ -44,7 +45,9 @@ export const sendFeatureUpdateEmail = async (req, res) => { ...result, }); } catch (error) { - console.error("Error sending email:", error); + log.error("Failed to queue feature update broadcast", { + detail: error.message, + }); res.status(500).json({ message: "Failed to send email" }); } }; @@ -54,7 +57,9 @@ export const getFeatureUpdateRecipients = async (_req, res) => { const audience = await getFeatureUpdateRecipientsList(); return res.status(200).json(audience); } catch (error) { - console.error("Error getting recipients:", error); + log.error("Failed to list broadcast recipients", { + detail: error.message, + }); return res.status(500).json({ message: "Failed to get recipients" }); } }; @@ -64,7 +69,7 @@ export const getEmailQueueStatus = async (_req, res) => { const stats = await getEmailQueueStats(); return res.status(200).json(stats); } catch (error) { - console.error("Error getting queue stats:", error); + log.error("Failed to read email queue stats", { detail: error.message }); return res.status(500).json({ message: "Failed to get queue stats" }); } }; diff --git a/server/src/controllers/github.controller.js b/server/src/controllers/github.controller.js index a444132..c7abbed 100644 --- a/server/src/controllers/github.controller.js +++ b/server/src/controllers/github.controller.js @@ -12,6 +12,7 @@ import { } from "../utils/githubApiClient.js"; import { redis } from "../utils/redis.js"; import { liveUpdate } from "../services/convex.service.js"; +import { githubLog, serverLog, queueLog } from "../utils/logger.js"; export function verifyGithubSignature(req) { if (!Buffer.isBuffer(req.body)) return false; @@ -71,7 +72,10 @@ export const getGithubRepos = async (req, res) => { res.status(200).json({ reposData }); } catch (error) { - console.log(error); + githubLog.error("Failed to list user repositories", { + userId: req.userId, + detail: error.message, + }); res .status(500) .json({ message: "Error fetching GitHub repositories", error }); @@ -197,10 +201,10 @@ export const addRepoActivity = async (req, res) => { activeRepo.lastProcessedSha = headSha; await activeRepo.save(); } catch (err) { - console.error( - "Failed to trigger initial README generation:", - err.message, - ); + queueLog.error("Failed to queue initial README generation", { + repo: repoFullName, + detail: err.message, + }); } } @@ -208,7 +212,10 @@ export const addRepoActivity = async (req, res) => { res.status(200).json({ message: "Repository activity added successfully" }); } catch (error) { - console.error("Error adding repository activity:", error); + githubLog.error("Failed to activate repository", { + userId: req.userId, + detail: error.message, + }); res .status(500) .json({ message: "Error adding repository activity", error }); @@ -242,7 +249,11 @@ export const deactivateRepoActivity = async (req, res) => { accessToken, ); } catch (error) { - console.error("Error deleting webhook:", error.message); + githubLog.warn("Failed to delete webhook — deactivating anyway", { + repo: `${activeRepo.repoOwner}/${activeRepo.repoName}`, + webhookId: activeRepo.webhookId, + detail: error.message, + }); } const response = await ActiveRepo.updateOne( @@ -294,9 +305,11 @@ export const githubWebhookHandler = async (req, res) => { // Only process README generation on default branch if (branchName !== activeRepo.defaultBranch) { - console.log( - `Ignoring push to non-default branch: ${branchName} (default: ${activeRepo.defaultBranch})`, - ); + githubLog.info("Push ignored — not the default branch", { + repo: activeRepo.repoFullName, + branch: branchName, + defaultBranch: activeRepo.defaultBranch, + }); return res.status(200).send("Non-default branch ignored"); } @@ -304,7 +317,10 @@ export const githubWebhookHandler = async (req, res) => { commitMessage.includes("[skip ci]") || commitMessage.includes("auto-update README") ) { - console.log(`Ignoring bot commit: ${commitSha}`); + githubLog.info("Push ignored — bot commit", { + repo: activeRepo.repoFullName, + commit: commitSha, + }); return res.status(200).send("Bot commit ignored"); } @@ -312,9 +328,10 @@ export const githubWebhookHandler = async (req, res) => { return res.status(200).send("Already processed"); } - console.log( - `Received push event for repo ${activeRepo.repoFullName} at commit ${commitSha}`, - ); + githubLog.info("Push event accepted", { + repo: activeRepo.repoFullName, + commit: commitSha, + }); readmeQueue.add("generate-readme", { userId: activeRepo.userId, @@ -331,7 +348,7 @@ export const githubWebhookHandler = async (req, res) => { return res.status(200).send("Webhook processed"); } catch (err) { - console.error(err); + githubLog.error("Webhook handling failed", { detail: err.message }); return res.status(500).send("Webhook error"); } }; @@ -354,7 +371,7 @@ export const fetchAdminAnalytics = async (_req, res) => { try { const cachedAnalytics = await redis.get("admin_analytics"); if (cachedAnalytics) { - console.log("[cache] Serving admin analytics from Redis cache"); + serverLog.debug("Serving admin analytics from cache"); return res.status(200).json(JSON.parse(cachedAnalytics)); } @@ -506,10 +523,7 @@ export const fetchAdminAnalytics = async (_req, res) => { recentLogs: threeLatestLogs, }), ); - console.log( - "[cache] Admin analytics saved to Redis cache with ID:", - saveCache, - ); + serverLog.debug("Admin analytics cached", { result: saveCache }); return res.status(200).json({ overview: { @@ -527,7 +541,9 @@ export const fetchAdminAnalytics = async (_req, res) => { recentLogs: threeLatestLogs, }); } catch (error) { - console.error("Error fetching admin analytics:", error); + serverLog.error("Failed to fetch admin analytics", { + detail: error.message, + }); return res.status(500).json({ message: "Error fetching admin analytics" }); } }; @@ -581,7 +597,7 @@ export const fetchAdminUsers = async (req, res) => { }, }); } catch (error) { - console.error("Error fetching admin users:", error); + serverLog.error("Failed to fetch admin users", { detail: error.message }); return res.status(500).json({ message: "Error fetching admin users" }); } }; @@ -592,11 +608,11 @@ export const cleanUpReadme = async (req, res) => { const sharedLogId = crypto.randomUUID(); try { - console.log("[cleanUpReadme] Started"); - const { repoId } = req.body; if (!repoId) { - console.log("[cleanUpReadme] Missing repoId"); + serverLog.warn("Cleanup request rejected — repoId missing", { + userId: req.userId, + }); return res.status(400).json({ message: "repoId is required" }); } @@ -607,20 +623,25 @@ export const cleanUpReadme = async (req, res) => { active: true, }); if (!activeRepo) { - console.log("[cleanUpReadme] Please activate the repository first"); + serverLog.warn("Cleanup request rejected — repository not active", { + userId, + repoId, + }); return res .status(404) .json({ message: "Please activate the repository first" }); } - console.log( - "[cleanUpReadme] Active repository found:", - `${activeRepo.repoOwner}/${activeRepo.repoName}`, - ); + serverLog.info("Cleanup requested", { + repo: `${activeRepo.repoOwner}/${activeRepo.repoName}`, + logId: sharedLogId, + }); const user = await User.findById(userId); if (!user?.githubAccessToken) { - console.log("[cleanUpReadme] GitHub access token not found"); + serverLog.warn("Cleanup request rejected — no GitHub access token", { + userId, + }); return res.status(404).json({ message: "GitHub access token not found" }); } @@ -651,7 +672,10 @@ export const cleanUpReadme = async (req, res) => { logId: sharedLogId, }); } catch (error) { - console.error("[cleanUpReadme] Failed:", error.message); + serverLog.error("Cleanup request failed", { + logId: sharedLogId, + detail: error.message, + }); liveUpdate(sharedLogId, `✗ Failed: ${error.message}`); return res .status(500) diff --git a/server/src/controllers/oauthcontroller.js b/server/src/controllers/oauthcontroller.js index b5b97d2..b8a42bc 100644 --- a/server/src/controllers/oauthcontroller.js +++ b/server/src/controllers/oauthcontroller.js @@ -6,6 +6,7 @@ import UserLogModel from "../schema/userLog.schema.js"; import { encrypt, decrypt } from "../utils/crypto.js"; import { GITHUB_API_BASE, githubDelete } from "../utils/githubApiClient.js"; import { redis } from "../utils/redis.js"; +import { authLog as log } from "../utils/logger.js"; export { encrypt, decrypt }; @@ -58,14 +59,14 @@ export const githubCallBack = async (req, res) => { const result = await createOAuthUser(userInfo, accessToken, primaryEmail); user = result.user; } catch (error) { - console.error("Error creating OAuth user:", error); + log.error("OAuth user creation failed", { detail: error.message }); return res .status(500) .json({ message: "Error creating OAuth user", error: error.message }); } if (!user || !user._id) { - console.error("User creation failed: user object is invalid"); + log.error("OAuth user creation returned an invalid user object"); return res .status(500) .json({ message: "Failed to create or retrieve user" }); @@ -125,7 +126,9 @@ export const createOAuthUser = async ( await user.save(); await redis.del("admin_analytics"); } else { - console.log("User already exists. Updating access token."); + log.info("Existing user signed in — refreshing access token", { + userId: user._id, + }); user.githubAccessToken = encrypt(access_token); if (profile.email || primaryEmail) { user.email = profile.email || primaryEmail; @@ -145,7 +148,7 @@ export const verifyUser = async (req, res) => { } return res.status(200).json({ user }); } catch (error) { - console.error("Verify user error:", error); + log.error("User verification failed", { detail: error.message }); return res.status(500).json({ message: "Internal server error" }); } }; @@ -172,10 +175,10 @@ export const deleteAccount = async (req, res) => { ); } catch (webhookError) { if (webhookError.response?.status !== 404) { - console.warn( - `Failed to delete webhook for ${repo.repoName}:`, - webhookError.message, - ); + log.warn("Failed to delete webhook during account deletion", { + repo: `${repo.repoOwner}/${repo.repoName}`, + detail: webhookError.message, + }); } } } @@ -185,7 +188,10 @@ export const deleteAccount = async (req, res) => { await redis.del("admin_analytics"); return res.status(200).json({ message: "Account deleted successfully" }); } catch (error) { - console.error("Delete account error:", error); + log.error("Account deletion failed", { + userId, + detail: error.message, + }); return res.status(500).json({ message: "Internal server error" }); } }; diff --git a/server/src/db/connectDB.js b/server/src/db/connectDB.js index fe80a86..a83639d 100644 --- a/server/src/db/connectDB.js +++ b/server/src/db/connectDB.js @@ -1,4 +1,5 @@ import mongoose from "mongoose"; +import { dbLog as log } from "../utils/logger.js"; export const connectDB = async () => { try { @@ -7,9 +8,9 @@ export const connectDB = async () => { socketTimeoutMS: 45000, connectTimeoutMS: 10000, }); - console.log("MongoDB connected successfully"); + log.info("MongoDB connected"); } catch (error) { - console.error("MongoDB connection error:", error); + log.error("MongoDB connection failed", { detail: error.message }); throw error; } }; diff --git a/server/src/index.js b/server/src/index.js index 82e1fe8..c79b95a 100644 --- a/server/src/index.js +++ b/server/src/index.js @@ -7,6 +7,7 @@ import emailRoutes from "./routes/email.routes.js"; import { connectDB } from "./db/connectDB.js"; import { recoverInterruptedCleanupLogs } from "./services/logRecovery.service.js"; import { githubWebhookHandler } from "./controllers/github.controller.js"; +import { serverLog, requestLogger } from "./utils/logger.js"; const app = express(); const PORT = process.env.PORT || 3000; @@ -31,6 +32,9 @@ app.use( app.use(express.json()); +// One line per finished request, before the routes so every route is covered. +app.use(requestLogger); + app.use("/auth", authRoutes); app.use("/api/github", githubRoutes); app.use("/api/email", emailRoutes); @@ -40,7 +44,6 @@ app.get("/", (req, res) => { }); app.get("/health", (req, res) => { - console.log("Health check endpoint called"); res.status(200).json({ status: "ok", timestamp: new Date().toISOString(), @@ -51,7 +54,11 @@ app.get("/health", (req, res) => { // eslint-disable-next-line no-unused-vars -- 4-arg signature required for Express to treat this as error middleware app.use((err, req, res, next) => { - console.error("Unhandled error:", err.message); + serverLog.error("Unhandled request error", { + method: req.method, + url: req.originalUrl, + detail: err.message, + }); res.status(500).json({ message: "Internal server error" }); }); @@ -60,23 +67,27 @@ connectDB() recoverInterruptedCleanupLogs() .then((recoveredCount) => { if (recoveredCount > 0) { - console.warn( - `[startup] Marked ${recoveredCount} interrupted cleanup log(s) as failed`, - ); + serverLog.warn("Recovered interrupted cleanup logs", { + count: recoveredCount, + }); } }) .catch((error) => { - console.error( - "[startup] Failed to recover interrupted cleanup logs:", - error.message, - ); + serverLog.error("Failed to recover interrupted cleanup logs", { + detail: error.message, + }); }) .finally(() => { app.listen(PORT, () => { - console.log(`Server is running on port ${PORT}`); + serverLog.info("Server listening", { + port: PORT, + env: process.env.NODE_ENV || "development", + }); }); }); }) .catch((error) => { - console.error("Failed to connect to the database:", error); + serverLog.error("Startup aborted — database unavailable", { + detail: error.message, + }); }); diff --git a/server/src/llm/ai.sdk.js b/server/src/llm/ai.sdk.js index 1e46aa9..f2368b3 100644 --- a/server/src/llm/ai.sdk.js +++ b/server/src/llm/ai.sdk.js @@ -1,4 +1,5 @@ import { generateText } from "ai"; +import { aiLog } from "../utils/logger.js"; // Thin wrapper over the AI SDK. No custom option abstraction — // callers pass real generateText() options straight through. @@ -9,7 +10,9 @@ export async function aiCall({ model, prompt, ...options }) { ...options, }); - console.log(text); + // The completion itself is far too large for an info line — only its size + // is useful, and the body stays behind debug for local troubleshooting. + aiLog.debug("Completion received", { chars: text.length }); return text; } diff --git a/server/src/llm/llm.service.js b/server/src/llm/llm.service.js index b86ae97..7409b69 100644 --- a/server/src/llm/llm.service.js +++ b/server/src/llm/llm.service.js @@ -1,4 +1,5 @@ import { liveUpdate } from "../services/convex.service.js"; +import { aiLog as log } from "../utils/logger.js"; import { GeminiProvider } from "./providers/gemini.provider.js"; import { SarvamProvider } from "./providers/sarvam.provider.js"; import { detectReadme, generateReadme } from "./readme.generate.js"; @@ -41,7 +42,7 @@ export class LlmService { sharedLogId, }); - console.log(`[LLM] Generation mode: ${mode} — ${reason}`); + log.info("Generation mode selected", { mode, reason }); liveUpdate( sharedLogId, `Update strategy: ${mode === "patch" ? "targeted update" : "full rewrite"} — ${reason}`, @@ -49,7 +50,7 @@ export class LlmService { //full generation pipeline setup if (mode === "full") { - console.log(`[LLM] FULL mode — scanning entire repository`); + log.info("Full mode — scanning entire repository"); liveUpdate(sharedLogId, "Reading the full repository"); const readme = await generateReadme({ @@ -71,7 +72,7 @@ export class LlmService { //patch pipeline setup if (mode === "patch") { - console.log(`[LLM] PATCH mode — scanning modified files only`); + log.info("Patch mode — scanning modified files only"); liveUpdate(sharedLogId, "Reading the changed files"); return await patchReadme({ @@ -97,14 +98,14 @@ export class LlmService { // the same primary/fallback handling instead of inheriting it from above. async cleanup(existingReadme, sharedLogId) { try { - console.log( - `[LLM] Cleaning README with ${this.geminiProvider.getName()}`, - ); + log.info("Cleaning README", { provider: this.geminiProvider.getName() }); return await this.geminiProvider.cleanup(existingReadme); } catch (error) { - console.warn( - `[LLM] ${this.geminiProvider.getName()} cleanup failed (${error.message}) — falling back to ${this.sarvamProvider.getName()}`, - ); + log.warn("Cleanup failed — falling back", { + provider: this.geminiProvider.getName(), + fallback: this.sarvamProvider.getName(), + detail: error.message, + }); liveUpdate( sharedLogId, "Primary model unavailable — switching to backup", diff --git a/server/src/llm/providers/gemini.provider.js b/server/src/llm/providers/gemini.provider.js index c8f0329..7a355b7 100644 --- a/server/src/llm/providers/gemini.provider.js +++ b/server/src/llm/providers/gemini.provider.js @@ -4,6 +4,9 @@ import { aiCall } from "../ai.sdk.js"; import { buildDetectPrompt } from "../prompts/detect.prompt.js"; import { extractJson } from "../utils/response.js"; import { buildCleanupPrompt } from "../prompts/cleanup.prompt.js"; +import { providerLog } from "../../utils/logger.js"; + +const log = providerLog("Gemini"); // Keys are tried in slot order. Unset or blank slots are dropped, so a // half-filled .env still works instead of burning an attempt on nothing. @@ -99,9 +102,11 @@ export class GeminiProvider { if (!isRotatable(error)) throw error; lastError = error; - console.warn( - `[Gemini] key ${index + 1}/${this.clients.length} failed on ${modelId} (${describe(error)}) — trying next key`, - ); + log.warn("API key failed — trying next key", { + key: `${index + 1}/${this.clients.length}`, + model: modelId, + detail: describe(error), + }); } } diff --git a/server/src/llm/providers/sarvam.provider.js b/server/src/llm/providers/sarvam.provider.js index 9df1bc8..434dd87 100644 --- a/server/src/llm/providers/sarvam.provider.js +++ b/server/src/llm/providers/sarvam.provider.js @@ -3,6 +3,9 @@ import { SarvamAIClient } from "sarvamai"; import { buildDetectPrompt } from "../prompts/detect.prompt.js"; import { buildCleanupPrompt } from "../prompts/cleanup.prompt.js"; import { extractJson } from "../utils/response.js"; +import { providerLog } from "../../utils/logger.js"; + +const log = providerLog("Sarvam"); // Sarvam ships no AI SDK adapter, so this provider talks to the vendor client // directly. It exposes the same surface as GeminiProvider (getName/detect/ @@ -55,9 +58,10 @@ export class SarvamProvider { messages: [{ role: "user", content: prompt }], }); } catch (error) { - console.error( - `[Sarvam] ${label} failed on ${MODEL} (${describe(error)})`, - ); + log.error(`${label} call failed`, { + model: MODEL, + detail: describe(error), + }); throw error; } @@ -67,9 +71,10 @@ export class SarvamProvider { throw new Error(`Sarvam returned an empty ${label} response`); } - console.log( - `[Sarvam] ${label} completed on ${MODEL} in ${Date.now() - startedAt}ms`, - ); + log.info(`${label} call completed`, { + model: MODEL, + durationMs: Date.now() - startedAt, + }); return content; } diff --git a/server/src/llm/readme.generate.js b/server/src/llm/readme.generate.js index 0574435..24a5690 100644 --- a/server/src/llm/readme.generate.js +++ b/server/src/llm/readme.generate.js @@ -1,5 +1,8 @@ import { liveUpdate } from "../services/convex.service.js"; import { buildFullReadmePrompt } from "./prompts/full.generate.prompt.js"; +import { aiLog } from "../utils/logger.js"; + +const log = aiLog.child({ pipeline: "full" }); // Exported so the patch pipeline renders commit diffs identically to full mode. export function formatCommitDiff(commitData) { @@ -133,9 +136,9 @@ export function validateContext(context) { } if (hasFullCodebase) { - console.log( - `[Validate] Full codebase mode: ${context.fullCodebase.length} files`, - ); + aiLog.debug("Full codebase context", { + files: context.fullCodebase.length, + }); } const size = estimateContextSize(context); @@ -244,21 +247,21 @@ export async function detectReadme({ let result; try { - console.log(`[LLM] Detecting update mode with ${provider.getName()}`); + log.info("Detecting update mode", { provider: provider.getName() }); liveUpdate(sharedLogId, "Analysing the existing README"); result = await provider.detect(existingReadme); } catch (error) { - console.warn( - `[LLM] ${provider.getName()} detection failed (${error.message}) — falling back to ${fallBackProvider.getName()}`, - ); + log.warn("Detection failed — falling back", { + provider: provider.getName(), + fallback: fallBackProvider.getName(), + detail: error.message, + }); liveUpdate(sharedLogId, "Primary model unavailable — switching to backup"); result = await fallBackProvider.detect(existingReadme); } if (!result) { - console.error( - `[LLM] Detection returned no usable result from any provider`, - ); + log.error("Detection returned no usable result from any provider"); result = { mode: "failed", reason: "Unable to analyse the existing README", @@ -281,7 +284,7 @@ export async function generateReadme({ provider, fallBackProvider, }) { - console.log(`[LLM] Building full generation context`); + log.info("Building generation context", { repo: `${repoOwner}/${repoName}` }); liveUpdate(sharedLogId, "Preparing the repository context"); let context = buildReadmeContext({ @@ -302,13 +305,14 @@ export async function generateReadme({ } if (validation.warnings.length > 0) { - console.warn("[LLM] Context warnings:", validation.warnings); + log.warn("Context warnings", { warnings: validation.warnings }); } const fileCount = context.fullCodebase.length; - console.log( - `[LLM] Full context ready — ${fileCount} codebase file(s), ~${validation.estimatedTokens} tokens`, - ); + log.info("Context ready", { + files: fileCount, + estimatedTokens: validation.estimatedTokens, + }); liveUpdate( sharedLogId, `Context ready — ${fileCount} file(s), roughly ${validation.estimatedTokens.toLocaleString()} tokens`, @@ -322,8 +326,8 @@ export async function generateReadme({ context.changedFiles.length === 0 && !context.commitDiff ) { - console.warn( - `[LLM] No code context available — README will be limited to repository metadata`, + log.warn( + "No code context available — README limited to repository metadata", ); liveUpdate( sharedLogId, @@ -332,7 +336,10 @@ export async function generateReadme({ } if (validation.estimatedTokens > 180000) { - console.log(`[LLM] Optimizing large context`); + log.info("Trimming oversized context", { + estimatedTokens: validation.estimatedTokens, + limit: 180000, + }); liveUpdate(sharedLogId, "Trimming the context to fit the model window"); context = optimizeContext(context, 180000); } @@ -341,26 +348,26 @@ export async function generateReadme({ let readme; try { - console.log(`[LLM] Generating README with ${provider.getName()}`); + log.info("Generating README", { provider: provider.getName() }); liveUpdate(sharedLogId, "Writing the README"); readme = await provider.generate(prompt); } catch (error) { - console.warn( - `[LLM] ${provider.getName()} generation failed (${error.message}) — falling back to ${fallBackProvider.getName()}`, - ); + log.warn("Generation failed — falling back", { + provider: provider.getName(), + fallback: fallBackProvider.getName(), + detail: error.message, + }); liveUpdate(sharedLogId, "Primary model unavailable — switching to backup"); readme = await fallBackProvider.generate(prompt); } if (!readme) throw new Error("No README returned by any provider"); - console.log(`[LLM] Validating generated README`); + log.debug("Validating generated README"); liveUpdate(sharedLogId, "Reviewing the generated README"); const validatedReadme = validateGeneratedReadme(readme); - console.log( - `[LLM] ✓ Full README generated (${validatedReadme.length} chars)`, - ); + log.info("README generated", { chars: validatedReadme.length }); liveUpdate(sharedLogId, "README ready"); return validatedReadme; diff --git a/server/src/llm/readme.patch.js b/server/src/llm/readme.patch.js index 286744d..527a91f 100644 --- a/server/src/llm/readme.patch.js +++ b/server/src/llm/readme.patch.js @@ -1,4 +1,7 @@ import { liveUpdate } from "../services/convex.service.js"; +import { aiLog } from "../utils/logger.js"; + +const log = aiLog.child({ pipeline: "patch" }); import { parseReadmeSections, mergePatchedSections, @@ -194,7 +197,7 @@ export function parsePatchResponse(response, { sections, editableKeys }) { // An entry with no content is the model saying "nothing to change here". // Treat it as a no-op section instead of failing the whole run. if (typeof content !== "string" || !content.trim()) { - console.log(`[Patch] Skipping empty update for section "${section}"`); + log.debug("Skipping empty section update", { section }); continue; } @@ -290,7 +293,9 @@ export async function patchReadme({ throw new Error("PATCH mode requires an existing README"); } - console.log(`[Patch] Analyzing README changes`); + log.info("Analysing README against commit", { + repo: `${repoOwner}/${repoName}`, + }); liveUpdate(sharedLogId, "Comparing the commit against the current README"); const { context, sections, orderedKeys, editableKeys } = buildPatchContext({ @@ -309,7 +314,7 @@ export async function patchReadme({ } if (validation.warnings.length > 0) { - console.warn("[Patch] Context warnings:", validation.warnings); + log.warn("Context warnings", { warnings: validation.warnings }); } let patchContext = context; @@ -318,7 +323,7 @@ export async function patchReadme({ patchContext = optimizePatchContext(context, MAX_CONTEXT_TOKENS); } - console.log(`[Patch] ${editableKeys.length} patchable section(s)`); + log.info("Patchable sections identified", { sections: editableKeys.length }); liveUpdate(sharedLogId, "Identifying the affected README sections"); const prompt = buildPatchReadmePrompt(patchContext); @@ -327,18 +332,18 @@ export async function patchReadme({ let response; try { - console.log( - `[Patch] Generating section updates with ${provider.getName()}`, - ); + log.info("Generating section updates", { provider: provider.getName() }); response = await provider.generate(prompt); } catch (error) { // Same contract as full mode: the primary provider throws only once every // one of its keys is spent, so a throw here is the signal to switch. if (!fallBackProvider) throw error; - console.warn( - `[Patch] ${provider.getName()} generation failed (${error.message}) — falling back to ${fallBackProvider.getName()}`, - ); + log.warn("Generation failed — falling back", { + provider: provider.getName(), + fallback: fallBackProvider.getName(), + detail: error.message, + }); liveUpdate(sharedLogId, "Primary model unavailable — switching to backup"); response = await fallBackProvider.generate(prompt); } @@ -351,7 +356,7 @@ export async function patchReadme({ // An empty patch is a valid outcome: the commit did not change anything the // README documents. Skip the run instead of failing it. if (patchedKeys.length === 0) { - console.log(`[Patch] No sections needed updating — skipping`); + log.info("No sections needed updating — skipping commit"); liveUpdate( sharedLogId, "No changes needed — the README is already current", @@ -372,7 +377,7 @@ export async function patchReadme({ throw new Error(`Patch rejected: ${patchValidation.reason}`); } - console.log(`[Patch] Applying sections: ${patchedKeys.join(", ")}`); + log.info("Applying section updates", { sections: patchedKeys.join(", ") }); liveUpdate( sharedLogId, `Applying updates to ${patchedKeys.length} section(s)`, @@ -381,9 +386,10 @@ export async function patchReadme({ const finalReadme = mergePatchedSections(sections, orderedKeys, patches); const validatedReadme = validatePatchedReadme(finalReadme, orderedKeys); - console.log( - `[Patch] ✓ Patched [${patchedKeys.join(", ")}] (${validatedReadme.length} chars)`, - ); + log.info("README patched", { + sections: patchedKeys.join(", "), + chars: validatedReadme.length, + }); liveUpdate(sharedLogId, "README updated"); return { skipped: false, readme: validatedReadme }; diff --git a/server/src/middlewares/auth.middleware.js b/server/src/middlewares/auth.middleware.js index 6df3f34..986a33c 100644 --- a/server/src/middlewares/auth.middleware.js +++ b/server/src/middlewares/auth.middleware.js @@ -1,5 +1,6 @@ import jwt from "jsonwebtoken"; import User from "../schema/user.schema.js"; +import { authLog as log } from "../utils/logger.js"; export const authenticate = (req, res, next) => { try { @@ -44,7 +45,10 @@ export const requireAdmin = async (req, res, next) => { next(); } catch (error) { - console.error("Admin auth error:", error); + log.error("Admin authorisation check failed", { + userId: req.userId, + detail: error.message, + }); return res.status(500).json({ message: "Internal server error" }); } }; diff --git a/server/src/services/convex.service.js b/server/src/services/convex.service.js index 1030cbf..d938344 100644 --- a/server/src/services/convex.service.js +++ b/server/src/services/convex.service.js @@ -1,10 +1,9 @@ import { ConvexHttpClient } from "convex/browser"; import { makeFunctionReference } from "convex/server"; +import { convexLog as log } from "../utils/logger.js"; if (!process.env.CONVEX_URL) { - console.warn( - "[convex.service] CONVEX_URL is not set — Convex queries will fail.", - ); + log.warn("CONVEX_URL is not set — live updates will fail"); } const client = new ConvexHttpClient(process.env.CONVEX_URL); @@ -15,10 +14,10 @@ export function liveUpdate(sharedLogId, message) { client .mutation(logsAddMessage, { logId: sharedLogId, message }) .catch((err) => - console.warn( - "[cleanUpReadme] Convex log message failed (non-fatal):", - err.message, - ), + log.warn("Live update failed (non-fatal)", { + logId: sharedLogId, + detail: err.message, + }), ); } diff --git a/server/src/services/email.queue.js b/server/src/services/email.queue.js index e24c97f..644492c 100644 --- a/server/src/services/email.queue.js +++ b/server/src/services/email.queue.js @@ -2,12 +2,13 @@ import { Queue, Worker } from "bullmq"; import User from "../schema/user.schema.js"; import { sendEmail } from "./email.service.js"; import { redisConnection } from "../utils/redis.js"; +import { emailLog as log } from "../utils/logger.js"; const MAX_CONCURRENCY = 2; const EMAIL_QUEUE_NAME = "email-broadcast"; redisConnection.on("error", (err) => { - console.error("Email queue Redis error:", err.message); + log.error("Email queue Redis error", { detail: err.message }); }); export const emailQueue = new Queue(EMAIL_QUEUE_NAME, { diff --git a/server/src/services/github.service.js b/server/src/services/github.service.js index 383a937..054aba8 100644 --- a/server/src/services/github.service.js +++ b/server/src/services/github.service.js @@ -5,6 +5,7 @@ import { } from "../utils/githubApiClient.js"; import { getLanguageFromExtension } from "../utils/langMap.js"; import { IGNORED_DIR_PATTERNS } from "../utils/scan.filters.js"; +import { githubLog as log } from "../utils/logger.js"; /** * Get commit diff between two commits @@ -32,7 +33,12 @@ export async function getCommitDiff( totalCommits: response.data.total_commits || 0, }; } catch (error) { - console.error("Error fetching commit diff:", error.message); + log.error("Failed to fetch commit diff", { + repo: `${owner}/${repo}`, + baseSha, + headSha, + detail: error.message, + }); throw new Error(`Failed to fetch commit diff: ${error.message}`); } } @@ -58,7 +64,11 @@ export async function getCommit(accessToken, owner, repo, sha) { stats: response.data.stats, }; } catch (error) { - console.error("Error fetching commit:", error.message); + log.error("Failed to fetch commit", { + repo: `${owner}/${repo}`, + sha, + detail: error.message, + }); throw new Error(`Failed to fetch commit: ${error.message}`); } } @@ -86,7 +96,10 @@ export async function getRepoTree(accessToken, owner, repo, branch) { truncated: treeResponse.data.truncated || false, }; } catch (error) { - console.error("Error fetching repo tree:", error.message); + log.error("Failed to fetch repository tree", { + repo: `${owner}/${repo}`, + detail: error.message, + }); throw new Error(`Failed to fetch repo tree: ${error.message}`); } } @@ -120,7 +133,11 @@ export async function getFileContent(accessToken, owner, repo, path, branch) { if (error.response && error.response.status === 404) { return null; // File doesn't exist } - console.error(`Error fetching file content (${path}):`, error.message); + log.error("Failed to fetch file content", { + repo: `${owner}/${repo}`, + path, + detail: error.message, + }); throw new Error(`Failed to fetch file content: ${error.message}`); } } @@ -169,10 +186,13 @@ export async function commitFile( commit: response.data.commit, }; } catch (error) { - console.error(`Error committing file (${path}):`, error.message); - if (error.response) { - console.error("Response data:", error.response.data); - } + log.error("Failed to commit file", { + repo: `${owner}/${repo}`, + path, + branch, + detail: error.message, + response: error.response?.data, + }); throw new Error(`Failed to commit file: ${error.message}`); } } diff --git a/server/src/utils/git.worker.js b/server/src/utils/git.worker.js index 603f66b..7f22ae8 100644 --- a/server/src/utils/git.worker.js +++ b/server/src/utils/git.worker.js @@ -19,6 +19,10 @@ import { import { selectImportantFiles } from "./scan.filters.js"; import UserLogModel from "../schema/userLog.schema.js"; import { liveUpdate } from "../services/convex.service.js"; +import { githubLog, queueLog, redisLog, workerLog } from "./logger.js"; + +const generationLog = workerLog.child({ job: "readme-generation" }); +const cleanupLog = workerLog.child({ job: "readme-cleanup" }); import { LlmService } from "../llm/llm.service.js"; export const connection = new IORedis({ @@ -32,13 +36,13 @@ export const connection = new IORedis({ keepAlive: 30000, retryStrategy: (times) => { const delay = Math.min(times * 1000, 10000); - console.log(`Retrying Redis connection in ${delay}ms (attempt ${times})`); + redisLog.warn("Retrying connection", { attempt: times, delayMs: delay }); return delay; }, reconnectOnError: (err) => { const targetErrors = ["READONLY", "ECONNRESET", "ETIMEDOUT"]; if (targetErrors.some((e) => err.message.includes(e))) { - console.log("Reconnecting due to:", err.message); + redisLog.warn("Reconnecting after error", { detail: err.message }); return true; } return false; @@ -48,23 +52,22 @@ export const connection = new IORedis({ }); connection.on("error", (err) => - console.error("Redis connection error:", err.message), + redisLog.error("Connection error", { detail: err.message }), ); -connection.on("connect", () => console.log("Redis connected successfully")); -connection.on("ready", () => console.log("Redis ready to accept commands")); +connection.on("connect", () => redisLog.info("Connected")); +connection.on("ready", () => redisLog.info("Ready to accept commands")); connection.on("close", () => - console.warn("Redis connection closed. Will attempt to reconnect..."), + redisLog.warn("Connection closed — will attempt to reconnect"), ); connection.on("reconnecting", (timeToReconnect) => - console.log(`Reconnecting to Redis in ${timeToReconnect}ms...`), + redisLog.info("Reconnecting", { delayMs: timeToReconnect }), ); -connection.on("end", () => console.error("Redis connection ended permanently")); +connection.on("end", () => redisLog.error("Connection ended permanently")); connection.connect().catch((err) => { - console.error("Failed to connect to Redis:", err.message); - console.log( - "Redis is optional. Server will continue without queue functionality.", - ); + redisLog.error("Initial connection failed — queues disabled", { + detail: err.message, + }); }); export const readmeQueue = new Queue("readme-generation", { connection }); @@ -72,7 +75,11 @@ export const readmeQueue = new Queue("readme-generation", { connection }); new Worker( "readme-generation", async (job) => { - console.log("Processing job:", job.data); + queueLog.info("README generation job received", { + jobId: job.id, + repo: job.data.repoFullName, + commit: job.data.commitSha, + }); const sharedLogId = crypto.randomUUID(); const userLog = await UserLogModel.create({ logId: sharedLogId, @@ -85,7 +92,11 @@ new Worker( await redis.del("admin_analytics"); job.data.logId = userLog._id.toString(); job.data.sharedLogId = sharedLogId; - console.log("Updated job data with logId:", job.data.logId); + queueLog.debug("Job bound to log row", { + jobId: job.id, + logId: job.data.logId, + sharedLogId, + }); await aihandler(job.data); }, @@ -114,13 +125,18 @@ async function updateLogStatus(logId, action, status, commitId = null) { }); if (log) { - console.log( - `[AI Handler] Log ${logId} saved as action=${log.action} status=${log.status}`, - ); + generationLog.debug("Log row updated", { + logId, + action: log.action, + status: log.status, + }); await redis.del("admin_analytics"); } } catch (err) { - console.error("[AI Handler] Failed to update log:", err.message); + generationLog.error("Failed to update log row", { + logId, + detail: err.message, + }); } } @@ -138,9 +154,10 @@ const aihandler = async (data) => { const repo_limits = REPOSITORY_LIMITS; - console.log( - `[AI Handler] Starting README generation for ${repoFullName} at commit ${commitSha}`, - ); + generationLog.info("Starting README generation", { + repo: repoFullName, + commit: commitSha, + }); liveUpdate( sharedLogId, `Starting README generation for ${repoFullName} at commit ${commitSha.slice(0, 7)}`, @@ -161,7 +178,10 @@ const aihandler = async (data) => { }); if (!activeRepo) throw new Error("Active repository not found"); - console.log(`[AI Handler] Fetching commit details for ${commitSha}`); + githubLog.info("Fetching commit details", { + repo: repoFullName, + commit: commitSha, + }); liveUpdate(sharedLogId, `Fetching commit details`); const commitData = await getCommit( accessToken, @@ -170,7 +190,7 @@ const aihandler = async (data) => { commitSha, ); - console.log(`[AI Handler] Fetching repository structure`); + githubLog.info("Fetching repository tree", { repo: repoFullName }); liveUpdate(sharedLogId, `Fetching repository structure`); let repoStructure = ""; let repoTree = null; @@ -184,20 +204,23 @@ const aihandler = async (data) => { repoStructure = formatRepoTree(repoTree.tree, 3); if (repoTree.truncated) { - console.warn( - `[AI Handler] Repository tree truncated by GitHub — scan may be partial`, - ); + githubLog.warn("Repository tree truncated by GitHub — partial scan", { + repo: repoFullName, + }); liveUpdate( sharedLogId, `Repository tree truncated by GitHub — scan may be partial`, ); } } catch (error) { - console.warn(`[AI Handler] Could not fetch repo tree: ${error.message}`); + githubLog.warn("Could not fetch repository tree", { + repo: repoFullName, + detail: error.message, + }); repoStructure = "Repository structure not available"; } - console.log(`[AI Handler] Checking for existing README`); + githubLog.info("Checking for existing README", { repo: repoFullName }); liveUpdate(sharedLogId, `Checking for existing README`); const readmeFileName = process.env.README_FILE_NAME || "README.md"; let existingReadme = null; @@ -214,18 +237,20 @@ const aihandler = async (data) => { if (readmeData) { existingReadme = readmeData.content; existingReadmeSha = readmeData.sha; - console.log( - `[AI Handler] Found existing README (${readmeData.size} bytes)`, - ); + githubLog.info("Existing README found", { + repo: repoFullName, + bytes: readmeData.size, + }); liveUpdate( sharedLogId, `Found existing README (${readmeData.size} bytes)`, ); } } catch (error) { - console.log( - `[AI Handler] No existing README found or error fetching: ${error.message}`, - ); + githubLog.info("No existing README — generating from scratch", { + repo: repoFullName, + detail: error.message, + }); liveUpdate( sharedLogId, `No existing README found — will generate from scratch`, @@ -251,12 +276,16 @@ const aihandler = async (data) => { repo_limits.maxFilesFullScan, repo_limits.maxLinesPerFile, ); - console.log( - `[AI Handler] Scanned ${fullCodebase.length} important files from repository`, - ); + githubLog.info("Repository scan complete", { + repo: repoFullName, + files: fullCodebase.length, + }); liveUpdate(sharedLogId, `Scanned ${fullCodebase.length} important files`); } catch (error) { - console.error(`[AI Handler] Error scanning repository: ${error.message}`); + githubLog.error("Repository scan failed", { + repo: repoFullName, + detail: error.message, + }); } const fullCodebasePathSet = new Set(fullCodebase.map((f) => f.path)); @@ -288,9 +317,10 @@ const aihandler = async (data) => { // Nothing worth documenting changed — this is a normal outcome, not a // failure, so settle the log as skipped and commit nothing. if (result.skipped) { - console.log( - `[AI Handler] No README update needed for ${repoFullName} — ${result.reason}`, - ); + generationLog.info("No README update needed", { + repo: repoFullName, + reason: result.reason, + }); liveUpdate( sharedLogId, `No major section update — skipping README commit`, @@ -332,7 +362,10 @@ const aihandler = async (data) => { sharedLogId, ); - console.log("Readme is commited successfully"); + githubLog.info("README committed", { + repo: repoFullName, + commit: commitResult.commit.sha, + }); } catch { liveUpdate(sharedLogId, `Readme failed to commit `); @@ -344,14 +377,15 @@ const aihandler = async (data) => { sharedLogId, ); - console.log("Readme failed to commit"); + githubLog.error("README commit failed", { repo: repoFullName }); } } catch (error) { - console.error( - `[AI Handler] ✗ Error generating README for ${repoFullName}:`, - error.message, - ); - console.error(error.stack); + generationLog.error("README generation failed", { + repo: repoFullName, + commit: commitSha, + detail: error.message, + stack: error.stack, + }); liveUpdate(sharedLogId, `✗ Failed: ${error.message}`); await updateLogStatus( data.logId, @@ -401,9 +435,11 @@ async function fetchFilesFromTree( }); } } catch (err) { - console.warn( - `[AI Handler] Could not fetch file ${filePath}: ${err.message}`, - ); + githubLog.warn("Could not fetch file", { + repo: `${owner}/${repo}`, + path: filePath, + detail: err.message, + }); } } return results; @@ -448,9 +484,11 @@ async function fetchChangedFiles( }); } } catch (err) { - console.warn( - `[AI Handler] Could not fetch changed file ${file.filename}: ${err.message}`, - ); + githubLog.warn("Could not fetch changed file", { + repo: `${owner}/${repo}`, + path: file.filename, + detail: err.message, + }); } } return results; @@ -514,7 +552,9 @@ async function cleanupHandler(job) { sharedLogId, `Starting README cleanup for ${repoOwner}/${repoName}`, ); - console.log("[cleanUpReadme] Fetching README.md"); + githubLog.info("Fetching README for cleanup", { + repo: `${repoOwner}/${repoName}`, + }); const readmeFile = await getFileContent( accessToken, repoOwner, @@ -524,16 +564,23 @@ async function cleanupHandler(job) { ); if (!readmeFile?.content?.trim()) { - console.log("[cleanUpReadme] README.md not found"); + githubLog.warn("README not found — cleanup cannot run", { + repo: `${repoOwner}/${repoName}`, + }); // Retrying cannot conjure a README — fail the job outright rather than // burning every attempt plus its backoff on a job that cannot succeed. throw new UnrecoverableError("README.md not found in repository"); } - console.log("[cleanUpReadme] README fetched"); + githubLog.info("README fetched", { + repo: `${repoOwner}/${repoName}`, + bytes: readmeFile.content.length, + }); liveUpdate(sharedLogId, "Fetched existing README.md"); liveUpdate(sharedLogId, "Rewriting the README"); - console.log("[cleanUpReadme] Running AI cleanup"); + cleanupLog.info("Running README cleanup", { + repo: `${repoOwner}/${repoName}`, + }); const llmService = new LlmService(); const cleanedReadme = await llmService.cleanup( readmeFile.content, @@ -543,13 +590,15 @@ async function cleanupHandler(job) { liveUpdate(sharedLogId, "The model returned an empty README"); throw new Error("Cleanup returned empty content"); } - console.log("[cleanUpReadme] AI cleanup complete"); + cleanupLog.info("Cleanup complete", { chars: cleanedReadme.length }); liveUpdate( sharedLogId, `Cleanup complete — ${cleanedReadme.length.toLocaleString()} characters`, ); - console.log("[cleanUpReadme] Committing README"); + githubLog.info("Committing cleaned README", { + repo: `${repoOwner}/${repoName}`, + }); liveUpdate(sharedLogId, "Committing cleaned README to GitHub"); const commitResult = await commitFile( accessToken, @@ -562,7 +611,10 @@ async function cleanupHandler(job) { readmeFile.sha, ); - console.log("[cleanUpReadme] README committed:", commitResult.commit.sha); + githubLog.info("Cleaned README committed", { + repo: `${repoOwner}/${repoName}`, + commit: commitResult.commit.sha, + }); liveUpdate( sharedLogId, `✓ README committed: ${commitResult.commit.sha.slice(0, 7)}`, @@ -581,7 +633,10 @@ async function cleanupHandler(job) { ); await redis.del("admin_analytics"); } catch (error) { - console.error("[cleanUpReadme] Failed:", error.message); + cleanupLog.error("README cleanup failed", { + repo: `${repoOwner}/${repoName}`, + detail: error.message, + }); // Only settle the log as failed once no attempt is left, so a transient // failure does not flash "failed" in the UI before the retry reopens it. diff --git a/server/src/utils/logger.js b/server/src/utils/logger.js new file mode 100644 index 0000000..842d4fc --- /dev/null +++ b/server/src/utils/logger.js @@ -0,0 +1,132 @@ +import winston from "winston"; + +const { combine, timestamp, printf, colorize, errors, json, splat } = + winston.format; + +const isProduction = process.env.NODE_ENV === "production"; + +// Tags name the subsystem a line came from, so no call site has to hand-write +// a "[Something]" prefix into its message any more. Add a tag here rather than +// passing a raw string at the call site — a typo'd tag is invisible in search. +export const TAGS = { + SERVER: "server", + GITHUB: "github", + AI: "ai", + WORKER: "worker", + QUEUE: "queue", + DB: "db", + AUTH: "auth", + EMAIL: "email", + CONVEX: "convex", + REDIS: "redis", +}; + +// Anything that is not part of the message itself is printed as key=value at +// the end of the line, so structured fields survive the human-readable format +// instead of being flattened into prose. +function formatMeta(meta) { + const entries = Object.entries(meta).filter( + ([, value]) => value !== undefined && value !== null && value !== "", + ); + + if (entries.length === 0) return ""; + + return ( + " " + + entries + .map(([key, value]) => { + const text = + typeof value === "object" ? JSON.stringify(value) : String(value); + return `${key}=${text}`; + }) + .join(" ") + ); +} + +const humanFormat = printf((info) => { + const { + level, + message, + timestamp: time, + tag, + provider, + stack, + ...rest + } = info; + + // Winston's own bookkeeping symbols carry no information the printed line + // needs, and they would otherwise show up as key=value noise. + const meta = Object.fromEntries(Object.entries(rest)); + + // Provider rides alongside the tag (ai:Gemini) because for AI lines the + // provider is the first thing you look for when a run goes wrong. + const label = provider ? `${tag}:${provider}` : tag; + const head = `${time} ${level} [${label ?? "app"}] ${message}`; + + return stack + ? `${head}${formatMeta(meta)}\n${stack}` + : head + formatMeta(meta); +}); + +export const logger = winston.createLogger({ + level: process.env.LOG_LEVEL || (isProduction ? "info" : "debug"), + // errors({ stack: true }) lets `log.error("msg", error)` keep the stack + // instead of collapsing the error to "[object Object]". + format: combine(errors({ stack: true }), splat(), timestamp()), + transports: [ + new winston.transports.Console({ + // JSON in production so a log shipper can parse it; readable lines in + // development where a human is the only consumer. + format: isProduction + ? json() + : combine(colorize({ level: true }), humanFormat), + handleExceptions: true, + handleRejections: true, + }), + ], + exitOnError: false, +}); + +// Child logger bound to a tag (and any other permanent fields, such as the +// provider name for an AI call). Children inherit the level and transports. +export function taggedLogger(tag, meta = {}) { + return logger.child({ tag, ...meta }); +} + +export const serverLog = taggedLogger(TAGS.SERVER); +export const githubLog = taggedLogger(TAGS.GITHUB); +export const aiLog = taggedLogger(TAGS.AI); +export const workerLog = taggedLogger(TAGS.WORKER); +export const queueLog = taggedLogger(TAGS.QUEUE); +export const dbLog = taggedLogger(TAGS.DB); +export const authLog = taggedLogger(TAGS.AUTH); +export const emailLog = taggedLogger(TAGS.EMAIL); +export const convexLog = taggedLogger(TAGS.CONVEX); +export const redisLog = taggedLogger(TAGS.REDIS); + +// AI lines always carry the provider that served the call, so a fallback run +// reads as ai:Gemini failing and ai:Sarvam succeeding rather than one blur. +export function providerLog(providerName) { + return taggedLogger(TAGS.AI, { provider: providerName }); +} + +// Express request logging: one line per finished request, with the status and +// duration attached as fields instead of being baked into the message. +export function requestLogger(req, res, next) { + const startedAt = Date.now(); + + res.on("finish", () => { + const durationMs = Date.now() - startedAt; + const level = + res.statusCode >= 500 ? "error" : res.statusCode >= 400 ? "warn" : "info"; + + serverLog.log(level, `${req.method} ${req.originalUrl}`, { + status: res.statusCode, + durationMs, + }); + }); + + next(); +} + +export default logger;