From 201fe45edc1589cf5d6ee6890fe21500e56e4c77 Mon Sep 17 00:00:00 2001
From: "Dirk-Jan C. Binnema" <djcb@djcbsoftware.nl>
Date: Thu, 19 Jan 2023 00:38:26 +0200
Subject: [PATCH] server: add a few stopwatches

For measuring performance.
---
 lib/mu-server.cc      | 7 +++++++
 lib/utils/mu-utils.hh | 6 +++---
 2 files changed, 10 insertions(+), 3 deletions(-)

diff --git a/lib/mu-server.cc b/lib/mu-server.cc
index 04b83db7..b96f50f8 100644
--- a/lib/mu-server.cc
+++ b/lib/mu-server.cc
@@ -687,6 +687,9 @@ Server::Private::find_handler(const Command& cmd)
 	if (threads)
 		qflags |= QueryFlags::Threading;
 
+	StopWatch sw{format("%s (indexing: %s)", __func__,
+			    indexer().is_running() ? "yes" :  "no")};
+
 	std::lock_guard l{store_.lock()};
 	auto qres{store_.run_query(q, sort_field->id, qflags, maxnum)};
 	if (!qres)
@@ -778,6 +781,7 @@ Server::Private::index_handler(const Command& cmd)
 
 	// start a background track.
 	index_thread_ = std::thread([this, conf = std::move(conf)] {
+		StopWatch sw{"indexing"};
 		indexer().start(conf);
 		while (indexer().is_running()) {
 			std::this_thread::sleep_for(std::chrono::milliseconds(2000));
@@ -1024,6 +1028,9 @@ Server::Private::view_mark_as_read(Store::Id docid, Message&& msg, bool rename)
 void
 Server::Private::view_handler(const Command& cmd)
 {
+	StopWatch sw{format("%s (indexing: %s)", __func__,
+			    indexer().is_running() ? "yes" :  "no")};
+
 	const auto mark_as_read{cmd.boolean_arg(":mark-as-read")};
 	/* for now, do _not_ rename, as it seems to confuse mbsync */
 	const auto rename{false};
diff --git a/lib/utils/mu-utils.hh b/lib/utils/mu-utils.hh
index 4f77b08e..836f3b06 100644
--- a/lib/utils/mu-utils.hh
+++ b/lib/utils/mu-utils.hh
@@ -231,11 +231,11 @@ struct StopWatch {
 	{
 		const auto us{static_cast<double>(to_us(Clock::now() - start_))};
 		if (us > 2000000)
-			g_debug("%s: finished after %0.1f s", name_.c_str(), us / 1000000);
+			g_debug("sw: %s: finished after %0.1f s", name_.c_str(), us / 1000000);
 		else if (us > 2000)
-			g_debug("%s: finished after %0.1f ms", name_.c_str(), us / 1000);
+			g_debug("sw: %s: finished after %0.1f ms", name_.c_str(), us / 1000);
 		else
-			g_debug("%s: finished after %g us", name_.c_str(), us);
+			g_debug("sw: %s: finished after %g us", name_.c_str(), us);
 	}
 
 private: