boost-ext / sml

C++14 State Machine library
https://boost-ext.github.io/sml
Boost Software License 1.0
1.1k stars 173 forks source link

events are logged 3 times when SM has on_entry/exit #321

Open cppden opened 4 years ago

cppden commented 4 years ago

When SM has a state with on_entry and on_exit then event in other states are logged 3 times:

*sNull    + event<evMaster> / (set_replica, start_redis, conf_redis)        = sStarting,
D 2019/12/23 19:07:20.092348 (2beba700) Cdb.cpp[171]:>>Enter StartUp \
D 2019/12/23 19:07:20.093233 (2beba700) fsm.hpp[39]:cdb::cdb_fsm_t::Fsm.event[evMaster]
#01:    0x7f052b2111f0 void fsm::log::log_process_event<cdb::cdb_fsm_t::Fsm, cdb::evMaster>(cdb::evMaster const&)
#02:    0x7f052b201e30 void cdb::cdb_fsm_t::onRequestFromGate<cdb::evMaster>(cdb::evMaster const&)
#03:    0x7f052b1f86f0 Cdb::StartUp()

....
D 2019/12/23 19:07:20.094191 (2beba700) fsm.hpp[39]:cdb::cdb_fsm_t::Fsm.event[evMaster>]
#01:    0x7f052b213550 void fsm::log::log_process_event<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::on_exit<boost::sml::v1_1_0::back::_, cdb::evMaster> >(boost::sml::v1_1_0::back::on_exi
t<boost::sml::v1_1_0::back::_, cdb::evMaster> const&)
#02:    0x7f052b208b70 bool boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1
_0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > >::process_event_noexcept<boost::sml::v1_1_0::back::get_event_mapping_impl_helpe
r<cdb::evMaster, boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1_0::back::p
olicies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > >::mappings>, cdb::evMaster, boost::sml::v1_1_0::aux::pool<cdb::cdb_fsm_t*, fsm::log&>, boo
st::sml::v1_1_0::aux::pool<boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1_
0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > > > >(cdb::evMaster const&, boost::sml::v1_1_0::aux::pool<cdb::cdb_fsm_t*, fsm::l
og&>&, boost::sml::v1_1_0::aux::pool<boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::
sml::v1_1_0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > > >&, boost::sml::v1_1_0::aux::integral_constant<bool, true>)
#03:    0x7f052b201e30 void cdb::cdb_fsm_t::onRequestFromGate<cdb::evMaster>(cdb::evMaster const&)
#04:    0x7f052b1f86f0 Cdb::StartUp()

.....
D 2019/12/23 19:07:20.120076 (2beba700) fsm.hpp[39]:cdb::cdb_fsm_t::Fsm.event[evMaster>]

#01:    0x7f052b213610 void fsm::log::log_process_event<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::on_entry<boost::sml::v1_1_0::back::_, cdb::evMaster> >(boost::sml::v1_1_0::back::on_entry<boost::sml::v1_1_0::back::_, cdb::evMaster> const&)
#02:    0x7f052b208b70 bool boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1_0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > >::process_event_noexcept<boost::sml::v1_1_0::back::get_event_mapping_impl_helper<cdb::evMaster, boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1_0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > >::mappings>, cdb::evMaster, boost::sml::v1_1_0::aux::pool<cdb::cdb_fsm_t*, fsm::log&>, boost::sml::v1_1_0::aux::pool<boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1_0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > > > >(cdb::evMaster const&, boost::sml::v1_1_0::aux::pool<cdb::cdb_fsm_t*, fsm::log&>&, boost::sml::v1_1_0::aux::pool<boost::sml::v1_1_0::back::sm_impl<boost::sml::v1_1_0::back::sm_policy<cdb::cdb_fsm_t::Fsm, boost::sml::v1_1_0::back::policies::logger<fsm::log>, boost::sml::v1_1_0::back::policies::defer_queue<std::deque>, boost::sml::v1_1_0::back::policies::process_queue<std::queue> > > >&, boost::sml::v1_1_0::aux::integral_constant<bool, true>)
#03:    0x7f052b201e30 void cdb::cdb_fsm_t::onRequestFromGate<cdb::evMaster>(cdb::evMaster const&)
#04:    0x7f052b1f86f0 Cdb::StartUp()
.....
D 2019/12/23 19:07:20.120723 (2beba700) Cdb.cpp[171]:<<Leave StartUp /
GuiCodron commented 3 years ago

Do you consider it a bug?

Each event is a bit different, you have an onexit<, my_event>, the event itself and onentry, my_event>.

You can check for on_entry and on_exit by specializing your event logger to filter them out i think.

struct SmlLogger {
  template <class SM, class TEvent>
  void log_process_event(const TEvent&) {
    // handle plain event
  }
  template <class SM, class _, class TEvent>
  void log_process_event(const boost::sml::back::on_entry<_,TEvent>&) {
    // handle on_entry
  }
  template <class SM, class _, class TEvent>
  void log_process_event(const boost::sml::back::on_exit_,TEvent>&) {
    // handle on_exit
  }
// other methods
};

I didn;t test this code but it is to point out a possible solution to your problem.

cppden commented 3 years ago

the problem not in the logging per se but in the fact that all events will have on_entry/exit even if only one actually uses it. normally in C++ we get used to not pay for not needed things, right?

still when looking at the log I'd also prefer to not see 2 false prints for each event even when I didn't define on_entry/exit for them.

hope my point is clear. and more hope it is possible to fix or we're doomed? ;)