Continue to debug

src/query/interpreter.cpp

@@ -3622,6 +3622,8 @@ Interpreter::PrepareResult Interpreter::Prepare(const std::string &query_string,
          utils::Downcast<TransactionQueueQuery>(parsed_query.query))) {
       memgraph::metrics::IncrementCounter(memgraph::metrics::ActiveTransactions);
       auto &db_acc = *db_acc_;
+      spdlog::error("{} Creating Accessor in interpreter. db_accessor_ {}", std::this_thread::get_id(),
+                    (db_accessor_ ? "has value" : "nullptr"));
       db_accessor_ = db_acc->Access(GetIsolationLevelOverride());
       execution_db_accessor_.emplace(db_accessor_.get());
       transaction_status_.store(TransactionStatus::ACTIVE, std::memory_order_release);
@@ -3662,6 +3664,7 @@ Interpreter::PrepareResult Interpreter::Prepare(const std::string &query_string,
       prepared_query = PrepareDumpQuery(std::move(parsed_query), &query_execution->summary, &*execution_db_accessor_,
                                         memory_resource);
     } else if (utils::Downcast<IndexQuery>(parsed_query.query)) {
+      spdlog::error("{} PrepareIndexQuery in interpreter.", std::this_thread::get_id());
       prepared_query = PrepareIndexQuery(std::move(parsed_query), in_explicit_transaction_,
                                          &query_execution->notifications, db->storage(), get_plan_cache());
     } else if (utils::Downcast<AnalyzeGraphQuery>(parsed_query.query)) {
@@ -3999,6 +4002,7 @@ void Interpreter::Commit() {
   if (!commit_confirmed_by_all_sync_repplicas) {
     throw ReplicationException("At least one SYNC replica has not confirmed committing last transaction.");
   }
+  db_accessor_.reset();
 }
 
 void Interpreter::AdvanceCommand() {

src/storage/v2/inmemory/storage.cpp

@@ -195,6 +195,8 @@ InMemoryStorage::InMemoryAccessor::~InMemoryAccessor() {
   }
 
   FinalizeTransaction();
+  spdlog::error("{} InMemoryAccessor::~InMemoryAccessor deleting accessor.\n Stack: {}", std::this_thread::get_id(),
+                "" /*utils::Stacktrace().dump()*/);
 }
 
 VertexAccessor InMemoryStorage::InMemoryAccessor::CreateVertex() {
@@ -949,7 +951,9 @@ void InMemoryStorage::InMemoryAccessor::FinalizeTransaction() {
 
 utils::BasicResult<StorageIndexDefinitionError, void> InMemoryStorage::CreateIndex(
     LabelId label, const std::optional<uint64_t> desired_commit_timestamp) {
+  spdlog::error("{} CreateIndex trying to acquire lock", std::this_thread::get_id());
   std::unique_lock<utils::RWLock> storage_guard(main_lock_);
+  spdlog::error("{} CreateIndex acquired lock", std::this_thread::get_id());
   auto *mem_label_index = static_cast<InMemoryLabelIndex *>(indices_.label_index_.get());
   if (!mem_label_index->CreateIndex(label, vertices_.access(), std::nullopt)) {
     return StorageIndexDefinitionError{IndexDefinitionError{}};
@@ -972,7 +976,9 @@ utils::BasicResult<StorageIndexDefinitionError, void> InMemoryStorage::CreateInd
 
 utils::BasicResult<StorageIndexDefinitionError, void> InMemoryStorage::CreateIndex(
     LabelId label, PropertyId property, const std::optional<uint64_t> desired_commit_timestamp) {
+  spdlog::error("{} CreatedIndex2 trying to acquire lock", std::this_thread::get_id());
   std::unique_lock<utils::RWLock> storage_guard(main_lock_);
+  spdlog::error("{} CreatedIndex2 acquired lock", std::this_thread::get_id());
   auto *mem_label_property_index = static_cast<InMemoryLabelPropertyIndex *>(indices_.label_property_index_.get());
   if (!mem_label_property_index->CreateIndex(label, property, vertices_.access(), std::nullopt)) {
     return StorageIndexDefinitionError{IndexDefinitionError{}};
@@ -1041,7 +1047,9 @@ utils::BasicResult<StorageIndexDefinitionError, void> InMemoryStorage::DropIndex
 
 utils::BasicResult<StorageExistenceConstraintDefinitionError, void> InMemoryStorage::CreateExistenceConstraint(
     LabelId label, PropertyId property, const std::optional<uint64_t> desired_commit_timestamp) {
+  spdlog::error("{} CreateExistenceConstraint trying to acquire lock", std::this_thread::get_id());
   std::unique_lock<utils::RWLock> storage_guard(main_lock_);
+  spdlog::error("{} CreateExistenceConstraint acquired lock", std::this_thread::get_id());
 
   if (constraints_.existence_constraints_->ConstraintExists(label, property)) {
     return StorageExistenceConstraintDefinitionError{ConstraintDefinitionError{}};
@@ -1089,7 +1097,9 @@ utils::BasicResult<StorageExistenceConstraintDroppingError, void> InMemoryStorag
 utils::BasicResult<StorageUniqueConstraintDefinitionError, UniqueConstraints::CreationStatus>
 InMemoryStorage::CreateUniqueConstraint(LabelId label, const std::set<PropertyId> &properties,
                                         const std::optional<uint64_t> desired_commit_timestamp) {
+  spdlog::error("{} CreateUniqueConstraint trying to acquire lock", std::this_thread::get_id());
   std::unique_lock<utils::RWLock> storage_guard(main_lock_);
+  spdlog::error("{} CreateUniqueConstraint acquired lock", std::this_thread::get_id());
   auto *mem_unique_constraints = static_cast<InMemoryUniqueConstraints *>(constraints_.unique_constraints_.get());
   auto ret = mem_unique_constraints->CreateConstraint(label, properties, vertices_.access());
   if (ret.HasError()) {
@@ -1200,15 +1210,19 @@ void InMemoryStorage::CollectGarbage(std::unique_lock<utils::RWLock> main_guard)
     if constexpr (force) {
       // We take the unique lock on the main storage lock, so we can forcefully clean
       // everything we can
+      spdlog::error("{} CollectGarbage trying to acquire unique lock", std::this_thread::get_id());
       if (!main_lock_.try_lock()) {
         CollectGarbage<false>();
         return;
       }
+      spdlog::error("{} CollectGarbage acquired unique lock", std::this_thread::get_id());
     } else {
       // Because the garbage collector iterates through the indices and constraints
       // to clean them up, it must take the main lock for reading to make sure that
       // the indices and constraints aren't concurrently being modified.
+      spdlog::error("{} CollectGarbage trying to acquire shared lock", std::this_thread::get_id());
       main_lock_.lock_shared();
+      spdlog::error("{} CollectGarbage acquired shared lock", std::this_thread::get_id());
     }
   } else {
     MG_ASSERT(main_guard.mutex() == std::addressof(main_lock_), "main_guard should be only for the main_lock_");
@@ -1752,13 +1766,17 @@ utils::BasicResult<InMemoryStorage::CreateSnapshotError> InMemoryStorage::Create
   auto max_num_tries{10};
   while (max_num_tries) {
     if (should_try_shared) {
+      spdlog::error("{} CreateSnapshot trying to acquire shared lock", std::this_thread::get_id());
       std::shared_lock<utils::RWLock> storage_guard(main_lock_);
+      spdlog::error("{} CreateSnapshot acquired shared lock", std::this_thread::get_id());
       if (storage_mode_ == memgraph::storage::StorageMode::IN_MEMORY_TRANSACTIONAL) {
         snapshot_creator();
         return {};
       }
     } else {
+      spdlog::error("{} CreateSnapshot trying to acquire unique lock", std::this_thread::get_id());
       std::unique_lock main_guard{main_lock_};
+      spdlog::error("{} CreateSnapshot acquired unique lock", std::this_thread::get_id());
       if (storage_mode_ == memgraph::storage::StorageMode::IN_MEMORY_ANALYTICAL) {
         if (is_periodic && *is_periodic) {
           return CreateSnapshotError::DisabledForAnalyticsPeriodicCommit;

src/storage/v2/storage.cpp

@@ -9,6 +9,7 @@
 // by the Apache License, Version 2.0, included in the file
 // licenses/APL.txt.
 
+#include <thread>
 #include "absl/container/flat_hash_set.h"
 #include "spdlog/spdlog.h"
 
@@ -21,6 +22,7 @@
 #include "utils/exceptions.hpp"
 #include "utils/file.hpp"
 #include "utils/logging.hpp"
+#include "utils/stacktrace.hpp"
 #include "utils/stat.hpp"
 #include "utils/timer.hpp"
 #include "utils/typeinfo.hpp"
@@ -64,7 +66,10 @@ Storage::Accessor::Accessor(Storage *storage, IsolationLevel isolation_level, St
       storage_guard_(storage_->main_lock_),
       transaction_(storage->CreateTransaction(isolation_level, storage_mode)),
       is_transaction_active_(true),
-      creation_storage_mode_(storage_mode) {}
+      creation_storage_mode_(storage_mode) {
+  spdlog::error("{} Accessor::Accessor acquired shared lock.\nStack: {}", std::this_thread::get_id(),
+                "" /*utils::Stacktrace().dump()*/);
+}
 
 Storage::Accessor::Accessor(Accessor &&other) noexcept
     : storage_(other.storage_),
@@ -74,23 +79,30 @@ Storage::Accessor::Accessor(Accessor &&other) noexcept
       is_transaction_active_(other.is_transaction_active_),
       creation_storage_mode_(other.creation_storage_mode_) {
   // Don't allow the other accessor to abort our transaction in destructor.
+  spdlog::error("{} move Accessor::Accessor acquired shared lock", std::this_thread::get_id());
   other.is_transaction_active_ = false;
   other.commit_timestamp_.reset();
 }
 
 IndicesInfo Storage::ListAllIndices() const {
+  spdlog::error("{} ListAllIndices trying to acquire shared lock", std::this_thread::get_id());
   std::shared_lock<utils::RWLock> storage_guard_(main_lock_);
+  spdlog::error("{} ListAllIndices acquired shared lock", std::this_thread::get_id());
   return {indices_.label_index_->ListIndices(), indices_.label_property_index_->ListIndices()};
 }
 
 ConstraintsInfo Storage::ListAllConstraints() const {
+  spdlog::error("{} ListAllConstraints trying to acquire shared lock", std::this_thread::get_id());
   std::shared_lock<utils::RWLock> storage_guard_(main_lock_);
+  spdlog::error("{} ListAllConstraints acquired shared lock", std::this_thread::get_id());
   return {constraints_.existence_constraints_->ListConstraints(), constraints_.unique_constraints_->ListConstraints()};
 }
 
 /// Main lock is taken by the caller.
 void Storage::SetStorageMode(StorageMode storage_mode) {
+  spdlog::error("{} SetStorageMode trying to acquire lock", std::this_thread::get_id());
   std::unique_lock main_guard{main_lock_};
+  spdlog::error("{} SetStorageMode acquired lock", std::this_thread::get_id());
   MG_ASSERT(
       (storage_mode_ == StorageMode::IN_MEMORY_ANALYTICAL || storage_mode_ == StorageMode::IN_MEMORY_TRANSACTIONAL) &&
       (storage_mode == StorageMode::IN_MEMORY_ANALYTICAL || storage_mode == StorageMode::IN_MEMORY_TRANSACTIONAL));
@@ -105,7 +117,9 @@ StorageMode Storage::GetStorageMode() const { return storage_mode_; }
 IsolationLevel Storage::GetIsolationLevel() const noexcept { return isolation_level_; }
 
 utils::BasicResult<Storage::SetIsolationLevelError> Storage::SetIsolationLevel(IsolationLevel isolation_level) {
+  spdlog::error("{} SetIsolationLevel trying to acquire lock", std::this_thread::get_id());
   std::unique_lock main_guard{main_lock_};
+  spdlog::error("{} SetIsolationLevel acquired lock", std::this_thread::get_id());
   if (storage_mode_ == storage::StorageMode::IN_MEMORY_ANALYTICAL) {
     return Storage::SetIsolationLevelError::DisabledForAnalyticalMode;
   }

src/storage/v2/storage.hpp

@@ -101,7 +101,7 @@ class Storage {
 
     Accessor(Accessor &&other) noexcept;
 
-    virtual ~Accessor() {}
+    virtual ~Accessor() { spdlog::error("{} Accessor::Accessor unlock shared lock", std::this_thread::get_id()); }
 
     virtual VertexAccessor CreateVertex() = 0;
 

src/utils/rw_lock.hpp

@@ -1,4 +1,4 @@
-// Copyright 2022 Memgraph Ltd.
+// Copyright 2023 Memgraph Ltd.
 //
 // Use of this software is governed by the Business Source License
 // included in the file licenses/BSL.txt; by using this file, you agree to be bound by the terms of the Business Source
@@ -14,6 +14,7 @@
 
 #include <pthread.h>
 #include <unistd.h>
+#include <thread>
 
 #include <cerrno>
 
@@ -74,7 +75,11 @@ class RWLock {
 
   ~RWLock() { pthread_rwlock_destroy(&lock_); }
 
-  void lock() { MG_ASSERT(pthread_rwlock_wrlock(&lock_) == 0, "Couldn't lock utils::RWLock!"); }
+  void lock() {
+    spdlog::error("{} Trying to lock unique lock", std::this_thread::get_id());
+    MG_ASSERT(pthread_rwlock_wrlock(&lock_) == 0, "Couldn't lock utils::RWLock!");
+    spdlog::error("{} Lock unique lock", std::this_thread::get_id());
+  }
 
   bool try_lock() {
     int err = pthread_rwlock_trywrlock(&lock_);
@@ -83,13 +88,19 @@ class RWLock {
     return false;
   }
 
-  void unlock() { MG_ASSERT(pthread_rwlock_unlock(&lock_) == 0, "Couldn't unlock utils::RWLock!"); }
+  void unlock() {
+    spdlog::error("{} Trying to unlock unique lock", std::this_thread::get_id());
+    MG_ASSERT(pthread_rwlock_unlock(&lock_) == 0, "Couldn't unlock utils::RWLock!");
+    spdlog::error("{} Unlock unique lock", std::this_thread::get_id());
+  }
 
   void lock_shared() {
     int err;
     while (true) {
+      spdlog::error("{} Trying to acquire lock_shared lock", std::this_thread::get_id());
       err = pthread_rwlock_rdlock(&lock_);
       if (err == 0) {
+        spdlog::error("{} Acquired lock_shared lock", std::this_thread::get_id());
         return;
       } else if (err == EAGAIN) {
         continue;
@@ -115,7 +126,11 @@ class RWLock {
     }
   }
 
-  void unlock_shared() { MG_ASSERT(pthread_rwlock_unlock(&lock_) == 0, "Couldn't unlock shared utils::RWLock!"); }
+  void unlock_shared() {
+    spdlog::error("{} Trying to  unlock shared lock", std::this_thread::get_id());
+    MG_ASSERT(pthread_rwlock_unlock(&lock_) == 0, "Couldn't unlock shared utils::RWLock!");
+    spdlog::error("{} unlock shared lock", std::this_thread::get_id());
+  }
 
  private:
   pthread_rwlock_t lock_ = PTHREAD_RWLOCK_INITIALIZER;