This commit is contained in:
seb
2026-10-08 03:43:28 +02:00
parent c543c76a21
commit 717f4754d4
9 changed files with 787 additions and 24 deletions

View File

@@ -14,8 +14,11 @@ import { closeAll as closeAllSse } from './sse.js';
import { closeAllManagers } from '../services/conversationManager.js';
import { shutdownImageCropWorkers } from '../services/imageCrop.js';
import { getOrCreateCert } from '../util/cert.js';
import { createLogger } from '../util/logger.js';
import v1Router from '../v1/index.js';
const apiLog = createLogger('api');
const __filename = fileURLToPath(import.meta.url);
const __dirname = path.dirname(__filename);
@@ -155,7 +158,7 @@ async function createApi() {
if (err instanceof SyntaxError && err.status === 400 && 'body' in err) {
return res.status(400).json({ error: 'Invalid JSON body' });
}
console.error('Unhandled API error:', err);
apiLog.error('Unhandled API error:', err);
const status = typeof err.status === 'number' && err.status >= 400 && err.status < 600 ? err.status : 500;
res.status(status).json({ error: err.message || 'Internal server error' });
});
@@ -178,9 +181,9 @@ function listenServer(instance, port, protocol) {
} catch {
// lsof unavailable or no match
}
console.error(`Port ${port} (${protocol}) is already in use${detail}. Check with: lsof -i :${port}`);
apiLog.error(`Port ${port} (${protocol}) is already in use${detail}. Check with: lsof -i :${port}`);
} else {
console.error(`${protocol} server error:`, err.message);
apiLog.error(`${protocol} server error:`, err.message);
}
reject(err);
});
@@ -206,7 +209,7 @@ export async function startApi() {
const httpInstance = http.createServer(app);
await listenServer(httpInstance, env.port, 'HTTP');
server = httpInstance;
console.log(`API listening on port ${env.port} (HTTP)`);
apiLog.info(`API listening on port ${env.port} (HTTP)`);
if (env.httpsPort) {
try {
@@ -214,9 +217,9 @@ export async function startApi() {
const httpsInstance = https.createServer(tls, app);
await listenServer(httpsInstance, env.httpsPort, 'HTTPS');
httpsServer = httpsInstance;
console.log(`API listening on port ${env.httpsPort} (HTTPS self-signed)`);
apiLog.info(`API listening on port ${env.httpsPort} (HTTPS self-signed)`);
} catch (err) {
console.error('Failed to start HTTPS server:', err.message);
apiLog.error('Failed to start HTTPS server:', err.message);
}
}

View File

@@ -1,17 +1,18 @@
import chalk from 'chalk';
import { isEmpty, prettyJson } from '../../util/prettyJson.js';
import { writeErrorLog } from '../../util/errorLog.js';
import { createLogger, chalk } from '../../util/logger.js';
const httpLog = createLogger('http');
function logField(label, value, { skipEmpty = false } = {}) {
if (skipEmpty && isEmpty(value)) return;
const rendered = prettyJson(value);
const prefix = chalk.gray(` ${label}: `);
if (!rendered.includes('\n')) {
console.log(prefix + rendered);
httpLog.debug(prefix + rendered);
return;
}
console.log(prefix);
console.log(rendered.replace(/^/gm, ' '));
httpLog.debug(prefix + '\n' + rendered.replace(/^/gm, ' '));
}
function captureResponseBody(res) {
@@ -53,14 +54,22 @@ export const loggerMiddleware = (req, res, next) => {
else if (status >= 300) status = chalk.cyan(status);
else status = chalk.green(status);
console.log(`${method} ${url} ${status} ${chalk.gray(`(${duration}ms)`)}`);
const summary = `${method} ${url} ${status} ${chalk.gray(`(${duration}ms)`)}`;
if (res.statusCode >= 500) {
httpLog.error(summary);
} else if (res.statusCode >= 400) {
httpLog.warn(summary);
} else {
httpLog.info(summary);
}
logField('params', req.params ?? {}, { skipEmpty: true });
logField('query', req.query ?? {}, { skipEmpty: true });
if (req.headers['content-type']) {
console.log(chalk.gray(' content-type:'), chalk.cyan(req.headers['content-type']));
httpLog.debug(chalk.gray(' content-type: ') + chalk.cyan(req.headers['content-type']));
}
if (req.headers.authorization) {
console.log(chalk.gray(' authorization:'), chalk.cyan(req.headers.authorization));
httpLog.debug(chalk.gray(' authorization: ') + chalk.cyan(req.headers.authorization));
}
logField('body', req.body ?? {}, { skipEmpty: true });
logField('response', getBody());

View File

@@ -17,6 +17,7 @@ export default {
httpsPort: parseHttpsPort(process.env.HTTPS_PORT),
httpsKeyPath: process.env.HTTPS_KEY_PATH || resolve(__dirname, '../../certs/key.pem'),
httpsCertPath: process.env.HTTPS_CERT_PATH || resolve(__dirname, '../../certs/cert.pem'),
logLevel: process.env.LOG_LEVEL || 'debug',
bodyLimit: process.env.BODY_LIMIT || '100mb',
corsOrigins: (process.env.CORS_ORIGINS || 'http://localhost:5173,https://quixpos.com,https://app.quixpos.com')
.split(',')

View File

@@ -1,8 +1,10 @@
import chalk from 'chalk';
import LibDashStore from 'libdashstore';
import { MssqlProvider } from 'libdashstore/providers/mssql';
import { BetterSqlite3Provider } from 'libdashstore/providers/better-sqlite3';
import env from '../config/env.js';
import { createLogger, chalk } from '../util/logger.js';
const storeLog = createLogger('libstore');
let provider;
let store;
@@ -65,13 +67,11 @@ function wrapStoreWithTiming(rawStore) {
const start = Date.now();
try {
const result = await fn(...args);
console.log(
`${chalk.magenta('libstore')} ${namespace}.${method} ${chalk.gray(`(${Date.now() - start}ms)`)}`
);
storeLog.debug(`${namespace}.${method} ${chalk.gray(`(${Date.now() - start}ms)`)}`);
return result;
} catch (err) {
console.error(
`${chalk.magenta('libstore')} ${namespace}.${method} ${chalk.red('FAILED')} ` +
storeLog.error(
`${namespace}.${method} ${chalk.red('FAILED')} ` +
`${chalk.gray(`(${Date.now() - start}ms)`)} ${chalk.red(err.message)}`
);
throw err;
@@ -90,7 +90,7 @@ function wrapStoreWithTiming(rawStore) {
return await fn(...args);
} finally {
const duration = Date.now() - start;
console.log(`${chalk.magenta('libstore')} ${method} ${chalk.gray(`(${duration}ms)`)}`);
storeLog.info(`${method} ${chalk.gray(`(${duration}ms)`)}`);
}
};
}

View File

@@ -1,13 +1,16 @@
import './config/env.js';
import { startApi, stopApi } from './api/index.js';
import { closeStore } from './db/store.js';
import { createLogger } from './util/logger.js';
const sysLog = createLogger('system');
async function shutdown() {
await stopApi();
try {
await closeStore();
} catch (error) {
console.error('Failed to close database:', error);
sysLog.error('Failed to close database:', error);
process.exitCode = 1;
}
}
@@ -20,6 +23,6 @@ process.on('SIGTERM', () => {
});
startApi().catch((err) => {
console.error('Failed to start API:', err.message);
sysLog.error('Failed to start API:', err.message);
process.exit(1);
});

View File

@@ -2,6 +2,9 @@ import { appendFileSync, mkdirSync } from 'fs';
import { dirname, resolve } from 'path';
import { fileURLToPath } from 'url';
import { prettyJson } from '../util/prettyJson.js';
import { createLogger } from '../util/logger.js';
const log = createLogger('error-log');
const __dirname = dirname(fileURLToPath(import.meta.url));
const LOG_DIR = process.env.ERROR_LOG_DIR || resolve(__dirname, '../../logs/errors');
@@ -46,10 +49,10 @@ export function writeErrorLog(label, sections) {
}
appendFileSync(filePath, `${parts.join('\n')}\n`);
console.error(`[error-log] Wrote ${filePath}`);
log.info(`Wrote ${filePath}`);
return filePath;
} catch (err) {
console.error('[error-log] Failed to write error log:', err.message);
log.error('Failed to write error log:', err.message);
return null;
}
}

369
src/util/logger.js Normal file
View File

@@ -0,0 +1,369 @@
import util from 'node:util';
import defaultChalk, { Chalk } from 'chalk';
// Ensure color is preserved under PM2 / non-TTY environments unless NO_COLOR is set
if (!process.env.NO_COLOR && (process.env.FORCE_COLOR === undefined || process.env.FORCE_COLOR === '')) {
process.env.FORCE_COLOR = '3';
}
export const colorLevel = process.env.NO_COLOR ? 0 : (Number(process.env.FORCE_COLOR) || 3);
export const chalk = new Chalk({ level: colorLevel });
/**
* Log severity levels and their numeric weights.
*/
export const LogLevel = Object.freeze({
TRACE: 10,
DEBUG: 20,
INFO: 30,
WARN: 40,
ERROR: 50,
FATAL: 60,
SILENT: 100,
});
/**
* Map of string names to numeric levels.
*/
const LEVEL_VALUES = {
trace: LogLevel.TRACE,
debug: LogLevel.DEBUG,
info: LogLevel.INFO,
warn: LogLevel.WARN,
warning: LogLevel.WARN,
error: LogLevel.ERROR,
fatal: LogLevel.FATAL,
silent: LogLevel.SILENT,
};
/**
* Pre-styled severity tags padded to 5 characters.
*/
const SEVERITY_TAGS = {
[LogLevel.TRACE]: chalk.gray('TRACE'),
[LogLevel.DEBUG]: chalk.blue('DEBUG'),
[LogLevel.INFO]: chalk.green('INFO '),
[LogLevel.WARN]: chalk.yellow('WARN '),
[LogLevel.ERROR]: chalk.red.bold('ERROR'),
[LogLevel.FATAL]: chalk.bgRed.white.bold('FATAL'),
};
/**
* Predefined colors for common division names.
*/
const DIVISION_COLORS = {
api: chalk.cyan,
http: chalk.hex('#10b981'), // Emerald
store: chalk.magenta,
libstore: chalk.magenta,
db: chalk.blueBright,
auth: chalk.hex('#f59e0b'), // Amber
sse: chalk.hex('#8b5cf6'), // Purple
system: chalk.hex('#94a3b8'), // Slate
import: chalk.hex('#ec4899'), // Pink
conversation: chalk.hex('#06b6d4'), // Light cyan
worker: chalk.hex('#f97316'), // Orange
cron: chalk.hex('#eab308'), // Yellow
vfs: chalk.hex('#14b8a6'), // Teal
event: chalk.hex('#a855f7'), // Violet
};
/**
* Palette of vibrant chalk colors for dynamic divisions.
*/
const PALETTE = [
chalk.cyan,
chalk.magenta,
chalk.blueBright,
chalk.yellow,
chalk.greenBright,
chalk.hex('#f59e0b'),
chalk.hex('#8b5cf6'),
chalk.hex('#06b6d4'),
chalk.hex('#ec4899'),
chalk.hex('#10b981'),
chalk.hex('#3b82f6'),
chalk.hex('#f97316'),
chalk.hex('#14b8a6'),
chalk.hex('#a855f7'),
chalk.hex('#e879f9'),
chalk.hex('#22d3ee'),
];
/**
* Returns a cached or deterministically picked chalk styling function for a division name.
* @param {string} division
* @returns {(text: string) => string}
*/
const divisionColorCache = new Map();
function getDivisionStyle(division) {
const cached = divisionColorCache.get(division);
if (cached) return cached;
const lower = division.toLowerCase();
let style = DIVISION_COLORS[lower];
if (!style) {
let hash = 0;
for (let i = 0; i < division.length; i++) {
hash = (hash << 5) - hash + division.charCodeAt(i);
hash |= 0;
}
const index = Math.abs(hash) % PALETTE.length;
style = PALETTE[index];
}
const wrapped = (txt) => style.bold(txt);
divisionColorCache.set(division, wrapped);
return wrapped;
}
/**
* Formats a Date object into local timestamp: YYYY-MM-DD HH:mm:ss.SSS
* @param {Date} [date]
* @returns {string}
*/
export function formatTimestamp(date = new Date()) {
const y = date.getFullYear();
const m = String(date.getMonth() + 1).padStart(2, '0');
const d = String(date.getDate()).padStart(2, '0');
const hh = String(date.getHours()).padStart(2, '0');
const mm = String(date.getMinutes()).padStart(2, '0');
const ss = String(date.getSeconds()).padStart(2, '0');
const ms = String(date.getMilliseconds()).padStart(3, '0');
return `${y}-${m}-${d} ${hh}:${mm}:${ss}.${ms}`;
}
/**
* Parse string or number to numeric LogLevel.
* @param {string | number} val
* @param {number} [fallback=LogLevel.DEBUG]
* @returns {number}
*/
function parseLogLevel(val, fallback = LogLevel.DEBUG) {
if (typeof val === 'number') return val;
if (typeof val === 'string') {
const lower = val.trim().toLowerCase();
if (lower in LEVEL_VALUES) return LEVEL_VALUES[lower];
}
return fallback;
}
/**
* Global log level configuration. Defaults to LOG_LEVEL env var, or DEBUG in dev/test.
*/
let currentLogLevel = parseLogLevel(process.env.LOG_LEVEL, LogLevel.DEBUG);
export function setLogLevel(level) {
currentLogLevel = parseLogLevel(level, currentLogLevel);
}
export function getLogLevel() {
return currentLogLevel;
}
/**
* Formats a log line adhering to:
* time - severity - division - text
*
* @param {number} levelNumeric
* @param {string} division
* @param {any[]} args
* @returns {string}
*/
export function formatLogEntry(levelNumeric, division, args) {
const timeStr = chalk.gray(formatTimestamp());
const sep = chalk.gray(' - ');
const severityStr = SEVERITY_TAGS[levelNumeric] || chalk.white(String(levelNumeric).padEnd(5));
const divisionStr = getDivisionStyle(division)(division);
const prefix = `${timeStr}${sep}${severityStr}${sep}${divisionStr}${sep}`;
// Format remaining arguments (handles %s specifiers, Error objects, JSON structures, etc.)
const formattedText = util.formatWithOptions(
{ colors: colorLevel > 0 },
...args
);
if (!formattedText.includes('\n')) {
return prefix + formattedText;
}
const lines = formattedText.split('\n');
const indent = ' ';
return prefix + lines[0] + '\n' + lines.slice(1).map((l) => indent + l).join('\n');
}
/**
* Modern Logger instance. Supports scoped divisions, child loggers, and timers.
*/
export class Logger {
/**
* @param {string} [division='app']
* @param {{ level?: string | number, stream?: (msg: string) => void }} [options={}]
*/
constructor(division = 'app', options = {}) {
this.divisionName = division;
this.customLevel = options.level ? parseLogLevel(options.level) : null;
this._write = options.stream || null;
this._timers = new Map();
}
/**
* Effective log level for this instance.
*/
get level() {
return this.customLevel ?? currentLogLevel;
}
set level(val) {
this.customLevel = parseLogLevel(val);
}
/**
* Checks if a level is enabled.
* @param {number} levelNumeric
* @returns {boolean}
*/
isLevelEnabled(levelNumeric) {
return this.level <= levelNumeric;
}
/**
* Core log method.
* @param {number} levelNumeric
* @param {string | any} firstArg
* @param {...any} rest
*/
log(levelNumeric, firstArg, ...rest) {
if (!this.isLevelEnabled(levelNumeric)) return;
let division = this.divisionName;
let args;
// If this is the root/unscoped logger ('app') and the first arg looks like an explicit division:
if (
this.divisionName === 'app' &&
typeof firstArg === 'string' &&
firstArg.length > 0 &&
!firstArg.includes(' ') &&
rest.length > 0
) {
division = firstArg;
args = rest;
} else {
args = [firstArg, ...rest];
}
const output = formatLogEntry(levelNumeric, division, args);
if (this._write) {
this._write(output);
return;
}
if (levelNumeric >= LogLevel.ERROR) {
console.error(output);
} else if (levelNumeric >= LogLevel.WARN) {
console.warn(output);
} else {
console.log(output);
}
}
trace(...args) {
this.log(LogLevel.TRACE, ...args);
}
debug(...args) {
this.log(LogLevel.DEBUG, ...args);
}
info(...args) {
this.log(LogLevel.INFO, ...args);
}
warn(...args) {
this.log(LogLevel.WARN, ...args);
}
error(...args) {
this.log(LogLevel.ERROR, ...args);
}
fatal(...args) {
this.log(LogLevel.FATAL, ...args);
}
/**
* Starts a timer for a given label.
* @param {string} label
*/
time(label) {
this._timers.set(label, Date.now());
}
/**
* Ends a timer and logs duration at DEBUG or INFO level.
* @param {string} label
* @param {string} [msg]
* @param {'debug' | 'info'} [level='debug']
*/
timeEnd(label, msg, level = 'debug') {
const start = this._timers.get(label);
this._timers.delete(label);
const duration = start ? Date.now() - start : 0;
const text = msg ? `${msg} (${duration}ms)` : `${label} completed in ${duration}ms`;
if (level === 'info') {
this.info(text);
} else {
this.debug(text);
}
}
/**
* Creates a scoped child logger for a subdivision or new division.
* @param {string} subdivision
* @param {object} [options]
* @returns {Logger}
*/
child(subdivision, options = {}) {
const newDivision =
this.divisionName && this.divisionName !== 'app'
? `${this.divisionName}:${subdivision}`
: subdivision;
return new Logger(newDivision, {
level: options.level ?? this.customLevel,
stream: options.stream ?? this._write,
});
}
/**
* Alias for child / scoped logger.
* @param {string} division
* @returns {Logger}
*/
for(division) {
return new Logger(division, {
level: this.customLevel,
stream: this._write,
});
}
}
/**
* Root logger instance.
*/
export const logger = new Logger('app');
/**
* Creates a scoped logger instance for a given division.
* @param {string} division
* @param {object} [options]
* @returns {Logger}
*/
export function createLogger(division, options) {
return new Logger(division, options);
}
export default logger;