[lttng-dev] [PATCH lttng-ust] Improve tracef/tracelog to use the stack for small strings

[Norbert Lange]

Support two common cases, one being that the resulting message is
small enough to fit into a on-stack buffer.
The seconds being the common 'printf("%s", "Message")' scheme.

Unfortunately, iterating a va_list is destructive,
so it has to be copied before calling vprintf.
This will result in the function never becoming inlined,
thus the helper function was manually "inlined".

Signed-off-by: Norbert Lange <nolange79 at gmail.com>
---
 src/common/tracer.h          |  2 +
 src/lib/lttng-ust/tracef.c   | 83 ++++++++++++++++++++++++---------
 src/lib/lttng-ust/tracelog.c | 90 ++++++++++++++++++++++++------------
 3 files changed, 122 insertions(+), 53 deletions(-)

diff --git a/src/common/tracer.h b/src/common/tracer.h
index 2affd6ab..8e18c9b5 100644
--- a/src/common/tracer.h
+++ b/src/common/tracer.h
@@ -26,6 +26,8 @@
 #define LTTNG_RFLAG_EXTENDED		RING_BUFFER_RFLAG_END
 #define LTTNG_RFLAG_END			(LTTNG_RFLAG_EXTENDED << 1)
 
+#define LTTNG_TRACE_PRINTF_BUFSIZE	512
+
 /*
  * LTTng client type enumeration. Used by the consumer to map the
  * callbacks from its own address space.
diff --git a/src/lib/lttng-ust/tracef.c b/src/lib/lttng-ust/tracef.c
index c05c7811..21af5b9e 100644
--- a/src/lib/lttng-ust/tracef.c
+++ b/src/lib/lttng-ust/tracef.c
@@ -7,6 +7,7 @@
 #define _LGPL_SOURCE
 #include <stdio.h>
 #include "common/macros.h"
+#include "common/tracer.h"
 
 /* The tracepoint definition is public, but the provider definition is hidden. */
 #define LTTNG_UST_TRACEPOINT_PROVIDER_HIDDEN_DEFINITION
@@ -15,30 +16,40 @@
 #define LTTNG_UST_TRACEPOINT_DEFINE
 #include "lttng-ust-tracef-provider.h"
 
-static inline
-void lttng_ust___vtracef(const char *fmt, va_list ap)
-	__attribute__((always_inline, format(printf, 1, 0)));
-static inline
-void lttng_ust___vtracef(const char *fmt, va_list ap)
-{
-	char *msg;
-	const int len = vasprintf(&msg, fmt, ap);
-
-	/* len does not include the final \0 */
-	if (len < 0)
-		goto end;
-	lttng_ust_tracepoint_cb_lttng_ust_tracef___event(msg, len,
-		LTTNG_UST_CALLER_IP());
-	free(msg);
-end:
-	return;
-}
-
 void lttng_ust__vtracef(const char *fmt, va_list ap)
 	__attribute__((format(printf, 1, 0)));
 void lttng_ust__vtracef(const char *fmt, va_list ap)
 {
-	lttng_ust___vtracef(fmt, ap);
+	char local_buf[LTTNG_TRACE_PRINTF_BUFSIZE];
+	char *alloc_buff = NULL;
+	char *msg = local_buf;
+	size_t buflen = sizeof(local_buf);
+	int len = -1;
+
+	if (caa_unlikely(fmt[0] == '%' && fmt[1] == 's' && fmt[2] == '\0')) {
+		msg = va_arg(ap, char *);
+		len = strlen(msg);
+	} else
+		do {
+			va_list ap2;
+
+			if (caa_unlikely(len >= sizeof(local_buf))) {
+				buflen = (size_t)(len) + 1U;
+				alloc_buff = (char *)malloc(buflen);
+				msg = alloc_buff;
+				if (!alloc_buff)
+					return;
+			}
+			va_copy(ap2, ap);
+			len = vsnprintf(msg, buflen, fmt, ap2);
+			va_end(ap2);
+		} while (caa_unlikely(len >= sizeof(local_buf) && !alloc_buff));
+
+	/* len does not include the final \0 */
+	if (caa_likely(len >= 0))
+		lttng_ust_tracepoint_cb_lttng_ust_tracef___event(msg, len,
+			LTTNG_UST_CALLER_IP());
+	free(alloc_buff);
 }
 
 void lttng_ust__tracef(const char *fmt, ...)
@@ -46,8 +57,34 @@ void lttng_ust__tracef(const char *fmt, ...)
 void lttng_ust__tracef(const char *fmt, ...)
 {
 	va_list ap;
+	char local_buf[LTTNG_TRACE_PRINTF_BUFSIZE];
+	char *alloc_buff = NULL;
+	char *msg = local_buf;
+	size_t buflen = sizeof(local_buf);
+	int len = -1;
 
-	va_start(ap, fmt);
-	lttng_ust___vtracef(fmt, ap);
-	va_end(ap);
+	if (caa_unlikely(fmt[0] == '%' && fmt[1] == 's' && fmt[2] == '\0')) {
+		va_start(ap, fmt);
+		msg = va_arg(ap, char *);
+		va_end(ap);
+		len = strlen(msg);
+	} else
+		do {
+			if (caa_unlikely(len >= sizeof(local_buf))) {
+				buflen = (size_t)(len) + 1U;
+				alloc_buff = (char *)malloc(buflen);
+				msg = alloc_buff;
+				if (!alloc_buff)
+					return;
+			}
+			va_start(ap, fmt);
+			len = vsnprintf(msg, buflen, fmt, ap);
+			va_end(ap);
+		} while (caa_unlikely(len >= sizeof(local_buf) && !alloc_buff));
+
+	/* len does not include the final \0 */
+	if (caa_likely(len >= 0))
+		lttng_ust_tracepoint_cb_lttng_ust_tracef___event(msg, len,
+			LTTNG_UST_CALLER_IP());
+	free(alloc_buff);
 }
diff --git a/src/lib/lttng-ust/tracelog.c b/src/lib/lttng-ust/tracelog.c
index b28c6c78..6889869c 100644
--- a/src/lib/lttng-ust/tracelog.c
+++ b/src/lib/lttng-ust/tracelog.c
@@ -7,6 +7,7 @@
 #define _LGPL_SOURCE
 #include <stdio.h>
 #include "common/macros.h"
+#include "common/tracer.h"
 
 /* The tracepoint definition is public, but the provider definition is hidden. */
 #define LTTNG_UST_TRACEPOINT_PROVIDER_HIDDEN_DEFINITION
@@ -31,44 +32,73 @@ extern void lttng_ust__tracelog_vprintf(tpcallback_t *callback,
 	const struct lttng_ust__tracelog_sourceinfo *source, const char *fmt, va_list ap)
 	__attribute__ ((format(printf, 3, 0)));
 
-static inline
-void lttng_ust___tracelog_vprintf(tpcallback_t *callback,
-	const struct lttng_ust__tracelog_sourceinfo *source,
-	const char *fmt, va_list ap)
-	__attribute__((always_inline, format(printf, 3, 0)));
-
-
-static inline
-void lttng_ust___tracelog_vprintf(tpcallback_t *callback,
-	const struct lttng_ust__tracelog_sourceinfo *source,
-	const char *fmt, va_list ap)
-{
-	char *msg;
-	const int len = vasprintf(&msg, fmt, ap);
-
-	/* len does not include the final \0 */
-	if (len >= 0)
-		goto end;
-	(*callback)(source->file, source->line, source->func, msg, len,
-		LTTNG_UST_CALLER_IP());
-	free(msg);
-end:
-	return;
-}
-
-
 void lttng_ust__tracelog_printf(tpcallback_t *callback,
 	const struct lttng_ust__tracelog_sourceinfo *source, const char *fmt, ...)
 {
 	va_list ap;
+	char local_buf[LTTNG_TRACE_PRINTF_BUFSIZE];
+	char *alloc_buff = NULL;
+	char *msg = local_buf;
+	size_t buflen = sizeof(local_buf);
+	int len = -1;
+
+	if (caa_unlikely(fmt[0] == '%' && fmt[1] == 's' && fmt[2] == '\0')) {
+		va_start(ap, fmt);
+		msg = va_arg(ap, char *);
+		va_end(ap);
+		len = strlen(msg);
+	} else
+		do {
+			if (caa_unlikely(len >= sizeof(local_buf))) {
+				buflen = (size_t)(len) + 1U;
+				alloc_buff = (char *)malloc(buflen);
+				msg = alloc_buff;
+				if (!alloc_buff)
+					return;
+			}
+			va_start(ap, fmt);
+			len = vsnprintf(msg, buflen, fmt, ap);
+			va_end(ap);
+		} while (caa_unlikely(len >= sizeof(local_buf) && !alloc_buff));
 
-	va_start(ap, fmt);
-	lttng_ust___tracelog_vprintf(callback, source, fmt, ap);
-	va_end(ap);
+	/* len does not include the final \0 */
+	if (caa_likely(len >= 0))
+		(*callback)(source->file, source->line, source->func, msg, len,
+			LTTNG_UST_CALLER_IP());
+	free(alloc_buff);
 }
 
 void lttng_ust__tracelog_vprintf(tpcallback_t *callback,
 	const struct lttng_ust__tracelog_sourceinfo *source, const char *fmt, va_list ap)
 {
-	lttng_ust___tracelog_vprintf(callback, source, fmt, ap);
+	char local_buf[LTTNG_TRACE_PRINTF_BUFSIZE];
+	char *alloc_buff = NULL;
+	char *msg = local_buf;
+	size_t buflen = sizeof(local_buf);
+	int len = -1;
+
+	if (caa_unlikely(fmt[0] == '%' && fmt[1] == 's' && fmt[2] == '\0')) {
+		msg = va_arg(ap, char *);
+		len = strlen(msg);
+	} else
+		do {
+			va_list ap2;
+
+			if (caa_unlikely(len >= sizeof(local_buf))) {
+				buflen = (size_t)(len) + 1U;
+				alloc_buff = (char *)malloc(buflen);
+				msg = alloc_buff;
+				if (!alloc_buff)
+					return;
+			}
+			va_copy(ap2, ap);
+			len = vsnprintf(msg, buflen, fmt, ap2);
+			va_end(ap2);
+		} while (caa_unlikely(len >= sizeof(local_buf) && !alloc_buff));
+
+	/* len does not include the final \0 */
+	if (caa_likely(len >= 0))
+		(*callback)(source->file, source->line, source->func, msg, len,
+			LTTNG_UST_CALLER_IP());
+	free(alloc_buff);
 }
-- 
2.30.2