Merge pull request #2030 from Expensify/diagnose-stuck-quiesce

Add log lines
Expensify · Dec 17, 2024 · 4059218 · 4059218
2 parents a74a5d6 + 9da6394
commit 4059218
Show file tree

Hide file tree

Showing 2 changed files with 11 additions and 0 deletions.
diff --git a/BedrockServer.cpp b/BedrockServer.cpp
@@ -1823,6 +1823,7 @@ atomic<bool> __quiesceShouldUnlock(false);
 thread* __quiesceThread = nullptr;
 
 void BedrockServer::_control(unique_ptr<BedrockCommand>& command) {
+    SINFO("Received control command: " << command->request.methodLine);
     SData& response = command->response;
     string reason = "MANUAL";
     response.methodLine = "200 OK";
@@ -1913,7 +1914,9 @@ void BedrockServer::_control(unique_ptr<BedrockCommand>& command) {
                 if (dbPoolCopy) {
                     SQLiteScopedHandle dbScope(*_dbPool, _dbPool->getIndex());
                     SQLite& db = dbScope.db();
+                    SINFO("[quiesce] Exclusive locking DB");
                     db.exclusiveLockDB();
+                    SINFO("[quiesce] Exclusive locked DB");
                     locked = true;
                     while (true) {
                         if (__quiesceShouldUnlock) {
@@ -1936,12 +1939,16 @@ void BedrockServer::_control(unique_ptr<BedrockCommand>& command) {
             response.methodLine = "200 Blocked";
         }
     } else if (SIEquals(command->request.methodLine, "UnblockWrites")) {
+        SINFO("[quiesce] Locking __quiesceLock");
         lock_guard lock(__quiesceLock);
+        SINFO("[quiesce] __quiesceLock locked");
         if (!__quiesceThread) {
             response.methodLine = "200 Not Blocked";
         } else {
             __quiesceShouldUnlock = true;
+            SINFO("[quiesce] Joining __quiesceThread");
             __quiesceThread->join();
+            SINFO("[quiesce] __quiesceThread joined");
             delete __quiesceThread;
             __quiesceThread = nullptr;
             response.methodLine = "200 Unblocked";

diff --git a/sqlitecluster/SQLite.cpp b/sqlitecluster/SQLite.cpp
@@ -331,13 +331,17 @@ void SQLite::exclusiveLockDB() {
     // writes in this case.
     // So when these are both locked by the same thread at the same time, `commitLock` is always locked first, and we do it the same way here to avoid deadlocks.
     try {
+        SINFO("Locking commitLock");
         _sharedData.commitLock.lock();
+        SINFO("commitLock Locked");
     } catch (const system_error& e) {
         SWARN("Caught system_error calling _sharedData.commitLock, code: " << e.code() << ", message: " << e.what());
         throw;
     }
     try {
+        SINFO("Locking writeLock");
         _sharedData.writeLock.lock();
+        SINFO("writeLock Locked");
     } catch(const system_error& e) {
         SWARN("Caught system_error calling _sharedData.writeLock, code: " << e.code() << ", message: " << e.what());
         throw;