From: Willy Tarreau <w@1wt.eu>
Date: Thu, 22 Oct 2020 06:04:23 +0000 (+0200)
Subject: MINOR: threads/debug: only report lock stats for used operations
X-Git-Tag: v2.3-dev8~23
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=de785f04e11218cee7ff0d3e30fbcfc6da91ce87;p=thirdparty%2Fhaproxy.git

MINOR: threads/debug: only report lock stats for used operations

In addition to the previous simplification, most locks don't use the
seek or read lock (e.g. spinlocks etc) so let's split the dump into
distinct operations (write/seek/read) and only report those which
were used. Now the output size is roughly divided by 5 compared
to previous ones.
---

diff --git a/include/haproxy/thread.h b/include/haproxy/thread.h
index 84571217c5..e4d630ddf3 100644
--- a/include/haproxy/thread.h
+++ b/include/haproxy/thread.h
@@ -464,36 +464,44 @@ static inline void show_lock_stats()
 		}
 
 		fprintf(stderr,
-			"Stats about Lock %s: \n"
-			"\t # write lock  : %lu\n"
-			"\t # write unlock: %lu (%ld)\n"
-			"\t # wait time for write     : %.3f msec\n"
-			"\t # wait time for write/lock: %.3f nsec\n"
-			"\t # seek lock   : %lu\n"
-			"\t # seek unlock : %lu (%ld)\n"
-			"\t # wait time for seek      : %.3f msec\n"
-			"\t # wait time for seek/lock : %.3f nsec\n"
-			"\t # read lock   : %lu\n"
-			"\t # read unlock : %lu (%ld)\n"
-			"\t # wait time for read      : %.3f msec\n"
-			"\t # wait time for read/lock : %.3f nsec\n",
-
-			lock_label(lbl),
-			lock_stats[lbl].num_write_locked,
-			lock_stats[lbl].num_write_unlocked,
-			lock_stats[lbl].num_write_unlocked - lock_stats[lbl].num_write_locked,
-			(double)lock_stats[lbl].nsec_wait_for_write / 1000000.0,
-			lock_stats[lbl].num_write_locked ? ((double)lock_stats[lbl].nsec_wait_for_write / (double)lock_stats[lbl].num_write_locked) : 0,
-			lock_stats[lbl].num_seek_locked,
-			lock_stats[lbl].num_seek_unlocked,
-			lock_stats[lbl].num_seek_unlocked - lock_stats[lbl].num_seek_locked,
-			(double)lock_stats[lbl].nsec_wait_for_seek / 1000000.0,
-			lock_stats[lbl].num_seek_locked ? ((double)lock_stats[lbl].nsec_wait_for_seek / (double)lock_stats[lbl].num_seek_locked) : 0,
-			lock_stats[lbl].num_read_locked,
-			lock_stats[lbl].num_read_unlocked,
-			lock_stats[lbl].num_read_unlocked - lock_stats[lbl].num_read_locked,
-			(double)lock_stats[lbl].nsec_wait_for_read / 1000000.0,
-			lock_stats[lbl].num_read_locked ? ((double)lock_stats[lbl].nsec_wait_for_read / (double)lock_stats[lbl].num_read_locked) : 0);
+			"Stats about Lock %s: \n",
+			lock_label(lbl));
+
+		if (lock_stats[lbl].num_write_locked)
+			fprintf(stderr,
+			        "\t # write lock  : %lu\n"
+			        "\t # write unlock: %lu (%ld)\n"
+			        "\t # wait time for write     : %.3f msec\n"
+			        "\t # wait time for write/lock: %.3f nsec\n",
+			        lock_stats[lbl].num_write_locked,
+			        lock_stats[lbl].num_write_unlocked,
+			        lock_stats[lbl].num_write_unlocked - lock_stats[lbl].num_write_locked,
+			        (double)lock_stats[lbl].nsec_wait_for_write / 1000000.0,
+			        lock_stats[lbl].num_write_locked ? ((double)lock_stats[lbl].nsec_wait_for_write / (double)lock_stats[lbl].num_write_locked) : 0);
+
+		if (lock_stats[lbl].num_seek_locked)
+			fprintf(stderr,
+			        "\t # seek lock   : %lu\n"
+			        "\t # seek unlock : %lu (%ld)\n"
+			        "\t # wait time for seek      : %.3f msec\n"
+			        "\t # wait time for seek/lock : %.3f nsec\n",
+			        lock_stats[lbl].num_seek_locked,
+			        lock_stats[lbl].num_seek_unlocked,
+			        lock_stats[lbl].num_seek_unlocked - lock_stats[lbl].num_seek_locked,
+			        (double)lock_stats[lbl].nsec_wait_for_seek / 1000000.0,
+			        lock_stats[lbl].num_seek_locked ? ((double)lock_stats[lbl].nsec_wait_for_seek / (double)lock_stats[lbl].num_seek_locked) : 0);
+
+		if (lock_stats[lbl].num_read_locked)
+			fprintf(stderr,
+			        "\t # read lock   : %lu\n"
+			        "\t # read unlock : %lu (%ld)\n"
+			        "\t # wait time for read      : %.3f msec\n"
+			        "\t # wait time for read/lock : %.3f nsec\n",
+			        lock_stats[lbl].num_read_locked,
+			        lock_stats[lbl].num_read_unlocked,
+			        lock_stats[lbl].num_read_unlocked - lock_stats[lbl].num_read_locked,
+			        (double)lock_stats[lbl].nsec_wait_for_read / 1000000.0,
+			        lock_stats[lbl].num_read_locked ? ((double)lock_stats[lbl].nsec_wait_for_read / (double)lock_stats[lbl].num_read_locked) : 0);
 	}
 }