refactor logging to use winston logger across multiple services and events

This commit is contained in:
StarAppeal
2025-09-27 00:28:02 +02:00
parent a2c5403d39
commit 67ca195c15
25 changed files with 384 additions and 67 deletions
+218
View File
@@ -32,6 +32,7 @@
"rimraf": "^5.0.5",
"typescript": "^5.3.3",
"typescript-eslint": "^8.44.1",
"winston": "^3.17.0",
"ws": "8.17.1"
},
"devDependencies": {
@@ -1258,6 +1259,15 @@
"node": ">=18"
}
},
"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==",
"license": "MIT",
"engines": {
"node": ">=0.1.90"
}
},
"node_modules/@cspotcode/source-map-support": {
"version": "0.8.1",
"dev": true,
@@ -1278,6 +1288,17 @@
"@jridgewell/sourcemap-codec": "^1.4.10"
}
},
"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==",
"license": "MIT",
"dependencies": {
"colorspace": "1.1.x",
"enabled": "2.0.x",
"kuler": "^2.0.0"
}
},
"node_modules/@esbuild/win32-x64": {
"version": "0.25.10",
"cpu": [
@@ -3243,6 +3264,12 @@
"@types/superagent": "^8.1.0"
}
},
"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==",
"license": "MIT"
},
"node_modules/@types/uuid": {
"version": "9.0.8",
"resolved": "https://registry.npmjs.org/@types/uuid/-/uuid-9.0.8.tgz",
@@ -4064,6 +4091,16 @@
"node": ">=8.10.0"
}
},
"node_modules/color": {
"version": "3.2.1",
"resolved": "https://registry.npmjs.org/color/-/color-3.2.1.tgz",
"integrity": "sha512-aBl7dZI9ENN6fUGC7mWpMTPNHmWUSNan9tuWN6ahh5ZLNk9baLJOnSMlrQkHcrfFgz2/RigjUVAjdx36VcemKA==",
"license": "MIT",
"dependencies": {
"color-convert": "^1.9.3",
"color-string": "^1.6.0"
}
},
"node_modules/color-convert": {
"version": "2.0.1",
"license": "MIT",
@@ -4078,6 +4115,16 @@
"version": "1.1.4",
"license": "MIT"
},
"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==",
"license": "MIT",
"dependencies": {
"color-name": "^1.0.0",
"simple-swizzle": "^0.2.2"
}
},
"node_modules/color-support": {
"version": "1.1.3",
"license": "ISC",
@@ -4085,6 +4132,31 @@
"color-support": "bin.js"
}
},
"node_modules/color/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==",
"license": "MIT",
"dependencies": {
"color-name": "1.1.3"
}
},
"node_modules/color/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==",
"license": "MIT"
},
"node_modules/colorspace": {
"version": "1.1.4",
"resolved": "https://registry.npmjs.org/colorspace/-/colorspace-1.1.4.tgz",
"integrity": "sha512-BgvKJiuVu1igBUF2kEjRCZXol6wiiGbY5ipL/oVPwm0BL9sIpMIzM8IK7vwuxIIzOXMV3Ey5w+vxhm0rR/TN8w==",
"license": "MIT",
"dependencies": {
"color": "^3.1.3",
"text-hex": "1.0.x"
}
},
"node_modules/combined-stream": {
"version": "1.0.8",
"license": "MIT",
@@ -4370,6 +4442,12 @@
"version": "8.0.0",
"license": "MIT"
},
"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==",
"license": "MIT"
},
"node_modules/encodeurl": {
"version": "2.0.0",
"license": "MIT",
@@ -4926,6 +5004,12 @@
"version": "1.0.11",
"license": "MIT"
},
"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==",
"license": "MIT"
},
"node_modules/file-entry-cache": {
"version": "8.0.0",
"resolved": "https://registry.npmjs.org/file-entry-cache/-/file-entry-cache-8.0.0.tgz",
@@ -4998,6 +5082,12 @@
"integrity": "sha512-GX+ysw4PBCz0PzosHDepZGANEuFCMLrnRTiEy9McGjmkCQYwRq4A/X786G/fjM/+OjsWSU1ZrY5qyARZmO/uwg==",
"license": "ISC"
},
"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==",
"license": "MIT"
},
"node_modules/follow-redirects": {
"version": "1.15.11",
"funding": [
@@ -5437,6 +5527,12 @@
"node": ">= 0.10"
}
},
"node_modules/is-arrayish": {
"version": "0.3.4",
"resolved": "https://registry.npmjs.org/is-arrayish/-/is-arrayish-0.3.4.tgz",
"integrity": "sha512-m6UrgzFVUYawGBh1dUsWR5M2Clqic9RVXC/9f8ceNlv2IcO9j9J/z8UoCLPqtsPBFNzEpfR3xftohbfqDx8EQA==",
"license": "MIT"
},
"node_modules/is-binary-path": {
"version": "2.1.0",
"license": "MIT",
@@ -5495,6 +5591,18 @@
"version": "4.0.0",
"license": "MIT"
},
"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==",
"license": "MIT",
"engines": {
"node": ">=8"
},
"funding": {
"url": "https://github.com/sponsors/sindresorhus"
}
},
"node_modules/isexe": {
"version": "2.0.0",
"license": "ISC"
@@ -5673,6 +5781,12 @@
"json-buffer": "3.0.1"
}
},
"node_modules/kuler": {
"version": "2.0.0",
"resolved": "https://registry.npmjs.org/kuler/-/kuler-2.0.0.tgz",
"integrity": "sha512-Xq9nH7KlWZmXAtodXDDRE7vs6DU1gTU8zYDHDiWLSip45Egwq3plLHzPn27NgvzL2r1LMPC1vdqh98sQxtqj4A==",
"license": "MIT"
},
"node_modules/levn": {
"version": "0.4.1",
"resolved": "https://registry.npmjs.org/levn/-/levn-0.4.1.tgz",
@@ -5739,6 +5853,23 @@
"version": "4.1.1",
"license": "MIT"
},
"node_modules/logform": {
"version": "2.7.0",
"resolved": "https://registry.npmjs.org/logform/-/logform-2.7.0.tgz",
"integrity": "sha512-TFYA4jnP7PVbmlBIfhlSe+WKxs9dklXMTEGcBCIvLhE/Tn3H6Gk1norupVW7m5Cnd4bLcr08AytbyV/xj7f/kQ==",
"license": "MIT",
"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/loupe": {
"version": "3.2.1",
"dev": true,
@@ -6283,6 +6414,15 @@
"wrappy": "1"
}
},
"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==",
"license": "MIT",
"dependencies": {
"fn.name": "1.x.x"
}
},
"node_modules/openweather-api-node": {
"version": "3.1.5",
"license": "MIT"
@@ -6999,6 +7139,15 @@
],
"license": "MIT"
},
"node_modules/safe-stable-stringify": {
"version": "2.5.0",
"resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz",
"integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==",
"license": "MIT",
"engines": {
"node": ">=10"
}
},
"node_modules/safer-buffer": {
"version": "2.1.2",
"license": "MIT"
@@ -7156,6 +7305,15 @@
"version": "3.0.7",
"license": "ISC"
},
"node_modules/simple-swizzle": {
"version": "0.2.4",
"resolved": "https://registry.npmjs.org/simple-swizzle/-/simple-swizzle-0.2.4.tgz",
"integrity": "sha512-nAu1WFPQSMNr2Zn9PGSZK9AGn4t/y97lEm+MXTtUDwfP0ksAIX4nO+6ruD9Jwut4C49SB1Ws+fbXsm/yScWOHw==",
"license": "MIT",
"dependencies": {
"is-arrayish": "^0.3.1"
}
},
"node_modules/smart-buffer": {
"version": "4.2.0",
"license": "MIT",
@@ -7229,6 +7387,15 @@
"version": "1.1.2",
"license": "BSD-3-Clause"
},
"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==",
"license": "MIT",
"engines": {
"node": "*"
}
},
"node_modules/stackback": {
"version": "0.0.2",
"dev": true,
@@ -7457,6 +7624,12 @@
"node": ">=18"
}
},
"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==",
"license": "MIT"
},
"node_modules/tinybench": {
"version": "2.9.0",
"dev": true,
@@ -7568,6 +7741,15 @@
"tree-kill": "cli.js"
}
},
"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==",
"license": "MIT",
"engines": {
"node": ">= 14.0.0"
}
},
"node_modules/ts-api-utils": {
"version": "2.1.0",
"resolved": "https://registry.npmjs.org/ts-api-utils/-/ts-api-utils-2.1.0.tgz",
@@ -8170,6 +8352,42 @@
"string-width": "^1.0.2 || 2 || 3 || 4"
}
},
"node_modules/winston": {
"version": "3.17.0",
"resolved": "https://registry.npmjs.org/winston/-/winston-3.17.0.tgz",
"integrity": "sha512-DLiFIXYC5fMPxaRg832S6F5mJYvePtmO5G9v9IgUFPhXm9/GkXarH/TUrBAVzhTCzAj9anE/+GjrgXp/54nOgw==",
"license": "MIT",
"dependencies": {
"@colors/colors": "^1.6.0",
"@dabh/diagnostics": "^2.0.2",
"async": "^3.2.3",
"is-stream": "^2.0.0",
"logform": "^2.7.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.9.0"
},
"engines": {
"node": ">= 12.0.0"
}
},
"node_modules/winston-transport": {
"version": "4.9.0",
"resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.9.0.tgz",
"integrity": "sha512-8drMJ4rkgaPo1Me4zD/3WLfI/zPdA9o2IipKODunnGDcuqbHwjsbB79ylv04LCGGzU0xQ6vTznOMpQGaLhhm6A==",
"license": "MIT",
"dependencies": {
"logform": "^2.7.0",
"readable-stream": "^3.6.2",
"triple-beam": "^1.3.0"
},
"engines": {
"node": ">= 12.0.0"
}
},
"node_modules/word-wrap": {
"version": "1.2.5",
"resolved": "https://registry.npmjs.org/word-wrap/-/word-wrap-1.2.5.tgz",
+1
View File
@@ -47,6 +47,7 @@
"rimraf": "^5.0.5",
"typescript": "^5.3.3",
"typescript-eslint": "^8.44.1",
"winston": "^3.17.0",
"ws": "8.17.1"
},
"devDependencies": {
+2 -1
View File
@@ -1,5 +1,6 @@
import { UserModel } from "./user";
import { appEventBus, USER_UPDATED_EVENT } from "../../utils/eventBus";
import logger from "../../utils/logger";
export function watchUserChanges() {
const changeStream = UserModel.watch([], { fullDocument: "updateLookup" });
@@ -12,5 +13,5 @@ export function watchUserChanges() {
}
});
console.log("Watching for changes in the User collection...");
logger.info("User collection change stream initialized - watching for database updates");
}
+2 -1
View File
@@ -9,6 +9,7 @@ import { SpotifyPollingService } from "./services/spotifyPollingService";
import { WeatherPollingService } from "./services/weatherPollingService";
import { JwtAuthenticator } from "./utils/jwtAuthenticator";
import { FileService } from "./services/db/fileService";
import logger from "./utils/logger";
async function bootstrap() {
const {
@@ -103,7 +104,7 @@ async function bootstrap() {
if (process.env.NODE_ENV !== "test") {
bootstrap().catch((error) => {
console.error("Fatal error during server startup:", error.message);
logger.error("Fatal error during server startup:", error.message);
process.exit(1);
});
}
+2 -2
View File
@@ -1,6 +1,7 @@
import { Request, Response, NextFunction } from "express";
import { unauthorized } from "../utils/responses";
import { JwtAuthenticator } from "../../utils/jwtAuthenticator";
import logger from "../../utils/logger";
const BEARER_PREFIX = "Bearer ";
@@ -24,7 +25,6 @@ export function authenticateJwt(jwtAuthenticator: JwtAuthenticator) {
try {
const decodedToken = jwtAuthenticator.verifyToken(token);
console.log(decodedToken);
if (!decodedToken) {
return unauthorized(res, "Unauthorized: Invalid token");
@@ -33,7 +33,7 @@ export function authenticateJwt(jwtAuthenticator: JwtAuthenticator) {
req.payload = decodedToken;
next();
} catch (error: any) {
console.error("JWT Verification Error:", error.message);
logger.error("JWT Verification Error:", error.message);
return unauthorized(res, "Unauthorized: Token verification failed");
}
};
+7 -6
View File
@@ -22,6 +22,7 @@ import { SpotifyTokenService } from "./services/spotifyTokenService";
import { WeatherPollingService } from "./services/weatherPollingService";
import { S3Service } from "./services/s3Service";
import { RestStorage } from "./rest/restStorage";
import logger from "./utils/logger";
interface ServerDependencies {
userService: UserService;
@@ -72,7 +73,7 @@ export class Server {
this._setupErrorHandling();
this.httpServer = this.app.listen(this.config.port, () => {
console.log(`Server is running on port ${this.config.port}`);
logger.info(`Server started and listening on port ${this.config.port}`);
});
this.webSocketServer = new ExtendedWebSocketServer(
@@ -89,11 +90,11 @@ export class Server {
}
public async stop(): Promise<void> {
console.log("Stopping server gracefully...");
logger.info("Shutting down server gracefully...");
await disconnectFromDatabase();
if (this.httpServer) {
this.httpServer.close(() => {
console.log("HTTP server closed.");
logger.info("HTTP server closed successfully");
});
}
}
@@ -161,9 +162,9 @@ export class Server {
const errorId = randomUUID();
const statusCode = err?.status || 500;
console.error(`Error ID: ${errorId} | Status: ${statusCode} | Message: ${err?.message}`);
logger.error(`Error ID: ${errorId} | Status: ${statusCode} | Message: ${err?.message}`);
if (err.stack) {
console.error(`Stack Trace [${errorId}]:`, err.stack);
logger.error(`Stack Trace [${errorId}]:`, err.stack);
}
let errorMessage = err?.message || "Internal Server Error";
@@ -183,7 +184,7 @@ export class Server {
private _setupGracefulShutdown(): void {
process.on("SIGTERM", async () => {
console.log("SIGTERM signal received. Closing server gracefully.");
logger.info("SIGTERM signal received. Closing server gracefully.");
await this.stop();
process.exit(0);
});
+3 -2
View File
@@ -1,4 +1,5 @@
import { FileModel, File } from "../../db/models/file";
import logger from "../../utils/logger";
export class FileService {
private static instance: FileService;
@@ -48,12 +49,12 @@ export class FileService {
try {
const count = await FileModel.countDocuments({
userId,
originalName: originalName,
originalName,
});
return count > 0;
} catch (error) {
console.error(`Error in isFileDuplicate: ${error}`);
logger.error(`Error checking file duplicate: ${error}`);
return false;
}
}
+4 -3
View File
@@ -8,6 +8,7 @@ import {
import { getSignedUrl } from "@aws-sdk/s3-request-presigner";
import { FileService } from "./db/fileService";
import { randomUUID } from "crypto";
import logger from "../utils/logger";
export interface S3ClientConfig {
endpoint: string;
@@ -56,10 +57,10 @@ export class S3Service {
async ensureBucketExists(): Promise<void> {
try {
await this.client.send(new CreateBucketCommand({ Bucket: this.bucketName }));
console.log(`Bucket "${this.bucketName}" created successfully or already existed.`);
logger.info(`Bucket "${this.bucketName}" created successfully or already existed.`);
} catch (err: any) {
if (err.name === "BucketAlreadyOwnedByYou" || err.name === "BucketAlreadyExists") {
console.log(`Bucket "${this.bucketName}" already exists.`);
logger.info(`Bucket "${this.bucketName}" already exists.`);
} else {
throw err;
}
@@ -112,7 +113,7 @@ export class S3Service {
await this.fileService.deleteFileRecord(objectKey);
console.log(`File deleted: ${objectKey}`);
logger.info(`File deleted: ${objectKey}`);
}
async getSignedDownloadUrl(objectKey: string, expiresIn: number = 60): Promise<string> {
+10 -9
View File
@@ -4,6 +4,7 @@ import { IUser } from "../db/models/user";
import { AxiosError } from "axios";
import { UserService } from "./db/UserService";
import { SpotifyTokenService } from "./spotifyTokenService";
import logger from "../utils/logger";
const userStateCache = new Map<string, any>();
const activePolls = new Map<string, NodeJS.Timeout>();
@@ -19,7 +20,7 @@ export class SpotifyPollingService {
const uuid = user.uuid;
if (activePolls.has(uuid)) return;
console.log(`[SpotifyPolling] Starting polling for user ${uuid}`);
logger.info(`Starting Spotify polling service for user ${uuid}`);
const intervalId = setInterval(() => this._pollUser(uuid), 3000);
activePolls.set(uuid, intervalId);
@@ -28,7 +29,7 @@ export class SpotifyPollingService {
public stopPollingForUser(uuid: string): void {
if (activePolls.has(uuid)) {
console.log(`[SpotifyPolling] Stopping polling for user ${uuid}`);
logger.info(`Stopping Spotify polling service for user ${uuid}`);
clearInterval(activePolls.get(uuid)!);
activePolls.delete(uuid);
userStateCache.delete(uuid);
@@ -44,7 +45,7 @@ export class SpotifyPollingService {
try {
if (Date.now() > user.spotifyConfig.expirationDate.getTime()) {
console.log(`[SpotifyPolling] Token for ${uuid} expired, refreshing...`);
logger.debug(`Spotify token expired for user ${uuid}, refreshing token`);
const token = await this.spotifyTokenService.refreshToken(user.spotifyConfig.refreshToken);
const newConfig = {
refreshToken: user.spotifyConfig.refreshToken,
@@ -54,14 +55,14 @@ export class SpotifyPollingService {
};
user = await this.userService.updateUserByUUID(uuid, { spotifyConfig: newConfig });
console.log(`[SpotifyPolling] Token for ${uuid} refreshed.`);
logger.debug(`Successfully refreshed Spotify token for user ${uuid}`);
}
const currentState = await this.spotifyApiService.getCurrentlyPlaying(user!.spotifyConfig!.accessToken);
const lastState = userStateCache.get(uuid);
if (this._hasStateChanged(lastState, currentState)) {
console.log(`[SpotifyPolling] State change for ${uuid}. Emitting event.`);
logger.debug(`Spotify state changed for user ${uuid} - emitting update event`);
userStateCache.set(uuid, currentState);
appEventBus.emit(SPOTIFY_STATE_UPDATED_EVENT, { uuid, state: currentState });
}
@@ -69,14 +70,14 @@ export class SpotifyPollingService {
if (error instanceof AxiosError && error.response) {
if (error.response.status === 429) {
const retryAfter = Number(error.response.headers["retry-after"] || 5);
console.warn(`[SpotifyPolling] Rate limit for ${uuid}. Pausing for ${retryAfter}s.`);
logger.warn(`Spotify API rate limit reached for user ${uuid}. Pausing for ${retryAfter} seconds`);
this._pausePolling(uuid, retryAfter * 1000);
} else if (error.response.status === 401) {
console.error(`[SpotifyPolling] Bad token for ${uuid}. Stopping poll.`);
logger.error(`Invalid Spotify token for user ${uuid}. Stopping polling service`);
this.stopPollingForUser(uuid);
}
} else {
console.error(`[SpotifyPolling] Unknown error for ${uuid}:`, error);
logger.error(`Unknown error in Spotify polling service for user ${uuid}:`, error);
}
}
}
@@ -93,7 +94,7 @@ export class SpotifyPollingService {
clearInterval(activePolls.get(uuid)!);
activePolls.delete(uuid);
setTimeout(() => {
console.log(`[SpotifyPolling] Resuming polling for ${uuid}.`);
logger.debug(`Resuming Spotify polling service for user ${uuid}`);
this.userService.getUserByUUID(uuid).then((user) => {
if (user) this.startPollingForUser(user);
});
+4 -3
View File
@@ -1,5 +1,6 @@
import axios from "axios";
import { OAuthTokenResponse } from "../interfaces/OAuthTokenResponse";
import logger from "../utils/logger";
const url = "https://accounts.spotify.com/api/token";
@@ -10,7 +11,7 @@ export class SpotifyTokenService {
) {}
public async refreshToken(refreshToken: string) {
console.log("refreshToken");
logger.debug("Refreshing Spotify token");
const response = await axios.post(url, `grant_type=refresh_token&refresh_token=${refreshToken}`, {
headers: {
"Content-Type": "application/x-www-form-urlencoded",
@@ -22,7 +23,7 @@ export class SpotifyTokenService {
}
public async generateToken(authorizationCode: string, redirectUri: string) {
console.log("generateToken");
logger.debug("Generating new Spotify token");
const response = await axios.post(
url,
`grant_type=authorization_code&code=${authorizationCode}&redirect_uri=${redirectUri}`,
@@ -34,7 +35,7 @@ export class SpotifyTokenService {
}
);
console.log(response.data);
logger.debug("Received Spotify token response", { data: response.data });
return response.data as OAuthTokenResponse;
}
+8 -7
View File
@@ -1,6 +1,7 @@
import { appEventBus, USER_UPDATED_EVENT, WEATHER_STATE_UPDATED_EVENT } from "../utils/eventBus";
import { getCurrentWeather } from "./owmApiService";
import { IUser } from "../db/models/user";
import logger from "../utils/logger";
export class WeatherPollingService {
private readonly activeLocationPolls: Map<string, NodeJS.Timeout>;
@@ -20,7 +21,7 @@ export class WeatherPollingService {
}
public subscribeUser(uuid: string, location: string): void {
console.log(`[WeatherPolling] User ${uuid} subscribed to location "${location}"`);
logger.info(`User ${uuid} subscribed to weather updates for location "${location}"`);
if (!this.locationSubscriptions.has(location)) {
this.locationSubscriptions.set(location, new Set());
@@ -39,7 +40,7 @@ export class WeatherPollingService {
}
public unsubscribeUser(uuid: string, location: string): void {
console.log(`[WeatherPolling] User ${uuid} unsubscribed from location "${location}"`);
logger.info(`User ${uuid} unsubscribed from weather updates for location "${location}"`);
const subscribers = this.locationSubscriptions.get(location);
if (subscribers) {
@@ -55,7 +56,7 @@ export class WeatherPollingService {
}
private _startPollingForLocation(location: string): void {
console.log(`[WeatherPolling] Starting new poll for location: "${location}"`);
logger.info(`Starting new weather polling service for location: "${location}"`);
const intervalId = setInterval(() => this._pollLocation(location), 1000 * 60 * 10);
this.activeLocationPolls.set(location, intervalId);
@@ -64,7 +65,7 @@ export class WeatherPollingService {
private _stopPollingForLocation(location: string): void {
if (this.activeLocationPolls.has(location)) {
console.log(`[WeatherPolling] Stopping poll for location: "${location}"`);
logger.info(`Stopping weather polling service for location: "${location}"`);
clearInterval(this.activeLocationPolls.get(location)!);
this.activeLocationPolls.delete(location);
}
@@ -72,7 +73,7 @@ export class WeatherPollingService {
private async _pollLocation(location: string): Promise<void> {
try {
console.log(`[WeatherPolling] Fetching weather for "${location}"...`);
logger.debug(`Fetching weather data for location "${location}"`);
const weatherData = await getCurrentWeather(location);
if (!weatherData) return;
@@ -83,7 +84,7 @@ export class WeatherPollingService {
appEventBus.emit(WEATHER_STATE_UPDATED_EVENT, { weatherData, subscribers: Array.from(subscribers) });
}
} catch (error) {
console.error(`[WeatherPolling] Error polling for location "${location}":`, error);
logger.error(`Error polling weather data for location "${location}":`, error);
}
}
@@ -93,7 +94,7 @@ export class WeatherPollingService {
const oldLocation = this.userLocationCache.get(uuid);
if (oldLocation && newLocation && oldLocation !== newLocation) {
console.log(`[WeatherPolling] Detected location change for user ${uuid} via User-Update.`);
logger.info(`Detected location change for user ${uuid} via User-Update.`);
this.unsubscribeUser(uuid, oldLocation);
this.subscribeUser(uuid, newLocation);
+67
View File
@@ -0,0 +1,67 @@
import winston from "winston";
import path from "path";
const logLevels = {
error: 0,
warn: 1,
info: 2,
http: 3,
debug: 4,
};
const logColors = {
error: "red",
warn: "yellow",
info: "green",
http: "magenta",
debug: "blue",
};
const logFormat = winston.format.combine(
winston.format.timestamp({ format: "YYYY-MM-DD HH:mm:ss" }),
winston.format.errors({ stack: true }),
winston.format.splat(),
winston.format.printf(({ level, message, timestamp, stack }) => {
return `${timestamp} [${level.toUpperCase()}]: ${message} ${stack || ""}`;
})
);
const colorizedFormat = winston.format.combine(
winston.format.colorize({ all: true }),
winston.format.timestamp({ format: "YYYY-MM-DD HH:mm:ss" }),
winston.format.printf(({ level, message, timestamp, stack }) => {
return `${timestamp} [${level.toUpperCase()}]: ${message} ${stack || ""}`;
})
);
const logger = winston.createLogger({
levels: logLevels,
level: process.env.NODE_ENV === "production" ? "info" : "debug",
format: logFormat,
transports: [
new winston.transports.File({
filename: path.join("logs", "combined.log"),
maxsize: 5242880, // 5MB
maxFiles: 5,
}),
new winston.transports.File({
filename: path.join("logs", "error.log"),
level: "error",
maxsize: 5242880, // 5MB
maxFiles: 5,
}),
new winston.transports.Console({
format: colorizedFormat,
}),
],
exceptionHandlers: [new winston.transports.File({ filename: path.join("logs", "exceptions.log") })],
rejectionHandlers: [new winston.transports.File({ filename: path.join("logs", "rejections.log") })],
});
try {
require("fs").mkdirSync("logs");
} catch (e) {
// Directory already exists
}
export default logger;
+2 -1
View File
@@ -3,6 +3,7 @@ import "dotenv/config";
import { IncomingMessage } from "node:http";
import { ExtendedIncomingMessage } from "../interfaces/extendedIncomingMessage";
import { JwtAuthenticator } from "./jwtAuthenticator";
import logger from "./logger";
export function verifyClient(
request: IncomingMessage,
@@ -19,6 +20,6 @@ export function verifyClient(
}
const reject = (request: IncomingMessage, callback: (res: boolean, code?: number, message?: string) => void) => {
console.log("Connection refused", `${request.socket.remoteAddress}:${request.socket.remotePort}`);
logger.warn(`Connection refused from ${request.socket.remoteAddress}:${request.socket.remotePort}`);
callback(false, 401, "Unauthorized");
};
@@ -1,6 +1,7 @@
import { WebsocketEventType } from "./websocketEventType";
import { CustomWebsocketEvent } from "./customWebsocketEvent";
import { ExtendedWebSocket } from "../../../interfaces/extendedWebsocket";
import logger from "../../logger";
interface ErrorData {
message: string;
@@ -15,7 +16,7 @@ export class ErrorEvent extends CustomWebsocketEvent<ErrorData> {
}
handler = async (data: ErrorData) => {
console.warn("Error message received", data.message);
console.warn("Traceback", data.traceback);
logger.warn("Error message received", data.message);
logger.warn("Traceback", data.traceback);
};
}
@@ -1,12 +1,14 @@
import { CustomWebsocketEvent } from "./customWebsocketEvent";
import { WebsocketEventType } from "./websocketEventType";
import { NoData } from "./NoData";
import logger from "../../../utils/logger";
export class GetSettingsEvent extends CustomWebsocketEvent<NoData> {
export class GetSettingsEvent extends CustomWebsocketEvent {
event = WebsocketEventType.GET_SETTINGS;
handler = async () => {
console.log("Getting settings");
logger.debug(`User ${this.ws.payload?.username} requested settings`);
// Send settings back to client
this.ws.send(
JSON.stringify({
type: "SETTINGS",
@@ -3,6 +3,7 @@ import { WebsocketEventType } from "./websocketEventType";
import { NoData } from "./NoData";
import { ExtendedWebSocket } from "../../../interfaces/extendedWebsocket";
import { CustomWebsocketEvent } from "./customWebsocketEvent";
import logger from "../../../utils/logger";
export class GetSpotifyUpdatesEvent extends CustomWebsocketEvent<NoData> {
event = WebsocketEventType.GET_SPOTIFY_UPDATE;
@@ -15,7 +16,7 @@ export class GetSpotifyUpdatesEvent extends CustomWebsocketEvent<NoData> {
}
handler = async () => {
console.log("Client requests Spotify updates. Starting polling.");
logger.info(`User ${this.ws.payload?.username} requested Spotify updates - starting polling service`);
if (this.ws.user) {
this.spotifyPollingService.startPollingForUser(this.ws.user);
}
@@ -1,16 +1,22 @@
import { CustomWebsocketEvent } from "./customWebsocketEvent";
import { WebsocketEventType } from "./websocketEventType";
import { NoData } from "./NoData";
import logger from "../../../utils/logger";
export class GetStateEvent extends CustomWebsocketEvent<NoData> {
export class GetStateEvent extends CustomWebsocketEvent {
event = WebsocketEventType.GET_STATE;
handler = async () => {
console.log("Getting state");
const messageToSend = {
type: "STATE",
payload: this.ws.user.lastState,
};
this.ws.send(JSON.stringify(messageToSend), { binary: false });
logger.debug(`User ${this.ws.payload?.username} requested state information`);
// Send state back to client
this.ws.send(
JSON.stringify({
type: "STATE",
payload: {
state: this.ws.user.lastState,
},
}),
{ binary: false }
);
};
}
@@ -3,6 +3,7 @@ import { WebsocketEventType } from "./websocketEventType";
import { NoData } from "./NoData";
import { SpotifyPollingService } from "../../../services/spotifyPollingService";
import { ExtendedWebSocket } from "../../../interfaces/extendedWebsocket";
import logger from "../../../utils/logger";
export class StopSpotifyUpdatesEvent extends CustomWebsocketEvent<NoData> {
event = WebsocketEventType.STOP_SPOTIFY_UPDATES;
@@ -15,14 +16,14 @@ export class StopSpotifyUpdatesEvent extends CustomWebsocketEvent<NoData> {
}
handler = async () => {
console.log("Client requests to stop Spotify updates. Stopping polling.");
logger.info(`User ${this.ws.payload?.username} requested to stop Spotify updates`);
const uuid = this.ws.payload?.uuid;
if (uuid) {
this.spotifyPollingService.stopPollingForUser(uuid);
} else {
console.warn("Could not stop Spotify polling: No UUID found on WebSocket payload.");
logger.warn("Could not stop Spotify polling: No UUID found on WebSocket payload.");
}
};
}
@@ -3,6 +3,7 @@ import { WebsocketEventType } from "./websocketEventType";
import { NoData } from "./NoData";
import { ExtendedWebSocket } from "../../../interfaces/extendedWebsocket";
import { WeatherPollingService } from "../../../services/weatherPollingService";
import logger from "../../../utils/logger";
export class StopWeatherUpdatesEvent extends CustomWebsocketEvent<NoData> {
event = WebsocketEventType.STOP_WEATHER_UPDATES;
@@ -14,7 +15,7 @@ export class StopWeatherUpdatesEvent extends CustomWebsocketEvent<NoData> {
}
handler = async () => {
console.log(`User ${this.ws.user.uuid} requested stop weather updates`);
logger.info(`User ${this.ws.user.uuid} requested to stop weather updates`);
const user = this.ws.user;
if (user?.location && user.uuid) {
this.weatherPollingService.unsubscribeUser(user.uuid, user.location);
@@ -1,15 +1,16 @@
import { WebsocketEventType } from "./websocketEventType";
import { CustomWebsocketEvent } from "./customWebsocketEvent";
import { IUser } from "../../../db/models/user";
import logger from "../../../utils/logger";
export class UpdateUserSingleEvent extends CustomWebsocketEvent<IUser> {
event = WebsocketEventType.UPDATE_USER_SINGLE;
handler = async (data: IUser) => {
console.log("Updating user");
logger.debug(`Updating user ${data?.uuid || "unknown"}`);
if (data) {
this.ws.user = data;
console.log("User updated");
logger.debug(`User ${data.uuid} updated successfully`);
}
};
}
@@ -2,7 +2,6 @@ export enum WebsocketEventType {
GET_SETTINGS = "GET_SETTINGS",
GET_STATE = "GET_STATE",
GET_SPOTIFY_UPDATE = "GET_SPOTIFY_UPDATES",
GET_SINGLE_WEATHER_UPDATE = "GET_SINGLE_WEATHER_UPDATE",
GET_WEATHER_UPDATES = "GET_WEATHER_UPDATES",
STOP_SPOTIFY_UPDATES = "STOP_SPOTIFY_UPDATES",
STOP_WEATHER_UPDATES = "STOP_WEATHER_UPDATES",
+10 -5
View File
@@ -3,6 +3,7 @@ import { CustomWebsocketEvent } from "./websocketCustomEvents/customWebsocketEve
import { getEventListeners } from "./websocketCustomEvents/websocketEventUtils";
import { SpotifyPollingService } from "../../services/spotifyPollingService";
import { WeatherPollingService } from "../../services/weatherPollingService";
import logger from "../../utils/logger";
export class WebsocketEventHandler {
constructor(
@@ -12,21 +13,25 @@ export class WebsocketEventHandler {
) {}
public enableErrorEvent() {
this.webSocket.on("error", console.error);
this.webSocket.on("error", (error) => {
logger.error("WebSocket error:", error);
});
}
//needed for the heartbeat mechanism
public enablePongEvent() {
this.webSocket.on("pong", () => {
this.webSocket.isAlive = true;
console.log("Pong received");
logger.debug("Pong received from client");
});
}
public enableDisconnectEvent(callback: () => void) {
this.webSocket.onclose = (event) => {
console.log("WebSocket closed:", event.code, event.reason, event.wasClean, event.type);
console.log(`User: ${this.webSocket.payload.username} disconnected`);
logger.info(
`WebSocket closed: code=${event.code}, reason=${event.reason}, wasClean=${event.wasClean}, type=${event.type}`
);
logger.info(`User: ${this.webSocket.payload.username} disconnected`);
callback();
};
@@ -37,7 +42,7 @@ export class WebsocketEventHandler {
const message = data.toString();
const messageJson = JSON.parse(message);
const { type } = messageJson;
console.log("Received message:", message);
logger.debug(`Received WebSocket message of type "${type}"`, { messageData: messageJson });
// emit event to the custom event handler
this.webSocket.emit(type, messageJson);
@@ -3,6 +3,7 @@ import { ExtendedIncomingMessage } from "../../interfaces/extendedIncomingMessag
import { Server as WebSocketServer } from "ws";
import { heartbeat } from "./websocketServerHeartbeatInterval";
import { UserService } from "../../services/db/UserService";
import logger from "../../utils/logger";
export class WebsocketServerEventHandler {
private readonly heartbeat: () => void;
@@ -44,7 +45,7 @@ export class WebsocketServerEventHandler {
public enableCloseEvent(callback: () => void) {
this.webSocketServer.on("close", () => {
console.log("WebSocket server closed");
logger.info("WebSocket server closed");
callback();
});
}
@@ -1,10 +1,13 @@
import { WebSocket, WebSocketServer } from "ws";
import { DecodedToken } from "../../interfaces/decodedToken";
import logger from "../../utils/logger";
export function heartbeat(wss: WebSocketServer) {
return () => {
wss.clients.forEach((ws: WebSocket & { isAlive?: boolean; payload?: DecodedToken }) => {
console.log(new Date().toLocaleString("de-DE") + ":" + ws.payload?.username + ": isAlive: " + ws.isAlive);
logger.debug(
`Heartbeat check: ${new Date().toLocaleString("de-DE")} - User: ${ws.payload?.username} - isAlive: ${ws.isAlive}`
);
if (!ws.isAlive) return ws.terminate();
ws.isAlive = false;
+6 -5
View File
@@ -16,6 +16,7 @@ import { SpotifyPollingService } from "./services/spotifyPollingService";
import { UserService } from "./services/db/UserService";
import { WeatherPollingService } from "./services/weatherPollingService";
import { JwtAuthenticator } from "./utils/jwtAuthenticator";
import logger from "./utils/logger";
export class ExtendedWebSocketServer {
private readonly _wss: WebSocketServer;
@@ -76,7 +77,7 @@ export class ExtendedWebSocketServer {
}
private _onNewClientReady(ws: ExtendedWebSocket): void {
console.log("WebSocket client connected and authenticated");
logger.info("WebSocket client connected and authenticated");
const socketEventHandler = new WebsocketEventHandler(
ws,
@@ -89,7 +90,7 @@ export class ExtendedWebSocketServer {
socketEventHandler.enableMessageEvent();
socketEventHandler.registerCustomEvents();
socketEventHandler.enableDisconnectEvent(() => {
console.log("User disconnected");
logger.info("User disconnected");
});
// send initial state and settings
@@ -99,17 +100,17 @@ export class ExtendedWebSocketServer {
private _listenForAppEvents(): void {
appEventBus.on(USER_UPDATED_EVENT, (user: IUser) => {
console.log(`Received update for user ${user.uuid}`);
logger.debug(`Received update for user ${user.uuid}`);
const client = this._findClientByUUID(user.uuid);
if (client) {
console.log(`Pushing update to user ${user.uuid}`);
logger.debug(`Pushing update to user ${user.uuid}`);
client.emit(WebsocketEventType.UPDATE_USER_SINGLE, user);
}
});
appEventBus.on(SPOTIFY_STATE_UPDATED_EVENT, ({ uuid, state }) => {
const client = this._findClientByUUID(uuid);
console.log(`Received update for user ${uuid}`);
logger.debug(`Received update for user ${uuid}`);
if (client) {
client.send(
JSON.stringify({