Add background thread related stats.

9 files changed, 214 insertions, 21 deletions

diff --git a/include/jemalloc/internal/background_thread_externs.h b/include/jemalloc/internal/background_thread_externs.h
index 993f0e3..fe25acf 100644
--- a/include/jemalloc/internal/background_thread_externs.h
+++ b/include/jemalloc/internal/background_thread_externs.h
@@ -19,6 +19,8 @@ void background_thread_prefork0(tsdn_t *tsdn);
 void background_thread_prefork1(tsdn_t *tsdn);
 void background_thread_postfork_parent(tsdn_t *tsdn);
 void background_thread_postfork_child(tsdn_t *tsdn);
+bool background_thread_stats_read(tsdn_t *tsdn,
+    background_thread_stats_t *stats);
 
 #if defined(JEMALLOC_BACKGROUND_THREAD) || defined(JEMALLOC_LAZY_LOCK)
 extern int (*pthread_create_fptr)(pthread_t *__restrict, const pthread_attr_t *,
diff --git a/include/jemalloc/internal/background_thread_structs.h b/include/jemalloc/internal/background_thread_structs.h
index a43d600..c4eb827 100644
--- a/include/jemalloc/internal/background_thread_structs.h
+++ b/include/jemalloc/internal/background_thread_structs.h
@@ -18,8 +18,19 @@ struct background_thread_info_s {
 	 *  background thread to wake up earlier.
 	 */
 	size_t			npages_to_purge_new;
+	/* Stats: total number of runs since started. */
+	uint64_t		tot_n_runs;
+	/* Stats: total sleep time since started. */
+	nstime_t		tot_sleep_time;
 #endif /* ifdef JEMALLOC_BACKGROUND_THREAD */
 };
 typedef struct background_thread_info_s background_thread_info_t;
 
+struct background_thread_stats_s {
+	size_t num_threads;
+	uint64_t num_runs;
+	nstime_t run_interval;
+};
+typedef struct background_thread_stats_s background_thread_stats_t;
+
 #endif /* JEMALLOC_INTERNAL_BACKGROUND_THREAD_STRUCTS_H */
diff --git a/include/jemalloc/internal/ctl.h b/include/jemalloc/internal/ctl.h
index 60b3979..f159383 100644
--- a/include/jemalloc/internal/ctl.h
+++ b/include/jemalloc/internal/ctl.h
@@ -52,6 +52,7 @@ typedef struct ctl_stats_s {
 	size_t mapped;
 	size_t retained;
 
+	background_thread_stats_t background_thread;
 	mutex_prof_data_t mutex_prof_data[mutex_prof_num_global_mutexes];
 } ctl_stats_t;
 
diff --git a/include/jemalloc/internal/nstime.h b/include/jemalloc/internal/nstime.h
index ad7efb8..17c177c 100644
--- a/include/jemalloc/internal/nstime.h
+++ b/include/jemalloc/internal/nstime.h
@@ -18,7 +18,9 @@ uint64_t nstime_nsec(const nstime_t *time);
 void nstime_copy(nstime_t *time, const nstime_t *source);
 int nstime_compare(const nstime_t *a, const nstime_t *b);
 void nstime_add(nstime_t *time, const nstime_t *addend);
+void nstime_iadd(nstime_t *time, uint64_t addend);
 void nstime_subtract(nstime_t *time, const nstime_t *subtrahend);
+void nstime_isubtract(nstime_t *time, uint64_t subtrahend);
 void nstime_imultiply(nstime_t *time, uint64_t multiplier);
 void nstime_idivide(nstime_t *time, uint64_t divisor);
 uint64_t nstime_divide(const nstime_t *time, const nstime_t *divisor);
diff --git a/src/background_thread.c b/src/background_thread.c
index 671e57f..076d981 100644
--- a/src/background_thread.c
+++ b/src/background_thread.c
@@ -36,8 +36,21 @@ void background_thread_prefork0(tsdn_t *tsdn) NOT_REACHED
 void background_thread_prefork1(tsdn_t *tsdn) NOT_REACHED
 void background_thread_postfork_parent(tsdn_t *tsdn) NOT_REACHED
 void background_thread_postfork_child(tsdn_t *tsdn) NOT_REACHED
+bool background_thread_stats_read(tsdn_t *tsdn,
+    background_thread_stats_t *stats) NOT_REACHED
 #undef NOT_REACHED
 #else
+
+static void
+background_thread_info_reinit(background_thread_info_t *info) {
+	nstime_init(&info->next_wakeup, 0);
+	info->npages_to_purge_new = 0;
+	if (config_stats) {
+		info->tot_n_runs = 0;
+		nstime_init(&info->tot_sleep_time, 0);
+	}
+}
+
 bool
 background_threads_init(tsd_t *tsd) {
 	assert(have_background_thread);
@@ -68,8 +81,7 @@ background_threads_init(tsd_t *tsd) {
 			return true;
 		}
 		info->started = false;
-		nstime_init(&info->next_wakeup, 0);
-		info->npages_to_purge_new = 0;
+		background_thread_info_reinit(info);
 	}
 
 	return false;
@@ -248,33 +260,49 @@ background_work(tsdn_t *tsdn, unsigned ind) {
 	malloc_mutex_lock(tsdn, &info->mtx);
 	while (info->started) {
 		uint64_t interval = background_work_once(tsdn, ind);
+		if (config_stats) {
+			info->tot_n_runs++;
+		}
 		info->npages_to_purge_new = 0;
 
+		struct timeval tv;
+		gettimeofday(&tv, NULL);
+		nstime_t before_sleep;
+		nstime_init2(&before_sleep, tv.tv_sec, tv.tv_usec * 1000);
+
 		if (interval == BACKGROUND_THREAD_INDEFINITE_SLEEP) {
 			nstime_init(&info->next_wakeup,
 			    BACKGROUND_THREAD_INDEFINITE_SLEEP);
 			ret = pthread_cond_wait(&info->cond, &info->mtx.lock);
 			assert(ret == 0);
-			continue;
+		} else {
+			assert(interval >= BACKGROUND_THREAD_MIN_INTERVAL_NS &&
+			    interval <= BACKGROUND_THREAD_INDEFINITE_SLEEP);
+			nstime_init(&info->next_wakeup, 0);
+			nstime_update(&info->next_wakeup);
+			nstime_iadd(&info->next_wakeup, interval);
+
+			nstime_t ts_wakeup;
+			nstime_copy(&ts_wakeup, &before_sleep);
+			nstime_iadd(&ts_wakeup, interval);
+			struct timespec ts;
+			ts.tv_sec = (size_t)nstime_sec(&ts_wakeup);
+			ts.tv_nsec = (size_t)nstime_nsec(&ts_wakeup);
+
+			ret = pthread_cond_timedwait(&info->cond,
+			    &info->mtx.lock, &ts);
+			assert(ret == ETIMEDOUT || ret == 0);
 		}
 
-		assert(interval >= BACKGROUND_THREAD_MIN_INTERVAL_NS &&
-		    interval <= BACKGROUND_THREAD_INDEFINITE_SLEEP);
-		nstime_init(&info->next_wakeup, 0);
-		nstime_update(&info->next_wakeup);
-		info->next_wakeup.ns += interval;
-
-		nstime_t ts_wakeup;
-		struct timeval tv;
-		gettimeofday(&tv, NULL);
-		nstime_init2(&ts_wakeup, tv.tv_sec,
-		    tv.tv_usec * 1000 + interval);
-		struct timespec ts;
-		ts.tv_sec = (size_t)nstime_sec(&ts_wakeup);
-		ts.tv_nsec = (size_t)nstime_nsec(&ts_wakeup);
-		ret = pthread_cond_timedwait(&info->cond, &info->mtx.lock,
-		    &ts);
-		assert(ret == ETIMEDOUT || ret == 0);
+		if (config_stats) {
+			gettimeofday(&tv, NULL);
+			nstime_t after_sleep;
+			nstime_init2(&after_sleep, tv.tv_sec, tv.tv_usec * 1000);
+			if (nstime_compare(&after_sleep, &before_sleep) > 0) {
+				nstime_subtract(&after_sleep, &before_sleep);
+				nstime_add(&info->tot_sleep_time, &after_sleep);
+			}
+		}
 	}
 	malloc_mutex_unlock(tsdn, &info->mtx);
 }
@@ -332,6 +360,7 @@ background_thread_create(tsd_t *tsd, unsigned arena_ind) {
 	assert(info->started == false);
 	if (err == 0) {
 		info->started = true;
+		background_thread_info_reinit(info);
 		n_background_threads++;
 	}
 	malloc_mutex_unlock(tsd_tsdn(tsd), &info->mtx);
@@ -540,6 +569,36 @@ background_thread_postfork_child(tsdn_t *tsdn) {
 	malloc_mutex_unlock(tsdn, &background_thread_lock);
 }
 
+bool
+background_thread_stats_read(tsdn_t *tsdn, background_thread_stats_t *stats) {
+	assert(config_stats);
+	malloc_mutex_lock(tsdn, &background_thread_lock);
+	if (!background_thread_enabled()) {
+		malloc_mutex_unlock(tsdn, &background_thread_lock);
+		return true;
+	}
+
+	stats->num_threads = n_background_threads;
+	uint64_t num_runs = 0;
+	nstime_init(&stats->run_interval, 0);
+	for (unsigned i = 0; i < ncpus; i++) {
+		background_thread_info_t *info = &background_thread_info[i];
+		malloc_mutex_lock(tsdn, &info->mtx);
+		if (info->started) {
+			num_runs += info->tot_n_runs;
+			nstime_add(&stats->run_interval, &info->tot_sleep_time);
+		}
+		malloc_mutex_unlock(tsdn, &info->mtx);
+	}
+	stats->num_runs = num_runs;
+	if (num_runs > 0) {
+		nstime_idivide(&stats->run_interval, num_runs);
+	}
+	malloc_mutex_unlock(tsdn, &background_thread_lock);
+
+	return false;
+}
+
 #undef BACKGROUND_THREAD_NPAGES_THRESHOLD
 #undef BILLION
 #undef BACKGROUND_THREAD_MIN_INTERVAL_NS
diff --git a/src/ctl.c b/src/ctl.c
index ee0979a..caa9f3e 100644
--- a/src/ctl.c
+++ b/src/ctl.c
@@ -181,6 +181,9 @@ CTL_PROTO(stats_arenas_i_resident)
 INDEX_PROTO(stats_arenas_i)
 CTL_PROTO(stats_allocated)
 CTL_PROTO(stats_active)
+CTL_PROTO(stats_background_thread_num_threads)
+CTL_PROTO(stats_background_thread_num_runs)
+CTL_PROTO(stats_background_thread_run_interval)
 CTL_PROTO(stats_metadata)
 CTL_PROTO(stats_resident)
 CTL_PROTO(stats_mapped)
@@ -478,6 +481,12 @@ static const ctl_indexed_node_t stats_arenas_node[] = {
 	{INDEX(stats_arenas_i)}
 };
 
+static const ctl_named_node_t stats_background_thread_node[] = {
+	{NAME("num_threads"),	CTL(stats_background_thread_num_threads)},
+	{NAME("num_runs"),	CTL(stats_background_thread_num_runs)},
+	{NAME("run_interval"),	CTL(stats_background_thread_run_interval)}
+};
+
 #define OP(mtx) MUTEX_PROF_DATA_NODE(mutexes_##mtx)
 MUTEX_PROF_GLOBAL_MUTEXES
 #undef OP
@@ -497,6 +506,8 @@ static const ctl_named_node_t stats_node[] = {
 	{NAME("resident"),	CTL(stats_resident)},
 	{NAME("mapped"),	CTL(stats_mapped)},
 	{NAME("retained"),	CTL(stats_retained)},
+	{NAME("background_thread"),
+	 CHILD(named, stats_background_thread)},
 	{NAME("mutexes"),	CHILD(named, stats_mutexes)},
 	{NAME("arenas"),	CHILD(indexed, stats_arenas)}
 };
@@ -873,6 +884,16 @@ ctl_arena_init(tsdn_t *tsdn, extent_hooks_t *extent_hooks) {
 }
 
 static void
+ctl_background_thread_stats_read(tsdn_t *tsdn) {
+	background_thread_stats_t *stats = &ctl_stats->background_thread;
+	if (!have_background_thread ||
+	    background_thread_stats_read(tsdn, stats)) {
+		memset(stats, 0, sizeof(background_thread_stats_t));
+		nstime_init(&stats->run_interval, 0);
+	}
+}
+
+static void
 ctl_refresh(tsdn_t *tsdn) {
 	unsigned i;
 	ctl_arena_t *ctl_sarena = arenas_i(MALLCTL_ARENAS_ALL);
@@ -915,6 +936,8 @@ ctl_refresh(tsdn_t *tsdn) {
 		ctl_stats->retained = atomic_load_zu(
 		    &ctl_sarena->astats->astats.retained, ATOMIC_RELAXED);
 
+		ctl_background_thread_stats_read(tsdn);
+
 #define READ_GLOBAL_MUTEX_PROF_DATA(i, mtx)				\
     malloc_mutex_lock(tsdn, &mtx);					\
     malloc_mutex_prof_read(tsdn, &ctl_stats->mutex_prof_data[i], &mtx);	\
@@ -2403,6 +2426,13 @@ CTL_RO_CGEN(config_stats, stats_resident, ctl_stats->resident, size_t)
 CTL_RO_CGEN(config_stats, stats_mapped, ctl_stats->mapped, size_t)
 CTL_RO_CGEN(config_stats, stats_retained, ctl_stats->retained, size_t)
 
+CTL_RO_CGEN(config_stats, stats_background_thread_num_threads,
+    ctl_stats->background_thread.num_threads, size_t)
+CTL_RO_CGEN(config_stats, stats_background_thread_num_runs,
+    ctl_stats->background_thread.num_runs, uint64_t)
+CTL_RO_CGEN(config_stats, stats_background_thread_run_interval,
+    nstime_ns(&ctl_stats->background_thread.run_interval), uint64_t)
+
 CTL_RO_GEN(stats_arenas_i_dss, arenas_i(mib[2])->dss, const char *)
 CTL_RO_GEN(stats_arenas_i_dirty_decay_ms, arenas_i(mib[2])->dirty_decay_ms,
     ssize_t)
diff --git a/src/nstime.c b/src/nstime.c
index e541227..71db353 100644
--- a/src/nstime.c
+++ b/src/nstime.c
@@ -56,6 +56,13 @@ nstime_add(nstime_t *time, const nstime_t *addend) {
 }
 
 void
+nstime_iadd(nstime_t *time, uint64_t addend) {
+	assert(UINT64_MAX - time->ns >= addend);
+
+	time->ns += addend;
+}
+
+void
 nstime_subtract(nstime_t *time, const nstime_t *subtrahend) {
 	assert(nstime_compare(time, subtrahend) >= 0);
 
@@ -63,6 +70,13 @@ nstime_subtract(nstime_t *time, const nstime_t *subtrahend) {
 }
 
 void
+nstime_isubtract(nstime_t *time, uint64_t subtrahend) {
+	assert(time->ns >= subtrahend);
+
+	time->ns -= subtrahend;
+}
+
+void
 nstime_imultiply(nstime_t *time, uint64_t multiplier) {
 	assert((((time->ns | multiplier) & (UINT64_MAX << (sizeof(uint64_t) <<
 	    2))) == 0) || ((time->ns * multiplier) / multiplier == time->ns));
diff --git a/src/stats.c b/src/stats.c
index f98b8ec..fd10816 100644
--- a/src/stats.c
+++ b/src/stats.c
@@ -1013,6 +1013,8 @@ stats_print_helper(void (*write_cb)(void *, const char *), void *cbopaque,
     bool json, bool merged, bool destroyed, bool unmerged, bool bins,
     bool large, bool mutex) {
 	size_t allocated, active, metadata, resident, mapped, retained;
+	size_t num_background_threads;
+	uint64_t background_thread_num_runs, background_thread_run_interval;
 
 	CTL_GET("stats.allocated", &allocated, size_t);
 	CTL_GET("stats.active", &active, size_t);
@@ -1026,6 +1028,19 @@ stats_print_helper(void (*write_cb)(void *, const char *), void *cbopaque,
 		read_global_mutex_stats(mutex_stats);
 	}
 
+	if (have_background_thread) {
+		CTL_GET("stats.background_thread.num_threads",
+		    &num_background_threads, size_t);
+		CTL_GET("stats.background_thread.num_runs",
+		    &background_thread_num_runs, uint64_t);
+		CTL_GET("stats.background_thread.run_interval",
+		    &background_thread_run_interval, uint64_t);
+	} else {
+		num_background_threads = 0;
+		background_thread_num_runs = 0;
+		background_thread_run_interval = 0;
+	}
+
 	if (json) {
 		malloc_cprintf(write_cb, cbopaque,
 		    "\t\t\"stats\": {\n");
@@ -1041,7 +1056,21 @@ stats_print_helper(void (*write_cb)(void *, const char *), void *cbopaque,
 		malloc_cprintf(write_cb, cbopaque,
 		    "\t\t\t\"mapped\": %zu,\n", mapped);
 		malloc_cprintf(write_cb, cbopaque,
-		    "\t\t\t\"retained\": %zu%s\n", retained, mutex ? "," : "");
+		    "\t\t\t\"retained\": %zu,\n", retained);
+
+		malloc_cprintf(write_cb, cbopaque,
+		    "\t\t\t\"background_thread\": {\n");
+		malloc_cprintf(write_cb, cbopaque,
+		    "\t\t\t\t\"num_threads\": %zu,\n", num_background_threads);
+		malloc_cprintf(write_cb, cbopaque,
+		    "\t\t\t\t\"num_runs\": %"FMTu64",\n",
+		    background_thread_num_runs);
+		malloc_cprintf(write_cb, cbopaque,
+		    "\t\t\t\t\"run_interval\": %"FMTu64"\n",
+		    background_thread_run_interval);
+		malloc_cprintf(write_cb, cbopaque, "\t\t\t}%s\n",
+		    mutex ? "," : "");
+
 		if (mutex) {
 			malloc_cprintf(write_cb, cbopaque,
 			    "\t\t\t\"mutexes\": {\n");
@@ -1061,6 +1090,15 @@ stats_print_helper(void (*write_cb)(void *, const char *), void *cbopaque,
 		    "Allocated: %zu, active: %zu, metadata: %zu,"
 		    " resident: %zu, mapped: %zu, retained: %zu\n",
 		    allocated, active, metadata, resident, mapped, retained);
+
+		if (have_background_thread && num_background_threads > 0) {
+			malloc_cprintf(write_cb, cbopaque,
+			    "Background threads: %zu, num_runs: %"FMTu64", "
+			    "run_interval: %"FMTu64" ns\n",
+			    num_background_threads,
+			    background_thread_num_runs,
+			    background_thread_run_interval);
+		}
 		if (mutex) {
 			mutex_prof_global_ind_t i;
 			for (i = 0; i < mutex_prof_num_global_mutexes; i++) {
diff --git a/test/unit/nstime.c b/test/unit/nstime.c
index f8384f5..f313780 100644
--- a/test/unit/nstime.c
+++ b/test/unit/nstime.c
@@ -85,6 +85,23 @@ TEST_BEGIN(test_nstime_add) {
 }
 TEST_END
 
+TEST_BEGIN(test_nstime_iadd) {
+	nstime_t nsta, nstb;
+
+	nstime_init2(&nsta, 42, BILLION - 1);
+	nstime_iadd(&nsta, 1);
+	nstime_init2(&nstb, 43, 0);
+	assert_d_eq(nstime_compare(&nsta, &nstb), 0,
+	    "Incorrect addition result");
+
+	nstime_init2(&nsta, 42, 1);
+	nstime_iadd(&nsta, BILLION + 1);
+	nstime_init2(&nstb, 43, 2);
+	assert_d_eq(nstime_compare(&nsta, &nstb), 0,
+	    "Incorrect addition result");
+}
+TEST_END
+
 TEST_BEGIN(test_nstime_subtract) {
 	nstime_t nsta, nstb;
 
@@ -104,6 +121,23 @@ TEST_BEGIN(test_nstime_subtract) {
 }
 TEST_END
 
+TEST_BEGIN(test_nstime_isubtract) {
+	nstime_t nsta, nstb;
+
+	nstime_init2(&nsta, 42, 43);
+	nstime_isubtract(&nsta, 42*BILLION + 43);
+	nstime_init(&nstb, 0);
+	assert_d_eq(nstime_compare(&nsta, &nstb), 0,
+	    "Incorrect subtraction result");
+
+	nstime_init2(&nsta, 42, 43);
+	nstime_isubtract(&nsta, 41*BILLION + 44);
+	nstime_init2(&nstb, 0, BILLION - 1);
+	assert_d_eq(nstime_compare(&nsta, &nstb), 0,
+	    "Incorrect subtraction result");
+}
+TEST_END
+
 TEST_BEGIN(test_nstime_imultiply) {
 	nstime_t nsta, nstb;
 
@@ -204,7 +238,9 @@ main(void) {
 	    test_nstime_copy,
 	    test_nstime_compare,
 	    test_nstime_add,
+	    test_nstime_iadd,
 	    test_nstime_subtract,
+	    test_nstime_isubtract,
 	    test_nstime_imultiply,
 	    test_nstime_idivide,
 	    test_nstime_divide,