From 0c238dd9f178f57075bb1408f8305ad17e0a04eb Mon Sep 17 00:00:00 2001 From: Zutatensuppe Date: Tue, 13 Apr 2021 20:18:41 +0200 Subject: [PATCH] logger func to better know when and where soemthing was logged --- common/Util.js | 24 ++++++++++++++++++++++++ game/Debug.js | 6 +++++- game/PuzzleGraphics.js | 6 +++++- scripts/fix_tiles.js | 9 ++++++--- scripts/rewrite_logs.js | 5 ++++- server/Game.js | 6 ++++-- server/GameLog.js | 11 +++++++---- server/GameSockets.js | 12 ++++++++---- server/WebSocketServer.js | 7 +++++-- server/index.js | 28 +++++++++++++++------------- 10 files changed, 83 insertions(+), 31 deletions(-) diff --git a/common/Util.js b/common/Util.js index 95c1172..3354bb7 100644 --- a/common/Util.js +++ b/common/Util.js @@ -1,5 +1,29 @@ import { Rng } from './Rng.js' + +const pad = (x, pad) => { + const str = `${x}` + if (str.length >= pad.length) { + return str + } + return pad.substr(0, pad.length - str.length) + str +} + +export const logger = (...pre) => { + const log = (m) => (...args) => { + const d = new Date() + const hh = pad(d.getHours(), '00') + const mm = pad(d.getMinutes(), '00') + const ss = pad(d.getSeconds(), '00') + console[m](`${hh}:${mm}:${ss}`, ...pre, ...args) + } + return { + log: log('log'), + error: log('error'), + info: log('info'), + } +} + // get a unique id export const uniqId = () => Date.now().toString(36) + Math.random().toString(36).substring(2) diff --git a/game/Debug.js b/game/Debug.js index c7b47be..1306d08 100644 --- a/game/Debug.js +++ b/game/Debug.js @@ -1,3 +1,7 @@ +import { logger } from '../common/Util.js' + +const log = logger('Debug.js') + let _pt = 0 let _mindiff = 0 @@ -10,7 +14,7 @@ const checkpoint = (label) => { const now = performance.now(); const diff = now - _pt if (diff > _mindiff) { - console.log(label + ': ' + (diff)); + log.log(label + ': ' + (diff)); } _pt = now; } diff --git a/game/PuzzleGraphics.js b/game/PuzzleGraphics.js index 270d493..59fdb65 100644 --- a/game/PuzzleGraphics.js +++ b/game/PuzzleGraphics.js @@ -1,8 +1,11 @@ import Geometry from '../common/Geometry.js' import Graphics from './Graphics.js' -import Util from './../common/Util.js' +import Util, { logger } from './../common/Util.js' + +const log = logger('PuzzleGraphics.js') async function createPuzzleTileBitmaps(img, tiles, info) { + log.log('start createPuzzleTileBitmaps') var tileSize = info.tileSize var tileMarginWidth = info.tileMarginWidth var tileDrawSize = info.tileDrawSize @@ -190,6 +193,7 @@ async function createPuzzleTileBitmaps(img, tiles, info) { bitmaps[tile.idx] = await createImageBitmap(c) } + log.log('end createPuzzleTileBitmaps') return bitmaps } diff --git a/scripts/fix_tiles.js b/scripts/fix_tiles.js index f214d27..545b766 100644 --- a/scripts/fix_tiles.js +++ b/scripts/fix_tiles.js @@ -1,7 +1,10 @@ -import fs from 'fs' import GameCommon from '../common/GameCommon.js' +import { logger } from '../common/Util.js' import Game from '../server/Game.js' + +const log = logger('fix_tiles.js') + function fix_tiles(gameId) { Game.loadGame(gameId) let changed = false @@ -12,14 +15,14 @@ function fix_tiles(gameId) { if (p.x === tile.pos.x && p.y === tile.pos.y) { // console.log('all good', tile.pos) } else { - console.log('bad tile pos', tile.pos, 'should be: ', p) + log.log('bad tile pos', tile.pos, 'should be: ', p) tile.pos = p GameCommon.setTile(gameId, tile.idx, tile) changed = true } } else if (tile.owner !== 0) { tile.owner = 0 - console.log('unowning tile', tile.idx) + log.log('unowning tile', tile.idx) GameCommon.setTile(gameId, tile.idx, tile) changed = true } diff --git a/scripts/rewrite_logs.js b/scripts/rewrite_logs.js index ae1aae8..19ae2ea 100644 --- a/scripts/rewrite_logs.js +++ b/scripts/rewrite_logs.js @@ -1,5 +1,8 @@ import fs from 'fs' import Protocol from '../common/Protocol.js' +import { logger } from '../common/Util.js' + +const log = logger('rewrite_logs') const DATA_DIR = '../data' @@ -7,7 +10,7 @@ const filename = (gameId) => `${DATA_DIR}/log_${gameId}.log` const rewrite = (gameId) => { const file = filename(gameId) - console.log(file) + log.log(file) if (!fs.existsSync(file)) { return [] } diff --git a/server/Game.js b/server/Game.js index e4da166..53b1699 100644 --- a/server/Game.js +++ b/server/Game.js @@ -1,11 +1,13 @@ import fs from 'fs' import GameCommon from './../common/GameCommon.js' -import Util from './../common/Util.js' +import Util, { logger } from './../common/Util.js' import { Rng } from '../common/Rng.js' import GameLog from './GameLog.js' import { createPuzzle } from './Puzzle.js' import Protocol from '../common/Protocol.js' +const log = logger('Game.js') + const DATA_DIR = './../data' function loadAllGames() { @@ -27,7 +29,7 @@ function loadGame(gameId) { try { game = JSON.parse(contents) } catch { - console.log(`[ERR] unable to load game from file ${file}`); + log.log(`[ERR] unable to load game from file ${file}`); } if (typeof game.puzzle.data.started === 'undefined') { game.puzzle.data.started = Math.round(fs.statSync(file).ctimeMs) diff --git a/server/GameLog.js b/server/GameLog.js index a3c2b19..5c75fdb 100644 --- a/server/GameLog.js +++ b/server/GameLog.js @@ -1,4 +1,7 @@ import fs from 'fs' +import { logger } from '../common/Util.js' + +const log = logger('GameLog.js') const DATA_DIR = './../data' @@ -16,7 +19,7 @@ const exists = (gameId) => { return fs.existsSync(file) } -const log = (gameId, ...args) => { +const _log = (gameId, ...args) => { const file = filename(gameId) if (!fs.existsSync(file)) { return @@ -35,8 +38,8 @@ const get = (gameId) => { try { return JSON.parse(line) } catch (e) { - console.log(line) - console.log(e) + log.log(line) + log.log(e) } }) } @@ -44,6 +47,6 @@ const get = (gameId) => { export default { create, exists, - log, + log: _log, get, } diff --git a/server/GameSockets.js b/server/GameSockets.js index c8e32c0..875ab9b 100644 --- a/server/GameSockets.js +++ b/server/GameSockets.js @@ -1,3 +1,7 @@ +import { logger } from '../common/Util.js' + +const log = logger('GameSocket.js') + // Map const SOCKETS = {} @@ -13,8 +17,8 @@ function removeSocket(gameId, socket) { return } SOCKETS[gameId] = SOCKETS[gameId].filter(s => s !== socket) - console.log('removed socket: ', gameId, socket.protocol) - console.log('socket count: ', Object.keys(SOCKETS[gameId]).length) + log.log('removed socket: ', gameId, socket.protocol) + log.log('socket count: ', Object.keys(SOCKETS[gameId]).length) } function addSocket(gameId, socket) { @@ -23,8 +27,8 @@ function addSocket(gameId, socket) { } if (!SOCKETS[gameId].includes(socket)) { SOCKETS[gameId].push(socket) - console.log('added socket: ', gameId, socket.protocol) - console.log('socket count: ', Object.keys(SOCKETS[gameId]).length) + log.log('added socket: ', gameId, socket.protocol) + log.log('socket count: ', Object.keys(SOCKETS[gameId]).length) } } diff --git a/server/WebSocketServer.js b/server/WebSocketServer.js index b9464ca..d1f3bd7 100644 --- a/server/WebSocketServer.js +++ b/server/WebSocketServer.js @@ -1,4 +1,7 @@ import WebSocket from 'ws' +import { logger } from '../common/Util.js' + +const log = logger('WebSocketServer.js') /* Example config @@ -44,12 +47,12 @@ class WebSocketServer { this._websocketserver.on('connection', (socket, request, client) => { const pathname = new URL(this.config.connectstring).pathname if (request.url.indexOf(pathname) !== 0) { - console.log('bad request url: ', request.url) + log.log('bad request url: ', request.url) socket.close() return } socket.on('message', (data) => { - console.log(`ws`, socket.protocol, data) + log.log(`ws`, socket.protocol, data) this.evt.dispatch('message', {socket, data}) }) socket.on('close', () => { diff --git a/server/index.js b/server/index.js index a39f779..e67da82 100644 --- a/server/index.js +++ b/server/index.js @@ -5,7 +5,7 @@ import express from 'express' import multer from 'multer' import config from './../config.js' import Protocol from './../common/Protocol.js' -import Util from './../common/Util.js' +import Util, { logger } from './../common/Util.js' import Game from './Game.js' import twing from 'twing' import bodyParser from 'body-parser' @@ -13,6 +13,8 @@ import v8 from 'v8' import GameLog from './GameLog.js' import GameSockets from './GameSockets.js' +const log = logger('index.js') + const allImages = () => [ ...fs.readdirSync('./../data/uploads/').map(f => ({ file: `./../data/uploads/${f}`, @@ -62,7 +64,7 @@ app.use('/replay/:gid', async (req, res, next) => { app.post('/upload', (req, res) => { upload(req, res, (err) => { if (err) { - console.log(err) + log.log(err) res.status(400).send("Something went wrong!"); } res.send({ @@ -75,7 +77,7 @@ app.post('/upload', (req, res) => { }) app.post('/newgame', bodyParser.json(), async (req, res) => { - console.log(req.body.tiles, req.body.image) + log.log(req.body.tiles, req.body.image) const gameId = Util.uniqId() if (!Game.exists(gameId)) { const ts = Util.timestamp() @@ -211,7 +213,7 @@ Game.loadAllGames() const server = app.listen( port, hostname, - () => console.log(`server running on http://${hostname}:${port}`) + () => log.log(`server running on http://${hostname}:${port}`) ) wss.listen() @@ -220,37 +222,37 @@ const memoryUsageHuman = () => { const totalHeapSize = v8.getHeapStatistics().total_available_size let totalHeapSizeInGB = (totalHeapSize / 1024 / 1024 / 1024).toFixed(2) - console.log(`Total heap size (bytes) ${totalHeapSize}, (GB ~${totalHeapSizeInGB})`) + log.log(`Total heap size (bytes) ${totalHeapSize}, (GB ~${totalHeapSizeInGB})`) const used = process.memoryUsage().heapUsed / 1024 / 1024 - console.log(`Mem: ${Math.round(used * 100) / 100}M`) + log.log(`Mem: ${Math.round(used * 100) / 100}M`) } memoryUsageHuman() // persist games in fixed interval const persistInterval = setInterval(() => { - console.log('Persisting games...') + log.log('Persisting games...') Game.persistChangedGames() memoryUsageHuman() }, config.persistence.interval) const gracefulShutdown = (signal) => { - console.log(`${signal} received...`) + log.log(`${signal} received...`) - console.log('clearing persist interval...') + log.log('clearing persist interval...') clearInterval(persistInterval) - console.log('persisting games...') + log.log('persisting games...') Game.persistChangedGames() - console.log('shutting down webserver...') + log.log('shutting down webserver...') server.close() - console.log('shutting down websocketserver...') + log.log('shutting down websocketserver...') wss.close() - console.log('shutting down...') + log.log('shutting down...') process.exit() }