common/cmd_ext_common: measure throughput

PATCH New Andreas Bießmann 4 participants 9 messages Oct 17, 2012 – Nov 14, 2012 VFS

lore

Share & tools

lore

Andreas Bießmann

author

2012-10-17 09:58 UTC #0 lore raw

PATCH 1/1 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---

---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 <[email protected]>

---
 common/cmd_ext_common.c |   11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

common/cmd_ext_common.c +10 -1

index 1952f4d..57958e6 100644
@@ -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);

Signature · 1 line

1.7.10.4

Wolfgang Denk

2012-10-17 10:05 UTC #1 lore raw

PATCH 1/1 common/cmd_ext_common: measure throughput

Dear Andreas Bie?mann,

Quoted 2 lines · In message <[email protected]> you…

This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.

...

Quoted 1 line

common/cmd_ext_common.c +1 -0
+	unsigned long time_start;

...

common/cmd_ext_common.c int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, · line 146

Quoted 8 lines

common/cmd_ext_common.c +2 -0

+	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/ ?

common/cmd_ext_common.c int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, · line 155

Quoted 1 line

common/cmd_ext_common.c +1 -0
+		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

Signature · 4 lines

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 matter where you go, there you are..."          - Buckaroo Banzai

Andreas Bießmann

author

2012-10-17 10:16 UTC #2 lore raw

PATCH 1/1 common/cmd_ext_common: measure throughput

Dear Wolfgang Denk,

Quoted 8 lines · Wolfgang Denk

Dear Andreas Bie?mann,
Quoted 2 lines · In message <[email protected]> you…
This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
...
Quoted 1 line
common/cmd_ext_common.c +1 -0
+	unsigned long time_start;
...

Quoted 11 lines

common/cmd_ext_common.c int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, · line 146
Quoted 8 lines
common/cmd_ext_common.c +2 -0
+	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.

Quoted 4 lines

common/cmd_ext_common.c int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, · line 155
Quoted 1 line
common/cmd_ext_common.c +1 -0
+		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

Tom Rini

2012-10-25 19:03 UTC #3 lore raw

PATCH 1/1 common/cmd_ext_common: measure throughput

Quoted 49 lines · Andreas Bie??mann

Dear Wolfgang Denk,
Quoted 8 lines · Wolfgang Denk
Dear Andreas Bie??mann,
Quoted 2 lines · In message <[email protected]> you…
This patch adds time measurement and throughput calculation for the ext2load and ext4load commands.
...
Quoted 1 line
common/cmd_ext_common.c +1 -0
+	unsigned long time_start;
...
Quoted 11 lines
common/cmd_ext_common.c int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, · line 146
Quoted 8 lines
common/cmd_ext_common.c +2 -0
+	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.
Quoted 4 lines
common/cmd_ext_common.c int do_ext_load(cmd_tbl_t *cmdtp, int flag, int argc, · line 155
Quoted 1 line
common/cmd_ext_common.c +1 -0
+		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---

Quoted 8 lines

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!

Signature · 8 lines

Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: Digital signature
URL: <http://lists.denx.de/pipermail/u-boot/attachments/20121025/483996ba/attachment.pgp>

Andreas Bießmann

author

2012-10-26 08:20 UTC #4 lore raw

PATCH v2 1/1 common/cmd_ext_common: measure throughput

In reply to Andreas Bießmann

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---

---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 <[email protected]>

---
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(-)

common/cmd_ext_common.c +10 -1

index 1952f4d..63f1b1f 100644
@@ -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);

Signature · 1 line

1.7.10.4

Andreas Bießmann

author

2012-10-30 11:49 UTC #5 lore raw

PATCH v3 1/1 fs/fs.c: do_fsload: measure throughput

This patch adds time measurement and throughput calculation for all supported fsload commands.

The output of ext2load changes from

---8<---
1830666 bytes read
--->8---

---8<---
1830666 bytes read in 237 ms (7.4 MiB/s)
--->8---

Signed-off-by Andreas Bie?mann <[email protected]>

---
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(-)

fs/fs.c +10 -1

index 23ffa25..9f1cfed 100644
@@ -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);

Signature · 1 line

1.7.10.4

Andreas Bießmann

author

2012-10-31 07:39 UTC #6 lore raw

PATCH v3 1/1 fs/fs.c: do_fsload: measure throughput

Dear Tom Rini,

Quoted 20 lines · Andreas Bie?mann

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 <[email protected]>
---
since v1:
* use 'time' instead of 'time_start' as suggested by Wolfgang

Quoted 6 lines

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

Tom Rini

2012-11-04 18:00 UTC #7 lore raw

PATCH v3 1/1 fs/fs.c: do_fsload: measure throughput

Quoted 30 lines · Andreas Bie??mann

Dear Tom Rini,
Quoted 20 lines · Andreas Bie??mann
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 <[email protected]>
---
since v1:
* use 'time' instead of 'time_start' as suggested by Wolfgang
Quoted 6 lines
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.

Quoted 2 lines

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.

Signature · 8 lines

Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: Digital signature
URL: <http://lists.denx.de/pipermail/u-boot/attachments/20121104/b37ac18f/attachment.pgp>

Anatolij Gustschin

Applied

2012-11-14 12:59 UTC #8 lore raw

PATCH v3 1/1 fs/fs.c: do_fsload: measure throughput

In reply to Andreas Bießmann

Hi,

Quoted 27 lines · On Tue, 30 Oct 2012 12:49:26 +0100 Andreas Bie?mann…

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 <[email protected]>
---
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.

Quoted 2 lines

 fs/fs.c |   11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

Applied to staging/agust at denx.de after rebasing. Also slightly revised commit log. Thanks!

Anatolij