enable debug

This commit is contained in:
cpu
2025-03-28 03:11:14 +01:00
parent 13a16d71f8
commit b6f9e07d70
3 changed files with 84 additions and 45 deletions

View File

@@ -69,6 +69,7 @@ It's designed to be run as a Docker container and integrated with Traefik v3 for
* `INITIAL_RETRY_DELAY_MS`: (Default: `1000`) Initial delay in milliseconds before first retry. Must be a number. * `INITIAL_RETRY_DELAY_MS`: (Default: `1000`) Initial delay in milliseconds before first retry. Must be a number.
* `DNS_TIMEOUT_MS`: (Default: `5000`) DNS resolution timeout in milliseconds. Must be a number. * `DNS_TIMEOUT_MS`: (Default: `5000`) DNS resolution timeout in milliseconds. Must be a number.
* `HTTP_TIMEOUT_MS`: (Default: `10000`) HTTP request timeout in milliseconds. Must be a number. * `HTTP_TIMEOUT_MS`: (Default: `10000`) HTTP request timeout in milliseconds. Must be a number.
* `LOG_LEVEL`: (Default: `info`) Controls verbosity of logs. Valid values are `error`, `warn`, `info`, or `debug`. Use `debug` to see detailed header information and other diagnostic messages.
* `TRAEFIK_SERVICE_HOST`: Your public domain for this service (e.g., `webpush.virtonline.eu`). * `TRAEFIK_SERVICE_HOST`: Your public domain for this service (e.g., `webpush.virtonline.eu`).
* `TRAEFIK_CERT_RESOLVER`: The name of your TLS certificate resolver configured in Traefik (e.g., `le`, `myresolver`). * `TRAEFIK_CERT_RESOLVER`: The name of your TLS certificate resolver configured in Traefik (e.g., `le`, `myresolver`).
@@ -191,7 +192,7 @@ If you receive a different response, refer to the Troubleshooting section below.
## Troubleshooting ## Troubleshooting
* **Check Backend Logs:** `docker logs flic-webhook-webpush`. Look for errors related to configuration, file access, JSON parsing, authentication, or sending push notifications. * **Check Backend Logs:** `docker logs flic-webhook-webpush`. Look for errors related to configuration, file access, JSON parsing, authentication, or sending push notifications.
* The server logs all headers received from Flic requests to help with debugging. Look for lines starting with `DEBUG - All headers received:` to see all headers sent by the Flic button. * To see detailed debug information including all headers received from the Flic button, set `LOG_LEVEL=debug` in your .env file.
* **Check Traefik Logs:** `docker logs traefik`. Look for routing errors or certificate issues. * **Check Traefik Logs:** `docker logs traefik`. Look for routing errors or certificate issues.
* **Verify `.env`:** Ensure all required variables are set correctly, especially VAPID keys and Traefik settings. * **Verify `.env`:** Ensure all required variables are set correctly, especially VAPID keys and Traefik settings.
* **Verify `labels`:** Double-check that variables were correctly substituted manually and match your `.env` and Traefik setup. * **Verify `labels`:** Double-check that variables were correctly substituted manually and match your `.env` and Traefik setup.

14
labels
View File

@@ -8,7 +8,7 @@ traefik.docker.network=traefik
traefik.http.routers.flic-webhook-webpush.rule=Host(`webpush.virtonline.eu`) traefik.http.routers.flic-webhook-webpush.rule=Host(`webpush.virtonline.eu`)
# Specify the entrypoint ('websecure' for HTTPS) # Specify the entrypoint ('websecure' for HTTPS)
traefik.http.routers.flic-webhook-webpush.entrypoints=web-secure traefik.http.routers.flic-webhook-webpush.entrypoints=web-secure
traefik.http.routers.flic-webhook-webpush.tls=true # Enable TLS traefik.http.routers.flic-webhook-webpush.tls=true
traefik.http.routers.flic-webhook-webpush.tls.certResolver=default traefik.http.routers.flic-webhook-webpush.tls.certResolver=default
# Link the router to the service defined below # Link the router to the service defined below
traefik.http.routers.flic-webhook-webpush.service=flic-webhook-webpush traefik.http.routers.flic-webhook-webpush.service=flic-webhook-webpush
@@ -17,16 +17,16 @@ traefik.http.routers.flic-webhook-webpush.service=flic-webhook-webpush
traefik.http.services.flic-webhook-webpush.loadbalancer.server.port=3000 traefik.http.services.flic-webhook-webpush.loadbalancer.server.port=3000
# Middleware CORS # Middleware CORS
traefik.http.middlewares.cors-headers.headers.accesscontrolallowmethods=POST,GET,OPTIONS # Allow POST, GET, and OPTIONS requests traefik.http.middlewares.cors-headers.headers.accesscontrolallowmethods=POST,GET,OPTIONS
traefik.http.middlewares.cors-headers.headers.accesscontrolalloworiginlist=https://game-timer.virtonline.eu # Allow requests from game-timer.virtonline.eu traefik.http.middlewares.cors-headers.headers.accesscontrolalloworiginlist=https://game-timer.virtonline.eu
traefik.http.middlewares.cors-headers.headers.accesscontrolallowheaders=Content-Type,Authorization # Allow Content-Type and Authorization headers traefik.http.middlewares.cors-headers.headers.accesscontrolallowheaders=Content-Type,Authorization
traefik.http.middlewares.cors-headers.headers.accesscontrolmaxage=600 # Cache preflight responses for 10 minutes traefik.http.middlewares.cors-headers.headers.accesscontrolmaxage=600
traefik.http.middlewares.cors-headers.headers.addvaryheader=true # Add Vary header to responses traefik.http.middlewares.cors-headers.headers.addvaryheader=true
# Apply the middleware to the router # Apply the middleware to the router
traefik.http.routers.flic-webhook-webpush.middlewares=cors-headers traefik.http.routers.flic-webhook-webpush.middlewares=cors-headers
# Middleware Rate Limiting # Middleware Rate Limiting
traefik.http.middlewares.flic-ratelimit.ratelimit.average=10 # requests per second traefik.http.middlewares.flic-ratelimit.ratelimit.average=10
traefik.http.middlewares.flic-ratelimit.ratelimit.burst=20 traefik.http.middlewares.flic-ratelimit.ratelimit.burst=20
# Apply the middleware to the router # Apply the middleware to the router
traefik.http.routers.flic-webhook-webpush.middlewares=flic-ratelimit traefik.http.routers.flic-webhook-webpush.middlewares=flic-ratelimit

112
server.js
View File

@@ -25,6 +25,37 @@ const maxRetries = parseInt(process.env.MAX_NOTIFICATION_RETRIES || 3, 10);
const initialRetryDelay = parseInt(process.env.INITIAL_RETRY_DELAY_MS || 1000, 10); // 1 second const initialRetryDelay = parseInt(process.env.INITIAL_RETRY_DELAY_MS || 1000, 10); // 1 second
// HTTP request timeout configuration // HTTP request timeout configuration
const httpTimeout = parseInt(process.env.HTTP_TIMEOUT_MS || 10000, 10); // 10 seconds const httpTimeout = parseInt(process.env.HTTP_TIMEOUT_MS || 10000, 10); // 10 seconds
// Logging level configuration
const LOG_LEVEL = (process.env.LOG_LEVEL || 'info').toLowerCase();
// --- Logging Utility ---
const LogLevels = {
error: 0,
warn: 1,
info: 2,
debug: 3
};
const logger = {
error: (...args) => {
console.error(...args);
},
warn: (...args) => {
if (LogLevels[LOG_LEVEL] >= LogLevels.warn) {
console.warn(...args);
}
},
info: (...args) => {
if (LogLevels[LOG_LEVEL] >= LogLevels.info) {
console.log(...args);
}
},
debug: (...args) => {
if (LogLevels[LOG_LEVEL] >= LogLevels.debug) {
console.log('DEBUG -', ...args);
}
}
};
// Configure global HTTP agent with timeouts to prevent hanging requests // Configure global HTTP agent with timeouts to prevent hanging requests
const https = require('https'); const https = require('https');
@@ -43,7 +74,7 @@ https.globalAgent = httpsAgent;
// --- Validation --- // --- Validation ---
if (!vapidPublicKey || !vapidPrivateKey || !vapidSubject) { if (!vapidPublicKey || !vapidPrivateKey || !vapidSubject) {
console.error('Error: VAPID_PUBLIC_KEY, VAPID_PRIVATE_KEY, and VAPID_SUBJECT must be set in the environment variables.'); logger.error('Error: VAPID_PUBLIC_KEY, VAPID_PRIVATE_KEY, and VAPID_SUBJECT must be set in the environment variables.');
process.exit(1); process.exit(1);
} }
@@ -96,12 +127,12 @@ let subscriptions = {}; // In-memory cache of subscriptions
function loadSubscriptions() { function loadSubscriptions() {
if (!fs.existsSync(subscriptionsFilePath)) { if (!fs.existsSync(subscriptionsFilePath)) {
console.warn(`Warning: Subscriptions file not found at ${subscriptionsFilePath}. Creating an empty file.`); logger.warn(`Warning: Subscriptions file not found at ${subscriptionsFilePath}. Creating an empty file.`);
try { try {
fs.writeFileSync(subscriptionsFilePath, '{}', 'utf8'); fs.writeFileSync(subscriptionsFilePath, '{}', 'utf8');
subscriptions = {}; subscriptions = {};
} catch (err) { } catch (err) {
console.error(`Error: Could not create subscriptions file at ${subscriptionsFilePath}.`, err); logger.error(`Error: Could not create subscriptions file at ${subscriptionsFilePath}.`, err);
// Exit or continue with empty object depending on desired robustness // Exit or continue with empty object depending on desired robustness
process.exit(1); // Exit if we can't even create the file process.exit(1); // Exit if we can't even create the file
} }
@@ -109,9 +140,9 @@ function loadSubscriptions() {
try { try {
const data = fs.readFileSync(subscriptionsFilePath, 'utf8'); const data = fs.readFileSync(subscriptionsFilePath, 'utf8');
subscriptions = JSON.parse(data || '{}'); // Handle empty file case subscriptions = JSON.parse(data || '{}'); // Handle empty file case
console.log(`Loaded ${Object.keys(subscriptions).length} subscriptions from ${subscriptionsFilePath}`); logger.info(`Loaded ${Object.keys(subscriptions).length} subscriptions from ${subscriptionsFilePath}`);
} catch (err) { } catch (err) {
console.error(`Error reading or parsing subscriptions file at ${subscriptionsFilePath}. Please ensure it's valid JSON. Using empty cache.`, err); logger.error(`Error reading or parsing subscriptions file at ${subscriptionsFilePath}. Please ensure it's valid JSON. Using empty cache.`, err);
// Continue with empty subscriptions, but log the error // Continue with empty subscriptions, but log the error
subscriptions = {}; subscriptions = {};
} }
@@ -121,9 +152,9 @@ function loadSubscriptions() {
function saveSubscriptions() { function saveSubscriptions() {
try { try {
fs.writeFileSync(subscriptionsFilePath, JSON.stringify(subscriptions, null, 2), 'utf8'); // Pretty print JSON fs.writeFileSync(subscriptionsFilePath, JSON.stringify(subscriptions, null, 2), 'utf8'); // Pretty print JSON
console.log(`Subscriptions successfully saved to ${subscriptionsFilePath}`); logger.info(`Subscriptions successfully saved to ${subscriptionsFilePath}`);
} catch (err) { } catch (err) {
console.error(`Error writing subscriptions file: ${subscriptionsFilePath}`, err); logger.error(`Error writing subscriptions file: ${subscriptionsFilePath}`, err);
// Note: The in-memory object is updated, but persistence failed. // Note: The in-memory object is updated, but persistence failed.
} }
} }
@@ -167,32 +198,37 @@ const authenticateFlicRequest = (req, res, next) => {
const authHeader = req.headers.authorization; const authHeader = req.headers.authorization;
if (!authHeader || !authHeader.startsWith('Bearer ')) { if (!authHeader || !authHeader.startsWith('Bearer ')) {
console.warn('Auth (Flic): Missing or malformed Authorization header'); logger.warn('Auth (Flic): Missing or malformed Authorization header');
return res.status(401).json({ message: 'Unauthorized: Missing or malformed Bearer token' }); return res.status(401).json({ message: 'Unauthorized: Missing or malformed Bearer token' });
} }
const token = authHeader.split(' ')[1]; const token = authHeader.split(' ')[1];
if (token !== flicSecret) { if (token !== flicSecret) {
console.warn('Auth (Flic): Invalid Bearer token received'); logger.warn('Auth (Flic): Invalid Bearer token received');
return res.status(401).json({ message: 'Unauthorized: Invalid token' }); return res.status(401).json({ message: 'Unauthorized: Invalid token' });
} }
console.log('Auth (Flic): Request authenticated successfully.'); logger.debug('Auth (Flic): Request authenticated successfully.');
next(); next();
}; };
app.post('/subscribe', async (req, res) => { app.post('/subscribe', async (req, res) => {
const { button_id, subscription } = req.body; const { button_id, subscription } = req.body;
console.log(`Received subscription request for button: ${button_id}`); logger.debug('All headers received:');
Object.keys(req.headers).forEach(headerName => {
logger.debug(` ${headerName}: ${req.headers[headerName]}`);
});
logger.info(`Received subscription request for button: ${button_id}`);
// Basic Validation // Basic Validation
if (!button_id || typeof button_id !== 'string' || button_id.trim() === '') { if (!button_id || typeof button_id !== 'string' || button_id.trim() === '') {
console.warn('Subscription Error: Missing or invalid button_id'); logger.warn('Subscription Error: Missing or invalid button_id');
return res.status(400).json({ message: 'Bad Request: Missing or invalid button_id' }); return res.status(400).json({ message: 'Bad Request: Missing or invalid button_id' });
} }
if (!subscription || typeof subscription !== 'object' || !subscription.endpoint || !subscription.keys || !subscription.keys.p256dh || !subscription.keys.auth) { if (!subscription || typeof subscription !== 'object' || !subscription.endpoint || !subscription.keys || !subscription.keys.p256dh || !subscription.keys.auth) {
console.warn('Subscription Error: Missing or invalid subscription object structure'); logger.warn('Subscription Error: Missing or invalid subscription object structure');
return res.status(400).json({ message: 'Bad Request: Missing or invalid subscription object' }); return res.status(400).json({ message: 'Bad Request: Missing or invalid subscription object' });
} }
@@ -200,7 +236,7 @@ app.post('/subscribe', async (req, res) => {
// Update in-memory store // Update in-memory store
subscriptions[normalizedButtonId] = subscription; subscriptions[normalizedButtonId] = subscription;
console.log(`Subscription for button ${normalizedButtonId} added/updated in memory.`); logger.info(`Subscription for button ${normalizedButtonId} added/updated in memory.`);
// Persist to file // Persist to file
try { try {
@@ -222,17 +258,17 @@ app.get('/flic-webhook', authenticateFlicRequest, async (req, res) => {
// Get click_type from query parameter instead of request body // Get click_type from query parameter instead of request body
const click_type = req.query.click_type; const click_type = req.query.click_type;
// Debug: Log all headers received from Flic // Log all headers received from Flic
console.log('DEBUG - All headers received:'); logger.debug('All headers received:');
Object.keys(req.headers).forEach(headerName => { Object.keys(req.headers).forEach(headerName => {
console.log(` ${headerName}: ${req.headers[headerName]}`); logger.debug(` ${headerName}: ${req.headers[headerName]}`);
}); });
console.log(`Received GET webhook: Button=${buttonName}, Type=${click_type}, Timestamp=${timestamp || 'N/A'}`); logger.info(`Received GET webhook: Button=${buttonName}, Type=${click_type}, Timestamp=${timestamp || 'N/A'}`);
// Basic validation // Basic validation
if (!buttonName || !click_type) { if (!buttonName || !click_type) {
console.warn(`Webhook Error: Missing Button-Name header or click_type query parameter`); logger.warn(`Webhook Error: Missing Button-Name header or click_type query parameter`);
return res.status(400).json({ message: 'Bad Request: Missing Button-Name header or click_type query parameter' }); return res.status(400).json({ message: 'Bad Request: Missing Button-Name header or click_type query parameter' });
} }
@@ -242,7 +278,7 @@ app.get('/flic-webhook', authenticateFlicRequest, async (req, res) => {
const subscription = subscriptions[normalizedButtonName]; const subscription = subscriptions[normalizedButtonName];
if (!subscription) { if (!subscription) {
console.warn(`Webhook: No subscription found for button ID: ${normalizedButtonName} (original: ${buttonName})`); logger.warn(`Webhook: No subscription found for button ID: ${normalizedButtonName} (original: ${buttonName})`);
return res.status(404).json({ message: `Not Found: No subscription configured for button ${normalizedButtonName}` }); return res.status(404).json({ message: `Not Found: No subscription configured for button ${normalizedButtonName}` });
} }
@@ -259,15 +295,16 @@ app.get('/flic-webhook', authenticateFlicRequest, async (req, res) => {
}); });
try { try {
console.log(`Sending push notification for ${normalizedButtonName} to endpoint: ${subscription.endpoint.substring(0, 40)}...`); logger.debug(`Subscription endpoint: ${subscription.endpoint}`);
logger.info(`Sending push notification for ${normalizedButtonName} to endpoint: ${subscription.endpoint.substring(0, 40)}...`);
await sendWebPushWithRetry(subscription, payload); await sendWebPushWithRetry(subscription, payload);
console.log(`Push notification sent successfully for button ${normalizedButtonName}.`); logger.info(`Push notification sent successfully for button ${normalizedButtonName}.`);
res.status(200).json({ message: 'Push notification sent successfully' }); res.status(200).json({ message: 'Push notification sent successfully' });
} catch (error) { } catch (error) {
console.error(`Error sending push notification for button ${normalizedButtonName}:`, error.body || error.message || error); logger.error(`Error sending push notification for button ${normalizedButtonName}:`, error.body || error.message || error);
if (error.statusCode === 404 || error.statusCode === 410) { if (error.statusCode === 404 || error.statusCode === 410) {
console.warn(`Subscription for button ${normalizedButtonName} is invalid or expired (404/410). Removing it.`); logger.warn(`Subscription for button ${normalizedButtonName} is invalid or expired (404/410). Removing it.`);
// Optionally remove the stale subscription // Optionally remove the stale subscription
delete subscriptions[normalizedButtonName]; delete subscriptions[normalizedButtonName];
saveSubscriptions(); // Attempt to save the updated list saveSubscriptions(); // Attempt to save the updated list
@@ -283,30 +320,31 @@ app.get('/flic-webhook', authenticateFlicRequest, async (req, res) => {
const server = http.createServer(app); const server = http.createServer(app);
server.listen(port, () => { server.listen(port, () => {
console.log(`Flic Webhook to WebPush server listening on port ${port}`); logger.info(`Flic Webhook to WebPush server listening on port ${port}`);
console.log(`Allowed Origins: ${allowedOrigins.length > 0 ? allowedOrigins.join(', ') : '(Any)'}`); logger.info(`Allowed Origins: ${allowedOrigins.length > 0 ? allowedOrigins.join(', ') : '(Any)'}`);
console.log(`Allowed Methods: ${allowedMethods.join(', ')}`); logger.info(`Allowed Methods: ${allowedMethods.join(', ')}`);
console.log(`Allowed Headers: ${allowedHeaders.join(', ')}`); logger.info(`Allowed Headers: ${allowedHeaders.join(', ')}`);
console.log(`Flic Webhook Auth: ${flicSecret ? 'Enabled (Bearer Token)' : 'Disabled'}`); logger.info(`Flic Webhook Auth: ${flicSecret ? 'Enabled (Bearer Token)' : 'Disabled'}`);
console.log(`Subscription Endpoint Auth: Disabled`); logger.info(`Subscription Endpoint Auth: Disabled`);
console.log(`Subscriptions File: ${subscriptionsFilePath}`); logger.info(`Subscriptions File: ${subscriptionsFilePath}`);
console.log(`Push Notification Retry Config: ${maxRetries} retries, ${initialRetryDelay}ms initial delay`); logger.info(`Push Notification Retry Config: ${maxRetries} retries, ${initialRetryDelay}ms initial delay`);
console.log(`DNS Config: IPv4 first, timeout ${dnsTimeout}ms`); logger.info(`DNS Config: IPv4 first, timeout ${dnsTimeout}ms`);
console.log(`HTTP Timeout: ${httpTimeout}ms`); logger.info(`HTTP Timeout: ${httpTimeout}ms`);
logger.info(`Log Level: ${LOG_LEVEL.toUpperCase()}`);
}); });
// --- Graceful Shutdown --- // --- Graceful Shutdown ---
const closeGracefully = (signal) => { const closeGracefully = (signal) => {
console.log(`${signal} signal received: closing HTTP server`); logger.info(`${signal} signal received: closing HTTP server`);
server.close(() => { server.close(() => {
console.log('HTTP server closed'); logger.info('HTTP server closed');
// Perform any other cleanup here if needed // Perform any other cleanup here if needed
process.exit(0); process.exit(0);
}); });
// Force close server after 10 seconds // Force close server after 10 seconds
setTimeout(() => { setTimeout(() => {
console.error('Could not close connections in time, forcefully shutting down'); logger.error('Could not close connections in time, forcefully shutting down');
process.exit(1); process.exit(1);
}, 10000); // 10 seconds timeout - This is a literal so no need to parse }, 10000); // 10 seconds timeout - This is a literal so no need to parse
} }