From d410c76e9ef6f5b02afd372e6799731adb8aa4d6 Mon Sep 17 00:00:00 2001
From: Tyler Karaszewski <tyler@expensify.com>
Date: Fri, 8 Mar 2024 11:55:40 -0800
Subject: [PATCH 1/2] Fix poll interrupt, add timing info to tests.

---
 sqlitecluster/SQLiteNode.cpp            |  5 +++++
 test/clustertest/BedrockClusterTester.h |  2 +-
 test/lib/tpunit++.cpp                   | 15 +++++++++++++--
 3 files changed, 19 insertions(+), 3 deletions(-)

diff --git a/sqlitecluster/SQLiteNode.cpp b/sqlitecluster/SQLiteNode.cpp
index ff6172389..f47e01384 100644
--- a/sqlitecluster/SQLiteNode.cpp
+++ b/sqlitecluster/SQLiteNode.cpp
@@ -2420,6 +2420,11 @@ int SQLiteNode::_handleCommitTransaction(SQLite& db, SQLitePeer* peer, const uin
         return result;
     }
 
+    // If the commit completed, interrupt the sync thread `poll` loop in case any other threads were waiting on this commit to complete.
+    if (result == SQLITE_OK) {
+        notifyCommit();
+    }
+
     // Clear the list of committed transactions. We're following, so we don't need to send these.
     db.popCommittedTransactions();
 
diff --git a/test/clustertest/BedrockClusterTester.h b/test/clustertest/BedrockClusterTester.h
index 4fead588d..78a60684b 100644
--- a/test/clustertest/BedrockClusterTester.h
+++ b/test/clustertest/BedrockClusterTester.h
@@ -173,7 +173,7 @@ ClusterTester<T>::ClusterTester(ClusterSize size,
             } catch (...) {
                 // This will happen if the server's not up yet. We'll just try again.
             }
-            usleep(500000); // 0.5 seconds.
+            usleep(100000); // 0.1 seconds.
         }
     }
 }
diff --git a/test/lib/tpunit++.cpp b/test/lib/tpunit++.cpp
index 0b0f8b9a0..d193c4f3f 100644
--- a/test/lib/tpunit++.cpp
+++ b/test/lib/tpunit++.cpp
@@ -2,6 +2,7 @@
 #include <string.h>
 #include <iostream>
 #include <regex>
+#include <chrono>
 using namespace tpunit;
 
 bool tpunit::TestFixture::exitFlag = false;
@@ -418,23 +419,33 @@ void tpunit::TestFixture::tpunit_detail_do_tests(TestFixture* f) {
             f->_stats._assertions = 0;
             f->_stats._exceptions = 0;
             f->testOutputBuffer = "";
+            auto start = chrono::steady_clock::now();
             tpunit_detail_do_methods(f->_befores);
             tpunit_detail_do_method(t);
             tpunit_detail_do_methods(f->_afters);
+            auto end = chrono::steady_clock::now();
+            stringstream timeStream;
+            timeStream << "(" << chrono::duration_cast<std::chrono::milliseconds>(end - start);
+            if (chrono::duration_cast<std::chrono::milliseconds>(end - start) > 5000ms) {
+                timeStream << " \xF0\x9F\x90\x8C";
+            }
+            timeStream << ")";
+            string timeStr = timeStream.str();
+            const char* time = timeStr.c_str();
 
             // No new assertions or exceptions. This not currently synchronized correctly. They can cause tests that
             // passed to appear failed when another test failed while this test was running. They cannot cause failed
             // tests to appear to have passed.
             if(!f->_stats._assertions && !f->_stats._exceptions) {
                 lock_guard<recursive_mutex> lock(m);
-                printf("\xE2\x9C\x85 %s\n", t->_name);
+                printf("\xE2\x9C\x85 %s %s\n", t->_name, time);
                 tpunit_detail_stats()._passes++;
             } else {
                 lock_guard<recursive_mutex> lock(m);
 
                 // Dump the test buffer if the test included any log lines.
                 f->printTestBuffer();
-                printf("\xE2\x9D\x8C !FAILED! \xE2\x9D\x8C %s\n", t->_name);
+                printf("\xE2\x9D\x8C !FAILED! \xE2\x9D\x8C %s %s\n", t->_name, time);
                 tpunit_detail_stats()._failures++;
                 tpunit_detail_stats()._failureNames.emplace(t->_name);
             }

From 8bc13824c4fe7982f69e9744d6adf9e494059576 Mon Sep 17 00:00:00 2001
From: Tyler Karaszewski <tyler@expensify.com>
Date: Fri, 8 Mar 2024 12:42:40 -0800
Subject: [PATCH 2/2] add more timing

---
 test/lib/tpunit++.cpp | 21 +++++++++++++++++++++
 1 file changed, 21 insertions(+)

diff --git a/test/lib/tpunit++.cpp b/test/lib/tpunit++.cpp
index d193c4f3f..ff2b49e07 100644
--- a/test/lib/tpunit++.cpp
+++ b/test/lib/tpunit++.cpp
@@ -167,11 +167,15 @@ int tpunit::TestFixture::tpunit_detail_do_run(const set<string>& include, const
     }
 
     list<TestFixture*> afterTests;
+    mutex testTimeLock;
+    multimap<chrono::milliseconds, string> testTimes;
 
     for (int threadID = 0; threadID < threads; threadID++) {
         // Capture everything by reference except threadID, because we don't want it to be incremented for the
         // next thread in the loop.
         thread t = thread([&, threadID]{
+           auto start = chrono::steady_clock::now();
+
            threadInitFunction();
             try {
                 // Do test.
@@ -259,6 +263,11 @@ int tpunit::TestFixture::tpunit_detail_do_run(const set<string>& include, const
                 exitFlag = true;
                 printf("Thread %d caught shutdown exception, exiting.\n", threadID);
             }
+            auto end = chrono::steady_clock::now();
+            if (currentTestName.size()) {
+                lock_guard<mutex> lock(testTimeLock);
+                testTimes.emplace(make_pair(chrono::duration_cast<std::chrono::milliseconds>(end - start), currentTestName));
+            }
         });
         threadList.push_back(move(t));
     }
@@ -294,6 +303,18 @@ int tpunit::TestFixture::tpunit_detail_do_run(const set<string>& include, const
                 printf("%s\n", failure.c_str());
             }
         }
+
+        cout << endl;
+        cout << "Slowest Test Classes: " << endl;
+        auto it = testTimes.rbegin();
+        for (size_t i = 0; i < 10; i++) {
+            if (it == testTimes.rend()) {
+                break;
+            }
+            cout << it->first << ": " << it->second << endl;
+            it++;
+        }
+
         return tpunit_detail_stats()._failures;
     }
     return 1;