Files
smartmta/dist_ts/mail/delivery/smtpserver/utils/adaptive-logging.js

413 lines
31 KiB
JavaScript
Raw Normal View History

2026-02-10 15:54:09 +00:00
/**
* 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.js';
import { logger } from '../../../../logger.js';
import { SecurityLogLevel, SecurityEventType } from '../constants.js';
/**
* Log modes based on server load
*/
export var LogMode;
(function (LogMode) {
LogMode["VERBOSE"] = "VERBOSE";
LogMode["REDUCED"] = "REDUCED";
LogMode["MINIMAL"] = "MINIMAL"; // 40+ connections: Aggregated logging only, critical errors only
})(LogMode || (LogMode = {}));
/**
* Adaptive SMTP Logger that scales logging based on server load
*/
export class AdaptiveSmtpLogger {
static instance;
currentMode = LogMode.VERBOSE;
config;
aggregatedEntries = new Map();
aggregationTimer = null;
connectionTracker = {
activeConnections: 0,
peakConnections: 0,
totalConnections: 0,
connectionsPerSecond: 0,
lastConnectionTime: Date.now()
};
constructor(config) {
this.config = {
verboseThreshold: 20,
reducedThreshold: 40,
aggregationInterval: 30000, // 30 seconds
maxAggregatedEntries: 100,
...config
};
this.startAggregationTimer();
}
/**
* Get singleton instance
*/
static getInstance(config) {
if (!AdaptiveSmtpLogger.instance) {
AdaptiveSmtpLogger.instance = new AdaptiveSmtpLogger(config);
}
return AdaptiveSmtpLogger.instance;
}
/**
* Update active connection count and adjust log mode if needed
*/
updateConnectionCount(activeConnections) {
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
*/
trackConnection() {
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
*/
getCurrentMode() {
return this.currentMode;
}
/**
* Get connection statistics
*/
getConnectionStats() {
return { ...this.connectionTracker };
}
/**
* Log a message with adaptive behavior
*/
log(level, message, options = {}) {
// 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
*/
logCommand(command, socket, session) {
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
*/
logResponse(response, socket) {
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
*/
logConnection(socket, eventType, session, error) {
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)
*/
logSecurityEvent(level, type, message, details, ipAddress, domain, success) {
const 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
*/
determineLogMode(activeConnections) {
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
*/
switchLogMode(newMode) {
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
*/
aggregateEntry(type, level, message, options) {
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
*/
startAggregationTimer() {
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
*/
flushAggregatedEntries() {
if (this.aggregatedEntries.size === 0) {
return;
}
const summary = {};
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
*/
destroy() {
if (this.aggregationTimer) {
clearInterval(this.aggregationTimer);
this.aggregationTimer = null;
}
this.flushAggregatedEntries();
}
}
/**
* Default instance for easy access
*/
export const adaptiveLogger = AdaptiveSmtpLogger.getInstance();
//# sourceMappingURL=data:application/json;base64,eyJ2ZXJzaW9uIjozLCJmaWxlIjoiYWRhcHRpdmUtbG9nZ2luZy5qcyIsInNvdXJjZVJvb3QiOiIiLCJzb3VyY2VzIjpbIi4uLy4uLy4uLy4uLy4uL3RzL21haWwvZGVsaXZlcnkvc210cHNlcnZlci91dGlscy9hZGFwdGl2ZS1sb2dnaW5nLnRzIl0sIm5hbWVzIjpbXSwibWFwcGluZ3MiOiJBQUFBOzs7O0dBSUc7QUFFSCxPQUFPLEtBQUssT0FBTyxNQUFNLHdCQUF3QixDQUFDO0FBQ2xELE9BQU8sRUFBRSxNQUFNLEVBQUUsTUFBTSx1QkFBdUIsQ0FBQztBQUMvQyxPQUFPLEVBQUUsZ0JBQWdCLEVBQUUsaUJBQWlCLEVBQUUsTUFBTSxpQkFBaUIsQ0FBQztBQUl0RTs7R0FFRztBQUNILE1BQU0sQ0FBTixJQUFZLE9BSVg7QUFKRCxXQUFZLE9BQU87SUFDakIsOEJBQW1CLENBQUE7SUFDbkIsOEJBQW1CLENBQUE7SUFDbkIsOEJBQW1CLENBQUEsQ0FBTSxpRUFBaUU7QUFDNUYsQ0FBQyxFQUpXLE9BQU8sS0FBUCxPQUFPLFFBSWxCO0FBc0NEOztHQUVHO0FBQ0gsTUFBTSxPQUFPLGtCQUFrQjtJQUNyQixNQUFNLENBQUMsUUFBUSxDQUFxQjtJQUNwQyxXQUFXLEdBQVksT0FBTyxDQUFDLE9BQU8sQ0FBQztJQUN2QyxNQUFNLENBQXFCO0lBQzNCLGlCQUFpQixHQUFxQyxJQUFJLEdBQUcsRUFBRSxDQUFDO0lBQ2hFLGdCQUFnQixHQUEwQixJQUFJLENBQUM7SUFDL0MsaUJBQWlCLEdBQXVCO1FBQzlDLGlCQUFpQixFQUFFLENBQUM7UUFDcEIsZUFBZSxFQUFFLENBQUM7UUFDbEIsZ0JBQWdCLEVBQUUsQ0FBQztRQUNuQixvQkFBb0IsRUFBRSxDQUFDO1FBQ3ZCLGtCQUFrQixFQUFFLElBQUksQ0FBQyxHQUFHLEVBQUU7S0FDL0IsQ0FBQztJQUVGLFlBQW9CLE1BQW9DO1FBQ3RELElBQUksQ0FBQyxNQUFNLEdBQUc7WUFDWixnQkFBZ0IsRUFBRSxFQUFFO1lBQ3BCLGdCQUFnQixFQUFFLEVBQUU7WUFDcEIsbUJBQW1CLEVBQUUsS0FBSyxFQUFFLGFBQWE7WUFDekMsb0JBQW9CLEVBQUUsR0FBRztZQUN6QixHQUFHLE1BQU07U0FDVixDQUFDO1FBRUYsSUFBSSxDQUFDLHFCQUFxQixFQUFFLENBQUM7SUFDL0IsQ0FBQztJQUVEOztPQUVHO0lBQ0ksTUFBTSxDQUFDLFdBQVcsQ0FBQyxNQUFvQztRQUM1RCxJQUFJLENBQUMsa0JBQWtCLENBQUMsUUFBUSxFQUFFLENBQUM7WUFDakMsa0JBQWtCLENBQUMsUUFBUSxHQUFHLElBQUksa0JBQWtCLENBQUMsTUFBTSxDQUFDLENBQUM7UUFDL0QsQ0FBQztRQUNELE9BQU8sa0JBQWtCLENBQUMsUUFBUSxDQUFDO0lBQ3JDLENBQUM7SUFFRDs7T0FFRztJQUNJLHFCQUFxQixDQUFDLGlCQUF5QjtRQUNwRCxJQUFJLENBQUMsaUJBQWlCLENBQUMsaUJBQWlCLEdBQUcsaUJBQWlCLENBQUM7UUFDN0QsSUFBSSxDQUFDLGlCQUFpQixDQUFDLGVBQWUsR0FBRyxJQUFJLENBQUMsR0FBRyxDQUMvQyxJQUFJLENBQUMsaUJBQWlCLENBQUMsZUFBZSxFQUN0QyxpQkFBaUIsQ0FDbEIsQ0FBQztRQUVGLE1BQU0sT0FBTyxHQUFHLElBQUksQ0FBQyxnQkFBZ0IsQ0FBQyxpQkFBaUIsQ0FBQyxDQUFDO1FBQ3pELElBQUksT0FBTyxLQUFLLElBQUksQ0FBQyxXQUFXLEVBQUUsQ0FBQztZQUNqQyxJQUFJLENBQUMsYUFBYSxDQUFDLE9BQU8sQ0FBQyxDQUFDO1FBQzlCLENBQUM7SUFDSCxDQUFDO0lBRUQ7O09BRUc7SUFDSSxlQUFlO1FBQ3BCLElBQUksQ0FBQyxpQkFBaUIsQ0FBQyxnQkFBZ0IsRUFBRSxDQUFDO1FBQzFDLE1BQU0sR0FBRyxHQUFHLElBQUksQ0FBQyxHQUFHLEVBQUUsQ0FBQztRQUN2QixNQUFNLFFBQVEsR0FBRyxDQUFDLEdBQUcsR0FBRyxJQUFJLENBQUMsaUJBQWlCLENBQUMsa0JBQWtCLENBQUMsR0FBRyxJQUFJLENBQUM7UUFDMUUsSUFBSSxRQUFRLEdBQUcsQ0FBQyxFQUFFLENBQUM7WUFDakIsSUFBSSxDQUFDLGlCQUFpQixDQUFDLG9CQUFvQixHQUFHLENBQUMsR0FBRyxRQUFRLENBQUM7UUFDN0QsQ0FBQztRQUNELElBQUksQ0FBQyxpQkFBaUIsQ0FBQyxrQkFBa0IsR0FBRyxHQUFHLENBQUM7SUFDbEQsQ0FBQztJQUVEOztPQUVHO0lBQ0ksY0FBYztRQUNuQixPQUFPLElBQUksQ0FBQyxXQUFXLENBQUM7SUFDMUIsQ0FBQztJQUVEOztPQUVHO0lBQ0ksa0JBQWtCO1FBQ3ZCLE9BQU8sRUFBRSxHQUFHLElBQUksQ0FBQyxpQkFBaUIsRUFBRSxDQUFDO0lBQ3ZDLENBQUM7SUFFRDs7T0FFRztJQUNJLEdBQUcsQ0FBQyxLQUFlLEVBQUUsT0FBZSxFQUFFLFVBQTJCLEVBQUU7UUFDeEUsNkJBQTZCO1FBQzdCLE1BQU0sU0FBUyxHQUFHLE9BQU8sQ0FBQyxLQUFLLENBQUMsQ0FBQyxDQUFDO1lBQ2hDLFlBQVksRUFBRSxPQUFPLENBQUMsS0FBSyxDQUFDLE9BQU87WUFDbkMsVUFBVSxFQUFFLE9BQU8sQ0FBQyxLQUFLLENBQUMsS0FBSztZQUMvQixTQUFTLEVBQUUsT0FBTyxDQUFDLEtBQUssQ0FBQyxJQUFJO1NBQzlCLENBQUMsQ0FBQyxDQUFDLEVBQUUsQ0FBQztRQUVQLE1BQU0sT0FBTyxHQUFHO1lBQ2QsU0FBUyxFQUFFLGFBQWE7WUFDeEIsT0FBTyxFQUFFLElBQUksQ0FBQyxXQUFXO1lBQ3pCLGlCQUFpQixFQUFFLElBQUksQ0FBQyxpQkFBaUIsQ0FBQyxpQkFBaUI7WUFDM0QsR0FBRyxPQUFPO1lBQ1YsR0FBRyxTQUFTO1NBQ2IsQ0FBQztRQUVGLElBQUksT0FBTyxDQUFDLEtBQUssRUFBRSxDQUFDO1lBQ2xCLE9BQU8sT0FBTyxDQUFDLEtBQUssQ0FBQztRQUN2QixDQUFDO1FBRUQsTUFBTSxDQUFDLEdBQUcsQ0FBQyxLQUFLLEVBQUUsT0FBTyxFQUFFLE9BQU8sQ0FBQyxDQUFDO1FBRXBDLHlDQUF5QztRQUN6QyxRQUFRLElBQUksQ0FBQyxXQUFXLEVBQUUsQ0FBQztZQUN6QixLQUFLLE9BQU8sQ0FBQyxPQUFPO2dCQUNsQix1QkFBdUI7Z0JBQ3ZCLElBQUksS0FBSyxLQUFLLE9BQU8sSUFBSSxLQUFLLEtBQUssTUFBTSxFQUFFLENBQUM7b0JBQzFDLE9BQU8sQ0FBQyxLQUFLLENBQUMsQ0FBQyxVQUFVLE9BQU8sRUFBRSxFQUFFLE9BQU8sQ0FBQyxDQUFDO2dCQUMvQyxDQUFDO2dCQUNELE1BQU07WUFFUixLQUFLLE9BQU8sQ0FBQyxPQUFPO2dCQUNsQixzQ0FBc0M7Z0JBQ3RDLElBQUksS0FBSyxLQUFLLE9BQU8sSUFBSSxLQUFLLEtBQUssTUFBTSxFQUFFLENBQUM7b0JBQzFDLE9BQU8sQ0FBQyxLQUFLLENBQUMsQ0FBQyxVQUFVL