# HG changeset patch # User Benjamin Golinvaux # Date 1567094875 -7200 # Node ID 38409549db4392c2338e145251a99460e1bdbe58 # Parent fdf8b013f228f2973d499a35e88b07e0dc5bb969 Log with addresses + added fingerprint mechanism to avoid calling zombie objects where: - a message is sent with a receiver - the receiver dies - another receiver with the SAME address is created - the message reply is executed --> execution on the wrong object! (since their "identity" is their address. The fix is to identify them with an UUID stored at creation time) diff -r fdf8b013f228 -r 38409549db43 Framework/Loaders/LoaderStateMachine.cpp --- a/Framework/Loaders/LoaderStateMachine.cpp Thu Aug 29 13:12:03 2019 +0200 +++ b/Framework/Loaders/LoaderStateMachine.cpp Thu Aug 29 18:07:55 2019 +0200 @@ -23,11 +23,6 @@ #include -#if 0 -extern bool logbgo233; -extern bool logbgo115; -#endif - namespace OrthancStone { void LoaderStateMachine::State::Handle(const OrthancRestApiCommand::SuccessMessage& message) @@ -50,12 +45,7 @@ void LoaderStateMachine::Schedule(OracleCommandWithPayload* command) { -#if 0 - if (logbgo233) { - if (logbgo115) - LOG(TRACE) << " LoaderStateMachine::Schedule()"; - } -#endif + LOG(TRACE) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::Schedule()"; std::auto_ptr protection(command); @@ -69,13 +59,6 @@ throw Orthanc::OrthancException(Orthanc::ErrorCode_ParameterOutOfRange, "The payload must contain the next state"); } - -#if 0 - if (logbgo233) { - if (logbgo115) - LOG(TRACE) << " * LoaderStateMachine::Schedule(): adding command with addr: " << std::hex << protection.get() << std::dec << " pendingCommands_.size() is now : " << pendingCommands_.size()+1; - } -#endif pendingCommands_.push_back(protection.release()); Step(); @@ -84,6 +67,8 @@ void LoaderStateMachine::Start() { + LOG(TRACE) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::Start()"; + if (active_) { LOG(TRACE) << "LoaderStateMachine::Start() called while active_ is true"; @@ -101,22 +86,16 @@ void LoaderStateMachine::Step() { -#if 0 - if (logbgo115) - LOG(TRACE) << " LoaderStateMachine::Step(): pendingCommands_.size() = " << pendingCommands_.size(); -#endif if (!pendingCommands_.empty() && activeCommands_ < simultaneousDownloads_) { IOracleCommand* nextCommand = pendingCommands_.front(); -#if 0 - if (logbgo233) { - if (logbgo115) - LOG(TRACE) << " * LoaderStateMachine::Step(): activeCommands_ (" << activeCommands_ << ") < simultaneousDownloads_ (" << simultaneousDownloads_ << ") --> will Schedule command addr " << std::hex << nextCommand << std::dec; - } -#endif + LOG(TRACE) << " LoaderStateMachine(" << std::hex << this << std::dec << + ")::Step(): activeCommands_ (" << activeCommands_ << + ") < simultaneousDownloads_ (" << simultaneousDownloads_ << + ") --> will Schedule command addr " << std::hex << nextCommand << std::dec; oracle_.Schedule(*this, nextCommand); pendingCommands_.pop_front(); @@ -125,18 +104,17 @@ } else { -#if 0 - if (logbgo233) { - if (logbgo115) - LOG(TRACE) << " * pendingCommands_.size() == " << pendingCommands_.size() << " LoaderStateMachine::Step(): activeCommands_ (" << activeCommands_ << ") >= simultaneousDownloads_ (" << simultaneousDownloads_ << ") --> will NOT Schedule anything"; - } -#endif + LOG(TRACE) << " LoaderStateMachine(" << std::hex << this << std::dec << + ")::Step(): activeCommands_ (" << activeCommands_ << + ") < simultaneousDownloads_ (" << simultaneousDownloads_ << + ") --> will NOT Schedule command"; } } void LoaderStateMachine::Clear() { + LOG(TRACE) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::Clear()"; for (PendingCommands::iterator it = pendingCommands_.begin(); it != pendingCommands_.end(); ++it) { @@ -158,7 +136,10 @@ template void LoaderStateMachine::HandleSuccessMessage(const T& message) { - assert(activeCommands_ > 0); + LOG(TRACE) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::HandleSuccessMessage()"; + if (activeCommands_ <= 0) { + LOG(ERROR) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::HandleSuccessMessage : activeCommands_ should be > 0 but is: " << activeCommands_; + } activeCommands_--; try @@ -183,6 +164,8 @@ simultaneousDownloads_(4), activeCommands_(0) { + LOG(TRACE) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::LoaderStateMachine()"; + oracleObservable.RegisterObserverCallback( new Callable (*this, &LoaderStateMachine::HandleSuccessMessage)); @@ -200,6 +183,11 @@ (*this, &LoaderStateMachine::HandleExceptionMessage)); } + LoaderStateMachine::~LoaderStateMachine() + { + LOG(TRACE) << "LoaderStateMachine(" << std::hex << this << std::dec << ")::~LoaderStateMachine()"; + Clear(); + } void LoaderStateMachine::SetSimultaneousDownloads(unsigned int count) { diff -r fdf8b013f228 -r 38409549db43 Framework/Loaders/LoaderStateMachine.h --- a/Framework/Loaders/LoaderStateMachine.h Thu Aug 29 13:12:03 2019 +0200 +++ b/Framework/Loaders/LoaderStateMachine.h Thu Aug 29 18:07:55 2019 +0200 @@ -104,10 +104,7 @@ LoaderStateMachine(IOracle& oracle, IObservable& oracleObservable); - virtual ~LoaderStateMachine() - { - Clear(); - } + virtual ~LoaderStateMachine(); bool IsActive() const { diff -r fdf8b013f228 -r 38409549db43 Framework/Messages/ICallable.h --- a/Framework/Messages/ICallable.h Thu Aug 29 13:12:03 2019 +0200 +++ b/Framework/Messages/ICallable.h Thu Aug 29 18:07:55 2019 +0200 @@ -23,8 +23,12 @@ #include "IMessage.h" +#include + #include +#include + namespace OrthancStone { class IObserver; @@ -61,18 +65,32 @@ TObserver& observer_; MemberFunction function_; + std::string observerFingerprint_; public: Callable(TObserver& observer, MemberFunction function) : observer_(observer), + observerFingerprint_(observer.GetFingerprint()), function_(function) { } void ApplyInternal(const TMessage& message) { +#if 0 (observer_.*function_) (message); +#else + if (observerFingerprint_ != observer_.GetFingerprint()) + { + LOG(WARNING) << "The observer at address " << std::hex << &observer_ << std::dec << ") has a different fingerprint than the one recorded at callback registration time. Callback will NOT be sent!"; + LOG(WARNING) << " recorded fingerprint = " << observerFingerprint_ << " current fingerprint = " << observer_.GetFingerprint(); + } + else + { + (observer_.*function_) (message); + } +#endif } virtual void Apply(const IMessage& message) diff -r fdf8b013f228 -r 38409549db43 Framework/Messages/IObservable.cpp --- a/Framework/Messages/IObservable.cpp Thu Aug 29 13:12:03 2019 +0200 +++ b/Framework/Messages/IObservable.cpp Thu Aug 29 18:07:55 2019 +0200 @@ -21,6 +21,7 @@ #include "IObservable.h" +#include #include #include diff -r fdf8b013f228 -r 38409549db43 Framework/Messages/IObserver.h --- a/Framework/Messages/IObserver.h Thu Aug 29 13:12:03 2019 +0200 +++ b/Framework/Messages/IObserver.h Thu Aug 29 18:07:55 2019 +0200 @@ -24,25 +24,37 @@ #include "MessageBroker.h" #include "IMessage.h" +#include + namespace OrthancStone { class IObserver : public boost::noncopyable { private: MessageBroker& broker_; - + // the following is a UUID that is used to disambiguate different observers + // that may have the same address + std::string fingerprint_; public: - IObserver(MessageBroker& broker) : - broker_(broker) + IObserver(MessageBroker& broker) + : broker_(broker) + , fingerprint_(Orthanc::Toolbox::GenerateUuid()) { + LOG(TRACE) << "IObserver(" << std::hex << this << std::dec << ")::IObserver : fingerprint_ == " << fingerprint_; broker_.Register(*this); } virtual ~IObserver() { + LOG(TRACE) << "IObserver(" << std::hex << this << std::dec << ")::~IObserver : fingerprint_ == " << fingerprint_; broker_.Unregister(*this); } + const std::string& GetFingerprint() const + { + return fingerprint_; + } + MessageBroker& GetBroker() const { return broker_; diff -r fdf8b013f228 -r 38409549db43 Framework/Oracle/WebAssemblyOracle.cpp --- a/Framework/Oracle/WebAssemblyOracle.cpp Thu Aug 29 13:12:03 2019 +0200 +++ b/Framework/Oracle/WebAssemblyOracle.cpp Thu Aug 29 18:07:55 2019 +0200 @@ -99,6 +99,7 @@ private: Emitter emitter_; const IObserver& receiver_; + std::string receiverFingerprint_; std::auto_ptr command_; std::string expectedContentType_; @@ -109,6 +110,7 @@ const std::string& expectedContentType) : emitter_(oracle), receiver_(receiver), + receiverFingerprint_(receiver.GetFingerprint()), command_(command), expectedContentType_(expectedContentType) { @@ -118,6 +120,16 @@ } } + bool IsFingerprintOK() const + { + bool ok = receiverFingerprint_ == receiver_.GetFingerprint(); + if (!ok) + { + LOG(TRACE) << "IsFingerprintOK returned false. receiverFingerprint_ = " << receiverFingerprint_ << " | receiver_(" << std::hex << (&receiver_) << std::dec << ").GetFingerprint() = " << receiver_.GetFingerprint(); + } + return ok; + } + const std::string& GetExpectedContentType() const { return expectedContentType_; @@ -195,6 +207,7 @@ **/ std::auto_ptr context(reinterpret_cast(fetch->userData)); + if (fetch->userData == NULL) { LOG(ERROR) << "WebAssemblyOracle::FetchContext::SuccessCallback fetch->userData is NULL!!!!!!!"; @@ -234,49 +247,57 @@ /** * Secondly, use the retrieved data. + * We only use the receiver if its fingerprint matches the one stored + * at command creation. **/ - - try + if (!context->IsFingerprintOK()) { - if (context.get() == NULL) + LOG(WARNING) << "FetchContext::SuccessCallback -- the initial request initiator has been destroyed. Response will be discarded."; + } + else + { + try { - throw Orthanc::OrthancException(Orthanc::ErrorCode_NullPointer); - } - else - { - switch (context->GetCommand().GetType()) + if (context.get() == NULL) { + throw Orthanc::OrthancException(Orthanc::ErrorCode_NullPointer); + } + else + { + switch (context->GetCommand().GetType()) + { case IOracleCommand::Type_OrthancRestApi: { OrthancRestApiCommand::SuccessMessage message - (context->GetTypedCommand(), headers, answer); + (context->GetTypedCommand(), headers, answer); context->EmitMessage(message); break; } - + case IOracleCommand::Type_GetOrthancImage: { context->GetTypedCommand().ProcessHttpAnswer - (context->GetEmitter(), context->GetReceiver(), answer, headers); + (context->GetEmitter(), context->GetReceiver(), answer, headers); break; } - + case IOracleCommand::Type_GetOrthancWebViewerJpeg: { context->GetTypedCommand().ProcessHttpAnswer - (context->GetEmitter(), context->GetReceiver(), answer); + (context->GetEmitter(), context->GetReceiver(), answer); break; } - + default: LOG(ERROR) << "Command type not implemented by the WebAssembly Oracle: " - << context->GetCommand().GetType(); + << context->GetCommand().GetType(); + } } } - } - catch (Orthanc::OrthancException& e) - { - LOG(ERROR) << "Error while processing a fetch answer in the oracle: " << e.What(); + catch (Orthanc::OrthancException& e) + { + LOG(ERROR) << "Error while processing a fetch answer in the oracle: " << e.What(); + } } }