Improve the debug messages

diff --git a/examples/cpp/synchro-barrier/s4u-mc-synchro-barrier.tesh b/examples/cpp/synchro-barrier/s4u-mc-synchro-barrier.tesh
index 9ed6eb7..a9ee7ce 100644 (file)
--- a/examples/cpp/synchro-barrier/s4u-mc-synchro-barrier.tesh
+++ b/examples/cpp/synchro-barrier/s4u-mc-synchro-barrier.tesh
@@ -3,9 +3,9 @@
 $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.thres:verbose --log=root.fmt="[Checker]%e%m%n" -- ${bindir:=.}/s4u-synchro-barrier 1 --log=s4u_test.thres:critical --log=root.fmt="[App%e%e%e%e]%e%m%n"
 > [Checker] Start a DFS exploration. Reduction is: dpor.
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
+> [Checker] Executed 1: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: BARRIER_WAIT(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
+> [Checker] Executed 1: BARRIER_WAIT(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
 > [Checker] 0 actors remain, but none of them need to be interleaved (depth 4).
 > [Checker] Execution came to an end at 1;1 (state: 3, depth: 3)
 > [Checker] Backtracking from 1;1
@@ -14,19 +14,19 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.thres:verbose --log=root.fmt="[Checker]%e%m%n" -- ${bindir:=.}/s4u-synchro-barrier 2 --log=s4u_test.thres:critical --log=root.fmt="[App%e%e%e%e]%e%m%n"
 > [Checker] Start a DFS exploration. Reduction is: dpor.
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
+> [Checker] Executed 1: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
+> [Checker] Executed 2: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 BARRIER_ASYNC_LOCK(barrier: 0) (state=1)
 > [Checker]  #2 BARRIER_ASYNC_LOCK(barrier: 0) (state=2)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: BARRIER_WAIT(barrier: 0) (stack depth: 3, state: 3, 0 interleaves)
+> [Checker] Executed 1: BARRIER_WAIT(barrier: 0) (stack depth: 3, state: 3, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #2 BARRIER_ASYNC_LOCK(barrier: 0) (state=2)
 > [Checker]  #1 BARRIER_WAIT(barrier: 0) (state=3)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: BARRIER_WAIT(barrier: 0) (stack depth: 4, state: 4, 0 interleaves)
+> [Checker] Executed 2: BARRIER_WAIT(barrier: 0) (stack depth: 4, state: 4, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 BARRIER_WAIT(barrier: 0) (state=3)
 > [Checker]  #2 BARRIER_WAIT(barrier: 0) (state=4)
@@ -38,7 +38,7 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker] Backtracking from 1;2;1;2
 > [Checker] Sleep set actually containing:
 > [Checker]   <1,BARRIER_ASYNC_LOCK(barrier: 0)>
-> [Checker] Execute 2: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
+> [Checker] Executed 2: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
 > [Checker] 2 actors remain, but none of them need to be interleaved (depth 3).
 > [Checker] Backtracking from 2
 > [Checker] DFS exploration ended. 6 unique states visited; 1 backtracks (0 transition replays, 7 states visited overall)
@@ -46,14 +46,14 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.thres:verbose --log=root.fmt="[Checker]%e%m%n" -- ${bindir:=.}/s4u-synchro-barrier 3 --log=s4u_test.thres:critical --log=root.fmt="[App%e%e%e%e]%e%m%n"
 > [Checker] Start a DFS exploration. Reduction is: dpor.
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
+> [Checker] Executed 1: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 1, state: 1, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
+> [Checker] Executed 2: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 BARRIER_ASYNC_LOCK(barrier: 0) (state=1)
 > [Checker]  #2 BARRIER_ASYNC_LOCK(barrier: 0) (state=2)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 3: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 3, state: 3, 0 interleaves)
+> [Checker] Executed 3: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 3, state: 3, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #2 BARRIER_ASYNC_LOCK(barrier: 0) (state=2)
 > [Checker]  #3 BARRIER_ASYNC_LOCK(barrier: 0) (state=3)
@@ -61,12 +61,12 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker]  #1 BARRIER_ASYNC_LOCK(barrier: 0) (state=1)
 > [Checker]  #3 BARRIER_ASYNC_LOCK(barrier: 0) (state=3)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: BARRIER_WAIT(barrier: 0) (stack depth: 4, state: 4, 0 interleaves)
+> [Checker] Executed 1: BARRIER_WAIT(barrier: 0) (stack depth: 4, state: 4, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #3 BARRIER_ASYNC_LOCK(barrier: 0) (state=3)
 > [Checker]  #1 BARRIER_WAIT(barrier: 0) (state=4)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: BARRIER_WAIT(barrier: 0) (stack depth: 5, state: 5, 0 interleaves)
+> [Checker] Executed 2: BARRIER_WAIT(barrier: 0) (stack depth: 5, state: 5, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 BARRIER_WAIT(barrier: 0) (state=4)
 > [Checker]  #2 BARRIER_WAIT(barrier: 0) (state=5)
@@ -74,7 +74,7 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker]  #3 BARRIER_ASYNC_LOCK(barrier: 0) (state=3)
 > [Checker]  #2 BARRIER_WAIT(barrier: 0) (state=5)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 3: BARRIER_WAIT(barrier: 0) (stack depth: 6, state: 6, 0 interleaves)
+> [Checker] Executed 3: BARRIER_WAIT(barrier: 0) (stack depth: 6, state: 6, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #2 BARRIER_WAIT(barrier: 0) (state=5)
 > [Checker]  #3 BARRIER_WAIT(barrier: 0) (state=6)
@@ -89,7 +89,7 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker] Backtracking from 1;2;3;1;2;3
 > [Checker] Sleep set actually containing:
 > [Checker]   <2,BARRIER_ASYNC_LOCK(barrier: 0)>
-> [Checker] Execute 3: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
+> [Checker] Executed 3: BARRIER_ASYNC_LOCK(barrier: 0) (stack depth: 2, state: 2, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 BARRIER_ASYNC_LOCK(barrier: 0) (state=1)
 > [Checker]  #3 BARRIER_ASYNC_LOCK(barrier: 0) (state=2)

diff --git a/examples/cpp/synchro-mutex/s4u-mc-synchro-mutex.tesh b/examples/cpp/synchro-mutex/s4u-mc-synchro-mutex.tesh
index 5f726fe..26f7e20 100644 (file)
--- a/examples/cpp/synchro-mutex/s4u-mc-synchro-mutex.tesh
+++ b/examples/cpp/synchro-mutex/s4u-mc-synchro-mutex.tesh
@@ -6,13 +6,13 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [App    ] Configuration change: Set 'actors' to '1'
 > [Checker] Start a DFS exploration. Reduction is: dpor.
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: MUTEX_ASYNC_LOCK(mutex: 0, owner: 1) (stack depth: 1, state: 1, 0 interleaves)
+> [Checker] Executed 1: MUTEX_ASYNC_LOCK(mutex: 0, owner: 1) (stack depth: 1, state: 1, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: MUTEX_WAIT(mutex: 0, owner: 1) (stack depth: 2, state: 2, 0 interleaves)
+> [Checker] Executed 1: MUTEX_WAIT(mutex: 0, owner: 1) (stack depth: 2, state: 2, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: MUTEX_UNLOCK(mutex: 0, owner: -1) (stack depth: 3, state: 3, 0 interleaves)
+> [Checker] Executed 1: MUTEX_UNLOCK(mutex: 0, owner: -1) (stack depth: 3, state: 3, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (stack depth: 4, state: 4, 0 interleaves)
+> [Checker] Executed 2: MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (stack depth: 4, state: 4, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 MUTEX_UNLOCK(mutex: 0, owner: -1) (state=3)
 > [Checker]  #2 MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (state=4)
@@ -23,12 +23,12 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker]  #1 MUTEX_ASYNC_LOCK(mutex: 0, owner: 1) (state=1)
 > [Checker]  #2 MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (state=4)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: MUTEX_WAIT(mutex: 0, owner: 2) (stack depth: 5, state: 5, 0 interleaves)
+> [Checker] Executed 2: MUTEX_WAIT(mutex: 0, owner: 2) (stack depth: 5, state: 5, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #1 MUTEX_UNLOCK(mutex: 0, owner: -1) (state=3)
 > [Checker]  #2 MUTEX_WAIT(mutex: 0, owner: 2) (state=5)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: MUTEX_UNLOCK(mutex: 0, owner: -1) (stack depth: 6, state: 6, 0 interleaves)
+> [Checker] Executed 2: MUTEX_UNLOCK(mutex: 0, owner: -1) (stack depth: 6, state: 6, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #1 MUTEX_UNLOCK(mutex: 0, owner: -1) (state=3)
 > [Checker]  #2 MUTEX_UNLOCK(mutex: 0, owner: -1) (state=6)
@@ -37,7 +37,7 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker] Backtracking from 1;1;1;2;2;2
 > [Checker] Sleep set actually containing:
 > [Checker]   <1,MUTEX_UNLOCK(mutex: 0, owner: -1)>
-> [Checker] Execute 2: MUTEX_ASYNC_LOCK(mutex: 0, owner: 1) (stack depth: 3, state: 3, 0 interleaves)
+> [Checker] Executed 2: MUTEX_ASYNC_LOCK(mutex: 0, owner: 1) (stack depth: 3, state: 3, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 MUTEX_WAIT(mutex: 0, owner: 1) (state=2)
 > [Checker]  #2 MUTEX_ASYNC_LOCK(mutex: 0, owner: 1) (state=3)
@@ -48,29 +48,29 @@ $ $VALGRIND_NO_TRACE_CHILDREN ${bindir:=.}/../../../bin/simgrid-mc --log=mc_dfs.
 > [Checker] Backtracking from 1;1;2
 > [Checker] Sleep set actually containing:
 > [Checker]   <1,MUTEX_ASYNC_LOCK(mutex: 0, owner: 1)>
-> [Checker] Execute 2: MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (stack depth: 1, state: 1, 0 interleaves)
+> [Checker] Executed 2: MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (stack depth: 1, state: 1, 0 interleaves)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (stack depth: 2, state: 9, 0 interleaves)
+> [Checker] Executed 1: MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (stack depth: 2, state: 9, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #2 MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (state=1)
 > [Checker]  #1 MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (state=9)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: MUTEX_WAIT(mutex: 0, owner: 2) (stack depth: 3, state: 10, 0 interleaves)
+> [Checker] Executed 2: MUTEX_WAIT(mutex: 0, owner: 2) (stack depth: 3, state: 10, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (state=9)
 > [Checker]  #2 MUTEX_WAIT(mutex: 0, owner: 2) (state=10)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 2: MUTEX_UNLOCK(mutex: 0, owner: 1) (stack depth: 4, state: 11, 0 interleaves)
+> [Checker] Executed 2: MUTEX_UNLOCK(mutex: 0, owner: 1) (stack depth: 4, state: 11, 0 interleaves)
 > [Checker] INDEPENDENT Transitions:
 > [Checker]  #1 MUTEX_ASYNC_LOCK(mutex: 0, owner: 2) (state=9)
 > [Checker]  #2 MUTEX_UNLOCK(mutex: 0, owner: 1) (state=11)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: MUTEX_WAIT(mutex: 0, owner: 1) (stack depth: 5, state: 12, 0 interleaves)
+> [Checker] Executed 1: MUTEX_WAIT(mutex: 0, owner: 1) (stack depth: 5, state: 12, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #2 MUTEX_UNLOCK(mutex: 0, owner: 1) (state=11)
 > [Checker]  #1 MUTEX_WAIT(mutex: 0, owner: 1) (state=12)
 > [Checker] Sleep set actually containing:
-> [Checker] Execute 1: MUTEX_UNLOCK(mutex: 0, owner: -1) (stack depth: 6, state: 13, 0 interleaves)
+> [Checker] Executed 1: MUTEX_UNLOCK(mutex: 0, owner: -1) (stack depth: 6, state: 13, 0 interleaves)
 > [Checker] Dependent Transitions:
 > [Checker]  #2 MUTEX_UNLOCK(mutex: 0, owner: 1) (state=11)
 > [Checker]  #1 MUTEX_UNLOCK(mutex: 0, owner: -1) (state=13)

diff --git a/src/kernel/actor/ActorImpl.cpp b/src/kernel/actor/ActorImpl.cpp
index 013ad5b..61e0479 100644 (file)
--- a/src/kernel/actor/ActorImpl.cpp
+++ b/src/kernel/actor/ActorImpl.cpp
@@ -509,8 +509,10 @@ void create_maestro(const std::function<void()>& code)
 /** (in kernel mode) unpack the simcall and activate the handler */
 void ActorImpl::simcall_handle(int times_considered)
 {
-  XBT_DEBUG("Handling simcall %p: %s(%ld) %s", &simcall_, simcall_.issuer_->get_cname(), simcall_.issuer_->get_pid(),
-            (simcall_.observer_ != nullptr ? simcall_.observer_->to_string().c_str() : simcall_.get_cname()));
+  XBT_DEBUG("Handling simcall %p: %s(%ld) %s (times_considered:%d)", &simcall_, simcall_.issuer_->get_cname(),
+            simcall_.issuer_->get_pid(),
+            (simcall_.observer_ != nullptr ? simcall_.observer_->to_string().c_str() : simcall_.get_cname()),
+            times_considered);
   if (simcall_.observer_ != nullptr)
     simcall_.observer_->prepare(times_considered);
   if (wannadie())

diff --git a/src/mc/explo/DFSExplorer.cpp b/src/mc/explo/DFSExplorer.cpp
index ffa682f..3041301 100644 (file)
--- a/src/mc/explo/DFSExplorer.cpp
+++ b/src/mc/explo/DFSExplorer.cpp
@@ -163,13 +163,16 @@ void DFSExplorer::run()
         XBT_VERB("  <%ld,%s>", aid, transition->to_string().c_str());
     }
 
+    auto todo = state->get_actors_list().at(next).get_transition();
+    XBT_DEBUG("wanna execute %ld: %.60s", next, todo->to_string().c_str());
+
     /* Actually answer the request: let's execute the selected request (MCed does one step) */
     auto executed_transition = state->execute_next(next, get_remote_app());
     on_transition_execute_signal(state->get_transition_out().get(), get_remote_app());
 
     // If there are processes to interleave and the maximum depth has not been
     // reached then perform one step of the exploration algorithm.
-    XBT_VERB("Execute %ld: %.60s (stack depth: %zu, state: %ld, %zu interleaves)", state->get_transition_out()->aid_,
+    XBT_VERB("Executed %ld: %.60s (stack depth: %zu, state: %ld, %zu interleaves)", state->get_transition_out()->aid_,
              state->get_transition_out()->to_string().c_str(), stack_.size(), state->get_num(), state->count_todo());
 
     /* Create the new expanded state (copy the state of MCed into our MCer data) */