Update trace format to be less verbose in INFO and ERROR levels

- By default, traces of severity TRACE_INFO or lower will not print
the thread ID, function name or line number. Can be controlled by
CFG_MSG_LONG_PREFIX_THRESHOLD (see mk/config.mk).
- The trace level string is updated ("DEBUG", "INFO" etc. instead of
"DBG", "INF" etc.) for consistency with ARM Trusted Firmware.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
Reviewed-by: Pascal Brand <pascal.brand@linaro.org>
Reviewed-by: Jens Wiklander <jens.wiklander@linaro.org>

lib/libutils/ext/trace.c

@@ -53,12 +53,13 @@ int trace_get_level(void)
 
 static const char *trace_level_to_string(int level, bool level_ok)
 {
-	static const char lvl_strs[][4] = {
-		"UKN", "ERR", "INF", "DBG", "FLW" };
+	static const char lvl_strs[][9] = {
+		"UNKNOWN:", "ERROR:  ", "INFO:   ", "DEBUG:  ",
+		"FLOW:   " };
 	int l = 0;
 
 	if (!level_ok)
-		return "MSG";
+		return "MESSAGE:";
 
 	if ((level >= TRACE_MIN) && (level <= TRACE_MAX))
 		l = level;
@@ -74,27 +75,52 @@ void trace_printf(const char *function, int line, int level, bool level_ok,
 	char buf[MAX_PRINT_SIZE];
 	size_t boffs = 0;
 	int res;
+	int thread_id;
 
 	if (level_ok && level > trace_level)
 		return;
 
+	res = snprintk(buf, sizeof(buf), "%s ",
+		       trace_level_to_string(level, level_ok));
+	if (res < 0)
+		return;
+	boffs += res;
+
+	if (level_ok && level < CFG_MSG_LONG_PREFIX_THRESHOLD)
+		thread_id = -1;
+	else
+		thread_id = trace_ext_get_thread_id();
+
+	if (thread_id >= 0) {
+		res = snprintk(buf + boffs, sizeof(buf) - boffs, "[0x%x] ",
+			       thread_id);
+		if (res < 0)
+			return;
+		boffs += res;
+	}
+
+	res = snprintk(buf + boffs, sizeof(buf) - boffs, "%s:",
+		       trace_ext_prefix);
+	if (res < 0)
+		return;
+	boffs += res;
+
+	if (level_ok && level < CFG_MSG_LONG_PREFIX_THRESHOLD)
+		function = NULL;
+
 	if (function) {
-		int thread_id = trace_ext_get_thread_id();
-
-		if (thread_id >= 0)
-			res = snprintk(buf, sizeof(buf), "%s [0x%x] %s:%s:%d: ",
-				       trace_level_to_string(level, level_ok),
-				       thread_id, trace_ext_prefix,
-				       function, line);
-		else
-			res = snprintk(buf, sizeof(buf), "%s %s:%s:%d: ",
-				       trace_level_to_string(level, level_ok),
-				       trace_ext_prefix, function, line);
+		res = snprintk(buf + boffs, sizeof(buf) - boffs, "%s:%d:",
+			       function, line);
 		if (res < 0)
-			return; /* "Can't happen" */
-		boffs = res;
+			return;
+		boffs += res;
 	}
 
+	res = snprintk(buf + boffs, sizeof(buf) - boffs, " ");
+	if (res < 0)
+		return;
+	boffs += res;
+
 	va_start(ap, fmt);
 	res = vsnprintk(buf + boffs, sizeof(buf) - boffs, fmt, ap);
 	va_end(ap);

mk/config.mk

@@ -72,6 +72,13 @@ CFG_TEE_CORE_USER_MEM_DEBUG ?= 1
 CFG_TEE_CORE_MALLOC_DEBUG ?= n
 CFG_TEE_TA_MALLOC_DEBUG ?= n
 
+# All message with level equal or higher to the following value will be
+# prefixed with long debugging information (severity, thread ID, component
+# name, function name, line number). Otherwise a short prefix is used
+# (severity and component name only).
+# Levels: 0=none 1=error 2=info 3=debug 4=flow
+CFG_MSG_LONG_PREFIX_THRESHOLD ?= 3
+
 # PRNG configuration
 # If CFG_WITH_SOFTWARE_PRNG is enabled, crypto provider provided
 # software PRNG implementation is used.