summaryrefslogtreecommitdiff
path: root/src/test/java/testing/protocols/MessageDeliveryDebug2Test.java
blob: abebfe0c328b3e0ce70400a8e9e6e45a1e34d76e (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
package testing.protocols;

import testing.*;
import org.junit.jupiter.api.*;
import static org.junit.jupiter.api.Assertions.*;
import java.lang.reflect.Field;
import core.VSTask;
import core.VSTaskManager;
import java.util.*;

/**
 * Extended debug test to understand why protocols are running twice.
 */
public class MessageDeliveryDebug2Test {
    private HeadlessSimulationRunner runner;
    
    @BeforeEach
    public void setup() {
        runner = new HeadlessSimulationRunner();
    }
    
    @AfterEach
    public void teardown() {
        runner.shutdown();
    }
    
    @Test
    @DisplayName("Debug why PingPong client sends two messages")
    public void debugDuplicateMessages() throws Exception {
        System.out.println("\n=== Starting Duplicate Message Debug Test ===");
        
        // Custom log listener to trace task execution
        LogListener listener = new LogListener() {
            private int messagesSent = 0;
            
            @Override
            public void onLogEntry(LogEntry entry) {
                String msg = entry.getMessage();
                
                // Track all events
                if (msg.contains("activated") || msg.contains("Message sent") || 
                    msg.contains("onClientStart") || msg.contains("counter=")) {
                    System.out.println(String.format("[TRACE %5d] P%d: %s", 
                        entry.getTimestamp(), entry.getProcessNum(), msg));
                    
                    if (msg.contains("Message sent")) {
                        messagesSent++;
                        if (messagesSent == 2) {
                            System.out.println("!!! ISSUE: Second message sent immediately at time " + 
                                entry.getTimestamp() + " - protocol likely executed twice!");
                        }
                    }
                }
                
                // Look for protocol event execution
                if (msg.contains("VSProtocolEvent") || msg.contains("VSPingPongProtocol")) {
                    System.out.println(String.format("[EVENT %5d] P%d: %s", 
                        entry.getTimestamp(), entry.getProcessNum(), msg));
                }
            }
        };
        
        SimulationResult result = runner.runSimulation(
            "saved-simulations/ping-pong.dat", 
            1000,  // Just 1 second is enough to see the issue
            listener
        );
        
        System.out.println("\n=== Analysis ===");
        
        // Count messages sent at time 0
        int messagesAtTimeZero = 0;
        for (LogEntry entry : result.getAllLogs()) {
            if (entry.getTimestamp() == 0 && entry.getMessage().contains("Message sent")) {
                messagesAtTimeZero++;
                System.out.println("Message at time 0: " + entry.getMessage());
            }
        }
        
        System.out.println("\nMessages sent at time 0: " + messagesAtTimeZero);
        
        if (messagesAtTimeZero > 1) {
            System.out.println("ERROR: Multiple messages sent at time 0 indicates duplicate protocol execution!");
        }
        
        System.out.println("\n=== Test Complete ===");
    }
}