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.

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

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 */

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_impl_varargs((log_var).name, __VA_ARGS__);		\
-		    (log_var).name, __VA_ARGS__);			\
 	log_do_end(log_var)						\
 } while (0)
 

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,

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
@@ -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

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,

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);
 }