[U-Boot] [PATCH] CONFIG_PRINT_TIME: Measuring boot time.

This option prefixes every console line with the time in seconds since power-up. It is inspired by the Linux kernel option PRINTK_TIME and uses the same output format.
It can be used to measure the time taken by U-Boot to boot the kernel or application. For example:
[ 0.003532] U-Boot 2009.03-rc1-00008-gfa74f69-dirty (mar 04 2009 - 14:18:39) [ 0.011994] [ 0.013694] CPU: AMCC PowerPC 440EPx Rev. A at 528 MHz (PLB=132, OPB=66, EBC=66 MHz) [ 0.023121] Security/Kasumi support [ 0.028001] Bootstrap Option H - Boot ROM Location I2C (Addr 0x52) [ 0.036075] Internal PCI arbiter enabled, PCI async ext clock used [ 0.044142] 32 kB I-Cache 32 kB D-Cache [ 0.049445] Board: Sequoia - AMCC PPC440EPx Evaluation Board, Rev. F, PCI=66 MHz ...
Signed-off-by: Benoît Monin bmonin@adeneo.eu --- README | 5 +++++ common/console.c | 36 ++++++++++++++++++++++++++++++------ 2 files changed, 35 insertions(+), 6 deletions(-)
diff --git a/README b/README index d0a636e..848ff29 100644 --- a/README +++ b/README @@ -478,6 +478,11 @@ The following options need to be configured: the "silent" environment variable. See doc/README.silent for more information.
+ When CONFIG_PRINT_TIME is defined, all console messages + are prefixed with the time in second since power-up. + This option mimics the Linux kernel option PRINTK_TIME + and uses the same output format (ex: [ 0.049445] ...). + - Console Baudrate: CONFIG_BAUDRATE - in bps Select one of the baudrates listed in diff --git a/common/console.c b/common/console.c index 2add047..75f0f28 100644 --- a/common/console.c +++ b/common/console.c @@ -325,6 +325,17 @@ int tstc(void) return serial_tstc(); }
+static void __putc(const char c) +{ + if (gd->flags & GD_FLG_DEVINIT) { + /* Send to the standard output */ + fputc (stdout, c); + } else { + /* Send directly to the handler */ + serial_putc (c); + } +} + void putc(const char c) { #ifdef CONFIG_SILENT_CONSOLE @@ -337,13 +348,20 @@ void putc(const char c) return; #endif
- if (gd->flags & GD_FLG_DEVINIT) { - /* Send to the standard output */ - fputc(stdout, c); - } else { - /* Send directly to the handler */ - serial_putc(c); + __putc(c); +#ifdef CONFIG_PRINT_TIME + if (c == '\n') { + unsigned long ms; + char tbuf[32]; + int tlen; + int i; + + ms = ticks2usec(get_ticks()); + tlen = sprintf(tbuf, "[%5lu.%06lu] ", (ms / 1000000UL), (ms % 1000000UL)); + for (i = 0; i < tlen; i++) + __putc(tbuf[i]); } +#endif }
void puts(const char *s) @@ -358,6 +376,11 @@ void puts(const char *s) return; #endif
+#ifdef CONFIG_PRINT_TIME + while (*s) { + putc(*s++); + } +#else if (gd->flags & GD_FLG_DEVINIT) { /* Send to the standard output */ fputs(stdout, s); @@ -365,6 +388,7 @@ void puts(const char *s) /* Send directly to the handler */ serial_puts(s); } +#endif }
void printf(const char *fmt, ...)

On 17:16 Wed 04 Mar , Benoit Monin wrote:
This option prefixes every console line with the time in seconds since power-up. It is inspired by the Linux kernel option PRINTK_TIME and uses the same output format.
It can be used to measure the time taken by U-Boot to boot the kernel or application. For example:
[ 0.003532] U-Boot 2009.03-rc1-00008-gfa74f69-dirty (mar 04 2009 - 14:18:39) [ 0.011994] [ 0.013694] CPU: AMCC PowerPC 440EPx Rev. A at 528 MHz (PLB=132, OPB=66, EBC=66 MHz) [ 0.023121] Security/Kasumi support [ 0.028001] Bootstrap Option H - Boot ROM Location I2C (Addr 0x52) [ 0.036075] Internal PCI arbiter enabled, PCI async ext clock used [ 0.044142] 32 kB I-Cache 32 kB D-Cache [ 0.049445] Board: Sequoia - AMCC PPC440EPx Evaluation Board, Rev. F, PCI=66 MHz ...
Signed-off-by: Benoît Monin bmonin@adeneo.eu
README | 5 +++++ common/console.c | 36 ++++++++++++++++++++++++++++++------ 2 files changed, 35 insertions(+), 6 deletions(-)
diff --git a/README b/README index d0a636e..848ff29 100644 --- a/README +++ b/README @@ -478,6 +478,11 @@ The following options need to be configured: the "silent" environment variable. See doc/README.silent for more information.
When CONFIG_PRINT_TIME is defined, all console messages
are prefixed with the time in second since power-up.
This option mimics the Linux kernel option PRINTK_TIME
and uses the same output format (ex: [ 0.049445] ...).
- Console Baudrate: CONFIG_BAUDRATE - in bps Select one of the baudrates listed in
diff --git a/common/console.c b/common/console.c index 2add047..75f0f28 100644 --- a/common/console.c +++ b/common/console.c @@ -325,6 +325,17 @@ int tstc(void) return serial_tstc(); }
+static void __putc(const char c) +{
- if (gd->flags & GD_FLG_DEVINIT) {
/* Send to the standard output */
fputc (stdout, c);
- } else {
/* Send directly to the handler */
serial_putc (c);
- }
+}
void putc(const char c) { #ifdef CONFIG_SILENT_CONSOLE @@ -337,13 +348,20 @@ void putc(const char c) return; #endif
- if (gd->flags & GD_FLG_DEVINIT) {
/* Send to the standard output */
fputc(stdout, c);
- } else {
/* Send directly to the handler */
serial_putc(c);
- __putc(c);
+#ifdef CONFIG_PRINT_TIME
- if (c == '\n') {
unsigned long ms;
char tbuf[32];
int tlen;
int i;
NACK
ms = ticks2usec(get_ticks());
ticks2usec only exist on ppc
tlen = sprintf(tbuf, "[%5lu.%06lu] ", (ms / 1000000UL), (ms % 1000000UL));
wont work on arm please do_div
for (i = 0; i < tlen; i++)
}__putc(tbuf[i]);
+#endif }
void puts(const char *s) @@ -358,6 +376,11 @@ void puts(const char *s) return; #endif
+#ifdef CONFIG_PRINT_TIME
- while (*s) {
putc(*s++);
please use fputs and serail_puts
Best Regards, J.

Dear Benoit Monin,
In message 13935170.21001.1236183410521.JavaMail.www@wwinf8202 you wrote:
This option prefixes every console line with the time in seconds since power-up. It is inspired by the Linux kernel option PRINTK_TIME and uses the same output format.
Thanks, but I reject this patch, as it adds only code bloat and slows down the boot process. The same effect can be acchieved by a few linex of expect code parsing the output - without adding code or slowing down the system.
Best regards,
Wolfgang Denk
participants (3)
-
Benoit Monin
-
Jean-Christophe PLAGNIOL-VILLARD
-
Wolfgang Denk