feat(MainDb): log durations

src/db/main-db.cpp

@@ -919,6 +919,10 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 			buildSqlEventFilter({ ConferenceCallFilter, ConferenceChatMessageFilter, ConferenceInfoFilter }, mask);
 		int count = 0;
 
+		DurationLogger durationLogger(
+			"Get events count with mask=" + Utils::toString(static_cast<int>(mask)) + "."
+		);
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -951,6 +955,11 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 
 		list<shared_ptr<EventLog>> events;
 
+		DurationLogger durationLogger(
+			"Get conference notified events of: `" + peerAddress +
+			"` (lastNotifyId=" + Utils::toString(lastNotifyId) + ")."
+		);
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -984,6 +993,8 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 
 		int count = 0;
 
+		DurationLogger durationLogger("Get chat messages count of: `" + peerAddress + "`.");
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -1027,6 +1038,8 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 		query += " direction = " + Utils::toString(static_cast<int>(ChatMessage::Direction::Incoming)) +
 			+ " AND state <> " + Utils::toString(static_cast<int>(ChatMessage::State::Displayed));
 
+		DurationLogger durationLogger("Get unread chat messages count of: `" + peerAddress + "`.");
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -1063,6 +1076,8 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 				") AND";
 		query += " direction = " + Utils::toString(static_cast<int>(ChatMessage::Direction::Incoming));
 
+		DurationLogger durationLogger("Mark chat messages as read of: `" + peerAddress + "`.");
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -1076,6 +1091,8 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 	}
 
 	list<shared_ptr<ChatMessage>> MainDb::getUnreadChatMessages (const std::string &peerAddress) const {
+		DurationLogger durationLogger("Get unread chat messages: `" + peerAddress + "`.");
+
 		// TODO.
 		return list<shared_ptr<ChatMessage>>();
 	}
@@ -1126,6 +1143,11 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 		if (begin > 0)
 			query += "  OFFSET " + Utils::toString(begin);
 
+		DurationLogger durationLogger(
+			"Get history range of: `" + peerAddress +
+			"` (begin=" + Utils::toString(begin) + ", end=" + Utils::toString(end) + ")."
+		);
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -1171,6 +1193,10 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 				ConferenceCallFilter, ConferenceChatMessageFilter, ConferenceInfoFilter
 			}, mask);
 
+		DurationLogger durationLogger(
+			"Clean history of: `" + peerAddress + "` (mask=" + Utils::toString(static_cast<int>(mask)) + ")."
+		);
+
 		L_BEGIN_LOG_EXCEPTION
 
 		d->invalidEventsFromQuery(query, peerAddress);
@@ -1200,6 +1226,8 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 
 		list<shared_ptr<ChatRoom>> chatRooms;
 
+		DurationLogger durationLogger("Get chat rooms.");
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::session *session = d->dbSession.getBackendSession<soci::session>();
@@ -1254,6 +1282,10 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 			return;
 		}
 
+		DurationLogger durationLogger(
+			"Insert chat room: `" + peerAddress + "` (capabilities=" + Utils::toString(capabilities) + ")."
+		);
+
 		L_BEGIN_LOG_EXCEPTION
 
 		soci::transaction tr(*d->dbSession.getBackendSession<soci::session>());
@@ -1277,6 +1309,8 @@ MainDb::MainDb (const shared_ptr<Core> &core) : AbstractDb(*new MainDbPrivate),
 			return;
 		}
 
+		DurationLogger durationLogger("Delete chat room: `" + peerAddress + "`.");
+
 		L_BEGIN_LOG_EXCEPTION
 
 		d->invalidEventsFromQuery(

src/logger/logger.cpp

@@ -17,9 +17,12 @@
  * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
  */
 
+#include <chrono>
+#include <memory>
+
 #include "linphone/core.h"
 
-#include "object/object-p.h"
+#include "object/base-object-p.h"
 
 #include "logger.h"
 
@@ -29,7 +32,7 @@ using namespace std;
 
 LINPHONE_BEGIN_NAMESPACE
 
-class LoggerPrivate : public ObjectPrivate {
+class LoggerPrivate : public BaseObjectPrivate {
 public:
 	Logger::Level level;
 	ostringstream os;
@@ -37,7 +40,7 @@ public:
 
 // -----------------------------------------------------------------------------
 
-Logger::Logger (Level level) : Object(*new LoggerPrivate) {
+Logger::Logger (Level level) : BaseObject(*new LoggerPrivate) {
 	L_D();
 	d->level = level;
 }
@@ -73,4 +76,32 @@ ostringstream &Logger::getOutput () {
 	return d->os;
 }
 
+// -----------------------------------------------------------------------------
+
+class DurationLoggerPrivate : public BaseObjectPrivate {
+public:
+	unique_ptr<Logger> logger;
+
+	chrono::high_resolution_clock::time_point start;
+};
+
+// -----------------------------------------------------------------------------
+
+DurationLogger::DurationLogger (const string &label, Logger::Level level) : BaseObject(*new DurationLoggerPrivate) {
+	L_D();
+
+	d->logger.reset(new Logger(level));
+	d->logger->getOutput() << "Duration of [" + label + "]: ";
+	d->start = chrono::high_resolution_clock::now();
+
+	Logger(level).getOutput() << "Start measurement of [" + label + "].";
+}
+
+DurationLogger::~DurationLogger () {
+	L_D();
+
+	chrono::high_resolution_clock::time_point end = chrono::high_resolution_clock::now();
+	d->logger->getOutput() << chrono::duration_cast<chrono::milliseconds>(end - d->start).count() << "ms.";
+}
+
 LINPHONE_END_NAMESPACE

src/logger/logger.h

@@ -22,7 +22,7 @@
 
 #include <sstream>
 
-#include "object/object.h"
+#include "object/base-object.h"
 
 // =============================================================================
 
@@ -30,7 +30,7 @@ LINPHONE_BEGIN_NAMESPACE
 
 class LoggerPrivate;
 
-class LINPHONE_PUBLIC Logger : public Object {
+class LINPHONE_PUBLIC Logger : public BaseObject {
 public:
 	enum Level {
 		Debug,
@@ -50,6 +50,18 @@ private:
 	L_DISABLE_COPY(Logger);
 };
 
+class DurationLoggerPrivate;
+
+class DurationLogger : public BaseObject {
+public:
+	DurationLogger (const std::string &label, Logger::Level level = Logger::Info);
+	~DurationLogger ();
+
+private:
+	L_DECLARE_PRIVATE(DurationLogger);
+	L_DISABLE_COPY(DurationLogger);
+};
+
 LINPHONE_END_NAMESPACE
 
 #define lDebug() LinphonePrivate::Logger(LinphonePrivate::Logger::Debug).getOutput()
@@ -61,8 +73,8 @@ LINPHONE_END_NAMESPACE
 #define L_BEGIN_LOG_EXCEPTION try {
 
 #define L_END_LOG_EXCEPTION \
-} catch (const exception &e) { \
-	lWarning() << "Error: " << e.what(); \
-}
+	} catch (const exception &e) { \
+		lWarning() << "Error: " << e.what(); \
+	}
 
 #endif // ifndef _LOGGER_H_

tester/main-db-tester.cpp

@@ -75,14 +75,14 @@ static void get_events_count () {
 	BC_ASSERT_EQUAL(mainDb.getEventsCount(), 4994, int, "%d");
 	BC_ASSERT_EQUAL(mainDb.getEventsCount(MainDb::ConferenceCallFilter), 0, int, "%d");
 	BC_ASSERT_EQUAL(mainDb.getEventsCount(MainDb::ConferenceInfoFilter), 18, int, "%d");
-	BC_ASSERT_EQUAL(mainDb.getEventsCount(MainDb::ConferenceChatMessageFilter), 4976, int, "%d");
+	BC_ASSERT_EQUAL(mainDb.getEventsCount(MainDb::ConferenceChatMessageFilter), 5157, int, "%d");
 	BC_ASSERT_EQUAL(mainDb.getEventsCount(MainDb::NoFilter), 4994, int, "%d");
 }
 
 static void get_messages_count () {
 	MainDbProvider provider;
 	const MainDb &mainDb = provider.getMainDb();
-	BC_ASSERT_EQUAL(mainDb.getChatMessagesCount(), 4976, int, "%d");
+	BC_ASSERT_EQUAL(mainDb.getChatMessagesCount(), 5157, int, "%d");
 	BC_ASSERT_EQUAL(mainDb.getChatMessagesCount("sip:test-39@sip.linphone.org"), 3, int, "%d");
 }