fix(logger): Replace raw console logging calls with structured logger usage across certificate management, connection handling, and route processing for improved observability.

This commit is contained in:
2025-05-19 23:37:11 +00:00
parent e61766959f
commit c9abdea556
6 changed files with 456 additions and 240 deletions

View File

@ -2,6 +2,7 @@ import * as plugins from '../../plugins.js';
import type { IConnectionRecord, ISmartProxyOptions } from './models/interfaces.js';
import { SecurityManager } from './security-manager.js';
import { TimeoutManager } from './timeout-manager.js';
import { logger } from '../../core/utils/logger.js';
/**
* Manages connection lifecycle, tracking, and cleanup
@ -97,7 +98,7 @@ export class ConnectionManager {
*/
public initiateCleanupOnce(record: IConnectionRecord, reason: string = 'normal'): void {
if (this.settings.enableDetailedLogging) {
console.log(`[${record.id}] Connection cleanup initiated for ${record.remoteIP} (${reason})`);
logger.log('info', `Connection cleanup initiated`, { connectionId: record.id, remoteIP: record.remoteIP, reason, component: 'connection-manager' });
}
if (
@ -139,7 +140,7 @@ export class ConnectionManager {
// Reset the handler references
record.renegotiationHandler = undefined;
} catch (err) {
console.log(`[${record.id}] Error removing data handlers: ${err}`);
logger.log('error', `Error removing data handlers for connection ${record.id}: ${err}`, { connectionId: record.id, error: err, component: 'connection-manager' });
}
}
@ -160,16 +161,36 @@ export class ConnectionManager {
// Log connection details
if (this.settings.enableDetailedLogging) {
console.log(
`[${record.id}] Connection from ${record.remoteIP} on port ${record.localPort} terminated (${reason}).` +
` Duration: ${plugins.prettyMs(duration)}, Bytes IN: ${bytesReceived}, OUT: ${bytesSent}, ` +
`TLS: ${record.isTLS ? 'Yes' : 'No'}, Keep-Alive: ${record.hasKeepAlive ? 'Yes' : 'No'}` +
`${record.usingNetworkProxy ? ', Using NetworkProxy' : ''}` +
`${record.domainSwitches ? `, Domain switches: ${record.domainSwitches}` : ''}`
logger.log('info',
`Connection from ${record.remoteIP} on port ${record.localPort} terminated (${reason}). ` +
`Duration: ${plugins.prettyMs(duration)}, Bytes IN: ${bytesReceived}, OUT: ${bytesSent}, ` +
`TLS: ${record.isTLS ? 'Yes' : 'No'}, Keep-Alive: ${record.hasKeepAlive ? 'Yes' : 'No'}` +
`${record.usingNetworkProxy ? ', Using NetworkProxy' : ''}` +
`${record.domainSwitches ? `, Domain switches: ${record.domainSwitches}` : ''}`,
{
connectionId: record.id,
remoteIP: record.remoteIP,
localPort: record.localPort,
reason,
duration: plugins.prettyMs(duration),
bytes: { in: bytesReceived, out: bytesSent },
tls: record.isTLS,
keepAlive: record.hasKeepAlive,
usingNetworkProxy: record.usingNetworkProxy,
domainSwitches: record.domainSwitches || 0,
component: 'connection-manager'
}
);
} else {
console.log(
`[${record.id}] Connection from ${record.remoteIP} terminated (${reason}). Active connections: ${this.connectionRecords.size}`
logger.log('info',
`Connection from ${record.remoteIP} terminated (${reason}). Active connections: ${this.connectionRecords.size}`,
{
connectionId: record.id,
remoteIP: record.remoteIP,
reason,
activeConnections: this.connectionRecords.size,
component: 'connection-manager'
}
);
}
}
@ -189,7 +210,7 @@ export class ConnectionManager {
socket.destroy();
}
} catch (err) {
console.log(`[${record.id}] Error destroying ${side} socket: ${err}`);
logger.log('error', `Error destroying ${side} socket for connection ${record.id}: ${err}`, { connectionId: record.id, side, error: err, component: 'connection-manager' });
}
}, 1000);
@ -199,13 +220,13 @@ export class ConnectionManager {
}
}
} catch (err) {
console.log(`[${record.id}] Error closing ${side} socket: ${err}`);
logger.log('error', `Error closing ${side} socket for connection ${record.id}: ${err}`, { connectionId: record.id, side, error: err, component: 'connection-manager' });
try {
if (!socket.destroyed) {
socket.destroy();
}
} catch (destroyErr) {
console.log(`[${record.id}] Error destroying ${side} socket: ${destroyErr}`);
logger.log('error', `Error destroying ${side} socket for connection ${record.id}: ${destroyErr}`, { connectionId: record.id, side, error: destroyErr, component: 'connection-manager' });
}
}
}
@ -224,21 +245,36 @@ export class ConnectionManager {
if (code === 'ECONNRESET') {
reason = 'econnreset';
console.log(
`[${record.id}] ECONNRESET on ${side} side from ${record.remoteIP}: ${err.message}. ` +
`Duration: ${plugins.prettyMs(connectionDuration)}, Last activity: ${plugins.prettyMs(lastActivityAge)} ago`
);
logger.log('warn', `ECONNRESET on ${side} connection from ${record.remoteIP}. Error: ${err.message}. Duration: ${plugins.prettyMs(connectionDuration)}, Last activity: ${plugins.prettyMs(lastActivityAge)}`, {
connectionId: record.id,
side,
remoteIP: record.remoteIP,
error: err.message,
duration: plugins.prettyMs(connectionDuration),
lastActivity: plugins.prettyMs(lastActivityAge),
component: 'connection-manager'
});
} else if (code === 'ETIMEDOUT') {
reason = 'etimedout';
console.log(
`[${record.id}] ETIMEDOUT on ${side} side from ${record.remoteIP}: ${err.message}. ` +
`Duration: ${plugins.prettyMs(connectionDuration)}, Last activity: ${plugins.prettyMs(lastActivityAge)} ago`
);
logger.log('warn', `ETIMEDOUT on ${side} connection from ${record.remoteIP}. Error: ${err.message}. Duration: ${plugins.prettyMs(connectionDuration)}, Last activity: ${plugins.prettyMs(lastActivityAge)}`, {
connectionId: record.id,
side,
remoteIP: record.remoteIP,
error: err.message,
duration: plugins.prettyMs(connectionDuration),
lastActivity: plugins.prettyMs(lastActivityAge),
component: 'connection-manager'
});
} else {
console.log(
`[${record.id}] Error on ${side} side from ${record.remoteIP}: ${err.message}. ` +
`Duration: ${plugins.prettyMs(connectionDuration)}, Last activity: ${plugins.prettyMs(lastActivityAge)} ago`
);
logger.log('error', `Error on ${side} connection from ${record.remoteIP}: ${err.message}. Duration: ${plugins.prettyMs(connectionDuration)}, Last activity: ${plugins.prettyMs(lastActivityAge)}`, {
connectionId: record.id,
side,
remoteIP: record.remoteIP,
error: err.message,
duration: plugins.prettyMs(connectionDuration),
lastActivity: plugins.prettyMs(lastActivityAge),
component: 'connection-manager'
});
}
if (side === 'incoming' && record.incomingTerminationReason === null) {
@ -259,7 +295,12 @@ export class ConnectionManager {
public handleClose(side: 'incoming' | 'outgoing', record: IConnectionRecord) {
return () => {
if (this.settings.enableDetailedLogging) {
console.log(`[${record.id}] Connection closed on ${side} side from ${record.remoteIP}`);
logger.log('info', `Connection closed on ${side} side`, {
connectionId: record.id,
side,
remoteIP: record.remoteIP,
component: 'connection-manager'
});
}
if (side === 'incoming' && record.incomingTerminationReason === null) {
@ -321,11 +362,13 @@ export class ConnectionManager {
if (inactivityTime > effectiveTimeout && !record.connectionClosed) {
// For keep-alive connections, issue a warning first
if (record.hasKeepAlive && !record.inactivityWarningIssued) {
console.log(
`[${id}] Warning: Keep-alive connection from ${record.remoteIP} inactive for ${
plugins.prettyMs(inactivityTime)
}. Will close in 10 minutes if no activity.`
);
logger.log('warn', `Keep-alive connection ${id} from ${record.remoteIP} inactive for ${plugins.prettyMs(inactivityTime)}. Will close in 10 minutes if no activity.`, {
connectionId: id,
remoteIP: record.remoteIP,
inactiveFor: plugins.prettyMs(inactivityTime),
closureWarning: '10 minutes',
component: 'connection-manager'
});
// Set warning flag and add grace period
record.inactivityWarningIssued = true;
@ -337,27 +380,30 @@ export class ConnectionManager {
record.outgoing.write(Buffer.alloc(0));
if (this.settings.enableDetailedLogging) {
console.log(`[${id}] Sent probe packet to test keep-alive connection`);
logger.log('info', `Sent probe packet to test keep-alive connection ${id}`, { connectionId: id, component: 'connection-manager' });
}
} catch (err) {
console.log(`[${id}] Error sending probe packet: ${err}`);
logger.log('error', `Error sending probe packet to connection ${id}: ${err}`, { connectionId: id, error: err, component: 'connection-manager' });
}
}
} else {
// For non-keep-alive or after warning, close the connection
console.log(
`[${id}] Inactivity check: No activity on connection from ${record.remoteIP} ` +
`for ${plugins.prettyMs(inactivityTime)}.` +
(record.hasKeepAlive ? ' Despite keep-alive being enabled.' : '')
);
logger.log('warn', `Closing inactive connection ${id} from ${record.remoteIP} (inactive for ${plugins.prettyMs(inactivityTime)}, keep-alive: ${record.hasKeepAlive ? 'Yes' : 'No'})`, {
connectionId: id,
remoteIP: record.remoteIP,
inactiveFor: plugins.prettyMs(inactivityTime),
hasKeepAlive: record.hasKeepAlive,
component: 'connection-manager'
});
this.cleanupConnection(record, 'inactivity');
}
} else if (inactivityTime <= effectiveTimeout && record.inactivityWarningIssued) {
// If activity detected after warning, clear the warning
if (this.settings.enableDetailedLogging) {
console.log(
`[${id}] Connection activity detected after inactivity warning, resetting warning`
);
logger.log('info', `Connection ${id} activity detected after inactivity warning`, {
connectionId: id,
component: 'connection-manager'
});
}
record.inactivityWarningIssued = false;
}
@ -369,11 +415,12 @@ export class ConnectionManager {
!record.connectionClosed &&
now - record.outgoingClosedTime > 120000
) {
console.log(
`[${id}] Parity check: Incoming socket for ${record.remoteIP} still active ${
plugins.prettyMs(now - record.outgoingClosedTime)
} after outgoing closed.`
);
logger.log('warn', `Parity check: Connection ${id} from ${record.remoteIP} has incoming socket still active ${plugins.prettyMs(now - record.outgoingClosedTime)} after outgoing socket closed`, {
connectionId: id,
remoteIP: record.remoteIP,
timeElapsed: plugins.prettyMs(now - record.outgoingClosedTime),
component: 'connection-manager'
});
this.cleanupConnection(record, 'parity_check');
}
}
@ -406,7 +453,7 @@ export class ConnectionManager {
record.outgoing.end();
}
} catch (err) {
console.log(`Error during graceful connection end for ${id}: ${err}`);
logger.log('error', `Error during graceful end of connection ${id}: ${err}`, { connectionId: id, error: err, component: 'connection-manager' });
}
}
}
@ -433,7 +480,7 @@ export class ConnectionManager {
}
}
} catch (err) {
console.log(`Error during forced connection destruction for ${id}: ${err}`);
logger.log('error', `Error during forced destruction of connection ${id}: ${err}`, { connectionId: id, error: err, component: 'connection-manager' });
}
}
}