It take too long time on Uboot "Retrieving file"

Robotics & Edge Computing Jetson & Embedded Systems Jetson TX2
1

I’m working on optimizate tx2 start-up time,
It is strange that uboot take about 18 second on “Retrieving file: /boot/Image”
Are there any wrong config or miss file cause the issues?

U-Boot 2016.07-dirty (Jun 28 2019 - 15:30:11 +0800)

TEGRA186
Model: NVIDIA P2771-0000-500
DRAM: 7.8 GiB
MC: Tegra SD/MMC: 0, Tegra SD/MMC: 1
*** Warning - bad CRC, using default environment

In: serial
Out: serial
Err: serial
Net: eth0: ethernet@2490000
Hit any key to stop autoboot: 0
MMC: no card present
switch to partitions #0, OK
mmc0(part 0) is current device
Scanning mmc 0:1…
Found /boot/extlinux/extlinux.conf
Retrieving file: /boot/extlinux/extlinux.conf addr_buf: ffb293d0
213 bytes read in 65 ms (2.9 KiB/s)
p2771-0000 eMMC boot options
1: primary kernel
Enter choice: 1: primary kernel

Retrieving file: /boot/Image 
21864560 bytes read in 17640 ms (1.2 MiB/s)

append: root=/dev/mmcblk0p1 rw rootwait console=ttyS0,115200n8 console=tty0 OS=l4t fbcon=map:0 net.ifnames=0 memtype=0 video=tegrafb no_console_suspend=1 earlycon=uart8250,mmio32,0x03100000 nvdumper_reserved=0x2772e0000 gpt tegra_fbmem2=0x800000@0x969ed000 lut_mem2=0x2008@0x969ea000 tegraid=18.1.2.0.0 tegra_keep_boot_clocks maxcpus=6 boot.slot_suffix= boot.ratchetvalues=0.2.1 androidboot.serialno=0420819050367 bl_prof_dataptr=0x10000@0x277040000 sdhci_tegra.en_boot_part_access=1 root=/dev/mmcblk0p1 rw rootwait rootfstype=ext4

2

I have some founds:
After I do entire flash command “./flash.sh jetson-tx2 mmcblk0p1”,
the time on “Retrieving file: /boot/Image” reduce to 567ms.

Retrieving file: /boot/Image addr_buf: ffb28220
21864560 bytes read in 567 ms (36.8 MiB/s)

Anyone can try to give me the possible reason?
Are there any lost config file?

Thanks,

3

If you look at a full boot log over serial console (including U-Boot messages), then typically the default is to scan for devices in a given order. Macros define the order and list of devices searched. Very likely time is spent detecting if USB or SD card content is present. Even within the eMMC scan it is likely time is being spent scanning at alternate locations. If the macros defined only to search eMMC extlinux.conf, then time could be saved (but you’d have to add an explicit boot entry in the eMMC extlinux.conf if you want to boot to other media, e.g., SD card).

If you were to interrupt U-Boot with serial console and go to the U-Boot command line, then you could see commands with “help”. In particular, if you were to run “printenv”, then you would see a list of environment variables. Many of those variables are boot-related macros. Each macro can be edited, and then booted once with those edits if not saved, or saved and permanently used (e.g., “editenv” and “saveenv”). The boot starts with the macro “run_distro_bootcmd”. Note there are multiple ways to view individual variables, but here is an excerpt of some R28.2 environment:

bootcmd=run distro_bootcmd

distro_bootcmd=for target in ${boot_targets}; do run bootcmd_${target}; done

boot_targets=mmc1 mmc0 usb0 pxe dhcp

# ...consider also that once a target is chosen, there is more than one place an extlinux.conf
# can exist...lots of scanning which could be fixed not scan and just use a specific entry:
boot_extlinux=sysboot ${devtype} ${devnum}:${distro_bootpart} any ${scriptaddr} ${prefix}extlinux/extlinux.conf

scan_dev_for_boot=echo Scanning ${devtype} ${devnum}:${distro_bootpart}...; for prefix in ${boot_prefixes}; do run scan_dev_for_extlinux; run scan_dev_for_scripts; done;run scan_dev_for_efi;

scan_dev_for_boot_part=part list ${devtype} ${devnum} -bootable devplist; env exists devplist || setenv devplist $defaultdevplist; for distro_bootpart in ${devplist}; do if fstype ${devtype} ${devnum}:${distro_bootpart} bootfstype; then run scan_dev_for_boot; fi; done

scan_dev_for_extlinux=if test -e ${devtype} ${devnum}:${distro_bootpart} ${prefix}extlinux/extlinux.conf; then echo Found ${prefix}extlinux/extlinux.conf; run boot_extlinux; echo SCRIPT FAILED: continuing...; fi

scan_dev_for_scripts=for script in ${boot_scripts}; do if test -e ${devtype} ${devnum}:${distro_bootpart} ${prefix}${script}; then echo Found U-Boot script ${prefix}${script}; run boot_a_script; echo SCRIPT FAILED: continuing...; fi; done

If you have a dedicated boot path, and you do not want other options to be checked, then you could eliminate scanning and hard code (well, really firm code since it is environment) all of that macro scripted logic and be able to skip some of the time required from scanning. Having a boot log would probably show you actual choices made, and allow you to hard code those choices.

The other nice thing about serial console logs is that it includes timestamps. Breaking down actual location of delays is a big advantage versus just trying to blindly fix things which might not be an issue.

4

Hello linuxdev,

Thank you for your detailed information.
It is a little difficult for me to understand the ‘scan_dev_for_boot_part’,
I just try to understand the reason uboot take too long time on “Retrieving file”.
Your means that’s lots of boot scanning.
For my design,only need to use built-in eMMC boot path.
Would you please guide me how to edit the boot env?

Thanks

5

I add some debug print in the mmc_bread function of /drivers/mmc/mmc.c

#ifdef CONFIG_BLK
static ulong mmc_bread(struct udevice *dev, lbaint_t start, lbaint_t blkcnt,
		       void *dst)
#else
static ulong mmc_bread(struct blk_desc *block_dev, lbaint_t start,
		       lbaint_t blkcnt, void *dst)
#endif
{
#ifdef CONFIG_BLK
	struct blk_desc *block_dev = dev_get_uclass_platdata(dev);
#endif
	int dev_num = block_dev->devnum;
	int err;
	lbaint_t cur, blocks_todo = blkcnt;
    unsigned long time;
	if (blkcnt == 0)
		return 0;

	struct mmc *mmc = find_mmc_device(dev_num);
	if (!mmc)
		return 0;

	err = blk_dselect_hwpart(block_dev, block_dev->hwpart);
	if (err < 0)
		return 0;

	if ((start + blkcnt) > block_dev->lba) {
#if !defined(CONFIG_SPL_BUILD) || defined(CONFIG_SPL_LIBCOMMON_SUPPORT)
		printf("MMC: block number 0x" LBAF " exceeds max(0x" LBAF ")\n",
			start + blkcnt, block_dev->lba);
#endif
		return 0;
	}
    printf("<%d>mmc_bread blocks_todo = %lu start = %lu",
           dev_num,
           blocks_todo,
           start);
	if (mmc_set_blocklen(mmc, mmc->read_bl_len)) {
		debug("%s: Failed to set blocklen\n", __func__);
		return 0;
	}
    time = get_timer(0);
	do {
		cur = (blocks_todo > mmc->cfg->b_max) ?
			mmc->cfg->b_max : blocks_todo;
		if (mmc_read_blocks(mmc, dst, start, cur) != cur) 
		{
			debug("%s: Failed to read blocks\n", __func__);
			return 0;
		}
		blocks_todo -= cur;
		start += cur;
		dst += cur * mmc->read_bl_len;
	} while (blocks_todo > 0);
    time = get_timer(time);
	printf("use %lu ms\n",time);
	return blkcnt;
}

on the U-Boot command line running following command:

set devtype mmc
run scan_dev_for_boot_part

I get as following serial boot log:
…
<0>mmc_bread blocks_todo = 1 start = 17043889use 1 ms
filename:/boot/extlinux/extlinux.conf addr:2185232384
213 bytes read in 166 ms (1000 Bytes/s)
p2771-0000 eMMC boot options
1: primary kernel
Enter choice: 1: primary kernel
Retrieving file: /boot/Image addr_buf: ffb28220
…
<0>mmc_bread blocks_todo = 1 start = 1use 2 ms
<0>mmc_bread blocks_todo = 8 start = 2use 3 ms
<0>mmc_bread blocks_todo = 1 start = 4097use 2 ms
<0>mmc_bread blocks_todo = 2 start = 4099use 3 ms
<0>mmc_bread blocks_todo = 1 start = 4105use 2 ms
<0>mmc_bread blocks_todo = 1 start = 12553use 2 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 1 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 2 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 2 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 2 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 1 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 2 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 2 ms
<0>mmc_bread blocks_todo = 1 start = 78089use 2 ms
<0>mmc_bread blocks_todo = 1 start = 4109use 2 ms
<0>mmc_bread blocks_todo = 1 start = 16781569use 2 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 2 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 1 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 2 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 1 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 2 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 1 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 2 ms
<0>mmc_bread blocks_todo = 1 start = 16847105use 2 ms
<0>mmc_bread blocks_todo = 1 start = 4109use 2 ms
…
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 2 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 2 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 2 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 1376 start = 1415169use 19 ms
<0>mmc_bread blocks_todo = 2 start = 1401505use 2 ms
<0>mmc_bread blocks_todo = 1 start = 1401507use 2 ms
filename:/boot/Image addr:2148007936
21423296 bytes read in 34753 ms (601.6 KiB/s)
append: root=/dev/mmcblk0p1 rw rootwait console=ttyS0,115200n8 console=tty0 OS=l4t fbcon=map:0 net.ifnames=0 memtype=0 video=tegrafb no_console_suspend=1 earlycon=uart8250,mmio32,0x03100000 nvdumper_reserved=0x2772e0000 gpt tegra_fbmem2=0x800000@0x969ed000 lut_mem2=0x2008@0x969ea000 tegraid=18.1.2.0.0 tegra_keep_boot_clocks maxcpus=6 boot.slot_suffix= boot.ratchetvalues=0.2.1 androidboot.serialno=0420819050367 bl_prof_dataptr=0x10000@0x277040000 sdhci_tegra.en_boot_part_access=1 root=/dev/mmcblk0p1 rw rootwait rootfstype=ext4
boot_get_fdt argc = 3select 92000000

Flattened Device Tree blob at 92000000

Booting using the fdt blob at 0x92000000
reserving fdt memory region: addr=80000000 size=10000
Using Device Tree in place at 0000000092000000, end 000000009203baab
…

this type message "<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms" repeat almost 5000 times.
It seem like there are many same address(such as block start number 17090473) access.

For this board(slowly start-up), I have installed some software package.

If I use the entire flash command to re-flash this board, the issues will go away.

Can you give me any suggestion on how to fix the issues ?

6

No need to edit U-Boot. Those macro variables are all that needs edit, and are not hard coded within U-Boot. If the variables are set up, then the default U-Boot will work. However, instructions will possibly change depending on which version of L4T you use (see “head -n 1 /etc/nv_tegra_release”). The most recent is R32.1 (from JetPack/SDKManager4.2).

To start with, do you have serial console connected? If so, then early on in boot you can interrupt boot with any keystroke. When you hit a key within early U-Boot it goes to a U-Boot command line console. You will see something like this:

[0004.169] I> Kernel EP: 0x84600000, DTB: 0x80000000

U-Boot 2016.07-g0eb73f4 (Mar 13 2019 - 00:20:34 -0700)

TEGRA186
Model: NVIDIA P2771-0000-500
DRAM:  7.8 GiB
MC:   Tegra SD/MMC: 0, Tegra SD/MMC: 1
*** Warning - bad CRC, using default environment

In:    serial
Out:   serial
Err:   serial
Net:   eth0: ethernet@2490000
<i><b>Hit any key to stop autoboot:  2 </b></i>

…you will have less than two seconds to hit any key and drop to command line (if you are a bit late it will instead drop you into a kernel menu select…with only one kernel the only “continue” choice is “0”, the first kernel). Once in command line you can continue boot with the command “boot”. You can get a list of commands you have access to by typing the command “help”. One of those commands is “printenv”. Those values are not hard coded and do not need edit of U-Boot to change. Are you able to reach U-Boot console over serial console?

7

Hello linuxdev,

Yes, I am able to reach U-boot console over serial console.
Would you please provide me detailed instruction to config fixed eMMC boot path?
Also, I’m using Jetpack 3.3 L4T R28.2.1

Thanks

8

I haven’t tried to remove all the extra scanning before, but the macro expansion is simple to figure out once you understand where it starts. Edits are also simple. What I’ll recommend is that you start by creating a log of some content. On your serial console, interrupt to get to the U-Boot prompt. Then start logging. Run the command “printenv”. End logging and save that to a file. You might even want to actually print this. You might consider also saving a copy of the “help” command output. Some particular help commands to look at:

  • help
  • help editenv
  • help echo
  • help saveenv
  • help run
  • help mmc
  • help part

Note that what follows is from R32.1, but I believe most of U-Boot will be a match for R28.2.1. The methodology is still valid for either. Xaviers can’t use this since Xaviers don’t use U-Boot.

Take a close look at the “bootcmd” variable. When you type “boot” to continue booting, this is what runs:

bootcmd=run distro_bootcmd

If you wanted to change this, you might check “help editenv”. If you edit, but don’t save, then your boot will contain the edit, but the next boot will forget the edit and the environment will be back to what it was before the edit. For the most part you are free to make mistakes if you do not “saveenv”. If you want to see the content of one variable, then you could “echo $bootcmd” just like a Linux command line shell.

Here is an excerpt of some macros and commands (how these are used is added later):

  • bootcmd=run distro_bootcmd
  • "run" is a command. "help run".
  • "distro_bootcmd" is an environment variable which gets expanded. "echo $distro_bootcmd".
  • boot_targets=mmc1 mmc0 usb0 pxe dhcp /* This is interesting! Scans SD then eMMC, so on. What if it were just eMMC, "mmc0"? */
  • bootcmd_mmc0=setenv devnum 0; run mmc_boot /* "printenv mmc_boot". setenv does what you expect, creates an environment variable named "devnum" and sets to "0". */
  • mmc_boot=if mmc dev ${devnum}; then setenv devtype mmc; run scan_dev_for_boot_part; fi "mmc" is a command. "help mmc". Sets a device and returns if successful or not.
  • scan_dev_for_boot_part=part list ${devtype} ${devnum} -bootable devplist; env exists devplist || setenv devplist $defaultdevplist; for distro_bootpart in ${devplist}; do if fstype ${devtype} ${devnum}:${distro_bootpart} bootfstype; then run scan_dev_for_boot; fi; done
  • part list is a command to list partitions. We'll see this becomes type "mmc" and device "0". Try it on command line: part list mmc 0 /* What if we already know which partition and don't need to scan and select among 31 partitions? */
  • fstype is a command to find filesystem type. Try it: fstype mmc 0. /* What if we already know the type is going to be ext4? Why scan for it? */
  • scan_dev_for_boot=echo Scanning ${devtype} ${devnum}:${distro_bootpart}...; for prefix in ${boot_prefixes}; do run scan_dev_for_extlinux; run scan_dev_for_scripts; done;run scan_dev_for_efi; /* This almost looks like the previous macro, but instead of scanning for partitions, it scans for bootable partitions among a list of partitions. */ /* VERY INTERESTING: Note that you can inject echo into any macro, and serial console will see the macro as you boot. Good debug and exploration tool. */
  • boot_prefixes=/ /boot/ /* This says to scan for boot content files (like extlinux.conf) in "/" and "/boot/", starting with "/". But we already know it is in "/boot/", so why scan for "/" at all? Later on, consider we don't even need to scan "/boot/" because we already know content is there, but we'd still have to manually substitute this location somewhere in the environment if we wish to completely circumvent scan. Scanning one location instead of two is faster; not scanning at all is better for speed. */
  • It goes on like this, and many scanned values could be hard coded in the environment. Either by scanning that device first, or by not scanning at all and substituting what we expect to work without scans. Look for scanning and testing...find out what branch or result is used, and edit out one at a time in the environment.
  • If you write your commands to edit a piece at a time from your host PC, then you can copy and paste and try again without using saveenv. If you know something works, then you can saveenv for tiny changes. If you don't saveenv and something goes wrong, then just reboot to reset. If you saveenv in some way which prevents serial console access, then you will have to flash again to get access.

Everything starts with variable “bootcmd” when you run command “boot”. Start with this. See what is in it, then expand out to what the meaning is behind each variable or command within that. If curious about something, then add an “echo” to a value, then log while rebooting.

“bootcmd” leads to “run distro_bootcmd”. “distro_bootcmd”, after some logic, leads to “bootcmd_mmc0”. “bootcmd_mmc0” leads to some scanning for devices and partitions. Some macros write new macros, usually to remember test/scan results rather than being logic.

I don’t know if I would advise to do so, but in the end you could just rewrite “bootcmd” as a single “run …something…” which has no tests for devices, partitions, filesystem types, so on, and directly loads what you know will be the correct answer anyway. None of which requires compiling or modifying U-Boot source itself.

9

Hi LinuxDev,

I can understand uboot process on bring-up kernel about Env variable.
From my debug result by adding debug message, it look like that it is not related with scan difference boot device and partitions.

Actually,uboot take 17.6sec on read /boot/Image in the ext4 fs, I believe it is not normal.
However, if I do entire flash command “./flash.sh jetson-tx2 mmcblk0p1” on the same board with the same uboot source then the time result is about 500ms.

let me again show the uboot start-up log message:

Found /boot/extlinux/extlinux.conf
Retrieving file: /boot/extlinux/extlinux.conf 
filename:/boot/extlinux/extlinux.conf addr:2185232384 
213 bytes read in 65 ms (2.9 KiB/s)
p2771-0000 eMMC boot options
1:	primary kernel
Enter choice: 1:	primary kernel
Retrieving file: /boot/Image
filename:/boot/Image addr:2148007936 
21864560 bytes read in 17639 ms (1.2 MiB/s)

I assume “Retrieving file: /boot/Image” is reading Image from eMMC to DDRAM.
I try to summary following on calling sequence, if there is any error, Please correct me.

  1. do_load()(fs.c,~L356) → fs_read()(fs.c,~L294)
  2. ext4_read_file() → ext4fs_read() → ext4fs_read_file()->ext4fs_devread() // those function in the ext4fs.c
  3. blk_dread() → ops->read() (blk-uclass.c)
  4. mmc_bread() → mmc_read_blocks() → mmc_send_cmd()

added debug print in the function mmc_bread(), then get many calling with same block param(startblock,numblock)

I think it is not normal, maybe that’s the reason cause the long time?

<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 2 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 2 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms
<0>mmc_bread blocks_todo = 8 start = 17090473use 2 ms 
<0>mmc_bread blocks_todo = 8 start = 17090473use 3 ms

I don’t know why there are so many repeated calling with same params.(detail please refer to comment#5)

I also post the completed boot log as attached file uboot_slow_startup.log.

Thanks

uboot_slow_startup.log (325 KB)

10

Yes, the loading Image is copy of Image from disk and loading to a base address in RAM. eMMC is a block device, and entire blocks are read until reaching the end of the file.

I am just speculating here, so don’t take this too seriously, but if one is using dd to read a file, then the process is quite similar. Since in this case the eMMC block size is 512 bytes, dd performs best if block size is a multiple of 512 (dd parameter “bs=512” is an example). If one has knowledge that there a lot of blocks of size 512, then dd can get a performance improvement by using a larger buffer which is a multiple of 512. So for example, “2^16” is 65536, and so something like “512*(2^16) = 33554432 bytes” could be used (e.g., “bs=33554432”) and performance would go up. If one were to use dd to read in block size of 1 or 2 bytes, then 512 bytes would still be read, and other than the 1 or 2 bytes, the content would be thrown away. Once could read more bytes than the total file size, but this would be a waste of RAM reservation. Perhaps, if you were to modify this to read a larger number of bytes which are evenly divisible by 512 performance would go up.

I don’t see the actual block size from what you posted, and I have not read the U-Boot source, but you could try taking the existing code of U-Boot and having it read 8 times more per read and checking the timing differences. The overhead of individual reads should go down. In the case of reading a file the result of reading the entire amount at once has the overhead of open and close only once, but reading a bit, closing, and reopening thousands of times would be a far worse load time. You are working at a lower level in U-Boot, so I don’t know what is possible, but just for the case of reading the kernel Image you could possibly get a speed benefit with larger read chunks/blocks.

Incidentally, I’m not positive about read size from the logs since I don’t know about the modifications to echo, but I see mostly 2 or 3 ms per read. Every once in a while “start” uses a different value and time goes up (but this might be ok if more is read). The really big point to think about is that the log shows a lot of 2 or 3 ms reads. As a contrived example, if the overhead of each 2 or 3 ms copy is 1 ms of time to open and close, then combining 10 3 ms calls into 1 call would reduce the 30 ms you’d expect by 10*1 ms, and would end up as only 20 ms for the same thing. If there is no overhead to separating read into a lot of 3 ms calls, then you won’t gain anything by combining this into a larger single call, but any improvement at all will be multiplied by a lot and be very beneficial. If I were to investigate, and if saw actual read of the kernel was the bottleneck, then I’d look very closely at whether some generic read function could be used in a different way. The resulting improvement can be dramatic.

11

I found the similar probelm:
[U-Boot] [PATCH] ext4fs: Add ext4 extent cache for read operations
http://u-boot.10912.n7.nabble.com/EXT4-slow-boot-problem-td310693.html
I tried to applay the patch on Nvidia Uboot source, But Get some error when applay the patch.
For Jetpack3.3 R28.2.1 need to applay similar patch?

12

I could not tell you about that patch content. I would recommend starting purely with the macros and simplifying those to go straight to the known configuration. Only after this would I resort to patches (the environment variables are the bulk of the boot time and do not require a modified U-Boot).

Meanwhile, does anyone at NVIDIA have knowledge of whether the above patches work with R28.2.1/JetPack3.3?

13

We do have a patch (applied late Jan '19) in our downstream L4T U-Boot to cache extent data. Look for ‘ext: cache extant data’ from Stephen Warren in your U-Boot source commit log, probably in the R32.2 source (I’m pretty sure it was fixed after R28.2.1). I believe we sourced it from upstream (Denx) U-Boot. It should apply equally to TX1/Nano and TX2.

HTH,

Tom

14

@LinuxDev,

I was reading uboot ‘printenv’ output and could not figure out where is ‘distro_bootpart’ got initialized?

15

If a variable is not set, then that content will be blank. However, another macro can set “distro_bootpart” (each macro can set or clear or edit anything in the environment). The subtle implication is that when you reach the command line prompt of U-Boot you will only see items already set…items set through macros or other dynamic generation won’t occur until the boot actually starts and the macro has run. So for example, it might be that the value is set once you’ve picked a kernel to boot or a stage where kernels have been scanned for. I believe you are just looking too early in boot prior to when the variable has been set.

Keep in mind that during boot you can “echo” content, e.g., debug statements (e.g., ‘echo “hello world”’), and so you might find a place where “distro_bootcmd” is used, and then add an echo statement to see the content…which should be visible during serial console logging upon boot. Perhaps if there are several places with this value being used, then at the end of each statement you could also add:

; echo "debug 1 ${distro_bootcmd}"
...
; echo "debug 2 ${distro_bootcmd}"
...
; echo "debug 3 ${distro_bootcmd}"
...
# and so on.

You can edit for only one boot without risk, and see what goes on once you type in “boot” at the U-Boot command line. I can’t tell you where this value is actually set, but printing at each step would tell you where this is set. If you know this, then you could for example overwrite the value with another value in the next line of code.

If you look at the U-Boot source code, then you’ll see this has a default value set via this in start.c:

int sandbox_main_loop_init(void)
{
        struct sandbox_state *state = state_get_current();

        /* Execute command if required */
        if (state->cmd || state->run_distro_boot) {
                int retval = 0;

                cli_init();

[b]#ifdef CONFIG_CMDLINE
                if (state->cmd)
                        retval = run_command_list(state->cmd, -1, 0);

                if (state->run_distro_boot)
                        retval = cli_simple_run_command("run distro_bootcmd",
                                                        0);
#endif[/b]
                if (!state->interactive)
                        os_exit(retval);
        }

        return 0;
}

…and so I imagine this could be configured directly in the U-Boot binary (which in turn has Tegra-specific configurations).

16

@linuxdev, thanks for the explanation.
I’ve found ‘distro_bootpart’ being set in pxe.c::label_boot but why pxe code since it’s doing net booting?

#ifdef CONFIG_HUSH_PARSER
		distro_bootpart = getenv("distro_bootpart");
		hush_bootpart = get_local_var("distro_bootpart");
		if (hush_bootpart && !distro_bootpart) {
			char partnumstr[32];
			unsigned long partnum = simple_strtoul(hush_bootpart, NULL, 16);
			snprintf(partnumstr, sizeof(partnumstr), "%lu", partnum);
			setenv("distro_bootpart", partnumstr);
		}
#endif
		cli_simple_process_macros(bootargs, finalbootargs);
		setenv("bootargs", finalbootargs);
		printf("append: %s\n", finalbootargs);
#ifdef CONFIG_HUSH_PARSER
		if (hush_bootpart && !distro_bootpart)
			setenv("distro_bootpart", NULL);
#endif
17

I am unable to give you answers on that design, but just beware that many bootloaders (and boot loading in general) step through a series of tests to see what to boot. Depending on the sorting and options set up, the first valid boot device would be found simply by iterating through that list of devices. There are times when a step might be in common for other steps.

In terms of individual variables, whatever function sets this value last is the final value chosen. If this value is set in more than one place, then the last value chosen at the moment of booting the kernel would be the value actually used even if there had been earlier different values. I do not know what other times or places distro_bootpart might be set in, but you can add print commands (in U-Boot code) or echo commands (in U-Boot macro expansions) to gain insight.