From: Timo Sirainen <timo.sirainen@dovecot.fi>
Date: Mon, 24 Oct 2016 12:59:07 +0000 (+0300)
Subject: lib: With FILE_LOCK_SLOW_WARNING_MSECS log a warning also when keeping lock for long.
X-Git-Tag: 2.2.26~46
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=b909e9579d72684faaebbe3189cab6c012935a6b;p=thirdparty%2Fdovecot%2Fcore.git

lib: With FILE_LOCK_SLOW_WARNING_MSECS log a warning also when keeping lock for long.

This can help catching which process kept the lock for too long.
---

diff --git a/src/lib/file-lock.c b/src/lib/file-lock.c
index ffe35465fa..eb67419ef8 100644
--- a/src/lib/file-lock.c
+++ b/src/lib/file-lock.c
@@ -15,6 +15,7 @@ struct file_lock {
 	int fd;
 	char *path;
 
+	struct timeval locked_time;
 	int lock_type;
 	enum file_lock_method lock_method;
 };
@@ -23,6 +24,8 @@ static struct timeval lock_wait_start;
 static uint64_t file_lock_wait_usecs = 0;
 static long long file_lock_slow_warning_usecs = -1;
 
+static void file_lock_log_warning_if_slow(struct file_lock *lock);
+
 bool file_lock_method_parse(const char *name, enum file_lock_method *method_r)
 {
 	if (strcasecmp(name, "fcntl") == 0)
@@ -317,6 +320,8 @@ int file_wait_lock_error(int fd, const char *path, int lock_type,
 	lock->path = i_strdup(path);
 	lock->lock_type = lock_type;
 	lock->lock_method = lock_method;
+	if (gettimeofday(&lock->locked_time, NULL) < 0)
+		i_fatal("gettimeofday() failed: %m");
 	*lock_r = lock;
 	return 1;
 }
@@ -324,9 +329,15 @@ int file_wait_lock_error(int fd, const char *path, int lock_type,
 int file_lock_try_update(struct file_lock *lock, int lock_type)
 {
 	const char *error;
+	int ret;
 
-	return file_lock_do(lock->fd, lock->path, lock_type,
-			    lock->lock_method, 0, &error);
+	ret = file_lock_do(lock->fd, lock->path, lock_type,
+			   lock->lock_method, 0, &error);
+	if (ret <= 0)
+		return ret;
+	file_lock_log_warning_if_slow(lock);
+	lock->lock_type = lock_type;
+	return 1;
 }
 
 void file_unlock(struct file_lock **_lock)
@@ -351,6 +362,7 @@ void file_lock_free(struct file_lock **_lock)
 
 	*_lock = NULL;
 
+	file_lock_log_warning_if_slow(lock);
 	i_free(lock->path);
 	i_free(lock);
 }
@@ -382,6 +394,31 @@ static void file_lock_wait_init_warning(void)
 	}
 }
 
+static void file_lock_log_warning_if_slow(struct file_lock *lock)
+{
+	if (file_lock_slow_warning_usecs < 0)
+		file_lock_wait_init_warning();
+	if (file_lock_slow_warning_usecs == LLONG_MAX) {
+		/* slowness checking is disabled */
+		return;
+	}
+	if (lock->lock_type != F_WRLCK) {
+		/* some shared locks can legitimately be kept for a long time.
+		   don't warn about them. */
+		return;
+	}
+
+	struct timeval now;
+	if (gettimeofday(&now, NULL) < 0)
+		i_fatal("gettimeofday() failed: %m");
+
+	int diff = timeval_diff_msecs(&now, &lock->locked_time);
+	if (diff > file_lock_slow_warning_usecs/1000) {
+		i_warning("Lock %s kept for %d.%03d secs", lock->path,
+			  diff / 1000, diff % 1000);
+	}
+}
+
 void file_lock_wait_end(const char *lock_name)
 {
 	struct timeval now;