[U-Boot] [PATCH] common/cmd_ext_common: measure throughput

This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
The output of ext2load changes from
---8<--- Loading file "/boot/uImage" from mmc device 0:1 1830666 bytes read --->8---
to
---8<--- Loading file "/boot/uImage" from mmc device 0:1 1830666 bytes read in 237 ms (7.4 MiB/s) --->8---
Signed-off-by: Andreas Bießmann andreas.devel@googlemail.com --- common/cmd_ext_common.c | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-)
diff --git a/common/cmd_ext_common.c b/common/cmd_ext_common.c index 1952f4d..57958e6 100644 --- a/common/cmd_ext_common.c +++ b/common/cmd_ext_common.c @@ -76,6 +76,7 @@ int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, char buf[12]; unsigned long count; const char *addr_str; + unsigned long time_start;
count = 0; addr = simple_strtoul(argv[3], NULL, 16); @@ -135,18 +136,26 @@ int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, if ((count < filelen) && (count != 0)) filelen = count;
+ time_start = get_timer(0); if (ext4fs_read((char *)addr, filelen) != filelen) { printf("** Unable to read "%s" from %s %d:%d **\n", filename, argv[1], dev, part); ext4fs_close(); goto fail; } + time_start = get_timer(time_start);
ext4fs_close(); /* Loading ok, update default load address */ load_addr = addr;
- printf("%d bytes read\n", filelen); + printf("%d bytes read in %lu ms", filelen, time_start); + if (time_start > 0) { + puts(" ("); + print_size(filelen / time_start * 1000, "/s"); + puts(")"); + } + puts("\n"); sprintf(buf, "%X", filelen); setenv("filesize", buf);

Dear Andreas Bießmann,
In message 1350467910-2014-1-git-send-email-andreas.devel@googlemail.com you wrote:
This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
...
- unsigned long time_start;
...
- time_start = get_timer(0); if (ext4fs_read((char *)addr, filelen) != filelen) { printf("** Unable to read "%s" from %s %d:%d **\n", filename, argv[1], dev, part); ext4fs_close(); goto fail; }
- time_start = get_timer(time_start);
There, "time_start" is clearly a mis-nomer. How about s/time_start/time/ ?
print_size(filelen / time_start * 1000, "/s");
Does this give reasonable results for small files, say when loading a 20 byte file ?
Best regards,
Wolfgang Denk

Dear Wolfgang Denk,
On 17.10.2012 12:05, Wolfgang Denk wrote:
Dear Andreas Bießmann,
In message 1350467910-2014-1-git-send-email-andreas.devel@googlemail.com you wrote:
This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
...
- unsigned long time_start;
...
- time_start = get_timer(0); if (ext4fs_read((char *)addr, filelen) != filelen) { printf("** Unable to read "%s" from %s %d:%d **\n", filename, argv[1], dev, part); ext4fs_close(); goto fail; }
- time_start = get_timer(time_start);
There, "time_start" is clearly a mis-nomer. How about s/time_start/time/ ?
sounds better, however this is a plane copy from Simons tftp measurement patch.
print_size(filelen / time_start * 1000, "/s");
Does this give reasonable results for small files, say when loading a 20 byte file ?
Well, possible no:
---8<--- U-Boot> ext2load mmc 0 10020000 /etc/hosts Loading file "/etc/hosts" from mmc device 0:1 20 bytes read in 0 ms U-Boot> ext2load mmc 0 10020000 /etc/shadow Loading file "/etc/shadow" from mmc device 0:1 95 bytes read in 0 ms U-Boot> ext2load mmc 0 10020000 /etc/passwd Loading file "/etc/passwd" from mmc device 0:1 366 bytes read in 0 ms U-Boot> ext2load mmc 0 10020000 /etc/services Loading file "/etc/services" from mmc device 0:1 18465 bytes read in 3 ms (5.9 MiB/s) U-Boot> --->8---
But as you see extremely short transfers are omitted due to time difference of '0' (at least on my avr32 system here). The main aim for this patch was to measure performance gain of Josh Wu's gen_atmel_mci patch for multiple block access, hopefully this is useful for others. I would like to have some feedback how the measurement is for very small files on other systems. Then I could provide a v2 which uses another variable name for the time.
Best regards
Andreas Bießmann

On Wed, Oct 17, 2012 at 12:16:14PM +0200, Andreas Bie??mann wrote:
Dear Wolfgang Denk,
On 17.10.2012 12:05, Wolfgang Denk wrote:
Dear Andreas Bie??mann,
In message 1350467910-2014-1-git-send-email-andreas.devel@googlemail.com you wrote:
This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
...
- unsigned long time_start;
...
- time_start = get_timer(0); if (ext4fs_read((char *)addr, filelen) != filelen) { printf("** Unable to read "%s" from %s %d:%d **\n", filename, argv[1], dev, part); ext4fs_close(); goto fail; }
- time_start = get_timer(time_start);
There, "time_start" is clearly a mis-nomer. How about s/time_start/time/ ?
sounds better, however this is a plane copy from Simons tftp measurement patch.
print_size(filelen / time_start * 1000, "/s");
Does this give reasonable results for small files, say when loading a 20 byte file ?
Well, possible no:
---8<--- U-Boot> ext2load mmc 0 10020000 /etc/hosts Loading file "/etc/hosts" from mmc device 0:1 20 bytes read in 0 ms U-Boot> ext2load mmc 0 10020000 /etc/shadow Loading file "/etc/shadow" from mmc device 0:1 95 bytes read in 0 ms U-Boot> ext2load mmc 0 10020000 /etc/passwd Loading file "/etc/passwd" from mmc device 0:1 366 bytes read in 0 ms U-Boot> ext2load mmc 0 10020000 /etc/services Loading file "/etc/services" from mmc device 0:1 18465 bytes read in 3 ms (5.9 MiB/s) U-Boot> --->8---
But as you see extremely short transfers are omitted due to time difference of '0' (at least on my avr32 system here). The main aim for this patch was to measure performance gain of Josh Wu's gen_atmel_mci patch for multiple block access, hopefully this is useful for others. I would like to have some feedback how the measurement is for very small files on other systems. Then I could provide a v2 which uses another variable name for the time.
I'm fine with not giving a speed on <1 ms transactions. Lets see a v2 with the new variable name, thanks!

This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
The output of ext2load changes from
---8<--- Loading file "/boot/uImage" from mmc device 0:1 1830666 bytes read --->8---
to
---8<--- Loading file "/boot/uImage" from mmc device 0:1 1830666 bytes read in 237 ms (7.4 MiB/s) --->8---
Signed-off-by: Andreas Bießmann andreas.devel@googlemail.com --- since v1: * use 'time' instead of 'time_start' as suggested by Wolfgang
common/cmd_ext_common.c | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-)
diff --git a/common/cmd_ext_common.c b/common/cmd_ext_common.c index 1952f4d..63f1b1f 100644 --- a/common/cmd_ext_common.c +++ b/common/cmd_ext_common.c @@ -76,6 +76,7 @@ int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, char buf[12]; unsigned long count; const char *addr_str; + unsigned long time;
count = 0; addr = simple_strtoul(argv[3], NULL, 16); @@ -135,18 +136,26 @@ int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, if ((count < filelen) && (count != 0)) filelen = count;
+ time = get_timer(0); if (ext4fs_read((char *)addr, filelen) != filelen) { printf("** Unable to read "%s" from %s %d:%d **\n", filename, argv[1], dev, part); ext4fs_close(); goto fail; } + time = get_timer(time);
ext4fs_close(); /* Loading ok, update default load address */ load_addr = addr;
- printf("%d bytes read\n", filelen); + printf("%d bytes read in %lu ms", filelen, time); + if (time > 0) { + puts(" ("); + print_size(filelen / time * 1000, "/s"); + puts(")"); + } + puts("\n"); sprintf(buf, "%X", filelen); setenv("filesize", buf);

This patch adds time measurement and throughput calculation for all supported fsload commands.
The output of ext2load changes from
---8<--- 1830666 bytes read --->8---
to
---8<--- 1830666 bytes read in 237 ms (7.4 MiB/s) --->8---
Signed-off-by: Andreas Bießmann andreas.devel@googlemail.com --- since v1: * use 'time' instead of 'time_start' as suggested by Wolfgang
since v2: * rebase on top of 045fa1e1142552799ad3203e9e0bc22a11e866ea Now there is some more overhead in the measurement caused by the respective fs-type functions (detect fs-type, eventually do mount and so on). Nevertheless I think such a measurement is good for further improvements like increasing throughput by whatever measures.
fs/fs.c | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-)
diff --git a/fs/fs.c b/fs/fs.c index 23ffa25..9f1cfed 100644 --- a/fs/fs.c +++ b/fs/fs.c @@ -246,6 +246,7 @@ int do_fsload(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[], unsigned long pos; int len_read; char buf[12]; + unsigned long time;
if (argc < 5) return CMD_RET_USAGE; @@ -280,11 +281,19 @@ int do_fsload(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[], else pos = 0;
+ time = get_timer(0); len_read = fs_read(filename, addr, pos, bytes); + time = get_timer(time); if (len_read <= 0) return 1;
- printf("%d bytes read\n", len_read); + printf("%d bytes read in %lu ms", len_read, time); + if (time > 0) { + puts(" ("); + print_size(len_read / time * 1000, "/s"); + puts(")"); + } + puts("\n");
sprintf(buf, "0x%x", len_read); setenv("filesize", buf);

Dear Tom Rini,
On 30.10.2012 12:49, Andreas Bießmann wrote:
This patch adds time measurement and throughput calculation for all supported fsload commands.
The output of ext2load changes from
---8<--- 1830666 bytes read --->8---
to
---8<--- 1830666 bytes read in 237 ms (7.4 MiB/s) --->8---
Signed-off-by: Andreas Bießmann andreas.devel@googlemail.com
since v1:
- use 'time' instead of 'time_start' as suggested by Wolfgang
since v2:
- rebase on top of 045fa1e1142552799ad3203e9e0bc22a11e866ea Now there is some more overhead in the measurement caused by the respective fs-type functions (detect fs-type, eventually do mount and so on). Nevertheless I think such a measurement is good for further improvements like increasing throughput by whatever measures.
I've just seen v3 is marked superseded in patchwork (http://patchwork.ozlabs.org/patch/195465/), can you please tell why?
Best regards
Andreas Bießmann

On Wed, Oct 31, 2012 at 08:39:39AM +0100, Andreas Bie??mann wrote:
Dear Tom Rini,
On 30.10.2012 12:49, Andreas Bie??mann wrote:
This patch adds time measurement and throughput calculation for all supported fsload commands.
The output of ext2load changes from
---8<--- 1830666 bytes read --->8---
to
---8<--- 1830666 bytes read in 237 ms (7.4 MiB/s) --->8---
Signed-off-by: Andreas Bie??mann andreas.devel@googlemail.com
since v1:
- use 'time' instead of 'time_start' as suggested by Wolfgang
since v2:
- rebase on top of 045fa1e1142552799ad3203e9e0bc22a11e866ea Now there is some more overhead in the measurement caused by the respective fs-type functions (detect fs-type, eventually do mount and so on). Nevertheless I think such a measurement is good for further improvements like increasing throughput by whatever measures.
I've just seen v3 is marked superseded in patchwork (http://patchwork.ozlabs.org/patch/195465/), can you please tell why?
Too quick on the triage I guess, sorry, put back as New.

Hi,
On Tue, 30 Oct 2012 12:49:26 +0100 Andreas Bießmann andreas.devel@googlemail.com wrote:
This patch adds time measurement and throughput calculation for all supported fsload commands.
The output of ext2load changes from
---8<--- 1830666 bytes read --->8---
to
---8<--- 1830666 bytes read in 237 ms (7.4 MiB/s) --->8---
Signed-off-by: Andreas Bießmann andreas.devel@googlemail.com
since v1:
- use 'time' instead of 'time_start' as suggested by Wolfgang
since v2:
- rebase on top of 045fa1e1142552799ad3203e9e0bc22a11e866ea Now there is some more overhead in the measurement caused by the respective fs-type functions (detect fs-type, eventually do mount and so on). Nevertheless I think such a measurement is good for further improvements like increasing throughput by whatever measures.
fs/fs.c | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-)
Applied to staging/agust@denx.de after rebasing. Also slightly revised commit log. Thanks!
Anatolij
participants (4)
-
Anatolij Gustschin
-
Andreas Bießmann
-
Tom Rini
-
Wolfgang Denk