implemented performance profiling into some areas
This commit is contained in:
@@ -13,6 +13,8 @@ import { MemberState } from '@app/shared/types/member';
|
|||||||
import { toDateTime } from '@app/shared/utils/time';
|
import { toDateTime } from '@app/shared/utils/time';
|
||||||
import { logger } from '../services/logging/logger';
|
import { logger } from '../services/logging/logger';
|
||||||
const querystring = require('querystring');
|
const querystring = require('querystring');
|
||||||
|
import { performance } from 'perf_hooks';
|
||||||
|
|
||||||
|
|
||||||
function parseJwt(token) {
|
function parseJwt(token) {
|
||||||
return JSON.parse(Buffer.from(token.split('.')[1], 'base64').toString());
|
return JSON.parse(Buffer.from(token.split('.')[1], 'base64').toString());
|
||||||
@@ -179,28 +181,75 @@ passport.serializeUser(function (user, cb) {
|
|||||||
});
|
});
|
||||||
|
|
||||||
passport.deserializeUser(function (user, cb) {
|
passport.deserializeUser(function (user, cb) {
|
||||||
|
const start = performance.now();
|
||||||
|
const timings: Record<string, number> = {};
|
||||||
|
|
||||||
process.nextTick(async function () {
|
process.nextTick(async function () {
|
||||||
|
|
||||||
const memberID = user.memberId as number;
|
const memberID = user.memberId as number;
|
||||||
|
let con;
|
||||||
|
|
||||||
|
|
||||||
var userData: { id: number, name: string, roles: Role[], state: MemberState };
|
|
||||||
try {
|
try {
|
||||||
var con = await pool.getConnection();
|
let t;
|
||||||
let userResults = await con.query(`SELECT id, name FROM members WHERE id = ?;`, [memberID])
|
|
||||||
userData = userResults[0];
|
t = performance.now();
|
||||||
let userRoles = await getUserRoles(memberID);
|
con = await pool.getConnection();
|
||||||
|
timings.getConnection = performance.now() - t;
|
||||||
|
|
||||||
|
t = performance.now();
|
||||||
|
const userResults = await con.query(
|
||||||
|
`SELECT id, name FROM members WHERE id = ?;`,
|
||||||
|
[memberID]
|
||||||
|
);
|
||||||
|
timings.memberQuery = performance.now() - t;
|
||||||
|
|
||||||
|
const userData: {
|
||||||
|
id: number;
|
||||||
|
name: string;
|
||||||
|
roles: Role[];
|
||||||
|
state: MemberState;
|
||||||
|
} = userResults[0];
|
||||||
|
|
||||||
|
t = performance.now();
|
||||||
|
const userRoles = await getUserRoles(memberID);
|
||||||
|
timings.roles = performance.now() - t;
|
||||||
userData.roles = userRoles || [];
|
userData.roles = userRoles || [];
|
||||||
|
|
||||||
|
t = performance.now();
|
||||||
userData.state = await getUserState(memberID);
|
userData.state = await getUserState(memberID);
|
||||||
} catch (error) {
|
timings.state = performance.now() - t;
|
||||||
console.error(error)
|
|
||||||
} finally {
|
// 📊 PROFILING LOG
|
||||||
con.release();
|
logger.info(
|
||||||
}
|
'profiling',
|
||||||
|
'passport.deserializeUser completed',
|
||||||
|
{
|
||||||
|
memberId: memberID,
|
||||||
|
total_ms: performance.now() - start,
|
||||||
|
breakdown_ms: timings,
|
||||||
|
},
|
||||||
|
'profiling'
|
||||||
|
);
|
||||||
|
|
||||||
return cb(null, userData);
|
return cb(null, userData);
|
||||||
|
|
||||||
|
} catch (error) {
|
||||||
|
logger.error(
|
||||||
|
'profiling',
|
||||||
|
'passport.deserializeUser failed',
|
||||||
|
{
|
||||||
|
memberId: memberID,
|
||||||
|
error: error instanceof Error ? error.message : String(error),
|
||||||
|
}
|
||||||
|
);
|
||||||
|
return cb(error);
|
||||||
|
|
||||||
|
} finally {
|
||||||
|
if (con) con.release();
|
||||||
|
}
|
||||||
});
|
});
|
||||||
});
|
});
|
||||||
|
|
||||||
|
|
||||||
declare global {
|
declare global {
|
||||||
namespace Express {
|
namespace Express {
|
||||||
interface Request {
|
interface Request {
|
||||||
|
|||||||
@@ -9,6 +9,9 @@ import { getAllMembersLite, getMemberSettings, getMembersFull, getMembersLite, g
|
|||||||
import { getUserRoles } from '../services/db/rolesService';
|
import { getUserRoles } from '../services/db/rolesService';
|
||||||
import { memberSettings, MemberState, myData } from '@app/shared/types/member';
|
import { memberSettings, MemberState, myData } from '@app/shared/types/member';
|
||||||
|
|
||||||
|
import { Performance } from 'perf_hooks';
|
||||||
|
import { logger } from '../services/logging/logger';
|
||||||
|
|
||||||
//get all users
|
//get all users
|
||||||
router.get('/', [requireLogin, requireMemberState(MemberState.Member)], async (req, res) => {
|
router.get('/', [requireLogin, requireMemberState(MemberState.Member)], async (req, res) => {
|
||||||
try {
|
try {
|
||||||
@@ -32,23 +35,56 @@ router.get('/', [requireLogin, requireMemberState(MemberState.Member)], async (r
|
|||||||
}
|
}
|
||||||
});
|
});
|
||||||
|
|
||||||
router.get('/me', [requireLogin], async (req, res) => {
|
router.get('/me', [requireLogin], async (req: Request, res) => {
|
||||||
if (req.user === undefined)
|
if (!req.user) return res.sendStatus(401);
|
||||||
return res.sendStatus(401)
|
|
||||||
|
const routeStart = performance.now();
|
||||||
|
const timings: Record<string, number> = {};
|
||||||
|
|
||||||
try {
|
try {
|
||||||
const memData = await getUserData(req.user.id);
|
let t;
|
||||||
const LOAData = await getUserActiveLOA(req.user.id);
|
|
||||||
const memState = await getUserState(req.user.id);
|
t = performance.now();
|
||||||
const roleData = await getUserRoles(req.user.id);
|
const memData = await getUserData(req.user.id);
|
||||||
|
timings.member = performance.now() - t;
|
||||||
|
|
||||||
|
t = performance.now();
|
||||||
|
const LOAData = await getUserActiveLOA(req.user.id);
|
||||||
|
timings.loa = performance.now() - t;
|
||||||
|
|
||||||
|
t = performance.now();
|
||||||
|
const memState = await getUserState(req.user.id);
|
||||||
|
timings.state = performance.now() - t;
|
||||||
|
|
||||||
|
t = performance.now();
|
||||||
|
const roleData = await getUserRoles(req.user.id);
|
||||||
|
timings.roles = performance.now() - t;
|
||||||
|
|
||||||
|
const userDataFull: myData = {
|
||||||
|
member: memData,
|
||||||
|
LOAs: LOAData,
|
||||||
|
roles: roleData,
|
||||||
|
state: memState,
|
||||||
|
};
|
||||||
|
|
||||||
const userDataFull: myData = { member: memData, LOAs: LOAData, roles: roleData, state: memState };
|
|
||||||
res.status(200).json(userDataFull);
|
res.status(200).json(userDataFull);
|
||||||
|
|
||||||
|
logger.info('profiling', 'GET /members/me completed', {
|
||||||
|
userId: req.user.id,
|
||||||
|
total_ms: performance.now() - routeStart,
|
||||||
|
breakdown_ms: timings,
|
||||||
|
}, 'profiling');
|
||||||
|
|
||||||
} catch (error) {
|
} catch (error) {
|
||||||
console.error('Error fetching user data:', error);
|
logger.error('profiling', 'GET /members/me failed', {
|
||||||
|
userId: req.user?.id,
|
||||||
|
error: error instanceof Error ? error.message : String(error),
|
||||||
|
});
|
||||||
|
|
||||||
return res.status(500).json({ error: 'Failed to fetch user data' });
|
return res.status(500).json({ error: 'Failed to fetch user data' });
|
||||||
}
|
}
|
||||||
})
|
});
|
||||||
|
|
||||||
|
|
||||||
router.get('/settings', [requireLogin], async (req: Request, res: Response) => {
|
router.get('/settings', [requireLogin], async (req: Request, res: Response) => {
|
||||||
try {
|
try {
|
||||||
|
|||||||
@@ -1,6 +1,6 @@
|
|||||||
export type LogLevel = 'debug' | 'info' | 'warn' | 'error';
|
export type LogLevel = 'debug' | 'info' | 'warn' | 'error';
|
||||||
export type LogDepth = 'normal' | 'verbose';
|
export type LogDepth = 'normal' | 'verbose' | 'profiling';
|
||||||
export type LogType = 'http' | 'app' | 'auth';
|
export type LogType = 'http' | 'app' | 'auth' | 'profiling';
|
||||||
|
|
||||||
export interface LogHeader {
|
export interface LogHeader {
|
||||||
timestamp: string;
|
timestamp: string;
|
||||||
@@ -18,7 +18,7 @@ export interface LogPayload {
|
|||||||
// Environment defaults
|
// Environment defaults
|
||||||
const CURRENT_DEPTH: LogDepth = (process.env.LOG_DEPTH as LogDepth) || 'normal';
|
const CURRENT_DEPTH: LogDepth = (process.env.LOG_DEPTH as LogDepth) || 'normal';
|
||||||
|
|
||||||
const DEPTH_ORDER: Record<LogDepth, number> = { normal: 0, verbose: 1 };
|
const DEPTH_ORDER: Record<LogDepth, number> = { normal: 0, verbose: 1, profiling: 2 };
|
||||||
|
|
||||||
function shouldLog(depth: LogDepth) {
|
function shouldLog(depth: LogDepth) {
|
||||||
let should = DEPTH_ORDER[depth] <= DEPTH_ORDER[CURRENT_DEPTH]
|
let should = DEPTH_ORDER[depth] <= DEPTH_ORDER[CURRENT_DEPTH]
|
||||||
|
|||||||
Reference in New Issue
Block a user