In INET, why does ARPTest example network take over 500 seconds to run?
In the INET example project "ARPTest" running on top of OMNeT++, it seems that 1 megabyte of data is being transferred from each of three hosts over Ethernet cables with bandwidths of 512 Mb/s and 100 Mb/s to a server. In real life, it seems this data transfer should take less than a second. However when running the simulation full speed, the simulation runs for 500 virtual seconds and still isn't finished. Can someone explain this discrepancy regarding simulator time, or what am I missing?
First of all, always check the log outputs to see what a simulation is actually doing. The problem with running a simulation in Express mode is that log outputs are skipped, so you don't see what is actually happening.
Now, looking at your question, there is no discrepancy between the simulation time and the actual transmission time of the data transfer.
The 500 sec simulation time is courtesy of the simulation time limit, set in the omnetpp.ini via sim-time-limit = 500s.
OMNeT++ will stop the simulation at 500 seconds simulation time, regardless of further events to process.
For the sake of completeness, I'll post the final log outputs for the ARPtest:
** Event #385441 t=5.831682347368 ARPTest.server.tcp (TCP, id=257) on ACK (inet::tcp::TCPSegment, id=499229)
DETAIL (TCP)ARPTest.server.tcp: Connection 10.0.0.14:1000 to 10.0.0.1:1025 on app[0], connId=8 in LAST_ACK
INFO (TCP)ARPTest.server.tcp: Seg arrived: .1025 > .1000: ack 2347163 win 7504
DETAIL (TCP)ARPTest.server.tcp: TCB: snd_una=2346444 snd_nxt=2346980 snd_max=2347163 snd_wnd=7504 rcv_nxt=1298578 rcv_wnd=7504 snd_cwnd=536 rto=2 ssthresh=3728
DETAIL (TCP)ARPTest.server.tcp: Processing ACK in a data transfer state
DETAIL (TCP)ARPTest.server.tcp: ACK acks our FIN
INFO (TCP)ARPTest.server.tcp: Updating send window from segment: new wnd=7504
INFO (TCP)ARPTest.server.tcp: ACK acks all outstanding segments, cancel REXMIT timer
INFO (TCP)ARPTest.server.tcp: cwnd <= ssthresh: Slow Start: increasing cwnd by one SMSS bytes to cwnd=1072
INFO (TCP)ARPTest.server.tcp: Last ACK arrived
INFO (TCP)ARPTest.server.tcp: Transition: LAST_ACK --> CLOSED (event was: RCV_ACK)
DEBUG (TCP)ARPTest.server.tcp: tcp: LAST_ACK --> CLOSED (on RCV_ACK)
INFO (TCP)ARPTest.server.tcp: Notifying app: CLOSED
INFO (TCP)ARPTest.server.tcp: Deleting TCP connection
** Event #385442 t=5.831682347368 ARPTest.server.tcpApp[0] (TCPEchoApp, id=256) on CLOSED (omnetpp::cMessage, id=499231)
** Event #385443 t=245.831667258618 ARPTest.client.tcp (TCP, id=30) on selfmsg 2MSL (omnetpp::cMessage, id=87)
DETAIL (TCP)ARPTest.client.tcp: Connection 10.0.0.1:1025 to 10.0.0.14:1000 on app[0], connId=7 in TIME_WAIT
DETAIL (TCP)ARPTest.client.tcp: 2MSL timer expired
INFO (TCP)ARPTest.client.tcp: Transition: TIME_WAIT --> CLOSED (event was: TIMEOUT_2MSL)
DEBUG (TCP)ARPTest.client.tcp: tcp: TIME_WAIT --> CLOSED (on TIMEOUT_2MSL)
INFO (TCP)ARPTest.client.tcp: Deleting TCP connection
** Event #385444 t=500 on endsimulation (omnetpp::cEndSimulationEvent)
<!> Simulation time limit reached -- at t=500s, event #385444
** Calling finish() methods of modules
INFO (TCPSessionApp)ARPTest.client.tcpApp[0]: ARPTest.client.tcpApp[0]: ARPTest.client.tcpApp[0]: received 2097152 bytes in 3447 packets
INFO (TCP)ARPTest.client.tcp: ARPTest.client.tcp: ARPTest.client.tcp: finishing with 0 connections open.
INFO (TCP)ARPTest.server.tcp: ARPTest.server.tcp: ARPTest.server.tcp: finishing with 1 connections open.
In the log output, you can clearly see that around 5.83 seconds, the last acknowledgments for the data transfer arrived and the TCP connection is finally closed. Afterwards, a timer expires around 245 seconds and at 500 seconds, the simulation exits (due to the simulation time limit).
The simulation would continue until all timers run out or no further events need to be processed (whatever is the first case for this example).