Mercurial > dovecot > core-2.2

changeset 20481:94736fed1324

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
cassandra: Warn if queries take too long (default 5 secs) Can be changed with e.g. "connect = ... warn_timeout=30s"
author Timo Sirainen <timo.sirainen@dovecot.fi>
date Fri, 01 Jul 2016 16:30:06 +0300
parents 4909fa3325e8
children bde406ffe5b2
files src/lib-sql/driver-cassandra.c
diffstat 1 files changed, 20 insertions(+), 4 deletions(-) [+]
line wrap: on
line diff
--- a/src/lib-sql/driver-cassandra.c	Fri Jul 01 16:27:30 2016 +0300
+++ b/src/lib-sql/driver-cassandra.c	Fri Jul 01 16:30:06 2016 +0300
@@ -25,6 +25,8 @@
 #define CASSANDRA_FALLBACK_FIRST_RETRY_MSECS 50
 #define CASSANDRA_FALLBACK_MAX_RETRY_MSECS (1000*60)
 
+#define CASS_QUERY_DEFAULT_WARN_TIMEOUT_SECS 5
+
 typedef void driver_cassandra_callback_t(CassFuture *future, void *context);
 
 enum cassandra_query_type {
@@ -56,6 +58,7 @@
 	unsigned int protocol_version;
 	unsigned int num_threads;
 	unsigned int connect_timeout_secs, request_timeout_secs;
+	unsigned int warn_timeout_secs;
 	in_port_t port;
 
 	CassCluster *cluster;
@@ -384,6 +387,7 @@
 	db->delete_consistency = CASS_CONSISTENCY_LOCAL_QUORUM;
 	db->connect_timeout_secs = SQL_CONNECT_TIMEOUT_SECS;
 	db->request_timeout_secs = SQL_QUERY_TIMEOUT_SECS;
+	db->warn_timeout_secs = CASS_QUERY_DEFAULT_WARN_TIMEOUT_SECS;
 
 	args = t_strsplit_spaces(connect_string, " ");
 	for (; *args != NULL; args++) {
@@ -447,6 +451,9 @@
 		} else if (strcmp(key, "request_timeout") == 0) {
 			if (settings_get_time(value, &db->request_timeout_secs, &error) < 0)
 				i_fatal("cassandra: Invalid request_timeout '%s': %s", value, error);
+		} else if (strcmp(key, "warn_timeout") == 0) {
+			if (settings_get_time(value, &db->warn_timeout_secs, &error) < 0)
+				i_fatal("cassandra: Invalid warn_timeout '%s': %s", value, error);
 		} else if (strcmp(key, "metrics") == 0) {
 			i_free(db->metrics_path);
 			db->metrics_path = i_strdup(value);
@@ -614,6 +621,8 @@
 	struct cassandra_db *db = (struct cassandra_db *)_result->db;
         struct cassandra_result *result = (struct cassandra_result *)_result;
 	struct timeval now;
+	const char *str;
+	long long reply_usecs;
 
 	i_assert(!result->api.callback);
 	i_assert(result->callback == NULL);
@@ -621,14 +630,21 @@
 	if (_result == db->sync_result)
 		db->sync_result = NULL;
 
-	if (db->log_level >= CASS_LOG_DEBUG) {
+	reply_usecs = timeval_diff_usecs(&result->finish_time, &result->start_time);
+	if (db->log_level >= CASS_LOG_DEBUG ||
+	    reply_usecs/1000000 >= db->warn_timeout_secs) {
 		if (gettimeofday(&now, NULL) < 0)
 			i_fatal("gettimeofday() failed: %m");
-		i_debug("cassandra: Finished query '%s' (%u rows, %lld+%lld us): %s", result->query,
-			result->row_count,
-			timeval_diff_usecs(&result->finish_time, &result->start_time),
+		str = t_strdup_printf(
+			"cassandra: Finished query '%s' (%u rows, %lld+%lld us): %s",
+			result->query, result->row_count, reply_usecs,
 			timeval_diff_usecs(&now, &result->finish_time),
 			result->error != NULL ? result->error : "success");
+
+		if (reply_usecs/1000000 >= db->warn_timeout_secs)
+			i_warning("%s", str);
+		else
+			i_debug("%s", str);
 	}
 
 	if (result->result != NULL)