lib: Track how much time has been spent on waiting for locks.

src/lib/file-dotlock.c

@@ -5,6 +5,7 @@
 #include "str.h"
 #include "hex-binary.h"
 #include "hostpid.h"
+#include "file-lock.h"
 #include "eacces-error.h"
 #include "write-full.h"
 #include "safe-mkstemp.h"
@@ -496,6 +497,7 @@ dotlock_create(struct dotlock *dotlock, enum dotlock_create_flags flags,
 
 	last_notify = 0; do_wait = FALSE;
 
+	file_lock_wait_start();
 	do {
 		if (do_wait) {
 			if (prev_last_change != lock_info.last_change) {
@@ -560,6 +562,7 @@ dotlock_create(struct dotlock *dotlock, enum dotlock_create_flags flags,
 		do_wait = TRUE;
 		now = time(NULL);
 	} while (now < max_wait_time);
+	file_lock_wait_end();
 
 	if (ret > 0) {
 		if (fstat(lock_info.fd, &st) < 0) {

src/lib/file-lock.c

@@ -3,6 +3,7 @@
 #include "lib.h"
 #include "istream.h"
 #include "file-lock.h"
+#include "time-util.h"
 
 #include <time.h>
 #include <sys/stat.h>
@@ -18,6 +19,9 @@ struct file_lock {
 	enum file_lock_method lock_method;
 };
 
+static struct timeval lock_wait_start;
+static uint64_t file_lock_wait_usecs = 0;
+
 bool file_lock_method_parse(const char *name, enum file_lock_method *method_r)
 {
 	if (strcasecmp(name, "fcntl") == 0)
@@ -165,8 +169,10 @@ static int file_lock_do(int fd, const char *path, int lock_type,
 
 	i_assert(fd != -1);
 
-	if (timeout_secs != 0)
+	if (timeout_secs != 0) {
 		alarm(timeout_secs);
+		file_lock_wait_start();
+	}
 
 	lock_type_str = lock_type == F_UNLCK ? "unlock" :
 		(lock_type == F_RDLCK ? "read-lock" : "write-lock");
@@ -186,7 +192,10 @@ static int file_lock_do(int fd, const char *path, int lock_type,
 		fl.l_len = 0;
 
 		ret = fcntl(fd, timeout_secs != 0 ? F_SETLKW : F_SETLK, &fl);
-		if (timeout_secs != 0) alarm(0);
+		if (timeout_secs != 0) {
+			alarm(0);
+			file_lock_wait_end();
+		}
 
 		if (ret == 0)
 			break;
@@ -237,7 +246,10 @@ static int file_lock_do(int fd, const char *path, int lock_type,
 		}
 
 		ret = flock(fd, operation);
-		if (timeout_secs != 0) alarm(0);
+		if (timeout_secs != 0) {
+			alarm(0);
+			file_lock_wait_end();
+		}
 
 		if (ret == 0)
 			break;
@@ -341,3 +353,28 @@ void file_lock_free(struct file_lock **_lock)
 	i_free(lock->path);
 	i_free(lock);
 }
+
+void file_lock_wait_start(void)
+{
+	i_assert(lock_wait_start.tv_sec == 0);
+
+	if (gettimeofday(&lock_wait_start, NULL) < 0)
+		i_fatal("gettimeofday() failed: %m");
+}
+
+void file_lock_wait_end(void)
+{
+	struct timeval now;
+
+	i_assert(lock_wait_start.tv_sec != 0);
+
+	if (gettimeofday(&now, NULL) < 0)
+		i_fatal("gettimeofday() failed: %m");
+	file_lock_wait_usecs += timeval_diff_usecs(&now, &lock_wait_start);
+	lock_wait_start.tv_sec = 0;
+}
+
+uint64_t file_lock_wait_get_total_usecs(void)
+{
+	return file_lock_wait_usecs;
+}

src/lib/file-lock.h

@@ -56,4 +56,10 @@ void file_lock_free(struct file_lock **lock);
 const char *file_lock_find(int lock_fd, enum file_lock_method lock_method,
 			   int lock_type);
 
+/* Track the duration of a lock wait. */
+void file_lock_wait_start(void);
+void file_lock_wait_end(void);
+/* Return how many microseconds has been spent on lock waiting. */
+uint64_t file_lock_wait_get_total_usecs(void);
+
 #endif