Implement logger on pusher

This commit is contained in:
Alexis Faizeau 2021-11-08 19:05:25 +01:00
parent 6a195be814
commit dd89f12c2e
15 changed files with 263 additions and 72 deletions

View file

@ -7,6 +7,7 @@ import {
WorldFullWarningToRoomMessage,
RefreshRoomPromptMessage,
} from "../Messages/generated/messages_pb";
import log from "../Services/Logger";
export class AdminController extends BaseController {
constructor(private App: TemplatedApp) {
@ -25,14 +26,14 @@ export class AdminController extends BaseController {
// eslint-disable-next-line @typescript-eslint/no-misused-promises
this.App.post("/room/refresh", async (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/message request was aborted");
log.warn("/message request was aborted");
});
const token = req.getHeader("admin-token");
const body = await res.json();
if (token !== ADMIN_API_TOKEN) {
console.error("Admin access refused for token: " + token);
log.error("Admin access refused for token: " + token);
res.writeStatus("401 Unauthorized").end("Incorrect token");
return;
}
@ -72,14 +73,14 @@ export class AdminController extends BaseController {
// eslint-disable-next-line @typescript-eslint/no-misused-promises
this.App.post("/message", async (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/message request was aborted");
log.warn("/message request was aborted");
});
const token = req.getHeader("admin-token");
const body = await res.json();
if (token !== ADMIN_API_TOKEN) {
console.error("Admin access refused for token: " + token);
log.error("Admin access refused for token: " + token);
res.writeStatus("401 Unauthorized").end("Incorrect token");
return;
}

View file

@ -5,6 +5,7 @@ import { adminApi } from "../Services/AdminApi";
import { AuthTokenData, jwtTokenManager } from "../Services/JWTTokenManager";
import { parse } from "query-string";
import { openIDClient } from "../Services/OpenIDClient";
import log from "../Services/Logger";
export interface TokenInterface {
userUuid: string;
@ -24,7 +25,7 @@ export class AuthenticateController extends BaseController {
//eslint-disable-next-line @typescript-eslint/no-misused-promises
this.App.get("/login-screen", async (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/message request was aborted");
log.warn("/message request was aborted");
});
try {
@ -43,7 +44,7 @@ export class AuthenticateController extends BaseController {
res.writeHeader("Location", loginUri);
return res.end();
} catch (e) {
console.error("openIDLogin => e", e);
log.error("openIDLogin => e", e);
return this.errorToResponse(e, res);
}
});
@ -53,7 +54,7 @@ export class AuthenticateController extends BaseController {
//eslint-disable-next-line @typescript-eslint/no-misused-promises
this.App.get("/login-callback", async (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/message request was aborted");
log.warn("/message request was aborted");
});
const { code, nonce, token } = parse(req.getQuery());
try {
@ -69,7 +70,7 @@ export class AuthenticateController extends BaseController {
this.addCorsHeaders(res);
return res.end(JSON.stringify({ authToken: token }));
} catch (err) {
console.info("User was not connected", err);
log.info("User was not connected", err);
}
}
@ -84,7 +85,7 @@ export class AuthenticateController extends BaseController {
this.addCorsHeaders(res);
return res.end(JSON.stringify({ authToken }));
} catch (e) {
console.error("openIDCallback => ERROR", e);
log.error("openIDCallback => ERROR", e);
return this.errorToResponse(e, res);
}
});
@ -92,7 +93,7 @@ export class AuthenticateController extends BaseController {
// eslint-disable-next-line @typescript-eslint/no-misused-promises
this.App.get("/logout-callback", async (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/message request was aborted");
log.warn("/message request was aborted");
});
const { token } = parse(req.getQuery());
@ -104,7 +105,7 @@ export class AuthenticateController extends BaseController {
}
await openIDClient.logoutUser(authTokenData.hydraAccessToken);
} catch (error) {
console.error("openIDCallback => logout-callback", error);
log.error("openIDCallback => logout-callback", error);
} finally {
res.writeStatus("200");
this.addCorsHeaders(res);
@ -125,7 +126,7 @@ export class AuthenticateController extends BaseController {
this.App.post("/register", (res: HttpResponse, req: HttpRequest) => {
(async () => {
res.onAborted(() => {
console.warn("Login request was aborted");
log.warn("Login request was aborted");
});
const param = await res.json();
@ -156,7 +157,7 @@ export class AuthenticateController extends BaseController {
})
);
} catch (e) {
console.error("register => ERROR", e);
log.error("register => ERROR", e);
this.errorToResponse(e, res);
}
})();
@ -172,7 +173,7 @@ export class AuthenticateController extends BaseController {
this.App.post("/anonymLogin", (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("Login request was aborted");
log.warn("Login request was aborted");
});
const userUuid = v4();
@ -194,7 +195,7 @@ export class AuthenticateController extends BaseController {
// eslint-disable-next-line @typescript-eslint/no-misused-promises
this.App.get("/profile-callback", async (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/message request was aborted");
log.warn("/message request was aborted");
});
const { userIdentify, token } = parse(req.getQuery());
try {
@ -218,7 +219,7 @@ export class AuthenticateController extends BaseController {
}
}
} catch (error) {
console.error("profileCallback => ERROR", error);
log.error("profileCallback => ERROR", error);
this.errorToResponse(error, res);
}
});

View file

@ -1,4 +1,5 @@
import { HttpResponse } from "uWebSockets.js";
import log from "../Services/Logger";
export class BaseController {
protected addCorsHeaders(res: HttpResponse): void {
@ -19,12 +20,12 @@ export class BaseController {
} else {
url = "";
}
console.error("ERROR: " + e.message + url);
log.error("ERROR: " + e.message + url);
} else if (typeof e === "string") {
console.error(e);
log.error(e);
}
if (e.stack) {
console.error(e.stack);
log.error(e.stack);
}
if (e.response) {
res.writeStatus(e.response.status + " " + e.response.statusText);

View file

@ -31,6 +31,7 @@ import { Zone } from "_Model/Zone";
import { ExAdminSocketInterface } from "_Model/Websocket/ExAdminSocketInterface";
import { v4 } from "uuid";
import { CharacterTexture } from "../Services/AdminApi/CharacterTexture";
import log from "../Services/Logger";
export class IoSocketController {
private nextUserId: number = 1;
@ -49,13 +50,13 @@ export class IoSocketController {
const websocketExtensions = req.getHeader("sec-websocket-extensions");
const token = query.token;
if (token !== ADMIN_API_TOKEN) {
console.log("Admin access refused for token: " + token);
log.info("Admin access refused for token: " + token);
res.writeStatus("401 Unauthorized").end("Incorrect token");
return;
}
const roomId = query.roomId;
if (typeof roomId !== "string") {
console.error("Received");
log.error("Received");
res.writeStatus("400 Bad Request").end("Missing room id");
return;
}
@ -63,7 +64,7 @@ export class IoSocketController {
res.upgrade({ roomId }, websocketKey, websocketProtocol, websocketExtensions, context);
},
open: (ws) => {
console.log("Admin socket connect for room: " + ws.roomId);
log.info("Admin socket connect for room: " + ws.roomId);
ws.disconnecting = false;
socketManager.handleAdminRoom(ws as ExAdminSocketInterface, ws.roomId as string);
@ -96,7 +97,7 @@ export class IoSocketController {
}
}
} catch (err) {
console.error(err);
log.error(err);
}
},
close: (ws, code, message) => {
@ -105,8 +106,8 @@ export class IoSocketController {
Client.disconnecting = true;
socketManager.leaveAdminRoom(Client);
} catch (e) {
console.error('An error occurred on admin "disconnect"');
console.error(e);
log.error('An error occurred on admin "disconnect"');
log.error(e);
}
},
});
@ -198,7 +199,7 @@ export class IoSocketController {
if (err?.response?.status == 404) {
// If we get an HTTP 404, the token is invalid. Let's perform an anonymous login!
console.warn(
log.warn(
'Cannot find user with email "' +
(userIdentifier || "anonymous") +
'". Performing an anonymous login instead.'
@ -238,13 +239,13 @@ export class IoSocketController {
throw new Error("Use the login URL to connect");
}
} catch (e) {
console.log(
log.info(
"access not granted for user " +
(userIdentifier || "anonymous") +
" and room " +
roomId
);
console.error(e);
log.error(e);
throw new Error("User cannot access this world");
}
}
@ -254,7 +255,7 @@ export class IoSocketController {
SocketManager.mergeCharacterLayersAndCustomTextures(characterLayers, memberTextures);
if (upgradeAborted.aborted) {
console.log("Ouch! Client disconnected before we could upgrade it!");
log.info("Ouch! Client disconnected before we could upgrade it!");
/* You must not upgrade now */
return;
}
@ -395,7 +396,7 @@ export class IoSocketController {
//let ok = ws.send(message, isBinary);
},
drain: (ws) => {
console.log("WebSocket backpressure: " + ws.getBufferedAmount());
log.info("WebSocket backpressure: " + ws.getBufferedAmount());
},
close: (ws, code, message) => {
const Client = ws as ExSocketInterface;
@ -404,8 +405,8 @@ export class IoSocketController {
//leave room
socketManager.leaveRoom(Client);
} catch (e) {
console.error('An error occurred on "disconnect"');
console.error(e);
log.error('An error occurred on "disconnect"');
log.error(e);
}
},
});

View file

@ -8,6 +8,7 @@ import { MapDetailsData } from "../Services/AdminApi/MapDetailsData";
import { socketManager } from "../Services/SocketManager";
import { AuthTokenData, jwtTokenManager } from "../Services/JWTTokenManager";
import { v4 } from "uuid";
import log from "../Services/Logger";
export class MapController extends BaseController {
constructor(private App: TemplatedApp) {
@ -26,13 +27,13 @@ export class MapController extends BaseController {
this.App.get("/map", (res: HttpResponse, req: HttpRequest) => {
res.onAborted(() => {
console.warn("/map request was aborted");
log.warn("/map request was aborted");
});
const query = parse(req.getQuery());
if (typeof query.playUri !== "string") {
console.error("Expected playUri parameter in /map endpoint");
log.error("Expected playUri parameter in /map endpoint");
res.writeStatus("400 Bad request");
this.addCorsHeaders(res);
res.end("Expected playUri parameter");
@ -82,7 +83,7 @@ export class MapController extends BaseController {
// Decode token, in this case we don't need to create new token.
authTokenData = jwtTokenManager.verifyJWTToken(query.authToken as string, true);
userId = authTokenData.identifier;
console.info("JWT expire, but decoded", userId);
log.info("JWT expire, but decoded", userId);
}
}
const mapDetails = await adminApi.fetchMapDetails(query.playUri as string, userId);

View file

@ -11,6 +11,7 @@
import { Zone, ZoneEventListener } from "./Zone";
import { ViewportInterface } from "_Model/Websocket/ViewportMessage";
import { ExSocketInterface } from "_Model/Websocket/ExSocketInterface";
import log from "../Services/Logger";
//import Debug from "debug";
//const debug = Debug('positiondispatcher');
@ -44,7 +45,7 @@ export class PositionDispatcher {
*/
public setViewport(socket: ExSocketInterface, viewport: ViewportInterface): void {
if (viewport.left > viewport.right || viewport.top > viewport.bottom) {
console.warn("Invalid viewport received: ", viewport);
log.warn("Invalid viewport received: ", viewport);
return;
}

View file

@ -20,6 +20,7 @@ import {
import { ClientReadableStream } from "grpc";
import { PositionDispatcher } from "_Model/PositionDispatcher";
import Debug from "debug";
import log from "../Services/Logger";
const debug = Debug("zone");
@ -209,7 +210,7 @@ export class Zone {
const userDescriptor = this.users.get(userId);
if (userDescriptor === undefined) {
console.error('Unexpected move message received for user "' + userId + '"');
log.error('Unexpected move message received for user "' + userId + '"');
return;
}

View file

@ -2,6 +2,7 @@ import { createWriteStream } from "fs";
import { join, dirname } from "path";
import Busboy from "busboy";
import mkdirp from "mkdirp";
import log from "../../Services/Logger";
function formData(
contType: string,
@ -19,7 +20,7 @@ function formData(
filename?: (oldName: string) => string;
} = {}
) {
console.log("Enter form data");
log.info("Enter form data");
options.headers = {
"content-type": contType,
};

View file

@ -1,4 +1,5 @@
import { CPU_OVERHEAT_THRESHOLD } from "../Enum/EnvironmentVariable";
import log from "./Logger";
function secNSec2ms(secNSec: Array<number> | number) {
if (Array.isArray(secNSec)) {
@ -28,16 +29,16 @@ class CpuTracker {
if (!this.overHeating && this.cpuPercent > CPU_OVERHEAT_THRESHOLD) {
this.overHeating = true;
console.warn('CPU high threshold alert. Going in "overheat" mode');
log.warn('CPU high threshold alert. Going in "overheat" mode');
} else if (this.overHeating && this.cpuPercent <= CPU_OVERHEAT_THRESHOLD) {
this.overHeating = false;
console.log('CPU is back to normal. Canceling "overheat" mode');
log.info('CPU is back to normal. Canceling "overheat" mode');
}
/*console.log('elapsed time ms: ', elapTimeMS)
console.log('elapsed user ms: ', elapUserMS)
console.log('elapsed system ms:', elapSystMS)
console.log('cpu percent: ', this.cpuPercent)*/
/*log.info('elapsed time ms: ', elapTimeMS)
log.info('elapsed user ms: ', elapUserMS)
log.info('elapsed system ms:', elapSystMS)
log.info('cpu percent: ', this.cpuPercent)*/
}, 100);
}

View file

@ -1,6 +1,7 @@
import { ExSocketInterface } from "_Model/Websocket/ExSocketInterface";
import { BatchMessage, ErrorMessage, ServerToClientMessage, SubMessage } from "../Messages/generated/messages_pb";
import { WebSocket } from "uWebSockets.js";
import log from "./Logger";
export function emitInBatch(socket: ExSocketInterface, payload: SubMessage): void {
socket.batchedMessages.addPayload(payload);
@ -31,5 +32,5 @@ export function emitError(Client: WebSocket, message: string): void {
if (!Client.disconnecting) {
Client.send(serverToClientMessage.serializeBinary().buffer, true);
}
console.warn(message);
log.warn(message);
}

View file

@ -0,0 +1,16 @@
import * as winston from "winston";
const logger = winston.createLogger({
transports: [
new winston.transports.Console({
format: winston.format.combine(
winston.format.colorize(),
winston.format.timestamp(),
winston.format.align(),
winston.format.printf((info) => `${info.timestamp} ${info.level}: ${info.message}`)
),
}),
],
});
export default logger;

View file

@ -49,6 +49,7 @@ import { ExAdminSocketInterface } from "_Model/Websocket/ExAdminSocketInterface"
import { WebSocket } from "uWebSockets.js";
import { isRoomRedirect } from "./AdminApi/RoomRedirect";
import { CharacterTexture } from "./AdminApi/CharacterTexture";
import log from "./Logger";
const debug = Debug("socket");
@ -115,15 +116,15 @@ export class SocketManager implements ZoneEventListener {
}
})
.on("end", () => {
console.warn("Admin connection lost to back server");
log.warn("Admin connection lost to back server");
// Let's close the front connection if the back connection is closed. This way, we can retry connecting from the start.
if (!client.disconnecting) {
this.closeWebsocketConnection(client, 1011, "Admin Connection lost to back server");
}
console.log("A user left");
log.info("A user left");
})
.on("error", (err: Error) => {
console.error("Error in connection to back server:", err);
log.error("Error in connection to back server:", err);
if (!client.disconnecting) {
this.closeWebsocketConnection(client, 1011, "Error while connecting to back server");
}
@ -166,7 +167,7 @@ export class SocketManager implements ZoneEventListener {
joinRoomMessage.addCharacterlayer(characterLayerMessage);
}
console.log("Calling joinRoom '"+client.roomId+"' for client "+client.userUuid);
log.info("Calling joinRoom '" + client.roomId + "' for client " + client.userUuid);
const apiClient = await apiClientRepository.getClient(client.roomId);
const streamToPusher = apiClient.joinRoom();
clientEventsEmitter.emitClientJoin(client.userUuid, client.roomId);
@ -198,12 +199,21 @@ export class SocketManager implements ZoneEventListener {
if (!client.disconnecting) {
this.closeWebsocketConnection(client, 1011, "Connection lost to back server");
}
console.log("Closed connection for user '"+client.userUuid+"' to back server "+apiClient.getChannel().getTarget());
log.info(
"Closed connection for user '" +
client.userUuid +
"' to back server " +
apiClient.getChannel().getTarget()
);
})
.on("error", (err: Error) => {
console.error("Error in connection to back server '"+apiClient.getChannel().getTarget()+"':", err);
log.error("Error in connection to back server '" + apiClient.getChannel().getTarget() + "':", err);
if (!client.disconnecting) {
this.closeWebsocketConnection(client, 1011, "Error while connecting to back server '"+apiClient.getChannel().getTarget()+"'");
this.closeWebsocketConnection(
client,
1011,
"Error while connecting to back server '" + apiClient.getChannel().getTarget() + "'"
);
}
});
@ -214,8 +224,8 @@ export class SocketManager implements ZoneEventListener {
const pusherRoom = await this.getOrCreateRoom(client.roomId);
pusherRoom.join(client);
} catch (e) {
console.error('An error occurred on "join_room" event');
console.error(e);
log.error('An error occurred on "join_room" event');
log.error(e);
}
}
@ -232,13 +242,13 @@ export class SocketManager implements ZoneEventListener {
const room = this.rooms.get(client.roomId);
if (!room) {
console.error("In SET_VIEWPORT, could not find world with id '", client.roomId, "'");
log.error("In SET_VIEWPORT, could not find world with id '", client.roomId, "'");
return;
}
room.setViewport(client, client.viewport);
} catch (e) {
console.error('An error occurred on "SET_VIEWPORT" event');
console.error(e);
log.error('An error occurred on "SET_VIEWPORT" event');
log.error(e);
}
}
@ -309,8 +319,8 @@ export class SocketManager implements ZoneEventListener {
client.roomId
);
} catch (e) {
console.error('An error occurred on "handleReportMessage"');
console.error(e);
log.error('An error occurred on "handleReportMessage"');
log.error(e);
}
}
@ -345,14 +355,14 @@ export class SocketManager implements ZoneEventListener {
debug("Room %s is empty. Deleting.", socket.roomId);
}
} else {
console.error("Could not find the GameRoom the user is leaving!");
log.error("Could not find the GameRoom the user is leaving!");
}
//user leave previous room
//Client.leave(Client.roomId);
} finally {
//delete Client.roomId;
clientEventsEmitter.emitClientLeave(socket.userUuid, socket.roomId);
console.log("User '"+socket.userUuid+"' left");
log.info("User '" + socket.userUuid + "' left");
}
}
} finally {
@ -434,7 +444,7 @@ export class SocketManager implements ZoneEventListener {
client.send(serverToClientMessage.serializeBinary().buffer, true);
} catch (e) {
console.error("An error occurred while generating the Jitsi JWT token: ", e);
log.error("An error occurred while generating the Jitsi JWT token: ", e);
}
}
@ -458,7 +468,7 @@ export class SocketManager implements ZoneEventListener {
backAdminMessage.setType(type);
backConnection.sendAdminMessage(backAdminMessage, (error) => {
if (error !== null) {
console.error("Error while sending admin message", error);
log.error("Error while sending admin message", error);
}
});
}
@ -483,7 +493,7 @@ export class SocketManager implements ZoneEventListener {
banMessage.setType(type);
backConnection.ban(banMessage, (error) => {
if (error !== null) {
console.error("Error while sending admin message", error);
log.error("Error while sending admin message", error);
}
});
}