From 3b2b596014db2b709789c968a9713eed4b4a6cab Mon Sep 17 00:00:00 2001 From: 0x1d Date: Thu, 16 Oct 2025 22:08:56 +0200 Subject: [PATCH] feat: logging system and reduced logs --- docs/LOGGING.md | 69 +++++++++++++++++++++++++++++++++++++++++++++++++ index.js | 54 +++++++++++++++++++++++--------------- 2 files changed, 102 insertions(+), 21 deletions(-) create mode 100644 docs/LOGGING.md diff --git a/docs/LOGGING.md b/docs/LOGGING.md new file mode 100644 index 0000000..dc56053 --- /dev/null +++ b/docs/LOGGING.md @@ -0,0 +1,69 @@ +# SPORE UI Backend Logging + +The SPORE UI backend now includes a configurable logging system to reduce log noise while maintaining important information. + +## Log Levels + +The logging system supports different levels: + +- **INFO**: Important operational messages (default) +- **DEBUG**: Detailed debugging information (only shown when enabled) +- **WARN**: Warning messages +- **ERROR**: Error messages + +## Controlling Log Levels + +### Environment Variables + +Set the `LOG_LEVEL` environment variable to control logging: + +```bash +# Show only INFO, WARN, and ERROR messages (default) +LOG_LEVEL=info + +# Show all messages including DEBUG +LOG_LEVEL=debug +``` + +### Development Mode + +In development mode (`NODE_ENV=development`), DEBUG messages are automatically enabled: + +```bash +NODE_ENV=development npm start +``` + +## What Was Changed + +The following verbose logging has been moved to DEBUG level: + +1. **Heartbeat Messages**: Regular heartbeat logs from nodes +2. **WebSocket Broadcasts**: Routine cluster update broadcasts +3. **Proxy Calls**: Individual API proxy request details +4. **Cluster Updates**: Member list change notifications +5. **Discovery Events**: Routine node discovery messages + +## Important Messages Still Shown + +These messages remain at INFO level for operational visibility: + +- Node discovery (new nodes) +- Node status changes (inactive/stale) +- Failover events +- Server startup/shutdown +- Error conditions + +## Example Usage + +```bash +# Production with minimal logging +LOG_LEVEL=info npm start + +# Development with full debugging +LOG_LEVEL=debug npm start + +# Or use development mode +NODE_ENV=development npm start +``` + +This reduces log noise significantly while preserving important operational information. diff --git a/index.js b/index.js index ace820e..34ba222 100644 --- a/index.js +++ b/index.js @@ -6,6 +6,18 @@ const SporeApiClient = require('./src/client'); const cors = require('cors'); const WebSocket = require('ws'); +// Simple logging utility with level control +const logger = { + debug: (...args) => { + if (process.env.LOG_LEVEL === 'debug' || process.env.NODE_ENV === 'development') { + console.log('[DEBUG]', ...args); + } + }, + info: (...args) => console.log('[INFO]', ...args), + warn: (...args) => console.warn('[WARN]', ...args), + error: (...args) => console.error('[ERROR]', ...args) +}; + const app = express(); const PORT = process.env.PORT || 3001; @@ -113,7 +125,7 @@ udpServer.on('message', (msg, rinfo) => { existingNode.hostname = hostname; existingNode.status = 'active'; // Mark as active when heartbeat received - console.log(`💓 Heartbeat from ${sourceIp}:${sourcePort} (${hostname}). Total nodes: ${discoveredNodes.size}`); + logger.debug(`💓 Heartbeat from ${sourceIp}:${sourcePort} (${hostname}). Total nodes: ${discoveredNodes.size}`); // Check if hostname changed const hostnameChanged = oldHostname !== hostname; @@ -127,7 +139,7 @@ udpServer.on('message', (msg, rinfo) => { hostnameChanged ? 'hostname update' : 'active heartbeat'; - console.log(`📡 Broadcasting heartbeat update: ${reason}`); + logger.debug(`📡 Broadcasting heartbeat update: ${reason}`); broadcastMemberListChange(reason); } else { // Create new node entry from heartbeat - NEW NODE DISCOVERED @@ -210,7 +222,7 @@ function markStaleNodes() { nodesMarkedStale = true; // Broadcast stale node event immediately - console.log(`📡 Broadcasting stale node event for ${ip}`); + logger.debug(`📡 Broadcasting stale node event for ${ip}`); broadcastNodeDiscovery(ip, 'stale'); // If this was our primary node, clear it and select a new one @@ -332,7 +344,7 @@ async function performWithFailover(operation) { if (ip !== primaryNodeIp) { primaryNodeIp = ip; sporeClient = client; - console.log(`Failover: switched primary node to ${ip}`); + logger.info(`Failover: switched primary node to ${ip}`); broadcastMemberListChange('failover primary node switch'); } return result; @@ -680,9 +692,9 @@ app.post('/api/proxy-call', async (req, res) => { // Debug logging to trace upstream requests try { - console.log('[proxy-call] →', upperMethod, fullUrl); + logger.debug('[proxy-call] →', upperMethod, fullUrl); if (upperMethod !== 'GET') { - console.log('[proxy-call] body:', fetchOptions.body); + logger.debug('[proxy-call] body:', fetchOptions.body); } } catch (_) { // ignore logging errors @@ -892,7 +904,7 @@ function broadcastClusterUpdate() { if (wsClients.size === 0 || !wss) return; const startTime = Date.now(); - console.log(`📡 [${new Date().toISOString()}] Starting cluster update broadcast to ${wsClients.size} clients`); + logger.debug(`📡 [${new Date().toISOString()}] Starting cluster update broadcast to ${wsClients.size} clients`); // Get cluster members asynchronously getCurrentClusterMembers().then(members => { @@ -906,8 +918,8 @@ function broadcastClusterUpdate() { const message = JSON.stringify(clusterData); const broadcastTime = Date.now() - startTime; - console.log(`📡 [${new Date().toISOString()}] Broadcasting cluster update to ${wsClients.size} WebSocket clients (took ${broadcastTime}ms)`); - console.log(`📊 Cluster data: ${members.length} members, primary: ${primaryNodeIp || 'none'}`); + logger.debug(`📡 [${new Date().toISOString()}] Broadcasting cluster update to ${wsClients.size} WebSocket clients (took ${broadcastTime}ms)`); + logger.debug(`📊 Cluster data: ${members.length} members, primary: ${primaryNodeIp || 'none'}`); wsClients.forEach((client) => { if (client.readyState === WebSocket.OPEN) { @@ -941,7 +953,7 @@ function broadcastNodeDiscovery(nodeIp, action) { // Helper function to broadcast member list changes function broadcastMemberListChange(reason = 'update') { const timestamp = new Date().toISOString(); - console.log(`🔄 [${timestamp}] Member list changed (${reason}), broadcasting update`); + logger.debug(`🔄 [${timestamp}] Member list changed (${reason}), broadcasting update`); broadcastClusterUpdate(); } @@ -953,14 +965,14 @@ async function getCurrentClusterMembers() { } // Fetch real cluster data from SPORE nodes for accurate information - console.log(`📡 Fetching real cluster data from ${discoveredNodes.size} nodes for WebSocket broadcast`); + logger.debug(`📡 Fetching real cluster data from ${discoveredNodes.size} nodes for WebSocket broadcast`); const clusterResponse = await performWithFailover((client) => client.getClusterStatus()); const apiMembers = clusterResponse.members || []; // Debug: Log the labels from the API response apiMembers.forEach(member => { if (member.labels && Object.keys(member.labels).length > 0) { - console.log(`🏷️ API member ${member.ip} labels:`, member.labels); + logger.debug(`🏷️ API member ${member.ip} labels:`, member.labels); } }); @@ -977,7 +989,7 @@ async function getCurrentClusterMembers() { JSON.stringify(localNode.labels) !== JSON.stringify(apiMember.labels); if (needsUpdate) { - console.log(`🔄 Updating local node ${apiMember.ip} with fresh API data`); + logger.debug(`🔄 Updating local node ${apiMember.ip} with fresh API data`); localNode.hostname = apiMember.hostname; localNode.status = apiMember.status; localNode.latency = apiMember.latency; @@ -987,7 +999,7 @@ async function getCurrentClusterMembers() { } } else { // New node discovered via API - shouldn't happen but handle it - console.log(`🆕 New node discovered via API: ${apiMember.ip}`); + logger.debug(`🆕 New node discovered via API: ${apiMember.ip}`); discoveredNodes.set(apiMember.ip, { ip: apiMember.ip, hostname: apiMember.hostname, @@ -1003,7 +1015,7 @@ async function getCurrentClusterMembers() { // If we updated any nodes, broadcast the changes if (updatedNodes) { - console.log(`📡 Local node data updated, triggering immediate broadcast`); + logger.debug(`📡 Local node data updated, triggering immediate broadcast`); // Note: We don't call broadcastMemberListChange here because we're already in the middle of a broadcast // The calling function will handle the broadcast } @@ -1025,13 +1037,13 @@ async function getCurrentClusterMembers() { return apiMember; }); - console.log(`📊 Returning ${enhancedMembers.length} enhanced cluster members via WebSocket`); + logger.debug(`📊 Returning ${enhancedMembers.length} enhanced cluster members via WebSocket`); return enhancedMembers; } catch (error) { console.error('Error getting cluster members for WebSocket:', error); // Fallback to local data if API fails - console.log('⚠️ API failed, falling back to local discoveredNodes data'); + logger.debug('⚠️ API failed, falling back to local discoveredNodes data'); const fallbackMembers = Array.from(discoveredNodes.values()).map(node => ({ ip: node.ip, hostname: node.hostname || 'Unknown Device', @@ -1042,7 +1054,7 @@ async function getCurrentClusterMembers() { resources: node.resources || {} })); - console.log(`📊 Fallback: Returning ${fallbackMembers.length} local cluster members`); + logger.debug(`📊 Fallback: Returning ${fallbackMembers.length} local cluster members`); return fallbackMembers; } } @@ -1053,7 +1065,7 @@ function initializeWebSocketServer(httpServer) { // WebSocket connection handler wss.on('connection', (ws) => { - console.log('WebSocket client connected'); + logger.debug('WebSocket client connected'); wsClients.add(ws); // Send current cluster state to newly connected client @@ -1067,7 +1079,7 @@ function initializeWebSocketServer(httpServer) { totalNodes: discoveredNodes.size, timestamp: new Date().toISOString() }; - console.log(`🔌 Sending initial cluster state to new WebSocket client: ${members.length} members`); + logger.debug(`🔌 Sending initial cluster state to new WebSocket client: ${members.length} members`); ws.send(JSON.stringify(clusterData)); }).catch(error => { console.error('Error sending initial cluster state:', error); @@ -1076,7 +1088,7 @@ function initializeWebSocketServer(httpServer) { // Handle client disconnection ws.on('close', () => { - console.log('WebSocket client disconnected'); + logger.debug('WebSocket client disconnected'); wsClients.delete(ws); });