feat: add pino logger

This commit is contained in:
mrjvs
2025-09-03 12:17:29 +02:00
parent 8ea0fe7c49
commit 64b33cb25f
8 changed files with 504 additions and 235 deletions

View File

@@ -2,7 +2,6 @@ import crypto from 'node:crypto';
import path from 'node:path';
import fs from 'fs-extra';
import dotenv from 'dotenv';
import { LOG_INFO, LOG_WARN, LOG_ERROR } from '@/logger';
dotenv.config();
@@ -15,8 +14,6 @@ const BOSS_WIIU_AES_KEY_MD5_HASH = '5202ce5099232c3d365e28379790a919';
const BOSS_WIIU_HMAC_KEY_MD5_HASH = 'b4482fef177b0100090ce0dbeb8ce977';
const BOSS_3DS_AES_KEY_MD5_HASH = '86fbc2bb4cb703b2a4c6cc9961319926';
LOG_INFO('Loading config');
const warnings: string[] = [];
const errors: string[] = [];
@@ -29,6 +26,10 @@ export const config = {
http: {
port: Number(process.env.PN_BOSS_CONFIG_HTTP_PORT?.trim() || '')
},
log: {
format: process.env.PN_BOSS_CONFIG_LOG_FORMAT?.trim() || 'pretty',
level: process.env.PN_BOSS_CONFIG_LOG_LEVEL?.trim() || 'info'
},
crypto: {
wup: {
aes_key: process.env.PN_BOSS_CONFIG_BOSS_WIIU_AES_KEY?.trim() || '',
@@ -81,12 +82,20 @@ export const config = {
}
};
LOG_INFO('Config loaded, checking integrity');
if (!config.http.port) {
errors.push('Failed to find HTTP port. Set the PN_BOSS_CONFIG_HTTP_PORT environment variable');
}
const possibleConfigFormats = ['pretty', 'json'];
if (!possibleConfigFormats.includes(config.log.format)) {
errors.push(`Invalid log format, possible values: ${possibleConfigFormats.join(', ')}`);
}
const possibleconfigLevels = ['error', 'warn', 'info', 'debug', 'trace'];
if (!possibleconfigLevels.includes(config.log.level)) {
errors.push(`Invalid log level, possible values: ${possibleConfigFormats.join(', ')}`);
}
if (md5(config.crypto.wup.aes_key) !== BOSS_WIIU_AES_KEY_MD5_HASH) {
warnings.push('Invalid BOSS WiiU AES key. Uploading and encrypting new BOSS content for the Wii U won\'t work! Set or correct the PN_BOSS_CONFIG_BOSS_WIIU_AES_KEY environment variable');
}
@@ -180,12 +189,12 @@ if (disabledFeatures.s3) {
}
for (const warning of warnings) {
LOG_WARN(warning);
console.warn(warning);
}
if (errors.length !== 0) {
for (const error of errors) {
LOG_ERROR(error);
console.error(error);
}
process.exit(0);

View File

@@ -1,55 +1,46 @@
import fs from 'fs-extra';
import colors from 'colors';
import { pino } from 'pino';
import pinoPretty from 'pino-pretty';
import { pinoHttp } from 'pino-http';
import { config } from '@/config-manager';
import type { SerializedRequest, SerializedResponse } from 'pino';
colors.enable();
const pretty = config.log.format == 'pretty'
? pinoPretty({
customPrettifiers: {
// Clean up Express types for developer eyes
req(inputData, _key, _log, { colors }) {
const req = inputData as SerializedRequest;
return `${colors.bold(req.method)} ${req.headers.host}${req.url} (${req.remoteAddress}:${req.remotePort})`;
},
res(inputData, _key, _log, { colors }) {
const res = inputData as SerializedResponse;
const color = ((): (val: any) => string => {
if (res.statusCode >= 500) {
return colors.red;
} else if (res.statusCode >= 400) {
return colors.yellow;
} else if (res.statusCode >= 200) {
return colors.green;
} else {
return colors.reset;
}
})();
const root = process.env.PN_BOSS_CONFIG_LOGGER_PATH ? process.env.PN_BOSS_CONFIG_LOGGER_PATH : `${__dirname}/..`;
fs.ensureDirSync(`${root}/logs`);
return `${color(res.statusCode)} (${res.headers['content-length']} bytes)`;
}
}
})
: undefined;
const streams = {
latest: fs.createWriteStream(`${root}/logs/latest.log`),
success: fs.createWriteStream(`${root}/logs/success.log`),
error: fs.createWriteStream(`${root}/logs/error.log`),
warn: fs.createWriteStream(`${root}/logs/warn.log`),
info: fs.createWriteStream(`${root}/logs/info.log`)
} as const;
// Main logger object
export const logger = pino({
level: config.log.level,
function getCurrentTimestamp(): string {
const date = new Date();
const year = date.getFullYear();
const month = String(date.getMonth() + 1).padStart(2, '0'); // * Months are 0-indexed
const day = String(date.getDate()).padStart(2, '0');
const hours = String(date.getHours()).padStart(2, '0');
const minutes = String(date.getMinutes()).padStart(2, '0');
const seconds = String(date.getSeconds()).padStart(2, '0');
customLevels: {
success: 35 // between INFO and WARN
}
}, pretty);
return `${year}-${month}-${day} ${hours}:${minutes}:${seconds}`;
}
export function LOG_SUCCESS(input: string): void {
input = `[${getCurrentTimestamp()}] [SUCCESS]: ${input}`;
streams.success.write(`${input}\n`);
console.log(`${input}`.green.bold);
}
export function LOG_ERROR(input: string): void {
input = `[${getCurrentTimestamp()}] [ERROR]: ${input}`;
streams.error.write(`${input}\n`);
console.error(`${input}`.red.bold);
}
export function LOG_WARN(input: string): void {
input = `[${getCurrentTimestamp()}] [WARN]: ${input}`;
streams.warn.write(`${input}\n`);
console.log(`${input}`.yellow.bold);
}
export function LOG_INFO(input: string): void {
input = `[${getCurrentTimestamp()}] [INFO]: ${input}`;
streams.info.write(`${input}\n`);
console.log(`${input}`.cyan.bold);
}
export const loggerHttp = pinoHttp({
logger: logger
});

View File

@@ -1,9 +1,8 @@
import express from 'express';
import morgan from 'morgan';
import { connect as connectDatabase } from '@/database';
import { startGRPCServer } from '@/services/grpc/server';
import RequestException from '@/request-exception';
import { LOG_INFO, LOG_SUCCESS } from '@/logger';
import { logger, loggerHttp } from '@/logger';
import { config } from '@/config-manager';
import parseUserAgentMiddleware from '@/middleware/parse-user-agent';
import authenticationMiddleware from '@/middleware/authentication';
@@ -21,8 +20,8 @@ process.on('SIGTERM', () => {
const app = express();
LOG_INFO('Setting up Middleware');
app.use(morgan('dev'));
logger.info('Setting up Middleware');
app.use(loggerHttp);
app.use(express.json());
app.use(express.urlencoded({
extended: true
@@ -38,7 +37,7 @@ app.use(npfl);
app.use(npdl);
app.use(spr);
LOG_INFO('Creating 404 status handler');
logger.info('Creating 404 status handler');
app.use((_request, response) => {
response.status(404);
response.json({
@@ -48,7 +47,7 @@ app.use((_request, response) => {
});
});
LOG_INFO('Creating non-404 status handler');
logger.info('Creating non-404 status handler');
app.use((error: unknown, _request: express.Request, response: express.Response, _next: express.NextFunction) => {
let status: number = 500;
let message: string = 'Unknown error';
@@ -69,16 +68,16 @@ app.use((error: unknown, _request: express.Request, response: express.Response,
});
async function main(): Promise<void> {
LOG_INFO('Starting server');
logger.info('Starting server');
await connectDatabase();
LOG_SUCCESS('Database connected');
logger.success('Database connected');
await startGRPCServer();
LOG_SUCCESS(`gRPC server started at address ${config.grpc.boss.address}:${config.grpc.boss.port}`);
logger.success(`gRPC server started at address ${config.grpc.boss.address}:${config.grpc.boss.port}`);
app.listen(config.http.port, () => {
LOG_SUCCESS(`HTTP server started on port ${config.http.port}`);
logger.success(`HTTP server started on port ${config.http.port}`);
});
}

View File

@@ -2,7 +2,7 @@ import { Stream } from 'node:stream';
import express from 'express';
import { getTaskFile } from '@/database';
import { getCDNFileStream } from '@/util';
import { LOG_ERROR } from '@/logger';
import { logger } from '@/logger';
import { config } from '@/config-manager';
import { restrictHostnames } from '@/middleware/host-limit';
@@ -43,7 +43,7 @@ npdl.get([
Stream.pipeline(readStream, response, (err) => {
if (err) {
LOG_ERROR('Error with response stream: ' + err.message);
logger.error('Error with response stream: ' + err.message);
response.end();
}
});

View File

@@ -8,9 +8,9 @@ import { CECData } from '@/models/cec-data';
import { CECSlot } from '@/models/cec-slot';
import { SendMode } from '@/types/common/spr-slot';
import RequestException from '@/request-exception';
import { LOG_WARN, LOG_INFO } from '@/logger';
import { config } from '@/config-manager';
import { restrictHostnames } from '@/middleware/host-limit';
import { logger } from '@/logger';
import type { SPRSlot } from '@/types/common/spr-slot';
const spr = express.Router();
@@ -89,7 +89,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
// * Check that the account is a 3DS and isn't banned
if (!request.nexAccount.friendCode || request.nexAccount.accessLevel < 0) {
LOG_INFO(`{request.pid}: User is not a 3DS or is banned`);
logger.info(`{request.pid}: User is not a 3DS or is banned`);
response.sendStatus(403);
return;
}
@@ -97,7 +97,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
const sprMetadataBuffer: Buffer | undefined = request.files['spr-meta'];
if (!sprMetadataBuffer) {
LOG_WARN(`{request.pid}: Missing spr-meta file`);
logger.warn(`{request.pid}: Missing spr-meta file`);
response.sendStatus(400);
return;
}
@@ -109,7 +109,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
const metadataHeaders = sprMetadata.split('\r\n'); // * Split header lines
if (metadataHeaders.length < 1) {
LOG_WARN(`{request.pid}: spr-meta file is too short / empty`);
logger.warn(`{request.pid}: spr-meta file is too short / empty`);
response.sendStatus(400);
return;
}
@@ -118,7 +118,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
const metadataHeader = metadataHeaders[i];
const [header, value] = metadataHeader.split(': '); // * Split header and value
if (!header || !value) {
LOG_WARN(`{request.pid}: Bad spr-meta entry`);
logger.warn(`{request.pid}: Bad spr-meta entry`);
response.sendStatus(400);
return;
}
@@ -127,7 +127,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
// * we can guarantee that i must match with the slot we are looking at except for 0, which will be the slotsize
if (i === 0) {
if (header !== 'slotsize') {
LOG_WARN(`{request.pid}: spr-meta missing slotsize`);
logger.warn(`{request.pid}: spr-meta missing slotsize`);
response.sendStatus(400);
return;
}
@@ -137,14 +137,14 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
try {
slotsize = parseInt(value);
} catch {
LOG_WARN(`{request.pid}: Invalid spr-meta slotsize`);
logger.warn(`{request.pid}: Invalid spr-meta slotsize`);
response.sendStatus(400);
return;
}
// * We don't count the slotsize header itself in the slot count
if (slotsize !== (metadataHeaders.length - 1)) {
LOG_WARN(`{request.pid}: Bad spr-meta slotsize`);
logger.warn(`{request.pid}: Bad spr-meta slotsize`);
response.sendStatus(400);
return;
}
@@ -155,7 +155,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
const metadata = value.split(','); // * Split the value to get the metadata
if (metadata.length !== 3) {
LOG_WARN(`{request.pid}: Bad spr-meta entry param count`);
logger.warn(`{request.pid}: Bad spr-meta entry param count`);
response.sendStatus(400);
return;
}
@@ -168,7 +168,7 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
gameID = parseInt(metadata[1], 16);
size = parseInt(metadata[2]);
} catch {
LOG_WARN(`{request.pid}: Invalid spr-meta entry params`);
logger.warn(`{request.pid}: Invalid spr-meta entry params`);
response.sendStatus(400);
return;
}
@@ -179,13 +179,13 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
const slotData: Buffer | undefined = request.files['spr-slot' + slot];
if (!slotData) {
LOG_WARN(`{request.pid}: Missing slot data file`);
logger.warn(`{request.pid}: Missing slot data file`);
response.sendStatus(400);
return;
}
if (slotData.length !== size) {
LOG_WARN(`{request.pid}: Invalid slot data size`);
logger.warn(`{request.pid}: Invalid slot data size`);
response.sendStatus(400);
return;
}
@@ -200,25 +200,25 @@ spr.post('/relay/0', multipartParser, async (request, response) => {
// * Check that we at least have enough size for the StreetPass header
if (slotData.length < 0x12) {
LOG_WARN(`{request.pid}: Slot is too short`);
logger.warn(`{request.pid}: Slot is too short`);
response.sendStatus(400);
return;
}
if (slotData.readUInt32LE() !== 0x6161) {
LOG_WARN(`{request.pid}: Slot header missmatch`);
logger.warn(`{request.pid}: Slot header missmatch`);
response.sendStatus(400);
return;
}
if (slotData.readUInt32LE(4) !== size) {
LOG_WARN(`{request.pid}: Slot bad size`);
logger.warn(`{request.pid}: Slot bad size`);
response.sendStatus(400);
return;
}
if (slotData.readUInt32LE(8) !== gameID) {
LOG_WARN(`{request.pid}: Slot bad gameID`);
logger.warn(`{request.pid}: Slot bad gameID`);
response.sendStatus(400);
return;
}

View File

@@ -6,7 +6,7 @@ import { GetObjectCommand, PutObjectCommand, S3 } from '@aws-sdk/client-s3';
import { AccountDefinition } from '@pretendonetwork/grpc/account/account_service';
import { FriendsDefinition } from '@pretendonetwork/grpc/friends/friends_service';
import { config, disabledFeatures } from '@/config-manager';
import { LOG_ERROR } from '@/logger';
import { logger } from './logger';
import type { FriendsClient } from '@pretendonetwork/grpc/friends/friends_service';
import type { AccountClient } from '@pretendonetwork/grpc/account/account_service';
import type { S3Client } from '@aws-sdk/client-s3';
@@ -72,7 +72,7 @@ export function fileErrCallback(response: Response) {
if (!response.headersSent) {
response.status(500).send('Server Error');
}
LOG_ERROR('Error in sending file: ' + err.message);
logger.error('Error in sending file: ' + err.message);
}
}
};