RE: Poor write performance to boot area using rcar-gen3-sdhi

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Richard Weinberger,

> -----Original Message-----
> From: Richard Weinberger <richard@xxxxxx>
> Sent: Monday, April 17, 2023 9:09 PM
> To: linux-mmc@xxxxxxxxxxxxxxx
> Cc: linux-renesas-soc@xxxxxxxxxxxxxxx; wsa+renesas@xxxxxxxxxxxxxxxxxxxx;
> ulf.hansson@xxxxxxxxxx
> Subject: Poor write performance to boot area using rcar-gen3-sdhi
> 
> Hi!
> 
> Writing to the boot area of an eMMC takes significant longer than writing to
> the user area on v6.1 (Tested also on v5.4).
> The following trace shows write of 4k using "dd if=4k.dat
> of=/dev/mmcblk1boot1 bs=512 oflag=sync".
> As you can see from the timings, the whole operation took almost 80ms where
> most of the time was consumed by the MMC_WRITE_MULTIPLE_BLOCK command.
> 
> 
>      kworker/1:1H-34      [001] .....  5113.734166: mmc_request_start: mmc1:
> start struct mmc_request[0000000005d331e4]: cmd_opcode=18 cmd_arg=0x0
> cmd_flags=0xb5 cmd_retries=0 stop_opcode=12 stop_arg=0x0 stop_flags=0x95
> stop_retries=0 sbc_opcode=23 sbc_arg=0x8 sbc_flags=0x15 sbc_retires=0
> blocks=8 block_size=512 blk_addr=0 data_flags=0x200 tag=26 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=1 retune_period=0
>      kworker/0:1-25      [000] .....  5113.735860: mmc_request_done: mmc1:
> end struct mmc_request[0000000005d331e4]: cmd_opcode=18 cmd_err=0
> cmd_resp=0x900 0x900 0x900 0x900 cmd_retries=0 stop_opcode=12 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=23 sbc_err=0
> sbc_resp=0x900 0x900 0x900 0x900 sbc_retries=0 bytes_xfered=4096 data_err=0
> tag=26 can_retune=1 doing_retune=0 retune_now=0 need_retune=0 hold_retune=1
> retune_period=0
>     kworker/1:1H-34      [001] .....  5113.735996: mmc_request_start: mmc1:
> start struct mmc_request[00000000174773b9]: cmd_opcode=25 cmd_arg=0x0
> cmd_flags=0xb5 cmd_retries=0 stop_opcode=12 stop_arg=0x0 stop_flags=0x49d
> stop_retries=0 sbc_opcode=23 sbc_arg=0x8 sbc_flags=0x15 sbc_retires=0
> blocks=8 block_size=512 blk_addr=0 data_flags=0x100 tag=27 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=1 retune_period=0
>      kworker/0:1-25      [000] .....  5113.814376: mmc_request_done: mmc1:
> end struct mmc_request[00000000174773b9]: cmd_opcode=25 cmd_err=0
> cmd_resp=0x900 0x900 0x900 0x900 cmd_retries=0 stop_opcode=12 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=23 sbc_err=0
> sbc_resp=0x900 0x900 0x900 0x900 sbc_retries=0 bytes_xfered=4096 data_err=0
> tag=27 can_retune=1 doing_retune=0 retune_now=0 need_retune=0 hold_retune=1
> retune_period=0
>     kworker/0:1H-144     [000] .....  5113.814391: mmc_request_start: mmc1:
> start struct mmc_request[00000000101675e9]: cmd_opcode=13 cmd_arg=0x10000
> cmd_flags=0x195 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5113.814408: mmc_request_done: mmc1:
> end struct mmc_request[00000000101675e9]: cmd_opcode=13 cmd_err=0
> cmd_resp=0x900 0x900 0x900 0x900 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>     kworker/1:1H-34      [001] .....  5113.814477: mmc_request_start: mmc1:
> start struct mmc_request[0000000008526179]: cmd_opcode=6 cmd_arg=0x3200101
> cmd_flags=0x95 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5113.814497: mmc_request_done: mmc1:
> end struct mmc_request[0000000008526179]: cmd_opcode=6 cmd_err=0
> cmd_resp=0x800 0x900 0x900 0x800 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>     kworker/1:1H-34      [001] .....  5113.814511: mmc_request_start: mmc1:
> start struct mmc_request[0000000061873c4a]: cmd_opcode=13 cmd_arg=0x10000
> cmd_flags=0x195 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5113.814529: mmc_request_done: mmc1:
> end struct mmc_request[0000000061873c4a]: cmd_opcode=13 cmd_err=0
> cmd_resp=0x900 0x900 0x800 0x900 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0O
> 
> 
> On the other hand, writing to the user area using "dd if=4k.dat
> of=/dev/mmcblk1p13 bs=512 oflag=sync" is fast:
> 
> 
>     kworker/1:1H-34      [001] .....  5163.989096: mmc_request_start: mmc1:
> start struct mmc_request[000000003c3d18f8]: cmd_opcode=6 cmd_arg=0x3b30801
> cmd_flags=0x49d cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5163.991009: mmc_request_done: mmc1:
> end struct mmc_request[000000003c3d18f8]: cmd_opcode=6 cmd_err=0
> cmd_resp=0x800 0x900 0x900 0x800 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>     kworker/1:1H-34      [001] .....  5163.991027: mmc_request_start: mmc1:
> start struct mmc_request[00000000a1a3cac1]: cmd_opcode=13 cmd_arg=0x10000
> cmd_flags=0x195 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5163.991056: mmc_request_done: mmc1:
> end struct mmc_request[00000000a1a3cac1]: cmd_opcode=13 cmd_err=0
> cmd_resp=0x900 0x900 0x800 0x900 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>     kworker/1:1H-34      [001] .....  5163.991081: mmc_request_start: mmc1:
> start struct mmc_request[00000000f096e251]: cmd_opcode=18 cmd_arg=0x4ea000
> cmd_flags=0xb5 cmd_retries=0 stop_opcode=12 stop_arg=0x0 stop_flags=0x95
> stop_retries=0 sbc_opcode=23 sbc_arg=0x8 sbc_flags=0x15 sbc_retires=0
> blocks=8 block_size=512 blk_addr=5152768 data_flags=0x200 tag=6 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=1 retune_period=0
>      kworker/0:1-25      [000] .....  5163.991705: mmc_request_done: mmc1:
> end struct mmc_request[00000000f096e251]: cmd_opcode=18 cmd_err=0
> cmd_resp=0x900 0x900 0x900 0x900 cmd_retries=0 stop_opcode=12 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=23 sbc_err=0
> sbc_resp=0x900 0x900 0x900 0x900 sbc_retries=0 bytes_xfered=4096 data_err=0
> tag=6 can_retune=1 doing_retune=0 retune_now=0 need_retune=0 hold_retune=1
> retune_period=0
>     kworker/1:1H-34      [001] .....  5163.991838: mmc_request_start: mmc1:
> start struct mmc_request[00000000ec4997fb]: cmd_opcode=25 cmd_arg=0x4ea000
> cmd_flags=0xb5 cmd_retries=0 stop_opcode=12 stop_arg=0x0 stop_flags=0x49d
> stop_retries=0 sbc_opcode=23 sbc_arg=0x8 sbc_flags=0x15 sbc_retires=0
> blocks=8 block_size=512 blk_addr=5152768 data_flags=0x100 tag=7 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=1 retune_period=0
>      kworker/0:1-25      [000] .....  5163.992203: mmc_request_done: mmc1:
> end struct mmc_request[00000000ec4997fb]: cmd_opcode=25 cmd_err=0
> cmd_resp=0x900 0x900 0x900 0x900 cmd_retries=0 stop_opcode=12 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=23 sbc_err=0
> sbc_resp=0x900 0x900 0x900 0x900 sbc_retries=0 bytes_xfered=4096 data_err=0
> tag=7 can_retune=1 doing_retune=0 retune_now=0 need_retune=0 hold_retune=1
> retune_period=0
>     kworker/0:1H-144     [000] .....  5163.992215: mmc_request_start: mmc1:
> start struct mmc_request[00000000101675e9]: cmd_opcode=13 cmd_arg=0x10000
> cmd_flags=0x195 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5163.992231: mmc_request_done: mmc1:
> end struct mmc_request[00000000101675e9]: cmd_opcode=13 cmd_err=0
> cmd_resp=0x900 0x900 0x900 0x900 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>     kworker/1:1H-34      [001] .....  5163.992291: mmc_request_start: mmc1:
> start struct mmc_request[0000000008526179]: cmd_opcode=6 cmd_arg=0x3200101
> cmd_flags=0x95 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5163.992310: mmc_request_done: mmc1:
> end struct mmc_request[0000000008526179]: cmd_opcode=6 cmd_err=0
> cmd_resp=0x800 0x900 0x900 0x800 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>     kworker/1:1H-34      [001] .....  5163.992790: mmc_request_start: mmc1:
> start struct mmc_request[0000000061873c4a]: cmd_opcode=13 cmd_arg=0x10000
> cmd_flags=0x195 cmd_retries=3 stop_opcode=0 stop_arg=0x0 stop_flags=0x0
> stop_retries=0 sbc_opcode=0 sbc_arg=0x0 sbc_flags=0x0 sbc_retires=0 blocks=0
> block_size=0 blk_addr=0 data_flags=0x0 tag=0 can_retune=1 doing_retune=0
> retune_now=0 need_retune=0 hold_retune=2 retune_period=0
>      kworker/0:1-25      [000] .....  5163.992808: mmc_request_done: mmc1:
> end struct mmc_request[0000000061873c4a]: cmd_opcode=13 cmd_err=0
> cmd_resp=0x900 0x900 0x800 0x900 cmd_retries=3 stop_opcode=0 stop_err=0
> stop_resp=0x0 0x0 0x0 0x0 stop_retries=0 sbc_opcode=0 sbc_err=0 sbc_resp=0x0
> 0x0 0x0 0x0 sbc_retries=0 bytes_xfered=0 data_err=0 tag=0 can_retune=1
> doing_retune=0 retune_now=0 need_retune=0 hold_retune=2 retune_period=0
> 
> The whole operation took only about 3ms.
> 
> Is this expected?
> 
> Off the head I don't really see why writing to the boot area should be
> slower.
> BTW: Using u-boot the write is blazing fast, so the eMMC itself should be
> fine.
> At driver level there shouldn't be much difference between writing to boot
> and user area except from MMC_SWITCH.

Not sure, the file system used between /dev/mmcblk1boot1 and /dev/mmcblk1p13 is making 
difference at Linux?

I have seen performance difference between FAT and ext4.

Cheers,
Biju




[Index of Archives]     [Linux Memonry Technology]     [Linux USB Devel]     [Linux Media]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]

  Powered by Linux