feat: logging system and reduced logs
This commit is contained in:
69
docs/LOGGING.md
Normal file
69
docs/LOGGING.md
Normal file
@@ -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.
|
||||||
54
index.js
54
index.js
@@ -6,6 +6,18 @@ const SporeApiClient = require('./src/client');
|
|||||||
const cors = require('cors');
|
const cors = require('cors');
|
||||||
const WebSocket = require('ws');
|
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 app = express();
|
||||||
const PORT = process.env.PORT || 3001;
|
const PORT = process.env.PORT || 3001;
|
||||||
|
|
||||||
@@ -113,7 +125,7 @@ udpServer.on('message', (msg, rinfo) => {
|
|||||||
existingNode.hostname = hostname;
|
existingNode.hostname = hostname;
|
||||||
existingNode.status = 'active'; // Mark as active when heartbeat received
|
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
|
// Check if hostname changed
|
||||||
const hostnameChanged = oldHostname !== hostname;
|
const hostnameChanged = oldHostname !== hostname;
|
||||||
@@ -127,7 +139,7 @@ udpServer.on('message', (msg, rinfo) => {
|
|||||||
hostnameChanged ? 'hostname update' :
|
hostnameChanged ? 'hostname update' :
|
||||||
'active heartbeat';
|
'active heartbeat';
|
||||||
|
|
||||||
console.log(`📡 Broadcasting heartbeat update: ${reason}`);
|
logger.debug(`📡 Broadcasting heartbeat update: ${reason}`);
|
||||||
broadcastMemberListChange(reason);
|
broadcastMemberListChange(reason);
|
||||||
} else {
|
} else {
|
||||||
// Create new node entry from heartbeat - NEW NODE DISCOVERED
|
// Create new node entry from heartbeat - NEW NODE DISCOVERED
|
||||||
@@ -210,7 +222,7 @@ function markStaleNodes() {
|
|||||||
nodesMarkedStale = true;
|
nodesMarkedStale = true;
|
||||||
|
|
||||||
// Broadcast stale node event immediately
|
// Broadcast stale node event immediately
|
||||||
console.log(`📡 Broadcasting stale node event for ${ip}`);
|
logger.debug(`📡 Broadcasting stale node event for ${ip}`);
|
||||||
broadcastNodeDiscovery(ip, 'stale');
|
broadcastNodeDiscovery(ip, 'stale');
|
||||||
|
|
||||||
// If this was our primary node, clear it and select a new one
|
// If this was our primary node, clear it and select a new one
|
||||||
@@ -332,7 +344,7 @@ async function performWithFailover(operation) {
|
|||||||
if (ip !== primaryNodeIp) {
|
if (ip !== primaryNodeIp) {
|
||||||
primaryNodeIp = ip;
|
primaryNodeIp = ip;
|
||||||
sporeClient = client;
|
sporeClient = client;
|
||||||
console.log(`Failover: switched primary node to ${ip}`);
|
logger.info(`Failover: switched primary node to ${ip}`);
|
||||||
broadcastMemberListChange('failover primary node switch');
|
broadcastMemberListChange('failover primary node switch');
|
||||||
}
|
}
|
||||||
return result;
|
return result;
|
||||||
@@ -680,9 +692,9 @@ app.post('/api/proxy-call', async (req, res) => {
|
|||||||
|
|
||||||
// Debug logging to trace upstream requests
|
// Debug logging to trace upstream requests
|
||||||
try {
|
try {
|
||||||
console.log('[proxy-call] →', upperMethod, fullUrl);
|
logger.debug('[proxy-call] →', upperMethod, fullUrl);
|
||||||
if (upperMethod !== 'GET') {
|
if (upperMethod !== 'GET') {
|
||||||
console.log('[proxy-call] body:', fetchOptions.body);
|
logger.debug('[proxy-call] body:', fetchOptions.body);
|
||||||
}
|
}
|
||||||
} catch (_) {
|
} catch (_) {
|
||||||
// ignore logging errors
|
// ignore logging errors
|
||||||
@@ -892,7 +904,7 @@ function broadcastClusterUpdate() {
|
|||||||
if (wsClients.size === 0 || !wss) return;
|
if (wsClients.size === 0 || !wss) return;
|
||||||
|
|
||||||
const startTime = Date.now();
|
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
|
// Get cluster members asynchronously
|
||||||
getCurrentClusterMembers().then(members => {
|
getCurrentClusterMembers().then(members => {
|
||||||
@@ -906,8 +918,8 @@ function broadcastClusterUpdate() {
|
|||||||
|
|
||||||
const message = JSON.stringify(clusterData);
|
const message = JSON.stringify(clusterData);
|
||||||
const broadcastTime = Date.now() - startTime;
|
const broadcastTime = Date.now() - startTime;
|
||||||
console.log(`📡 [${new Date().toISOString()}] Broadcasting cluster update to ${wsClients.size} WebSocket clients (took ${broadcastTime}ms)`);
|
logger.debug(`📡 [${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(`📊 Cluster data: ${members.length} members, primary: ${primaryNodeIp || 'none'}`);
|
||||||
|
|
||||||
wsClients.forEach((client) => {
|
wsClients.forEach((client) => {
|
||||||
if (client.readyState === WebSocket.OPEN) {
|
if (client.readyState === WebSocket.OPEN) {
|
||||||
@@ -941,7 +953,7 @@ function broadcastNodeDiscovery(nodeIp, action) {
|
|||||||
// Helper function to broadcast member list changes
|
// Helper function to broadcast member list changes
|
||||||
function broadcastMemberListChange(reason = 'update') {
|
function broadcastMemberListChange(reason = 'update') {
|
||||||
const timestamp = new Date().toISOString();
|
const timestamp = new Date().toISOString();
|
||||||
console.log(`🔄 [${timestamp}] Member list changed (${reason}), broadcasting update`);
|
logger.debug(`🔄 [${timestamp}] Member list changed (${reason}), broadcasting update`);
|
||||||
broadcastClusterUpdate();
|
broadcastClusterUpdate();
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -953,14 +965,14 @@ async function getCurrentClusterMembers() {
|
|||||||
}
|
}
|
||||||
|
|
||||||
// Fetch real cluster data from SPORE nodes for accurate information
|
// 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 clusterResponse = await performWithFailover((client) => client.getClusterStatus());
|
||||||
const apiMembers = clusterResponse.members || [];
|
const apiMembers = clusterResponse.members || [];
|
||||||
|
|
||||||
// Debug: Log the labels from the API response
|
// Debug: Log the labels from the API response
|
||||||
apiMembers.forEach(member => {
|
apiMembers.forEach(member => {
|
||||||
if (member.labels && Object.keys(member.labels).length > 0) {
|
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);
|
JSON.stringify(localNode.labels) !== JSON.stringify(apiMember.labels);
|
||||||
|
|
||||||
if (needsUpdate) {
|
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.hostname = apiMember.hostname;
|
||||||
localNode.status = apiMember.status;
|
localNode.status = apiMember.status;
|
||||||
localNode.latency = apiMember.latency;
|
localNode.latency = apiMember.latency;
|
||||||
@@ -987,7 +999,7 @@ async function getCurrentClusterMembers() {
|
|||||||
}
|
}
|
||||||
} else {
|
} else {
|
||||||
// New node discovered via API - shouldn't happen but handle it
|
// 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, {
|
discoveredNodes.set(apiMember.ip, {
|
||||||
ip: apiMember.ip,
|
ip: apiMember.ip,
|
||||||
hostname: apiMember.hostname,
|
hostname: apiMember.hostname,
|
||||||
@@ -1003,7 +1015,7 @@ async function getCurrentClusterMembers() {
|
|||||||
|
|
||||||
// If we updated any nodes, broadcast the changes
|
// If we updated any nodes, broadcast the changes
|
||||||
if (updatedNodes) {
|
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
|
// Note: We don't call broadcastMemberListChange here because we're already in the middle of a broadcast
|
||||||
// The calling function will handle the broadcast
|
// The calling function will handle the broadcast
|
||||||
}
|
}
|
||||||
@@ -1025,13 +1037,13 @@ async function getCurrentClusterMembers() {
|
|||||||
return apiMember;
|
return apiMember;
|
||||||
});
|
});
|
||||||
|
|
||||||
console.log(`📊 Returning ${enhancedMembers.length} enhanced cluster members via WebSocket`);
|
logger.debug(`📊 Returning ${enhancedMembers.length} enhanced cluster members via WebSocket`);
|
||||||
return enhancedMembers;
|
return enhancedMembers;
|
||||||
} catch (error) {
|
} catch (error) {
|
||||||
console.error('Error getting cluster members for WebSocket:', error);
|
console.error('Error getting cluster members for WebSocket:', error);
|
||||||
|
|
||||||
// Fallback to local data if API fails
|
// 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 => ({
|
const fallbackMembers = Array.from(discoveredNodes.values()).map(node => ({
|
||||||
ip: node.ip,
|
ip: node.ip,
|
||||||
hostname: node.hostname || 'Unknown Device',
|
hostname: node.hostname || 'Unknown Device',
|
||||||
@@ -1042,7 +1054,7 @@ async function getCurrentClusterMembers() {
|
|||||||
resources: node.resources || {}
|
resources: node.resources || {}
|
||||||
}));
|
}));
|
||||||
|
|
||||||
console.log(`📊 Fallback: Returning ${fallbackMembers.length} local cluster members`);
|
logger.debug(`📊 Fallback: Returning ${fallbackMembers.length} local cluster members`);
|
||||||
return fallbackMembers;
|
return fallbackMembers;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -1053,7 +1065,7 @@ function initializeWebSocketServer(httpServer) {
|
|||||||
|
|
||||||
// WebSocket connection handler
|
// WebSocket connection handler
|
||||||
wss.on('connection', (ws) => {
|
wss.on('connection', (ws) => {
|
||||||
console.log('WebSocket client connected');
|
logger.debug('WebSocket client connected');
|
||||||
wsClients.add(ws);
|
wsClients.add(ws);
|
||||||
|
|
||||||
// Send current cluster state to newly connected client
|
// Send current cluster state to newly connected client
|
||||||
@@ -1067,7 +1079,7 @@ function initializeWebSocketServer(httpServer) {
|
|||||||
totalNodes: discoveredNodes.size,
|
totalNodes: discoveredNodes.size,
|
||||||
timestamp: new Date().toISOString()
|
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));
|
ws.send(JSON.stringify(clusterData));
|
||||||
}).catch(error => {
|
}).catch(error => {
|
||||||
console.error('Error sending initial cluster state:', error);
|
console.error('Error sending initial cluster state:', error);
|
||||||
@@ -1076,7 +1088,7 @@ function initializeWebSocketServer(httpServer) {
|
|||||||
|
|
||||||
// Handle client disconnection
|
// Handle client disconnection
|
||||||
ws.on('close', () => {
|
ws.on('close', () => {
|
||||||
console.log('WebSocket client disconnected');
|
logger.debug('WebSocket client disconnected');
|
||||||
wsClients.delete(ws);
|
wsClients.delete(ws);
|
||||||
});
|
});
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user