admin/39948-vm
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

improved logging

Browse Source
This commit is contained in:
Dmitri 2026-07-02 07:38:38 +02:00
parent cc5dbee5be
commit ed328ee06c
13 changed files with 141 additions and 256 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

9
backend/src/db/db-config.ts
View File

@ -1,10 +1,15 @@
import '../load-env.ts';
import { logger } from '../utils/logger.ts';
import type { DatabaseConfigMap } from '../types/index.ts';
const sequelizeStorage = 'sequelize';
const migrationStorageTableName = 'SequelizeMeta';
type DatabaseLogging = NonNullable<DatabaseConfigMap['production']['logging']>;
function logSql(message: string): void {
logger.debug({ sql: message }, 'Sequelize query');
}
function readEnvPort(name: string): number | undefined {
const value = process.env[name];
if (!value) return undefined;
@ -53,12 +58,12 @@ const dbConfig: DatabaseConfigMap = {
password: '',
database: 'db_tour_builder_platform',
host: process.env.DB_HOST || 'localhost',
logging: console.log,
logging: logSql,
seederStorage: sequelizeStorage,
migrationStorage: sequelizeStorage,
migrationStorageTableName,
},
dev_stage: createEnvDatabaseConfig(console.log),
dev_stage: createEnvDatabaseConfig(logSql),
};
export default dbConfig;

13
backend/src/helpers.ts
View File

@ -18,6 +18,7 @@ import type {
RouteIdRequestLike,
} from './types/index.ts';
import { logger } from './utils/logger.ts';
import { getRequestLogger } from './utils/request-context.ts';
import { assertBodyIdMatchesRouteId } from './utils/request-body.ts';
function wrapAsync<
@ -39,7 +40,7 @@ function wrapAsync<
const commonErrorHandler: ErrorRequestHandler = (
error: RouteError,
_req: Request,
req: Request,
res: Response,
_next: NextFunction,
): Response => {
@ -59,7 +60,15 @@ const commonErrorHandler: ErrorRequestHandler = (
return res.status(statusCode).send(error.message);
}
logger.error({ err: error }, 'Unhandled route error');
const requestLog = getRequestLogger(req) ?? logger;
requestLog.error(
{
err: error,
method: req.method,
url: req.originalUrl || req.url,
},
'Route handler failed',
);
return res.status(500).send('Internal server error');
};

22
backend/src/index.ts
View File

@ -46,7 +46,6 @@ import rolesRoutesModule from './routes/roles.ts';
import runtimeAccessRoutesModule from './routes/runtime-access.ts';
import runtimeContextRoutesModule from './routes/runtime-context.ts';
import searchRoutesModule from './routes/search.ts';
import sqlRoutesModule from './routes/sql.ts';
import tourPagesRoutesModule from './routes/tour_pages.ts';
import usersRoutesModule from './routes/users.ts';
import RuntimePresentationAccessService from './services/runtime-presentation-access.ts';
@ -60,8 +59,14 @@ import type {
SwaggerHostMiddleware,
SwaggerUiModuleWithHost,
} from './types/index.ts';
import { logger, requestLogger } from './utils/logger.ts';
import {
exitAfterLogging,
logger,
registerProcessErrorHandlers,
requestLogger,
} from './utils/logger.ts';
import {
getRequestLogger,
getRuntimeContext,
setCurrentUser,
setRuntimePublicRequest,
@ -70,6 +75,7 @@ import {
const app = express();
const swaggerUiWithHost: SwaggerUiModuleWithHost = swaggerUI;
registerProcessErrorHandlers();
initializePermissionsMiddleware();
function isExpressRouter(value: unknown): value is ExpressRouter {
@ -140,7 +146,6 @@ const runtimeContextRoutes = getExpressRouter(
runtimeContextRoutesModule,
);
const searchRoutes = getExpressRouter('search', searchRoutesModule);
const sqlRoutes = getExpressRouter('sql', sqlRoutesModule);
const tourPagesRoutes = getExpressRouter('tour_pages', tourPagesRoutesModule);
const usersRoutes = getExpressRouter('users', usersRoutesModule);
@ -399,7 +404,6 @@ app.use('/api/project-ui-control-settings', projectUiControlSettingsRoutes);
app.use('/api/publish', jwtAuth, publishRoutes);
app.use('/api/search', jwtAuth, searchLimiter, searchRoutes);
app.use('/api/sql', jwtAuth, sqlRoutes);
const publicDir = path.join(process.cwd(), 'public');
@ -414,7 +418,11 @@ if (fs.existsSync(publicDir)) {
// Generic error handler
const appErrorHandler: AppErrorHandler = (err, req, res, _next) => {
if (!res.headersSent) {
logger.error({ err, url: req.url, method: req.method }, 'Unhandled error');
const requestLog = getRequestLogger(req) ?? logger;
requestLog.error(
{ err, url: req.url, method: req.method },
'Express error middleware caught unhandled error',
);
res.status(500).json({ message: 'Internal server error' });
}
};
@ -443,9 +451,7 @@ server.on('error', (err: NodeJS.ErrnoException) => {
{ err, port: PORT, env: process.env.NODE_ENV || 'development' },
'Server failed to start',
);
setImmediate(() => {
process.exit(1);
});
exitAfterLogging();
});
export default app;

34
backend/src/middlewares/check-permissions.ts
View File

@ -16,36 +16,26 @@ let publicRoleCache: RoleWithPermissionLoader | null = null;
// Function to asynchronously fetch and cache the 'Public' role
async function fetchAndCachePublicRole(): Promise<void> {
try {
// Use RolesDBApi to find the role by name 'Public'
publicRoleCache = await RolesDBApi.findBy({ name: 'Public' });
// Use RolesDBApi to find the role by name 'Public'
publicRoleCache = await RolesDBApi.findBy({ name: 'Public' });
if (!publicRoleCache) {
logger.warn(
{ role: 'Public' },
'Role not found during permissions middleware startup',
);
// The system might not function correctly without this role. May need to throw an error or use a fallback stub.
} else {
logger.info(
{ role: 'Public', roleId: publicRoleCache.id },
'Role loaded and cached',
);
}
} catch (error) {
logger.error(
{ err: error, role: 'Public' },
'Error fetching role during permissions middleware startup',
if (!publicRoleCache) {
logger.warn(
{ role: 'Public' },
'Role not found during permissions middleware startup',
);
} else {
logger.info(
{ role: 'Public', roleId: publicRoleCache.id },
'Role loaded and cached',
);
// Handle the error during startup fetch
throw error; // Important to know if the app can proceed without the Public role
}
}
function initializePermissionsMiddleware(): void {
fetchAndCachePublicRole().catch((error) => {
logger.error(
{ err: error },
{ err: error, role: 'Public' },
'Critical error during permissions middleware initialization',
);
});

114
backend/src/routes/sql.ts
View File

@ -1,114 +0,0 @@
import express from 'express';
import db from '../db/models/index.ts';
import { wrapAsync } from '../helpers.ts';
import type {
ExecuteSqlErrorResponse,
ExecuteSqlRequestBody,
ExecuteSqlSuccessResponse,
SqlQueryRow,
} from '../types/index.ts';
import { getCurrentUser } from '../utils/request-context.ts';
import { validateReadOnlySql } from '../utils/sqlValidator.ts';
const router = express.Router();
const MAX_SQL_LENGTH = 5000;
const MAX_SQL_ROWS = 1000;
const SQL_TIMEOUT_MS = 5000;
function isExecuteSqlRequestBody(body: unknown): body is ExecuteSqlRequestBody {
return (
body !== null &&
typeof body === 'object' &&
'sql' in body &&
typeof body.sql === 'string'
);
}
/**
* @swagger
* /api/sql:
* post:
* security:
* - bearerAuth: []
* summary: Execute a SELECT-only SQL query
* description: Executes a read-only SQL query and returns rows.
* requestBody:
* required: true
* content:
* application/json:
* schema:
* type: object
* properties:
* sql:
* type: string
* required:
* - sql
* responses:
* 200:
* description: Query result
* 400:
* description: Invalid SQL
* 401:
* $ref: "#/components/responses/UnauthorizedError"
* 500:
* description: Internal server error
*/
router.post(
'/',
wrapAsync(async (req, res) => {
const currentUser = getCurrentUser(req);
const isAdminUser = Boolean(
currentUser &&
currentUser.app_role &&
(currentUser.app_role.name === 'Administrator' ||
currentUser.app_role.globalAccess === true),
);
if (!isAdminUser) {
const response: ExecuteSqlErrorResponse = {
error: 'Only administrators can execute SQL queries',
};
return res.status(403).json(response);
}
const body: unknown = req.body;
if (!isExecuteSqlRequestBody(body)) {
const response: ExecuteSqlErrorResponse = {
error: 'SQL query must be a non-empty string',
};
return res.status(400).json(response);
}
const validation = validateReadOnlySql(body.sql, {
maxLength: MAX_SQL_LENGTH,
});
if (!validation.valid) {
const response: ExecuteSqlErrorResponse = { error: validation.error };
return res.status(400).json(response);
}
const wrappedSql = `SELECT * FROM (${validation.normalized}) AS query_result LIMIT ${MAX_SQL_ROWS}`;
const rows = await db.sequelize.transaction(async (transaction) => {
await db.sequelize.query(`SET LOCAL statement_timeout = ${SQL_TIMEOUT_MS}`, {
transaction,
});
return db.sequelize.query<SqlQueryRow>(wrappedSql, {
transaction,
type: db.Sequelize.QueryTypes.SELECT,
});
});
const response: ExecuteSqlSuccessResponse = {
rows,
meta: {
maxRows: MAX_SQL_ROWS,
statementTimeoutMs: SQL_TIMEOUT_MS,
},
};
return res.status(200).json(response);
}),
);
export default router;

8
backend/src/types/db-models.ts
View File

@ -34,7 +34,6 @@ import type {
ProductionPresentationProject,
PaginatedResult,
QueryWhere,
SqlQueryRow,
RuntimeProjectInclude,
RuntimeEnvironment,
TourPageRecord,
@ -53,6 +52,13 @@ import type {
} from './index.ts';
import type { QueryTypes, SyncOptions, Transaction } from 'sequelize';
export type SqlQueryScalar = string | number | boolean | Date | Buffer | null;
export type SqlQueryValue =
| SqlQueryScalar
| ReadonlyArray<SqlQueryScalar>
| Readonly<Record<string, SqlQueryScalar>>;
export type SqlQueryRow = Record<string, SqlQueryValue>;
export interface SequelizeQueryOptions {
transaction?: Transaction;
type?: QueryTypes.SELECT;

13
backend/src/types/index.ts
View File

@ -406,19 +406,6 @@ export type {
RouteIdRequestBody,
RouteIdRequestLike,
} from './http.ts';
export type {
ExecuteSqlErrorResponse,
ExecuteSqlRequestBody,
ExecuteSqlResponseMeta,
ExecuteSqlSuccessResponse,
InvalidSqlValidationResult,
ReadOnlySqlValidationOptions,
SqlQueryRow,
SqlQueryScalar,
SqlValidationResult,
SqlQueryValue,
ValidSqlValidationResult,
} from './sql.ts';
export type { NodeEnvironment, ValidatedEnvironment } from './env.ts';
export type {
DbModels,

43
backend/src/types/sql.ts
View File

@ -1,43 +0,0 @@
export interface ReadOnlySqlValidationOptions {
maxLength?: number;
}
export interface ExecuteSqlRequestBody {
sql: string;
}
export type SqlQueryScalar = string | number | boolean | Date | Buffer | null;
export type SqlQueryValue =
| SqlQueryScalar
| ReadonlyArray<SqlQueryScalar>
| Readonly<Record<string, SqlQueryScalar>>;
export type SqlQueryRow = Record<string, SqlQueryValue>;
export interface ExecuteSqlResponseMeta {
maxRows: number;
statementTimeoutMs: number;
}
export interface ExecuteSqlSuccessResponse {
rows: SqlQueryRow[];
meta: ExecuteSqlResponseMeta;
}
export interface ExecuteSqlErrorResponse {
error: string;
}
export interface InvalidSqlValidationResult {
valid: false;
error: string;
}
export interface ValidSqlValidationResult {
valid: true;
normalized: string;
}
export type SqlValidationResult =
| InvalidSqlValidationResult
| ValidSqlValidationResult;

5
backend/src/utils/env-validation.ts
View File

@ -1,5 +1,6 @@
import Joi from 'joi';
import { logger } from './logger.ts';
import type { NodeEnvironment, ValidatedEnvironment } from '../types/index.ts';
type EnvBooleanString = 'true' | 'false';
@ -153,12 +154,12 @@ function validateEnv(): ValidatedEnvironment {
const messages = result.error.details.map(
(detail) => ` - ${detail.message}`,
);
console.error(`Environment validation failed:\n${messages.join('\n')}`);
logger.error({ errors: messages }, 'Environment validation failed');
if (process.env.NODE_ENV === 'production') {
process.exit(1);
} else {
console.warn('Continuing with default values in non-production mode');
logger.warn('Continuing with default values in non-production mode');
}
}

8
backend/src/utils/index.ts
View File

@ -6,5 +6,11 @@ export {
UnauthorizedError,
ValidationError,
} from './errors.ts';
export { logger, requestLogger } from './logger.ts';
export {
exitAfterLogging,
logger,
normalizeLoggedError,
registerProcessErrorHandlers,
requestLogger,
} from './logger.ts';
export { envSchema, validateEnv } from './env-validation.ts';

60
backend/src/utils/logger.ts
View File

@ -38,6 +38,58 @@ const logger = pino(
: baseLoggerOptions,
);
let processErrorHandlersRegistered = false;
let processExitScheduled = false;
function normalizeLoggedError(reason: unknown): Error {
if (reason instanceof Error) return reason;
const message =
typeof reason === 'string'
? reason
: 'Non-Error value thrown or rejected';
return new Error(message, { cause: reason });
}
function exitAfterLogging(exitCode = 1): void {
if (processExitScheduled) return;
processExitScheduled = true;
const fallback = setTimeout(() => {
process.exit(exitCode);
}, 250);
fallback.unref();
logger.flush(() => {
clearTimeout(fallback);
process.exit(exitCode);
});
}
function registerProcessErrorHandlers(): void {
if (processErrorHandlersRegistered) return;
processErrorHandlersRegistered = true;
process.on('uncaughtException', (error) => {
logger.fatal(
{ err: normalizeLoggedError(error) },
'Uncaught exception, shutting down process',
);
exitAfterLogging();
});
process.on('unhandledRejection', (reason) => {
logger.fatal(
{ err: normalizeLoggedError(reason) },
'Unhandled promise rejection, shutting down process',
);
exitAfterLogging();
});
}
const requestLogger: RequestHandler = (req, res, next) => {
const headerRequestId = req.headers['x-request-id'];
const requestId =
@ -72,4 +124,10 @@ const requestLogger: RequestHandler = (req, res, next) => {
next();
};
export { logger, requestLogger };
export {
exitAfterLogging,
logger,
normalizeLoggedError,
registerProcessErrorHandlers,
requestLogger,
};

47
backend/src/utils/sqlValidator.ts
View File

@ -1,47 +0,0 @@
import type {
ReadOnlySqlValidationOptions,
SqlValidationResult,
} from '../types/index.ts';
const DEFAULT_MAX_LENGTH = 5000;
const RESTRICTED_FUNCTIONS = /\b(pg_sleep|set_config|copy)\b/i;
function validateReadOnlySql(
sql: unknown,
options: ReadOnlySqlValidationOptions = {},
): SqlValidationResult {
const maxLength = options.maxLength ?? DEFAULT_MAX_LENGTH;
if (typeof sql !== 'string' || !sql.trim()) {
return { valid: false, error: 'SQL query must be a non-empty string' };
}
if (sql.length > maxLength) {
return {
valid: false,
error: `SQL query is too long (max ${maxLength} characters)`,
};
}
const normalized = sql.trim().replace(/;+\s*$/, '');
if (!/^(select|with)\b/i.test(normalized)) {
return { valid: false, error: 'Only SELECT statements are allowed' };
}
if (normalized.includes(';')) {
return { valid: false, error: 'Only a single statement is allowed' };
}
if (/--|\/\*/.test(normalized)) {
return { valid: false, error: 'SQL comments are not allowed' };
}
if (RESTRICTED_FUNCTIONS.test(normalized)) {
return { valid: false, error: 'Restricted SQL function detected' };
}
return { valid: true, normalized };
}
export { validateReadOnlySql };

21
backend/tests/helpers.test.ts
View File

@ -2,6 +2,7 @@ import assert from 'node:assert/strict';
import test from 'node:test';
import { assertRouteIdMatchesBody } from '../src/helpers.ts';
import { normalizeLoggedError } from '../src/utils/logger.ts';
void test('assertRouteIdMatchesBody allows matching top-level body id', () => {
assert.doesNotThrow(() =>
@ -31,3 +32,23 @@ void test('assertRouteIdMatchesBody rejects mismatched body id', () => {
/Request body id does not match route id/,
);
});
void test('normalizeLoggedError preserves Error instances', () => {
const error = new Error('Original failure');
assert.equal(normalizeLoggedError(error), error);
});
void test('normalizeLoggedError wraps non-Error values', () => {
const reason = { code: 'E_UNKNOWN' };
const error = normalizeLoggedError(reason);
assert.equal(error.message, 'Non-Error value thrown or rejected');
assert.equal(error.cause, reason);
});
void test('normalizeLoggedError uses string reasons as messages', () => {
const error = normalizeLoggedError('plain rejection');
assert.equal(error.message, 'plain rejection');
});