fix data race in SqliteLogger::callback

src/loggers/bt_sqlite_logger.cpp

@@ -168,28 +168,8 @@ void SqliteLogger::callback(Duration timestamp, const TreeNode& node,
 {
   using namespace std::chrono;
   const int64_t tm_usec = int64_t(duration_cast<microseconds>(timestamp).count());
-  monotonic_timestamp_ = std::max(monotonic_timestamp_ + 1, tm_usec);
-
-  long elapsed_time = 0;
-
-  if(prev_status == NodeStatus::IDLE && status == NodeStatus::RUNNING)
-  {
-    starting_time_[&node] = monotonic_timestamp_;
-  }
-
-  if(prev_status == NodeStatus::RUNNING && status != NodeStatus::RUNNING)
-  {
-    elapsed_time = monotonic_timestamp_;
-    auto it = starting_time_.find(&node);
-    if(it != starting_time_.end())
-    {
-      elapsed_time -= it->second;
-    }
-  }
 
   Transition trans;
-  trans.timestamp = monotonic_timestamp_;
-  trans.duration = elapsed_time;
   trans.node_uid = node.UID();
   trans.status = status;
 
@@ -199,7 +179,31 @@ void SqliteLogger::callback(Duration timestamp, const TreeNode& node,
   }
 
   {
+    // This callback may be invoked concurrently from multiple threads
+    // (e.g. two ThreadedAction completing at the same time), so
+    // monotonic_timestamp_ and starting_time_ must be guarded too.
     const std::scoped_lock lk(queue_mutex_);
+    monotonic_timestamp_ = std::max(monotonic_timestamp_ + 1, tm_usec);
+
+    long elapsed_time = 0;
+
+    if(prev_status == NodeStatus::IDLE && status == NodeStatus::RUNNING)
+    {
+      starting_time_[&node] = monotonic_timestamp_;
+    }
+
+    if(prev_status == NodeStatus::RUNNING && status != NodeStatus::RUNNING)
+    {
+      elapsed_time = monotonic_timestamp_;
+      auto it = starting_time_.find(&node);
+      if(it != starting_time_.end())
+      {
+        elapsed_time -= it->second;
+      }
+    }
+
+    trans.timestamp = monotonic_timestamp_;
+    trans.duration = elapsed_time;
     transitions_queue_.push_back(trans);
   }
   queue_cv_.notify_one();

tests/gtest_loggers.cpp

@@ -22,6 +22,7 @@
 #include <cstring>
 #include <filesystem>
 #include <fstream>
+#include <thread>
 
 #include <gtest/gtest.h>
 
@@ -527,6 +528,59 @@ TEST_F(LoggerTest, SqliteLogger_MultipleTicks)
   ASSERT_TRUE(std::filesystem::exists(filepath));
 }
 
+// A ThreadedAction completes on its own worker thread, so the logger callback
+// of each instance runs concurrently with the ones invoked by the main thread.
+namespace
+{
+class ConcurrentAction : public BT::ThreadedAction
+{
+public:
+  ConcurrentAction(const std::string& name, const BT::NodeConfig& config)
+    : BT::ThreadedAction(name, config)
+  {}
+
+  static BT::PortsList providedPorts()
+  {
+    return {};
+  }
+
+  BT::NodeStatus tick() override
+  {
+    std::this_thread::sleep_for(std::chrono::milliseconds(1));
+    return BT::NodeStatus::SUCCESS;
+  }
+};
+}  // namespace
+
+TEST_F(LoggerTest, SqliteLogger_ConcurrentTransitions)
+{
+  factory.registerNodeType<ConcurrentAction>("ConcurrentAction");
+
+  const std::string xml_text = R"(
+    <root BTCPP_format="4">
+       <BehaviorTree>
+          <Parallel>
+            <ConcurrentAction name="A"/>
+            <ConcurrentAction name="B"/>
+          </Parallel>
+       </BehaviorTree>
+    </root>)";
+
+  auto tree = factory.createTreeFromText(xml_text);
+  std::string filepath = test_dir + "/concurrent.db3";
+
+  {
+    SqliteLogger logger(tree, filepath);
+    for(int i = 0; i < 50; i++)
+    {
+      tree.tickWhileRunning();
+      tree.haltTree();
+    }
+  }
+
+  ASSERT_TRUE(std::filesystem::exists(filepath));
+}
+
 // ============ Multiple loggers simultaneously ============
 
 TEST_F(LoggerTest, MultipleLoggers)