Added large amount of logging for debugging skill memory [to be removed!]

scenarios/SkillProviderTest/SkillProviderTest.scx

 <?xml version="1.0" encoding="utf-8"?>
-<scenario name="SkillProviderTest" creation="2022-06-02.15:33:15" globalConfigName="./config/global.cfg" package="RobotAPI" deploymentType="local" nodeName="NodeMain">
-	<application name="SkillProviderExample" instance="" package="RobotAPI" nodeName="" enabled="true" iceAutoRestart="false"/>
-	<application name="SkillsMemory" instance="" package="RobotAPI" nodeName="" enabled="true" iceAutoRestart="false"/>
-	<application name="MemoryNameSystem" instance="" package="RobotAPI" nodeName="" enabled="true" iceAutoRestart="false"/>
-	<application name="RemoteGuiProviderApp" instance="" package="ArmarXGui" nodeName="" enabled="true" iceAutoRestart="false"/>
-	<application name="ArVizStorage" instance="" package="RobotAPI" nodeName="" enabled="true" iceAutoRestart="false"/>
-	<application name="DebugObserver" instance="" package="ArmarXCore" nodeName="" enabled="true" iceAutoRestart="false"/>
+<scenario name="SkillProviderTest" creation="2022-06-02.15:33:15" globalConfigName="./config/global.cfg" package="RobotAPI" nodeName="NodeMain">
+	<application name="SkillProviderExample" instance="" package="RobotAPI" nodeName="" enabled="true"/>
+	<application name="SkillsMemory" instance="" package="RobotAPI" nodeName="" enabled="true"/>
+	<application name="MemoryNameSystem" instance="" package="RobotAPI" nodeName="" enabled="true"/>
+	<application name="RemoteGuiProviderApp" instance="" package="ArmarXGui" nodeName="" enabled="true"/>
+	<application name="ArVizStorage" instance="" package="RobotAPI" nodeName="" enabled="true"/>
+	<application name="DebugObserver" instance="" package="ArmarXCore" nodeName="" enabled="true"/>
 </scenario>
 

scenarios/SkillProviderTest/config/SkillProviderExample.cfg

@@ -200,6 +200,6 @@
 #  - Case sensitivity:   yes
 #  - Required:           no
 #  - Possible values: {Debug, Error, Fatal, Important, Info, Undefined, Verbose, Warning}
-# ArmarX.Verbosity = Info
+ArmarX.Verbosity = Debug
 
 

scenarios/SkillProviderTest/config/SkillsMemory.cfg

@@ -141,7 +141,7 @@
 #  - Case sensitivity:   yes
 #  - Required:           no
 #  - Possible values: {Debug, Error, Fatal, Important, Info, Undefined, Verbose, Warning}
-# ArmarX.SkillMemory.MinimumLoggingLevel = Undefined
+ArmarX.SkillMemory.MinimumLoggingLevel = Debug
 
 
 # ArmarX.SkillMemory.ObjectName:  Name of IceGrid well-known object
@@ -176,12 +176,60 @@
 # ArmarX.SkillMemory.mem.MemoryName = Skill
 
 
+# ArmarX.SkillMemory.mem.event.seg.CoreMaxHistorySize:  Maximal size of the SkillEvent entity histories (-1 for infinite).
+#  Attributes:
+#  - Default:            100
+#  - Case sensitivity:   yes
+#  - Required:           no
+ArmarX.SkillMemory.mem.event.seg.CoreMaxHistorySize = 2000
+
+
+# ArmarX.SkillMemory.mem.event.seg.CoreSegmentName:  Name of the SkillEvent core segment.
+#  Attributes:
+#  - Default:            SkillEvent
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.event.seg.CoreSegmentName = SkillEvent
+
+
+# ArmarX.SkillMemory.mem.executableskill.seg.CoreMaxHistorySize:  Maximal size of the ExecutableSkill entity histories (-1 for infinite).
+#  Attributes:
+#  - Default:            10
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.executableskill.seg.CoreMaxHistorySize = 10
+
+
+# ArmarX.SkillMemory.mem.executableskill.seg.CoreSegmentName:  Name of the ExecutableSkill core segment.
+#  Attributes:
+#  - Default:            ExecutableSkill
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.executableskill.seg.CoreSegmentName = ExecutableSkill
+
+
+# ArmarX.SkillMemory.mem.executionrequest.seg.CoreMaxHistorySize:  Maximal size of the SkillExecutionRequest entity histories (-1 for infinite).
+#  Attributes:
+#  - Default:            50
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.executionrequest.seg.CoreMaxHistorySize = 50
+
+
+# ArmarX.SkillMemory.mem.executionrequest.seg.CoreSegmentName:  Name of the SkillExecutionRequest core segment.
+#  Attributes:
+#  - Default:            SkillExecutionRequest
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.executionrequest.seg.CoreSegmentName = SkillExecutionRequest
+
+
 # ArmarX.SkillMemory.mem.ltm.configuration:  
 #  Attributes:
-#  - Default:            {"SnapshotFrequencyFilter": { "WaitingTimeInMs": 1000}, "PngConverter": {}}
+#  - Default:            { "SnapshotFrequencyFilter": {"WaitingTimeInMsForFilter" : 50}, "PngConverter": {}, "ExrConverter": {}}
 #  - Case sensitivity:   yes
 #  - Required:           no
-# ArmarX.SkillMemory.mem.ltm.configuration = {"SnapshotFrequencyFilter": { "WaitingTimeInMs": 1000}, "PngConverter": {}}
+# ArmarX.SkillMemory.mem.ltm.configuration = { "SnapshotFrequencyFilter": {"WaitingTimeInMsForFilter" : 50}, "PngConverter": {}, "ExrConverter": {}}
 
 
 # ArmarX.SkillMemory.mem.ltm.enabled:  
@@ -193,6 +241,87 @@
 # ArmarX.SkillMemory.mem.ltm.enabled = false
 
 
+# ArmarX.SkillMemory.mem.ltm.exportName:  
+#  Attributes:
+#  - Default:            MemoryExport
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.ltm.exportName = MemoryExport
+
+
+# ArmarX.SkillMemory.mem.ltm.exportPath:  
+#  Attributes:
+#  - Default:            ""
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.ltm.exportPath = ""
+
+
+# ArmarX.SkillMemory.mem.ltm.importOnStartUp:  
+#  Attributes:
+#  - Default:            false
+#  - Case sensitivity:   yes
+#  - Required:           no
+#  - Possible values: {0, 1, false, no, true, yes}
+# ArmarX.SkillMemory.mem.ltm.importOnStartUp = false
+
+
+# ArmarX.SkillMemory.mem.ltm.loadedCoreSegments:  
+#  Attributes:
+#  - Default:            Localization
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.ltm.loadedCoreSegments = Localization
+
+
+# ArmarX.SkillMemory.mem.ltm.maxAmountSnapshotsLoaded:  
+#  Attributes:
+#  - Default:            10
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.ltm.maxAmountSnapshotsLoaded = 10
+
+
+# ArmarX.SkillMemory.mem.ltm.storeFrequency:  
+#  Attributes:
+#  - Default:            10
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.ltm.storeFrequency = 10
+
+
+# ArmarX.SkillMemory.mem.statechartlistener.seg.CoreMaxHistorySize:  Maximal size of the Transitions entity histories (-1 for infinite).
+#  Attributes:
+#  - Default:            100
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.statechartlistener.seg.CoreMaxHistorySize = 100
+
+
+# ArmarX.SkillMemory.mem.statechartlistener.seg.CoreSegmentName:  Name of the Transitions core segment.
+#  Attributes:
+#  - Default:            Transitions
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.statechartlistener.seg.CoreSegmentName = Transitions
+
+
+# ArmarX.SkillMemory.mem.statechartlistener.seg.ProviderMaxHistorySize:  Maximal size of the StatechartListener entity histories (-1 for infinite).
+#  Attributes:
+#  - Default:            100
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.statechartlistener.seg.ProviderMaxHistorySize = 100
+
+
+# ArmarX.SkillMemory.mem.statechartlistener.seg.ProviderSegmentName:  Name of the StatechartListener provider segment.
+#  Attributes:
+#  - Default:            StatechartListener
+#  - Case sensitivity:   yes
+#  - Required:           no
+# ArmarX.SkillMemory.mem.statechartlistener.seg.ProviderSegmentName = StatechartListener
+
+
 # ArmarX.SkillMemory.mns.MemoryNameSystemEnabled:  Whether to use (and depend on) the Memory Name System (MNS).
 # Set to false to use this memory as a stand-alone.
 #  Attributes:
@@ -259,6 +388,6 @@
 #  - Case sensitivity:   yes
 #  - Required:           no
 #  - Possible values: {Debug, Error, Fatal, Important, Info, Undefined, Verbose, Warning}
-# ArmarX.Verbosity = Info
+ArmarX.Verbosity = Debug
 
 

source/RobotAPI/components/armem/server/SkillsMemory/SkillsMemory.cpp

@@ -202,7 +202,7 @@ namespace armarx
         auto op = this->skillEventCoreSegment.getSkillStatusUpdate(eid);
         if (op.has_value())
         {
-            ARMARX_DEBUG << "END getSkillExecutionStatus2";
+            ARMARX_DEBUG << "END getSkillExecutionStatus2 " << executionId.executionStartedTime << " " << executionId.skillId.providerId.providerName << " " << executionId.skillId.skillName << " " << executionId.executorName << " " << executionId.uuid;
             return op->toManagerIce();
         }
         ARMARX_DEBUG << "END getSkillExecutionStatus ";

source/RobotAPI/libraries/skills/core/Skill.cpp

@@ -346,10 +346,16 @@ namespace armarx
                 // skill already got stopped. Ignore
                 return;
             }
+
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF subskillsMutex " << __LINE__;
             std::scoped_lock l(subskillsMutex);
+            ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
+            
+            
             stopped = true;
             _onStopRequested();
             onStopRequested();
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF subskillsMutex " << __LINE__;
         }
 
         void
@@ -361,10 +367,12 @@ namespace armarx
                 return;
             }
 
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF subskillsMutex " << __LINE__;
             std::scoped_lock l(subskillsMutex);
             timeoutReached = true;
             _onTimeoutReached();
             onTimeoutReached();
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF subskillsMutex " << __LINE__;
         }
 
         bool

source/RobotAPI/libraries/skills/core/SkillProxy.cpp

@@ -79,6 +79,7 @@ namespace armarx
         SkillProxy::join(const SkillExecutionID& executionId) const
         {
             ARMARX_CHECK_NOT_NULL(manager);
+            ARMARX_DEBUG << "SkillProxy::join (1) ";
             auto s = this->manager->getSkillExecutionStatus(executionId.toManagerIce());
 
             while (s)
@@ -91,6 +92,8 @@ namespace armarx
                 }
 
                 std::this_thread::sleep_for(std::chrono::milliseconds(50));
+                ARMARX_DEBUG << "SkillProxy::join (2) " << "The subskill " << executionId.skillId.toString() << " has not been terminated yet. Continuing querying for updates. The latest state was: " << int(statusUpdate.status);
+
                 s = this->manager->getSkillExecutionStatus(executionId.toManagerIce());
             }
 

source/RobotAPI/libraries/skills/manager/SkillManagerComponentPlugin.cpp

@@ -406,7 +406,9 @@ namespace armarx::plugins
     {
         std::map<skills::SkillID, skills::SkillDescription> ret;
 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
         std::scoped_lock l(skillProviderMapMutex);
+        ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
         for (auto it = skillProviderMap.cbegin(); it != skillProviderMap.cend();)
         {
             const auto& providerId = it->first;
@@ -422,7 +424,9 @@ namespace armarx::plugins
 
             try
             {
+                ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
                 skills::provider::dto::SkillDescriptionMap m = provider->getSkillDescriptions();
+                ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
 
                 for (const auto& [provider_skillId_ice, skillDescription_ice] : m)
                 {
@@ -448,6 +452,8 @@ namespace armarx::plugins
     SkillManagerComponentPlugin::getSkillExecutionStatus(
         const skills::SkillExecutionID& executionId)
     {
+        ARMARX_DEBUG << "SkillManagerComponentPlugin::getSkillExecutionStatus";
+
         ARMARX_CHECK(executionId.skillId.isFullySpecified())
             << "Got: " << executionId.skillId.toString();
 
@@ -473,6 +479,7 @@ namespace armarx::plugins
 
             try
             {
+                ARMARX_DEBUG << "SkillManagerComponentPlugin::getSkillExecutionStatus2";
                 auto async = provider->begin_getSkillExecutionStatus(executionId.toProviderIce());
                 l.unlock(); // allow parallel e.g. stopping. Otherwise the manager would lock himself in nested calls
                 auto provider_statusUpdate_ice = provider->end_getSkillExecutionStatus(async);
@@ -521,6 +528,8 @@ namespace armarx::plugins
 
             try
             {
+                ARMARX_DEBUG << "SkillManagerComponentPlugin::getSkillExecutionStatuses::getSkillExecutionStatuses";
+
                 auto m = provider->getSkillExecutionStatuses();
 
                 for (const auto& [provider_executionId_ice, provider_statusUpdate_ice] : m)
@@ -701,6 +710,8 @@ namespace armarx
         const skills::manager::dto::SkillExecutionID& executionId,
         const Ice::Current& current)
     {
+        ARMARX_DEBUG << "SkillManagerComponentPluginUser::getSkillExecutionStatus";
+
         auto e = skills::SkillExecutionID::FromIce(executionId);
         auto o = this->plugin->getSkillExecutionStatus(e);
         if (o.has_value())

source/RobotAPI/libraries/skills/provider/SkillProviderComponentPlugin.cpp

@@ -69,6 +69,7 @@ namespace armarx::plugins
         const skills::ProviderID providerId({componentName});
 
         // lock skills map
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE UNIQUE LOCK OF FAC " << __LINE__;
         const std::unique_lock l(skillFactoriesMutex);
         auto skillId = fac->createSkillDescription(providerId).skillId;
 
@@ -90,6 +91,7 @@ namespace armarx::plugins
         //            s.first->second.skill->manager = manager;
         //            s.first->second.skill->providerName = providerName;
         //        }
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE UNIQUE LOCK OF FAC " << __LINE__;
     }
 
     skills::SkillBlueprint*
@@ -121,6 +123,7 @@ namespace armarx::plugins
     {
         ARMARX_CHECK(execId.skillId.isSkillSpecified());
 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         const std::shared_lock l(skillExecutionsMutex);
         if (skillExecutions.find(execId) == skillExecutions.end())
         {
@@ -129,7 +132,10 @@ namespace armarx::plugins
             return std::nullopt;
         }
 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
         std::scoped_lock l2{skillExecutions.at(execId).skillStatusesMutex};
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
+         ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         return skillExecutions.at(execId).statusUpdate;
     }
 
@@ -137,13 +143,17 @@ namespace armarx::plugins
     SkillProviderComponentPlugin::getSkillExecutionStatuses() const
     {
         std::map<skills::SkillExecutionID, skills::SkillStatusUpdate> skillUpdates;
-
+ 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         const std::shared_lock l(skillExecutionsMutex);
         for (const auto& [key, impl] : skillExecutions)
         {
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
             const std::scoped_lock l2(impl.skillStatusesMutex);
             skillUpdates.insert({key, impl.statusUpdate});
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
         }
+         ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         return skillUpdates;
     }
 
@@ -176,11 +186,15 @@ namespace armarx::plugins
     SkillProviderComponentPlugin::getSkillDescriptions() const
     {
         std::map<skills::SkillID, skills::SkillDescription> skillDesciptions;
+        ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
         const std::shared_lock l(skillFactoriesMutex);
+        ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
         for (const auto& [key, fac] : skillFactories)
         {
             ARMARX_CHECK(key.isFullySpecified());
+            ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
             skillDesciptions.insert({key, fac->createSkillDescription(*key.providerId)});
+            ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
         }
         return skillDesciptions;
     }
@@ -201,12 +215,14 @@ namespace armarx::plugins
 
         skills::detail::SkillRuntime* wrapper;
         {
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE UNIQUE LOCK OF FAC " << __LINE__;
             auto l1 = std::unique_lock{skillFactoriesMutex};
 
             const auto& fac = getSkillFactory(executionId.skillId);
             ARMARX_CHECK(fac) << "Could not find a factory for skill " << executionId.skillId;
 
             {
+                 ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE UNIQUE LOCK OF skillExecutionsMutex " << __LINE__;
                 const std::unique_lock l2{skillExecutionsMutex};
                 auto it =
                     skillExecutions.emplace(std::piecewise_construct,
@@ -217,6 +233,7 @@ namespace armarx::plugins
                                                             executionRequest.callbackInterface));
                 wrapper = &it.first->second;
                 // ATTENTION NOT DEFINED BEHAVIOR
+                 ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE UNIQUE LOCK OF skillExecutionsMutex " << __LINE__;
             }
 
             // async start execution. But we wait for the execution to finish at the end of this method
@@ -236,6 +253,7 @@ namespace armarx::plugins
                     }
                 });
         } // release lock. We don't know how long the skill needs to finish and we have to release the lock for being able to abort the execution
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE UNIQUE LOCK OF FAC " << __LINE__;
 
         if (wrapper && wrapper->execution.joinable())
         {
@@ -262,23 +280,36 @@ namespace armarx::plugins
 
         skills::detail::SkillRuntime* wrapper;
         {
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE UNIQUE LOCK OF FAC " << __LINE__;
             auto l1 = std::unique_lock{skillFactoriesMutex};
 
+
+ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
+
+
             const auto& fac = getSkillFactory(executionRequest.skillId);
+            ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
             ARMARX_CHECK(fac) << "Could not find a factory for skill " << executionRequest.skillId;
 
             {
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE UNIQUE LOCK OF skillExecutionsMutex " << __LINE__;
                 const std::unique_lock l2{skillExecutionsMutex};
 
+ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
+
                 executionId = skills::SkillExecutionID{executionRequest.skillId,
                                              executionRequest.executorName,
                                              armarx::core::time::DateTime::Now()};
 
+ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
+
                 if (skillExecutions.count(executionId) > 0)
                 {
                     ARMARX_ERROR << "SkillsExecutionID already exists! This is undefined behaviour and should not occur!";
                 }
 
+ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
+
                 auto it =
                     skillExecutions.emplace(std::piecewise_construct,
                                             std::make_tuple(executionId),
@@ -288,6 +319,8 @@ namespace armarx::plugins
                                                             executionRequest.callbackInterface));
                 wrapper = &it.first->second;
                 // ATTENTION NOT DEFINED BEHAVIOR
+
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE UNIQUE LOCK OF skillExecutionsMutex " << __LINE__;
             }
 
             wrapper->execution = std::thread(
@@ -304,19 +337,28 @@ namespace armarx::plugins
                     }
                 });
         }
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE UNIQUE LOCK OF FAC " << __LINE__;
 
         // wait until skill is constructed. This assures, that a status update exists.
         while (true)
         {
             {
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
                 std::scoped_lock l(wrapper->skillStatusesMutex);
 
                 if (wrapper->statusUpdate.hasBeenConstructed())
                 {
+                    ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
                     break;
                 }
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
             }
 
+            
+
+            ARMARX_DEBUG << "SkillProviderComponentPlugin::executeSkillAsync " << "The subskill " << executionId.skillId.toString() << " has not been terminated yet. Continuing querying for updates. The latest state was: " << int(wrapper->statusUpdate.status);
+
+
             std::this_thread::sleep_for(std::chrono::milliseconds(20));
         }
 
@@ -329,6 +371,7 @@ namespace armarx::plugins
     {
         ARMARX_CHECK(executionId.skillId.isFullySpecified());
 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         std::shared_lock l{skillExecutionsMutex};
         auto it = skillExecutions.find(executionId);
         if (it == skillExecutions.end())
@@ -338,6 +381,7 @@ namespace armarx::plugins
             return false;
         }
 
+ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
         std::scoped_lock l2{it->second.skillStatusesMutex};
         if (it->second.statusUpdate.status != skills::SkillStatus::Preparing)
         {
@@ -347,6 +391,8 @@ namespace armarx::plugins
         }
 
         it->second.updateSkillParameters(input);
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         return true;
     }
 
@@ -355,12 +401,15 @@ namespace armarx::plugins
     {
         ARMARX_CHECK(executionId.skillId.isFullySpecified());
 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         std::shared_lock l(skillExecutionsMutex);
+        ARMARX_INFO << __PRETTY_FUNCTION__ << " " << __LINE__;
         auto it = skillExecutions.find(executionId);
         if (it == skillExecutions.end())
         {
             ARMARX_INFO << "No acive execution for skill '" + executionId.skillId.toString() +
                                "' found! Ignoring abortSkill request.";
+            ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
             return false;
         }
 
@@ -370,16 +419,23 @@ namespace armarx::plugins
         while (true)
         {
             {
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
                 std::scoped_lock l(runtime.skillStatusesMutex);
                 auto status = runtime.statusUpdate;
 
                 if (status.hasBeenTerminated())
                 {
+                    ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
                     break;
                 }
+
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SCOPED LOCK OF skillStatusesMutex " << __LINE__;
             }
+            ARMARX_DEBUG << "SkillProviderComponentPlugin::abortSkill " << "The subskill " << executionId.skillId.toString() << " has not been terminated yet. Continuing querying for updates. The latest state was: " << int(runtime.statusUpdate.status);
+
             std::this_thread::sleep_for(std::chrono::milliseconds(20));
-        }
+        } 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
 
         return true;
     }
@@ -389,6 +445,7 @@ namespace armarx::plugins
     {
         ARMARX_CHECK(executionId.skillId.isFullySpecified());
 
+        ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         std::shared_lock l(skillExecutionsMutex);
         auto it = skillExecutions.find(executionId);
         if (it == skillExecutions.end())
@@ -399,6 +456,7 @@ namespace armarx::plugins
         }
 
         it->second.stopSkill();
+         ARMARX_INFO << __PRETTY_FUNCTION__ << "RELLEASE SHARED LOCK OF skillExecutionsMutex " << __LINE__;
         return true;
     }
 
@@ -441,6 +499,8 @@ namespace armarx
         const skills::provider::dto::SkillExecutionID& executionId,
         const Ice::Current& /*unused*/)
     {
+        ARMARX_DEBUG << "SkillProviderComponentPluginUser::getSkillExecutionStatus";
+
         auto execId = skills::SkillExecutionID::FromIce(
             executionId, skills::ProviderID{.providerName = getName()});
         auto o = plugin->getSkillExecutionStatus(execId);

source/RobotAPI/libraries/skills/provider/detail/SkillImplementationWrapper.cpp

@@ -73,6 +73,7 @@ namespace armarx
             auto updateStatus =
                 [&](const SkillStatus status, const aron::data::DictPtr& data = nullptr)
             {
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 std::unique_lock l(skillStatusesMutex);
                 statusUpdate.status = status;
                 statusUpdate.result = data;
@@ -87,6 +88,7 @@ namespace armarx
                     auto pid = providerId.toCallbackIce();
                     callback_interface->updateStatusForSkill(statusUpdate.toProviderIce(), pid);
                 }
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillStatusesMutex " << __LINE__;
             };
 
             auto createErrorMessageData = [](const std::string& message)
@@ -98,6 +100,7 @@ namespace armarx
             };
 
             {
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 std::unique_lock l(skillStatusesMutex);
 
                 // ---------------------------------------------------------------------------------
@@ -112,6 +115,7 @@ namespace armarx
                                      << "' has been scheduled > 1s ago. The execution should start "
                                         "much faster! Continue, but this is bad behavior..";
                 }
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillStatusesMutex " << __LINE__;
             }
 
             // -------------------------------------------------------------------------------------
@@ -134,6 +138,7 @@ namespace armarx
             {
                 updateStatus(SkillStatus::Aborted, createErrorMessageData(message));
 
+ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 std::unique_lock l(skillStatusesMutex);
                 auto terminated = TerminatedSkillStatusUpdate{
                     {.executionId = statusUpdate.executionId,
@@ -141,6 +146,7 @@ namespace armarx
                      .callbackInterface = statusUpdate.callbackInterface,
                      .result = statusUpdate.result}};
                 terminated.status = TerminatedSkillStatus::Aborted;
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 return terminated;
             };
 
@@ -149,6 +155,7 @@ namespace armarx
             {
                 updateStatus(SkillStatus::Failed, createErrorMessageData(message));
 
+ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 std::unique_lock l(skillStatusesMutex);
                 auto terminated = TerminatedSkillStatusUpdate{
                     {.executionId = statusUpdate.executionId,
@@ -156,6 +163,7 @@ namespace armarx
                      .callbackInterface = statusUpdate.callbackInterface,
                      .result = statusUpdate.result}};
                 terminated.status = TerminatedSkillStatus::Failed;
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "RELEASE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 return terminated;
             };
 
@@ -345,6 +353,7 @@ namespace armarx
                 updateStatus(SkillStatus::Succeeded, mainRet.data);
 
                 // return result of main method
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 std::unique_lock l(skillStatusesMutex);
                 TerminatedSkillStatusUpdate ret{
                     {.executionId = statusUpdate.executionId,
@@ -352,6 +361,7 @@ namespace armarx
                      .callbackInterface = statusUpdate.callbackInterface}};
                 ret.result = mainRet.data;
                 ret.status = TerminatedSkillStatus::Succeeded;
+                ARMARX_INFO << __PRETTY_FUNCTION__ << "TAKE SHARED LOCK OF skillStatusesMutex " << __LINE__;
                 return ret;
             }
         }

source/RobotAPI/libraries/skills_gui/memory/SkillManagerWrapper.cpp

@@ -21,19 +21,24 @@ namespace armarx::skills::gui
 
         try
         {
+        ARMARX_INFO << __LINE__;
             std::scoped_lock l(mutex_memory);
 
+        ARMARX_INFO << __LINE__;
             // we return this map
             StatusMap statusMap;
 
+        ARMARX_INFO << __LINE__;
             auto currentManagerStatuses = memory->ice_invocationTimeout(5000)->getSkillExecutionStatuses();
 
+        ARMARX_INFO << __LINE__;
             // iterate over raw data and convert to common types
             for (const auto& [k, v] : currentManagerStatuses)
             {
                 auto executionId = skills::SkillExecutionID::FromIce(k);
                 auto statusUpdate = skills::SkillStatusUpdate::FromIce(v);
 
+        ARMARX_INFO << __LINE__;
                 // update maps
                 statusMap[executionId] = statusUpdate;
             }
@@ -132,23 +137,31 @@ namespace armarx::skills::gui
 
         try
         {
+        ARMARX_INFO << __LINE__;
             std::scoped_lock l(mutex_memory);
 
+        ARMARX_INFO << __LINE__;
             SkillMap skills;
 
+        ARMARX_INFO << __LINE__;
             auto managerSkills = memory->ice_invocationTimeout(5000)->getSkillDescriptions();
 
+        ARMARX_INFO << __LINE__;
             for (const auto& [sid, desc] : managerSkills)
             {
+        ARMARX_INFO << __LINE__;
                 auto description = skills::SkillDescription::FromIce(desc);
                 auto skillId = skills::SkillID::FromIce(sid);
                 auto providerId = skillId.providerId.value_or(
                     skills::ProviderID{.providerName = "UNKNOWN PROVIDER NAME"});
 
+        ARMARX_INFO << __LINE__;
                 ARMARX_CHECK(skillId.isFullySpecified());
 
+        ARMARX_INFO << __LINE__;
                 auto& providedSkillsMap = skills[providerId]; // create new if not existing
                 providedSkillsMap.insert({skillId, description});
+        ARMARX_INFO << __LINE__;
             }
 
             return skills;
@@ -228,8 +241,11 @@ namespace armarx::skills::gui
     {
         std::scoped_lock l(mutex_snapshot);
 
+        ARMARX_INFO << __LINE__;
         snapshot.statuses = fetchExecutionsFromMemory();
+        ARMARX_INFO << __LINE__;
         snapshot.skills = fetchSkillsFromMemory();
+        ARMARX_INFO << __LINE__;
 
         // notify registered widgets of update
         emit updateAvailable(filterUpdate(snapshot));