From ed6e09ec6d5b419a1040b140839118a7dfa783cc Mon Sep 17 00:00:00 2001 From: Alexander Date: Thu, 28 Mar 2024 12:28:04 +0100 Subject: [PATCH] feat(assist): new logs format --- assist/package-lock.json | 233 ++++++++++++++++++++++++- assist/package.json | 3 +- assist/server.js | 4 +- assist/utils/HeapSnapshot.js | 19 +- assist/utils/assistHelper.js | 34 ++-- assist/utils/geoIP.js | 7 +- assist/utils/health.js | 12 +- assist/utils/helper.js | 36 ++-- assist/utils/httpHandlers.js | 13 +- assist/utils/logger.js | 23 +++ assist/utils/socketHandlers.js | 45 ++--- ee/assist/server.js | 31 ++-- ee/assist/servers/websocket-cluster.js | 12 +- ee/assist/servers/websocket.js | 3 +- ee/assist/utils/helper-ee.js | 3 +- ee/assist/utils/stats.js | 28 +-- ee/assist/utils/wsServer.js | 5 +- 17 files changed, 377 insertions(+), 134 deletions(-) create mode 100644 assist/utils/logger.js diff --git a/assist/package-lock.json b/assist/package-lock.json index 47aae7032..99f0dfafe 100644 --- a/assist/package-lock.json +++ b/assist/package-lock.json @@ -14,7 +14,26 @@ "jsonwebtoken": "^9.0.2", "prom-client": "^15.0.0", "socket.io": "^4.7.2", - "ua-parser-js": "^1.0.37" + "ua-parser-js": "^1.0.37", + "winston": "^3.13.0" + } + }, + "node_modules/@colors/colors": { + "version": "1.6.0", + "resolved": "https://registry.npmjs.org/@colors/colors/-/colors-1.6.0.tgz", + "integrity": "sha512-Ir+AOibqzrIsL6ajt3Rz3LskB7OiMVHqltZmspbW/TJuTVuyOMirVqAkjfY6JISiLHgyNqicAC8AyHHGzNd/dA==", + "engines": { + "node": ">=0.1.90" + } + }, + "node_modules/@dabh/diagnostics": { + "version": "2.0.3", + "resolved": "https://registry.npmjs.org/@dabh/diagnostics/-/diagnostics-2.0.3.tgz", + "integrity": "sha512-hrlQOIi7hAfzsMqlGSFyVucrx38O+j6wiGOf//H2ecvIEqYN4ADBSS2iLMh5UFyDunCNniUIPk/q3riFv45xRA==", + "dependencies": { + "colorspace": "1.1.x", + "enabled": "2.0.x", + "kuler": "^2.0.0" } }, "node_modules/@maxmind/geoip2-node": { @@ -57,6 +76,11 @@ "resolved": "https://registry.npmjs.org/@types/node/-/node-20.5.9.tgz", "integrity": "sha512-PcGNd//40kHAS3sTlzKB9C9XL4K0sTup8nbG5lC14kzEteTNuAFh9u5nA0o5TWnSG2r/JNPRXFVcHJIIeRlmqQ==" }, + "node_modules/@types/triple-beam": { + "version": "1.3.5", + "resolved": "https://registry.npmjs.org/@types/triple-beam/-/triple-beam-1.3.5.tgz", + "integrity": "sha512-6WaYesThRMCl19iryMYP7/x2OVgCtbIVflDGFpWnb9irXI3UjYE4AzmYuiUKY1AJstGijoY+MgUszMgRxIYTYw==" + }, "node_modules/accepts": { "version": "1.3.8", "resolved": "https://registry.npmjs.org/accepts/-/accepts-1.3.8.tgz", @@ -82,6 +106,11 @@ "node": ">=0.8" } }, + "node_modules/async": { + "version": "3.2.5", + "resolved": "https://registry.npmjs.org/async/-/async-3.2.5.tgz", + "integrity": "sha512-baNZyqaaLhyLVKm/DlvdW051MSgO6b8eVfIezl9E5PqWxFgzLm/wQntEW4zOytVburDEr0JlALEpdOFwvErLsg==" + }, "node_modules/base64id": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/base64id/-/base64id-2.0.0.tgz", @@ -143,6 +172,46 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/color": { + "version": "3.2.1", + "resolved": "https://registry.npmjs.org/color/-/color-3.2.1.tgz", + "integrity": "sha512-aBl7dZI9ENN6fUGC7mWpMTPNHmWUSNan9tuWN6ahh5ZLNk9baLJOnSMlrQkHcrfFgz2/RigjUVAjdx36VcemKA==", + "dependencies": { + "color-convert": "^1.9.3", + "color-string": "^1.6.0" + } + }, + "node_modules/color-convert": { + "version": "1.9.3", + "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-1.9.3.tgz", + "integrity": "sha512-QfAUtd+vFdAtFQcC8CCyYt1fYWxSqAiK2cSD6zDB8N3cpsEBAvRxp9zOGg6G/SHHJYAT88/az/IuDGALsNVbGg==", + "dependencies": { + "color-name": "1.1.3" + } + }, + "node_modules/color-name": { + "version": "1.1.3", + "resolved": "https://registry.npmjs.org/color-name/-/color-name-1.1.3.tgz", + "integrity": "sha512-72fSenhMw2HZMTVHeCA9KCmpEIbzWiQsjN+BHcBbS9vr1mtt+vJjPdksIBNUmKAW8TFUDPJK5SUU3QhE9NEXDw==" + }, + "node_modules/color-string": { + "version": "1.9.1", + "resolved": "https://registry.npmjs.org/color-string/-/color-string-1.9.1.tgz", + "integrity": "sha512-shrVawQFojnZv6xM40anx4CkoDP+fZsw/ZerEMsW/pyzsRbElpsL/DBVW7q3ExxwusdNXI3lXpuhEZkzs8p5Eg==", + "dependencies": { + "color-name": "^1.0.0", + "simple-swizzle": "^0.2.2" + } + }, + "node_modules/colorspace": { + "version": "1.1.4", + "resolved": "https://registry.npmjs.org/colorspace/-/colorspace-1.1.4.tgz", + "integrity": "sha512-BgvKJiuVu1igBUF2kEjRCZXol6wiiGbY5ipL/oVPwm0BL9sIpMIzM8IK7vwuxIIzOXMV3Ey5w+vxhm0rR/TN8w==", + "dependencies": { + "color": "^3.1.3", + "text-hex": "1.0.x" + } + }, "node_modules/content-disposition": { "version": "0.5.4", "resolved": "https://registry.npmjs.org/content-disposition/-/content-disposition-0.5.4.tgz", @@ -230,6 +299,11 @@ "resolved": "https://registry.npmjs.org/ee-first/-/ee-first-1.1.1.tgz", "integrity": "sha512-WMwm9LhRUo+WUaRN+vRuETqG89IgZphVSNkdFgeb6sS/E4OrDIN7t48CAewSHXc6C8lefD8KKfr5vY61brQlow==" }, + "node_modules/enabled": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/enabled/-/enabled-2.0.0.tgz", + "integrity": "sha512-AKrN98kuwOzMIdAizXGI86UFBoo26CL21UM763y1h/GMSJ4/OHU9k2YlsmBpyScFo/wbLzWQJBMCW4+IO3/+OQ==" + }, "node_modules/encodeurl": { "version": "1.0.2", "resolved": "https://registry.npmjs.org/encodeurl/-/encodeurl-1.0.2.tgz", @@ -357,6 +431,11 @@ "node >=0.6.0" ] }, + "node_modules/fecha": { + "version": "4.2.3", + "resolved": "https://registry.npmjs.org/fecha/-/fecha-4.2.3.tgz", + "integrity": "sha512-OP2IUU6HeYKJi3i0z4A19kHMQoLVs4Hc+DPqqxI2h/DPZHTm/vjsfC6P0b4jCMy14XizLBqvndQ+UilD7707Jw==" + }, "node_modules/finalhandler": { "version": "1.2.0", "resolved": "https://registry.npmjs.org/finalhandler/-/finalhandler-1.2.0.tgz", @@ -374,6 +453,11 @@ "node": ">= 0.8" } }, + "node_modules/fn.name": { + "version": "1.1.0", + "resolved": "https://registry.npmjs.org/fn.name/-/fn.name-1.1.0.tgz", + "integrity": "sha512-GRnmB5gPyJpAhTQdSZTSp9uaPSvl09KoYcMQtsB9rQoOmzs9dH6ffeccH+Z+cv6P68Hu5bC6JjRh4Ah/mHSNRw==" + }, "node_modules/forwarded": { "version": "0.2.0", "resolved": "https://registry.npmjs.org/forwarded/-/forwarded-0.2.0.tgz", @@ -490,6 +574,22 @@ "node": ">= 0.10" } }, + "node_modules/is-arrayish": { + "version": "0.3.2", + "resolved": "https://registry.npmjs.org/is-arrayish/-/is-arrayish-0.3.2.tgz", + "integrity": "sha512-eVRqCvVlZbuw3GrM63ovNSNAeA1K16kaR/LRY/92w0zxQ5/1YzwblUX652i4Xs9RwAGjW9d9y6X88t8OaAJfWQ==" + }, + "node_modules/is-stream": { + "version": "2.0.1", + "resolved": "https://registry.npmjs.org/is-stream/-/is-stream-2.0.1.tgz", + "integrity": "sha512-hFoiJiTl63nn+kstHGBtewWSKnQLpyb155KHheA1l39uvtO9nWIop1p3udqPcUd/xbF1VLMO4n7OI6p7RbngDg==", + "engines": { + "node": ">=8" + }, + "funding": { + "url": "https://github.com/sponsors/sindresorhus" + } + }, "node_modules/json-schema": { "version": "0.4.0", "resolved": "https://registry.npmjs.org/json-schema/-/json-schema-0.4.0.tgz", @@ -554,6 +654,11 @@ "safe-buffer": "^5.0.1" } }, + "node_modules/kuler": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/kuler/-/kuler-2.0.0.tgz", + "integrity": "sha512-Xq9nH7KlWZmXAtodXDDRE7vs6DU1gTU8zYDHDiWLSip45Egwq3plLHzPn27NgvzL2r1LMPC1vdqh98sQxtqj4A==" + }, "node_modules/lodash.includes": { "version": "4.3.0", "resolved": "https://registry.npmjs.org/lodash.includes/-/lodash.includes-4.3.0.tgz", @@ -589,6 +694,27 @@ "resolved": "https://registry.npmjs.org/lodash.once/-/lodash.once-4.1.1.tgz", "integrity": "sha512-Sb487aTOCr9drQVL8pIxOzVhafOjZN9UU54hiN8PU3uAiSV7lx1yYNpbNmex2PK6dSJoNTSJUUswT651yww3Mg==" }, + "node_modules/logform": { + "version": "2.6.0", + "resolved": "https://registry.npmjs.org/logform/-/logform-2.6.0.tgz", + "integrity": "sha512-1ulHeNPp6k/LD8H91o7VYFBng5i1BDE7HoKxVbZiGFidS1Rj65qcywLxX+pVfAPoQJEjRdvKcusKwOupHCVOVQ==", + "dependencies": { + "@colors/colors": "1.6.0", + "@types/triple-beam": "^1.3.2", + "fecha": "^4.2.0", + "ms": "^2.1.1", + "safe-stable-stringify": "^2.3.1", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/logform/node_modules/ms": { + "version": "2.1.3", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.3.tgz", + "integrity": "sha512-6FlzubTLZG3J2a/NVCAleEhjzq5oxgHyaCU9yYXvcLsvoVaHJq/s5xXI6/XXP6tz7R9xAOtHnSO/tXtF3WRTlA==" + }, "node_modules/lru-cache": { "version": "6.0.0", "resolved": "https://registry.npmjs.org/lru-cache/-/lru-cache-6.0.0.tgz", @@ -713,6 +839,14 @@ "node": ">= 0.8" } }, + "node_modules/one-time": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/one-time/-/one-time-1.0.0.tgz", + "integrity": "sha512-5DXOiRKwuSEcQ/l0kGCF6Q3jcADFv5tSmRaJck/OqkVFcOzutB134KRSfF0xDrL39MNnqxbHBbUUcjZIhTgb2g==", + "dependencies": { + "fn.name": "1.x.x" + } + }, "node_modules/parseurl": { "version": "1.3.3", "resolved": "https://registry.npmjs.org/parseurl/-/parseurl-1.3.3.tgz", @@ -786,6 +920,19 @@ "node": ">= 0.8" } }, + "node_modules/readable-stream": { + "version": "3.6.2", + "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.2.tgz", + "integrity": "sha512-9u/sniCrY3D5WdsERHzHE4G2YCXqoG5FTHUiCC4SIbr6XcLZBY05ya9EKjYek9O5xOAwjGq+1JdGBAS7Q9ScoA==", + "dependencies": { + "inherits": "^2.0.3", + "string_decoder": "^1.1.1", + "util-deprecate": "^1.0.1" + }, + "engines": { + "node": ">= 6" + } + }, "node_modules/safe-buffer": { "version": "5.2.1", "resolved": "https://registry.npmjs.org/safe-buffer/-/safe-buffer-5.2.1.tgz", @@ -805,6 +952,14 @@ } ] }, + "node_modules/safe-stable-stringify": { + "version": "2.4.3", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.4.3.tgz", + "integrity": "sha512-e2bDA2WJT0wxseVd4lsDP4+3ONX6HpMXQa1ZhFQ7SU+GjvORCmShbCMltrtIDfkYhVHrOcPtj+KhmDBdPdZD1g==", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", @@ -884,6 +1039,14 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/simple-swizzle": { + "version": "0.2.2", + "resolved": "https://registry.npmjs.org/simple-swizzle/-/simple-swizzle-0.2.2.tgz", + "integrity": "sha512-JA//kQgZtbuY83m+xT+tXJkmJncGMTFT+C+g2h2R9uxkYIrE2yy9sgmcLhCnw57/WSD+Eh3J97FPEDFnbXnDUg==", + "dependencies": { + "is-arrayish": "^0.3.1" + } + }, "node_modules/socket.io": { "version": "4.7.2", "resolved": "https://registry.npmjs.org/socket.io/-/socket.io-4.7.2.tgz", @@ -963,6 +1126,14 @@ "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.2.tgz", "integrity": "sha512-sGkPx+VjMtmA6MX27oA4FBFELFCZZ4S4XqeGOXCv68tT+jb3vk/RyaKWP0PTKyWtmLSM0b+adUTEvbs1PEaH2w==" }, + "node_modules/stack-trace": { + "version": "0.0.10", + "resolved": "https://registry.npmjs.org/stack-trace/-/stack-trace-0.0.10.tgz", + "integrity": "sha512-KGzahc7puUKkzyMt+IqAep+TVNbKP+k2Lmwhub39m1AsTSkaDutx56aDCo+HLDzf/D26BIHTJWNiTG1KAJiQCg==", + "engines": { + "node": "*" + } + }, "node_modules/statuses": { "version": "2.0.1", "resolved": "https://registry.npmjs.org/statuses/-/statuses-2.0.1.tgz", @@ -971,6 +1142,14 @@ "node": ">= 0.8" } }, + "node_modules/string_decoder": { + "version": "1.3.0", + "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-1.3.0.tgz", + "integrity": "sha512-hkRX8U1WjJFd8LsDJ2yQ/wWWxaopEsABU1XfkM8A+j0+85JAGppt16cr1Whg6KIbb4okU6Mql6BOj+uup/wKeA==", + "dependencies": { + "safe-buffer": "~5.2.0" + } + }, "node_modules/tdigest": { "version": "0.1.2", "resolved": "https://registry.npmjs.org/tdigest/-/tdigest-0.1.2.tgz", @@ -979,6 +1158,11 @@ "bintrees": "1.0.2" } }, + "node_modules/text-hex": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/text-hex/-/text-hex-1.0.0.tgz", + "integrity": "sha512-uuVGNWzgJ4yhRaNSiubPY7OjISw4sw4E5Uv0wbjp+OzcbmVU/rsT8ujgcXJhn9ypzsgr5vlzpPqP+MBBKcGvbg==" + }, "node_modules/tiny-lru": { "version": "11.0.1", "resolved": "https://registry.npmjs.org/tiny-lru/-/tiny-lru-11.0.1.tgz", @@ -995,6 +1179,14 @@ "node": ">=0.6" } }, + "node_modules/triple-beam": { + "version": "1.4.1", + "resolved": "https://registry.npmjs.org/triple-beam/-/triple-beam-1.4.1.tgz", + "integrity": "sha512-aZbgViZrg1QNcG+LULa7nhZpJTZSLm/mXnHXnbAbjmN5aSa0y7V+wvv6+4WaBtpISJzThKy+PIPxc1Nq1EJ9mg==", + "engines": { + "node": ">= 14.0.0" + } + }, "node_modules/type-is": { "version": "1.6.18", "resolved": "https://registry.npmjs.org/type-is/-/type-is-1.6.18.tgz", @@ -1037,6 +1229,11 @@ "node": ">= 0.8" } }, + "node_modules/util-deprecate": { + "version": "1.0.2", + "resolved": "https://registry.npmjs.org/util-deprecate/-/util-deprecate-1.0.2.tgz", + "integrity": "sha512-EPD5q1uXyFxJpCrLnCc1nHnq3gOa6DZBocAIiI2TaSCA7VCJ1UJDMagCzIkXNsUYfD1daK//LTEQ8xiIbrHtcw==" + }, "node_modules/utils-merge": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/utils-merge/-/utils-merge-1.0.1.tgz", @@ -1066,6 +1263,40 @@ "extsprintf": "^1.2.0" } }, + "node_modules/winston": { + "version": "3.13.0", + "resolved": "https://registry.npmjs.org/winston/-/winston-3.13.0.tgz", + "integrity": "sha512-rwidmA1w3SE4j0E5MuIufFhyJPBDG7Nu71RkZor1p2+qHvJSZ9GYDA81AyleQcZbh/+V6HjeBdfnTZJm9rSeQQ==", + "dependencies": { + "@colors/colors": "^1.6.0", + "@dabh/diagnostics": "^2.0.2", + "async": "^3.2.3", + "is-stream": "^2.0.0", + "logform": "^2.4.0", + "one-time": "^1.0.0", + "readable-stream": "^3.4.0", + "safe-stable-stringify": "^2.3.1", + "stack-trace": "0.0.x", + "triple-beam": "^1.3.0", + "winston-transport": "^4.7.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/winston-transport": { + "version": "4.7.0", + "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.7.0.tgz", + "integrity": "sha512-ajBj65K5I7denzer2IYW6+2bNIVqLGDHqDw3Ow8Ohh+vdW+rv4MZ6eiDvHoKhfJFZ2auyN8byXieDDJ96ViONg==", + "dependencies": { + "logform": "^2.3.2", + "readable-stream": "^3.6.0", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, "node_modules/ws": { "version": "8.11.0", "resolved": "https://registry.npmjs.org/ws/-/ws-8.11.0.tgz", diff --git a/assist/package.json b/assist/package.json index 3140cf4e6..6079b0d50 100644 --- a/assist/package.json +++ b/assist/package.json @@ -23,6 +23,7 @@ "jsonwebtoken": "^9.0.2", "prom-client": "^15.0.0", "socket.io": "^4.7.2", - "ua-parser-js": "^1.0.37" + "ua-parser-js": "^1.0.37", + "winston": "^3.13.0" } } diff --git a/assist/server.js b/assist/server.js index 911c8cf36..87e1821c8 100644 --- a/assist/server.js +++ b/assist/server.js @@ -5,6 +5,7 @@ const {request_logger} = require("./utils/helper"); const health = require("./utils/health"); const assert = require('assert').strict const register = require('./utils/metrics').register; +const {logger} = require('./utils/logger'); health.healthApp.get('/metrics', async (req, res) => { try { @@ -15,7 +16,6 @@ health.healthApp.get('/metrics', async (req, res) => { } }); -const debug = process.env.debug === "1"; const heapdump = process.env.heapdump === "1"; const HOST = process.env.LISTEN_HOST || '0.0.0.0'; const PORT = process.env.LISTEN_PORT || 9001; @@ -37,7 +37,7 @@ wsapp.use(`${PREFIX}/${P_KEY}`, socket.wsRouter); heapdump && wsapp.use(`${PREFIX}/${P_KEY}/heapdump`, dumps.router); const wsserver = wsapp.listen(PORT, HOST, () => { - console.log(`WS App listening on http://${HOST}:${PORT}`); + logger.info(`WS App listening on http://${HOST}:${PORT}`); health.healthApp.listen(health.PORT, HOST, health.listen_cb); }); diff --git a/assist/utils/HeapSnapshot.js b/assist/utils/HeapSnapshot.js index 6d266c22e..cbd961027 100644 --- a/assist/utils/HeapSnapshot.js +++ b/assist/utils/HeapSnapshot.js @@ -1,16 +1,16 @@ const fs = require('fs'); const v8 = require('v8'); const express = require('express'); -const router = express.Router(); +const {logger} = require('./logger'); -const heapdump = process.env.heapdump === "1"; +const router = express.Router(); const location = '/tmp/'; let creationStatus = null; let fileName = null; async function createHeapSnapshot() { if (creationStatus) { - return console.log(`In progress ${fileName}`); + return logger.info(`In progress ${fileName}`); } if (fileName === null) { fileName = `${Date.now()}.heapsnapshot`; @@ -20,7 +20,7 @@ async function createHeapSnapshot() { location + fileName, v8.getHeapSnapshot() ); - console.log(`Created ${fileName}`); + logger.info(`Created ${fileName}`); creationStatus = true; } @@ -33,13 +33,12 @@ async function downloadHeapSnapshot(req, res) { } res.download(location + fileName, function (err) { if (err) { - return console.error("error while uploading HeapSnapshot file"); + return logger.error("error while uploading HeapSnapshot file"); } try { fs.unlinkSync(location + fileName) } catch (err) { - console.error("error while deleting heapsnapshot file"); - console.error(err); + logger.error(`error while deleting heap snapshot file, err: ${err}`); } }); } @@ -61,11 +60,11 @@ function createNewHeapSnapshot(req, res) { res.end(JSON.stringify({path: location + fileName, 'done': creationStatus})); } -if (heapdump) { +if (process.env.heapdump === "1") { router.get(`/status`, getHeapSnapshotStatus); router.get(`/new`, createNewHeapSnapshot); router.get(`/download`, downloadHeapSnapshot); + logger.info(`HeapSnapshot enabled. Send a request to "/heapdump/new" to generate a heapdump.`); } -module.exports = {router} -heapdump && console.log(`HeapSnapshot enabled. Send a request to "/heapdump/new" to generate a heapdump.`); \ No newline at end of file +module.exports = {router}; diff --git a/assist/utils/assistHelper.js b/assist/utils/assistHelper.js index 5650f73fd..c27c80963 100644 --- a/assist/utils/assistHelper.js +++ b/assist/utils/assistHelper.js @@ -2,8 +2,8 @@ const jwt = require('jsonwebtoken'); const uaParser = require('ua-parser-js'); const {geoip} = require('./geoIP'); const {extractPeerId} = require('./helper'); +const {logger} = require('./logger'); -let debug = process.env.debug === "1"; const IDENTITIES = {agent: 'agent', session: 'session'}; const EVENTS_DEFINITION = { listen: { @@ -58,7 +58,7 @@ const BASE_sessionInfo = { * */ const extractSessionInfo = function (socket) { if (socket.handshake.query.sessionInfo !== undefined) { - debug && console.log(`received headers: ${socket.handshake.headers}`); + logger.debug(`received headers: ${socket.handshake.headers}`); socket.handshake.query.sessionInfo = JSON.parse(socket.handshake.query.sessionInfo); socket.handshake.query.sessionInfo = {...BASE_sessionInfo, ...socket.handshake.query.sessionInfo}; @@ -73,7 +73,7 @@ const extractSessionInfo = function (socket) { socket.handshake.query.sessionInfo.userState = null; socket.handshake.query.sessionInfo.userCity = null; if (geoip() !== null) { - debug && console.log(`looking for location of ${socket.handshake.headers['x-forwarded-for'] || socket.handshake.address}`); + logger.debug(`looking for location of ${socket.handshake.headers['x-forwarded-for'] || socket.handshake.address}`); try { let ip = socket.handshake.headers['x-forwarded-for'] || socket.handshake.address; ip = ip.split(",")[0]; @@ -82,8 +82,7 @@ const extractSessionInfo = function (socket) { socket.handshake.query.sessionInfo.userCity = info.city.names.en; socket.handshake.query.sessionInfo.userState = info.subdivisions.length > 0 ? info.subdivisions[0].names.en : null; } catch (e) { - debug && console.log("geoip-country failed"); - debug && console.log(e); + logger.debug(`geoip-country failed: ${e}`); } } } @@ -92,28 +91,28 @@ const extractSessionInfo = function (socket) { function socketConnexionTimeout(io) { if (process.env.CLEAR_SOCKET_TIME !== undefined && parseFloat(process.env.CLEAR_SOCKET_TIME) > 0) { const CLEAR_SOCKET_TIME = parseFloat(process.env.CLEAR_SOCKET_TIME); - console.log(`WS manually disconnecting sockets after ${CLEAR_SOCKET_TIME} min`); + logger.info(`WS manually disconnecting sockets after ${CLEAR_SOCKET_TIME} min`); setInterval(async (io) => { try { const now = new Date(); let allSockets = await io.fetchSockets(); for (let socket of allSockets) { if (socket._connectedAt !== undefined && ((now - socket._connectedAt) / 1000) / 60 > CLEAR_SOCKET_TIME) { - debug && console.log(`disconnecting ${socket.id} after more than ${CLEAR_SOCKET_TIME} of connexion.`); + logger.debug(`disconnecting ${socket.id} after more than ${CLEAR_SOCKET_TIME} of connexion.`); socket.disconnect(); } } } catch (e) { - console.error(e); + logger.error(`Error while disconnecting sockets: ${e}`); } }, 0.5 * 60 * 1000, io); } else { - debug && console.log(`WS no manually disconnecting sockets.`); + logger.info(`WS no manually disconnecting sockets.`); } } function errorHandler(listenerName, error) { - console.error(`Error detected from ${listenerName}\n${error}`); + logger.error(`Error detected from ${listenerName}\n${error}`); } function generateAccessToken(payload) { @@ -132,29 +131,26 @@ function check(socket, next) { token = token.substring(JWT_TOKEN_PREFIX.length); } jwt.verify(token, process.env.ASSIST_JWT_SECRET, (err, decoded) => { - debug && console.log("JWT payload:"); - debug && console.log(decoded); + logger.debug(`JWT payload: ${decoded}`); if (err) { - debug && console.error(err); + logger.debug(err); return next(new Error('Authentication error')); } const {projectKey, sessionId} = extractPeerId(socket.handshake.query.peerId); if (!projectKey || !sessionId) { - debug && console.error("Missing attribute:"); - debug && console.error(`projectKey:${projectKey}, sessionId:${sessionId}`); + logger.debug(`Missing attribute: projectKey:${projectKey}, sessionId:${sessionId}`); return next(new Error('Authentication error')); } if (String(projectKey) !== String(decoded.projectKey) || String(sessionId) !== String(decoded.sessionId)) { - debug && console.error(`Trying to access projectKey:${projectKey} instead of ${decoded.projectKey}\nor`); - debug && console.error(`Trying to access sessionId:${sessionId} instead of ${decoded.sessionId}`); + logger.debug(`Trying to access projectKey:${projectKey} instead of ${decoded.projectKey} or + to sessionId:${sessionId} instead of ${decoded.sessionId}`); return next(new Error('Authorization error')); } socket.decoded = decoded; return next(); }); } else { - debug && console.error("something missing in:"); - debug && console.error(socket.handshake); + logger.debug(`something missing in handshake: ${socket.handshake}`); return next(new Error('Authentication error')); } } diff --git a/assist/utils/geoIP.js b/assist/utils/geoIP.js index ae3955101..69445c4fe 100644 --- a/assist/utils/geoIP.js +++ b/assist/utils/geoIP.js @@ -1,4 +1,6 @@ const geoip2Reader = require('@maxmind/geoip2-node').Reader; +const {logger} = require('./logger'); + let geoip = null; if (process.env.MAXMINDDB_FILE !== undefined) { geoip2Reader.open(process.env.MAXMINDDB_FILE, {}) @@ -6,11 +8,10 @@ if (process.env.MAXMINDDB_FILE !== undefined) { geoip = reader; }) .catch(error => { - console.log("Error while opening the MAXMINDDB_FILE.") - console.error(error); + logger.error(`Error while opening the MAXMINDDB_FILE, err: ${error}`); }); } else { - console.error("!!! please provide a valid value for MAXMINDDB_FILE env var."); + logger.error("!!! please provide a valid value for MAXMINDDB_FILE env var."); } module.exports = { diff --git a/assist/utils/health.js b/assist/utils/health.js index 1f46b36ad..2363ad79e 100644 --- a/assist/utils/health.js +++ b/assist/utils/health.js @@ -1,9 +1,10 @@ const express = require('express'); +const {logger} = require('./logger'); +const {request_logger} = require("./helper"); + const HOST = process.env.LISTEN_HOST || '0.0.0.0'; const PORT = process.env.HEALTH_PORT || 8888; -const {request_logger} = require("./helper"); -const debug = process.env.debug === "1"; const respond = function (res, data) { res.statusCode = 200; res.setHeader('Content-Type', 'application/json'); @@ -11,7 +12,7 @@ const respond = function (res, data) { } const check_health = async function (req, res) { - debug && console.log("[WS]looking for all available sessions"); + logger.debug("[WS]looking for all available sessions"); respond(res, { "health": true, "details": { @@ -31,7 +32,7 @@ healthApp.get(['/'], (req, res) => { ); healthApp.get('/health', check_health); healthApp.get('/shutdown', (req, res) => { - console.log("Requested shutdown"); + logger.info("Requested shutdown"); res.statusCode = 200; res.end("ok!"); process.kill(1, "SIGTERM"); @@ -39,8 +40,7 @@ healthApp.get('/shutdown', (req, res) => { ); const listen_cb = async function () { - console.log(`Health App listening on http://${HOST}:${PORT}`); - console.log('Press Ctrl+C to quit.'); + logger.info(`Health App listening on http://${HOST}:${PORT}`); } module.exports = { diff --git a/assist/utils/helper.js b/assist/utils/helper.js index 2a03c58b3..6c7d28299 100644 --- a/assist/utils/helper.js +++ b/assist/utils/helper.js @@ -1,5 +1,5 @@ let PROJECT_KEY_LENGTH = parseInt(process.env.PROJECT_KEY_LENGTH) || 20; -let debug = process.env.debug === "1" || false; +const {logger} = require('./logger'); const extractRoomId = (peerId) => { let {projectKey, sessionId, tabId} = extractPeerId(peerId); @@ -20,11 +20,11 @@ const extractTabId = (peerId) => { const extractPeerId = (peerId) => { let splited = peerId.split("-"); if (splited.length < 2 || splited.length > 3) { - debug && console.error(`cannot split peerId: ${peerId}`); + logger.debug(`cannot split peerId: ${peerId}`); return {}; } if (PROJECT_KEY_LENGTH > 0 && splited[0].length !== PROJECT_KEY_LENGTH) { - debug && console.error(`wrong project key length for peerId: ${peerId}`); + logger.debug(`wrong project key length for peerId: ${peerId}`); return {}; } if (splited.length === 2) { @@ -35,11 +35,13 @@ const extractPeerId = (peerId) => { const request_logger = (identity) => { return (req, res, next) => { - debug && console.log(identity, new Date().toTimeString(), 'REQUEST', req.method, req.originalUrl); + logger.debug(identity, new Date().toTimeString(), 'REQUEST', req.method, req.originalUrl); req.startTs = performance.now(); // track request's start timestamp res.on('finish', function () { - if (this.statusCode !== 200 || debug) { - console.log(new Date().toTimeString(), 'RESPONSE', req.method, req.originalUrl, this.statusCode); + if (this.statusCode !== 200) { + logger.info(new Date().toTimeString(), 'RESPONSE', req.method, req.originalUrl, this.statusCode); + } else { + logger.debug(new Date().toTimeString(), 'RESPONSE', req.method, req.originalUrl, this.statusCode); } }) @@ -49,7 +51,7 @@ const request_logger = (identity) => { const extractProjectKeyFromRequest = function (req) { if (req.params.projectKey) { - debug && console.log(`[WS]where projectKey=${req.params.projectKey}`); + logger.debug(`[WS]where projectKey=${req.params.projectKey}`); return req.params.projectKey; } return undefined; @@ -57,7 +59,7 @@ const extractProjectKeyFromRequest = function (req) { const extractSessionIdFromRequest = function (req) { if (req.params.sessionId) { - debug && console.log(`[WS]where sessionId=${req.params.sessionId}`); + logger.debug(`[WS]where sessionId=${req.params.sessionId}`); return req.params.sessionId; } return undefined; @@ -146,13 +148,13 @@ const transformFilters = function (filter) { for (let key of Object.keys(filter)) { //To support old v1.7.0 payload if (Array.isArray(filter[key]) || filter[key] === undefined || filter[key] === null) { - debug && console.log(`[WS]old format for key=${key}`); + logger.debug(`[WS]old format for key=${key}`); filter[key] = {"values": filter[key]}; } if (filter[key].operator) { - debug && console.log(`[WS]where operator=${filter[key].operator}`); + logger.debug(`[WS]where operator=${filter[key].operator}`); } else { - debug && console.log(`[WS]where operator=DEFAULT-contains`); + logger.debug(`[WS]where operator=DEFAULT-contains`); filter[key].operator = "contains"; } } @@ -173,21 +175,21 @@ const extractPayloadFromRequest = async function (req, res) { } }; if (req.query.q) { - debug && console.log(`[WS]where q=${req.query.q}`); + logger.debug(`[WS]where q=${req.query.q}`); filters.query.value = req.query.q; } if (req.query.key) { - debug && console.log(`[WS]where key=${req.query.key}`); + logger.debug(`[WS]where key=${req.query.key}`); filters.query.key = req.query.key; } if (req.query.userId) { - debug && console.log(`[WS]where userId=${req.query.userId}`); + logger.debug(`[WS]where userId=${req.query.userId}`); filters.filter.userID = [req.query.userId]; } filters.filter = objectToObjectOfArrays(filters.filter); filters.filter = {...filters.filter, ...(req.body.filter || {})}; filters.filter = transformFilters(filters.filter); - debug && console.log("payload/filters:" + JSON.stringify(filters)) + logger.debug("payload/filters:" + JSON.stringify(filters)) return filters; } @@ -262,7 +264,7 @@ const getCompressionConfig = function () { // WS: The theoretical overhead per socket is 19KB (11KB for compressor and 8KB for decompressor) let perMessageDeflate = false; if (process.env.COMPRESSION === "true") { - console.log(`WS compression: enabled`); + logger.info(`WS compression: enabled`); perMessageDeflate = { zlibDeflateOptions: { windowBits: 10, @@ -273,7 +275,7 @@ const getCompressionConfig = function () { } } } else { - console.log(`WS compression: disabled`); + logger.info(`WS compression: disabled`); } return { perMessageDeflate: perMessageDeflate, diff --git a/assist/utils/httpHandlers.js b/assist/utils/httpHandlers.js index b602f9199..049420cc1 100644 --- a/assist/utils/httpHandlers.js +++ b/assist/utils/httpHandlers.js @@ -17,11 +17,10 @@ const { } = require('../utils/metrics'); const {fetchSockets} = require("./wsServer"); const {IDENTITIES} = require("./assistHelper"); - -const debug_log = process.env.debug === "1"; +const {logger} = require('./logger'); const respond = function (req, res, data) { - debug_log && console.log("responding with data: ", JSON.stringify(data)) + logger.debug("responding with data: ", JSON.stringify(data)) let result = {data} if (process.env.uws !== "true") { res.statusCode = 200; @@ -99,7 +98,7 @@ const getAllSessions = async function (projectKey, filters, onlineOnly= false) // Sort by projectKey const socketsListByProject = async function (req, res) { - debug_log && console.log("[WS]looking for available sessions"); + logger.debug("[WS]looking for available sessions"); res.handlerName = 'socketsListByProject'; const _projectKey = extractProjectKeyFromRequest(req); @@ -121,7 +120,7 @@ const socketsListByProject = async function (req, res) { // Sort by projectKey const socketsLiveByProject = async function (req, res) { - debug_log && console.log("[WS]looking for available LIVE sessions"); + logger.debug("[WS]looking for available LIVE sessions"); res.handlerName = 'socketsLiveByProject'; const _projectKey = extractProjectKeyFromRequest(req); @@ -143,7 +142,7 @@ const socketsLiveByProject = async function (req, res) { // Sort by roomID (projectKey+sessionId) const socketsLiveBySession = async function (req, res) { - debug_log && console.log("[WS]looking for LIVE session"); + logger.debug("[WS]looking for LIVE session"); res.handlerName = 'socketsLiveBySession'; const _projectKey = extractProjectKeyFromRequest(req); @@ -160,7 +159,7 @@ const socketsLiveBySession = async function (req, res) { // Sort by projectKey const autocomplete = async function (req, res) { - debug_log && console.log("[WS]autocomplete"); + logger.debug("[WS]autocomplete"); res.handlerName = 'autocomplete'; const _projectKey = extractProjectKeyFromRequest(req); diff --git a/assist/utils/logger.js b/assist/utils/logger.js new file mode 100644 index 000000000..d9147f1ee --- /dev/null +++ b/assist/utils/logger.js @@ -0,0 +1,23 @@ +const winston = require('winston'); + +const isDebugMode = process.env.debug === "1"; +const logLevel = isDebugMode ? 'debug' : 'info'; + +const logger = winston.createLogger({ + level: logLevel, + format: winston.format.combine( + winston.format.timestamp({ + format: 'YYYY-MM-DD HH:mm:ss.SSS' // The same format as in backend services + }), + winston.format.errors({ stack: true }), + winston.format.json() + ), + defaultMeta: { service: 'assist' }, + transports: [ + new winston.transports.Console(), + ], +}); + +module.exports = { + logger, +} diff --git a/assist/utils/socketHandlers.js b/assist/utils/socketHandlers.js index 169b7f955..1494293b5 100644 --- a/assist/utils/socketHandlers.js +++ b/assist/utils/socketHandlers.js @@ -23,9 +23,7 @@ const { IncreaseOnlineRooms, DecreaseOnlineRooms, } = require('../utils/metrics'); - -const debug_log = process.env.debug === "1"; -const error_log = process.env.ERROR === "1"; +const {logger} = require('./logger'); const findSessionSocketId = async (io, roomId, tabId) => { let pickFirstSession = tabId === undefined; @@ -69,11 +67,11 @@ function processNewSocket(socket) { socket.handshake.query.projectKey = connProjectKey; socket.handshake.query.sessId = connSessionId; socket.handshake.query.tabId = connTabId; - debug_log && console.log(`connProjectKey:${connProjectKey}, connSessionId:${connSessionId}, connTabId:${connTabId}, roomId:${socket.handshake.query.roomId}`); + logger.debug(`connProjectKey:${connProjectKey}, connSessionId:${connSessionId}, connTabId:${connTabId}, roomId:${socket.handshake.query.roomId}`); } async function onConnect(socket) { - debug_log && console.log(`WS started:${socket.id}, Query:${JSON.stringify(socket.handshake.query)}`); + logger.debug(`WS started:${socket.id}, Query:${JSON.stringify(socket.handshake.query)}`); processNewSocket(socket); IncreaseTotalWSConnections(socket.handshake.query.identity); IncreaseOnlineConnections(socket.handshake.query.identity); @@ -86,7 +84,7 @@ async function onConnect(socket) { if (tabsCount > 0) { for (let tab of tabIDs) { if (tab === socket.handshake.query.tabId) { - error_log && console.log(`session already connected, refusing new connexion, peerId: ${socket.handshake.query.peerId}`); + logger.debug(`session already connected, refusing new connexion, peerId: ${socket.handshake.query.peerId}`); io.to(socket.id).emit(EVENTS_DEFINITION.emit.SESSION_ALREADY_CONNECTED); return socket.disconnect(); } @@ -100,22 +98,17 @@ async function onConnect(socket) { } // Inform all connected agents about reconnected session if (agentsCount > 0) { - debug_log && console.log(`notifying new session about agent-existence`); + logger.debug(`notifying new session about agent-existence`); io.to(socket.id).emit(EVENTS_DEFINITION.emit.AGENTS_CONNECTED, agentIDs); socket.to(socket.handshake.query.roomId).emit(EVENTS_DEFINITION.emit.SESSION_RECONNECTED, socket.id); } } else if (tabsCount <= 0) { - debug_log && console.log(`notifying new agent about no SESSIONS with peerId:${socket.handshake.query.peerId}`); + logger.debug(`notifying new agent about no SESSIONS with peerId:${socket.handshake.query.peerId}`); io.to(socket.id).emit(EVENTS_DEFINITION.emit.NO_SESSIONS); } await socket.join(socket.handshake.query.roomId); - if (debug_log) { - let connectedSockets = await io.in(socket.handshake.query.roomId).fetchSockets(); - if (connectedSockets.length > 0) { - console.log(`${socket.id} joined room:${socket.handshake.query.roomId}, as:${socket.handshake.query.identity}, members:${connectedSockets.length}`); - } - } + logger.debug(`${socket.id} joined room:${socket.handshake.query.roomId}, as:${socket.handshake.query.identity}, connections:${agentsCount + tabsCount + 1}`) if (socket.handshake.query.identity === IDENTITIES.agent) { if (socket.handshake.query.agentInfo !== undefined) { @@ -144,36 +137,36 @@ async function onConnect(socket) { async function onDisconnect(socket) { DecreaseOnlineConnections(socket.handshake.query.identity); - debug_log && console.log(`${socket.id} disconnected from ${socket.handshake.query.roomId}`); + logger.debug(`${socket.id} disconnected from ${socket.handshake.query.roomId}`); if (socket.handshake.query.identity === IDENTITIES.agent) { socket.to(socket.handshake.query.roomId).emit(EVENTS_DEFINITION.emit.AGENT_DISCONNECT, socket.id); // Stats endAssist(socket, socket.handshake.query.agentID); } - debug_log && console.log("checking for number of connected agents and sessions"); + logger.debug("checking for number of connected agents and sessions"); const io = getServer(); let {tabsCount, agentsCount, tabIDs, agentIDs} = await getRoomData(io, socket.handshake.query.roomId); if (tabsCount === -1 && agentsCount === -1) { DecreaseOnlineRooms(); - debug_log && console.log(`room not found: ${socket.handshake.query.roomId}`); + logger.debug(`room not found: ${socket.handshake.query.roomId}`); return; } if (tabsCount === 0) { - debug_log && console.log(`notifying everyone in ${socket.handshake.query.roomId} about no SESSIONS`); + logger.debug(`notifying everyone in ${socket.handshake.query.roomId} about no SESSIONS`); socket.to(socket.handshake.query.roomId).emit(EVENTS_DEFINITION.emit.NO_SESSIONS); } if (agentsCount === 0) { - debug_log && console.log(`notifying everyone in ${socket.handshake.query.roomId} about no AGENTS`); + logger.debug(`notifying everyone in ${socket.handshake.query.roomId} about no AGENTS`); socket.to(socket.handshake.query.roomId).emit(EVENTS_DEFINITION.emit.NO_AGENTS); } } async function onUpdateEvent(socket, ...args) { - debug_log && console.log(`${socket.id} sent update event.`); + logger.debug(`${socket.id} sent update event.`); if (socket.handshake.query.identity !== IDENTITIES.session) { - debug_log && console.log('Ignoring update event.'); + logger.debug('Ignoring update event.'); return } @@ -194,24 +187,24 @@ async function onUpdateEvent(socket, ...args) { async function onAny(socket, eventName, ...args) { if (Object.values(EVENTS_DEFINITION.listen).indexOf(eventName) >= 0) { - debug_log && console.log(`received event:${eventName}, should be handled by another listener, stopping onAny.`); + logger.debug(`received event:${eventName}, should be handled by another listener, stopping onAny.`); return } args[0] = updateSessionData(socket, args[0]) if (socket.handshake.query.identity === IDENTITIES.session) { - debug_log && console.log(`received event:${eventName}, from:${socket.handshake.query.identity}, sending message to room:${socket.handshake.query.roomId}`); + logger.debug(`received event:${eventName}, from:${socket.handshake.query.identity}, sending message to room:${socket.handshake.query.roomId}`); socket.to(socket.handshake.query.roomId).emit(eventName, args[0]); } else { // Stats handleEvent(eventName, socket, args[0]); - debug_log && console.log(`received event:${eventName}, from:${socket.handshake.query.identity}, sending message to session of room:${socket.handshake.query.roomId}`); + logger.debug(`received event:${eventName}, from:${socket.handshake.query.identity}, sending message to session of room:${socket.handshake.query.roomId}`); const io = getServer(); let socketId = await findSessionSocketId(io, socket.handshake.query.roomId, args[0]?.meta?.tabId); if (socketId === null) { - debug_log && console.log(`session not found for:${socket.handshake.query.roomId}`); + logger.debug(`session not found for:${socket.handshake.query.roomId}`); io.to(socket.id).emit(EVENTS_DEFINITION.emit.NO_SESSIONS); } else { - debug_log && console.log("message sent"); + logger.debug("message sent"); io.to(socketId).emit(eventName, socket.id, args[0]); } } diff --git a/ee/assist/server.js b/ee/assist/server.js index fed10e38c..a9883692a 100644 --- a/ee/assist/server.js +++ b/ee/assist/server.js @@ -4,6 +4,13 @@ const express = require('express'); const health = require("./utils/health"); const assert = require('assert').strict; const register = require('./utils/metrics').register; +let socket; +if (process.env.redis === "true") { + socket = require("./servers/websocket-cluster"); +} else { + socket = require("./servers/websocket"); +} +const {logger} = require('./logger'); health.healthApp.get('/metrics', async (req, res) => { try { @@ -14,20 +21,12 @@ health.healthApp.get('/metrics', async (req, res) => { } }); -let socket; -if (process.env.redis === "true") { - socket = require("./servers/websocket-cluster"); -} else { - socket = require("./servers/websocket"); -} - const HOST = process.env.LISTEN_HOST || '0.0.0.0'; const PORT = process.env.LISTEN_PORT || 9001; assert.ok(process.env.ASSIST_KEY, 'The "ASSIST_KEY" environment variable is required'); const P_KEY = process.env.ASSIST_KEY; const PREFIX = process.env.PREFIX || process.env.prefix || `/assist`; -let debug = process.env.debug === "1"; const heapdump = process.env.heapdump === "1"; if (process.env.uws !== "true") { @@ -45,14 +44,14 @@ if (process.env.uws !== "true") { wsapp.enable('trust proxy'); const wsserver = wsapp.listen(PORT, HOST, () => { - console.log(`WS App listening on http://${HOST}:${PORT}`); + logger.info(`WS App listening on http://${HOST}:${PORT}`); health.healthApp.listen(health.PORT, HOST, health.listen_cb); }); socket.start(wsserver); module.exports = {wsserver}; } else { - console.log("Using uWebSocket"); + logger.info("Using uWebSocket"); const {App} = require("uWebSockets.js"); @@ -72,9 +71,9 @@ if (process.env.uws !== "true") { const onAbortedOrFinishedResponse = function (res) { if (res.id === -1) { - debug && console.log("ERROR! onAbortedOrFinishedResponse called twice for the same res!"); + logger.debug("ERROR! onAbortedOrFinishedResponse called twice for the same res!"); } else { - debug && console.log('Stream was closed'); + logger.debug('Stream was closed'); } /* Mark this response already accounted for */ @@ -104,17 +103,15 @@ if (process.env.uws !== "true") { uapp.listen(HOST, PORT, (token) => { if (!token) { - console.warn("port already in use"); + logger.error("port already in use"); } - console.log(`WS App listening on http://${HOST}:${PORT}`); + logger.info(`WS App listening on http://${HOST}:${PORT}`); health.healthApp.listen(health.PORT, HOST, health.listen_cb); }); process.on('uncaughtException', err => { - console.log(`Uncaught Exception: ${err.message}`); - debug && console.log(err.stack); - // process.exit(1); + logger.error(`Uncaught Exception: ${err}`); }); module.exports = {uapp}; } \ No newline at end of file diff --git a/ee/assist/servers/websocket-cluster.js b/ee/assist/servers/websocket-cluster.js index 42bd61bdc..4a42b54a0 100644 --- a/ee/assist/servers/websocket-cluster.js +++ b/ee/assist/servers/websocket-cluster.js @@ -15,15 +15,14 @@ const { socketsLiveBySession, autocomplete } = require('../utils/httpHandlers'); +const {logger} = require('./logger'); const {createAdapter} = require("@socket.io/redis-adapter"); const {createClient} = require("redis"); const REDIS_URL = (process.env.REDIS_URL || "localhost:6379").replace(/((^\w+:|^)\/\/|^)/, 'redis://'); const pubClient = createClient({url: REDIS_URL}); const subClient = pubClient.duplicate(); -console.log(`Using Redis: ${REDIS_URL}`); - -const debug_log = process.env.debug === "1"; +logger.info(`Using Redis: ${REDIS_URL}`); const wsRouter = express.Router(); wsRouter.get(`/sockets-list/:projectKey/autocomplete`, autocomplete); // autocomplete @@ -41,7 +40,7 @@ module.exports = { io.use(async (socket, next) => await authorizer.check(socket, next)); io.on('connection', (socket) => onConnect(socket)); - console.log("WS server started"); + logger.info("WS server started"); socketConnexionTimeout(io); @@ -49,11 +48,10 @@ module.exports = { .then(() => { io.adapter(createAdapter(pubClient, subClient, {requestsTimeout: process.env.REDIS_REQUESTS_TIMEOUT || 5000})); - console.log("> redis connected."); + logger.info("> redis connected."); }) .catch((err) => { - console.log("> redis connection error"); - debug_log && console.error(err); + logger.error(`redis connection error: ${err}`); process.exit(2); }); }, diff --git a/ee/assist/servers/websocket.js b/ee/assist/servers/websocket.js index 0bc40c035..a1ed4624c 100644 --- a/ee/assist/servers/websocket.js +++ b/ee/assist/servers/websocket.js @@ -15,6 +15,7 @@ const { socketsLiveBySession, autocomplete } = require('../utils/httpHandlers'); +const {logger} = require('./logger'); const wsRouter = express.Router(); wsRouter.get(`/sockets-list/:projectKey/autocomplete`, autocomplete); // autocomplete @@ -32,7 +33,7 @@ module.exports = { io.use(async (socket, next) => await authorizer.check(socket, next)); io.on('connection', (socket) => onConnect(socket)); - console.log("WS server started"); + logger.info("WS server started"); socketConnexionTimeout(io); }, handlers: { diff --git a/ee/assist/utils/helper-ee.js b/ee/assist/utils/helper-ee.js index 7c735a7ce..2700d5f32 100644 --- a/ee/assist/utils/helper-ee.js +++ b/ee/assist/utils/helper-ee.js @@ -1,6 +1,7 @@ const uWS = require("uWebSockets.js"); const helper = require('./helper'); -let debug = process.env.debug === "1"; +const {logger} = require('./logger'); + const getBodyFromUWSResponse = async function (res) { return new Promise(((resolve, reject) => { let buffer; diff --git a/ee/assist/utils/stats.js b/ee/assist/utils/stats.js index befa0a7de..39dae5e84 100644 --- a/ee/assist/utils/stats.js +++ b/ee/assist/utils/stats.js @@ -1,6 +1,6 @@ const statsHost = process.env.STATS_HOST || 'http://assist-stats-openreplay.app.svc.cluster.local:8000/events'; const authToken = process.env.STATS_AUTH_TOKEN || ''; -const debug = process.env.debug === "1"; +const {logger} = require('./logger'); class InMemoryCache { constructor() { @@ -42,9 +42,9 @@ async function postData(payload) { try { const response = await fetch(statsHost, options) const jsonResponse = await response.json(); - debug && console.log('JSON response', JSON.stringify(jsonResponse, null, 4)) + logger.debug('JSON response', JSON.stringify(jsonResponse, null, 4)) } catch(err) { - debug && console.log('ERROR', err); + logger.debug('ERROR', err); } } @@ -63,13 +63,13 @@ function startAssist(socket, agentID) { // Save uniq eventID to cache cache.set(`${socket.handshake.query.sessId}_${agentID}_assist`, eventID); // Debug log - debug && console.log(`assist_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); + logger.debug(`assist_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); } function endAssist(socket, agentID) { const eventID = cache.get(`${socket.handshake.query.sessId}_${agentID}_assist`); if (eventID === undefined) { - debug && console.log(`have to skip assist_ended, no eventID in the cache, agentID: ${socket.handshake.query.agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}`); + logger.debug(`have to skip assist_ended, no eventID in the cache, agentID: ${socket.handshake.query.agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}`); return } void postData({ @@ -84,7 +84,7 @@ function endAssist(socket, agentID) { // Remove eventID from cache cache.delete(`${socket.handshake.query.sessId}_${agentID}_assist`); // Debug logs - debug && console.log(`assist_ended, agentID: ${socket.handshake.query.agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}`); + logger.debug(`assist_ended, agentID: ${socket.handshake.query.agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}`); } function startCall(socket, agentID) { @@ -102,14 +102,14 @@ function startCall(socket, agentID) { // Save uniq eventID to cache cache.set(`${socket.handshake.query.sessId}_call`, eventID); // Debug logs - debug && console.log(`s_call_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); + logger.debug(`s_call_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); } function endCall(socket, agentID) { const tsNow = +new Date(); const eventID = cache.get(`${socket.handshake.query.sessId}_call`); if (eventID === undefined) { - debug && console.log(`have to skip s_call_ended, no eventID in the cache, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); + logger.debug(`have to skip s_call_ended, no eventID in the cache, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); return } void postData({ @@ -123,7 +123,7 @@ function endCall(socket, agentID) { }); cache.delete(`${socket.handshake.query.sessId}_call`) // Debug logs - debug && console.log(`s_call_ended, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); + logger.debug(`s_call_ended, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); } function startControl(socket, agentID) { @@ -140,14 +140,14 @@ function startControl(socket, agentID) { }); cache.set(`${socket.handshake.query.sessId}_control`, eventID) // Debug logs - debug && console.log(`s_control_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); + logger.debug(`s_control_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); } function endControl(socket, agentID) { const tsNow = +new Date(); const eventID = cache.get(`${socket.handshake.query.sessId}_control`); if (eventID === undefined) { - debug && console.log(`have to skip s_control_ended, no eventID in the cache, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); + logger.debug(`have to skip s_control_ended, no eventID in the cache, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${tsNow}`); return } void postData({ @@ -161,7 +161,7 @@ function endControl(socket, agentID) { }); cache.delete(`${socket.handshake.query.sessId}_control`) // Debug logs - debug && console.log(`s_control_ended, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); + logger.debug(`s_control_ended, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); } function startRecord(socket, agentID) { @@ -178,7 +178,7 @@ function startRecord(socket, agentID) { }); cache.set(`${socket.handshake.query.sessId}_record`, eventID) // Debug logs - debug && console.log(`s_recording_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); + logger.debug(`s_recording_started, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); } function endRecord(socket, agentID) { @@ -195,7 +195,7 @@ function endRecord(socket, agentID) { }); cache.delete(`${socket.handshake.query.sessId}_record`) // Debug logs - debug && console.log(`s_recording_ended, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); + logger.debug(`s_recording_ended, agentID: ${agentID}, sessID: ${socket.handshake.query.sessId}, projID: ${socket.handshake.query.projectId}, time: ${+new Date()}`); } function handleEvent(eventName, socket, agentID) { diff --git a/ee/assist/utils/wsServer.js b/ee/assist/utils/wsServer.js index 34afc098b..97fa6c268 100644 --- a/ee/assist/utils/wsServer.js +++ b/ee/assist/utils/wsServer.js @@ -1,5 +1,6 @@ const _io = require("socket.io"); const {getCompressionConfig} = require("./helper"); +const {logger} = require('./logger'); let io; @@ -14,7 +15,7 @@ if (useRedis) { const {createClient} = require("redis"); const REDIS_URL = (process.env.REDIS_URL || "localhost:6379").replace(/((^\w+:|^)\/\/|^)/, 'redis://'); redisClient = createClient({url: REDIS_URL}); - redisClient.on("error", (error) => console.error(`Redis error : ${error}`)); + redisClient.on("error", (error) => logger.error(`Redis error : ${error}`)); void redisClient.connect(); } @@ -39,7 +40,7 @@ const doFetchAllSockets = async function () { await redisClient.set('fetchSocketsResult', cachedString, {EX: 5}); return result; } catch (error) { - console.error('Error setting value with expiration:', error); + logger.error('Error setting value with expiration:', error); } } return await io.fetchSockets();