Logging: allow logging with empty varargs.

Currently, the log macro requires at least one argument after the format string,
because of the way the preprocessor handles varargs macros.  We can hide some of
that irritation by pushing the extra arguments into a varargs function.

7 files changed, 65 insertions, 17 deletions

diff --git a/configure.ac b/configure.ac
index 0215154..ba0409a 100644
--- a/configure.ac
+++ b/configure.ac
@@ -243,6 +243,7 @@ if test "x$GCC" = "xyes" ; then
   JE_CFLAGS_ADD([-Wshorten-64-to-32])
   JE_CFLAGS_ADD([-Wsign-compare])
   JE_CFLAGS_ADD([-Wundef])
+  JE_CFLAGS_ADD([-Wno-format-zero-length])
   JE_CFLAGS_ADD([-pipe])
   JE_CFLAGS_ADD([-g3])
 elif test "x$je_cv_msvc" = "xyes" ; then
diff --git a/include/jemalloc/internal/jemalloc_internal_macros.h b/include/jemalloc/internal/jemalloc_internal_macros.h
index 4571895..ed75d37 100644
--- a/include/jemalloc/internal/jemalloc_internal_macros.h
+++ b/include/jemalloc/internal/jemalloc_internal_macros.h
@@ -37,4 +37,7 @@
 #  define JET_MUTABLE const
 #endif
 
+#define JEMALLOC_VA_ARGS_HEAD(head, ...) head
+#define JEMALLOC_VA_ARGS_TAIL(head, ...) __VA_ARGS__
+
 #endif /* JEMALLOC_INTERNAL_MACROS_H */
diff --git a/include/jemalloc/internal/log.h b/include/jemalloc/internal/log.h
index 1df8cff..5ce8c35 100644
--- a/include/jemalloc/internal/log.h
+++ b/include/jemalloc/internal/log.h
@@ -2,14 +2,17 @@
 #define JEMALLOC_INTERNAL_LOG_H
 
 #include "jemalloc/internal/atomic.h"
+#include "jemalloc/internal/malloc_io.h"
 #include "jemalloc/internal/mutex.h"
 
 #ifdef JEMALLOC_LOG
-#  define JEMALLOC_LOG_BUFSIZE 1000
+#  define JEMALLOC_LOG_VAR_BUFSIZE 1000
 #else
-#  define JEMALLOC_LOG_BUFSIZE 1
+#  define JEMALLOC_LOG_VAR_BUFSIZE 1
 #endif
 
+#define JEMALLOC_LOG_BUFSIZE 4096
+
 /*
  * The log_vars malloc_conf option is a '|'-delimited list of log_var name
  * segments to log.  The log_var names are themselves hierarchical, with '.' as
@@ -41,7 +44,7 @@
  * statements.
  */
 
-extern char log_var_names[JEMALLOC_LOG_BUFSIZE];
+extern char log_var_names[JEMALLOC_LOG_VAR_BUFSIZE];
 extern atomic_b_t log_init_done;
 
 typedef struct log_var_s log_var_t;
@@ -84,11 +87,36 @@ if (config_log) {							\
 	}								\
 }
 
-#define log(log_var, format, ...)					\
+/*
+ * MSVC has some preprocessor bugs in its expansion of __VA_ARGS__ during
+ * preprocessing.  To work around this, we take all potential extra arguments in
+ * a var-args functions.  Since a varargs macro needs at least one argument in
+ * the "...", we accept the format string there, and require that the first
+ * argument in this "..." is a const char *.
+ */
+static inline void
+log_impl_varargs(const char *name, ...) {
+	char buf[JEMALLOC_LOG_BUFSIZE];
+	va_list ap;
+
+	va_start(ap, name);
+	const char *format = va_arg(ap, const char *);
+	size_t dst_offset = 0;
+	dst_offset += malloc_snprintf(buf, JEMALLOC_LOG_BUFSIZE, "%s: ", name);
+	dst_offset += malloc_vsnprintf(buf + dst_offset,
+	    JEMALLOC_LOG_BUFSIZE - dst_offset, format, ap);
+	dst_offset += malloc_snprintf(buf + dst_offset,
+	    JEMALLOC_LOG_BUFSIZE - dst_offset, "\n");
+	va_end(ap);
+
+	malloc_write(buf);
+}
+
+/* Call as log(log_var, "format_string %d", arg_for_format_string); */
+#define log(log_var, ...)						\
 do {									\
 	log_do_begin(log_var)						\
-		malloc_printf("%s: " format "\n",			\
-		    (log_var).name, __VA_ARGS__);			\
+		log_impl_varargs((log_var).name, __VA_ARGS__);		\
 	log_do_end(log_var)						\
 } while (0)
 
diff --git a/include/jemalloc/internal/malloc_io.h b/include/jemalloc/internal/malloc_io.h
index 47ae58e..4992d1d 100644
--- a/include/jemalloc/internal/malloc_io.h
+++ b/include/jemalloc/internal/malloc_io.h
@@ -53,6 +53,10 @@ size_t malloc_vsnprintf(char *str, size_t size, const char *format,
     va_list ap);
 size_t malloc_snprintf(char *str, size_t size, const char *format, ...)
     JEMALLOC_FORMAT_PRINTF(3, 4);
+/*
+ * The caller can set write_cb and cbopaque to null to choose to print with the
+ * je_malloc_message hook.
+ */
 void malloc_vcprintf(void (*write_cb)(void *, const char *), void *cbopaque,
     const char *format, va_list ap);
 void malloc_cprintf(void (*write_cb)(void *, const char *), void *cbopaque,
diff --git a/src/jemalloc.c b/src/jemalloc.c
index 48a268f..1dc6682 100644
--- a/src/jemalloc.c
+++ b/src/jemalloc.c
@@ -2364,7 +2364,7 @@ je_free(void *ptr) {
 		}
 		check_entry_exit_locking(tsd_tsdn(tsd));
 	}
-	log(log_core_free_exit, "%s", "");
+	log(log_core_free_exit, "");
 }
 
 /*
@@ -2957,7 +2957,7 @@ je_dallocx(void *ptr, int flags) {
 	}
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_dallocx_exit, "%s", "");
+	log(log_core_dallocx_exit, "");
 }
 
 JEMALLOC_ALWAYS_INLINE size_t
@@ -3024,7 +3024,7 @@ je_sdallocx(void *ptr, size_t size, int flags) {
 	}
 	check_entry_exit_locking(tsd_tsdn(tsd));
 
-	log(log_core_sdallocx_exit, "%s", "");
+	log(log_core_sdallocx_exit, "");
 }
 
 JEMALLOC_EXPORT size_t JEMALLOC_NOTHROW
@@ -3083,7 +3083,7 @@ je_mallctl(const char *name, void *oldp, size_t *oldlenp, void *newp,
 	check_entry_exit_locking(tsd_tsdn(tsd));
 	ret = ctl_byname(tsd, name, oldp, oldlenp, newp, newlen);
 	check_entry_exit_locking(tsd_tsdn(tsd));
-	
+
 	log(log_core_mallctl_exit, "result: %d", ret);
 	return ret;
 }
@@ -3124,7 +3124,7 @@ je_mallctlbymib(const size_t *mib, size_t miblen, void *oldp, size_t *oldlenp,
 	static log_var_t log_core_mallctlbymib_exit = LOG_VAR_INIT(
 	    "core.mallctlbymib.exit");
 
-	log(log_core_mallctlbymib_entry, "%s", "");
+	log(log_core_mallctlbymib_entry, "");
 
 
 	if (unlikely(malloc_init())) {
@@ -3150,13 +3150,13 @@ je_malloc_stats_print(void (*write_cb)(void *, const char *), void *cbopaque,
 	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, "%s", "");
+	log(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, "%s", "");
+	log(log_core_malloc_stats_print_exit, "");
 }
 
 JEMALLOC_EXPORT size_t JEMALLOC_NOTHROW
diff --git a/src/log.c b/src/log.c
index 022dc58..778902f 100644
--- a/src/log.c
+++ b/src/log.c
@@ -3,7 +3,7 @@
 
 #include "jemalloc/internal/log.h"
 
-char log_var_names[JEMALLOC_LOG_BUFSIZE];
+char log_var_names[JEMALLOC_LOG_VAR_BUFSIZE];
 atomic_b_t log_init_done = ATOMIC_INIT(false);
 
 /*
@@ -59,7 +59,7 @@ log_var_update_state(log_var_t *log_var) {
 	while (true) {
 		const char *segment_end = log_var_extract_segment(
 		    segment_begin);
-		assert(segment_end < log_var_names + JEMALLOC_LOG_BUFSIZE);
+		assert(segment_end < log_var_names + JEMALLOC_LOG_VAR_BUFSIZE);
 		if (log_var_matches_segment(segment_begin, segment_end,
 		    log_var_begin, log_var_end)) {
 			atomic_store_u(&log_var->state, LOG_ENABLED,
diff --git a/test/unit/log.c b/test/unit/log.c
index 6db256f..053fea4 100644
--- a/test/unit/log.c
+++ b/test/unit/log.c
@@ -170,13 +170,25 @@ TEST_BEGIN(test_logs_if_no_init) {
 }
 TEST_END
 
+/*
+ * This really just checks to make sure that this usage compiles; we don't have
+ * any test code to run.
+ */
+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.");
+	}
+}
+TEST_END
+
 int
 main(void) {
-
 	return test(
 	    test_log_disabled,
 	    test_log_enabled_direct,
 	    test_log_enabled_indirect,
 	    test_log_enabled_global,
-	    test_logs_if_no_init);
+	    test_logs_if_no_init,
+	    test_log_only_format_string);
 }