dovecot-2.2: cassandra: With debugging, log also how long result...

[dovecot at dovecot.org]

details:   http://hg.dovecot.org/dovecot-2.2/rev/ffb377cccd22
changeset: 19152:ffb377cccd22
user:      Timo Sirainen <tss at iki.fi>
date:      Thu Sep 17 07:24:28 2015 +0900
description:
cassandra: With debugging, log also how long result was used for before it was freed.
This includes the time spent on SELECT query's iterator.

diffstat:

 src/lib-sql/driver-cassandra.c |  22 ++++++++++++----------
 1 files changed, 12 insertions(+), 10 deletions(-)

diffs (58 lines):

diff -r 7ddc7d2a3036 -r ffb377cccd22 src/lib-sql/driver-cassandra.c
--- a/src/lib-sql/driver-cassandra.c	Thu Sep 17 07:20:32 2015 +0900
+++ b/src/lib-sql/driver-cassandra.c	Thu Sep 17 07:24:28 2015 +0900
@@ -64,7 +64,7 @@
 	char *query;
 	char *error;
 	enum cassandra_query_type query_type;
-	struct timeval start_time;
+	struct timeval start_time, finish_time;
 
 	pool_t row_pool;
 	ARRAY_TYPE(const_string) fields;
@@ -457,6 +457,7 @@
 {
 	struct cassandra_db *db = (struct cassandra_db *)_result->db;
         struct cassandra_result *result = (struct cassandra_result *)_result;
+	struct timeval now;
 
 	i_assert(!result->api.callback);
 	i_assert(result->callback == NULL);
@@ -464,6 +465,15 @@
 	if (_result == db->sync_result)
 		db->sync_result = NULL;
 
+	if (db->log_level >= CASS_LOG_DEBUG) {
+		if (gettimeofday(&now, NULL) < 0)
+			i_fatal("gettimeofday() failed: %m");
+		i_debug("cassandra: Finished query '%s' (%lld+%lld us): %s", result->query,
+			timeval_diff_usecs(&result->finish_time, &result->start_time),
+			timeval_diff_usecs(&now, &result->finish_time),
+			result->error != NULL ? result->error : "success");
+	}
+
 	if (result->result != NULL)
 		cass_result_free(result->result);
 	if (result->iterator != NULL)
@@ -480,20 +490,12 @@
 static void result_finish(struct cassandra_result *result)
 {
 	struct cassandra_db *db = (struct cassandra_db *)result->api.db;
-	struct timeval now;
 	bool free_result = TRUE;
 
 	result->finished = TRUE;
+	result->finish_time = ioloop_timeval;
 	driver_cassandra_result_unlink(db, result);
 
-	if (db->log_level >= CASS_LOG_DEBUG) {
-		if (gettimeofday(&now, NULL) < 0)
-			i_fatal("gettimeofday() failed: %m");
-		i_debug("cassandra: Finished query '%s' (%lld us): %s", result->query,
-			timeval_diff_usecs(&now, &result->start_time),
-			result->error != NULL ? result->error : "success");
-	}
-
 	i_assert((result->error != NULL) == (result->iterator == NULL));
 
 	result->api.callback = TRUE;