From ce82046a11521b0537ac2150a07a4de54aec883a Mon Sep 17 00:00:00 2001
From: Paul Buetow <paul@buetow.org>
Date: Sat, 21 Jun 2025 20:34:33 +0300
Subject: Improve verbose logging for protocol tests
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

- Enable real-time log output during simulation execution
- Fix HeadlessProtocolRunner to properly show logs as they happen
- Update LogCapture to format timestamps clearly
- Add test-verbose.sh script for demonstrating logging
- Remove duplicate log printing in verbose mode

Now when running tests with -Dds.sim.verbose=true or option 3 in
test-protocols.sh, users can see protocol actions as they occur.

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>
---
 src/main/java/testing/HeadlessProtocolRunner.java | 20 +++++++++--------
 src/main/java/testing/LogCapture.java             |  5 +++--
 src/main/java/testing/TestVerboseLogging.java     | 27 +++++++++++++++++++++++
 3 files changed, 41 insertions(+), 11 deletions(-)
 create mode 100644 src/main/java/testing/TestVerboseLogging.java

(limited to 'src/main/java/testing')

diff --git a/src/main/java/testing/HeadlessProtocolRunner.java b/src/main/java/testing/HeadlessProtocolRunner.java
index 69d398f..d68d743 100644
--- a/src/main/java/testing/HeadlessProtocolRunner.java
+++ b/src/main/java/testing/HeadlessProtocolRunner.java
@@ -29,25 +29,27 @@ public class HeadlessProtocolRunner {
         System.out.println("-".repeat(50));
         
         HeadlessSimulationRunner runner = new HeadlessSimulationRunner();
-        runner.setPrintLogs(verbose);
+        runner.setPrintLogs(verbose); // This will print logs in real-time during simulation
+        
+        if (verbose) {
+            System.out.println("\n--- Real-Time Simulation Log Output ---");
+            System.out.println("(Logs show protocol actions as they happen)\n");
+        }
         
         try {
             long startTime = System.currentTimeMillis();
             SimulationResult result = runner.runSimulation(simFile, 5000); // 5 second timeout
             long duration = System.currentTimeMillis() - startTime;
             
+            if (verbose) {
+                System.out.println("--- End of Simulation ---\n");
+            }
+            
             System.out.println("✓ Completed in " + duration + "ms");
             System.out.println("  Processes: " + result.getMetrics().getNumProcesses());
             System.out.println("  Log entries: " + result.getMetrics().getTotalLogCount());
             System.out.println("  Messages per process: " + result.getMetrics().getProcessMessageCounts());
             
-            if (verbose) {
-                System.out.println("\n--- Log Output ---");
-                for (LogEntry log : result.getAllLogs()) {
-                    System.out.println(log.toString());
-                }
-            }
-            
             System.out.println();
         } catch (Exception e) {
             System.err.println("✗ FAILED: " + e.getMessage());
@@ -81,7 +83,7 @@ public class HeadlessProtocolRunner {
             System.out.println("-".repeat(50));
             
             HeadlessSimulationRunner runner = new HeadlessSimulationRunner();
-            runner.setPrintLogs(false); // Don't print logs when running all tests
+            runner.setPrintLogs(verbose); // Print logs if verbose mode is enabled
             
             try {
                 long startTime = System.currentTimeMillis();
diff --git a/src/main/java/testing/LogCapture.java b/src/main/java/testing/LogCapture.java
index 59f7ede..97bb127 100644
--- a/src/main/java/testing/LogCapture.java
+++ b/src/main/java/testing/LogCapture.java
@@ -62,7 +62,7 @@ public class LogCapture extends VSLogging {
         notifyListeners(entry);
         
         if (printLogs) {
-            System.out.println(logPrefix + entry);
+            System.out.println(String.format("[%5d] %s", time, message));
         }
     }
     
@@ -90,7 +90,8 @@ public class LogCapture extends VSLogging {
         notifyListeners(entry);
         
         if (printLogs) {
-            System.out.println(logPrefix + "[P" + process.getProcessNum() + "] " + message);
+            System.out.println(String.format("[%5d] Process %d: %s", 
+                process.getTime(), process.getProcessNum(), message));
         }
     }
     
diff --git a/src/main/java/testing/TestVerboseLogging.java b/src/main/java/testing/TestVerboseLogging.java
new file mode 100644
index 0000000..9833d84
--- /dev/null
+++ b/src/main/java/testing/TestVerboseLogging.java
@@ -0,0 +1,27 @@
+package testing;
+
+/**
+ * Simple test to demonstrate verbose logging during simulation.
+ */
+public class TestVerboseLogging {
+    
+    public static void main(String[] args) throws Exception {
+        System.out.println("=== Testing Verbose Logging ===\n");
+        
+        // Run a short simulation with verbose logging
+        HeadlessSimulationRunner runner = new HeadlessSimulationRunner();
+        runner.setPrintLogs(true); // Enable real-time log output
+        
+        System.out.println("Starting simulation with real-time log output...\n");
+        
+        try {
+            SimulationResult result = runner.runSimulation("saved-simulations/ping-pong.dat", 1000);
+            
+            System.out.println("\n=== Simulation Complete ===");
+            System.out.println("Total logs captured: " + result.getAllLogs().size());
+            System.out.println("Processes: " + result.getMetrics().getNumProcesses());
+        } finally {
+            runner.shutdown();
+        }
+    }
+}
\ No newline at end of file
-- 
cgit v1.2.3