[U-Boot] [PATCH 0/4] Accurate boot time measurement

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

This defines the basics of a new boot time measurement feature. This allows
logging of very accurate time measurements as the boot proceeds, by using
an available microsecond counter.

To enable the feature, define CONFIG_BOOTSTAGE in your board config file.
Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be
printed just before handing off to the OS.

Example output is:

Timer summary in microseconds:
       Mark    Elapsed  Stage
          0          0  awake
  2,181,078  2,181,078  usb_start
 11,861,817  9,680,739  bootp_start
 11,884,610     22,793  bootp_stop
 11,884,689         79  tftp start
 15,271,536  3,386,847  tftp done
 15,271,568         32  bootm_start
 15,406,551    134,983  start_kernel

Simon Glass (4):
  Add microsecond boot time measurement
  Add bootstage progress report
  Add bootstage calls in places appropriate for network booting
  Add option to print boot stage report before starting kernel

 README               |   17 +++++++++
 arch/arm/lib/board.c |    2 +
 arch/arm/lib/bootm.c |    4 ++
 common/Makefile      |    1 +
 common/bootstage.c   |   97 ++++++++++++++++++++++++++++++++++++++++++++++++++
 common/cmd_bootm.c   |    2 +
 common/cmd_net.c     |    7 +++-
 common/cmd_usb.c     |    1 +
 include/bootstage.h  |   74 ++++++++++++++++++++++++++++++++++++++
 include/common.h     |    8 ++++
 net/bootp.c          |    3 ++
 net/net.c            |    1 +
 12 files changed, 216 insertions(+), 1 deletions(-)
 create mode 100644 common/bootstage.c
 create mode 100644 include/bootstage.h

-- 
1.7.3.1

[U-Boot] [PATCH 1/4] Add microsecond boot time measurement

[Simon Glass]

This defines the basics of a new boot time measurement feature. This allows
logging of very accurate time measurements as the boot proceeds, by using
an available microsecond counter.

Signed-off-by: Simon Glass <sjg@chromium.org>
---
 README              |   11 ++++++++
 common/Makefile     |    1 +
 common/bootstage.c  |   49 +++++++++++++++++++++++++++++++++++
 include/bootstage.h |   71 +++++++++++++++++++++++++++++++++++++++++++++++++++
 include/common.h    |    8 ++++++
 5 files changed, 140 insertions(+), 0 deletions(-)
 create mode 100644 common/bootstage.c
 create mode 100644 include/bootstage.h

diff --git a/README b/README
index 6f3748d..f9e4e65 100644
--- a/README
+++ b/README
@@ -2026,6 +2026,17 @@ The following options need to be configured:
 		example, some LED's) on your board. At the moment,
 		the following checkpoints are implemented:
 
+- Time boot progress
+		CONFIG_BOOTSTAGE
+
+		Define this option to enable microsecond boot stage timing
+		on supported platforms. For this to work your platform
+		needs to define a function timer_get_us() which returns the
+		number of microseconds since reset. This would normally
+		be done in your SOC or board timer.c file.
+
+		You can add calls to bootstage_mark() to set time markers.
+
 - Standalone program support:
 		CONFIG_STANDALONE_LOAD_ADDR
 
diff --git a/common/Makefile b/common/Makefile
index f81cff9..2c3bc9d 100644
--- a/common/Makefile
+++ b/common/Makefile
@@ -174,6 +174,7 @@ COBJS-$(CONFIG_LYNXKDI) += lynxkdi.o
 COBJS-$(CONFIG_MODEM_SUPPORT) += modem.o
 COBJS-$(CONFIG_UPDATE_TFTP) += update.o
 COBJS-$(CONFIG_USB_KEYBOARD) += usb_kbd.o
+COBJS-$(CONFIG_BOOTSTAGE) += bootstage.o
 
 
 COBJS	:= $(sort $(COBJS-y))
diff --git a/common/bootstage.c b/common/bootstage.c
new file mode 100644
index 0000000..10f1f34
--- /dev/null
+++ b/common/bootstage.c
@@ -0,0 +1,49 @@
+/*
+ * Copyright (c) 2011 The Chromium OS Authors.
+ *
+ * See file CREDITS for list of people who contributed to this
+ * project.
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License as
+ * published by the Free Software Foundation; either version 2 of
+ * the License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place, Suite 330, Boston,
+ * MA 02111-1307 USA
+ */
+
+
+/*
+ * This module records the progress of boot and arbitrary commands, and
+ * permits accurate timestamping of each.
+ */
+
+#include <common.h>
+
+
+struct bootstage_record {
+	uint32_t time_us;
+	const char *name;
+};
+
+static struct bootstage_record record[BOOTSTAGE_COUNT];
+
+uint32_t bootstage_mark(enum bootstage_id id, const char *name)
+{
+	struct bootstage_record *rec = &record[id];
+
+	/* Only record the first event for each */
+	if (!rec->name) {
+		rec->time_us = (uint32_t)timer_get_us();
+		rec->name = name;
+	}
+	return rec->time_us;
+}
diff --git a/include/bootstage.h b/include/bootstage.h
new file mode 100644
index 0000000..ba656ff
--- /dev/null
+++ b/include/bootstage.h
@@ -0,0 +1,71 @@
+/*
+ * Copyright (c) 2011 The Chromium OS Authors.
+ *
+ * See file CREDITS for list of people who contributed to this
+ * project.
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License as
+ * published by the Free Software Foundation; either version 2 of
+ * the License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place, Suite 330, Boston,
+ * MA 02111-1307 USA
+ */
+
+#ifndef __BOOTSTAGE_H
+#define __BOOTSTAGE_H
+
+/*
+ * These are the things that can be timestamped. There are some pre-defined
+ * by U-Boot, and some which are user defined.
+ */
+enum bootstage_id {
+	BOOTSTAGE_AWAKE,
+	BOOTSTAGE_START_UBOOT,
+	BOOTSTAGE_USB_START,
+	BOOTSTAGE_ETH_START,
+	BOOTSTAGE_BOOTP_START,
+	BOOTSTAGE_BOOTP_STOP,
+	BOOTSTAGE_KERNELREAD_START,
+	BOOTSTAGE_KERNELREAD_STOP,
+	BOOTSTAGE_BOOTM_START,
+	BOOTSTAGE_BOOTM_HANDOFF,
+
+	/* a few spare for the user, from here */
+	BOOTSTAGE_USER,
+
+	/*
+	 * Total number of entries - increase this at the cost of some BSS
+	 * and ATAG space.
+	 */
+	BOOTSTAGE_COUNT = 10
+};
+
+#ifdef CONFIG_BOOTSTAGE
+
+/**
+ * Mark a time stamp for the current boot stage.
+ *
+ * @param id	ID from enum bootstage_id
+ * @param name	name for this stage
+ * @returns timestamp in microseconds
+ */
+uint32_t bootstage_mark(enum bootstage_id id, const char *name);
+
+#else
+
+static inline uint32_t bootstage_mark(enum bootstage_id id, const char *name)
+{}
+
+#endif
+
+#endif
+
diff --git a/include/common.h b/include/common.h
index 1e4a6a5..04b0102 100644
--- a/include/common.h
+++ b/include/common.h
@@ -177,6 +177,14 @@ typedef void (interrupt_handler_t)(void *);
 #endif /* CONFIG_SERIAL_MULTI */
 
 /*
+ * Return the time since boot in microseconds, This is needed for bootstage
+ * and should be defined in CPU- or board-specific code.
+ */
+unsigned long timer_get_us(void);
+
+#include <bootstage.h>
+
+/*
  * General Purpose Utilities
  */
 #define min(X, Y)				\
-- 
1.7.3.1

[U-Boot] [PATCH 2/4] Add bootstage progress report

[Simon Glass]

You can call bootstage_report() at any time to print a report on boot stage
timings. It should ideally be called just before U-Boot hands off execution
to the next stage boot.

Signed-off-by: Simon Glass <sjg@chromium.org>
---
 common/bootstage.c  |   48 ++++++++++++++++++++++++++++++++++++++++++++++++
 include/bootstage.h |    3 +++
 2 files changed, 51 insertions(+), 0 deletions(-)

diff --git a/common/bootstage.c b/common/bootstage.c
index 10f1f34..5e0178a 100644
--- a/common/bootstage.c
+++ b/common/bootstage.c
@@ -47,3 +47,51 @@ uint32_t bootstage_mark(enum bootstage_id id, const char *name)
 	}
 	return rec->time_us;
 }
+
+static void print_time(unsigned long us_time)
+{
+	char str[12], *s;
+	int grab = 3;
+
+	/* We don't seem to have %'d in U-Boot */
+	sprintf(str, "%9ld", us_time);
+	for (s = str; *s; s += grab) {
+		if (s != str)
+			putc(s[-1] != ' ' ? ',' : ' ');
+		printf("%.*s", grab, s);
+		grab = 3;
+	}
+}
+
+static uint32_t print_time_record(enum bootstage_id id,
+			struct bootstage_record *rec, uint32_t prev)
+{
+	print_time(rec->time_us);
+	print_time(rec->time_us - prev);
+	if (rec->name)
+		printf("  %s\n", rec->name);
+	else
+		printf("  id=%d\n", id);
+	return rec->time_us;
+}
+
+void bootstage_report(void)
+{
+	int id;
+	uint32_t prev;
+
+	puts("Timer summary in microseconds:\n");
+	printf("%11s%11s  %s\n", "Mark", "Elapsed", "Stage");
+
+	/* Fake the first record - we could get it from early boot */
+	prev = 0;
+	record[BOOTSTAGE_AWAKE].name = "awake";
+
+	for (id = 0; id < BOOTSTAGE_COUNT; id++) {
+		struct bootstage_record *rec = &record[id];
+
+		if (id == BOOTSTAGE_AWAKE || rec->time_us != 0)
+			prev = print_time_record(id, rec, prev);
+	}
+}
+
diff --git a/include/bootstage.h b/include/bootstage.h
index ba656ff..b645434 100644
--- a/include/bootstage.h
+++ b/include/bootstage.h
@@ -60,6 +60,9 @@ enum bootstage_id {
  */
 uint32_t bootstage_mark(enum bootstage_id id, const char *name);
 
+/* Print a report about boot time */
+void bootstage_report(void);
+
 #else
 
 static inline uint32_t bootstage_mark(enum bootstage_id id, const char *name)
-- 
1.7.3.1

[U-Boot] [PATCH 3/4] Add bootstage calls in places appropriate for network booting

[Simon Glass]

This adds calls to to the bootstage_mark() function at various places
through the boot process.

Signed-off-by: Simon Glass <sjg@chromium.org>
---
 arch/arm/lib/board.c |    2 ++
 arch/arm/lib/bootm.c |    1 +
 common/cmd_bootm.c   |    2 ++
 common/cmd_net.c     |    7 ++++++-
 common/cmd_usb.c     |    1 +
 net/bootp.c          |    3 +++
 net/net.c            |    1 +
 7 files changed, 16 insertions(+), 1 deletions(-)

diff --git a/arch/arm/lib/board.c b/arch/arm/lib/board.c
index 1a784a1..13a86c3 100644
--- a/arch/arm/lib/board.c
+++ b/arch/arm/lib/board.c
@@ -275,6 +275,8 @@ void board_init_f (ulong bootflag)
 	gd_t *id;
 	ulong addr, addr_sp;
 
+	bootstage_mark(BOOTSTAGE_START_UBOOT, "start_armboot");
+
 	/* Pointer is writable since we allocated a register for it */
 	gd = (gd_t *) ((CONFIG_SYS_INIT_SP_ADDR) & ~0x07);
 	/* compiler optimization barrier needed for GCC >= 3.4 */
diff --git a/arch/arm/lib/bootm.c b/arch/arm/lib/bootm.c
index 802e833..b763403 100644
--- a/arch/arm/lib/bootm.c
+++ b/arch/arm/lib/bootm.c
@@ -83,6 +83,7 @@ void arch_lmb_reserve(struct lmb *lmb)
 static void announce_and_cleanup(void)
 {
 	printf("\nStarting kernel ...\n\n");
+	bootstage_mark(BOOTSTAGE_BOOTM_HANDOFF, "start_kernel");
 
 #ifdef CONFIG_USB_DEVICE
 	{
diff --git a/common/cmd_bootm.c b/common/cmd_bootm.c
index 1966da4..212e510 100644
--- a/common/cmd_bootm.c
+++ b/common/cmd_bootm.c
@@ -221,6 +221,8 @@ static int bootm_start(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]
 
 	bootm_start_lmb();
 
+	bootstage_mark(BOOTSTAGE_BOOTM_START, "bootm_start");
+
 	/* get kernel image header, start address and length */
 	os_hdr = boot_get_kernel (cmdtp, flag, argc, argv,
 			&images, &images.os.image_start, &images.os.image_len);
diff --git a/common/cmd_net.c b/common/cmd_net.c
index 8c6f5c8..49f8ffd 100644
--- a/common/cmd_net.c
+++ b/common/cmd_net.c
@@ -43,7 +43,12 @@ U_BOOT_CMD(
 
 int do_tftpb (cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[])
 {
-	return netboot_common (TFTP, cmdtp, argc, argv);
+	int ret;
+
+	bootstage_mark(BOOTSTAGE_KERNELREAD_START, "tftp start");
+	ret = netboot_common(TFTP, cmdtp, argc, argv);
+	bootstage_mark(BOOTSTAGE_KERNELREAD_STOP, "tftp done");
+	return ret;
 }
 
 U_BOOT_CMD(
diff --git a/common/cmd_usb.c b/common/cmd_usb.c
index 3ba6fff..c7b30a0 100644
--- a/common/cmd_usb.c
+++ b/common/cmd_usb.c
@@ -522,6 +522,7 @@ int do_usb(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[])
 
 	if ((strncmp(argv[1], "reset", 5) == 0) ||
 		 (strncmp(argv[1], "start", 5) == 0)) {
+		bootstage_mark(BOOTSTAGE_USB_START, "usb_start");
 		usb_stop();
 		printf("(Re)start USB...\n");
 		i = usb_init();
diff --git a/net/bootp.c b/net/bootp.c
index 4db63cb..043f9e0 100644
--- a/net/bootp.c
+++ b/net/bootp.c
@@ -311,6 +311,7 @@ BootpHandler(uchar *pkt, unsigned dest, IPaddr_t sip, unsigned src,
 		BootpVendorProcess((uchar *)&bp->bp_vend[4], len);
 
 	NetSetTimeout(0, (thand_f *)0);
+	bootstage_mark(BOOTSTAGE_BOOTP_STOP, "bootp_stop");
 
 	debug("Got good BOOTP\n");
 
@@ -552,6 +553,7 @@ BootpRequest (void)
 	Bootp_t *bp;
 	int ext_len, pktlen, iplen;
 
+	bootstage_mark(BOOTSTAGE_BOOTP_START, "bootp_start");
 #if defined(CONFIG_CMD_DHCP)
 	dhcp_state = INIT;
 #endif
@@ -914,6 +916,7 @@ DhcpHandler(uchar *pkt, unsigned dest, IPaddr_t sip, unsigned src,
 			BootpCopyNetParams(bp); /* Store net params from reply */
 			dhcp_state = BOUND;
 			printf ("DHCP client bound to address %pI4\n", &NetOurIP);
+			bootstage_mark(BOOTSTAGE_BOOTP_STOP, "bootp_stop");
 
 			/* Obey the 'autoload' setting */
 			if ((s = getenv("autoload")) != NULL) {
diff --git a/net/net.c b/net/net.c
index 2abf879..5ff99b6 100644
--- a/net/net.c
+++ b/net/net.c
@@ -377,6 +377,7 @@ NetLoop(proto_t protocol)
 		NetArpWaitTxPacketSize = 0;
 	}
 
+	bootstage_mark(BOOTSTAGE_ETH_START, "eth_start");
 	eth_halt();
 #ifdef CONFIG_NET_MULTI
 	eth_set_current();
-- 
1.7.3.1

[U-Boot] [PATCH 4/4] Add option to print boot stage report before starting kernel

[Simon Glass]

Define CONFIG_BOOTSTAGE_REPORT to get a timing report before the kernel
runs.

Signed-off-by: Simon Glass <sjg@chromium.org>
---
 README               |    6 ++++++
 arch/arm/lib/bootm.c |    3 +++
 2 files changed, 9 insertions(+), 0 deletions(-)

diff --git a/README b/README
index f9e4e65..d53981c 100644
--- a/README
+++ b/README
@@ -2037,6 +2037,12 @@ The following options need to be configured:
 
 		You can add calls to bootstage_mark() to set time markers.
 
+		CONFIG_BOOTSTAGE_REPORT
+
+		Define this to get a report listing the timing information
+		collected during the boot process. This is generated just
+		before control is handed off to the kernel.
+
 - Standalone program support:
 		CONFIG_STANDALONE_LOAD_ADDR
 
diff --git a/arch/arm/lib/bootm.c b/arch/arm/lib/bootm.c
index b763403..5116e95 100644
--- a/arch/arm/lib/bootm.c
+++ b/arch/arm/lib/bootm.c
@@ -84,6 +84,9 @@ static void announce_and_cleanup(void)
 {
 	printf("\nStarting kernel ...\n\n");
 	bootstage_mark(BOOTSTAGE_BOOTM_HANDOFF, "start_kernel");
+#ifdef CONFIG_BOOTSTAGE_REPORT
+	bootstage_report();
+#endif
 
 #ifdef CONFIG_USB_DEVICE
 	{
-- 
1.7.3.1

[U-Boot] [PATCH 1/4] Add microsecond boot time measurement

[Mike Frysinger]

On Friday, May 13, 2011 16:52:00 Simon Glass wrote:
> --- /dev/null
> +++ b/common/bootstage.c
> +/*
> + * Copyright (c) 2011 The Chromium OS Authors.

i'm not sure this is valid unless "Chromium OS Authors" is a legal entity

> +uint32_t bootstage_mark(enum bootstage_id id, const char *name)
> +{
> +	struct bootstage_record *rec = &record[id];
> +
> +	/* Only record the first event for each */
> +	if (!rec->name) {
> +		rec->time_us = (uint32_t)timer_get_us();

cast is pointless when time_us is of uint32_t type

> --- /dev/null
> +++ b/include/bootstage.h
> +enum bootstage_id {
> +	BOOTSTAGE_AWAKE,
> +	BOOTSTAGE_START_UBOOT,
> +	BOOTSTAGE_USB_START,
> +	BOOTSTAGE_ETH_START,
> +	BOOTSTAGE_BOOTP_START,
> +	BOOTSTAGE_BOOTP_STOP,
> +	BOOTSTAGE_KERNELREAD_START,
> +	BOOTSTAGE_KERNELREAD_STOP,
> +	BOOTSTAGE_BOOTM_START,
> +	BOOTSTAGE_BOOTM_HANDOFF,
> +
> +	/* a few spare for the user, from here */
> +	BOOTSTAGE_USER,
> +
> +	/*
> +	 * Total number of entries - increase this at the cost of some BSS
> +	 * and ATAG space.
> +	 */
> +	BOOTSTAGE_COUNT = 10
> +};

mmm BOOTSTAGE_COUNT supposed to be the number of enum's ?  hardcoding the 
number doesnt seem like a good idea ... how about just placing it at the right 
location in the list and let gcc calc the right value ?

> +static inline uint32_t bootstage_mark(enum bootstage_id id, const char
> *name) {}

missing a return value

> --- a/include/common.h
> +++ b/include/common.h
> +#include <bootstage.h>

in general, i'd rather see individual files opt in to the headers they need 
rather than having one giant header that includes everything else ...
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110514/062d62c5/attachment.pgp 

[U-Boot] [PATCH 1/4] Add microsecond boot time measurement

[Mike Frysinger]

On Friday, May 13, 2011 16:52:00 Simon Glass wrote:
> --- a/include/common.h
> +++ b/include/common.h
> @@ -177,6 +177,14 @@ typedef void (interrupt_handler_t)(void *);
>  #endif /* CONFIG_SERIAL_MULTI */
> 
>  /*
> + * Return the time since boot in microseconds, This is needed for
> bootstage
> + * and should be defined in CPU- or board-specific code.
> + */
> +unsigned long timer_get_us(void);

the API is already "get_timer()" for msec precision, so this probably should 
be named "timer_get_us()".  although this differs from the common "get_timer" 
in that this is supposed to return an absolute time from boot instead of 
relative to the passed in "base", so probably want to name it accordingly to 
avoid confusion: timer_get_boot_us().

the POST code already has a func that does this called "post_time_ms()".  so 
that should get thrown out and converted to this new func.

all of which means this particular func should be a sep patch.
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110514/81676fe0/attachment.pgp 

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Mike Frysinger]

On Friday, May 13, 2011 16:51:59 Simon Glass wrote:
> This defines the basics of a new boot time measurement feature. This allows
> logging of very accurate time measurements as the boot proceeds, by using
> an available microsecond counter.
> 
> To enable the feature, define CONFIG_BOOTSTAGE in your board config file.
> Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be
> printed just before handing off to the OS.

this seems to overlap the existing show_boot_progress() code.  any chance we 
can look at these being merged ?
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110514/803dcf2d/attachment.pgp 

[U-Boot] [PATCH 2/4] Add bootstage progress report

[Mike Frysinger]

On Friday, May 13, 2011 16:52:01 Simon Glass wrote:
> --- a/common/bootstage.c
> +++ b/common/bootstage.c
> +static void print_time(unsigned long us_time)
> +{
> +	char str[12], *s;
> +	int grab = 3;
> +
> +	/* We don't seem to have %'d in U-Boot */

do add it ?  this isnt really "printing time", it's formatting a number with a 
thousands separator which means it probably should be in common code with a 
different name at least.

> +

no trailing newlines please
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110514/152ab85c/attachment.pgp 

[U-Boot] [PATCH 3/4] Add bootstage calls in places appropriate for network booting

[Mike Frysinger]

On Friday, May 13, 2011 16:52:02 Simon Glass wrote:
> +	bootstage_mark(BOOTSTAGE_BOOTM_HANDOFF, "start_kernel");

cant we internalize this string to the bootstage code itself ?
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110514/02511ce0/attachment.pgp 

[U-Boot] [PATCH 4/4] Add option to print boot stage report before starting kernel

[Mike Frysinger]

On Friday, May 13, 2011 16:52:03 Simon Glass wrote:
> --- a/arch/arm/lib/bootm.c
> +++ b/arch/arm/lib/bootm.c
> +#ifdef CONFIG_BOOTSTAGE_REPORT
> +	bootstage_report();
> +#endif

the header should add a stub for this so the #ifdef lives in only one place
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110514/0ea34fdd/attachment.pgp 

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

On Sat, May 14, 2011 at 4:34 AM, Mike Frysinger <vapier@gentoo.org> wrote:

> On Friday, May 13, 2011 16:51:59 Simon Glass wrote:
> > This defines the basics of a new boot time measurement feature. This
> allows
> > logging of very accurate time measurements as the boot proceeds, by using
> > an available microsecond counter.
> >
> > To enable the feature, define CONFIG_BOOTSTAGE in your board config file.
> > Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be
> > printed just before handing off to the OS.
>
> this seems to overlap the existing show_boot_progress() code.  any chance
> we
> can look at these being merged ?
> -mike
>

Hi Mike,

Yes I did look at this a few weeks ago. It would be a pretty invasive
change. That code just uses a whole lot of numbers which presumably are
approximately how far through the boot process we are. Bootstage is intended
as a debugging tool for performance tune-up rather than a user display tool.
I could imagine adding a table to bootstage with the progess number for each
bootstage id, but then people are going to complain that the bootstage
report is far to long and includes uninteresting things. I suppose I could
fix that by including a flag as to whether to report each item or not...but
it any case as you can see it is not a clear win.

If there is a strong appetite for that sort of patch I'm happy to do it.

Regards,
Simon

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On 15/05/11 03:32, Simon Glass wrote:
> On Sat, May 14, 2011 at 4:34 AM, Mike Frysinger <vapier@gentoo.org> wrote:
> 
>> On Friday, May 13, 2011 16:51:59 Simon Glass wrote:
>>> This defines the basics of a new boot time measurement feature. This
>> allows
>>> logging of very accurate time measurements as the boot proceeds, by using
>>> an available microsecond counter.
>>>
>>> To enable the feature, define CONFIG_BOOTSTAGE in your board config file.
>>> Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be
>>> printed just before handing off to the OS.
>>
>> this seems to overlap the existing show_boot_progress() code.  any chance
>> we
>> can look at these being merged ?
>> -mike
>>
> 
> Hi Mike,
> 
> Yes I did look at this a few weeks ago. It would be a pretty invasive
> change. That code just uses a whole lot of numbers which presumably are
> approximately how far through the boot process we are. Bootstage is intended
> as a debugging tool for performance tune-up rather than a user display tool.
> I could imagine adding a table to bootstage with the progess number for each
> bootstage id, but then people are going to complain that the bootstage
> report is far to long and includes uninteresting things. I suppose I could
> fix that by including a flag as to whether to report each item or not...but
> it any case as you can see it is not a clear win.
> 
> If there is a strong appetite for that sort of patch I'm happy to do it.
> 
> Regards,
> Simon
> 

Couple of thoughts:
  - Macro the definition of show_boot_progress() so it accepts a (const
    char *) argument if CONFIG_BOOTSTAGE is defined
  - Change BOOTSTAGE_COUNT to CONFIG_MAX_BOOTSTAGE_RECORDS
  - Any call to show_boot_progress() with a non-null second argument
    causes it to be logged in the next available bootstage record
  - After the last bootstage record is filled, no further calls to
    show_boot_progress() cause logging to the bootstage records
  - Instead of CONFIG_BOOTSTAGE_REPORT, create a command which dumps the
    contents of the bootstage records

No this is going to result in a big patch (every instance of
show_boot_progress() will need to be touched to at least add NULL as the
second parameter - Maintainers can add better text later ;)

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Simon Glass,

In message <1305319923-9477-1-git-send-email-sjg@chromium.org> you wrote:
> This defines the basics of a new boot time measurement feature. This allows
> logging of very accurate time measurements as the boot proceeds, by using
> an available microsecond counter.

Well, as long as we talk about microsecond resolution, I do not see
the compelling advantage over the classic method of timing the output
on the serial console port.  At 115200 bps we have a "resolution" of
better than 0.1 millisecond per character; this should be precise
enough for most practical purposes.

Logging and timing the serial output has a number of advantages over
other solutions:

- It requires zero code changes.  You can run the production code and
  time it.  You can use it without rebuilding / reinstalling the
  software, yes even without access to the source code.
- It is completely platform, SoC and board idependent - we do not need
  to provide any specific timer servcies etc. which are inherently
  platform-dependent.
- It does not cause execution overhead on the running system - it
  affects neither the execution speed not the memory footprint of the
  target under test.

Can you please explain where your solution is better than this
approach, i. e. which problems can be addressed with your code where
the output timing method cannot be used, or where it is less
efficient?

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
"Oh dear, I think you'll find reality's on the blink again."
- Marvin The Paranoid Android

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

On Sun, May 15, 2011 at 3:03 AM, Graeme Russ <graeme.russ@gmail.com> wrote:

> Couple of thoughts:
>  - Macro the definition of show_boot_progress() so it accepts a (const
>    char *) argument if CONFIG_BOOTSTAGE is defined
>  - Change BOOTSTAGE_COUNT to CONFIG_MAX_BOOTSTAGE_RECORDS
>  - Any call to show_boot_progress() with a non-null second argument
>    causes it to be logged in the next available bootstage record
>  - After the last bootstage record is filled, no further calls to
>    show_boot_progress() cause logging to the bootstage records
>  - Instead of CONFIG_BOOTSTAGE_REPORT, create a command which dumps the
>    contents of the bootstage records
>
> No this is going to result in a big patch (every instance of
> show_boot_progress() will need to be touched to at least add NULL as the
> second parameter - Maintainers can add better text later ;)
>

Thanks for your thoughts. It can be done, but my bigger question is this:

> If there is a strong appetite for that sort of patch I'm happy to do it.

If I get some +ve responses then I will do it, otherwise I think I should
assume people want this left as is.

Regards,
Simon


>
> Regards,
>
> Graeme
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

On Sun, May 15, 2011 at 4:53 AM, Wolfgang Denk <wd@denx.de> wrote:

> Dear Simon Glass,
>
> In message <1305319923-9477-1-git-send-email-sjg@chromium.org> you wrote:
> > This defines the basics of a new boot time measurement feature. This
> allows
> > logging of very accurate time measurements as the boot proceeds, by using
> > an available microsecond counter.
>
> Well, as long as we talk about microsecond resolution, I do not see
> the compelling advantage over the classic method of timing the output
> on the serial console port.  At 115200 bps we have a "resolution" of
> better than 0.1 millisecond per character; this should be precise
> enough for most practical purposes.
>

Hi Wolfgang,

This is 100us which is pretty good although you are assuming that there is
no FIFO holding things. Also on modern ARM CPUs the 'processing' part of
U-Boot (where it is not just waiting on a device) can be over in under
100ms, and if you are wanting to reduce this, a little more resolution
doesn't hurt.


> Logging and timing the serial output has a number of advantages over
> other solutions:
>
> - It requires zero code changes.  You can run the production code and
>  time it.  You can use it without rebuilding / reinstalling the
>  software, yes even without access to the source code.
>

Are you not ignoring the timing parser on the serial port which must be
written and changed to cope with the different output of U-Boot (net boot,
USB boot, MMC boot, SD boot, etc.)? We have a lot of boot paths, different
architectures, etc. We want a simple solution.

In our case the console is silent on boot, so this solution does not work.
Secondly it requires a listener on the serial port which we often don't
have. Thirdly we want to log this information and record it in the field so
that we track boot time. This means that it has to be done by the device
itself.


> - It is completely platform, SoC and board idependent - we do not need
>  to provide any specific timer servcies etc. which are inherently
>  platform-dependent.
>

Is this really an advantage?


> - It does not cause execution overhead on the running system - it
>  affects neither the execution speed not the memory footprint of the
>  target under test.
>

Write to the serial port costs about 30ms on our platform at minimum. I
have't looked at why, but the serial FIFO is only so big so I assume that is
what is happening. The overhead of bootstage is a function call, a readl(),
a a few memory accesses and an optional strcpy. It is much cheaper than
outputting a serial character.

>
> Can you please explain where your solution is better than this
> approach, i. e. which problems can be addressed with your code where
> the output timing method cannot be used, or where it is less
> efficient?
>

With a little bit of cheating I can think of 10:

1. It doesn't need a serial watcher to be connected, which is not available
in the field, and is something that anyway would only be attached when the
engineer is not using the console for actually typing commands.

2. It is internal to the code, so as different code paths are taken it still
has working timing, and doesn't rely on separate serial traffic parsing code
to work out what happened

3. It still works with a silent console (we can either unmute the console
and print the info, or pass it on to Linux for logging)

4. It is simpler to write and extend (just add a new bootstage call around
any interesting section even if there is no serial output there)

5. It allows timing of things which don't result in serial output.

6. It times when the event actually happens rather than when a character
makes its way through a UART FIFO. At worst the character might take a few
ms to get through the FIFO which will skew timings.

7. It potentially allows two CPUs to run concurrently and log progress (no I
am not working on that yet).

8. We can log the information in the field, perhaps by passing it to Linux

9. There is only one code base to be changed when a boot path is adjusted.

10. It has higher resolution.

Regards,
Simon


>
> Best regards,
>
> Wolfgang Denk
>
> --
> DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
> HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
> Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
> "Oh dear, I think you'll find reality's on the blink again."
> - Marvin The Paranoid Android
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 7:58 AM, Simon Glass <sjg@chromium.org> wrote:
> On Sun, May 15, 2011 at 4:53 AM, Wolfgang Denk <wd@denx.de> wrote:
>
>> Dear Simon Glass,
>>
>> In message <1305319923-9477-1-git-send-email-sjg@chromium.org> you wrote:
>> > This defines the basics of a new boot time measurement feature. This
>> allows
>> > logging of very accurate time measurements as the boot proceeds, by using
>> > an available microsecond counter.
>>
>> Well, as long as we talk about microsecond resolution, I do not see
>> the compelling advantage over the classic method of timing the output
>> on the serial console port. ?At 115200 bps we have a "resolution" of
>> better than 0.1 millisecond per character; this should be precise
>> enough for most practical purposes.
>>

But at 9600 baud it is over 1ms - 9600 is still considered the lowest
common denominator for serial comms for diagnostic output for a lot of
devices such as industrial PLCs etc.

> Hi Wolfgang,
>
> This is 100us which is pretty good although you are assuming that there is
> no FIFO holding things. Also on modern ARM CPUs the 'processing' part of
> U-Boot (where it is not just waiting on a device) can be over in under
> 100ms, and if you are wanting to reduce this, a little more resolution
> doesn't hurt.
>
>
>> Logging and timing the serial output has a number of advantages over
>> other solutions:
>>
>> - It requires zero code changes. ?You can run the production code and
>> ?time it. ?You can use it without rebuilding / reinstalling the
>> ?software, yes even without access to the source code.
>>
>
> Are you not ignoring the timing parser on the serial port which must be
> written and changed to cope with the different output of U-Boot (net boot,
> USB boot, MMC boot, SD boot, etc.)? We have a lot of boot paths, different
> architectures, etc. We want a simple solution.
>
> In our case the console is silent on boot, so this solution does not work.
> Secondly it requires a listener on the serial port which we often don't
> have. Thirdly we want to log this information and record it in the field so
> that we track boot time. This means that it has to be done by the device
> itself.

I concur - Obtaining the timing information requires that the serial
console application can generate it - something most default terminal apps
(Hyperterminal for example) do not do. Also, timing is skewed by the UART
FIFO on the device and the UART FIFO on the host.

And in the field, you may be interested more in transient timing anomalies
which may result from network issues if the device is obtaining an IP address
or loading an image file. In such scenarios, you will need to log the boot
timing of every boot, not just when a serial terminal is connected

And finally, the lack of a serial port is a biggie - There are devices out
there that do not have serial ports

>> - It is completely platform, SoC and board idependent - we do not need
>> ?to provide any specific timer servcies etc. which are inherently
>> ?platform-dependent.
>>
>
> Is this really an advantage?
>
>
>> - It does not cause execution overhead on the running system - it
>> ?affects neither the execution speed not the memory footprint of the
>> ?target under test.
>>
>
> Write to the serial port costs about 30ms on our platform at minimum. I
> have't looked at why, but the serial FIFO is only so big so I assume that is
> what is happening. The overhead of bootstage is a function call, a readl(),
> a a few memory accesses and an optional strcpy. It is much cheaper than
> outputting a serial character.

The strcpy can be avoided for the 'bootstage' call (more info in another
post later)

>>
>> Can you please explain where your solution is better than this
>> approach, i. e. which problems can be addressed with your code where
>> the output timing method cannot be used, or where it is less
>> efficient?
>>
>
> With a little bit of cheating I can think of 10:
>
> 1. It doesn't need a serial watcher to be connected, which is not available
> in the field, and is something that anyway would only be attached when the
> engineer is not using the console for actually typing commands.
>
> 2. It is internal to the code, so as different code paths are taken it still
> has working timing, and doesn't rely on separate serial traffic parsing code
> to work out what happened
>
> 3. It still works with a silent console (we can either unmute the console
> and print the info, or pass it on to Linux for logging)
>
> 4. It is simpler to write and extend (just add a new bootstage call around
> any interesting section even if there is no serial output there)
>
> 5. It allows timing of things which don't result in serial output.
>
> 6. It times when the event actually happens rather than when a character
> makes its way through a UART FIFO. At worst the character might take a few
> ms to get through the FIFO which will skew timings.
>
> 7. It potentially allows two CPUs to run concurrently and log progress (no I
> am not working on that yet).

Not really a benefit for U-Boot as we don't run multi-cpu (we only
initialise additional CPUs)

> 8. We can log the information in the field, perhaps by passing it to Linux

Same as 3

> 9. There is only one code base to be changed when a boot path is adjusted.
>
> 10. It has higher resolution.
>

I think an 'boot profiling' API will be a useful thing to have

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 7:34 AM, Simon Glass <sjg@chromium.org> wrote:
> On Sun, May 15, 2011 at 3:03 AM, Graeme Russ <graeme.russ@gmail.com> wrote:
>>
>> Couple of thoughts:
>> ?- Macro the definition of show_boot_progress() so it accepts a (const
>> ? ?char *) argument if CONFIG_BOOTSTAGE is defined
>> ?- Change BOOTSTAGE_COUNT to CONFIG_MAX_BOOTSTAGE_RECORDS
>> ?- Any call to show_boot_progress() with a non-null second argument
>> ? ?causes it to be logged in the next available bootstage record
>> ?- After the last bootstage record is filled, no further calls to
>> ? ?show_boot_progress() cause logging to the bootstage records
>> ?- Instead of CONFIG_BOOTSTAGE_REPORT, create a command which dumps the
>> ? ?contents of the bootstage records
>>
>> No this is going to result in a big patch (every instance of
>> show_boot_progress() will need to be touched to at least add NULL as the
>> second parameter - Maintainers can add better text later ;)

I've thought of a 'better' approach:
  - Do no modify the parameters of show_boot_progress()
  - Create a new struct:
    struct boot_progress_msg {
      int boot_progress_id;
      const char *message;
    {
  - Initialise the 'boot profile messages'
    struct boot_progress_msg boot_messages[] = {init with any boot progress
    id's you want to assign a text message too}
  - The 'bootstage record' array is simply an array of int's
  - show_boot_progress() logs the argument into the 'bootstage record'
    array as described before
  - The 'dump boot profile' command dumps the contents in the array,
    looking up matches in the 'boot profile messages' array to print out
    meaningful messages (or just the raw integer if no message defined)
  - Can show_boot_progress() be modified to add a 'flag' to select logging
    to the boot profile (do any platforms already use the highest bit for
    flagging for example) - Maybe #define CONFIG_BOOTSTAGE_LOG_FLAG in the
    config file to select an available bit
  - Create another command to compile the boot profile into a memory (for
    passing to Linux for example) - This command would need to perform
    strcpy() but is not in the time critical path anymore

So the 'time' overhead of profiling is
  - A call to show_boot_progress() (already there for a majority of cases)
  - A timer read
  - An integer test (current record < MAX_RECORDS)
  - A integer write to boot_messages[]
  - An integer increment (current_record++)

The code impact is now negligible - no modification to show_boot_progress()
calls unless the 'profile' flag is added and only minor modifications
to the show_boot_progress() function which can all be contained in an
#ifdef

The memory overhead can be as little as almost zero (have nothing in
boot_progress_msg boot_messages[])@the expense of you profile log
requiring code or documentation to decode (can even add a #define
CONFIG_BOOTSTAGE_MESSAGES)


> Thanks for your thoughts. It can be done, but my bigger question is this:
>> If there is a strong appetite for that sort of patch I'm happy to do it.
>
> If I get some +ve responses then I will do it, otherwise I think I should
> assume people want this left as is.

I hope some more people are interested ;)

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Mike Frysinger]

serial debug statements might work as a "poor mans" timing implementation, but 
i think it makes sense to have a binary framework for this.
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110515/119e9bfa/attachment.pgp 

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Simon Glass,

In message <BANLkTi=0ijj7DnLsjovO-3eQjMw+RSOQwg@mail.gmail.com> you wrote:
> 
> This is 100us which is pretty good although you are assuming that there is
> no FIFO holding things. Also on modern ARM CPUs the 'processing' part of

I don't see that we use any FIFOs in the output direction.

> U-Boot (where it is not just waiting on a device) can be over in under
> 100ms, and if you are wanting to reduce this, a little more resolution
> doesn't hurt.

Sorry, I cannot parse the "over in under 100 millisecond" part.

> > - It requires zero code changes.  You can run the production code and
> >  time it.  You can use it without rebuilding / reinstalling the
> >  software, yes even without access to the source code.
> >
> 
> Are you not ignoring the timing parser on the serial port which must be
> written and changed to cope with the different output of U-Boot (net boot,
> USB boot, MMC boot, SD boot, etc.)? We have a lot of boot paths, different
> architectures, etc. We want a simple solution.

Well, the "timing parser", as you callit, can be written in 10 lines
or less of your scripting language of choice.  See for example here
for a solution in expect/tcl: ftp://ftp.denx.de/pub/tools/time_log
We've been using this for about 10 years by now (see for example this
7 year old boot time analysis:
http://www.denx.de/wiki/DULG/AN2004_11_BootTimeOptimization).

As we can trivially use regular expressions, the effort to implement a
"timing parser" can be ignored. And it is independet of what sort of
boot device we are using.


You write: "We want a simple solution."  I agree 100%.

Isn;t a 10 line script code solution that does not require ANY changes
to the U-Boot code _much_ simpler than your approach?

This is why I was asking if your solution had any significant
advantages.

> In our case the console is silent on boot, so this solution does not work.

Point taken. But, you need to output the timing information, don't you?

> Secondly it requires a listener on the serial port which we often don't
> have. Thirdly we want to log this information and record it in the field so

You must have one to rea the time logs, right?

> that we track boot time. This means that it has to be done by the device
> itself.

Did you see cases where the boot time in the field differs from that
in your lab?  Can you please explain what is causing such differecnes?

> > - It is completely platform, SoC and board idependent - we do not need
> >  to provide any specific timer servcies etc. which are inherently
> >  platform-dependent.
> 
> Is this really an advantage?

Don't you think so?

Will you provide the code to implement your solution for all currently
supported BlackFin, ColdFire, MicroBlaze, MIPS, NIOS, PPC, SH, SPARC
or x86 CPUs?  Or even for all currently supported ARMN SoCs?

> > - It does not cause execution overhead on the running system - it
> >  affects neither the execution speed not the memory footprint of the
> >  target under test.
> 
> Write to the serial port costs about 30ms on our platform at minimum. I
> have't looked at why, but the serial FIFO is only so big so I assume that is

I think this can (and should) be fixed. It makes little sense to use a
FIFO in the transmit direction in U-Boot.

> what is happening. The overhead of bootstage is a function call, a readl(),
> a a few memory accesses and an optional strcpy. It is much cheaper than
> outputting a serial character.

But you need storage for the timing events, and you don't have this
before relocation. So you miss some really interesting parts of the
boot procedure.

> > approach, i. e. which problems can be addressed with your code where
> > the output timing method cannot be used, or where it is less
> > efficient?
> 
> With a little bit of cheating I can think of 10:
> 
> 1. It doesn't need a serial watcher to be connected, which is not available
> in the field, and is something that anyway would only be attached when the
> engineer is not using the console for actually typing commands.

OK, not needing a console port during boot is indeed an advantage.  It
comes at the cost of needing log space, which is not available before
relocation, so we miss some interesting parts of the boot procedure.

> 2. It is internal to the code, so as different code paths are taken it still
> has working timing, and doesn't rely on separate serial traffic parsing code
> to work out what happened

I don't consider this an advantage.  On contrary.

> 3. It still works with a silent console (we can either unmute the console
> and print the info, or pass it on to Linux for logging)

OK.

> 4. It is simpler to write and extend (just add a new bootstage call around
> any interesting section even if there is no serial output there)

This is plain wrong.  Compare your implementation against the 10 lines
of TCL code referenced above.

> 5. It allows timing of things which don't result in serial output.

But to do so, you need to insert trace points.  With the same effort
we can insert a printf().

> 6. It times when the event actually happens rather than when a character
> makes its way through a UART FIFO. At worst the character might take a few
> ms to get through the FIFO which will skew timings.

Serial drivers are not supposed to use FIFOs in the tx direction.

> 7. It potentially allows two CPUs to run concurrently and log progress (no I
> am not working on that yet).
> 
> 8. We can log the information in the field, perhaps by passing it to Linux
> 
> 9. There is only one code base to be changed when a boot path is adjusted.

...which is a disadvantage, because with the externat tool nothing
needs to be changed at all.

> 10. It has higher resolution.

OK.

I understand your position, and I too see some advantages of your
implementation.  But I see also disadvantages, especially it being a
pretty much intrusive change to large areas of the code, and being
available for a single platform only.  Also, I see it as a
disadvantage that you lose pre-relocation information.

So far, I am not convinced that the result is worth the effort.

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
Syntactic sugar causes cancer of the semicolon.
                - Epigrams in Programming, ACM SIGPLAN Sept. 1982

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Graeme Russ,

In message <BANLkTim7=-rZa_L-Dy0B-+aDqv4ngOLb-g@mail.gmail.com> you wrote:
>
> But at 9600 baud it is over 1ms - 9600 is still considered the lowest
> common denominator for serial comms for diagnostic output for a lot of
> devices such as industrial PLCs etc.

I think in the last 5 years I have seen but 2 devices using 9600 bps.
All others appear to be using 115200 bps these days.

And even at 9600 we're still close to millisecond reolution...

> And in the field, you may be interested more in transient timing anomalies
> which may result from network issues if the device is obtaining an IP address
> or loading an image file. In such scenarios, you will need to log the boot
> timing of every boot, not just when a serial terminal is connected

time-stamping console output is not restricted to the serial port.  It
works as well with tty over USB, or netconsole, or even netconsole
over USB.

> And finally, the lack of a serial port is a biggie - There are devices out
> there that do not have serial ports

If they have a console interface, then the output can be time-stamped.


Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
To know how another being, another creature feels -  that  is  impos-
sible.                  - Terry Pratchett, _The Dark Side of the Sun_

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Graeme Russ,

In message <BANLkTinsYPvnPg06uoLZE65t-FCqdN_-tg@mail.gmail.com> you wrote:
>
> I've thought of a 'better' approach:
>   - Do no modify the parameters of show_boot_progress()
>   - Create a new struct:
>     struct boot_progress_msg {
>       int boot_progress_id;
>       const char *message;
>     {

Where do you store this data _before_ relocation, when we have no
access to RAM yet?

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
The years of peak mental activity are undoubtedly between the ages of
four and eighteen. At four we know all the questions, at eighteen all
the answers.

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 3:56 PM, Wolfgang Denk <wd@denx.de> wrote:
> Dear Graeme Russ,
>
> In message <BANLkTinsYPvnPg06uoLZE65t-FCqdN_-tg@mail.gmail.com> you wrote:
>>
>> I've thought of a 'better' approach:
>> ? - Do no modify the parameters of show_boot_progress()
>> ? - Create a new struct:
>> ? ? struct boot_progress_msg {
>> ? ? ? int boot_progress_id;
>> ? ? ? const char *message;
>> ? ? {
>
> Where do you store this data _before_ relocation, when we have no
> access to RAM yet?

This data is Read-Only so pre/post relocation is not an issue. The boot
stage records however are a problem

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 3:55 PM, Wolfgang Denk <wd@denx.de> wrote:
> Dear Graeme Russ,
>
> In message <BANLkTim7=-rZa_L-Dy0B-+aDqv4ngOLb-g@mail.gmail.com> you wrote:
>>
>> But at 9600 baud it is over 1ms - 9600 is still considered the lowest
>> common denominator for serial comms for diagnostic output for a lot of
>> devices such as industrial PLCs etc.
>
> I think in the last 5 years I have seen but 2 devices using 9600 bps.
> All others appear to be using 115200 bps these days.
>
> And even at 9600 we're still close to millisecond reolution...
>
>> And in the field, you may be interested more in transient timing anomalies
>> which may result from network issues if the device is obtaining an IP address
>> or loading an image file. In such scenarios, you will need to log the boot
>> timing of every boot, not just when a serial terminal is connected
>
> time-stamping console output is not restricted to the serial port. ?It
> works as well with tty over USB, or netconsole, or even netconsole
> over USB.

My point is, if the device reboots in the field, you cannot recover the
boot timing analysis as once it is streamed out it is gone forever

>
>> And finally, the lack of a serial port is a biggie - There are devices out
>> there that do not have serial ports
>
> If they have a console interface, then the output can be time-stamped.

See above

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 3:48 PM, Wolfgang Denk <wd@denx.de> wrote:
> Dear Simon Glass,
>
> In message <BANLkTi=0ijj7DnLsjovO-3eQjMw+RSOQwg@mail.gmail.com> you wrote:
>>
>> This is 100us which is pretty good although you are assuming that there is
>> no FIFO holding things. Also on modern ARM CPUs the 'processing' part of
>
> I don't see that we use any FIFOs in the output direction.
>
>> U-Boot (where it is not just waiting on a device) can be over in under
>> 100ms, and if you are wanting to reduce this, a little more resolution
>> doesn't hurt.
>
> Sorry, I cannot parse the "over in under 100 millisecond" part.
>
>> > - It requires zero code changes. ?You can run the production code and
>> > ?time it. ?You can use it without rebuilding / reinstalling the
>> > ?software, yes even without access to the source code.
>> >
>>
>> Are you not ignoring the timing parser on the serial port which must be
>> written and changed to cope with the different output of U-Boot (net boot,
>> USB boot, MMC boot, SD boot, etc.)? We have a lot of boot paths, different
>> architectures, etc. We want a simple solution.
>
> Well, the "timing parser", as you callit, can be written in 10 lines
> or less of your scripting language of choice. ?See for example here
> for a solution in expect/tcl: ftp://ftp.denx.de/pub/tools/time_log
> We've been using this for about 10 years by now (see for example this
> 7 year old boot time analysis:
> http://www.denx.de/wiki/DULG/AN2004_11_BootTimeOptimization).
>
> As we can trivially use regular expressions, the effort to implement a
> "timing parser" can be ignored. And it is independet of what sort of
> boot device we are using.
>

Fine if your running Linux - What if the only tool tyou have is
Hyperterminal?

>
> You write: "We want a simple solution." ?I agree 100%.
>
> Isn;t a 10 line script code solution that does not require ANY changes
> to the U-Boot code _much_ simpler than your approach?
>
> This is why I was asking if your solution had any significant
> advantages.
>
>> In our case the console is silent on boot, so this solution does not work.
>
> Point taken. But, you need to output the timing information, don't you?

If it can be compiled by U-Boot and passed to the OS then the OS can do
the ou

>> Secondly it requires a listener on the serial port which we often don't
>> have. Thirdly we want to log this information and record it in the field so
>
> You must have one to rea the time logs, right?

Maybe it can be retrieved over a network connection

>> that we track boot time. This means that it has to be done by the device
>> itself.
>
> Did you see cases where the boot time in the field differs from that
> in your lab? ?Can you please explain what is causing such differecnes?

I've seen many instances where everything works well 'in the lab' and as
soon as you put it in the field, things go pear shaped. Often you need to
resort to network sniffing but if the problem is intermittent, this is
very hit and miss. If you have several devices on a network and you can
see the breakdown of the bootstage on each individual device, traking
down the problem is much easier - Is it a associated with a common network
function (DHCP/TFTP)? A common network segment, a particular file being
TFTP'd?

>
>> > - It is completely platform, SoC and board idependent - we do not need
>> > ?to provide any specific timer servcies etc. which are inherently
>> > ?platform-dependent.
>>
>> Is this really an advantage?
>
> Don't you think so?
>
> Will you provide the code to implement your solution for all currently
> supported BlackFin, ColdFire, MicroBlaze, MIPS, NIOS, PPC, SH, SPARC
> or x86 CPUs? ?Or even for all currently supported ARMN SoCs?
>
>> > - It does not cause execution overhead on the running system - it
>> > ?affects neither the execution speed not the memory footprint of the
>> > ?target under test.
>>
>> Write to the serial port costs about 30ms on our platform at minimum. I
>> have't looked at why, but the serial FIFO is only so big so I assume that is
>
> I think this can (and should) be fixed. It makes little sense to use a
> FIFO in the transmit direction in U-Boot.
>
>> what is happening. The overhead of bootstage is a function call, a readl(),
>> a a few memory accesses and an optional strcpy. It is much cheaper than
>> outputting a serial character.
>
> But you need storage for the timing events, and you don't have this
> before relocation. So you miss some really interesting parts of the
> boot procedure.

Maybe a limited amount can be stored in global data by testing the
relocated flag

>> > approach, i. e. which problems can be addressed with your code where
>> > the output timing method cannot be used, or where it is less
>> > efficient?
>>
>> With a little bit of cheating I can think of 10:
>>
>> 1. It doesn't need a serial watcher to be connected, which is not available
>> in the field, and is something that anyway would only be attached when the
>> engineer is not using the console for actually typing commands.
>
> OK, not needing a console port during boot is indeed an advantage. ?It
> comes at the cost of needing log space, which is not available before
> relocation, so we miss some interesting parts of the boot procedure.

Can use global data for a limited number of pre-relocation records. And I
don't think pre-location is where a lot of problems will occur anyway
unless you have flaky/misconfigured  hardware

>> 2. It is internal to the code, so as different code paths are taken it still
>> has working timing, and doesn't rely on separate serial traffic parsing code
>> to work out what happened
>
> I don't consider this an advantage. ?On contrary.
>
>> 3. It still works with a silent console (we can either unmute the console
>> and print the info, or pass it on to Linux for logging)
>
> OK.
>
>> 4. It is simpler to write and extend (just add a new bootstage call around
>> any interesting section even if there is no serial output there)
>
> This is plain wrong. ?Compare your implementation against the 10 lines
> of TCL code referenced above.
>
>> 5. It allows timing of things which don't result in serial output.
>
> But to do so, you need to insert trace points. ?With the same effort
> we can insert a printf().

Which increase code/data size - If you don't care about having pretty
messages in you boot profile (you can always look up source or
documentation) the size impact per 'mark' is less

>> 6. It times when the event actually happens rather than when a character
>> makes its way through a UART FIFO. At worst the character might take a few
>> ms to get through the FIFO which will skew timings.
>
> Serial drivers are not supposed to use FIFOs in the tx direction.

Moot point and counterpoint when considering 3) above

>> 7. It potentially allows two CPUs to run concurrently and log progress (no I
>> am not working on that yet).
>>
>> 8. We can log the information in the field, perhaps by passing it to Linux
>>
>> 9. There is only one code base to be changed when a boot path is adjusted.
>
> ...which is a disadvantage, because with the externat tool nothing
> needs to be changed at all.
>
>> 10. It has higher resolution.
>
> OK.
>
> I understand your position, and I too see some advantages of your
> implementation. ?But I see also disadvantages, especially it being a
> pretty much intrusive change to large areas of the code, and being
> available for a single platform only. ?Also, I see it as a
> disadvantage that you lose pre-relocation information.

I think my refined suggestion has a far smaller impact than first thought
and you can get pre-relocation information if you are willing to use
some global data storage

>
> So far, I am not convinced that the result is worth the effort.
>

We live in hope ;)

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Graeme Russ,

In message <BANLkTim55MVfJ-FdEkea3GSbvQnnaicASw@mail.gmail.com> you wrote:
>
> > time-stamping console output is not restricted to the serial port. It
> > works as well with tty over USB, or netconsole, or even netconsole
> > over USB.
> 
> My point is, if the device reboots in the field, you cannot recover the
> boot timing analysis as once it is streamed out it is gone forever

Agreed. But so far I have never seen a need to perform boot time
measurements on devices in the field without access to the console
(serial, or usb or netconsole).  In all my experience, such behaviour
is pretty much deterministic and can be done in the lab, before
shipping systems.

The only way where I can imagine that the boot ime depends on the
actual user environment is when booting from the network, but then
again you can also run a network sniffer to measure this impact.

I really wonder what the benefit of adding such code to U-Boot is.

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
Genitiv ins Wasser, weil's Dativ ist!

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Graeme Russ,

In message <BANLkTi=u4gJ+Ci8hPfv95m8nYNyEdHgn-g@mail.gmail.com> you wrote:
>
> > As we can trivially use regular expressions, the effort to implement a
> > "timing parser" can be ignored. And it is independet of what sort of
> > boot device we are using.
> 
> Fine if your running Linux - What if the only tool tyou have is
> Hyperterminal?

AFAICT tcl is also available under Windoze...

> I've seen many instances where everything works well 'in the lab' and as
> soon as you put it in the field, things go pear shaped. Often you need to

We all have seen this, and we all appreciate any tool that is
available then.

> > But you need storage for the timing events, and you don't have this
> > before relocation. So you miss some really interesting parts of the
> > boot procedure.
> 
> Maybe a limited amount can be stored in global data by testing the
> relocated flag

I don't think so.

> > OK, not needing a console port during boot is indeed an advantage.  It
> > comes at the cost of needing log space, which is not available before
> > relocation, so we miss some interesting parts of the boot procedure.
> 
> Can use global data for a limited number of pre-relocation records. And I
> don't think pre-location is where a lot of problems will occur anyway
> unless you have flaky/misconfigured  hardware

I smell a bloated implementation which works on one specific system or
two.  This doesn't sound attractive to me.

> >> 5. It allows timing of things which don't result in serial output.
> >
> > But to do so, you need to insert trace points.  With the same effort
> > we can insert a printf().
> 
> Which increase code/data size - If you don't care about having pretty
> messages in you boot profile (you can always look up source or
> documentation) the size impact per 'mark' is less

What makes you think a call to printf()/puts()/putc() would increase
the code size worse than a call to the trace function? If I don't
care about pretty messages (and use silent console otherwise) my
serial console based messages consist of a plain "putc('a')" or
similar - certainly not more overhead than the call to the trace
function.


> I think my refined suggestion has a far smaller impact than first thought
> and you can get pre-relocation information if you are willing to use
> some global data storage

It's not about willing or not.  If willing or wanting would help, we
had an ideal world.  But in reality, we have a world full of
restrictions.

GD is definitely not buffer space for arbitrary amounts of log data.

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
A little suffering is good for the soul.
	-- Kirk, "The Corbomite Maneuver", stardate 1514.0

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Premi, Sanjeev]

> -----Original Message-----
> From: u-boot-bounces at lists.denx.de 
> [mailto:u-boot-bounces at lists.denx.de] On Behalf Of Graeme Russ
> Sent: Monday, May 16, 2011 11:54 AM
> To: Wolfgang Denk
> Cc: U-Boot Mailing List; Simon Schwarz
> Subject: Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
> 
> On Mon, May 16, 2011 at 3:48 PM, Wolfgang Denk <wd@denx.de> wrote:
> > Dear Simon Glass,
> >
[snip]...[snip]

> > Well, the "timing parser", as you callit, can be written in 10 lines
> > or less of your scripting language of choice. ?See for example here
> > for a solution in expect/tcl: ftp://ftp.denx.de/pub/tools/time_log
> > We've been using this for about 10 years by now (see for 
> example this
> > 7 year old boot time analysis:
> > http://www.denx.de/wiki/DULG/AN2004_11_BootTimeOptimization).
> >
> > As we can trivially use regular expressions, the effort to 
> implement a
> > "timing parser" can be ignored. And it is independet of what sort of
> > boot device we are using.
> >
> 
> Fine if your running Linux - What if the only tool tyou have is
> Hyperterminal?

[sp] I have personally found Realterm quite good specifically for
     for attaching timing info to the prints received.

     It is available at: http://realterm.sourceforge.net/

     For measurement, I send the output directly to a log file - not
     displayed on the screen.

     BTW, Teraterm is my choice for regular use.

~sanjeev

[snip]...[snip]

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

Hi Wolfgang,

Such a lot of text about such a small patch. It is clear to me that you are
used to doing things one way, and this is a different approach. As I said
there is more than one way to skin this cat and I think there are advantages
to having internal self-contained timing. I will try to address some of your
comments below.

On Sun, May 15, 2011 at 10:48 PM, Wolfgang Denk <wd@denx.de> wrote:

> Dear Simon Glass,
>
> In message <BANLkTi=0ijj7DnLsjovO-3eQjMw+RSOQwg@mail.gmail.com> you wrote:
> >
> > This is 100us which is pretty good although you are assuming that there
> is
> > no FIFO holding things. Also on modern ARM CPUs the 'processing' part of
>
> I don't see that we use any FIFOs in the output direction.
>

Yes we do, and in fact they do improve boot performance slightly when the
console is muted.


>
> > U-Boot (where it is not just waiting on a device) can be over in under
> > 100ms, and if you are wanting to reduce this, a little more resolution
> > doesn't hurt.
>
> Sorry, I cannot parse the "over in under 100 millisecond" part.
>

finished in under 100ms, the point being that if the time taken to load the
kernel is fixed, and you want to work on the other stuff, the total run-time
of it is under 100ms on some platforms.


> > > - It requires zero code changes.  You can run the production code and
> > >  time it.  You can use it without rebuilding / reinstalling the
> > >  software, yes even without access to the source code.
> > >
> >
> > Are you not ignoring the timing parser on the serial port which must be
> > written and changed to cope with the different output of U-Boot (net
> boot,
> > USB boot, MMC boot, SD boot, etc.)? We have a lot of boot paths,
> different
> > architectures, etc. We want a simple solution.
>
> Well, the "timing parser", as you callit, can be written in 10 lines
> or less of your scripting language of choice.  See for example here
> for a solution in expect/tcl: ftp://ftp.denx.de/pub/tools/time_log
> We've been using this for about 10 years by now (see for example this
> 7 year old boot time analysis:
> http://www.denx.de/wiki/DULG/AN2004_11_BootTimeOptimization).
>
> As we can trivially use regular expressions, the effort to implement a
> "timing parser" can be ignored. And it is independet of what sort of
> boot device we are using.
>

It looks great, I wish we could use it on our platform, but for the reasons
I have given it is not suitable.


>
>
> You write: "We want a simple solution."  I agree 100%.
>
> Isn;t a 10 line script code solution that does not require ANY changes
> to the U-Boot code _much_ simpler than your approach?
>
> This is why I was asking if your solution had any significant
> advantages.
>

OK fair enough, of course we want the simplest solution that covers the
requirements.


>
> > In our case the console is silent on boot, so this solution does not
> work.
>
> Point taken. But, you need to output the timing information, don't you?
>

We need to record it - generally this is done by Linux later (along with all
the boot performance stats from Linux).


>
> > Secondly it requires a listener on the serial port which we often don't
> > have. Thirdly we want to log this information and record it in the field
> so
>
> You must have one to rea the time logs, right?
>

See above - there is no serial port listener.


>
> > that we track boot time. This means that it has to be done by the device
> > itself.
>
> Did you see cases where the boot time in the field differs from that
> in your lab?  Can you please explain what is causing such differecnes?
>

We have a verified boot which can taken different paths when it sees an
update image, or corruption, for example. These paths can substantially
change the boot time. Changing boot times have often led us to bugs in the
past. Also the device itself can change. For example the performance of an
eMMC device changes over time and we want to track that.


> > > - It is completely platform, SoC and board idependent - we do not need
> > >  to provide any specific timer servcies etc. which are inherently
> > >  platform-dependent.
> >
> > Is this really an advantage?
>
> Don't you think so?
>
> Will you provide the code to implement your solution for all currently
> supported BlackFin, ColdFire, MicroBlaze, MIPS, NIOS, PPC, SH, SPARC
> or x86 CPUs?  Or even for all currently supported ARMN SoCs?
>

Here is the entire extent of the platform-specific code for Tegra2:

unsigned long timer_get_us(void)
{
struct timerus *timer_base = (struct timerus *)NV_PA_TMRUS_BASE;

return readl(&timer_base->cntr_1us);
}

I agree it is unfortunate to have features which require platform-specific
features. Perhaps we should define a microsecond timer as a requirement of a
U-Boot port? Or perhaps an option which opens up new features?


>
> > Write to the serial port costs about 30ms on our platform at minimum. I
> > have't looked at why, but the serial FIFO is only so big so I assume that
> is
>
> I think this can (and should) be fixed. It makes little sense to use a
> FIFO in the transmit direction in U-Boot.
>

It does save time.

>
> > what is happening. The overhead of bootstage is a function call, a
> readl(),
> > a a few memory accesses and an optional strcpy. It is much cheaper than
> > outputting a serial character.
>
> But you need storage for the timing events, and you don't have this
> before relocation. So you miss some really interesting parts of the
> boot procedure.
>

It is easy enough to get storage if we want it - you can maintain a
pre-reloc table which is copied over afterwards. I notice that some
functions do different things before and after reloc. I imagine that
reducing what is done before reloc is a good thing, so this window is likely
to shrink. We can always make bootstage more complex and feature-full as
time goes by, if there is some interest in having it in in the first place.

>
> > > approach, i. e. which problems can be addressed with your code where
> > > the output timing method cannot be used, or where it is less
> > > efficient?
> >
> > With a little bit of cheating I can think of 10:
> >
> > 1. It doesn't need a serial watcher to be connected, which is not
> available
> > in the field, and is something that anyway would only be attached when
> the
> > engineer is not using the console for actually typing commands.
>
> OK, not needing a console port during boot is indeed an advantage.  It
> comes at the cost of needing log space, which is not available before
> relocation, so we miss some interesting parts of the boot procedure.
>

See above.


>
> > 2. It is internal to the code, so as different code paths are taken it
> still
> > has working timing, and doesn't rely on separate serial traffic parsing
> code
> > to work out what happened
>
> I don't consider this an advantage.  On contrary.
>

OK, not sure why, but OK.

> 4. It is simpler to write and extend (just add a new bootstage call around
> > any interesting section even if there is no serial output there)
>
> This is plain wrong.  Compare your implementation against the 10 lines
> of TCL code referenced above.
>

I believe it compares favourably. It has a more friendly display, doesn't
require a serial port, is more accurate, can run self-hosted, etc. With the
TCL script you need to add a new line before you will get a new time.


> > 5. It allows timing of things which don't result in serial output.
>
> But to do so, you need to insert trace points.  With the same effort
> we can insert a printf().
>

Fair enough. If you have your heart set on the TCL script I'm really not
going to get very far!


>
> > 6. It times when the event actually happens rather than when a character
> > makes its way through a UART FIFO. At worst the character might take a
> few
> > ms to get through the FIFO which will skew timings.
>
> Serial drivers are not supposed to use FIFOs in the tx direction.
>

I don't see why not. That means they are busy waiting when they could be
carrying on with the boot.


>
> > 9. There is only one code base to be changed when a boot path is
> adjusted.
>
> ...which is a disadvantage, because with the externat tool nothing
> needs to be changed at all.
>

Yes, you must add a printf(), right? Otherwise you won't know it has taken a
different path

>
>
> I understand your position, and I too see some advantages of your
> implementation.  But I see also disadvantages, especially it being a
> pretty much intrusive change to large areas of the code, and being
> available for a single platform only.  Also, I see it as a
> disadvantage that you lose pre-relocation information.
>

I'm happy to post a patch for collecting pre-relocation information later if
that is of general interest. We can also have an automatic fallback call to
the ticks timer if microsecond resolution is not available. That would
support all platforms.

Instrumentation is always going to involve putting something in there. We
could run U-Boot in an emulator and do it that way I suppose. We could
require our users to connect a serial logging device. There are lots of
things we could do.


>
> So far, I am not convinced that the result is worth the effort.
>

In terms of all this discussion I can see your point :-) I did have
expressions of interest from two people including one I thought was at your
company, which I why I went to the effort to clean up and submit this. At
that time I didn't realise it would be such a touchy subject.

In summary I believe this patch is a clean, simple and functional solution
to a real problem that we have, and that I believe others have also.

But if you really don't want this in U-Boot then please accept my apologies
for wasting so much time on the list.

Regards,
Simon


>
> Best regards,
>
> Wolfgang Denk
>
> --
> DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
> HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
> Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
> Syntactic sugar causes cancer of the semicolon.
>                - Epigrams in Programming, ACM SIGPLAN Sept. 1982
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Scott Wood]

On Mon, 16 May 2011 13:40:20 +0200
Wolfgang Denk <wd@denx.de> wrote:

> Dear Graeme Russ,
> 
> In message <BANLkTi=u4gJ+Ci8hPfv95m8nYNyEdHgn-g@mail.gmail.com> you wrote:
> >
> > > As we can trivially use regular expressions, the effort to implement a
> > > "timing parser" can be ignored. And it is independet of what sort of
> > > boot device we are using.
> > 
> > Fine if your running Linux - What if the only tool tyou have is
> > Hyperterminal?
> 
> AFAICT tcl is also available under Windoze...

What about a board farm with a networked serial port server, adding
unpredictable latency?  Even if you have direct access to the host serial
port, there's not just the host FIFO distorting things, but the scheduling
latency of the application.  I suspect the useful precision of this
approach is significantly higher than 100 us.

> What makes you think a call to printf()/puts()/putc() would increase
> the code size worse than a call to the trace function? If I don't
> care about pretty messages (and use silent console otherwise) my
> serial console based messages consist of a plain "putc('a')" or
> similar - certainly not more overhead than the call to the trace
> function.

The size impact minor in either case, but in terms of time overhead (i.e.
the thing being measured), waiting for previous output to go
over the wire and the THR to empty is less overhead than putting a
timestamp in a log? Even if THR is already empty, those I/O accesses tend
to be much more expensive than reading from an CPU-internal time source and
writing to a cached data structure.

> It's not about willing or not.  If willing or wanting would help, we
> had an ideal world.  But in reality, we have a world full of
> restrictions.

And requiring that debugging infrastructure for such a low-level piece of
software be universally applicable is a pretty big
self-imposed restriction...

How many targets are so short on pre-relocation memory that they can't
spare a couple hundred bytes for debugging, lacking a suitable time
source, etc.?  It seems like the concept would be usable on more than just
a handful of boards, even if not necessarily all of them.

> GD is definitely not buffer space for arbitrary amounts of log data.

When did "limited" become "arbitrary"?

-Scott

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Simon Glass,

In message <BANLkTi=wdddeKLjoBFRoNcqzXJN9uGnBSw@mail.gmail.com> you wrote:
>
> Such a lot of text about such a small patch. It is clear to me that you are
> used to doing things one way, and this is a different approach. As I said

You can tell many things about me, but this one certainly is not the
case.

> > I don't see that we use any FIFOs in the output direction.
> 
> Yes we do, and in fact they do improve boot performance slightly when the
> console is muted.

Do you have an explanation how that works?  When there is no output on
the console, the use of a FIFO in tx direction should not matter at
all?

> I agree it is unfortunate to have features which require platform-specific
> features. Perhaps we should define a microsecond timer as a requirement of a
> U-Boot port? Or perhaps an option which opens up new features?

We already have that, or better.  The problem is that it depends on
the architecture.

On PPC systems for example you always have the time base, a 64 bit
counter which is clocked with something like 1/4 or 1/16 of the CPU
clock.

And whe have the timer that gettime() is based on - which is in
milliseocnd resolution (hence the demand that CONFIG_SYS_HZ must
always be defined as 1000).

The problem comes with the multitude of different architectures and
SoCs we support - there is no concept of timebase registers on ARM, on
some systems we need interrupts to implement timer services so these
are available only after relocation, etc.

> > But you need storage for the timing events, and you don't have this
> > before relocation. So you miss some really interesting parts of the
> > boot procedure.
> 
> It is easy enough to get storage if we want it - you can maintain a
> pre-reloc table which is copied over afterwards. I notice that some

Where will you store this "pre-reloc" table?  Yes, there are some
systems with plenty of on-chip-memory or huge caches that can beused
for this.  But there are also systems where we barely can find the
room for the most vital global data before relocation.

Even worse - if you take this seriously, you will probably also get
timing information from early boot stages, like how long it's taking
to load the U-Boot image from NAND - but on some systems this loader
code has to fit in as little as 2 KiB.

> I believe it compares favourably. It has a more friendly display, doesn't
> require a serial port, is more accurate, can run self-hosted, etc. With the
> TCL script you need to add a new line before you will get a new time.

Well, the display format is trivial to adapt, as well as the trigger
criteria. Keep in mind that this is just an example script that
covers the most common use case we've seen so far.

> > But to do so, you need to insert trace points.  With the same effort
> > we can insert a printf().
> 
> Fair enough. If you have your heart set on the TCL script I'm really not
> going to get very far!

I haven't my heart set on it.  It is just one example of solutions
which cover a large percentage of the potential use cases.  I am
trying to understand the ration of advanatges versus effort, that's
all.

> In terms of all this discussion I can see your point :-) I did have
> expressions of interest from two people including one I thought was at your
> company, which I why I went to the effort to clean up and submit this. At
> that time I didn't realise it would be such a touchy subject.

Where is the problem?  If you are convinced of you idea you should be
ready to defend it.  If you are not, it's not wort it at all.  And if
you see a voting result of 2:1 pro this is pretty good, isn't it?

> But if you really don't want this in U-Boot then please accept my apologies
> for wasting so much time on the list.

I don't consider this discussion a waste of time. I hope you don't do,
either.

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
Life would be so much easier if we could  just  look  at  the  source
code.                                                   -- Dave Olson

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

On Mon, May 16, 2011 at 11:32 AM, Wolfgang Denk <wd@denx.de> wrote:
> Dear Simon Glass,
>...
>> Yes we do, and in fact they do improve boot performance slightly when the
>> console is muted.
>
> Do you have an explanation how that works? ?When there is no output on
> the console, the use of a FIFO in tx direction should not matter at
> all?

Hi Wolfgang,

That's right, but when output is not muted, the FIFO allows for some
characters to be output before stalling the CPU.

>
>> I agree it is unfortunate to have features which require platform-specific
>> features. Perhaps we should define a microsecond timer as a requirement of a
>> U-Boot port? Or perhaps an option which opens up new features?
>
> We already have that, or better. ?The problem is that it depends on
> the architecture.

The implementation, maybe (not the interface which can be common), but
by expressing things in microseconds it is normally possible to
convert, and when this isn't available people will understand that
some rounding is going on.

>
> On PPC systems for example you always have the time base, a 64 bit
> counter which is clocked with something like 1/4 or 1/16 of the CPU
> clock.
>
> And whe have the timer that gettime() is based on - which is in
> milliseocnd resolution (hence the demand that CONFIG_SYS_HZ must
> always be defined as 1000).
>
> The problem comes with the multitude of different architectures and
> SoCs we support - there is no concept of timebase registers on ARM, on
> some systems we need interrupts to implement timer services so these
> are available only after relocation, etc.

On several ARM SOCs there is a monotonic timer - it's not always a
microsecond timer but is typically good enough for this sort of
purpose. In some cases this doesn't require interrupts (e.g. Tegra).

>
>> > But you need storage for the timing events, and you don't have this
>> > before relocation. So you miss some really interesting parts of the
>> > boot procedure.
>>
>> It is easy enough to get storage if we want it - you can maintain a
>> pre-reloc table which is copied over afterwards. I notice that some
>
> Where will you store this "pre-reloc" table? ?Yes, there are some
> systems with plenty of on-chip-memory or huge caches that can beused
> for this. ?But there are also systems where we barely can find the
> room for the most vital global data before relocation.

I would rather discuss this once we get agreement on the first part of
this, which is the concept of using a timer at all! But it is not hard
to store data pre-reloc and move it later. This is what happens with
the global data at the moment.

>
> Even worse - if you take this seriously, you will probably also get
> timing information from early boot stages, like how long it's taking
> to load the U-Boot image from NAND - but on some systems this loader
> code has to fit in as little as 2 KiB.

SOC boot ROMs are changing this, but even so I don't see this as a
serious limitation. If you don't have room for boot timing in your
pre-boot loader, don't add it.

>
>> I believe it compares favourably. It has a more friendly display, doesn't
>> require a serial port, is more accurate, can run self-hosted, etc. With the
>> TCL script you need to add a new line before you will get a new time.
>
> Well, the display format is trivial to adapt, as well as the trigger
> criteria. Keep in mind that this is just an example script that
> covers the most common use case we've seen so far.

OK

>
>> > But to do so, you need to insert trace points. ?With the same effort
>> > we can insert a printf().
>>
>> Fair enough. If you have your heart set on the TCL script I'm really not
>> going to get very far!
>
> I haven't my heart set on it. ?It is just one example of solutions
> which cover a large percentage of the potential use cases. ?I am
> trying to understand the ration of advanatges versus effort, that's
> all.

In that case will you consider the inclusion of this as a different
way of doing things?

>
>> In terms of all this discussion I can see your point :-) I did have
>> expressions of interest from two people including one I thought was at your
>> company, which I why I went to the effort to clean up and submit this. At
>> that time I didn't realise it would be such a touchy subject.
>
> Where is the problem? ?If you are convinced of you idea you should be
> ready to defend it. ?If you are not, it's not wort it at all. ?And if
> you see a voting result of 2:1 pro this is pretty good, isn't it?

I think I have mounted a robust defense. In fact I haven't written so
much on one topic for a week :-)

>
>> But if you really don't want this in U-Boot then please accept my apologies
>> for wasting so much time on the list.
>
> I don't consider this discussion a waste of time. I hope you don't do,
> either.

Regards,
Simon

>
> Best regards,
>
> Wolfgang Denk
>
> --
> DENX Software Engineering GmbH, ? ? MD: Wolfgang Denk & Detlev Zundel
> HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
> Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
> Life would be so much easier if we could ?just ?look ?at ?the ?source
> code. ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? -- Dave Olson
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 9:40 PM, Wolfgang Denk <wd@denx.de> wrote:
> Dear Graeme Russ,
>
> In message <BANLkTi=u4gJ+Ci8hPfv95m8nYNyEdHgn-g@mail.gmail.com> you wrote:
>>
>> > As we can trivially use regular expressions, the effort to implement a
>> > "timing parser" can be ignored. And it is independet of what sort of
>> > boot device we are using.
>>
>> Fine if your running Linux - What if the only tool tyou have is
>> Hyperterminal?
>
> AFAICT tcl is also available under Windoze...
>
>> I've seen many instances where everything works well 'in the lab' and as
>> soon as you put it in the field, things go pear shaped. Often you need to
>
> We all have seen this, and we all appreciate any tool that is
> available then.
>
>> > But you need storage for the timing events, and you don't have this
>> > before relocation. So you miss some really interesting parts of the
>> > boot procedure.
>>
>> Maybe a limited amount can be stored in global data by testing the
>> relocated flag
>
> I don't think so.

As I said before, the timing aberation per-boot in pre-relocation code is
going to be pretty minimal. 'In The Lab' you can easily use putc() and
your favourite terminal/script to do the timing analysis when you are
trying to trim micro-seconds (optimising SDRAM init/sizing etc, NAND
loading, NOR wait states)

My particular interest in the boot timing analysis is where it is being
affected by factors such as:
 - Device initialisation (peripherals via I2C, FPGAs etc)
 - Network (DHCP/TFTP requests)
 - Storage device access (HDDs, NAND etc)
 - Physical Environment (temperature etc)

These factors are not as reproducible 'In The Lab' and in the field may
be very transient.

>> > OK, not needing a console port during boot is indeed an advantage. ?It
>> > comes at the cost of needing log space, which is not available before
>> > relocation, so we miss some interesting parts of the boot procedure.
>>
>> Can use global data for a limited number of pre-relocation records. And I
>> don't think pre-location is where a lot of problems will occur anyway
>> unless you have flaky/misconfigured ?hardware
>
> I smell a bloated implementation which works on one specific system or
> two. ?This doesn't sound attractive to me.
>
>> >> 5. It allows timing of things which don't result in serial output.
>> >
>> > But to do so, you need to insert trace points. ?With the same effort
>> > we can insert a printf().
>>
>> Which increase code/data size - If you don't care about having pretty
>> messages in you boot profile (you can always look up source or
>> documentation) the size impact per 'mark' is less
>
> What makes you think a call to printf()/puts()/putc() would increase
> the code size worse than a call to the trace function? If I don't
> care about pretty messages (and use silent console otherwise) my
> serial console based messages consist of a plain "putc('a')" or
> similar - certainly not more overhead than the call to the trace
> function.

Another 'In The Field' scenario is where you do not have a free console
port available because thay are all used for communicating to other
devices. We have devices with five serial ports and at times we still run
out of ports

>> I think my refined suggestion has a far smaller impact than first thought
>> and you can get pre-relocation information if you are willing to use
>> some global data storage
>
> It's not about willing or not. ?If willing or wanting would help, we
> had an ideal world. ?But in reality, we have a world full of
> restrictions.

Yes, and some of those restrictions limit your ability to use a serial
port to debug boot times

> GD is definitely not buffer space for arbitrary amounts of log data.

Agreed, but:
 a) Pre-relocation logging may not strictly be needed because boot-times
    up to relocation can be fine tuned in the lab using putc()
 b) A few dozen bytes in GD in a debug build to isolate some stupid random
    issue onyl seen in the field can save hundreds (if not thousands) of
    <insert you local currency here> of engineering time

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Detlev Zundel]

Hi Simon and Wolfgang,

[...]

> In terms of all this discussion I can see your point :-) I did have
> expressions of interest from two people including one I thought was at your
> company, which I why I went to the effort to clean up and submit this. At
> that time I didn't realise it would be such a touchy subject.

I don't believe this topic to be touchy, it's just that Wolfgang trying
to keep the whole code base in shape has a healthy inertia before
introducing changes that may be difficult to keep consistent over the
multitude of SoCs that we support.

To throw in my personal view again, I still would like to see such an
infrastructure to get into U-Boot code.  I fully agree with Wolfgang
that practically the printfs and timing are a method already in place to
do measurements.  On the other hand my experience has shown that for
some reason or other this has never been widely used.  So effectively,
it wasn't too helpful for the project itself.  

So I still believe that if we _had_ an infrastructure like you propose,
we would get more people interested in _actually_ measuring and
improving the code base, which would certainly be a good thing.  

Of course we have systems that are very limited in their ressources, but
this is the reason why many features of U-Boot are opt-in features not
forcing any resource usage on such boards.  So if some of them are so
short on resources that they cannot use such a timing framework, then so
be it.  But as most of the probably are in the legacy code base, they
should not stop us from getting getting positive effects for the
currently important boards and architectures.

Cheers
  Detlev

-- 
A change in language can transform our appreciation of the cosmos
                       -- Benjamin Lee Whorf
--
DENX Software Engineering GmbH,      MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich,  Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: dzu at denx.de

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

On Tue, May 17, 2011 at 1:20 AM, Detlev Zundel <dzu@denx.de> wrote:
> Hi Simon and Wolfgang,
>
> [...]
>
>> In terms of all this discussion I can see your point :-) I did have
>> expressions of interest from two people including one I thought was at your
>> company, which I why I went to the effort to clean up and submit this. At
>> that time I didn't realise it would be such a touchy subject.
>
> I don't believe this topic to be touchy, it's just that Wolfgang trying
> to keep the whole code base in shape has a healthy inertia before
> introducing changes that may be difficult to keep consistent over the
> multitude of SoCs that we support.
>
> To throw in my personal view again, I still would like to see such an
> infrastructure to get into U-Boot code. ?I fully agree with Wolfgang
> that practically the printfs and timing are a method already in place to
> do measurements. ?On the other hand my experience has shown that for
> some reason or other this has never been widely used. ?So effectively,
> it wasn't too helpful for the project itself.
>
> So I still believe that if we _had_ an infrastructure like you propose,
> we would get more people interested in _actually_ measuring and
> improving the code base, which would certainly be a good thing.
>
> Of course we have systems that are very limited in their ressources, but
> this is the reason why many features of U-Boot are opt-in features not
> forcing any resource usage on such boards. ?So if some of them are so
> short on resources that they cannot use such a timing framework, then so
> be it. ?But as most of the probably are in the legacy code base, they
> should not stop us from getting getting positive effects for the
> currently important boards and architectures.
>
> Cheers
> ?Detlev

Hi Detlev and Wolfgang,

Thanks for your comments. I understand a little bit of healthy inertia
and do appreciate the constraints.

I believe I have covered this ground very thoroughly and would like
advice please on what to do next. The options I can see are:

- change the code to use a fallback when a microsecond timer is not available
- integrate with boot progress
- something else? drop it?

Regards.
Simon

>
> --
> A change in language can transform our appreciation of the cosmos
> ? ? ? ? ? ? ? ? ? ? ? -- Benjamin Lee Whorf
> --
> DENX Software Engineering GmbH, ? ? ?MD: Wolfgang Denk & Detlev Zundel
> HRB 165235 Munich, ?Office: Kirchenstr.5, D-82194 Groebenzell, Germany
> Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: dzu at denx.de
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

Hi Simon,

>
> Hi Detlev and Wolfgang,
>
> Thanks for your comments. I understand a little bit of healthy inertia
> and do appreciate the constraints.
>
> I believe I have covered this ground very thoroughly and would like
> advice please on what to do next. The options I can see are:
>
> - change the code to use a fallback when a microsecond timer is not available
> - integrate with boot progress
> - something else? drop it?

I suggest you create a V2 of this patch series, integrating the logging
into show_boot_progress() - Have a crawl through the existing code and see
if you can safely use a bit in the progress number (preferably a fixed
bit number across all platforms, or one defined in the config file if
this is not possible) to indicate if that progress mark should be logged

One day we can perhaps standardise how the parameter to show_boot_progress
is treated so the same value is consistent across the entire U-Boot code.

Don't worry too much about the 'pre-relocation' case for the time being.
You will have to check the relocated flag stored in global data so no
attempt to log is made before relocation. If there is enough support for
pre-relocation logging, there can always be a V3 patch :)

Make sure that the new feature has zero impact if the configuration option
is not enabled (CONFIG_LOG_BOOT_PROGRESS for example). Try not to make it
too ugly by littering code with #ifdef - If the bulk can be put into a
file which can be selectively included in the Makefile that would be good.
show_boot_progress() will naturally have some #ifdef's in it

Make sure you clearly comment in each patch that it is V2 and the changes
made from V1 and that you run it all through checkpatch.pl (from the Linux
kernel source)

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Detlev Zundel]

Hi Simon,

[...]

> I believe I have covered this ground very thoroughly and would like
> advice please on what to do next. The options I can see are:

As Graeme points out, you got enough positive feedback that I encourage
you to continue and address the comments.

> - change the code to use a fallback when a microsecond timer is not
> available

Excuse me for not diving into that too deep, but from my top-level
overview, it would seem like a good idea that if an architecture _has_ a
microsecond timer, it could use generic code to massage that into the
HZ=1000 API that we currently use with the addition of offering the
extended precision.  Your code then would need such a fallback and could
work with the best precision offered by the architecture.  New
architectures with microsecond timers would need to only implement the
new microsecond timer infrastructure and be done with it.

I know that this probably ignores much of the reality, but it is as much
as I can say with the time that I have available.

As a side-note, I would always suggest looking at how Linux solves similar
problems and follow examples set there.

> - integrate with boot progress

The current boot progress to me seems pretty ugly and could do with a
make-over.  So if it is possible to merge those two logical functions,
we would have a win-win situation.

> - something else? drop it?

No, please don't - I think you created enough interest to carry on.

Cheers
  Detlev

-- 
Perfecting oneself is as much unlearning as it is learning. 
                                        -- Edsger Dijkstra 
--
DENX Software Engineering GmbH,      MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich,  Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: dzu at denx.de

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Simon Glass]

On Thu, May 19, 2011 at 1:36 AM, Detlev Zundel <dzu@denx.de> wrote:
> Hi Simon,
>
> [...]
>
>> I believe I have covered this ground very thoroughly and would like
>> advice please on what to do next. The options I can see are:
>
> As Graeme points out, you got enough positive feedback that I encourage
> you to continue and address the comments.

OK, it would be nice to have a note from Wolfgang since without his OK
it won't make it in, right?

>
>> - change the code to use a fallback when a microsecond timer is not
>> available
>
> Excuse me for not diving into that too deep, but from my top-level
> overview, it would seem like a good idea that if an architecture _has_ a
> microsecond timer, it could use generic code to massage that into the
> HZ=1000 API that we currently use with the addition of offering the
> extended precision. ?Your code then would need such a fallback and could
> work with the best precision offered by the architecture. ?New
> architectures with microsecond timers would need to only implement the
> new microsecond timer infrastructure and be done with it.

Yes I suggested that a few emails ago but didn't get a response.

>> - integrate with boot progress
>
> The current boot progress to me seems pretty ugly and could do with a
> make-over. ?So if it is possible to merge those two logical functions,
> we would have a win-win situation.

OK fair enough. I will do this if there is agreement that this type of
boot timing is worth having.

Wolfgang can you please chime in here?

Regards,
Simon


>
>> - something else? drop it?
>
> No, please don't - I think you created enough interest to carry on.
>
> Cheers
> ?Detlev
>
> --
> Perfecting oneself is as much unlearning as it is learning.
> ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?-- Edsger Dijkstra
> --
> DENX Software Engineering GmbH, ? ? ?MD: Wolfgang Denk & Detlev Zundel
> HRB 165235 Munich, ?Office: Kirchenstr.5, D-82194 Groebenzell, Germany
> Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: dzu at denx.de
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Fri, May 20, 2011 at 11:48 AM, Simon Glass <sjg@chromium.org> wrote:
> On Thu, May 19, 2011 at 1:36 AM, Detlev Zundel <dzu@denx.de> wrote:
>> Hi Simon,
>>
>> [...]
>>
>>> I believe I have covered this ground very thoroughly and would like
>>> advice please on what to do next. The options I can see are:
>>
>> As Graeme points out, you got enough positive feedback that I encourage
>> you to continue and address the comments.
>
> OK, it would be nice to have a note from Wolfgang since without his OK
> it won't make it in, right?
>
>>
>>> - change the code to use a fallback when a microsecond timer is not
>>> available
>>
>> Excuse me for not diving into that too deep, but from my top-level
>> overview, it would seem like a good idea that if an architecture _has_ a
>> microsecond timer, it could use generic code to massage that into the
>> HZ=1000 API that we currently use with the addition of offering the
>> extended precision. ?Your code then would need such a fallback and could
>> work with the best precision offered by the architecture. ?New
>> architectures with microsecond timers would need to only implement the
>> new microsecond timer infrastructure and be done with it.
>
> Yes I suggested that a few emails ago but didn't get a response.

Is it just me or are get_timer(), set_timer() and reset_timer() in U-Boot
a little bit braindead? get_timer() returns microseconds since last
reset_timer() plus an optional offset, set_timer() allows the current
microseconds to an arbitrary value and reset_timer() is essentially
set_timer(0)

A random look at at91 is interesting though:

void set_timer(ulong t)
{
	gd->tbl = t;
}

void reset_timer(void)
{
	reset_timer_masked();
}

void reset_timer_masked(void)
{
	/* reset time */	
	at91_tc_t *tc = (at91_tc_t *) AT91_TC_BASE;
	gd->lastinc = readl(&tc->tc[0].cv) & 0x0000ffff;
	gd->tbl = 0;
}

So set_timer(0) != reset_timer() in a rather big way!

Now some arches (imx for example) do not implement set_timer() which makes
using it a 'Bad Idea'(tm)

And why do we need reset_timer() - Anything that uses it can just do:

ulong start_time = get_timer(0);
while (get_timer(start_time) < SOME_TIMEOUT) {
	...do stuff..
}

NOTE: May not be the 'safest' way to do that - I recall there being a LOT
of discussion about this with regards to wrap-around and safe ways of
doing the above

Anyway, my point is, if the timer API wasa fixed, all the boot logging API
needs to do is call get_timer() and your done - instant millisecond
timestamp - No fallbacks - Each arch just needs to implement get_timer()
correctly

>>> - integrate with boot progress
>>
>> The current boot progress to me seems pretty ugly and could do with a
>> make-over. ?So if it is possible to merge those two logical functions,
>> we would have a win-win situation.

Sounds like a two-patch approach - Fix up boot progress and then slap
logging on top

>
> OK fair enough. I will do this if there is agreement that this type of
> boot timing is worth having.

I could have a look at this if you like Simon

Regards,

Graeme

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

>
> Anyway, my point is, if the timer API wasa fixed, all the boot logging API
> needs to do is call get_timer() and your done - instant millisecond

make that microsecond ;)

> timestamp - No fallbacks - Each arch just needs to implement get_timer()
> correctly
>

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Detlev Zundel]

Hi Simon,

[...]

>>> I believe I have covered this ground very thoroughly and would like
>>> advice please on what to do next. The options I can see are:
>>
>> As Graeme points out, you got enough positive feedback that I encourage
>> you to continue and address the comments.
>
> OK, it would be nice to have a note from Wolfgang since without his OK
> it won't make it in, right?

Ultimately we are a democratic community, so when you get enough support
the changes will go in.  Usually we find a consensus acceptable to all
parties before resorting to such formal measures however.

Cheers
  Detlev

-- 
Q: Why did the chicken cross the Moebius strip?
A: To get to the other ... er, um ...
--
DENX Software Engineering GmbH,      MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich,  Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: dzu at denx.de

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Mike Frysinger]

On Monday, May 23, 2011 11:22:18 Detlev Zundel wrote:
> >>> I believe I have covered this ground very thoroughly and would like
> >> 
> >>> advice please on what to do next. The options I can see are:
> >> As Graeme points out, you got enough positive feedback that I encourage
> >> you to continue and address the comments.
> > 
> > OK, it would be nice to have a note from Wolfgang since without his OK
> > it won't make it in, right?
> 
> Ultimately we are a democratic community, so when you get enough support
> the changes will go in.  Usually we find a consensus acceptable to all
> parties before resorting to such formal measures however.

s/Ultimately/For the most part/

Ultimately, Wolfgang gets final word regardless of anything else.
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110523/1e915545/attachment.pgp 

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Mike Frysinger,

In message <201105232255.58602.vapier@gentoo.org> you wrote:
>
> Ultimately, Wolfgang gets final word regardless of anything else.

Do I?  That's news for me.

What prevents you to continue this project as you like if I should
decide something that appears to be unacceptable to the community?

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
No user-servicable parts inside. Refer to qualified service personnel.

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Mike Frysinger]

On Tuesday, May 24, 2011 03:18:00 Wolfgang Denk wrote:
> Mike Frysinger wrote:
> > Ultimately, Wolfgang gets final word regardless of anything else.
> 
> Do I?  That's news for me.
> 
> What prevents you to continue this project as you like if I should
> decide something that appears to be unacceptable to the community?

yours will be "Das U-Boot" while mine will be an uppity fork

doesnt denx also own the trademark on "Das U-Boot" as applied to low level 
boot loaders ?
-mike
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part.
Url : http://lists.denx.de/pipermail/u-boot/attachments/20110524/12308262/attachment.pgp 

[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Wolfgang Denk]

Dear Mike Frysinger,

In message <201105241422.41948.vapier@gentoo.org> you wrote:
>
> > What prevents you to continue this project as you like if I should
> > decide something that appears to be unacceptable to the community?
> 
> yours will be "Das U-Boot" while mine will be an uppity fork

If you have the community with you the name alone is in vain

> doesnt denx also own the trademark on "Das U-Boot" as applied to low level
> boot loaders ?

No.  I've been told that both "U-Boot" and "Das U-Boot" are too
generic terms to be used for a name mark description.  If we had a
logo, we could apply for a "brand mark" (word mark and logo).  But so
far we don't.

Best regards,

Wolfgang Denk

-- 
DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
What about WRITING it first and rationalizing it afterwords?  :-)
                       - Larry Wall in <8162@jpl-devvax.JPL.NASA.GOV>