Optimize system boot time - size of NVMe storage

Dear experts,

We recently replaced a 500GB with a 1TB NVMe in our Nvidia Jetson Xavier NX + Jetpack-5.0.2 based system and observed an extreme longer boot time (reported doubled the boot time of the 500GB NVMe case).

Below is the systemd analysis of our system using 512GB-NVMe (after disabling the nvgetty.service and also removing the ttyTCU0,115200n8 boot option from /boot/extlinux/extlinux.conf) :

$ systemd-analyze 
Startup finished in 5.151s (kernel) + 30.997s (userspace) = 36.148s 
graphical.target reached after 30.937s in userspace
$ systemd-analyze blame
20.008s dev-nvme0n1p1.device                
19.893s docker.service                      
15.272s rc-local.service                    
15.266s snap.lxd.activate.service           
10.014s gdm.service                         
 6.712s nv-l4t-usb-device-mode.service      
 5.791s snapd.service                       
 3.781s dev-zram3.device                    
 3.253s dev-zram0.device                    
 2.988s dev-zram1.device                    
 2.711s dev-zram2.device                    
 2.470s dev-zram4.device                    
 2.411s dev-zram5.device                    
 1.720s udisks2.service                     
 1.686s systemd-random-seed.service         
 1.601s upower.service                      
 1.291s user@1000.service                   
 1.233s systemd-udev-trigger.service        
 1.203s containerd.service                  
 1.137s nvphs.service                       
 1.004s accounts-daemon.service             
  902ms dev-loop0.device                    
  850ms nv.service                          
  850ms dev-loop1.device                    
  807ms alsa-restore.service                
  771ms dev-loop4.device                    
  766ms networkd-dispatcher.service         
  756ms snap-lxd-28475.mount                
  743ms snap-multipass-12830.mount          
  725ms snap-snapcraft-12030.mount          
  711ms nvpmodel.service                    
  697ms dev-loop6.device                    
  694ms dev-loop2.device                    
  663ms snap-core-17201.mount               
  662ms dev-loop5.device                    
  648ms dev-loop3.device                    
  630ms nvpower.service                     
  627ms dev-loop8.device                    
  620ms dev-loop7.device                    
  610ms snap-lxd-26202.mount                
  607ms snap-multipass-11106.mount          
  599ms snap-core22-1383.mount              
  596ms snap-ros2\x2dmulti-x1.mount         
  564ms snap-core-16204.mount               
  563ms systemd-logind.service              
  561ms dev-loop12.device                   
  535ms snap-core22-1035.mount              
  535ms dev-loop9.device                    
  507ms dev-loop10.device                   
  494ms snap-core20-2321.mount              
  479ms snap-core20-2019.mount              
  478ms snapd.seeded.service                
  472ms systemd-journald.service            
  466ms ModemManager.service                
  454ms dev-loop11.device                   
  449ms kerneloops.service                  
  437ms snap-snapcraft-10086.mount          
  431ms systemd-resolved.service            
  395ms apport.service                      
  324ms NetworkManager.service              
  323ms ssh.service                         
  295ms e2scrub_reap.service                
  282ms avahi-daemon.service                
  278ms packagekit.service                  
  266ms keyboard-setup.service              
  257ms binfmt-support.service              
  254ms systemd-timesyncd.service           
  233ms dundee.service                      
  232ms switcheroo-control.service          
  228ms systemd-udevd.service               
  189ms systemd-user-sessions.service       
  179ms systemd-modules-load.service        
  168ms systemd-tmpfiles-setup.service      
  162ms resolvconf-pull-resolved.service    
  158ms proc-sys-fs-binfmt_misc.mount       
  158ms dev-hugepages.mount                 
  153ms colord.service                      
  152ms dev-mqueue.mount                    
  148ms ofono.service                       
  147ms run-rpc_pipefs.mount                
  141ms sys-kernel-debug.mount              
  139ms polkit.service                      
  138ms sys-kernel-tracing.mount            
  136ms nv_nvsciipc_init.service            
  136ms nvfb-early.service                  
  130ms openvpn.service                     
  125ms kmod-static-nodes.service           
  123ms modprobe@ramoops.service            
  123ms modprobe@chromeos_pstore.service    
  122ms nvfb-udev.service                   
  122ms modprobe@pstore_blk.service         
  122ms modprobe@pstore_zone.service        
  121ms modprobe@efi_pstore.service         
  112ms rsyslog.service                     
  109ms systemd-remount-fs.service          
  107ms wpa_supplicant.service              
   98ms pppd-dns.service                    
   96ms user-runtime-dir@1000.service       
   56ms systemd-sysusers.service            
   56ms console-setup.service               
   53ms nfs-config.service                  
   50ms rtkit-daemon.service                
   47ms systemd-update-utmp.service         
   46ms systemd-sysctl.service              
   44ms systemd-tmpfiles-setup-dev.service  
   38ms rpcbind.service                     
   36ms sys-fs-fuse-connections.mount       
   35ms systemd-update-utmp-runlevel.service
   31ms sys-kernel-config.mount             
   26ms systemd-journal-flush.service       
   25ms plymouth-read-write.service         
   25ms nvfb.service                        
   17ms plymouth-quit-wait.service          
   16ms docker.socket                       
   14ms setvtrgb.service                    
    7ms snapd.socket

I will provide the analysis of the 1TB-NVMe based system later when possible. But by looking at the critical services in analysis of the 500GB based system :

20.008s dev-nvme0n1p1.device                
19.893s docker.service                      
15.272s rc-local.service                    
15.266s snap.lxd.activate.service           
10.014s gdm.service

do you think that the degradation in boot time depends heavily on the NVMe size?

Thanks in advance for your opinion and advice if any.

Best Regards,
Khang

Hi khang.l4es,

Are you using the devkit or custom board for Xavier NX?

What’s your current boot time in both cases?

I think NVMe size should not affect the boot time that so mcuh(double!?).

Please share the full serial console log with timestamp enabled for the boot time issue.

Hi @KevinFFF,

Are you using the devkit or custom board for Xavier NX?

We are using custom board.

What’s your current boot time in both cases?

I will update the info as soon as possible.

Please share the full serial console log with timestamp enabled for the boot time issue.

Will I need to do something specific to enable the timestamp?

Best Regards,
Khang

Hi @KevinFFF,

What’s your current boot time in both cases?

I will update the info as soon as possible.

For the 1TB-NVMe setup :

$ systemd-analyze 
Startup finished in 7.957s (kernel) + 27.157s (userspace) = 35.115s 
graphical.target reached after 27.103s in userspace
$ systemd-analyze blame                  
17.529s snap.lxd.activate.service               
15.881s dev-nvme0n1p1.device                    
15.612s docker.service                          
13.550s snapd.service                           
11.074s rc-local.service                        
10.469s dev-zram0.device                        
10.245s gdm.service                             
10.118s dev-zram1.device                        
10.094s dev-zram2.device                        
10.085s dev-zram5.device                        
10.069s dev-zram4.device                        
10.040s dev-zram3.device                        
 5.325s nv-l4t-usb-device-mode.service          
 2.979s dev-loop9.device                        
 2.872s dev-loop10.device                       
 2.814s dev-loop12.device                       
 2.647s dev-loop11.device                       
 2.403s dev-loop8.device                        
 1.374s accounts-daemon.service                 
 1.275s containerd.service                      
 1.231s nvphs.service                           
 1.184s networkd-dispatcher.service             
 1.147s ssh.service                             
 1.101s systemd-localed.service                 
 1.087s nv.service                              
 1.040s upower.service                          
 1.022s snap-lxd-28475.mount                    
 1.018s snap-multipass-11106.mount              
 1.012s snap-multipass-12708.mount              
 1.005s snapd.seeded.service                    
  932ms systemd-udev-trigger.service            
  921ms user@1000.service                       
  813ms dev-loop0.device                        
  787ms dev-loop1.device                        
  785ms systemd-hostnamed.service               
  745ms dev-loop2.device                        
  733ms dev-loop3.device                        
  707ms snap-core22-1383.mount                  
  673ms dev-loop5.device                        
  668ms dev-loop4.device                        
  660ms udisks2.service                         
  640ms nvpower.service                         
  633ms systemd-logind.service                  
  609ms dev-loop6.device                        
  609ms systemd-resolved.service                
  603ms nvpmodel.service                        
  595ms snap-lxd-26202.mount                    
  569ms snap-ros2\x2dmulti-x1.mount             
  549ms snap-core-16931.mount                   
  489ms alsa-restore.service                    
  486ms geoclue.service                         
  485ms snap-core22-1035.mount                  
  453ms dev-loop7.device                        
  442ms systemd-journald.service                
  438ms snap-snapcraft-11977.mount              
  421ms resolvconf-pull-resolved.service
  414ms snap-core-16204.mount                   
  407ms ModemManager.service                    
  370ms avahi-daemon.service                    
  366ms NetworkManager.service                  
  338ms apport.service                          
  317ms snap-core20-2321.mount                  
  295ms dundee.service                          
  288ms systemd-timesyncd.service               
  287ms kerneloops.service                      
  275ms snap-core20-2019.mount                  
  266ms systemd-modules-load.service            
  265ms snap-snapcraft-11868.mount              
  253ms keyboard-setup.service                  
  237ms nvfb-udev.service                       
  233ms modprobe@ramoops.service                
  231ms systemd-udevd.service                   
  228ms modprobe@pstore_zone.service            
  217ms modprobe@pstore_blk.service             
  216ms packagekit.service                      
  212ms systemd-remount-fs.service              
  206ms e2scrub_reap.service                    
  204ms switcheroo-control.service              
  203ms modprobe@efi_pstore.service             
  176ms ofono.service                           
  172ms polkit.service                          
  164ms nv_nvsciipc_init.service                
  164ms nvfb-early.service                      
  164ms dev-hugepages.mount                     
  158ms dev-mqueue.mount                        
  152ms run-rpc_pipefs.mount                    
  148ms sys-kernel-debug.mount                  
  147ms sys-kernel-tracing.mount                
  139ms modprobe@chromeos_pstore.service        
  138ms colord.service                          
  137ms kmod-static-nodes.service               
  113ms systemd-sysusers.service                
  104ms pppd-dns.service                        
  102ms rsyslog.service                         
  102ms systemd-tmpfiles-setup.service          
  101ms binfmt-support.service                  
   96ms openvpn.service                         
   93ms wpa_supplicant.service                  
   73ms user-runtime-dir@1000.service           
   72ms plymouth-quit-wait.service              
   64ms systemd-user-sessions.service           
   55ms sys-fs-fuse-connections.mount           
   53ms systemd-update-utmp.service             
   52ms sys-kernel-config.mount                 
   43ms systemd-sysctl.service                  
   41ms systemd-tmpfiles-setup-dev.service      
   39ms proc-sys-fs-binfmt_misc.mount           
   38ms systemd-update-utmp-runlevel.service    
   38ms rpcbind.service                         
   38ms rtkit-daemon.service                    
   34ms console-setup.service                   
   32ms systemd-random-seed.service             
   28ms systemd-journal-flush.service           
   23ms setvtrgb.service                        
   22ms plymouth-read-write.service             
   18ms nfs-config.service                      
   16ms docker.socket                           
   15ms nvfb.service                            
    7ms snapd.socket  

Boot time of 500GB NVMe based system : (30s, 40s)
Boot time of 1TB NVMe based system : > 1minute

Quick observation of the systemd analysis for 1TB NVMe based system :

10.469s dev-zram0.device                        
10.118s dev-zram1.device                        
10.094s dev-zram2.device                        
10.085s dev-zram5.device                        
10.069s dev-zram4.device                        
10.040s dev-zram3.device

compared to 500GB NVMe based system :

3.781s dev-zram3.device                    
3.253s dev-zram0.device                    
2.988s dev-zram1.device                    
2.711s dev-zram2.device                    
2.470s dev-zram4.device                    
2.411s dev-zram5.device   

What do you think?

It may depend on your serial application.
Let me take minicom as example that you can press CTRL+A → Z → N to enable timestamp.

What’s the rootfs size you used for 500GB and 1TB NVMe drive respectively?

Hi @KevinFFF,

On 500GB based system :

$ lsblk 
NAME         MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
loop0          7:0    0  59,3M  1 loop /snap/core20/2019
loop1          7:1    0  69,2M  1 loop /snap/core22/1383
loop2          7:2    0  93,3M  1 loop /snap/core/16204
loop3          7:3    0  69,1M  1 loop /snap/core22/1035
loop4          7:4    0 106,1M  1 loop /snap/multipass/11106
loop5          7:5    0  92,8M  1 loop /snap/lxd/28475
loop6          7:6    0    92M  1 loop /snap/core/17201
loop7          7:7    0 134,8M  1 loop /snap/lxd/26202
loop8          7:8    0  54,9M  1 loop /snap/snapcraft/10086
loop9          7:9    0 107,5M  1 loop /snap/multipass/12830
loop10         7:10   0  53,1M  1 loop /snap/ros2-multi/x1
loop11         7:11   0  59,8M  1 loop /snap/core20/2321
loop12         7:12   0  66,4M  1 loop /snap/snapcraft/12030
loop13         7:13   0    16M  1 loop 
mmcblk0      179:0    0  14,7G  0 disk 
├─mmcblk0p1  179:1    0    14G  0 part 
├─mmcblk0p2  179:2    0    64M  0 part 
├─mmcblk0p3  179:3    0   448K  0 part 
├─mmcblk0p4  179:4    0  32,6M  0 part 
├─mmcblk0p5  179:5    0   2,5M  0 part 
├─mmcblk0p6  179:6    0    64K  0 part 
├─mmcblk0p7  179:7    0     1M  0 part 
├─mmcblk0p8  179:8    0     1M  0 part 
├─mmcblk0p9  179:9    0     1M  0 part 
├─mmcblk0p10 179:10   0   1,5M  0 part 
├─mmcblk0p11 179:11   0     1M  0 part 
├─mmcblk0p12 179:12   0    64M  0 part 
├─mmcblk0p13 179:13   0   448K  0 part 
├─mmcblk0p14 179:14   0  32,5M  0 part 
├─mmcblk0p15 179:15   0    80M  0 part 
├─mmcblk0p16 179:16   0   512K  0 part 
├─mmcblk0p17 179:17   0   100M  0 part 
├─mmcblk0p18 179:18   0    64M  0 part 
└─mmcblk0p19 179:19   0 245,5M  0 part 
zram0        251:0    0   1,2G  0 disk [SWAP]
zram1        251:1    0   1,2G  0 disk [SWAP]
zram2        251:2    0   1,2G  0 disk [SWAP]
zram3        251:3    0   1,2G  0 disk [SWAP]
zram4        251:4    0   1,2G  0 disk [SWAP]
zram5        251:5    0   1,2G  0 disk [SWAP]
nvme0n1      259:0    0 465,8G  0 disk 
├─nvme0n1p1  259:1    0   450G  0 part /
├─nvme0n1p2  259:2    0    64M  0 part 
├─nvme0n1p3  259:3    0    64M  0 part 
├─nvme0n1p4  259:4    0   448K  0 part 
├─nvme0n1p5  259:5    0   448K  0 part 
├─nvme0n1p6  259:6    0    80M  0 part 
├─nvme0n1p7  259:7    0   512K  0 part 
├─nvme0n1p8  259:8    0   100M  0 part 
├─nvme0n1p9  259:9    0    64M  0 part 
└─nvme0n1p10 259:10   0  15,4G  0 part 

~$ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/nvme0n1p1  442G   58G  363G  14% /
none            7,3G     0  7,3G   0% /dev
tmpfs           7,3G  4,6M  7,3G   1% /dev/shm
tmpfs           1,5G   20M  1,5G   2% /run
tmpfs           5,0M  4,0K  5,0M   1% /run/lock
tmpfs           7,3G     0  7,3G   0% /sys/fs/cgroup
/dev/loop2       94M   94M     0 100% /snap/core/16204
/dev/loop0       60M   60M     0 100% /snap/core20/2019
/dev/loop3       70M   70M     0 100% /snap/core22/1035
/dev/loop4      107M  107M     0 100% /snap/multipass/11106
/dev/loop6       93M   93M     0 100% /snap/core/17201
/dev/loop5       93M   93M     0 100% /snap/lxd/28475
/dev/loop1       70M   70M     0 100% /snap/core22/1383
/dev/loop7      135M  135M     0 100% /snap/lxd/26202
/dev/loop8       55M   55M     0 100% /snap/snapcraft/10086
/dev/loop9      108M  108M     0 100% /snap/multipass/12830
/dev/loop10      54M   54M     0 100% /snap/ros2-multi/x1
/dev/loop11      60M   60M     0 100% /snap/core20/2321
/dev/loop12      67M   67M     0 100% /snap/snapcraft/12030
tmpfs           1,0M     0  1,0M   0% /var/snap/lxd/common/ns
tmpfs           1,5G   24K  1,5G   1% /run/user/1000

On 1TB based system cloned from the above 500GB :

$ lsblk 
NAME         MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
loop0          7:0    0  59,3M  1 loop /snap/core20/2019
loop1          7:1    0  69,1M  1 loop /snap/core22/1035
loop2          7:2    0  69,2M  1 loop /snap/core22/1383
loop3          7:3    0 106,1M  1 loop /snap/multipass/11106
loop4          7:4    0 134,8M  1 loop /snap/lxd/26202
loop5          7:5    0  91,9M  1 loop /snap/core/16931
loop6          7:6    0  92,8M  1 loop /snap/lxd/28475
loop7          7:7    0  66,7M  1 loop /snap/snapcraft/11868
loop8          7:8    0  66,7M  1 loop /snap/snapcraft/11977
loop9          7:9    0  59,8M  1 loop /snap/core20/2321
loop10         7:10   0  93,3M  1 loop /snap/core/16204
loop11         7:11   0 107,5M  1 loop /snap/multipass/12708
loop12         7:12   0  53,1M  1 loop /snap/ros2-multi/x1
loop13         7:13   0    16M  1 loop 
mmcblk0      179:0    0  14,7G  0 disk 
├─mmcblk0p1  179:1    0    14G  0 part 
├─mmcblk0p2  179:2    0    64M  0 part 
├─mmcblk0p3  179:3    0   448K  0 part 
├─mmcblk0p4  179:4    0  32,6M  0 part 
├─mmcblk0p5  179:5    0   2,5M  0 part 
├─mmcblk0p6  179:6    0    64K  0 part 
├─mmcblk0p7  179:7    0     1M  0 part 
├─mmcblk0p8  179:8    0     1M  0 part 
├─mmcblk0p9  179:9    0     1M  0 part 
├─mmcblk0p10 179:10   0   1,5M  0 part 
├─mmcblk0p11 179:11   0     1M  0 part 
├─mmcblk0p12 179:12   0    64M  0 part 
├─mmcblk0p13 179:13   0   448K  0 part 
├─mmcblk0p14 179:14   0  32,5M  0 part 
├─mmcblk0p15 179:15   0    80M  0 part 
├─mmcblk0p16 179:16   0   512K  0 part 
├─mmcblk0p17 179:17   0   100M  0 part 
├─mmcblk0p18 179:18   0    64M  0 part 
└─mmcblk0p19 179:19   0 245,5M  0 part 
zram0        251:0    0   1,2G  0 disk [SWAP]
zram1        251:1    0   1,2G  0 disk [SWAP]
zram2        251:2    0   1,2G  0 disk [SWAP]
zram3        251:3    0   1,2G  0 disk [SWAP]
zram4        251:4    0   1,2G  0 disk [SWAP]
zram5        251:5    0   1,2G  0 disk [SWAP]
nvme0n1      259:0    0 953,9G  0 disk 
├─nvme0n1p1  259:1    0   450G  0 part /
├─nvme0n1p2  259:2    0    64M  0 part 
├─nvme0n1p3  259:3    0    64M  0 part 
├─nvme0n1p4  259:4    0   448K  0 part 
├─nvme0n1p5  259:5    0   448K  0 part 
├─nvme0n1p6  259:6    0    80M  0 part 
├─nvme0n1p7  259:7    0   512K  0 part 
├─nvme0n1p8  259:8    0   100M  0 part 
├─nvme0n1p9  259:9    0    64M  0 part 
└─nvme0n1p10 259:10   0  15,4G  0 part 

$ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/nvme0n1p1  442G   72G  348G  18% /
none            7,3G     0  7,3G   0% /dev
tmpfs           7,3G  5,3M  7,3G   1% /dev/shm
tmpfs           1,5G   21M  1,5G   2% /run
tmpfs           5,0M  4,0K  5,0M   1% /run/lock
tmpfs           7,3G     0  7,3G   0% /sys/fs/cgroup
/dev/loop0       60M   60M     0 100% /snap/core20/2019
/dev/loop1       70M   70M     0 100% /snap/core22/1035
/dev/loop2       70M   70M     0 100% /snap/core22/1383
/dev/loop3      107M  107M     0 100% /snap/multipass/11106
/dev/loop4      135M  135M     0 100% /snap/lxd/26202
/dev/loop5       92M   92M     0 100% /snap/core/16931
/dev/loop7       67M   67M     0 100% /snap/snapcraft/11868
/dev/loop6       93M   93M     0 100% /snap/lxd/28475
/dev/loop8       67M   67M     0 100% /snap/snapcraft/11977
/dev/loop9       60M   60M     0 100% /snap/core20/2321
/dev/loop10      94M   94M     0 100% /snap/core/16204
/dev/loop11     108M  108M     0 100% /snap/multipass/12708
/dev/loop12      54M   54M     0 100% /snap/ros2-multi/x1
tmpfs           1,0M     0  1,0M   0% /var/snap/lxd/common/ns
tmpfs           1,5G   24K  1,5G   1% /run/user/1000

And I also discovered that there’s still half of the capacity wasted as the 1TB NVMe was cloned from the 500GB NVMe but it seems not able to resize the bigger one while running (we haven’t been able to merge the APP partition (/dev/nvme0n1p1) with the unallocated partition yet) :

Any advice?

Regards,
Khang

There is no update from you for a period, assuming this is not an issue any more.
Hence we are closing this topic. If need further support, please open a new one.
Thanks

Are 500GB and 1T SSD from the same vendor and series?
Or they are from different vendor/model?