From: Martin Quinson Date: Tue, 1 Nov 2022 22:55:04 +0000 (+0100) Subject: Merge branch 'master' of framagit.org:simgrid/simgrid X-Git-Tag: v3.34~717 X-Git-Url: http://info.iut-bm.univ-fcomte.fr/pub/gitweb/simgrid.git/commitdiff_plain/a8a66c743439c94d5de5bcb8a3e50dcd207b6d2f?hp=967a3b9f834126e8a07f185cdd660b12c487e9c3 Merge branch 'master' of framagit.org:simgrid/simgrid --- diff --git a/examples/c/actor-exiting/actor-exiting.tesh b/examples/c/actor-exiting/actor-exiting.tesh index 2fb10eec44..4bc56ef830 100644 --- a/examples/c/actor-exiting/actor-exiting.tesh +++ b/examples/c/actor-exiting/actor-exiting.tesh @@ -8,6 +8,6 @@ $ ${bindir:=.}/c-actor-exiting ${platfdir}/small_platform.xml "--log=root.fmt:[% > [ 3.000000] (maestro@) Oops! Deadlock detected, some activities are still around but will never complete. This usually happens when the user code is not perfectly clean. > [ 3.000000] (maestro@) 1 actors are still running, waiting for something. > [ 3.000000] (maestro@) Legend of the following listing: "Actor (@): " -> [ 3.000000] (maestro@) Actor 3 (C@Ginette): waiting for communication activity 0xdeadbeef () in state WAITING to finish +> [ 3.000000] (maestro@) Actor 3 (C@Ginette): waiting for communication activity 0xdeadbeef () in state WAITING to finish > [ 3.000000] (C@Ginette) I was killed! > [ 3.000000] (C@Ginette) The backtrace would be displayed here if --log=no_loc would not have been passed diff --git a/examples/cpp/actor-exiting/s4u-actor-exiting.tesh b/examples/cpp/actor-exiting/s4u-actor-exiting.tesh index cb819512b1..660b0839f5 100644 --- a/examples/cpp/actor-exiting/s4u-actor-exiting.tesh +++ b/examples/cpp/actor-exiting/s4u-actor-exiting.tesh @@ -12,7 +12,7 @@ $ ${bindir:=.}/s4u-actor-exiting ${platfdir}/small_platform.xml "--log=root.fmt: > [ 3.000000] (maestro@) Oops! Deadlock detected, some activities are still around but will never complete. This usually happens when the user code is not perfectly clean. > [ 3.000000] (maestro@) 1 actors are still running, waiting for something. > [ 3.000000] (maestro@) Legend of the following listing: "Actor (@): " -> [ 3.000000] (maestro@) Actor 3 (C@Ginette): waiting for communication activity 0xdeadbeef () in state WAITING to finish +> [ 3.000000] (maestro@) Actor 3 (C@Ginette): waiting for communication activity 0xdeadbeef () in state WAITING to finish > [ 3.000000] (C@Ginette) I was killed! > [ 3.000000] (C@Ginette) The backtrace would be displayed here if --log=no_loc would not have been passed > [ 3.000000] (maestro@) Actor C terminates now diff --git a/examples/cpp/mc-bugged1/s4u-mc-bugged1.tesh b/examples/cpp/mc-bugged1/s4u-mc-bugged1.tesh index bd135cf7bf..97ec9d5b62 100644 --- a/examples/cpp/mc-bugged1/s4u-mc-bugged1.tesh +++ b/examples/cpp/mc-bugged1/s4u-mc-bugged1.tesh @@ -31,5 +31,5 @@ $ ${bindir:=.}/../../../bin/simgrid-mc ${bindir:=.}/s4u-mc-bugged1 ${platfdir:=. > [ 0.000000] (0:maestro@) 1: iRecv(mbox=0) > [ 0.000000] (0:maestro@) 3: iSend(mbox=0) > [ 0.000000] (0:maestro@) 1: WaitComm(from 3 to 1, mbox=0, no timeout) -> [ 0.000000] (0:maestro@) Path = 1;2;1;1;2;4;1;1;3;1 +> [ 0.000000] (0:maestro@) You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1;2;1;1;2;4;1;1;3;1' > [ 0.000000] (0:maestro@) DFS exploration ended. 22 unique states visited; 4 backtracks (56 transition replays, 30 states visited overall) \ No newline at end of file diff --git a/examples/cpp/mc-bugged2/s4u-mc-bugged2.tesh b/examples/cpp/mc-bugged2/s4u-mc-bugged2.tesh index 9badbef5d1..e8b5ceb102 100644 --- a/examples/cpp/mc-bugged2/s4u-mc-bugged2.tesh +++ b/examples/cpp/mc-bugged2/s4u-mc-bugged2.tesh @@ -551,5 +551,5 @@ $ ${bindir:=.}/../../../bin/simgrid-mc ${bindir:=.}/s4u-mc-bugged2 ${platfdir:=. > [ 0.000000] (0:maestro@) 1: iRecv(mbox=0) > [ 0.000000] (0:maestro@) 3: iSend(mbox=0) > [ 0.000000] (0:maestro@) 1: WaitComm(from 3 to 1, mbox=0, no timeout) -> [ 0.000000] (0:maestro@) Path = 1;3;1;3;1;3;1 +> [ 0.000000] (0:maestro@) You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1;3;1;3;1;3;1' > [ 0.000000] (0:maestro@) DFS exploration ended. 1006 unique states visited; 350 backtracks (5319 transition replays, 3963 states visited overall) diff --git a/examples/cpp/mc-failing-assert/s4u-mc-failing-assert-nodpor.tesh b/examples/cpp/mc-failing-assert/s4u-mc-failing-assert-nodpor.tesh index 912b9a158b..0cfec07f8a 100644 --- a/examples/cpp/mc-failing-assert/s4u-mc-failing-assert-nodpor.tesh +++ b/examples/cpp/mc-failing-assert/s4u-mc-failing-assert-nodpor.tesh @@ -15,6 +15,6 @@ $ ${bindir:=.}/../../../bin/simgrid-mc --cfg=model-check/reduction:none -- ${bin > [0.000000] [mc_ModelChecker/INFO] 1: iRecv(mbox=0) > [0.000000] [mc_ModelChecker/INFO] 2: iSend(mbox=0) > [0.000000] [mc_ModelChecker/INFO] 1: WaitComm(from 2 to 1, mbox=0, no timeout) -> [0.000000] [mc_ModelChecker/INFO] Path = 1;3;1;1;2;1 +> [0.000000] [mc_ModelChecker/INFO] You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1;3;1;1;2;1' > [0.000000] [mc_dfs/INFO] DFS exploration ended. 119 unique states visited; 36 backtracks (330 transition replays, 175 states visited overall) diff --git a/examples/cpp/mc-failing-assert/s4u-mc-failing-assert.tesh b/examples/cpp/mc-failing-assert/s4u-mc-failing-assert.tesh index d49289dafb..fc687a94cc 100644 --- a/examples/cpp/mc-failing-assert/s4u-mc-failing-assert.tesh +++ b/examples/cpp/mc-failing-assert/s4u-mc-failing-assert.tesh @@ -22,5 +22,5 @@ $ ${bindir:=.}/../../../bin/simgrid-mc ${bindir:=.}/s4u-mc-failing-assert ${plat > [ 0.000000] (0:maestro@) 1: iRecv(mbox=0) > [ 0.000000] (0:maestro@) 2: iSend(mbox=0) > [ 0.000000] (0:maestro@) 1: WaitComm(from 2 to 1, mbox=0, no timeout) -> [ 0.000000] (0:maestro@) Path = 1;3;1;1;2;1 +> [ 0.000000] (0:maestro@) You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1;3;1;1;2;1' > [ 0.000000] (0:maestro@) DFS exploration ended. 18 unique states visited; 4 backtracks (36 transition replays, 14 states visited overall) diff --git a/examples/smpi/mc/sendsend.tesh b/examples/smpi/mc/sendsend.tesh index c1ca35ff21..4f73c5d3bc 100644 --- a/examples/smpi/mc/sendsend.tesh +++ b/examples/smpi/mc/sendsend.tesh @@ -19,9 +19,13 @@ $ ../../../smpi_script/bin/smpirun -quiet -wrapper "${bindir:=.}/../../../bin/si > [0.000000] [mc_global/INFO] ************************** > [0.000000] [mc_global/INFO] *** DEADLOCK DETECTED *** > [0.000000] [mc_global/INFO] ************************** +> [0.000000] [ker_engine/INFO] 2 actors are still running, waiting for something. +> [0.000000] [ker_engine/INFO] Legend of the following listing: "Actor (@): " +> [0.000000] [ker_engine/INFO] Actor 1 (0@node-0.simgrid.org) simcall CommWait(comm_id:1 src:1 dst:-1 mbox:SMPI-2(id:2) srcbuf:1 dstbuf:2 bufsize:4) +> [0.000000] [ker_engine/INFO] Actor 2 (1@node-1.simgrid.org) simcall CommWait(comm_id:2 src:2 dst:-1 mbox:SMPI-1(id:0) srcbuf:3 dstbuf:2 bufsize:4) > [0.000000] [mc_global/INFO] Counter-example execution trace: > [0.000000] [mc_global/INFO] 1: iSend(mbox=2) > [0.000000] [mc_global/INFO] 2: iSend(mbox=0) -> [0.000000] [mc_global/INFO] Path = 1;2 +> [0.000000] [mc_Session/INFO] You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1;2' > [0.000000] [mc_dfs/INFO] DFS exploration ended. 3 unique states visited; 1 backtracks (3 transition replays, 0 states visited overall) > Execution failed with code 3. diff --git a/examples/sthread/pthread-mc-mutex-simpledeadlock.tesh b/examples/sthread/pthread-mc-mutex-simpledeadlock.tesh index 63ff7761ca..8070caa6a8 100644 --- a/examples/sthread/pthread-mc-mutex-simpledeadlock.tesh +++ b/examples/sthread/pthread-mc-mutex-simpledeadlock.tesh @@ -15,6 +15,11 @@ $ ${bindir:=.}/../../bin/simgrid-mc --cfg=model-check/setenv:LD_PRELOAD=${libdir > [0.000000] [mc_global/INFO] ************************** > [0.000000] [mc_global/INFO] *** DEADLOCK DETECTED *** > [0.000000] [mc_global/INFO] ************************** +> [0.000000] [ker_engine/INFO] 3 actors are still running, waiting for something. +> [0.000000] [ker_engine/INFO] Legend of the following listing: "Actor (@): " +> [0.000000] [ker_engine/INFO] Actor 1 (main thread@Lilibeth) simcall ActorJoin(pid:2) +> [0.000000] [ker_engine/INFO] Actor 2 (0:1@Lilibeth) simcall MUTEX_WAIT(mutex_id: 1owner:3) +> [0.000000] [ker_engine/INFO] Actor 3 (0:2@Lilibeth) simcall MUTEX_WAIT(mutex_id: 0owner:2) > [0.000000] [mc_global/INFO] Counter-example execution trace: > [0.000000] [mc_global/INFO] 2: MUTEX_ASYNC_LOCK(mutex: 0, owner:2) > [0.000000] [mc_global/INFO] 2: MUTEX_WAIT(mutex: 0, owner:2) @@ -22,5 +27,5 @@ $ ${bindir:=.}/../../bin/simgrid-mc --cfg=model-check/setenv:LD_PRELOAD=${libdir > [0.000000] [mc_global/INFO] 2: MUTEX_ASYNC_LOCK(mutex: 1, owner:3) > [0.000000] [mc_global/INFO] 3: MUTEX_WAIT(mutex: 1, owner:3) > [0.000000] [mc_global/INFO] 3: MUTEX_ASYNC_LOCK(mutex: 0, owner:2) -> [0.000000] [mc_global/INFO] Path = 2;2;3;2;3;3 +> [0.000000] [mc_Session/INFO] You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'2;2;3;2;3;3' > [0.000000] [mc_dfs/INFO] DFS exploration ended. 19 unique states visited; 2 backtracks (22 transition replays, 2 states visited overall) diff --git a/src/kernel/EngineImpl.cpp b/src/kernel/EngineImpl.cpp index 717e7710d3..99304a9393 100644 --- a/src/kernel/EngineImpl.cpp +++ b/src/kernel/EngineImpl.cpp @@ -26,6 +26,8 @@ #include #endif /* _WIN32 */ +extern int xbt_log_no_loc; + #if SIMGRID_HAVE_MC #include "src/mc/remote/AppSide.hpp" #endif @@ -488,13 +490,17 @@ void EngineImpl::display_all_actor_status() const if (boost::dynamic_pointer_cast(actor->waiting_synchro_) != nullptr) synchro_description = "I/O"; - XBT_INFO("Actor %ld (%s@%s): waiting for %s activity %#zx (%s) in state %s to finish", actor->get_pid(), + XBT_INFO("Actor %ld (%s@%s): waiting for %s activity %#zx (%s) in state %s to finish %s", actor->get_pid(), actor->get_cname(), actor->get_host()->get_cname(), synchro_description, (xbt_log_no_loc ? (size_t)0xDEADBEEF : (size_t)actor->waiting_synchro_.get()), - actor->waiting_synchro_->get_cname(), actor->waiting_synchro_->get_state_str()); + actor->waiting_synchro_->get_cname(), actor->waiting_synchro_->get_state_str(), + (actor->simcall_.observer_ != nullptr && not xbt_log_no_loc + ? actor->simcall_.observer_->to_string().c_str() + : "")); } else { XBT_INFO("Actor %ld (%s@%s) simcall %s", actor->get_pid(), actor->get_cname(), actor->get_host()->get_cname(), - actor->simcall_.get_cname()); + (actor->simcall_.observer_ != nullptr ? actor->simcall_.observer_->to_string().c_str() + : actor->simcall_.get_cname())); } } } diff --git a/src/kernel/actor/ActorImpl.cpp b/src/kernel/actor/ActorImpl.cpp index 8f3b373617..e308692bd8 100644 --- a/src/kernel/actor/ActorImpl.cpp +++ b/src/kernel/actor/ActorImpl.cpp @@ -3,6 +3,7 @@ /* This program is free software; you can redistribute it and/or modify it * under the terms of the license (GNU LGPL) which comes with this package. */ +#include "src/mc/mc_replay.hpp" #include #include #include @@ -279,6 +280,8 @@ void ActorImpl::yield() if (not wannadie()) smpi_switch_data_segment(get_iface()); #endif + if (simgrid_mc_replay_show_backtraces) + xbt_backtrace_display_current(); } /** This actor will be terminated automatically when the last non-daemon actor finishes */ diff --git a/src/kernel/actor/CommObserver.cpp b/src/kernel/actor/CommObserver.cpp index 8f86d94cb9..983ba9483d 100644 --- a/src/kernel/actor/CommObserver.cpp +++ b/src/kernel/actor/CommObserver.cpp @@ -51,6 +51,25 @@ static void serialize_activity_test(const activity::ActivityImpl* act, std::stri stream << (short)mc::Transition::Type::UNKNOWN; } } +template static std::string ptr_to_id(A* ptr) +{ + static std::unordered_map map; + if (map.find(ptr) == map.end()) + map.insert(std::make_pair(ptr, std::to_string(map.size() + 1))); + return map[ptr]; +} +static std::string to_string_activity_test(const activity::ActivityImpl* act) +{ + if (auto* comm = dynamic_cast(act)) { + return std::string("CommTest(comm_id:") + ptr_to_id(comm) + + " src:" + std::to_string(comm->src_actor_ != nullptr ? comm->src_actor_->get_pid() : -1) + + " dst:" + std::to_string(comm->dst_actor_ != nullptr ? comm->dst_actor_->get_pid() : -1) + + " mbox:" + std::to_string(comm->get_mailbox_id()) + " srcbuf:" + ptr_to_id(comm->src_buff_) + + " dstbuf:" + ptr_to_id(comm->dst_buff_) + " bufsize:" + std::to_string(comm->src_buff_size_); + } else { + return "TestUnknownType()"; + } +} void ActivityTestanySimcall::serialize(std::stringstream& stream) const { stream << (short)mc::Transition::Type::TESTANY << ' ' << activities_.size() << ' '; @@ -59,10 +78,23 @@ void ActivityTestanySimcall::serialize(std::stringstream& stream) const stream << ' '; } } +std::string ActivityTestanySimcall::to_string() const +{ + std::stringstream buffer("TestAny("); + for (auto const& act : activities_) { + buffer << to_string_activity_test(act); + } + return buffer.str(); +} + void ActivityTestSimcall::serialize(std::stringstream& stream) const { serialize_activity_test(activity_, stream); } +std::string ActivityTestSimcall::to_string() const +{ + return to_string_activity_test(activity_); +} static void serialize_activity_wait(const activity::ActivityImpl* act, bool timeout, std::stringstream& stream) { if (auto* comm = dynamic_cast(act)) { @@ -77,6 +109,20 @@ static void serialize_activity_wait(const activity::ActivityImpl* act, bool time stream << (short)mc::Transition::Type::UNKNOWN; } } +static std::string to_string_activity_wait(const activity::ActivityImpl* act) +{ + if (auto* comm = dynamic_cast(act)) { + return std::string("CommWait(comm_id:") + ptr_to_id(comm) + + " src:" + std::to_string(comm->src_actor_ != nullptr ? comm->src_actor_->get_pid() : -1) + + " dst:" + std::to_string(comm->dst_actor_ != nullptr ? comm->dst_actor_->get_pid() : -1) + + " mbox:" + std::string(comm->get_mailbox() == nullptr ? xbt::string("-") : comm->get_mailbox()->get_name()) + + "(id:" + std::to_string(comm->get_mailbox_id()) + ") srcbuf:" + ptr_to_id(comm->src_buff_) + + " dstbuf:" + ptr_to_id(comm->dst_buff_) + " bufsize:" + std::to_string(comm->src_buff_size_) + + ")"; + } else { + return "WaitUnknownType()"; + } +} void ActivityWaitSimcall::serialize(std::stringstream& stream) const { @@ -90,6 +136,18 @@ void ActivityWaitanySimcall::serialize(std::stringstream& stream) const stream << ' '; } } +std::string ActivityWaitSimcall::to_string() const +{ + return to_string_activity_wait(activity_); +} +std::string ActivityWaitanySimcall::to_string() const +{ + std::stringstream buffer("WaitAny("); + for (auto const& act : activities_) { + buffer << to_string_activity_wait(act); + } + return buffer.str(); +} ActivityWaitanySimcall::ActivityWaitanySimcall(ActorImpl* actor, const std::vector& activities, double timeout) : ResultingSimcall(actor, -1), activities_(activities), timeout_(timeout) @@ -149,6 +207,12 @@ void CommIsendSimcall::serialize(std::stringstream& stream) const XBT_DEBUG("SendObserver comm:%p mbox:%u buff:%p size:%zu tag:%d", comm_, mbox_->get_id(), src_buff_, src_buff_size_, tag_); } +std::string CommIsendSimcall::to_string() const +{ + return std::string("CommAsyncSend(comm_id: ") + std::to_string((uintptr_t)comm_) + + " mbox:" + std::to_string(mbox_->get_id()) + " srcbuf:" + ptr_to_id(src_buff_) + + " bufsize:" + std::to_string(src_buff_size_) + " tag: " + std::to_string(tag_) + ")"; +} void CommIrecvSimcall::serialize(std::stringstream& stream) const { @@ -156,5 +220,11 @@ void CommIrecvSimcall::serialize(std::stringstream& stream) const stream << (uintptr_t)comm_ << ' ' << mbox_->get_id() << ' ' << (uintptr_t)dst_buff_ << ' ' << tag_; XBT_DEBUG("RecvObserver comm:%p mbox:%u buff:%p tag:%d", comm_, mbox_->get_id(), dst_buff_, tag_); } +std::string CommIrecvSimcall::to_string() const +{ + return std::string("CommAsyncRecv(comm_id: ") + ptr_to_id(comm_) + + " mbox:" + std::to_string(mbox_->get_id()) + " dstbuf:" + ptr_to_id(dst_buff_) + + " tag: " + std::to_string(tag_) + ")"; +} } // namespace simgrid::kernel::actor diff --git a/src/kernel/actor/CommObserver.hpp b/src/kernel/actor/CommObserver.hpp index 41607aa580..04ed6f3619 100644 --- a/src/kernel/actor/CommObserver.hpp +++ b/src/kernel/actor/CommObserver.hpp @@ -26,6 +26,7 @@ public: bool is_visible() const override { return true; } activity::ActivityImpl* get_activity() const { return activity_; } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; }; class ActivityTestanySimcall final : public ResultingSimcall { @@ -38,6 +39,7 @@ public: bool is_visible() const override { return true; } bool is_enabled() override { return true; /* can return -1 if no activity is ready */ } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; int get_max_consider() const override; void prepare(int times_considered) override; const std::vector& get_activities() const { return activities_; } @@ -54,6 +56,7 @@ public: { } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_visible() const override { return true; } bool is_enabled() override; activity::ActivityImpl* get_activity() const { return activity_; } @@ -71,6 +74,7 @@ public: ActivityWaitanySimcall(ActorImpl* actor, const std::vector& activities, double timeout); bool is_enabled() override; void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_visible() const override { return true; } void prepare(int times_considered) override; int get_max_consider() const override; @@ -116,6 +120,7 @@ public: { } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_visible() const override { return true; } activity::MailboxImpl* get_mailbox() const { return mbox_; } double get_payload_size() const { return payload_size_; } @@ -160,6 +165,7 @@ public: { } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_visible() const override { return true; } activity::MailboxImpl* get_mailbox() const { return mbox_; } double get_rate() const { return rate_; } diff --git a/src/kernel/actor/Simcall.cpp b/src/kernel/actor/Simcall.cpp index 156636dbc6..9f35a3b3b0 100644 --- a/src/kernel/actor/Simcall.cpp +++ b/src/kernel/actor/Simcall.cpp @@ -20,7 +20,8 @@ namespace simgrid::kernel::actor { */ void ActorImpl::simcall_handle(int times_considered) { - XBT_DEBUG("Handling simcall %p: %s", &simcall_, simcall_.get_cname()); + 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())); if (simcall_.observer_ != nullptr) simcall_.observer_->prepare(times_considered); if (wannadie()) diff --git a/src/kernel/actor/SimcallObserver.cpp b/src/kernel/actor/SimcallObserver.cpp index 88428f1b0f..c07d073e27 100644 --- a/src/kernel/actor/SimcallObserver.cpp +++ b/src/kernel/actor/SimcallObserver.cpp @@ -21,6 +21,10 @@ void RandomSimcall::serialize(std::stringstream& stream) const stream << (short)mc::Transition::Type::RANDOM << ' '; stream << min_ << ' ' << max_; } +std::string RandomSimcall::to_string() const +{ + return std::string("Random(min:") + std::to_string(min_) + " max:" + std::to_string(max_) + ")"; +} void RandomSimcall::prepare(int times_considered) { @@ -45,6 +49,10 @@ void ConditionWaitSimcall::serialize(std::stringstream& stream) const { THROW_UNIMPLEMENTED; } +std::string ConditionWaitSimcall::to_string() const +{ + THROW_UNIMPLEMENTED; +} ActorJoinSimcall::ActorJoinSimcall(ActorImpl* actor, ActorImpl* other, double timeout) : SimcallObserver(actor), other_(s4u::ActorPtr(other->get_iface())), timeout_(timeout) @@ -59,4 +67,8 @@ void ActorJoinSimcall::serialize(std::stringstream& stream) const stream << (short)mc::Transition::Type::ACTOR_JOIN << ' '; stream << other_->get_pid() << ' ' << (timeout_ > 0); } +std::string ActorJoinSimcall::to_string() const +{ + return std::string("ActorJoin(pid:") + std::to_string(other_->get_pid()) + ")"; +} } // namespace simgrid::kernel::actor diff --git a/src/kernel/actor/SimcallObserver.hpp b/src/kernel/actor/SimcallObserver.hpp index 909ebd1444..5b47b31adb 100644 --- a/src/kernel/actor/SimcallObserver.hpp +++ b/src/kernel/actor/SimcallObserver.hpp @@ -52,9 +52,12 @@ public: { /* Nothing to do by default */ } - /** Serialize to the given string buffer */ + /** Serialize to the given string buffer, to send over the network */ virtual void serialize(std::stringstream& stream) const = 0; + /** Used to debug (to display the simcall on which each actor is blocked when displaying it */ + virtual std::string to_string() const = 0; + /** Whether the MC should see this simcall. * Simcall that don't have an observer (ie, most of them) are not visible from the MC, but if there is an observer, * they are observable by default. */ @@ -84,6 +87,7 @@ public: xbt_assert(min < max); } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; int get_max_consider() const override; void prepare(int times_considered) override; int get_value() const { return next_value_; } @@ -101,6 +105,7 @@ public: { } void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_enabled() override; activity::ConditionVariableImpl* get_cond() const { return cond_; } activity::MutexImpl* get_mutex() const { return mutex_; } @@ -114,6 +119,7 @@ class ActorJoinSimcall final : public SimcallObserver { public: ActorJoinSimcall(ActorImpl* actor, ActorImpl* other, double timeout = -1.0); void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_enabled() override; s4u::ActorPtr get_other_actor() const { return other_; } diff --git a/src/kernel/actor/SynchroObserver.cpp b/src/kernel/actor/SynchroObserver.cpp index 96d75c7c63..8114a5eda2 100644 --- a/src/kernel/actor/SynchroObserver.cpp +++ b/src/kernel/actor/SynchroObserver.cpp @@ -28,6 +28,11 @@ void MutexObserver::serialize(std::stringstream& stream) const const auto* owner = get_mutex()->get_owner(); stream << (short)type_ << ' ' << get_mutex()->get_id() << ' ' << (owner != nullptr ? owner->get_pid() : -1); } +std::string MutexObserver::to_string() const +{ + return std::string(mc::Transition::to_c_str(type_)) + "(mutex_id: " + std::to_string(get_mutex()->get_id()) + + "owner:" + std::to_string(get_mutex()->get_owner()->get_pid()) + ")"; +} bool MutexObserver::is_enabled() { @@ -45,6 +50,10 @@ void SemaphoreObserver::serialize(std::stringstream& stream) const { stream << (short)type_ << ' ' << get_sem()->get_id() << ' ' << false /* Granted is ignored for LOCK/UNLOCK */; } +std::string SemaphoreObserver::to_string() const +{ + return std::string(mc::Transition::to_c_str(type_)) + "(sem_id: " + std::to_string(get_sem()->get_id()) + ")"; +} SemaphoreAcquisitionObserver::SemaphoreAcquisitionObserver(ActorImpl* actor, mc::Transition::Type type, activity::SemAcquisitionImpl* acqui, double timeout) @@ -59,6 +68,12 @@ void SemaphoreAcquisitionObserver::serialize(std::stringstream& stream) const { stream << (short)type_ << ' ' << acquisition_->semaphore_->get_id() << ' ' << acquisition_->granted_; } +std::string SemaphoreAcquisitionObserver::to_string() const +{ + return std::string(mc::Transition::to_c_str(type_)) + + "(sem_id: " + std::to_string(acquisition_->semaphore_->get_id()) + ' ' + + (acquisition_->granted_ ? "granted)" : "not granted)"); +} BarrierObserver::BarrierObserver(ActorImpl* actor, mc::Transition::Type type, activity::BarrierImpl* bar) : ResultingSimcall(actor, false), type_(type), barrier_(bar), timeout_(-1) @@ -76,6 +91,12 @@ void BarrierObserver::serialize(std::stringstream& stream) const xbt_assert(barrier_ != nullptr || (acquisition_ != nullptr && acquisition_->barrier_ != nullptr)); stream << (short)type_ << ' ' << (barrier_ != nullptr ? barrier_->get_id() : acquisition_->barrier_->get_id()); } +std::string BarrierObserver::to_string() const +{ + return std::string(mc::Transition::to_c_str(type_)) + + "(barrier_id: " + std::to_string(barrier_ != nullptr ? barrier_->get_id() : acquisition_->barrier_->get_id()) + + ")"; +} bool BarrierObserver::is_enabled() { return type_ == mc::Transition::Type::BARRIER_ASYNC_LOCK || diff --git a/src/kernel/actor/SynchroObserver.hpp b/src/kernel/actor/SynchroObserver.hpp index c953c5d20d..90c7335883 100644 --- a/src/kernel/actor/SynchroObserver.hpp +++ b/src/kernel/actor/SynchroObserver.hpp @@ -24,6 +24,7 @@ public: MutexObserver(ActorImpl* actor, mc::Transition::Type type, activity::MutexImpl* mutex); void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_enabled() override; activity::MutexImpl* get_mutex() const { return mutex_; } @@ -38,6 +39,7 @@ public: SemaphoreObserver(ActorImpl* actor, mc::Transition::Type type, activity::SemaphoreImpl* sem); void serialize(std::stringstream& stream) const override; + std::string to_string() const override; activity::SemaphoreImpl* get_sem() const { return sem_; } }; @@ -53,12 +55,13 @@ public: double timeout = -1.0); void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_enabled() override; double get_timeout() const { return timeout_; } }; -/* This observer is ued for BARRIER_LOCK and BARRIER_WAIT. WAIT is returning and needs the acquisition */ +/* This observer is used for BARRIER_LOCK and BARRIER_WAIT. WAIT is returning and needs the acquisition */ class BarrierObserver final : public ResultingSimcall { mc::Transition::Type type_; activity::BarrierImpl* const barrier_ = nullptr; @@ -71,6 +74,7 @@ public: double timeout = -1.0); void serialize(std::stringstream& stream) const override; + std::string to_string() const override; bool is_enabled() override; double get_timeout() const { return timeout_; } diff --git a/src/mc/ModelChecker.cpp b/src/mc/ModelChecker.cpp index 17e2bce738..eac05cd7d4 100644 --- a/src/mc/ModelChecker.cpp +++ b/src/mc/ModelChecker.cpp @@ -156,7 +156,9 @@ static void MC_report_crash(Exploration* explorer, int status) XBT_INFO("Counter-example execution trace:"); for (auto const& s : explorer->get_textual_trace()) XBT_INFO(" %s", s.c_str()); - XBT_INFO("Path = %s", explorer->get_record_trace().to_string().c_str()); + XBT_INFO("You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with " + "--cfg=model-check/replay:'%s'", + explorer->get_record_trace().to_string().c_str()); explorer->log_state(); if (xbt_log_no_loc) { XBT_INFO("Stack trace not displayed because you passed --log=no_loc"); @@ -241,7 +243,9 @@ bool ModelChecker::handle_message(const char* buffer, ssize_t size) XBT_INFO("Counter-example execution trace:"); for (auto const& s : get_exploration()->get_textual_trace()) XBT_INFO(" %s", s.c_str()); - XBT_INFO("Path = %s", get_exploration()->get_record_trace().to_string().c_str()); + XBT_INFO("You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with " + "--cfg=model-check/replay:'%s'", + get_exploration()->get_record_trace().to_string().c_str()); exploration_->log_state(); this->exit(SIMGRID_MC_EXIT_SAFETY); diff --git a/src/mc/api/RemoteApp.cpp b/src/mc/api/RemoteApp.cpp index 27518c41f8..64aed11e6e 100644 --- a/src/mc/api/RemoteApp.cpp +++ b/src/mc/api/RemoteApp.cpp @@ -198,13 +198,12 @@ void RemoteApp::check_deadlock() const (int)sizeof(message)); if (message.value != 0) { - XBT_CINFO(mc_global, "**************************"); - XBT_CINFO(mc_global, "*** DEADLOCK DETECTED ***"); - XBT_CINFO(mc_global, "**************************"); XBT_CINFO(mc_global, "Counter-example execution trace:"); for (auto const& frame : model_checker_->get_exploration()->get_textual_trace()) XBT_CINFO(mc_global, " %s", frame.c_str()); - XBT_CINFO(mc_global, "Path = %s", model_checker_->get_exploration()->get_record_trace().to_string().c_str()); + XBT_INFO("You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with " + "--cfg=model-check/replay:'%s'", + model_checker_->get_exploration()->get_record_trace().to_string().c_str()); model_checker_->get_exploration()->log_state(); throw DeadlockError(); } diff --git a/src/mc/explo/DFSExplorer.cpp b/src/mc/explo/DFSExplorer.cpp index 03122f3d31..3af39bc674 100644 --- a/src/mc/explo/DFSExplorer.cpp +++ b/src/mc/explo/DFSExplorer.cpp @@ -49,7 +49,9 @@ void DFSExplorer::check_non_termination(const State* current_state) XBT_INFO("Counter-example execution trace:"); for (auto const& s : get_textual_trace()) XBT_INFO(" %s", s.c_str()); - XBT_INFO("Path = %s", get_record_trace().to_string().c_str()); + XBT_INFO("You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with " + "--cfg=model-check/replay:'%s'", + get_record_trace().to_string().c_str()); log_state(); throw TerminationError(); @@ -95,7 +97,7 @@ void DFSExplorer::run() State* state = stack_.back().get(); XBT_DEBUG("**************************************************"); - XBT_DEBUG("Exploration depth=%zu (state:%ld; %zu interleaves)", stack_.size(), state->get_num(), + XBT_DEBUG("Exploration depth=%zu (state:#%ld; %zu interleaves todo)", stack_.size(), state->get_num(), state->count_todo()); mc_model_checker->inc_visited_states(); diff --git a/src/mc/explo/LivenessChecker.cpp b/src/mc/explo/LivenessChecker.cpp index 8f1ecb22d9..03ec2d033d 100644 --- a/src/mc/explo/LivenessChecker.cpp +++ b/src/mc/explo/LivenessChecker.cpp @@ -275,7 +275,9 @@ void LivenessChecker::show_acceptance_cycle(std::size_t depth) XBT_INFO("Counter-example that violates formula:"); for (auto const& s : this->get_textual_trace()) XBT_INFO(" %s", s.c_str()); - XBT_INFO("Path = %s", get_record_trace().to_string().c_str()); + XBT_INFO("You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with " + "--cfg=model-check/replay:'%s'", + get_record_trace().to_string().c_str()); log_state(); XBT_INFO("Counter-example depth: %zu", depth); } diff --git a/src/mc/mc_base.cpp b/src/mc/mc_base.cpp index 781a5ee262..ac3f49f346 100644 --- a/src/mc/mc_base.cpp +++ b/src/mc/mc_base.cpp @@ -19,6 +19,7 @@ #endif XBT_LOG_NEW_DEFAULT_CATEGORY(mc, "All MC categories"); +bool simgrid_mc_replay_show_backtraces = false; namespace simgrid::mc { @@ -26,6 +27,8 @@ void execute_actors() { auto* engine = kernel::EngineImpl::get_instance(); + XBT_DEBUG("execute_actors: %lu of %zu to run (%s)", engine->get_actor_to_run_count(), engine->get_actor_count(), + (MC_record_replay_is_active() ? "replay active" : "no replay")); while (engine->has_actors_to_run()) { engine->run_all_actors(); for (auto const& actor : engine->get_actors_that_ran()) { @@ -47,7 +50,6 @@ void execute_actors() * transition for ever. * This is controlled in the is_enabled() method of the corresponding observers. */ -// Called from both MCer and MCed: bool actor_is_enabled(kernel::actor::ActorImpl* actor) { #if SIMGRID_HAVE_MC @@ -75,10 +77,9 @@ bool request_is_visible(const kernel::actor::Simcall* req) #if SIMGRID_HAVE_MC xbt_assert(mc_model_checker == nullptr, "This should be called from the client side"); #endif - if (req->observer_ != nullptr) - return req->observer_->is_visible(); - else + if (req->observer_ == nullptr) return false; + return req->observer_->is_visible(); } } // namespace simgrid::mc diff --git a/src/mc/mc_record.cpp b/src/mc/mc_record.cpp index 72483fe420..67e88835b3 100644 --- a/src/mc/mc_record.cpp +++ b/src/mc/mc_record.cpp @@ -23,21 +23,47 @@ namespace simgrid::mc { void RecordTrace::replay() const { simgrid::mc::execute_actors(); + auto* engine = kernel::EngineImpl::get_instance(); - for (const simgrid::mc::Transition* transition : transitions_) { - XBT_DEBUG("Executing %ld$%i", transition->aid_, transition->times_considered_); + int frame_count = 1; + if (xbt_log_no_loc) + XBT_INFO("The backtrace of each transition will not be shown because of --log=no_loc"); + else + simgrid_mc_replay_show_backtraces = 1; - // Choose a request: - kernel::actor::ActorImpl* actor = kernel::EngineImpl::get_instance()->get_actor_by_pid(transition->aid_); + for (const simgrid::mc::Transition* transition : transitions_) { + kernel::actor::ActorImpl* actor = engine->get_actor_by_pid(transition->aid_); xbt_assert(actor != nullptr, "Unexpected actor (id:%ld).", transition->aid_); const kernel::actor::Simcall* simcall = &(actor->simcall_); - xbt_assert(simcall->call_ != kernel::actor::Simcall::Type::NONE, "No simcall for process %ld.", transition->aid_); - xbt_assert(simgrid::mc::request_is_visible(simcall) && simgrid::mc::actor_is_enabled(actor), "Unexpected simcall."); + xbt_assert(simgrid::mc::request_is_visible(simcall), "Simcall %s of actor %s is not visible.", simcall->get_cname(), + actor->get_cname()); + + XBT_INFO("***********************************************************************************"); + XBT_INFO("* Path chunk #%d '%ld/%i' Actor %s(pid:%ld): %s", frame_count++, transition->aid_, + transition->times_considered_, simcall->issuer_->get_cname(), simcall->issuer_->get_pid(), + simcall->observer_->to_string().c_str()); + XBT_INFO("***********************************************************************************"); + if (not mc::actor_is_enabled(actor)) + simgrid::kernel::EngineImpl::get_instance()->display_all_actor_status(); + + xbt_assert(simgrid::mc::actor_is_enabled(actor), "Actor %s (simcall %s) is not enabled.", actor->get_cname(), + simcall->get_cname()); // Execute the request: simcall->issuer_->simcall_handle(transition->times_considered_); simgrid::mc::execute_actors(); } + + const auto& actor_list = engine->get_actor_list(); + if (actor_list.empty()) { + XBT_INFO("The replay of the trace is complete. The application is terminating."); + } else if (std::none_of(begin(actor_list), end(actor_list), + [](const auto& kv) { return mc::actor_is_enabled(kv.second); })) { + XBT_INFO("The replay of the trace is complete. DEADLOCK detected."); + engine->display_all_actor_status(); + } else { + XBT_INFO("The replay of the trace is complete. The application could run further."); + } } void simgrid::mc::RecordTrace::replay(const std::string& path_string) @@ -59,7 +85,7 @@ simgrid::mc::RecordTrace::RecordTrace(const char* data) const char* current = data; while (*current) { long aid; - int times_considered; + int times_considered = 0; if (int count = sscanf(current, "%ld/%d", &aid, ×_considered); count != 2 && count != 1) throw std::invalid_argument("Could not parse record path"); diff --git a/src/mc/mc_replay.hpp b/src/mc/mc_replay.hpp index ae8cd4a06d..7c59b5db4d 100644 --- a/src/mc/mc_replay.hpp +++ b/src/mc/mc_replay.hpp @@ -25,4 +25,7 @@ static inline int MC_record_replay_is_active() return not MC_record_path().empty(); } +/** Whether we should display extra information during this MC replay */ +extern bool simgrid_mc_replay_show_backtraces; + #endif diff --git a/src/mc/remote/AppSide.cpp b/src/mc/remote/AppSide.cpp index cbc819b407..56de882c90 100644 --- a/src/mc/remote/AppSide.cpp +++ b/src/mc/remote/AppSide.cpp @@ -30,6 +30,7 @@ #include XBT_LOG_NEW_DEFAULT_SUBCATEGORY(mc_client, mc, "MC client logic"); +XBT_LOG_EXTERNAL_CATEGORY(mc_global); namespace simgrid::mc { @@ -84,11 +85,18 @@ AppSide* AppSide::initialize() void AppSide::handle_deadlock_check(const s_mc_message_t*) const { - const auto& actor_list = kernel::EngineImpl::get_instance()->get_actor_list(); + auto* engine = kernel::EngineImpl::get_instance(); + const auto& actor_list = engine->get_actor_list(); bool deadlock = not actor_list.empty() && std::none_of(begin(actor_list), end(actor_list), [](const auto& kv) { return mc::actor_is_enabled(kv.second); }); + if (deadlock) { + XBT_CINFO(mc_global, "**************************"); + XBT_CINFO(mc_global, "*** DEADLOCK DETECTED ***"); + XBT_CINFO(mc_global, "**************************"); + engine->display_all_actor_status(); + } // Send result: s_mc_message_int_t answer{MessageType::DEADLOCK_CHECK_REPLY, deadlock}; xbt_assert(channel_.send(answer) == 0, "Could not send response"); diff --git a/src/smpi/internals/smpi_global.cpp b/src/smpi/internals/smpi_global.cpp index 8b3a184c87..39941125fc 100644 --- a/src/smpi/internals/smpi_global.cpp +++ b/src/smpi/internals/smpi_global.cpp @@ -13,6 +13,7 @@ #include "smpi_host.hpp" #include "src/kernel/EngineImpl.hpp" #include "src/kernel/activity/CommImpl.hpp" +#include "src/mc/mc_replay.hpp" #include "src/smpi/include/smpi_actor.hpp" #include "xbt/config.hpp" #include "xbt/file.hpp" @@ -630,7 +631,7 @@ void smpi_mpi_init() { smpi_init_fortran_types(); if(_smpi_init_sleep > 0) simgrid::s4u::this_actor::sleep_for(_smpi_init_sleep); - if (not MC_is_active()) { + if (not MC_is_active() && not MC_record_replay_is_active()) { smpi_deployment_startup_barrier(smpi_process()->get_instance_id()); } } diff --git a/src/xbt/backtrace.cpp b/src/xbt/backtrace.cpp index bead6583cc..a180720217 100644 --- a/src/xbt/backtrace.cpp +++ b/src/xbt/backtrace.cpp @@ -50,7 +50,21 @@ public: if (frame_name.rfind("simgrid::xbt::MainFunction", 0) == 0 || frame_name.rfind("simgrid::kernel::context::Context::operator()()", 0) == 0) break; - ss << " -> " << frame_count++ << "# " << frame << "\n"; + if (xbt_log_no_loc) { // Don't display file source and line if so + if (frame.name().empty()) + ss << " -> #" << frame_count++ << " (debug info not found and log:no_loc activated)\n"; + else + ss << " -> #" << frame_count++ << " " << frame.name() << "\n"; + } else + ss << " -> #" << frame_count++ << " " << frame << "\n"; + // If we are displaying the user side of a simcall, remove the crude details of context switching + if (frame_name.find("simgrid::kernel::actor::simcall_answered") != std::string::npos || + frame_name.find("simgrid::kernel::actor::simcall_blocking") != std::string::npos || + frame_name.find("simcall_run_answered") != std::string::npos || + frame_name.find("simcall_run_blocking") != std::string::npos) { + frame_count = 0; + ss.str(std::string()); // This is how you clear a stringstream in C++. clear() is something else :'( + } if (frame_name == "main") break; } else { @@ -78,7 +92,8 @@ std::string Backtrace::resolve() const void Backtrace::display() const { std::string backtrace = resolve(); - std::fprintf(stderr, "Backtrace (displayed in actor %s):\n%s\n", xbt_procname(), + std::fprintf(stderr, "Backtrace (displayed in actor %s%s):\n%s\n", xbt_procname(), + (xbt_log_no_loc ? " -- short trace because of --log=no_loc" : ""), backtrace.empty() ? "(backtrace not set -- did you install Boost.Stacktrace?)" : backtrace.c_str()); } diff --git a/teshsuite/mc/CMakeLists.txt b/teshsuite/mc/CMakeLists.txt index b4b76485e3..7d0e35197a 100644 --- a/teshsuite/mc/CMakeLists.txt +++ b/teshsuite/mc/CMakeLists.txt @@ -15,6 +15,7 @@ foreach(x dwarf dwarf-expression random-bug mutex-handling) target_link_libraries(${x} simgrid) set_target_properties(${x} PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_CURRENT_BINARY_DIR}/${x}) set_property(TARGET ${x} APPEND PROPERTY INCLUDE_DIRECTORIES "${INTERNAL_INCLUDES}") + target_compile_options(${x} PRIVATE ${CMAKE_C_DEBUG_FLAGS}) add_dependencies(tests-mc ${x}) endif() diff --git a/teshsuite/mc/random-bug/random-bug-replay.tesh b/teshsuite/mc/random-bug/random-bug-replay.tesh index df085576c1..560b2d9253 100644 --- a/teshsuite/mc/random-bug/random-bug-replay.tesh +++ b/teshsuite/mc/random-bug/random-bug-replay.tesh @@ -1,12 +1,27 @@ #!/usr/bin/env tesh -$ ${bindir:=.}/random-bug printf ${platfdir}/small_platform.xml --log=xbt_cfg.thresh:warning "--log=root.fmt:[%10.6r]%e(%i:%a@%h)%e%m%n" "--cfg=model-check/replay:1/3;1/4" +$ ${bindir:=.}/random-bug printf ${platfdir}/small_platform.xml --log=xbt_cfg.thresh:warning "--log=root.fmt:[%10.6r]%e(%i:%a@%h)%e%m%n" "--cfg=model-check/replay:1/3;1/4" --log=no_loc > [ 0.000000] (0:maestro@) Behavior: printf > [ 0.000000] (0:maestro@) path=1/3;1/4 +> [ 0.000000] (0:maestro@) The backtrace of each transition will not be shown because of --log=no_loc +> [ 0.000000] (0:maestro@) *********************************************************************************** +> [ 0.000000] (0:maestro@) * Path chunk #1 '1/3' Actor app(pid:1): Random(min:0 max:5) +> [ 0.000000] (0:maestro@) *********************************************************************************** +> [ 0.000000] (0:maestro@) *********************************************************************************** +> [ 0.000000] (0:maestro@) * Path chunk #2 '1/4' Actor app(pid:1): Random(min:0 max:5) +> [ 0.000000] (0:maestro@) *********************************************************************************** > [ 0.000000] (1:app@Fafard) Error reached +> [ 0.000000] (0:maestro@) The replay of the trace is complete. The application is terminating. # Behavior: assert does not have the same output within and without MC, so don't test it here. That's already covered with the other ones ! expect signal SIGIOT -$ $VALGRIND_NO_LEAK_CHECK ${bindir:=.}/random-bug abort ${platfdir}/small_platform.xml --log=xbt_cfg.thresh:warning "--log=root.fmt:[%10.6r]%e(%i:%a@%h)%e%m%n" "--cfg=model-check/replay:1/3;1/4" +$ $VALGRIND_NO_LEAK_CHECK ${bindir:=.}/random-bug abort ${platfdir}/small_platform.xml --log=xbt_cfg.thresh:warning "--log=root.fmt:[%10.6r]%e(%i:%a@%h)%e%m%n" "--cfg=model-check/replay:1/3;1/4" --log=no_loc > [ 0.000000] (0:maestro@) Behavior: abort > [ 0.000000] (0:maestro@) path=1/3;1/4 +> [ 0.000000] (0:maestro@) The backtrace of each transition will not be shown because of --log=no_loc +> [ 0.000000] (0:maestro@) *********************************************************************************** +> [ 0.000000] (0:maestro@) * Path chunk #1 '1/3' Actor app(pid:1): Random(min:0 max:5) +> [ 0.000000] (0:maestro@) *********************************************************************************** +> [ 0.000000] (0:maestro@) *********************************************************************************** +> [ 0.000000] (0:maestro@) * Path chunk #2 '1/4' Actor app(pid:1): Random(min:0 max:5) +> [ 0.000000] (0:maestro@) *********************************************************************************** diff --git a/teshsuite/mc/random-bug/random-bug.tesh b/teshsuite/mc/random-bug/random-bug.tesh index 3b6ffa213b..952ba8ebe3 100644 --- a/teshsuite/mc/random-bug/random-bug.tesh +++ b/teshsuite/mc/random-bug/random-bug.tesh @@ -9,7 +9,7 @@ $ ${bindir:=.}/../../../bin/simgrid-mc ${bindir:=.}/random-bug assert ${platfdir > [ 0.000000] (0:maestro@) Counter-example execution trace: > [ 0.000000] (0:maestro@) 1: Random([0;5] ~> 3) > [ 0.000000] (0:maestro@) 1: Random([0;5] ~> 4) -> [ 0.000000] (0:maestro@) Path = 1/3;1/4 +> [ 0.000000] (0:maestro@) You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1/3;1/4' > [ 0.000000] (0:maestro@) DFS exploration ended. 27 unique states visited; 22 backtracks (68 transition replays, 19 states visited overall) ! expect return 6 @@ -24,7 +24,7 @@ $ ${bindir:=.}/../../../bin/simgrid-mc ${bindir:=.}/random-bug abort ${platfdir} > [ 0.000000] (0:maestro@) Counter-example execution trace: > [ 0.000000] (0:maestro@) 1: Random([0;5] ~> 3) > [ 0.000000] (0:maestro@) 1: Random([0;5] ~> 4) -> [ 0.000000] (0:maestro@) Path = 1/3;1/4 +> [ 0.000000] (0:maestro@) You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1/3;1/4' > [ 0.000000] (0:maestro@) DFS exploration ended. 27 unique states visited; 22 backtracks (68 transition replays, 19 states visited overall) > [ 0.000000] (0:maestro@) Stack trace not displayed because you passed --log=no_loc @@ -47,6 +47,6 @@ $ ${bindir:=.}/../../../bin/simgrid-mc ${bindir:=.}/random-bug segv ${platfdir}/ > [ 0.000000] (0:maestro@) Counter-example execution trace: > [ 0.000000] (0:maestro@) 1: Random([0;5] ~> 3) > [ 0.000000] (0:maestro@) 1: Random([0;5] ~> 4) -> [ 0.000000] (0:maestro@) Path = 1/3;1/4 +> [ 0.000000] (0:maestro@) You can debug the problem (and see the whole details) by rerunning out of simgrid-mc with --cfg=model-check/replay:'1/3;1/4' > [ 0.000000] (0:maestro@) DFS exploration ended. 27 unique states visited; 22 backtracks (68 transition replays, 19 states visited overall) > [ 0.000000] (0:maestro@) Stack trace not displayed because you passed --log=no_loc diff --git a/teshsuite/smpi/MBI/MBI.py b/teshsuite/smpi/MBI/MBI.py index 54040a879a..e04fc4e047 100755 --- a/teshsuite/smpi/MBI/MBI.py +++ b/teshsuite/smpi/MBI/MBI.py @@ -43,5 +43,5 @@ for test in mbi.parse_one_code(filename): if res_category != "TRUE_NEG" and res_category != "TRUE_POS": print("XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\n") - print(f"SimGrid gave the wrong result on {binary} ({outcome} instead of {test['expect']}).") + print(f"SimGrid gave the wrong result on {binary} ({outcome} instead of {test['detail']}).\nExpected diagnostic: {test['diagnostic']}") sys.exit(1) diff --git a/teshsuite/smpi/MBI/MBIutils.py b/teshsuite/smpi/MBI/MBIutils.py index 1d79bac835..c422cca055 100644 --- a/teshsuite/smpi/MBI/MBIutils.py +++ b/teshsuite/smpi/MBI/MBIutils.py @@ -138,7 +138,14 @@ def parse_one_code(filename): if detail not in possible_details: raise ValueError( f"\n{filename}:{line_num}: MBI parse error: Detailled outcome {detail} is not one of the allowed ones.") - test = {'filename': filename, 'id': test_num, 'cmd': cmd, 'expect': expect, 'detail': detail} + + nextline = next(input_file) + m = re.match('[ |]*(.*)', nextline) + if not m: + raise ValueError(f"\n{filename}:{line_num}: MBI parse error: Expected diagnostic of the test not found.\n") + diagnostic = m.group(1) + + test = {'filename': filename, 'id': test_num, 'cmd': cmd, 'expect': expect, 'detail': detail, 'diagnostic': diagnostic} res.append(test.copy()) test_num += 1 line_num += 1