ocfs2: Use hrtimer to track ocfs2 fs lock stats

Patch makes use of the hrtimer to track times in ocfs2 lock stats. The patch is a bit involved to ensure no additional impact on the memory footprint. The size of ocfs2_inode_cache remains 1280 bytes on 32-bit systems. A related change was to modify the unit of the max wait time from nanosec to microsec allowing us to track max time larger than 4 secs. This change necessitated the bumping of the output version in the debugfs file, locking_state, from 2 to 3. Signed-off-by: Sunil Mushran <sunil.mushran@oracle.com> Signed-off-by: Joel Becker <jlbec@evilplan.org>

ocfs2: Use hrtimer to track ocfs2 fs lock stats
Patch makes use of the hrtimer to track times in ocfs2 lock stats. The patch is a bit involved to ensure no additional impact on the memory footprint. The size of ocfs2_inode_cache remains 1280 bytes on 32-bit systems. A related change was to modify the unit of the max wait time from nanosec to microsec allowing us to track max time larger than 4 secs. This change necessitated the bumping of the output version in the debugfs file, locking_state, from 2 to 3. Signed-off-by: Sunil Mushran <sunil.mushran@oracle.com> Signed-off-by: Joel Becker <jlbec@evilplan.org>
Sunil Mushran · Joel Becker
1 parent 0cc9d52578
Showing 2 changed files with 64 additions and 56 deletions Side-by-side Diff
fs/ocfs2/dlmglue.c
fs/ocfs2/ocfs2.h
@@ -64,7 +64,7 @@
 	unsigned long		mw_mask;
 	unsigned long		mw_goal;
 #ifdef CONFIG_OCFS2_FS_STATS
-	unsigned long long 	mw_lock_start;
+	ktime_t			mw_lock_start;
 #endif
 };
  
  
  
  
  
  
@@ -435,44 +435,41 @@
 #ifdef CONFIG_OCFS2_FS_STATS
 static void ocfs2_init_lock_stats(struct ocfs2_lock_res *res)
 {
-	res->l_lock_num_prmode = 0;
-	res->l_lock_num_prmode_failed = 0;
-	res->l_lock_total_prmode = 0;
-	res->l_lock_max_prmode = 0;
-	res->l_lock_num_exmode = 0;
-	res->l_lock_num_exmode_failed = 0;
-	res->l_lock_total_exmode = 0;
-	res->l_lock_max_exmode = 0;
 	res->l_lock_refresh = 0;
+	memset(&res->l_lock_prmode, 0, sizeof(struct ocfs2_lock_stats));
+	memset(&res->l_lock_exmode, 0, sizeof(struct ocfs2_lock_stats));
 }
  
 static void ocfs2_update_lock_stats(struct ocfs2_lock_res *res, int level,
 				    struct ocfs2_mask_waiter *mw, int ret)
 {
-	unsigned long long *num, *sum;
-	unsigned int *max, *failed;
-	struct timespec ts = current_kernel_time();
-	unsigned long long time = timespec_to_ns(&ts) - mw->mw_lock_start;
+	u32 usec;
+	ktime_t kt;
+	struct ocfs2_lock_stats *stats;
  
-	if (level == LKM_PRMODE) {
-		num = &res->l_lock_num_prmode;
-		sum = &res->l_lock_total_prmode;
-		max = &res->l_lock_max_prmode;
-		failed = &res->l_lock_num_prmode_failed;
-	} else if (level == LKM_EXMODE) {
-		num = &res->l_lock_num_exmode;
-		sum = &res->l_lock_total_exmode;
-		max = &res->l_lock_max_exmode;
-		failed = &res->l_lock_num_exmode_failed;
-	} else
+	if (level == LKM_PRMODE)
+		stats = &res->l_lock_prmode;
+	else if (level == LKM_EXMODE)
+		stats = &res->l_lock_exmode;
+	else
 		return;
  
-	(*num)++;
-	(*sum) += time;
-	if (time > *max)
-		*max = time;
+	kt = ktime_sub(ktime_get(), mw->mw_lock_start);
+	usec = ktime_to_us(kt);
+
+	stats->ls_gets++;
+	stats->ls_total += ktime_to_ns(kt);
+	/* overflow */
+	if (unlikely(stats->ls_gets) == 0) {
+		stats->ls_gets++;
+		stats->ls_total = ktime_to_ns(kt);
+	}
+
+	if (stats->ls_max < usec)
+		stats->ls_max = usec;
+
 	if (ret)
-		(*failed)++;
+		stats->ls_fail++;
 }
  
 static inline void ocfs2_track_lock_refresh(struct ocfs2_lock_res *lockres)
@@ -482,8 +479,7 @@
  
 static inline void ocfs2_init_start_time(struct ocfs2_mask_waiter *mw)
 {
-	struct timespec ts = current_kernel_time();
-	mw->mw_lock_start = timespec_to_ns(&ts);
+	mw->mw_lock_start = ktime_get();
 }
 #else
 static inline void ocfs2_init_lock_stats(struct ocfs2_lock_res *res)
@@ -2869,8 +2865,15 @@
 	return iter;
 }
  
-/* So that debugfs.ocfs2 can determine which format is being used */
-#define OCFS2_DLM_DEBUG_STR_VERSION 2
+/*
+ * Version is used by debugfs.ocfs2 to determine the format being used
+ *
+ * New in version 2
+ *	- Lock stats printed
+ * New in version 3
+ *	- Max time in lock stats is in usecs (instead of nsecs)
+ */
+#define OCFS2_DLM_DEBUG_STR_VERSION 3
 static int ocfs2_dlm_seq_show(struct seq_file *m, void *v)
 {
 	int i;
  
@@ -2912,18 +2915,18 @@
 		seq_printf(m, "0x%x\t", lvb[i]);
  
 #ifdef CONFIG_OCFS2_FS_STATS
-# define lock_num_prmode(_l)		(_l)->l_lock_num_prmode
-# define lock_num_exmode(_l)		(_l)->l_lock_num_exmode
-# define lock_num_prmode_failed(_l)	(_l)->l_lock_num_prmode_failed
-# define lock_num_exmode_failed(_l)	(_l)->l_lock_num_exmode_failed
-# define lock_total_prmode(_l)		(_l)->l_lock_total_prmode
-# define lock_total_exmode(_l)		(_l)->l_lock_total_exmode
-# define lock_max_prmode(_l)		(_l)->l_lock_max_prmode
-# define lock_max_exmode(_l)		(_l)->l_lock_max_exmode
-# define lock_refresh(_l)		(_l)->l_lock_refresh
+# define lock_num_prmode(_l)		((_l)->l_lock_prmode.ls_gets)
+# define lock_num_exmode(_l)		((_l)->l_lock_exmode.ls_gets)
+# define lock_num_prmode_failed(_l)	((_l)->l_lock_prmode.ls_fail)
+# define lock_num_exmode_failed(_l)	((_l)->l_lock_exmode.ls_fail)
+# define lock_total_prmode(_l)		((_l)->l_lock_prmode.ls_total)
+# define lock_total_exmode(_l)		((_l)->l_lock_exmode.ls_total)
+# define lock_max_prmode(_l)		((_l)->l_lock_prmode.ls_max)
+# define lock_max_exmode(_l)		((_l)->l_lock_exmode.ls_max)
+# define lock_refresh(_l)		((_l)->l_lock_refresh)
 #else
-# define lock_num_prmode(_l)		(0ULL)
-# define lock_num_exmode(_l)		(0ULL)
+# define lock_num_prmode(_l)		(0)
+# define lock_num_exmode(_l)		(0)
 # define lock_num_prmode_failed(_l)	(0)
 # define lock_num_exmode_failed(_l)	(0)
 # define lock_total_prmode(_l)		(0ULL)
@@ -2933,8 +2936,8 @@
 # define lock_refresh(_l)		(0)
 #endif
 	/* The following seq_print was added in version 2 of this output */
-	seq_printf(m, "%llu\t"
-		   "%llu\t"
+	seq_printf(m, "%u\t"
+		   "%u\t"
 		   "%u\t"
 		   "%u\t"
 		   "%llu\t"
@@ -147,6 +147,17 @@
  
 typedef void (*ocfs2_lock_callback)(int status, unsigned long data);
  
+#ifdef CONFIG_OCFS2_FS_STATS
+struct ocfs2_lock_stats {
+	u64		ls_total;	/* Total wait in NSEC */
+	u32		ls_gets;	/* Num acquires */
+	u32		ls_fail;	/* Num failed acquires */
+
+	/* Storing max wait in usecs saves 24 bytes per inode */
+	u32		ls_max;		/* Max wait in USEC */
+};
+#endif
+
 struct ocfs2_lock_res {
 	void                    *l_priv;
 	struct ocfs2_lock_res_ops *l_ops;
@@ -182,15 +193,9 @@
 	struct list_head         l_debug_list;
  
 #ifdef CONFIG_OCFS2_FS_STATS
-	unsigned long long	 l_lock_num_prmode; 	   /* PR acquires */
-	unsigned long long 	 l_lock_num_exmode; 	   /* EX acquires */
-	unsigned int		 l_lock_num_prmode_failed; /* Failed PR gets */
-	unsigned int		 l_lock_num_exmode_failed; /* Failed EX gets */
-	unsigned long long	 l_lock_total_prmode; 	   /* Tot wait for PR */
-	unsigned long long	 l_lock_total_exmode; 	   /* Tot wait for EX */
-	unsigned int		 l_lock_max_prmode; 	   /* Max wait for PR */
-	unsigned int		 l_lock_max_exmode; 	   /* Max wait for EX */
-	unsigned int		 l_lock_refresh;	   /* Disk refreshes */
+	struct ocfs2_lock_stats  l_lock_prmode;		/* PR mode stats */
+	u32                      l_lock_refresh;	/* Disk refreshes */
+	struct ocfs2_lock_stats  l_lock_exmode;		/* EX mode stats */
 #endif
 #ifdef CONFIG_DEBUG_LOCK_ALLOC
 	struct lockdep_map	 l_lockdep_map;
...	...	@@ -64,7 +64,7 @@
64	64	unsigned long mw_mask;
65	65	unsigned long mw_goal;
66	66	#ifdef CONFIG_OCFS2_FS_STATS
67		- unsigned long long mw_lock_start;
	67	+ ktime_t mw_lock_start;
68	68	#endif
69	69	};
70	70
71	71
72	72
73	73
74	74
75	75
...	...	@@ -435,44 +435,41 @@
435	435	#ifdef CONFIG_OCFS2_FS_STATS
436	436	static void ocfs2_init_lock_stats(struct ocfs2_lock_res *res)
437	437	{
438		- res->l_lock_num_prmode = 0;
439		- res->l_lock_num_prmode_failed = 0;
440		- res->l_lock_total_prmode = 0;
441		- res->l_lock_max_prmode = 0;
442		- res->l_lock_num_exmode = 0;
443		- res->l_lock_num_exmode_failed = 0;
444		- res->l_lock_total_exmode = 0;
445		- res->l_lock_max_exmode = 0;
446	438	res->l_lock_refresh = 0;
	439	+ memset(&res->l_lock_prmode, 0, sizeof(struct ocfs2_lock_stats));
	440	+ memset(&res->l_lock_exmode, 0, sizeof(struct ocfs2_lock_stats));
447	441	}
448	442
449	443	static void ocfs2_update_lock_stats(struct ocfs2_lock_res *res, int level,
450	444	struct ocfs2_mask_waiter *mw, int ret)
451	445	{
452		- unsigned long long num, sum;
453		- unsigned int max, failed;
454		- struct timespec ts = current_kernel_time();
455		- unsigned long long time = timespec_to_ns(&ts) - mw->mw_lock_start;
	446	+ u32 usec;
	447	+ ktime_t kt;
	448	+ struct ocfs2_lock_stats *stats;
456	449
457		- if (level == LKM_PRMODE) {
458		- num = &res->l_lock_num_prmode;
459		- sum = &res->l_lock_total_prmode;
460		- max = &res->l_lock_max_prmode;
461		- failed = &res->l_lock_num_prmode_failed;
462		- } else if (level == LKM_EXMODE) {
463		- num = &res->l_lock_num_exmode;
464		- sum = &res->l_lock_total_exmode;
465		- max = &res->l_lock_max_exmode;
466		- failed = &res->l_lock_num_exmode_failed;
467		- } else
	450	+ if (level == LKM_PRMODE)
	451	+ stats = &res->l_lock_prmode;
	452	+ else if (level == LKM_EXMODE)
	453	+ stats = &res->l_lock_exmode;
	454	+ else
468	455	return;
469	456
470		- (*num)++;
471		- (*sum) += time;
472		- if (time > *max)
473		- *max = time;
	457	+ kt = ktime_sub(ktime_get(), mw->mw_lock_start);
	458	+ usec = ktime_to_us(kt);
	459	+
	460	+ stats->ls_gets++;
	461	+ stats->ls_total += ktime_to_ns(kt);
	462	+ /* overflow */
	463	+ if (unlikely(stats->ls_gets) == 0) {
	464	+ stats->ls_gets++;
	465	+ stats->ls_total = ktime_to_ns(kt);
	466	+ }
	467	+
	468	+ if (stats->ls_max < usec)
	469	+ stats->ls_max = usec;
	470	+
474	471	if (ret)
475		- (*failed)++;
	472	+ stats->ls_fail++;
476	473	}
477	474
478	475	static inline void ocfs2_track_lock_refresh(struct ocfs2_lock_res *lockres)
...	...	@@ -482,8 +479,7 @@
482	479
483	480	static inline void ocfs2_init_start_time(struct ocfs2_mask_waiter *mw)
484	481	{
485		- struct timespec ts = current_kernel_time();
486		- mw->mw_lock_start = timespec_to_ns(&ts);
	482	+ mw->mw_lock_start = ktime_get();
487	483	}
488	484	#else
489	485	static inline void ocfs2_init_lock_stats(struct ocfs2_lock_res *res)
...	...	@@ -2869,8 +2865,15 @@
2869	2865	return iter;
2870	2866	}
2871	2867
2872		-/* So that debugfs.ocfs2 can determine which format is being used */
2873		-#define OCFS2_DLM_DEBUG_STR_VERSION 2
	2868	+/*
	2869	+ * Version is used by debugfs.ocfs2 to determine the format being used
	2870	+ *
	2871	+ * New in version 2
	2872	+ * - Lock stats printed
	2873	+ * New in version 3
	2874	+ * - Max time in lock stats is in usecs (instead of nsecs)
	2875	+ */
	2876	+#define OCFS2_DLM_DEBUG_STR_VERSION 3
2874	2877	static int ocfs2_dlm_seq_show(struct seq_file m, void v)
2875	2878	{
2876	2879	int i;
2877	2880
...	...	@@ -2912,18 +2915,18 @@
2912	2915	seq_printf(m, "0x%x\t", lvb[i]);
2913	2916
2914	2917	#ifdef CONFIG_OCFS2_FS_STATS
2915		-# define lock_num_prmode(_l) (_l)->l_lock_num_prmode
2916		-# define lock_num_exmode(_l) (_l)->l_lock_num_exmode
2917		-# define lock_num_prmode_failed(_l) (_l)->l_lock_num_prmode_failed
2918		-# define lock_num_exmode_failed(_l) (_l)->l_lock_num_exmode_failed
2919		-# define lock_total_prmode(_l) (_l)->l_lock_total_prmode
2920		-# define lock_total_exmode(_l) (_l)->l_lock_total_exmode
2921		-# define lock_max_prmode(_l) (_l)->l_lock_max_prmode
2922		-# define lock_max_exmode(_l) (_l)->l_lock_max_exmode
2923		-# define lock_refresh(_l) (_l)->l_lock_refresh
	2918	+# define lock_num_prmode(_l) ((_l)->l_lock_prmode.ls_gets)
	2919	+# define lock_num_exmode(_l) ((_l)->l_lock_exmode.ls_gets)
	2920	+# define lock_num_prmode_failed(_l) ((_l)->l_lock_prmode.ls_fail)
	2921	+# define lock_num_exmode_failed(_l) ((_l)->l_lock_exmode.ls_fail)
	2922	+# define lock_total_prmode(_l) ((_l)->l_lock_prmode.ls_total)
	2923	+# define lock_total_exmode(_l) ((_l)->l_lock_exmode.ls_total)
	2924	+# define lock_max_prmode(_l) ((_l)->l_lock_prmode.ls_max)
	2925	+# define lock_max_exmode(_l) ((_l)->l_lock_exmode.ls_max)
	2926	+# define lock_refresh(_l) ((_l)->l_lock_refresh)
2924	2927	#else
2925		-# define lock_num_prmode(_l) (0ULL)
2926		-# define lock_num_exmode(_l) (0ULL)
	2928	+# define lock_num_prmode(_l) (0)
	2929	+# define lock_num_exmode(_l) (0)
2927	2930	# define lock_num_prmode_failed(_l) (0)
2928	2931	# define lock_num_exmode_failed(_l) (0)
2929	2932	# define lock_total_prmode(_l) (0ULL)
...	...	@@ -2933,8 +2936,8 @@
2933	2936	# define lock_refresh(_l) (0)
2934	2937	#endif
2935	2938	/* The following seq_print was added in version 2 of this output */
2936		- seq_printf(m, "%llu\t"
2937		- "%llu\t"
	2939	+ seq_printf(m, "%u\t"
	2940	+ "%u\t"
2938	2941	"%u\t"
2939	2942	"%u\t"
2940	2943	"%llu\t"
...	...	@@ -147,6 +147,17 @@
147	147
148	148	typedef void (*ocfs2_lock_callback)(int status, unsigned long data);
149	149
	150	+#ifdef CONFIG_OCFS2_FS_STATS
	151	+struct ocfs2_lock_stats {
	152	+ u64 ls_total; /* Total wait in NSEC */
	153	+ u32 ls_gets; /* Num acquires */
	154	+ u32 ls_fail; /* Num failed acquires */
	155	+
	156	+ /* Storing max wait in usecs saves 24 bytes per inode */
	157	+ u32 ls_max; /* Max wait in USEC */
	158	+};
	159	+#endif
	160	+
150	161	struct ocfs2_lock_res {
151	162	void *l_priv;
152	163	struct ocfs2_lock_res_ops *l_ops;
...	...	@@ -182,15 +193,9 @@
182	193	struct list_head l_debug_list;
183	194
184	195	#ifdef CONFIG_OCFS2_FS_STATS
185		- unsigned long long l_lock_num_prmode; /* PR acquires */
186		- unsigned long long l_lock_num_exmode; /* EX acquires */
187		- unsigned int l_lock_num_prmode_failed; /* Failed PR gets */
188		- unsigned int l_lock_num_exmode_failed; /* Failed EX gets */
189		- unsigned long long l_lock_total_prmode; /* Tot wait for PR */
190		- unsigned long long l_lock_total_exmode; /* Tot wait for EX */
191		- unsigned int l_lock_max_prmode; /* Max wait for PR */
192		- unsigned int l_lock_max_exmode; /* Max wait for EX */
193		- unsigned int l_lock_refresh; /* Disk refreshes */
	196	+ struct ocfs2_lock_stats l_lock_prmode; /* PR mode stats */
	197	+ u32 l_lock_refresh; /* Disk refreshes */
	198	+ struct ocfs2_lock_stats l_lock_exmode; /* EX mode stats */
194	199	#endif
195	200	#ifdef CONFIG_DEBUG_LOCK_ALLOC
196	201	struct lockdep_map l_lockdep_map;