Improve logging for Mikrotik requests and IP blocking operations

Enhance logging in `mikrotik.ts` to include request details, response statuses, and timings. Add verbose logging for successful operations and warnings for errors or slow responses. Update `getExistingBlockedIps` to log total entries and specific list counts per router. Modify `addToAddressList` to log successful additions and specific error conditions. Update `bulkBlockIps` to log detailed operation outcomes, including partial and failed IPs, with a final summary. Add router information to the `BLOCK-ALL` log in `routes.ts`.

Replit-Commit-Author: Agent
Replit-Commit-Session-Id: 7a657272-55ba-4a79-9a2e-f1ed9bc7a528
Replit-Commit-Checkpoint-Type: intermediate_checkpoint
Replit-Commit-Event-Id: 3945267e-74c4-4c36-912a-462ddd667392
Replit-Commit-Screenshot-Url: https://storage.googleapis.com/screenshot-production-us-central1/449cf7c4-c97a-45ae-8234-e5c5b8d6a84f/7a657272-55ba-4a79-9a2e-f1ed9bc7a528/6WuDAR4

server/mikrotik.ts

@@ -1,3 +1,5 @@
+const VERBOSE = process.env.MIKROTIK_DEBUG === '1' || process.env.MIKROTIK_DEBUG === 'true';
+
 interface RouterConfig {
   id: string;
   ipAddress: string;
@@ -26,6 +28,7 @@ async function mikrotikRequest(
   const protocol = useHttps ? "https" : "http";
   const url = `${protocol}://${router.ipAddress}:${router.apiPort}${path}`;
   const auth = Buffer.from(`${router.username}:${router.password}`).toString("base64");
+  const startTime = Date.now();
   
   const origTlsReject = process.env.NODE_TLS_REJECT_UNAUTHORIZED;
   if (useHttps) {
@@ -60,9 +63,24 @@ async function mikrotikRequest(
       data = text;
     }
 
+    const elapsed = Date.now() - startTime;
+    if (VERBOSE) {
+      const bodyStr = body ? ` body=${JSON.stringify(body)}` : '';
+      const dataPreview = typeof data === 'string' ? data.substring(0, 200) : JSON.stringify(data).substring(0, 200);
+      console.log(`[MIKROTIK] ${method} ${url} => HTTP ${response.status} (${elapsed}ms)${bodyStr} response=${dataPreview}`);
+    } else if (response.status >= 400) {
+      const dataPreview = typeof data === 'string' ? data.substring(0, 100) : JSON.stringify(data).substring(0, 100);
+      console.warn(`[MIKROTIK] ${method} ${router.ipAddress}${path} => HTTP ${response.status} (${elapsed}ms) err=${dataPreview}`);
+    } else if (elapsed > 5000) {
+      console.warn(`[MIKROTIK] SLOW: ${method} ${router.ipAddress}${path} => HTTP ${response.status} (${elapsed}ms)`);
+    }
+
     return { status: response.status, data };
   } catch (error: any) {
     clearTimeout(timeout);
+    const elapsed = Date.now() - startTime;
+    const errMsg = error.name === 'AbortError' ? `TIMEOUT after ${timeoutMs}ms` : error.message;
+    console.error(`[MIKROTIK] ${method} ${url} => ERRORE: ${errMsg} (${elapsed}ms)`);
     if (useHttps && origTlsReject !== undefined) {
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = origTlsReject;
     } else if (useHttps) {
@@ -94,19 +112,26 @@ export async function getExistingBlockedIps(
   listName: string = "ddos_blocked"
 ): Promise<Set<string>> {
   try {
+    if (VERBOSE) console.log(`[MIKROTIK] Fetching address-list da router ${router.ipAddress} (list=${listName}, timeout=20s)...`);
     const { status, data } = await mikrotikRequest(router, "GET", "/rest/ip/firewall/address-list", undefined, 20000);
     if (status === 200 && Array.isArray(data)) {
       const ips = new Set<string>();
+      const allLists = new Map<string, number>();
       for (const entry of data) {
+        const count = allLists.get(entry.list) || 0;
+        allLists.set(entry.list, count + 1);
         if (entry.list === listName) {
           ips.add(entry.address);
         }
       }
+      const listsInfo = Array.from(allLists.entries()).map(([name, count]) => `${name}:${count}`).join(', ');
+      console.log(`[MIKROTIK] Router ${router.ipAddress}: ${data.length} entries totali (${listsInfo}), ${ips.size} in list "${listName}"`);
       return ips;
     }
+    console.warn(`[MIKROTIK] Router ${router.ipAddress}: risposta inattesa status=${status}, data non e' array`);
     return new Set();
   } catch (e: any) {
-    console.error(`[MIKROTIK] Failed to get address-list from ${router.ipAddress}: ${e.message}`);
+    console.error(`[MIKROTIK] Router ${router.ipAddress}: ERRORE fetch address-list: ${e.message}`);
     return new Set();
   }
 }
@@ -127,41 +152,53 @@ export async function addToAddressList(
     });
 
     if (status === 200 || status === 201) {
+      if (VERBOSE) console.log(`[BLOCK] OK: ${ipAddress} aggiunto su router ${router.ipAddress} (HTTP ${status})`);
       return { routerIp: router.ipAddress, success: true };
     }
 
     if (status === 400 || status === 409) {
       const text = typeof data === "string" ? data.toLowerCase() : JSON.stringify(data).toLowerCase();
       if (text.includes("already") || text.includes("exists") || text.includes("duplicate") || text.includes("failure: already")) {
+        if (VERBOSE) console.log(`[BLOCK] SKIP: ${ipAddress} gia' presente su router ${router.ipAddress} (HTTP ${status})`);
         return { routerIp: router.ipAddress, success: true, alreadyExists: true };
       }
+      console.warn(`[BLOCK] VERIFICA: ${ipAddress} su router ${router.ipAddress} HTTP ${status} risposta="${text.substring(0, 150)}", verifico lista...`);
       try {
         const verifyResult = await mikrotikRequest(router, "GET", "/rest/ip/firewall/address-list");
         if (verifyResult.status === 200 && Array.isArray(verifyResult.data)) {
           for (const entry of verifyResult.data) {
             if (entry.address === ipAddress && entry.list === listName) {
+              console.log(`[BLOCK] CONFERMATO: ${ipAddress} trovato nella lista di router ${router.ipAddress} dopo verifica`);
               return { routerIp: router.ipAddress, success: true, alreadyExists: true };
             }
           }
         }
-      } catch {}
+      } catch (verifyErr: any) {
+        console.error(`[BLOCK] ERRORE verifica: ${ipAddress} su router ${router.ipAddress}: ${verifyErr.message}`);
+      }
+      const errMsg = `HTTP ${status}: ${typeof data === "string" ? data : JSON.stringify(data)}`;
+      console.error(`[BLOCK] FALLITO: ${ipAddress} su router ${router.ipAddress}: ${errMsg}`);
       return {
         routerIp: router.ipAddress,
         success: false,
-        error: `HTTP ${status}: ${typeof data === "string" ? data : JSON.stringify(data)}`,
+        error: errMsg,
       };
     }
 
+    const errMsg = `HTTP ${status}: ${typeof data === "string" ? data : JSON.stringify(data)}`;
+    console.error(`[BLOCK] FALLITO: ${ipAddress} su router ${router.ipAddress}: ${errMsg}`);
     return {
       routerIp: router.ipAddress,
       success: false,
-      error: `HTTP ${status}: ${typeof data === "string" ? data : JSON.stringify(data)}`,
+      error: errMsg,
     };
   } catch (error: any) {
+    const errMsg = error.name === 'AbortError' ? `TIMEOUT (8s)` : (error.message || "Connection failed");
+    console.error(`[BLOCK] ERRORE: ${ipAddress} su router ${router.ipAddress}: ${errMsg}`);
     return {
       routerIp: router.ipAddress,
       success: false,
-      error: error.message || "Connection failed",
+      error: errMsg,
     };
   }
 }
@@ -172,8 +209,10 @@ export async function removeFromAddressList(
   listName: string = "ddos_blocked"
 ): Promise<BlockResult> {
   try {
+    if (VERBOSE) console.log(`[UNBLOCK] Rimozione ${ipAddress} da router ${router.ipAddress} (list=${listName})...`);
     const { status, data } = await mikrotikRequest(router, "GET", "/rest/ip/firewall/address-list");
     if (status !== 200 || !Array.isArray(data)) {
+      console.error(`[UNBLOCK] ERRORE: impossibile leggere address-list da router ${router.ipAddress}: HTTP ${status}`);
       return { routerIp: router.ipAddress, success: false, error: "Failed to read address list" };
     }
 
@@ -182,14 +221,18 @@ export async function removeFromAddressList(
         const entryId = entry[".id"];
         const delResult = await mikrotikRequest(router, "DELETE", `/rest/ip/firewall/address-list/${entryId}`);
         if (delResult.status === 200 || delResult.status === 204) {
+          console.log(`[UNBLOCK] OK: ${ipAddress} rimosso da router ${router.ipAddress}`);
           return { routerIp: router.ipAddress, success: true };
         }
+        console.error(`[UNBLOCK] FALLITO: eliminazione ${ipAddress} da router ${router.ipAddress}: HTTP ${delResult.status}`);
         return { routerIp: router.ipAddress, success: false, error: `Delete failed: ${delResult.status}` };
       }
     }
 
+    if (VERBOSE) console.log(`[UNBLOCK] ${ipAddress} non trovato su router ${router.ipAddress} (gia' assente)`);
     return { routerIp: router.ipAddress, success: true };
   } catch (error: any) {
+    console.error(`[UNBLOCK] ERRORE: ${ipAddress} su router ${router.ipAddress}: ${error.message}`);
     return { routerIp: router.ipAddress, success: false, error: error.message };
   }
 }
@@ -281,6 +324,8 @@ export async function bulkBlockIps(
   let blocked = 0;
   let failed = 0;
   const details: Array<{ ip: string; status: string }> = [];
+  const partialIps: string[] = [];
+  const failedIps: string[] = [];
 
   async function processIp(ip: string) {
     const routerResults = await Promise.allSettled(
@@ -289,7 +334,7 @@ export async function bulkBlockIps(
         if (existing.has(ip)) {
           const st = routerStatus.get(router.ipAddress);
           if (st) st.skip++;
-          return true;
+          return { success: true, skipped: true, routerIp: router.ipAddress };
         }
         const start = Date.now();
         const result = await addToAddressList(router, ip, listName, `${commentPrefix} ${ip}`, timeoutDuration);
@@ -299,33 +344,52 @@ export async function bulkBlockIps(
           if (st) st.ok++;
         } else {
           if (st) st.fail++;
-          if (elapsed > 5000) {
-            console.warn(`[BULK-BLOCK] SLOW: Router ${router.ipAddress} took ${elapsed}ms for IP ${ip}: ${result.error}`);
         }
-        }
+        return { success: result.success, skipped: false, routerIp: router.ipAddress, elapsed, error: result.error };
-        return result.success;
       })
     );
 
+    const perRouterDetail = routerResults.map((r) => {
+      if (r.status === 'fulfilled') {
+        const v = r.value;
+        if (v.skipped) return `${v.routerIp}:SKIP`;
+        if (v.success) return `${v.routerIp}:OK(${v.elapsed}ms)`;
+        return `${v.routerIp}:FAIL(${v.elapsed}ms,${v.error})`;
+      }
+      return 'REJECTED';
+    }).join(' | ');
+
     const anySuccess = routerResults.some(
-      (r) => r.status === "fulfilled" && r.value === true
+      (r) => r.status === "fulfilled" && r.value.success
+    );
+    const allSuccess = routerResults.every(
+      (r) => r.status === "fulfilled" && r.value.success
     );
 
     if (anySuccess) {
       blocked++;
       details.push({ ip, status: "blocked" });
+      if (!allSuccess) {
+        partialIps.push(ip);
+        if (VERBOSE) console.warn(`[BULK-BLOCK] PARZIALE: IP ${ip}: ${perRouterDetail}`);
+      }
     } else {
       failed++;
+      failedIps.push(ip);
       details.push({ ip, status: "failed" });
+      if (VERBOSE) console.error(`[BULK-BLOCK] FALLITO: IP ${ip}: ${perRouterDetail}`);
     }
   }
 
+  const bulkStart = Date.now();
   for (let i = 0; i < newIps.length; i += concurrency) {
     const batch = newIps.slice(i, i + concurrency);
     await Promise.allSettled(batch.map((ip) => processIp(ip)));
 
-    if ((i + concurrency) % 50 === 0 || i + concurrency >= newIps.length) {
+    const progress = Math.min(i + concurrency, newIps.length);
-      console.log(`[BULK-BLOCK] Progress: ${Math.min(i + concurrency, newIps.length)}/${newIps.length}`);
+    if (progress === newIps.length || progress % 50 === 0) {
+      const elapsed = ((Date.now() - bulkStart) / 1000).toFixed(1);
+      console.log(`[BULK-BLOCK] Progress: ${progress}/${newIps.length} (${elapsed}s, ${blocked} ok, ${failed} fail)`);
     }
   }
 
@@ -333,11 +397,17 @@ export async function bulkBlockIps(
     details.push({ ip, status: "already_blocked" });
   }
 
-  // Report per-router
+  const totalElapsed = ((Date.now() - bulkStart) / 1000).toFixed(1);
   routerStatus.forEach((st, routerIp) => {
     console.log(`[BULK-BLOCK] Router ${routerIp}: ${st.ok} blocked, ${st.fail} failed, ${st.skip} skipped`);
   });
-  console.log(`[BULK-BLOCK] Done: ${blocked} blocked, ${failed} failed, ${skippedIps.length} skipped`);
+  console.log(`[BULK-BLOCK] Completato in ${totalElapsed}s: ${blocked} blocked, ${failed} failed, ${skippedIps.length} already_blocked, ${partialIps.length} parziali`);
+  if (failedIps.length > 0) {
+    console.error(`[BULK-BLOCK] IP non bloccati su nessun router (${failedIps.length}): ${failedIps.slice(0, 20).join(', ')}${failedIps.length > 20 ? '...' : ''}`);
+  }
+  if (partialIps.length > 0) {
+    console.warn(`[BULK-BLOCK] IP bloccati solo parzialmente (${partialIps.length}): ${partialIps.slice(0, 20).join(', ')}${partialIps.length > 20 ? '...' : ''}`);
+  }
 
   return { blocked, failed, skipped: skippedIps.length, details };
 }

server/routes.ts

@@ -672,7 +672,8 @@ export async function registerRoutes(app: Express): Promise<Server> {
       }
       
       const ipList = rows.map((r: any) => r.source_ip);
-      console.log(`[BLOCK-ALL] Avvio blocco massivo: ${ipList.length}/${totalUnblocked} IP con score >= ${min_score} su ${enabledRouters.length} router`);
+      const routerInfo = enabledRouters.map((r: any) => `${r.name || r.ipAddress}(${r.ipAddress}:${r.apiPort})`).join(', ');
+      console.log(`[BLOCK-ALL] Avvio blocco massivo: ${ipList.length}/${totalUnblocked} IP con score >= ${min_score} su ${enabledRouters.length} router: ${routerInfo}`);
       
       const result = await bulkBlockIps(
         enabledRouters as any,