Implement log framework

This patch gives users control over logging messages printed from the C
code using the LOG macros defined in debug.h Users now have the ability
to reduce the log_level at run time using the tf_log_set_max_level()
function. The default prefix string can be defined by platform by
overriding the `plat_log_get_prefix()` platform API which is also
introduced in this patch.

The new log framework results in saving of some RO data. For example,
when BL1 is built for FVP with LOG_LEVEL=LOG_LEVEL_VERBOSE, resulted
in saving 384 bytes of RO data and increase of 8 bytes of RW data. The
framework also adds about 108 bytes of code to the release build of FVP.

Fixes ARM-software/tf-issues#462

Change-Id: I476013d9c3deedfdd4c8b0b0f125665ba6250554
Co-authored-by: Eleanor Bonnici <Eleanor.bonnici@arm.com>
Signed-off-by: Soby Mathew <soby.mathew@arm.com>

Makefile

@@ -162,11 +162,13 @@ include lib/compiler-rt/compiler-rt.mk
 include lib/stdlib/stdlib.mk
 
 BL_COMMON_SOURCES	+=	common/bl_common.c			\
+				common/tf_log.c				\
 				common/tf_printf.c			\
 				common/tf_snprintf.c			\
 				common/${ARCH}/debug.S			\
 				lib/${ARCH}/cache_helpers.S		\
 				lib/${ARCH}/misc_helpers.S		\
+				plat/common/plat_log_common.c		\
 				plat/common/${ARCH}/plat_common.c	\
 				plat/common/${ARCH}/platform_helpers.S	\
 				${COMPILER_RT_SRCS}			\

common/tf_log.c

@@ -0,0 +1,61 @@
+/*
+ * Copyright (c) 2017, ARM Limited and Contributors. All rights reserved.
+ *
+ * SPDX-License-Identifier: BSD-3-Clause
+ */
+
+#include <assert.h>
+#include <debug.h>
+#include <platform.h>
+
+/* Set the default maximum log level to the `LOG_LEVEL` build flag */
+static unsigned int max_log_level = LOG_LEVEL;
+
+/*
+ * The common log function which is invoked by ARM Trusted Firmware code.
+ * This function should not be directly invoked and is meant to be
+ * only used by the log macros defined in debug.h. The function
+ * expects the first character in the format string to be one of the
+ * LOG_MARKER_* macros defined in debug.h.
+ */
+void tf_log(const char *fmt, ...)
+{
+	unsigned int log_level;
+	va_list args;
+	const char *prefix_str;
+
+	/* We expect the LOG_MARKER_* macro as the first character */
+	log_level = fmt[0];
+
+	/* Verify that log_level is one of LOG_MARKER_* macro defined in debug.h */
+	assert(log_level && log_level <= LOG_LEVEL_VERBOSE);
+	assert(log_level % 10 == 0);
+
+	if (log_level > max_log_level)
+		return;
+
+	prefix_str = plat_log_get_prefix(log_level);
+
+	if (prefix_str != NULL)
+		tf_string_print(prefix_str);
+
+	va_start(args, fmt);
+	tf_vprintf(fmt+1, args);
+	va_end(args);
+}
+
+/*
+ * The helper function to set the log level dynamically by platform. The
+ * maximum log level is determined by `LOG_LEVEL` build flag at compile time
+ * and this helper can set a lower log level than the one at compile.
+ */
+void tf_log_set_max_level(unsigned int log_level)
+{
+	assert(log_level <= LOG_LEVEL_VERBOSE);
+	assert((log_level % 10) == 0);
+
+	/* Cap log_level to the compile time maximum. */
+	if (log_level < LOG_LEVEL)
+		max_log_level = log_level;
+
+}

docs/porting-guide.rst

@@ -1014,6 +1014,21 @@ This function flushes to main memory all the image params that are passed to
 next image. This function is currently invoked in BL2 to flush this information
 to the next BL image, when LOAD\_IMAGE\_V2 is enabled.
 
+Function : plat\_log\_get\_prefix()
+~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+
+::
+
+    Argument : unsigned int
+    Return   : const char *
+
+This function defines the prefix string corresponding to the `log_level` to be
+prepended to all the log output from ARM Trusted Firmware. The `log_level`
+(argument) will correspond to one of the standard log levels defined in
+debug.h. The platform can override the common implementation to define a
+different prefix string for the log output.  The implementation should be
+robust to future changes that increase the number of log levels.
+
 Modifications specific to a Boot Loader stage
 ---------------------------------------------
 

include/common/debug.h

@@ -27,47 +27,59 @@
 #include <stdarg.h>
 #include <stdio.h>
 
+/*
+ * Define Log Markers corresponding to each log level which will
+ * be embedded in the format string and is expected by tf_log() to determine
+ * the log level.
+ */
+#define LOG_MARKER_ERROR		"\xa"	/* 10 */
+#define LOG_MARKER_NOTICE		"\x14"	/* 20 */
+#define LOG_MARKER_WARNING		"\x1e"	/* 30 */
+#define LOG_MARKER_INFO			"\x28"	/* 40 */
+#define LOG_MARKER_VERBOSE		"\x32"	/* 50 */
+
 #if LOG_LEVEL >= LOG_LEVEL_NOTICE
-# define NOTICE(...)	tf_printf("NOTICE:  " __VA_ARGS__)
+# define NOTICE(...)	tf_log(LOG_MARKER_NOTICE __VA_ARGS__)
 #else
 # define NOTICE(...)
 #endif
 
 #if LOG_LEVEL >= LOG_LEVEL_ERROR
-# define ERROR(...)	tf_printf("ERROR:   " __VA_ARGS__)
+# define ERROR(...)	tf_log(LOG_MARKER_ERROR __VA_ARGS__)
 #else
 # define ERROR(...)
 #endif
 
 #if LOG_LEVEL >= LOG_LEVEL_WARNING
-# define WARN(...)	tf_printf("WARNING: " __VA_ARGS__)
+# define WARN(...)	tf_log(LOG_MARKER_WARNING __VA_ARGS__)
 #else
 # define WARN(...)
 #endif
 
 #if LOG_LEVEL >= LOG_LEVEL_INFO
-# define INFO(...)	tf_printf("INFO:    " __VA_ARGS__)
+# define INFO(...)	tf_log(LOG_MARKER_INFO __VA_ARGS__)
 #else
 # define INFO(...)
 #endif
 
 #if LOG_LEVEL >= LOG_LEVEL_VERBOSE
-# define VERBOSE(...)	tf_printf("VERBOSE: " __VA_ARGS__)
+# define VERBOSE(...)	tf_log(LOG_MARKER_VERBOSE __VA_ARGS__)
 #else
 # define VERBOSE(...)
 #endif
 
-
 void __dead2 do_panic(void);
 #define panic()	do_panic()
 
 /* Function called when stack protection check code detects a corrupted stack */
 void __dead2 __stack_chk_fail(void);
 
+void tf_log(const char *fmt, ...) __printflike(1, 2);
 void tf_printf(const char *fmt, ...) __printflike(1, 2);
 int tf_snprintf(char *s, size_t n, const char *fmt, ...) __printflike(3, 4);
 void tf_vprintf(const char *fmt, va_list args);
 void tf_string_print(const char *str);
+void tf_log_set_max_level(unsigned int log_level);
 
 #endif /* __ASSEMBLY__ */
 #endif /* __DEBUG_H__ */

include/plat/common/platform.h

@@ -79,6 +79,7 @@ int plat_crash_console_putc(int c);
 int plat_crash_console_flush(void);
 void plat_error_handler(int err) __dead2;
 void plat_panic_handler(void) __dead2;
+const char *plat_log_get_prefix(unsigned int log_level);
 
 /*******************************************************************************
  * Mandatory BL1 functions

plat/common/plat_log_common.c

@@ -0,0 +1,25 @@
+/*
+ * Copyright (c) 2017, ARM Limited and Contributors. All rights reserved.
+ *
+ * SPDX-License-Identifier: BSD-3-Clause
+ */
+
+#include <assert.h>
+#include <debug.h>
+#include <platform.h>
+
+/* Allow platforms to override the log prefix string */
+#pragma weak plat_log_get_prefix
+
+static const char *prefix_str[] = {
+	"ERROR:   ", "NOTICE:  ", "WARNING: ", "INFO:    ", "VERBOSE: "};
+
+const char *plat_log_get_prefix(unsigned int log_level)
+{
+	if (log_level < LOG_LEVEL_ERROR)
+		log_level = LOG_LEVEL_ERROR;
+	else if (log_level > LOG_LEVEL_VERBOSE)
+		log_level = LOG_LEVEL_VERBOSE;
+
+	return prefix_str[(log_level/10) - 1];
+}