trace: make output more compact

The new format for traces are:
  <type>/<where>:<thread_id> [<func:line>] <message>

<type>:
  D = DEBUG
  E = ERROR
  I = INFO
  F = FLOW

<where>:
  TA = Trusted Application
  TC = TEE Core

I.e, it outputs messages like this:
  D/TC:00 ta_load:316 ELF load address 0x101000
  etc

Thread ID will either take a single or two digits depending on the
number of threads in use.

Signed-off-by: Joakim Bech <joakim.bech@linaro.org>
Reviewed-by: Jens Wiklander <jens.wiklander@linaro.org>
Reviewed-by: Etienne Carriere <etienne.carriere@linaro.org>

core/arch/arm/kernel/trace_ext.c

@@ -31,7 +31,7 @@
 #include <kernel/thread.h>
 #include <mm/core_mmu.h>
 
-const char trace_ext_prefix[] = "TEE-CORE";
+const char trace_ext_prefix[] = "TC";
 int trace_level = TRACE_LEVEL;
 static unsigned int puts_lock = SPINLOCK_UNLOCK;
 

lib/libutils/ext/trace.c

@@ -51,22 +51,41 @@ int trace_get_level(void)
 	return trace_level;
 }
 
-static const char *trace_level_to_string(int level, bool level_ok)
+static char trace_level_to_string(int level, bool level_ok)
 {
-	static const char lvl_strs[][9] = {
-		"UNKNOWN:", "ERROR:  ", "INFO:   ", "DEBUG:  ",
-		"FLOW:   " };
+	/*
+	 * U = Unused
+	 * E = Error
+	 * I = Information
+	 * D = Debug
+	 * F = Flow
+	 */
+	static const char lvl_strs[] = { 'U', 'E', 'I', 'D', 'F' };
 	int l = 0;
 
 	if (!level_ok)
-		return "MESSAGE:";
+		return 'M';
 
 	if ((level >= TRACE_MIN) && (level <= TRACE_MAX))
 		l = level;
 
 	return lvl_strs[l];
 }
 
+static int print_thread_id(char *buf, size_t bs, int thread_id)
+{
+#if CFG_NUM_THREADS > 9
+	int num_thread_digits = 2;
+#else
+	int num_thread_digits = 1;
+#endif
+
+	if (thread_id >= 0)
+		return snprintk(buf, bs, "%0*d ", num_thread_digits, thread_id);
+	else
+		return snprintk(buf, bs, "%*s ", num_thread_digits, "");
+}
+
 /* Format trace of user ta. Inline with kernel ta */
 void trace_printf(const char *function, int line, int level, bool level_ok,
 		  const char *fmt, ...)
@@ -80,47 +99,44 @@ void trace_printf(const char *function, int line, int level, bool level_ok,
 	if (level_ok && level > trace_level)
 		return;
 
-	res = snprintk(buf, sizeof(buf), "%s ",
+	/* Print the type of message */
+	res = snprintk(buf, sizeof(buf), "%c/",
 		       trace_level_to_string(level, level_ok));
 	if (res < 0)
 		return;
 	boffs += res;
 
+	/* Print the location, i.e., TEE core or TA */
+	res = snprintk(buf + boffs, sizeof(buf) - boffs, "%s:",
+		       trace_ext_prefix);
+	if (res < 0)
+		return;
+	boffs += res;
+
+	/* Print the Thread ID */
 	if (level_ok && !(BIT(level) & CFG_MSG_LONG_PREFIX_MASK))
 		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 = print_thread_id(buf + boffs, sizeof(buf) - boffs, thread_id);
 
-	res = snprintk(buf + boffs, sizeof(buf) - boffs, "%s:",
-		       trace_ext_prefix);
 	if (res < 0)
 		return;
 	boffs += res;
 
+	/* Print the function and line */
 	if (level_ok && !(BIT(level) & CFG_MSG_LONG_PREFIX_MASK))
 		function = NULL;
 
 	if (function) {
-		res = snprintk(buf + boffs, sizeof(buf) - boffs, "%s:%d:",
+		res = snprintk(buf + boffs, sizeof(buf) - boffs, "%s:%d ",
 			       function, line);
 		if (res < 0)
 			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);

ta/arch/arm/user_ta_header.c

@@ -33,11 +33,7 @@
 
 int trace_level = TRACE_LEVEL;
 
-#ifdef TA_LOG_PREFIX
-const char trace_ext_prefix[]  = TA_LOG_PREFIX;
-#else
-const char trace_ext_prefix[]  = "USER-TA";
-#endif
+const char trace_ext_prefix[]  = "TA";
 
 #ifndef TA_VERSION
 #define TA_VERSION "Undefined version"