Comm::wait_for is not intuitive. An ActivitySet container would be easier
Hello,
While working on !79 (merged) I noticed a rather odd / unexpected behaviour after Comm::wait_for
times-out (see this thread with the original context). Basically, it looks like successive calls to Comm::wait_for() on the same Comm
instance (when a timeout originally occurs) does not "progress" the simulation. Note that this behaviour is reproducible with equivalent c++ or Python (but I also imagine C) code.
Reproduction
It's very easy to reproduce with this example. After sending multiple requests simultaneously, sender
waits for all of them to complete before leaving. The default timeout in this example is such that no timeout occurs, but if we set it to something arbitrarily small like 0.1s, it then occurs (and the actor crashes). What I noticed is that changing the original code from this:
this_actor.info("Waiting for all outstanding communications to complete")
while pending_comms:
current_comm: Comm = pending_comms[-1]
current_comm.wait_for(1.0)
pending_comms.pop()
this_actor.info("Goodbye now!")
To this (basically waiting on the same comm until no timeout occurs):
this_actor.info("Waiting for all outstanding communications to complete")
wait_timeout = 0.2
while pending_comms:
current_comm: Comm = pending_comms[-1]
try:
current_comm.wait_for(wait_timeout)
pending_comms.pop()
except TimeoutException:
this_actor.info("timed out waiting for communication completion after {:f}s, retrying".format(wait_timeout))
this_actor.info("Goodbye now!")
The actor then goes into an endless loop:
venv ❯ python3.9 examples/python/comm-waituntil/comm-waituntil.py examples/platforms/small_platform_fatpipe.xml
[0.000000] [xbt_cfg/INFO] Configuration change: Set 'contexts/factory' to 'thread'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 0' to 'receiver-0'
[Ruby:receiver:(2) 0.000000] [python/INFO] Wait for my first message
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 1' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 2' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'finalize' to 'receiver-0
[Tremblay:sender:(1) 0.000000] [python/INFO] Done dispatching all messages
[Tremblay:sender:(1) 0.000000] [python/INFO] Waiting for all outstanding communications to complete
[Ruby:receiver:(2) 0.105458] [python/INFO] I got a 'Message 0'.
[Tremblay:sender:(1) 0.200000] [python/INFO] timed out waiting for communication completion after 0.200000s, retrying
[Tremblay:sender:(1) 0.200000] [python/INFO] timed out waiting for communication completion after 0.200000s, retrying
[Tremblay:sender:(1) 0.200000] [python/INFO] timed out waiting for communication completion after 0.200000s, retrying
[Tremblay:sender:(1) 0.200000] [python/INFO] timed out waiting for communication completion after 0.200000s, retrying
... goes on forever
Alternative reproduction (increasing timeouts)
I tried something else where the timeout increases after each round of loop:
this_actor.info("Waiting for all outstanding communications to complete")
wait_timeout_incr = 0.05
wait_timeout = wait_timeout_incr
while pending_comms:
current_comm: Comm = pending_comms[-1]
try:
current_comm.wait_for(wait_timeout)
pending_comms.pop()
except TimeoutException:
this_actor.info("timed out waiting for communication completion after {:f}s, retrying".format(wait_timeout))
wait_timeout += wait_timeout_incr
this_actor.info("Goodbye now!")
But it looks like increasing timeout values are ignored (look how the timeouts keep increasing, but the simulation time remains constant):
(venv) venv ❯ python comm-waitfor.py ../../platforms/small_platform_fatpipe.xml
[0.000000] [xbt_cfg/INFO] Configuration change: Set 'contexts/factory' to 'thread'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 0' to 'receiver-0'
[Ruby:receiver:(2) 0.000000] [python/INFO] Wait for my first message
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 1' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 2' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'finalize' to 'receiver-0
[Tremblay:sender:(1) 0.000000] [python/INFO] Done dispatching all messages
[Tremblay:sender:(1) 0.000000] [python/INFO] Waiting for all outstanding communications to complete
[Tremblay:sender:(1) 0.050000] [python/INFO] timed out waiting for communication completion after 0.050000s, retrying
[Tremblay:sender:(1) 0.050000] [python/INFO] timed out waiting for communication completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.050000] [python/INFO] timed out waiting for communication completion after 0.150000s, retrying
[Tremblay:sender:(1) 0.050000] [python/INFO] timed out waiting for communication completion after 0.200000s, retrying
[Tremblay:sender:(1) 0.050000] [python/INFO] timed out waiting for communication completion after 0.250000s, retrying
... goes on forever
Alternative reproduction (successively waiting on all remaining comms)
This one is even weirder: each successive timeout "advances" the simulation up until the point all messages have been received / processed by the receiver - but continues to time-out after that (although the comms clearly completed)
this_actor.info("Waiting for all outstanding communications to complete")
wait_timeout = 0.1
remaining_comms: list[Comm] = list(pending_comms)
while remaining_comms:
remaining_comms_next = []
for idx, comm in enumerate(remaining_comms):
try:
comm.wait_for(wait_timeout)
except TimeoutException:
this_actor.info("timed out waiting for remaining communication {:d} completion after {:f}s, retrying".format(idx, wait_timeout))
remaining_comms_next.append(comm)
remaining_comms = remaining_comms_next
this_actor.info("Goodbye now!")
[0.000000] [xbt_cfg/INFO] Configuration change: Set 'contexts/factory' to 'thread'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 0' to 'receiver-0'
[Ruby:receiver:(2) 0.000000] [python/INFO] Wait for my first message
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 1' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 2' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'finalize' to 'receiver-0
[Tremblay:sender:(1) 0.000000] [python/INFO] Done dispatching all messages
[Tremblay:sender:(1) 0.000000] [python/INFO] Waiting for all outstanding communications to complete
[Tremblay:sender:(1) 0.100000] [python/INFO] timed out waiting for remaining communication 0 completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.200000] [python/INFO] timed out waiting for remaining communication 1 completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.300000] [python/INFO] timed out waiting for remaining communication 2 completion after 0.100000s, retrying
[Ruby:receiver:(2) 0.301952] [python/INFO] I got a 'finalize'.
[Ruby:receiver:(2) 0.301952] [python/INFO] Goodbye now!
[Tremblay:sender:(1) 0.301952] [python/INFO] timed out waiting for remaining communication 0 completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.301952] [python/INFO] timed out waiting for remaining communication 1 completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.301952] [python/INFO] timed out waiting for remaining communication 2 completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.301952] [python/INFO] timed out waiting for remaining communication 0 completion after 0.100000s, retrying
[Tremblay:sender:(1) 0.301952] [python/INFO] timed out waiting for remaining communication 1 completion after 0.100000s, retrying
... goes on forever
Expected behaviour
- [0s] go into the loop a first time
- [0s] wait for the first message to be sent (or timeout after 0.1s)
- [0.1s] timeout after 0.1s
- [0.1s] wait for the first message to be sent (or timeout after 0.1s)
- [0.2s] timeout after 0.1s
- [0.2s] wait for the first message to be sent (or timeout after 0.1s)
- [0.3s] timeout after 0.1s
- [0.3s] wait for the first message to be sent (or timeout after 0.1s)
- [0.318326s] all messages delivered, leaves
In other words:
- Successive timeouts can be applied on an already awaited-timed-out communication
- Successive timeouts "advance" the simulation
Comm::wait_any_for
instead of Comm::wait_for
Working example: using I really did not expect this to work because it's very close to my previous examples, but it does:
this_actor.info("Waiting for all outstanding communications to complete")
wait_timeout = 0.1
while pending_comms:
idx = Comm.wait_any_for([pending_comms[-1]], wait_timeout)
if idx == -1:
this_actor.info("timed out waiting for communication completion after {:f}s, retrying".format(wait_timeout))
else:
pending_comms.pop()
this_actor.info("Goodbye now!")
And its output:
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 0' to 'receiver-0'
[Ruby:receiver:(2) 0.000000] [python/INFO] Wait for my first message
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 1' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'Message 2' to 'receiver-0'
[Tremblay:sender:(1) 0.000000] [python/INFO] Send 'finalize' to 'receiver-0
[Tremblay:sender:(1) 0.000000] [python/INFO] Done dispatching all messages
[Tremblay:sender:(1) 0.000000] [python/INFO] Waiting for all outstanding communications to complete
[Tremblay:sender:(1) 0.100000] [python/INFO] timed out waiting for communication completion after 0.100000s, retrying
[Ruby:receiver:(2) 0.105458] [python/INFO] I got a 'Message 0'.
[Tremblay:sender:(1) 0.200000] [python/INFO] timed out waiting for communication completion after 0.100000s, retrying
[Ruby:receiver:(2) 0.210917] [python/INFO] I got a 'Message 1'.
[Tremblay:sender:(1) 0.300000] [python/INFO] timed out waiting for communication completion after 0.100000s, retrying
[Ruby:receiver:(2) 0.316375] [python/INFO] I got a 'Message 2'.
[Ruby:receiver:(2) 0.318326] [python/INFO] I got a 'finalize'.
[Ruby:receiver:(2) 0.318326] [python/INFO] Goodbye now!
[Tremblay:sender:(1) 0.318326] [python/INFO] Goodbye now!
Proposed solution
I don't have one myself, but Martin suggested the following in his initial response:
If I understand correctly, the current code expects that the user remove the comms from the vector, or it keeps reporting the completion of the same comm. That's perfectly coherent with the code underneath, unfortunately.
To fix this, we should introduce something like a concept of ActivitySet, which would be somehow similar to vectors of activities, and then wait_any and friends would be instance methods of this type, instead of being static methods of Activity that apply on vectors of Activity.
Until now I thought that ActivitySet would be a nice cosmetic improvement. You just showed that it's actually needed, thanks.
I unfortunately don't understand the framework and its implementation well enough to judge but leaving his suggestion here for discussion :)
Just want to point out that this existing behaviour (even if it is expected?) is extremely confusing and makes me re-consider whether I really understand how simgrid works (and whether I can write accurate simulations) or not.
Thanks a lot for your help!