[Skiboot] [TRIVIAL][V1][PATCH] Make console-log time more readable

[Balbir Singh]

I've tried to align it with what the kernel prints today

The existing logs show

[20287269125,5] PSI[0x000]: Found PSI bridge [working=1, active=0]
[890425679,5] BT: Interface initialized, IO 0x00e4
[1249199642,4] SLW: HB-provided idle states property found
[1249344409,5] NVRAM: Size is 576 KB
[1484422964,3] NVRAM: Layout appears sane

The mftb() output is not very meaningful, the changed output shows

[   38.315784591,5] CENTAUR:   FSI host: 0x0 cMFSI0 port 2
[   38.315922971,5] PSI[0x000]: Found PSI bridge [working=1, active=0]
[    1.448765255,5] BT: Interface initialized, IO 0x00e4
[    2.398136129,5] NVRAM: Size is 576 KB
[    3.145017865,3] NVRAM: Layout appears sane

For the output sample, I've taken bits where one can see the time move back
w.r.t. previous log, but that was always the case. I don't think that is
worth fixing here

Adds an additional divide and modulo for every log printed

Signed-off-by: Balbir Singh <bsingharora at gmail.com>
---
 core/console-log.c | 5 +++--
 include/timebase.h | 5 +++++
 2 files changed, 8 insertions(+), 2 deletions(-)

diff --git a/core/console-log.c b/core/console-log.c
index 3b9475e..c70229f 100644
--- a/core/console-log.c
+++ b/core/console-log.c
@@ -32,6 +32,7 @@ static int vprlog(int log_level, const char *fmt, va_list ap)
 	int count;
 	char buffer[320];
 	bool flush_to_drivers = true;
+	unsigned long tb = mftb();
 
 	/* It's safe to return 0 when we "did" something here
 	 * as only printf cares about how much we wrote, and
@@ -43,8 +44,8 @@ static int vprlog(int log_level, const char *fmt, va_list ap)
 	if (log_level > (debug_descriptor.console_log_levels >> 4))
 		return 0;
 
-	count = snprintf(buffer, sizeof(buffer), "[%lu,%d] ",
-			 mftb(), log_level);
+	count = snprintf(buffer, sizeof(buffer), "[%5lu.%06lu,%d] ",
+			 tb_to_secs(tb), tb_remaining_nsecs(tb), log_level);
 	count+= vsnprintf(buffer+count, sizeof(buffer)-count, fmt, ap);
 
 	if (log_level > (debug_descriptor.console_log_levels & 0x0f))
diff --git a/include/timebase.h b/include/timebase.h
index 7f5afe1..c50f601 100644
--- a/include/timebase.h
+++ b/include/timebase.h
@@ -64,6 +64,11 @@ static inline unsigned long tb_to_secs(unsigned long tb)
 	return tb / tb_hz;
 }
 
+static inline unsigned long tb_remaining_nsecs(unsigned long tb)
+{
+	return tb % tb_hz;
+}
+
 static inline unsigned long msecs_to_tb(unsigned long msecs)
 {
 	return msecs * (tb_hz / 1000);
-- 
2.5.5