Mercurial > hg > orthanc-stone

changeset 973:38409549db43 toa2019082903

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
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)
author Benjamin Golinvaux <bgo@osimis.io>
date Thu, 29 Aug 2019 18:07:55 +0200
parents fdf8b013f228
children e4b028c1ede1
files Framework/Loaders/LoaderStateMachine.cpp Framework/Loaders/LoaderStateMachine.h Framework/Messages/ICallable.h Framework/Messages/IObservable.cpp Framework/Messages/IObserver.h Framework/Oracle/WebAssemblyOracle.cpp
diffstat 6 files changed, 98 insertions(+), 61 deletions(-) [+]
line wrap: on
line diff
--- 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 <Core/OrthancException.h>
 
-#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<OracleCommandWithPayload> 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 <typename T>
   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<LoaderStateMachine, OrthancRestApiCommand::SuccessMessage>
       (*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)
   {
--- 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
     {
--- 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 <Core/Logging.h>
+
 #include <boost/noncopyable.hpp>
 
+#include <string>
+
 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)
--- 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 <Core/Logging.h>
 #include <Core/OrthancException.h>
 
 #include <cassert>
--- 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 <Core/Toolbox.h>
+
 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_;
--- 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<IOracleCommand>  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<FetchContext> context(reinterpret_cast<FetchContext*>(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<OrthancRestApiCommand>(), headers, answer);
+              (context->GetTypedCommand<OrthancRestApiCommand>(), headers, answer);
               context->EmitMessage(message);
               break;
             }
-            
+
             case IOracleCommand::Type_GetOrthancImage:
             {
               context->GetTypedCommand<GetOrthancImageCommand>().ProcessHttpAnswer
-                (context->GetEmitter(), context->GetReceiver(), answer, headers);
+              (context->GetEmitter(), context->GetReceiver(), answer, headers);
               break;
             }
-          
+
             case IOracleCommand::Type_GetOrthancWebViewerJpeg:
             {
               context->GetTypedCommand<GetOrthancWebViewerJpegCommand>().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();
+        }
       }
     }