initial
This commit is contained in:
514
ts/mail/delivery/smtpserver/utils/adaptive-logging.ts
Normal file
514
ts/mail/delivery/smtpserver/utils/adaptive-logging.ts
Normal file
@@ -0,0 +1,514 @@
|
||||
/**
|
||||
* Adaptive SMTP Logging System
|
||||
* Automatically switches between logging modes based on server load (active connections)
|
||||
* to maintain performance during high-concurrency scenarios
|
||||
*/
|
||||
|
||||
import * as plugins from '../../../../plugins.ts';
|
||||
import { logger } from '../../../../logger.ts';
|
||||
import { SecurityLogLevel, SecurityEventType } from '../constants.ts';
|
||||
import type { ISmtpSession } from '../interfaces.ts';
|
||||
import type { LogLevel, ISmtpLogOptions } from './logging.ts';
|
||||
|
||||
/**
|
||||
* Log modes based on server load
|
||||
*/
|
||||
export enum LogMode {
|
||||
VERBOSE = 'VERBOSE', // < 20 connections: Full detailed logging
|
||||
REDUCED = 'REDUCED', // 20-40 connections: Limited command/response logging, full error logging
|
||||
MINIMAL = 'MINIMAL' // 40+ connections: Aggregated logging only, critical errors only
|
||||
}
|
||||
|
||||
/**
|
||||
* Configuration for adaptive logging thresholds
|
||||
*/
|
||||
export interface IAdaptiveLogConfig {
|
||||
verboseThreshold: number; // Switch to REDUCED mode above this connection count
|
||||
reducedThreshold: number; // Switch to MINIMAL mode above this connection count
|
||||
aggregationInterval: number; // How often to flush aggregated logs (ms)
|
||||
maxAggregatedEntries: number; // Max entries to hold before forced flush
|
||||
}
|
||||
|
||||
/**
|
||||
* Aggregated log entry for batching similar events
|
||||
*/
|
||||
interface IAggregatedLogEntry {
|
||||
type: 'connection' | 'command' | 'response' | 'error';
|
||||
count: number;
|
||||
firstSeen: number;
|
||||
lastSeen: number;
|
||||
sample: {
|
||||
message: string;
|
||||
level: LogLevel;
|
||||
options?: ISmtpLogOptions;
|
||||
};
|
||||
}
|
||||
|
||||
/**
|
||||
* Connection metadata for aggregation tracking
|
||||
*/
|
||||
interface IConnectionTracker {
|
||||
activeConnections: number;
|
||||
peakConnections: number;
|
||||
totalConnections: number;
|
||||
connectionsPerSecond: number;
|
||||
lastConnectionTime: number;
|
||||
}
|
||||
|
||||
/**
|
||||
* Adaptive SMTP Logger that scales logging based on server load
|
||||
*/
|
||||
export class AdaptiveSmtpLogger {
|
||||
private static instance: AdaptiveSmtpLogger;
|
||||
private currentMode: LogMode = LogMode.VERBOSE;
|
||||
private config: IAdaptiveLogConfig;
|
||||
private aggregatedEntries: Map<string, IAggregatedLogEntry> = new Map();
|
||||
private aggregationTimer: NodeJS.Timeout | null = null;
|
||||
private connectionTracker: IConnectionTracker = {
|
||||
activeConnections: 0,
|
||||
peakConnections: 0,
|
||||
totalConnections: 0,
|
||||
connectionsPerSecond: 0,
|
||||
lastConnectionTime: Date.now()
|
||||
};
|
||||
|
||||
private constructor(config?: Partial<IAdaptiveLogConfig>) {
|
||||
this.config = {
|
||||
verboseThreshold: 20,
|
||||
reducedThreshold: 40,
|
||||
aggregationInterval: 30000, // 30 seconds
|
||||
maxAggregatedEntries: 100,
|
||||
...config
|
||||
};
|
||||
|
||||
this.startAggregationTimer();
|
||||
}
|
||||
|
||||
/**
|
||||
* Get singleton instance
|
||||
*/
|
||||
public static getInstance(config?: Partial<IAdaptiveLogConfig>): AdaptiveSmtpLogger {
|
||||
if (!AdaptiveSmtpLogger.instance) {
|
||||
AdaptiveSmtpLogger.instance = new AdaptiveSmtpLogger(config);
|
||||
}
|
||||
return AdaptiveSmtpLogger.instance;
|
||||
}
|
||||
|
||||
/**
|
||||
* Update active connection count and adjust log mode if needed
|
||||
*/
|
||||
public updateConnectionCount(activeConnections: number): void {
|
||||
this.connectionTracker.activeConnections = activeConnections;
|
||||
this.connectionTracker.peakConnections = Math.max(
|
||||
this.connectionTracker.peakConnections,
|
||||
activeConnections
|
||||
);
|
||||
|
||||
const newMode = this.determineLogMode(activeConnections);
|
||||
if (newMode !== this.currentMode) {
|
||||
this.switchLogMode(newMode);
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Track new connection for rate calculation
|
||||
*/
|
||||
public trackConnection(): void {
|
||||
this.connectionTracker.totalConnections++;
|
||||
const now = Date.now();
|
||||
const timeDiff = (now - this.connectionTracker.lastConnectionTime) / 1000;
|
||||
if (timeDiff > 0) {
|
||||
this.connectionTracker.connectionsPerSecond = 1 / timeDiff;
|
||||
}
|
||||
this.connectionTracker.lastConnectionTime = now;
|
||||
}
|
||||
|
||||
/**
|
||||
* Get current logging mode
|
||||
*/
|
||||
public getCurrentMode(): LogMode {
|
||||
return this.currentMode;
|
||||
}
|
||||
|
||||
/**
|
||||
* Get connection statistics
|
||||
*/
|
||||
public getConnectionStats(): IConnectionTracker {
|
||||
return { ...this.connectionTracker };
|
||||
}
|
||||
|
||||
/**
|
||||
* Log a message with adaptive behavior
|
||||
*/
|
||||
public log(level: LogLevel, message: string, options: ISmtpLogOptions = {}): void {
|
||||
// Always log structured data
|
||||
const errorInfo = options.error ? {
|
||||
errorMessage: options.error.message,
|
||||
errorStack: options.error.stack,
|
||||
errorName: options.error.name
|
||||
} : {};
|
||||
|
||||
const logData = {
|
||||
component: 'smtp-server',
|
||||
logMode: this.currentMode,
|
||||
activeConnections: this.connectionTracker.activeConnections,
|
||||
...options,
|
||||
...errorInfo
|
||||
};
|
||||
|
||||
if (logData.error) {
|
||||
delete logData.error;
|
||||
}
|
||||
|
||||
logger.log(level, message, logData);
|
||||
|
||||
// Adaptive console logging based on mode
|
||||
switch (this.currentMode) {
|
||||
case LogMode.VERBOSE:
|
||||
// Full console logging
|
||||
if (level === 'error' || level === 'warn') {
|
||||
console[level](`[SMTP] ${message}`, logData);
|
||||
}
|
||||
break;
|
||||
|
||||
case LogMode.REDUCED:
|
||||
// Only errors and warnings to console
|
||||
if (level === 'error' || level === 'warn') {
|
||||
console[level](`[SMTP] ${message}`, logData);
|
||||
}
|
||||
break;
|
||||
|
||||
case LogMode.MINIMAL:
|
||||
// Only critical errors to console
|
||||
if (level === 'error' && (message.includes('critical') || message.includes('security') || message.includes('crash'))) {
|
||||
console[level](`[SMTP] ${message}`, logData);
|
||||
}
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Log command with adaptive behavior
|
||||
*/
|
||||
public logCommand(command: string, socket: plugins.net.Socket | plugins.tls.TLSSocket, session?: ISmtpSession): void {
|
||||
const clientInfo = {
|
||||
remoteAddress: socket.remoteAddress,
|
||||
remotePort: socket.remotePort,
|
||||
secure: socket instanceof plugins.tls.TLSSocket,
|
||||
sessionId: session?.id,
|
||||
sessionState: session?.state
|
||||
};
|
||||
|
||||
switch (this.currentMode) {
|
||||
case LogMode.VERBOSE:
|
||||
this.log('info', `Command received: ${command}`, {
|
||||
...clientInfo,
|
||||
command: command.split(' ')[0]?.toUpperCase()
|
||||
});
|
||||
console.log(`← ${command}`);
|
||||
break;
|
||||
|
||||
case LogMode.REDUCED:
|
||||
// Aggregate commands instead of logging each one
|
||||
this.aggregateEntry('command', 'info', `Command: ${command.split(' ')[0]?.toUpperCase()}`, clientInfo);
|
||||
// Only show error commands
|
||||
if (command.toUpperCase().startsWith('QUIT') || command.includes('error')) {
|
||||
console.log(`← ${command}`);
|
||||
}
|
||||
break;
|
||||
|
||||
case LogMode.MINIMAL:
|
||||
// Only aggregate, no console output unless it's an error command
|
||||
this.aggregateEntry('command', 'info', `Command: ${command.split(' ')[0]?.toUpperCase()}`, clientInfo);
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Log response with adaptive behavior
|
||||
*/
|
||||
public logResponse(response: string, socket: plugins.net.Socket | plugins.tls.TLSSocket): void {
|
||||
const clientInfo = {
|
||||
remoteAddress: socket.remoteAddress,
|
||||
remotePort: socket.remotePort,
|
||||
secure: socket instanceof plugins.tls.TLSSocket
|
||||
};
|
||||
|
||||
const responseCode = response.substring(0, 3);
|
||||
const isError = responseCode.startsWith('4') || responseCode.startsWith('5');
|
||||
|
||||
switch (this.currentMode) {
|
||||
case LogMode.VERBOSE:
|
||||
if (responseCode.startsWith('2') || responseCode.startsWith('3')) {
|
||||
this.log('debug', `Response sent: ${response}`, clientInfo);
|
||||
} else if (responseCode.startsWith('4')) {
|
||||
this.log('warn', `Temporary error response: ${response}`, clientInfo);
|
||||
} else if (responseCode.startsWith('5')) {
|
||||
this.log('error', `Permanent error response: ${response}`, clientInfo);
|
||||
}
|
||||
console.log(`→ ${response}`);
|
||||
break;
|
||||
|
||||
case LogMode.REDUCED:
|
||||
// Log errors normally, aggregate success responses
|
||||
if (isError) {
|
||||
if (responseCode.startsWith('4')) {
|
||||
this.log('warn', `Temporary error response: ${response}`, clientInfo);
|
||||
} else {
|
||||
this.log('error', `Permanent error response: ${response}`, clientInfo);
|
||||
}
|
||||
console.log(`→ ${response}`);
|
||||
} else {
|
||||
this.aggregateEntry('response', 'debug', `Response: ${responseCode}xx`, clientInfo);
|
||||
}
|
||||
break;
|
||||
|
||||
case LogMode.MINIMAL:
|
||||
// Only log critical errors
|
||||
if (responseCode.startsWith('5')) {
|
||||
this.log('error', `Permanent error response: ${response}`, clientInfo);
|
||||
console.log(`→ ${response}`);
|
||||
} else {
|
||||
this.aggregateEntry('response', 'debug', `Response: ${responseCode}xx`, clientInfo);
|
||||
}
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Log connection event with adaptive behavior
|
||||
*/
|
||||
public logConnection(
|
||||
socket: plugins.net.Socket | plugins.tls.TLSSocket,
|
||||
eventType: 'connect' | 'close' | 'error',
|
||||
session?: ISmtpSession,
|
||||
error?: Error
|
||||
): void {
|
||||
const clientInfo = {
|
||||
remoteAddress: socket.remoteAddress,
|
||||
remotePort: socket.remotePort,
|
||||
secure: socket instanceof plugins.tls.TLSSocket,
|
||||
sessionId: session?.id,
|
||||
sessionState: session?.state
|
||||
};
|
||||
|
||||
if (eventType === 'connect') {
|
||||
this.trackConnection();
|
||||
}
|
||||
|
||||
switch (this.currentMode) {
|
||||
case LogMode.VERBOSE:
|
||||
// Full connection logging
|
||||
switch (eventType) {
|
||||
case 'connect':
|
||||
this.log('info', `New ${clientInfo.secure ? 'secure ' : ''}connection from ${clientInfo.remoteAddress}:${clientInfo.remotePort}`, clientInfo);
|
||||
break;
|
||||
case 'close':
|
||||
this.log('info', `Connection closed from ${clientInfo.remoteAddress}:${clientInfo.remotePort}`, clientInfo);
|
||||
break;
|
||||
case 'error':
|
||||
this.log('error', `Connection error from ${clientInfo.remoteAddress}:${clientInfo.remotePort}`, {
|
||||
...clientInfo,
|
||||
error
|
||||
});
|
||||
break;
|
||||
}
|
||||
break;
|
||||
|
||||
case LogMode.REDUCED:
|
||||
// Aggregate normal connections, log errors
|
||||
if (eventType === 'error') {
|
||||
this.log('error', `Connection error from ${clientInfo.remoteAddress}:${clientInfo.remotePort}`, {
|
||||
...clientInfo,
|
||||
error
|
||||
});
|
||||
} else {
|
||||
this.aggregateEntry('connection', 'info', `Connection ${eventType}`, clientInfo);
|
||||
}
|
||||
break;
|
||||
|
||||
case LogMode.MINIMAL:
|
||||
// Only aggregate, except for critical errors
|
||||
if (eventType === 'error' && error && (error.message.includes('security') || error.message.includes('critical'))) {
|
||||
this.log('error', `Critical connection error from ${clientInfo.remoteAddress}:${clientInfo.remotePort}`, {
|
||||
...clientInfo,
|
||||
error
|
||||
});
|
||||
} else {
|
||||
this.aggregateEntry('connection', 'info', `Connection ${eventType}`, clientInfo);
|
||||
}
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Log security event (always logged regardless of mode)
|
||||
*/
|
||||
public logSecurityEvent(
|
||||
level: SecurityLogLevel,
|
||||
type: SecurityEventType,
|
||||
message: string,
|
||||
details: Record<string, any>,
|
||||
ipAddress?: string,
|
||||
domain?: string,
|
||||
success?: boolean
|
||||
): void {
|
||||
const logLevel: LogLevel = level === SecurityLogLevel.DEBUG ? 'debug' :
|
||||
level === SecurityLogLevel.INFO ? 'info' :
|
||||
level === SecurityLogLevel.WARN ? 'warn' : 'error';
|
||||
|
||||
// Security events are always logged in full detail
|
||||
this.log(logLevel, message, {
|
||||
component: 'smtp-security',
|
||||
eventType: type,
|
||||
success,
|
||||
ipAddress,
|
||||
domain,
|
||||
...details
|
||||
});
|
||||
}
|
||||
|
||||
/**
|
||||
* Determine appropriate log mode based on connection count
|
||||
*/
|
||||
private determineLogMode(activeConnections: number): LogMode {
|
||||
if (activeConnections >= this.config.reducedThreshold) {
|
||||
return LogMode.MINIMAL;
|
||||
} else if (activeConnections >= this.config.verboseThreshold) {
|
||||
return LogMode.REDUCED;
|
||||
} else {
|
||||
return LogMode.VERBOSE;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Switch to a new log mode
|
||||
*/
|
||||
private switchLogMode(newMode: LogMode): void {
|
||||
const oldMode = this.currentMode;
|
||||
this.currentMode = newMode;
|
||||
|
||||
// Log the mode switch
|
||||
console.log(`[SMTP] Adaptive logging switched from ${oldMode} to ${newMode} (${this.connectionTracker.activeConnections} active connections)`);
|
||||
|
||||
this.log('info', `Adaptive logging mode changed to ${newMode}`, {
|
||||
oldMode,
|
||||
newMode,
|
||||
activeConnections: this.connectionTracker.activeConnections,
|
||||
peakConnections: this.connectionTracker.peakConnections,
|
||||
totalConnections: this.connectionTracker.totalConnections
|
||||
});
|
||||
|
||||
// If switching to more verbose mode, flush aggregated entries
|
||||
if ((oldMode === LogMode.MINIMAL && newMode !== LogMode.MINIMAL) ||
|
||||
(oldMode === LogMode.REDUCED && newMode === LogMode.VERBOSE)) {
|
||||
this.flushAggregatedEntries();
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Add entry to aggregation buffer
|
||||
*/
|
||||
private aggregateEntry(
|
||||
type: 'connection' | 'command' | 'response' | 'error',
|
||||
level: LogLevel,
|
||||
message: string,
|
||||
options?: ISmtpLogOptions
|
||||
): void {
|
||||
const key = `${type}:${message}`;
|
||||
const now = Date.now();
|
||||
|
||||
if (this.aggregatedEntries.has(key)) {
|
||||
const entry = this.aggregatedEntries.get(key)!;
|
||||
entry.count++;
|
||||
entry.lastSeen = now;
|
||||
} else {
|
||||
this.aggregatedEntries.set(key, {
|
||||
type,
|
||||
count: 1,
|
||||
firstSeen: now,
|
||||
lastSeen: now,
|
||||
sample: { message, level, options }
|
||||
});
|
||||
}
|
||||
|
||||
// Force flush if we have too many entries
|
||||
if (this.aggregatedEntries.size >= this.config.maxAggregatedEntries) {
|
||||
this.flushAggregatedEntries();
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Start the aggregation timer
|
||||
*/
|
||||
private startAggregationTimer(): void {
|
||||
if (this.aggregationTimer) {
|
||||
clearInterval(this.aggregationTimer);
|
||||
}
|
||||
|
||||
this.aggregationTimer = setInterval(() => {
|
||||
this.flushAggregatedEntries();
|
||||
}, this.config.aggregationInterval);
|
||||
|
||||
// Unref the timer so it doesn't keep the process alive
|
||||
if (this.aggregationTimer && typeof this.aggregationTimer.unref === 'function') {
|
||||
this.aggregationTimer.unref();
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Flush aggregated entries to logs
|
||||
*/
|
||||
private flushAggregatedEntries(): void {
|
||||
if (this.aggregatedEntries.size === 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
const summary: Record<string, number> = {};
|
||||
let totalAggregated = 0;
|
||||
|
||||
for (const [key, entry] of this.aggregatedEntries.entries()) {
|
||||
summary[entry.type] = (summary[entry.type] || 0) + entry.count;
|
||||
totalAggregated += entry.count;
|
||||
|
||||
// Log a sample of high-frequency entries
|
||||
if (entry.count >= 10) {
|
||||
this.log(entry.sample.level, `${entry.sample.message} (aggregated: ${entry.count} occurrences)`, {
|
||||
...entry.sample.options,
|
||||
aggregated: true,
|
||||
occurrences: entry.count,
|
||||
timeSpan: entry.lastSeen - entry.firstSeen
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
// Log aggregation summary
|
||||
console.log(`[SMTP] Aggregated ${totalAggregated} log entries: ${JSON.stringify(summary)}`);
|
||||
|
||||
this.log('info', 'Aggregated log summary', {
|
||||
totalEntries: totalAggregated,
|
||||
breakdown: summary,
|
||||
logMode: this.currentMode,
|
||||
activeConnections: this.connectionTracker.activeConnections
|
||||
});
|
||||
|
||||
// Clear aggregated entries
|
||||
this.aggregatedEntries.clear();
|
||||
}
|
||||
|
||||
/**
|
||||
* Cleanup resources
|
||||
*/
|
||||
public destroy(): void {
|
||||
if (this.aggregationTimer) {
|
||||
clearInterval(this.aggregationTimer);
|
||||
this.aggregationTimer = null;
|
||||
}
|
||||
this.flushAggregatedEntries();
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Default instance for easy access
|
||||
*/
|
||||
export const adaptiveLogger = AdaptiveSmtpLogger.getInstance();
|
||||
Reference in New Issue
Block a user