Logging: log using the log var names directly.

Currently we have to log by writing something like:

  static log_var_t log_a_b_c = LOG_VAR_INIT("a.b.c");
  log (log_a_b_c, "msg");

This is sort of annoying.  Let's just write:

  log("a.b.c", "msg");

3 files changed, 51 insertions, 155 deletions

diff --git a/include/jemalloc/internal/log.h b/include/jemalloc/internal/log.h
index 5ce8c35..9f32fb4 100644
--- a/include/jemalloc/internal/log.h
+++ b/include/jemalloc/internal/log.h
@@ -112,9 +112,10 @@ log_impl_varargs(const char *name, ...) {
 	malloc_write(buf);
 }
 
-/* Call as log(log_var, "format_string %d", arg_for_format_string); */
-#define log(log_var, ...)						\
+/* Call as log("log.var.str", "format_string %d", arg_for_format_string); */
+#define log(log_var_str, ...)						\
 do {									\
+	static log_var_t log_var = LOG_VAR_INIT(log_var_str);		\
 	log_do_begin(log_var)						\
 		log_impl_varargs((log_var).name, __VA_ARGS__);		\
 	log_do_end(log_var)						\
diff --git a/src/jemalloc.c b/src/jemalloc.c
index 1dc6682..ed47052 100644
--- a/src/jemalloc.c
+++ b/src/jemalloc.c
@@ -1974,12 +1974,7 @@ je_malloc(size_t size) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_malloc_entry = LOG_VAR_INIT(
-	    "core.malloc.entry");
-	static log_var_t log_core_malloc_exit = LOG_VAR_INIT(
-	    "core.malloc.exit");
-
-	log(log_core_malloc_entry, "size: %zu", size);
+	log("core.malloc.entry", "size: %zu", size);
 
 	static_opts_init(&sopts);
 	dynamic_opts_init(&dopts);
@@ -1995,7 +1990,7 @@ je_malloc(size_t size) {
 
 	imalloc(&sopts, &dopts);
 
-	log(log_core_malloc_exit, "result: %p", ret);
+	log("core.malloc.exit", "result: %p", ret);
 
 	return ret;
 }
@@ -2007,12 +2002,7 @@ je_posix_memalign(void **memptr, size_t alignment, size_t size) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_posix_memalign_entry = LOG_VAR_INIT(
-	    "core.posix_memalign.entry");
-	static log_var_t log_core_posix_memalign_exit = LOG_VAR_INIT(
-	    "core.posix_memalign.exit");
-
-	log(log_core_posix_memalign_entry, "mem ptr: %p, alignment: %zu, "
+	log("core.posix_memalign.entry", "mem ptr: %p, alignment: %zu, "
 	    "size: %zu", memptr, alignment, size);
 
 	static_opts_init(&sopts);
@@ -2032,7 +2022,7 @@ je_posix_memalign(void **memptr, size_t alignment, size_t size) {
 
 	ret = imalloc(&sopts, &dopts);
 
-	log(log_core_posix_memalign_exit, "result: %d, alloc ptr: %p", ret,
+	log("core.posix_memalign.exit", "result: %d, alloc ptr: %p", ret,
 	    *memptr);
 
 	return ret;
@@ -2047,12 +2037,7 @@ je_aligned_alloc(size_t alignment, size_t size) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_aligned_alloc_entry = LOG_VAR_INIT(
-	    "core.aligned_alloc.entry");
-	static log_var_t log_core_aligned_alloc_exit = LOG_VAR_INIT(
-	    "core.aligned_alloc.exit");
-
-	log(log_core_aligned_alloc_entry, "alignment: %zu, size: %zu\n",
+	log("core.aligned_alloc.entry", "alignment: %zu, size: %zu\n",
 	    alignment, size);
 
 	static_opts_init(&sopts);
@@ -2074,7 +2059,7 @@ je_aligned_alloc(size_t alignment, size_t size) {
 
 	imalloc(&sopts, &dopts);
 
-	log(log_core_aligned_alloc_exit, "result: %p", ret);
+	log("core.aligned_alloc.exit", "result: %p", ret);
 
 	return ret;
 }
@@ -2087,12 +2072,7 @@ je_calloc(size_t num, size_t size) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_calloc_entry = LOG_VAR_INIT(
-	    "core.calloc.entry");
-	static log_var_t log_core_calloc_exit = LOG_VAR_INIT(
-	    "core.calloc.exit");
-
-	log(log_core_calloc_entry, "num: %zu, size: %zu\n", num, size);
+	log("core.calloc.entry", "num: %zu, size: %zu\n", num, size);
 
 	static_opts_init(&sopts);
 	dynamic_opts_init(&dopts);
@@ -2110,7 +2090,7 @@ je_calloc(size_t num, size_t size) {
 
 	imalloc(&sopts, &dopts);
 
-	log(log_core_calloc_exit, "result: %p", ret);
+	log("core.calloc.exit", "result: %p", ret);
 
 	return ret;
 }
@@ -2245,12 +2225,7 @@ je_realloc(void *ptr, size_t size) {
 	size_t usize JEMALLOC_CC_SILENCE_INIT(0);
 	size_t old_usize = 0;
 
-	static log_var_t log_core_realloc_entry = LOG_VAR_INIT(
-	    "core.realloc.entry");
-	static log_var_t log_core_realloc_exit = LOG_VAR_INIT(
-	    "core.realloc.exit");
-
-	log(log_core_realloc_entry, "ptr: %p, size: %zu\n", ptr, size);
+	log("core.realloc.entry", "ptr: %p, size: %zu\n", ptr, size);
 
 	if (unlikely(size == 0)) {
 		if (ptr != NULL) {
@@ -2265,7 +2240,7 @@ je_realloc(void *ptr, size_t size) {
 			}
 			ifree(tsd, ptr, tcache, true);
 
-			log(log_core_realloc_exit, "result: %p", NULL);
+			log("core.realloc.exit", "result: %p", NULL);
 			return NULL;
 		}
 		size = 1;
@@ -2299,7 +2274,7 @@ je_realloc(void *ptr, size_t size) {
 	} else {
 		/* realloc(NULL, size) is equivalent to malloc(size). */
 		void *ret = je_malloc(size);
-		log(log_core_realloc_exit, "result: %p", ret);
+		log("core.realloc.exit", "result: %p", ret);
 		return ret;
 	}
 
@@ -2322,18 +2297,13 @@ je_realloc(void *ptr, size_t size) {
 	UTRACE(ptr, size, ret);
 	check_entry_exit_locking(tsdn);
 
-	log(log_core_realloc_exit, "result: %p", ret);
+	log("core.realloc.exit", "result: %p", ret);
 	return ret;
 }
 
 JEMALLOC_EXPORT void JEMALLOC_NOTHROW
 je_free(void *ptr) {
-	static log_var_t log_core_free_entry = LOG_VAR_INIT(
-	    "core.free.entry");
-	static log_var_t log_core_free_exit = LOG_VAR_INIT(
-	    "core.free.exit");
-
-	log(log_core_free_entry, "ptr: %p", ptr);
+	log("core.free.entry", "ptr: %p", ptr);
 
 	UTRACE(ptr, 0, 0);
 	if (likely(ptr != NULL)) {
@@ -2364,7 +2334,7 @@ je_free(void *ptr) {
 		}
 		check_entry_exit_locking(tsd_tsdn(tsd));
 	}
-	log(log_core_free_exit, "");
+	log("core.free.exit", "");
 }
 
 /*
@@ -2384,12 +2354,7 @@ je_memalign(size_t alignment, size_t size) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_memalign_entry = LOG_VAR_INIT(
-	    "core.memalign.entry");
-	static log_var_t log_core_memalign_exit = LOG_VAR_INIT(
-	    "core.memalign.exit");
-
-	log(log_core_memalign_entry, "alignment: %zu, size: %zu\n", alignment,
+	log("core.memalign.entry", "alignment: %zu, size: %zu\n", alignment,
 	    size);
 
 	static_opts_init(&sopts);
@@ -2410,7 +2375,7 @@ je_memalign(size_t alignment, size_t size) {
 
 	imalloc(&sopts, &dopts);
 
-	log(log_core_memalign_exit, "result: %p", ret);
+	log("core.memalign.exit", "result: %p", ret);
 	return ret;
 }
 #endif
@@ -2425,12 +2390,7 @@ je_valloc(size_t size) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_valloc_entry = LOG_VAR_INIT(
-	    "core.valloc.entry");
-	static log_var_t log_core_valloc_exit = LOG_VAR_INIT(
-	    "core.valloc.exit");
-
-	log(log_core_valloc_entry, "size: %zu\n", size);
+	log("core.valloc.entry", "size: %zu\n", size);
 
 	static_opts_init(&sopts);
 	dynamic_opts_init(&dopts);
@@ -2450,7 +2410,7 @@ je_valloc(size_t size) {
 
 	imalloc(&sopts, &dopts);
 
-	log(log_core_valloc_exit, "result: %p\n", ret);
+	log("core.valloc.exit", "result: %p\n", ret);
 	return ret;
 }
 #endif
@@ -2524,12 +2484,7 @@ je_mallocx(size_t size, int flags) {
 	static_opts_t sopts;
 	dynamic_opts_t dopts;
 
-	static log_var_t log_core_mallocx_entry = LOG_VAR_INIT(
-	    "core.mallocx.entry");
-	static log_var_t log_core_mallocx_exit = LOG_VAR_INIT(
-	    "core.mallocx.exit");
-
-	log(log_core_mallocx_entry, "size: %zu, flags: %d", size, flags);
+	log("core.mallocx.entry", "size: %zu, flags: %d", size, flags);
 
 	static_opts_init(&sopts);
 	dynamic_opts_init(&dopts);
@@ -2565,7 +2520,7 @@ je_mallocx(size_t size, int flags) {
 
 	imalloc(&sopts, &dopts);
 
-	log(log_core_mallocx_exit, "result: %p", ret);
+	log("core.mallocx.exit", "result: %p", ret);
 	return ret;
 }
 
@@ -2646,12 +2601,7 @@ je_rallocx(void *ptr, size_t size, int flags) {
 	arena_t *arena;
 	tcache_t *tcache;
 
-	static log_var_t log_core_rallocx_entry = LOG_VAR_INIT(
-	    "core.rallocx.entry");
-	static log_var_t log_core_rallocx_exit = LOG_VAR_INIT(
-	    "core.rallocx.exit");
-
-	log(log_core_rallocx_entry, "ptr: %p, size: %zu, flags: %d", ptr,
+	log("core.rallocx.entry", "ptr: %p, size: %zu, flags: %d", ptr,
 	    size, flags);
 
 
@@ -2718,7 +2668,7 @@ je_rallocx(void *ptr, size_t size, int flags) {
 	UTRACE(ptr, size, p);
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_rallocx_exit, "result: %p", p);
+	log("core.rallocx.exit", "result: %p", p);
 	return p;
 label_oom:
 	if (config_xmalloc && unlikely(opt_xmalloc)) {
@@ -2728,7 +2678,7 @@ label_oom:
 	UTRACE(ptr, size, 0);
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_rallocx_exit, "result: %p", NULL);
+	log("core.rallocx.exit", "result: %p", NULL);
 	return NULL;
 }
 
@@ -2815,15 +2765,9 @@ je_xallocx(void *ptr, size_t size, size_t extra, int flags) {
 	size_t alignment = MALLOCX_ALIGN_GET(flags);
 	bool zero = flags & MALLOCX_ZERO;
 
-	static log_var_t log_core_xallocx_entry = LOG_VAR_INIT(
-	    "core.xallocx.entry");
-	static log_var_t log_core_xallocx_exit = LOG_VAR_INIT(
-	    "core.xallocx.exit");
-
-	log(log_core_xallocx_entry, "ptr: %p, size: %zu, extra: %zu, "
+	log("core.xallocx.entry", "ptr: %p, size: %zu, extra: %zu, "
 	    "flags: %d", ptr, size, extra, flags);
 
-
 	assert(ptr != NULL);
 	assert(size != 0);
 	assert(SIZE_T_MAX - size >= extra);
@@ -2874,7 +2818,7 @@ label_not_resized:
 	UTRACE(ptr, size, ptr);
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_xallocx_exit, "result: %zu", usize);
+	log("core.xallocx.exit", "result: %zu", usize);
 	return usize;
 }
 
@@ -2884,12 +2828,7 @@ je_sallocx(const void *ptr, int flags) {
 	size_t usize;
 	tsdn_t *tsdn;
 
-	static log_var_t log_core_sallocx_entry = LOG_VAR_INIT(
-	    "core.sallocx.entry");
-	static log_var_t log_core_sallocx_exit = LOG_VAR_INIT(
-	    "core.sallocx.exit");
-
-	log(log_core_sallocx_entry, "ptr: %p, flags: %d", ptr, flags);
+	log("core.sallocx.entry", "ptr: %p, flags: %d", ptr, flags);
 
 	assert(malloc_initialized() || IS_INITIALIZER);
 	assert(ptr != NULL);
@@ -2906,18 +2845,13 @@ je_sallocx(const void *ptr, int flags) {
 
 	check_entry_exit_locking(tsdn);
 
-	log(log_core_sallocx_exit, "result: %zu", usize);
+	log("core.sallocx.exit", "result: %zu", usize);
 	return usize;
 }
 
 JEMALLOC_EXPORT void JEMALLOC_NOTHROW
 je_dallocx(void *ptr, int flags) {
-	static log_var_t log_core_dallocx_entry = LOG_VAR_INIT(
-	    "core.dallocx.entry");
-	static log_var_t log_core_dallocx_exit = LOG_VAR_INIT(
-	    "core.dallocx.exit");
-
-	log(log_core_dallocx_entry, "ptr: %p, flags: %d", ptr, flags);
+	log("core.dallocx.entry", "ptr: %p, flags: %d", ptr, flags);
 
 	assert(ptr != NULL);
 	assert(malloc_initialized() || IS_INITIALIZER);
@@ -2957,7 +2891,7 @@ je_dallocx(void *ptr, int flags) {
 	}
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_dallocx_exit, "");
+	log("core.dallocx.exit", "");
 }
 
 JEMALLOC_ALWAYS_INLINE size_t
@@ -2979,12 +2913,7 @@ je_sdallocx(void *ptr, size_t size, int flags) {
 	assert(ptr != NULL);
 	assert(malloc_initialized() || IS_INITIALIZER);
 
-	static log_var_t log_core_sdallocx_entry = LOG_VAR_INIT(
-	    "core.sdallocx.entry");
-	static log_var_t log_core_sdallocx_exit = LOG_VAR_INIT(
-	    "core.sdallocx.exit");
-
-	log(log_core_sdallocx_entry, "ptr: %p, size: %zu, flags: %d", ptr,
+	log("core.sdallocx.entry", "ptr: %p, size: %zu, flags: %d", ptr,
 	    size, flags);
 
 	tsd_t *tsd = tsd_fetch();
@@ -3024,7 +2953,7 @@ je_sdallocx(void *ptr, size_t size, int flags) {
 	}
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_sdallocx_exit, "");
+	log("core.sdallocx.exit", "");
 }
 
 JEMALLOC_EXPORT size_t JEMALLOC_NOTHROW
@@ -3033,17 +2962,10 @@ je_nallocx(size_t size, int flags) {
 	size_t usize;
 	tsdn_t *tsdn;
 
-	static log_var_t log_core_nallocx_entry = LOG_VAR_INIT(
-	    "core.nallocx.entry");
-	static log_var_t log_core_nallocx_exit = LOG_VAR_INIT(
-	    "core.nallocx.exit");
-
-	log(log_core_nallocx_entry, "size: %zu, flags: %d", size, flags);
-
 	assert(size != 0);
 
 	if (unlikely(malloc_init())) {
-		log(log_core_nallocx_exit, "result: %zu", ZU(0));
+		log("core.nallocx.exit", "result: %zu", ZU(0));
 		return 0;
 	}
 
@@ -3052,12 +2974,12 @@ je_nallocx(size_t size, int flags) {
 
 	usize = inallocx(tsdn, size, flags);
 	if (unlikely(usize > LARGE_MAXCLASS)) {
-		log(log_core_nallocx_exit, "result: %zu", ZU(0));
+		log("core.nallocx.exit", "result: %zu", ZU(0));
 		return 0;
 	}
 
 	check_entry_exit_locking(tsdn);
-	log(log_core_nallocx_exit, "result: %zu", usize);
+	log("core.nallocx.exit", "result: %zu", usize);
 	return usize;
 }
 
@@ -3067,15 +2989,10 @@ je_mallctl(const char *name, void *oldp, size_t *oldlenp, void *newp,
 	int ret;
 	tsd_t *tsd;
 
-	static log_var_t log_core_mallctl_entry = LOG_VAR_INIT(
-	    "core.mallctl.entry");
-	static log_var_t log_core_mallctl_exit = LOG_VAR_INIT(
-	    "core.mallctl.exit");
-
-	log(log_core_mallctl_entry, "name: %s", name);
+	log("core.mallctl.entry", "name: %s", name);
 
 	if (unlikely(malloc_init())) {
-		log(log_core_mallctl_exit, "result: %d", EAGAIN);
+		log("core.mallctl.exit", "result: %d", EAGAIN);
 		return EAGAIN;
 	}
 
@@ -3084,7 +3001,7 @@ je_mallctl(const char *name, void *oldp, size_t *oldlenp, void *newp,
 	ret = ctl_byname(tsd, name, oldp, oldlenp, newp, newlen);
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_mallctl_exit, "result: %d", ret);
+	log("core.mallctl.exit", "result: %d", ret);
 	return ret;
 }
 
@@ -3092,15 +3009,10 @@ JEMALLOC_EXPORT int JEMALLOC_NOTHROW
 je_mallctlnametomib(const char *name, size_t *mibp, size_t *miblenp) {
 	int ret;
 
-	static log_var_t log_core_mallctlnametomib_entry = LOG_VAR_INIT(
-	    "core.mallctlnametomib.entry");
-	static log_var_t log_core_mallctlnametomib_exit = LOG_VAR_INIT(
-	    "core.mallctlnametomib.exit");
-
-	log(log_core_mallctlnametomib_entry, "name: %s", name);
+	log("core.mallctlnametomib.entry", "name: %s", name);
 
 	if (unlikely(malloc_init())) {
-		log(log_core_mallctlnametomib_exit, "result: %d", EAGAIN);
+		log("core.mallctlnametomib.exit", "result: %d", EAGAIN);
 		return EAGAIN;
 	}
 
@@ -3109,7 +3021,7 @@ je_mallctlnametomib(const char *name, size_t *mibp, size_t *miblenp) {
 	ret = ctl_nametomib(tsd, name, mibp, miblenp);
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_mallctlnametomib_exit, "result: %d", ret);
+	log("core.mallctlnametomib.exit", "result: %d", ret);
 	return ret;
 }
 
@@ -3119,16 +3031,10 @@ je_mallctlbymib(const size_t *mib, size_t miblen, void *oldp, size_t *oldlenp,
 	int ret;
 	tsd_t *tsd;
 
-	static log_var_t log_core_mallctlbymib_entry = LOG_VAR_INIT(
-	    "core.mallctlbymib.entry");
-	static log_var_t log_core_mallctlbymib_exit = LOG_VAR_INIT(
-	    "core.mallctlbymib.exit");
-
-	log(log_core_mallctlbymib_entry, "");
-
+	log("core.mallctlbymib.entry", "");
 
 	if (unlikely(malloc_init())) {
-		log(log_core_mallctlbymib_exit, "result: %d", EAGAIN);
+		log("core.mallctlbymib.exit", "result: %d", EAGAIN);
 		return EAGAIN;
 	}
 
@@ -3136,7 +3042,7 @@ je_mallctlbymib(const size_t *mib, size_t miblen, void *oldp, size_t *oldlenp,
 	check_entry_exit_locking(tsd_tsdn(tsd));
 	ret = ctl_bymib(tsd, mib, miblen, oldp, oldlenp, newp, newlen);
 	check_entry_exit_locking(tsd_tsdn(tsd));
-	log(log_core_mallctlbymib_exit, "result: %d", ret);
+	log("core.mallctlbymib.exit", "result: %d", ret);
 	return ret;
 }
 
@@ -3145,18 +3051,13 @@ je_malloc_stats_print(void (*write_cb)(void *, const char *), void *cbopaque,
     const char *opts) {
 	tsdn_t *tsdn;
 
-	static log_var_t log_core_malloc_stats_print_entry = LOG_VAR_INIT(
-	    "core.malloc_stats_print.entry");
-	static log_var_t log_core_malloc_stats_print_exit = LOG_VAR_INIT(
-	    "core.malloc_stats_print.exit");
-
-	log(log_core_malloc_stats_print_entry, "");
+	log("core.malloc_stats_print.entry", "");
 
 	tsdn = tsdn_fetch();
 	check_entry_exit_locking(tsdn);
 	stats_print(write_cb, cbopaque, opts);
 	check_entry_exit_locking(tsdn);
-	log(log_core_malloc_stats_print_exit, "");
+	log("core.malloc_stats_print.exit", "");
 }
 
 JEMALLOC_EXPORT size_t JEMALLOC_NOTHROW
@@ -3164,12 +3065,7 @@ je_malloc_usable_size(JEMALLOC_USABLE_SIZE_CONST void *ptr) {
 	size_t ret;
 	tsdn_t *tsdn;
 
-	static log_var_t log_core_malloc_usable_size_entry = LOG_VAR_INIT(
-	    "core.malloc_usable_size.entry");
-	static log_var_t log_core_malloc_usable_size_exit = LOG_VAR_INIT(
-	    "core.malloc_usable_size.exit");
-
-	log(log_core_malloc_usable_size_entry, "ptr: %p", ptr);
+	log("core.malloc_usable_size.entry", "ptr: %p", ptr);
 
 	assert(malloc_initialized() || IS_INITIALIZER);
 
@@ -3188,7 +3084,7 @@ je_malloc_usable_size(JEMALLOC_USABLE_SIZE_CONST void *ptr) {
 	}
 
 	check_entry_exit_locking(tsdn);
-	log(log_core_malloc_usable_size_exit, "result: %zu", ret);
+	log("core.malloc_usable_size.exit", "result: %zu", ret);
 	return ret;
 }
 
diff --git a/test/unit/log.c b/test/unit/log.c
index 053fea4..3c1a208 100644
--- a/test/unit/log.c
+++ b/test/unit/log.c
@@ -176,8 +176,7 @@ TEST_END
  */
 TEST_BEGIN(test_log_only_format_string) {
 	if (false) {
-		static log_var_t l = LOG_VAR_INIT("str");
-		log(l, "No arguments follow this format string.");
+		log("log_str", "No arguments follow this format string.");
 	}
 }
 TEST_END