Log perf logs in HTTP requests
MODIFY
src/assets/schemas/performance/performance.json
src/assets/schemas/performance/performance.json
"title": "Validate the performance object",
"type": "object",
"properties": {
+ "id": {
+ "type": "string"
+ },
"tenantSubdomain": {
"type": "string"
},

MODIFY
src/server/ExpressUtils.ts
src/server/ExpressUtils.ts
@@ -5,14 +5,12 @@ import Configuration from '../utils/Configuration';
import Constants from '../utils/Constants';
import Logging from '../utils/Logging';
import { StatusCodes } from 'http-status-codes';
-import TenantStorage from '../storage/mongodb/TenantStorage';
import Utils from '../utils/Utils';
import bodyParser from 'body-parser';
import bodyParserXml from 'body-parser-xml';
import cors from 'cors';
import helmet from 'helmet';
import hpp from 'hpp';
-import jwt from 'jsonwebtoken';
import locale from 'locale';
import morgan from 'morgan';
@@ -60,8 +58,6 @@ export default class ExpressUtils {
// Bind to express app
app.use(CFLog.logNetwork);
}
- // Log Express Request
- app.use(this.logExpressRequest.bind(this));
return app;
}
@@ -72,69 +68,7 @@ export default class ExpressUtils {
app.use(Logging.traceExpressError.bind(this));
}
- private static async logExpressRequest(req: Request, res: Response, next: NextFunction): Promise<void> {
- // Decode the Token
- const decodedToken = this.getDecodedTokenFromHttpRequest(req);
- // Get the Tenant
- const tenantID = await this.retrieveTenantFromHttpRequest(req, decodedToken);
- req['tenantID'] = tenantID;
- await Logging.traceExpressRequest(tenantID, decodedToken, req, res, next);
- }
-
private static healthCheckService(req: Request, res: Response, next: NextFunction): void {
res.sendStatus(StatusCodes.OK);
}
-
- private static getDecodedTokenFromHttpRequest(req: Request): string | { [key: string]: any; } {
- // Retrieve Tenant ID from JWT token if available
- try {
- if (req.headers?.authorization.startsWith('Bearer')) {
- // Decode the token (REST)
- try {
- return jwt.decode(req.headers.authorization.slice(7));
- } catch (error) {
- // Try Base 64 decoding (OCPI)
- return JSON.parse(Buffer.from(req.headers.authorization.slice(7), 'base64').toString());
- }
- }
- } catch (error) {
- // Do nothing
- }
- }
-
- private static async retrieveTenantFromHttpRequest(req: Request, decodedToken: any): Promise<string> {
- // Try from Token
- if (decodedToken) {
- // REST
- if (Utils.objectHasProperty(decodedToken, 'tenantID')) {
- return decodedToken.tenantID;
- }
- // OCPI
- if (Utils.objectHasProperty(decodedToken, 'tid')) {
- const tenant = await TenantStorage.getTenantBySubdomain(decodedToken.tid);
- if (tenant) {
- return tenant.id;
- }
- }
- }
- // Try from body
- if (req.body?.tenant !== '') {
- const tenant = await TenantStorage.getTenantBySubdomain(req.body.tenant);
- if (tenant) {
- return tenant.id;
- }
- }
- // Try from host header
- if (req.headers?.host) {
- const hostParts = req.headers.host.split('.');
- if (hostParts.length > 1) {
- // Try with the first param
- const tenant = await TenantStorage.getTenantBySubdomain(hostParts[0]);
- if (tenant) {
- return tenant.id;
- }
- }
- }
- return Constants.DEFAULT_TENANT;
- }
}

MODIFY
src/server/ocpi/AbstractOCPIService.ts
src/server/ocpi/AbstractOCPIService.ts
@@ -71,9 +71,6 @@ export default abstract class AbstractOCPIService {
return `${this.role}/${this.version}/`;
}
- /**
- * Return Version of OCPI Service
- */
public getVersion(): string {
return this.version;
}
@@ -106,13 +103,6 @@ export default abstract class AbstractOCPIService {
next();
}
- /**
- * Send Supported Endpoints
- *
- * @param req
- * @param res
- * @param next
- */
// eslint-disable-next-line @typescript-eslint/no-unused-vars
public getSupportedEndpoints(req: TenantIdHoldingRequest, res: Response, next: NextFunction): void {
const fullUrl = this.getServiceUrl(req);
@@ -126,14 +116,6 @@ export default abstract class AbstractOCPIService {
res.json(OCPIUtils.success({ 'version': this.getVersion(), 'endpoints': supportedEndpoints }));
}
- /**
- * Process Endpoint action
- *
- * @param action
- * @param req
- * @param res
- * @param next
- */
public async processEndpointAction(action: ServerAction, req: TenantIdHoldingRequest, res: Response, next: NextFunction): Promise<void> {
try {
const registeredEndpoints = this.getRegisteredEndpoints();

MODIFY
src/server/ocpi/OCPIServer.ts
src/server/ocpi/OCPIServer.ts
@@ -4,6 +4,7 @@ import { Application, NextFunction, Request, Response } from 'express';
import CPOService211 from './ocpi-services-impl/ocpi-2.1.1/CPOService';
import EMSPService211 from './ocpi-services-impl/ocpi-2.1.1/EMSPService';
import ExpressUtils from '../ExpressUtils';
+import Logging from '../../utils/Logging';
import OCPIServiceConfiguration from '../../types/configuration/OCPIServiceConfiguration';
import OCPIServices from './OCPIServices';
import { ServerUtils } from '../ServerUtils';
@@ -20,6 +21,8 @@ export default class OCPIServer {
this.ocpiRestConfig = ocpiRestConfig;
// Initialize express app
this.expressApplication = ExpressUtils.initApplication(null, ocpiRestConfig.debug);
+ // Log Express Request
+ this.expressApplication.use(Logging.traceExpressRequest.bind(this));
// New OCPI Services Instances
const ocpiServices = new OCPIServices(this.ocpiRestConfig);
// OCPI versions

MODIFY
src/server/ocpp/soap/SoapCentralSystemServer.ts
src/server/ocpp/soap/SoapCentralSystemServer.ts
@@ -27,6 +27,8 @@ export default class SoapCentralSystemServer extends CentralSystemServer {
super(centralSystemConfig, chargingStationConfig);
// Initialize express app
this.expressApplication = ExpressUtils.initApplication(null, centralSystemConfig.debug);
+ // Log Express Request
+ this.expressApplication.use(Logging.traceExpressRequest.bind(this));
// Initialize the HTTP server
this.httpServer = ServerUtils.createHttpServer(this.centralSystemConfig, this.expressApplication);
}

MODIFY
src/server/odata/ODataServer.ts
src/server/odata/ODataServer.ts
@@ -2,6 +2,7 @@ import express, { NextFunction, Request, Response } from 'express';
import Configuration from '../../utils/Configuration';
import ExpressUtils from '../ExpressUtils';
+import Logging from '../../utils/Logging';
import ODataRestAdapter from './ODataRestAdapter';
import ODataSchema from './odata-schema/ODataSchema';
import ODataServerFactory from '../odata/ODataServerFactory';
@@ -20,6 +21,8 @@ export default class ODataServer {
this.oDataServerConfig = oDataServerConfig;
// Initialize express app
this.expressApplication = ExpressUtils.initApplication(null, oDataServerConfig.debug);
+ // Log Express Request
+ this.expressApplication.use(Logging.traceExpressRequest.bind(this));
// Get URL of the CentralSystemRestServer
const restConf = Configuration.getCentralSystemRestServerConfig();
const restServerUrl = `${restConf.protocol}://${restConf.host}:${restConf.port}/`;

MODIFY
src/server/oicp/OICPServer.ts
src/server/oicp/OICPServer.ts
import { Application, NextFunction, Response } from 'express';
import ExpressUtils from '../ExpressUtils';
+import Logging from '../../utils/Logging';
import OICPServiceConfiguration from '../../types/configuration/OICPServiceConfiguration';
import OICPServices from './OICPServices';
import { ServerUtils } from '../ServerUtils';
@@ -17,6 +18,8 @@ export default class OICPServer {
this.oicpRestConfig = oicpRestConfig;
// Initialize express app
this.expressApplication = ExpressUtils.initApplication(null, oicpRestConfig.debug);
+ // Log Express Request
+ this.expressApplication.use(Logging.traceExpressRequest.bind(this));
// New OICP Services Instances
const oicpServices = new OICPServices(this.oicpRestConfig);
// Register all services in express

MODIFY
src/server/rest/CentralRestServer.ts
src/server/rest/CentralRestServer.ts
@@ -50,14 +50,9 @@ export default class CentralRestServer {
AuthService.authenticate(),
CentralRestServerService.restServiceSecured.bind(this));
// Util API
- this.expressApplication.all('/client/util/:action', CentralRestServerService.restServiceUtil.bind(this));
- // Workaround URL encoding issue
- this.expressApplication.all('/client%2Futil%2FFirmwareDownload%3FFileName%3Dr7_update_3.3.0.12_d4.epk', async (req: Request, res: Response, next: NextFunction) => {
- req.url = decodeURIComponent(req.originalUrl);
- req.params.action = 'FirmwareDownload';
- req.query.FileName = 'r7_update_3.3.0.12_d4.epk';
- await CentralRestServerService.restServiceUtil(req, res, next);
- });
+ this.expressApplication.all('/client/util/:action',
+ Logging.traceExpressRequest.bind(this),
+ CentralRestServerService.restServiceUtil.bind(this));
// Post init
ExpressUtils.postInitApplication(this.expressApplication);
// Create HTTP server to serve the express app

MODIFY
src/server/rest/CentralRestServerService.ts
src/server/rest/CentralRestServerService.ts
@@ -322,6 +322,7 @@ export default class CentralRestServerService {
return;
}
try {
+ await Logging.traceExpressRequest(req, res, next);
// Get the action
const handleRequest = RequestMapper.getInstanceFromHTTPVerb(req.method).getActionFromPath(action);
// Execute

MODIFY
src/server/rest/v1/router/GlobalRouter.ts
src/server/rest/v1/router/GlobalRouter.ts
@@ -8,6 +8,7 @@ import CarRouter from './api/CarRouter';
import ChargingStationRouter from './api/ChargingStationRouter';
import CompanyRouter from './api/CompanyRouter';
import ConnectionRouter from './api/ConnectionRouter';
+import Logging from '../../../../utils/Logging';
import LoggingRouter from './api/LoggingRouter';
import NotificationRouter from './api/NotificationRouter';
import OCPIEndpointRouter from './api/OCPIEndpointRouter';
@@ -43,6 +44,7 @@ export default class GlobalRouter {
this.router.use('/api',
AuthService.authenticate(),
AuthService.checkSessionHash.bind(this),
+ Logging.traceExpressRequest.bind(this),
[
new AssetRouter().buildRoutes(),
new BillingRouter().buildRoutes(),

MODIFY
src/storage/mongodb/PerformanceStorage.ts
src/storage/mongodb/PerformanceStorage.ts
import global, { FilterParams } from '../../types/GlobalType';
import Constants from '../../utils/Constants';
+import DatabaseUtils from './DatabaseUtils';
import { DeletedResult } from '../../types/DataResult';
import PerformanceRecord from '../../types/Performance';
import PerformanceValidatorStorage from './validator/PerformanceValidatorStorage';
import Utils from '../../utils/Utils';
export default class PerformanceStorage {
- public static async savePerformanceRecord(performanceRecord: PerformanceRecord): Promise<void> {
+ public static async savePerformanceRecord(performanceRecord: PerformanceRecord): Promise<string> {
// Remove default Tenant
if (!performanceRecord.tenantSubdomain || performanceRecord.tenantSubdomain === Constants.DEFAULT_TENANT) {
delete performanceRecord.tenantSubdomain;
@@ -16,8 +17,26 @@ export default class PerformanceStorage {
performanceRecord = PerformanceValidatorStorage.getInstance().validatePerformance(
performanceRecord as unknown as Record<string, unknown>);
// Insert
- await global.database.getCollection(Constants.DEFAULT_TENANT, 'performances')
+ const result = await global.database.getCollection(Constants.DEFAULT_TENANT, 'performances')
.insertOne(performanceRecord);
+ // Set
+ performanceRecord.id = result.insertedId.toString();
+ return performanceRecord.id;
+ }
+
+ public static async updatePerformanceRecord(performanceRecord: PerformanceRecord): Promise<void> {
+ // Validate
+ performanceRecord = PerformanceValidatorStorage.getInstance().validatePerformance(
+ performanceRecord as unknown as Record<string, unknown>);
+ // Convert to ObjectID
+ performanceRecord['_id'] = DatabaseUtils.convertToObjectID(performanceRecord.id);
+ delete performanceRecord.id;
+ // Update
+ await global.database.getCollection(Constants.DEFAULT_TENANT, 'performances').findOneAndUpdate(
+ { _id: performanceRecord['_id'] },
+ { $set: performanceRecord },
+ { upsert: true, returnDocument: 'after' }
+ );
}
public static async deletePerformanceRecords(params?: { deleteUpToDate: Date }): Promise<DeletedResult> {

MODIFY
src/storage/mongodb/TenantStorage.ts
src/storage/mongodb/TenantStorage.ts
@@ -88,10 +88,14 @@ export default class TenantStorage {
{ upsert: true, returnDocument: 'after' });
// Save Logo
if (saveLogo) {
- await TenantStorage.saveTenantLogo(tenantMDB._id.toString(), tenantToSave.logo);
+ // Modify
+ await global.database.getCollection<any>(Constants.DEFAULT_TENANT, 'tenantlogos').findOneAndUpdate(
+ { '_id': tenantMDB._id },
+ { $set: { logo: tenantToSave.logo } },
+ { upsert: true });
}
// Debug
- await Logging.traceDatabaseRequestEnd(Constants.DEFAULT_TENANT_OBJECT, MODULE_NAME, 'saveTenant', startTime, tenantMDB);
+ await Logging.traceDatabaseRequestEnd(Constants.DEFAULT_TENANT_OBJECT, MODULE_NAME, 'saveTenant', startTime, { tenant: tenantMDB, logo: tenantToSave.logo });
return tenantFilter._id.toString();
}
@@ -251,16 +255,4 @@ export default class TenantStorage {
logo: tenantLogoMDB ? tenantLogoMDB.logo : null
};
}
-
- private static async saveTenantLogo(tenantID: string, tenantLogoToSave: string): Promise<void> {
- // Debug
- const startTime = Logging.traceDatabaseRequestStart();
- // Modify
- await global.database.getCollection<any>(Constants.DEFAULT_TENANT, 'tenantlogos').findOneAndUpdate(
- { '_id': DatabaseUtils.convertToObjectID(tenantID) },
- { $set: { logo: tenantLogoToSave } },
- { upsert: true });
- // Debug
- await Logging.traceDatabaseRequestEnd(Constants.DEFAULT_TENANT_OBJECT, MODULE_NAME, 'saveTenantLogo', startTime, tenantLogoToSave);
- }
}

MODIFY
src/types/Performance.ts
src/types/Performance.ts
import { ServerAction } from './Server';
export default interface PerformanceRecord {
+ id?: string;
tenantSubdomain: string;
timestamp: Date;
host: string;

MODIFY
src/utils/Logging.ts
src/utils/Logging.ts
import { AxiosError, AxiosRequestConfig, AxiosResponse } from 'axios';
import { Log, LogLevel, LogType } from '../types/Log';
import { NextFunction, Request, Response } from 'express';
+import PerformanceRecord, { PerformanceRecordGroup } from '../types/Performance';
import global, { ActionsResponse } from '../types/GlobalType';
import AppAuthError from '../exception/AppAuthError';
@@ -15,10 +16,10 @@ import LoggingStorage from '../storage/mongodb/LoggingStorage';
import { OCPIResult } from '../types/ocpi/OCPIResult';
import { OCPPStatus } from '../types/ocpp/OCPPClient';
import { OICPResult } from '../types/oicp/OICPResult';
-import { PerformanceRecordGroup } from '../types/Performance';
import PerformanceStorage from '../storage/mongodb/PerformanceStorage';
import { ServerAction } from '../types/Server';
import Tenant from '../types/Tenant';
+import TenantStorage from '../storage/mongodb/TenantStorage';
import User from '../types/User';
import UserToken from '../types/UserToken';
import Utils from './Utils';
@@ -152,35 +153,6 @@ export default class Logging {
return Logging.logError(log);
}
- public static async traceExpressRequest(tenantID: string, decodedToken, req: Request, res: Response, next: NextFunction): Promise<void> {
- try {
- // Check perfs
- req['timestamp'] = new Date();
- // Log
- await Logging.logSecurityDebug({
- tenantID,
- action: ServerAction.HTTP_REQUEST,
- user: (Utils.objectHasProperty(decodedToken, 'id') ? decodedToken as UserToken : null),
- message: `Express HTTP Request << ${req.method} '${req.url}'`,
- module: MODULE_NAME, method: 'logExpressRequest',
- detailedMessages: {
- url: req.url,
- method: req.method,
- query: Utils.cloneObject(req.query),
- body: Utils.cloneObject(req.body),
- locale: req.locale,
- xhr: req.xhr,
- ip: req.ip,
- ips: req.ips,
- httpVersion: req.httpVersion,
- headers: req.headers,
- }
- });
- } finally {
- next();
- }
- }
-
public static async logActionsResponse(
tenantID: string, action: ServerAction, module: string, method: string, actionsResponse: ActionsResponse,
messageSuccess: string, messageError: string, messageSuccessAndError: string,
@@ -288,35 +260,115 @@ export default class Logging {
messageSuccess, messageError, messageSuccessAndError, messageNoSuccessNoError);
}
- public static traceExpressResponse(req: Request, res: Response, next: NextFunction): void {
- // eslint-disable-next-line @typescript-eslint/no-misused-promises
- res.on('finish', async () => {
+ public static async traceExpressRequest(req: Request, res: Response, next: NextFunction): Promise<void> {
try {
- // Retrieve Tenant ID if available
+ // Get Tenant info
+ let userID: string;
let tenantID: string;
let tenantSubdomain: string;
- if (req['tenantID']) {
- tenantID = req['tenantID'];
- }
+ // Keep date/time
+ req['timestamp'] = new Date();
+ // Check Tenant
if (req['tenant']) {
- tenantID = req.tenant.id;
- tenantSubdomain = req.tenant.subdomain;
+ const tenant = req['tenant'] as Tenant;
+ tenantID = tenant.id;
+ tenantSubdomain = tenant.subdomain;
+ // Check OCPI
+ } else if (req.headers?.authorization.startsWith('Token')) {
+ let token: string;
+ try {
+ if (req.headers?.authorization.startsWith('Token')) {
+ token = req.headers.authorization.slice(6);
+ }
+ if (req.headers?.authorization.startsWith('Bearer')) {
+ token = req.headers.authorization.slice(7);
+ }
+ // Try Base 64 decoding (OCPI)
+ if (token) {
+ const decodedToken = JSON.parse(Buffer.from(token, 'base64').toString());
+ if (Utils.objectHasProperty(decodedToken, 'tid')) {
+ tenantSubdomain = decodedToken['tid'];
+ const tenant = await TenantStorage.getTenantBySubdomain(tenantSubdomain);
+ if (tenant) {
+ tenantID = tenant.id;
}
- // Compute duration
- let executionDurationMillis = 0;
- if (req['timestamp']) {
- executionDurationMillis = (new Date().getTime() - req['timestamp'].getTime());
}
+ }
+ } catch (error) {
+ // Ignore
+ }
+ }
+ // Check User
+ if (req['user']) {
+ const user = req['user'] as User;
+ userID = user.id;
+ }
+ // Clear Default Tenant
+ if (tenantID === Constants.DEFAULT_TENANT) {
+ tenantID = null;
+ }
+ // Keep Tenant in request
+ req['tenantID'] = tenantID;
+ req['tenantSubdomain'] = tenantSubdomain;
// Compute Length
const sizeOfRequestDataKB = Utils.truncTo(Utils.createDecimal(
sizeof({ headers: req.headers, query: req.query, body: req.body })
).div(1024).toNumber(), 2);
+ // Log
+ const message = `Express HTTP Request << Req ${(sizeOfRequestDataKB > 0) ? sizeOfRequestDataKB : '?'} KB << ${req.method} '${req.url}'`;
+ Utils.isDevelopmentEnv() && console.debug(chalk.green(message));
+ await Logging.logSecurityDebug({
+ tenantID,
+ action: ServerAction.HTTP_REQUEST,
+ user: userID,
+ message,
+ module: MODULE_NAME, method: 'logExpressRequest',
+ detailedMessages: {
+ url: req.url,
+ method: req.method,
+ query: Utils.cloneObject(req.query),
+ body: Utils.cloneObject(req.body),
+ locale: req.locale,
+ xhr: req.xhr,
+ ip: req.ip,
+ ips: req.ips,
+ httpVersion: req.httpVersion,
+ headers: req.headers,
+ }
+ });
+ const performanceID = await PerformanceStorage.savePerformanceRecord(
+ Utils.buildPerformanceRecord({
+ tenantSubdomain,
+ group: Utils.getPerformanceRecordGroupFromURL(req.url),
+ httpUrl: req.url,
+ httpMethod: req.method,
+ reqSizeKb: sizeOfRequestDataKB,
+ action: ServerAction.HTTP_REQUEST,
+ })
+ );
+ req['performanceID'] = performanceID;
+ } finally {
+ next();
+ }
+ }
+
+ public static traceExpressResponse(req: Request, res: Response, next: NextFunction): void {
+ // eslint-disable-next-line @typescript-eslint/no-misused-promises
+ res.on('finish', async () => {
+ try {
+ // Get Tenant info
+ const tenantID = req['tenantID'] as string;
+ // Compute duration
+ let executionDurationMillis = 0;
+ if (req['timestamp']) {
+ executionDurationMillis = (new Date().getTime() - req['timestamp'].getTime());
+ }
let sizeOfResponseDataKB = 0;
if (res.getHeader('content-length')) {
sizeOfResponseDataKB = Utils.truncTo(
Utils.createDecimal(res.getHeader('content-length') as number).div(1024).toNumber(), 2);
}
- const message = `Express HTTP Response - ${(executionDurationMillis > 0) ? executionDurationMillis : '?'} ms - Req ${(sizeOfRequestDataKB > 0) ? sizeOfRequestDataKB : '?'} KB - Res ${(sizeOfResponseDataKB > 0) ? sizeOfResponseDataKB : '?'} KB >> ${req.method}/${res.statusCode} '${req.url}'`;
+ const message = `Express HTTP Response >> ${(executionDurationMillis > 0) ? executionDurationMillis : '?'} ms - Res ${(sizeOfResponseDataKB > 0) ? sizeOfResponseDataKB : '?'} KB >> ${req.method}/${res.statusCode} '${req.url}'`;
Utils.isDevelopmentEnv() && console.debug(chalk.green(message));
if (sizeOfResponseDataKB > Constants.PERF_MAX_DATA_VOLUME_KB) {
const error = new Error(`Data must be < ${Constants.PERF_MAX_DATA_VOLUME_KB} KB, got ${(sizeOfResponseDataKB > 0) ? sizeOfResponseDataKB : '?'} KB`);
@@ -367,19 +419,15 @@ export default class Logging {
headers: res.getHeaders(),
}
});
- void PerformanceStorage.savePerformanceRecord(
- Utils.buildPerformanceRecord({
- tenantSubdomain,
- group: Utils.getPerformanceRecordGroupFromURL(req.url),
- httpUrl: req.url,
+ if (req['performanceID']) {
+ const performanceRecord = {
+ id: req['performanceID'],
httpResponseCode: res.statusCode,
- httpMethod: req.method,
durationMs: executionDurationMillis,
resSizeKb: sizeOfResponseDataKB,
- reqSizeKb: sizeOfRequestDataKB,
- action: ServerAction.HTTP_RESPONSE,
- })
- );
+ } as PerformanceRecord;
+ await PerformanceStorage.updatePerformanceRecord(performanceRecord);
+ }
} finally {
next();
}

MODIFY
src/utils/Utils.ts
src/utils/Utils.ts
@@ -1540,7 +1540,7 @@ export default class Utils {
}
public static buildPerformanceRecord(params: {
- tenantSubdomain: string; durationMs: number; resSizeKb?: number;
+ tenantSubdomain: string; durationMs?: number; resSizeKb?: number;
reqSizeKb?: number; action: ServerAction|string; group?: PerformanceRecordGroup;
httpUrl?: string; httpMethod?: string; httpResponseCode?: number; chargingStationID?: string,
}): PerformanceRecord {

Log perf logs in HTTP requests