Xavier nx boot time issue

Hi, everyone. I’m working on reducing boot time on my custom board with Xavier NX, using L4T r35.3.1. And there is a question bothering me.

I use serial log to count boot time and it takes about 29s between powering on and login appearing.
And we need to ssh this board, when I use mobaxterm to ssh my board after login showing in serial log, it didn’t respond at the same time, it takes seconds to successfully ssh my board.

Do you know how to fix this? Because when I use r32.7.3 on Xavier NX, it can be ssh as soon as the login shows in serial log.

Here is my serial log on Xavier NX with r35.3.1.
seriallog xavier nx boot.log (93.6 KB)

Hi 85405347,

Do you mean the SSH server on your custom board with Xavier NX not work?

If so, please share the result of the following commands on you board.

$ ifconfig
$ systemctl status ssh

No, I can use the SSH server. The problem is there is a delay of a few seconds using SSH to access the board while the system is full booted up.
With r32.7.3, there is no such delay in Xavier NX.

What kind of delay do you mean? How long?
Have you checked the status of ssh server on your board?

with r32.7.3, when serial log ended in nvidia login:, the board can be SSH at the same time in mobaxterm shows nvidia@192.168.55.1's password:. But now when the login shows in serial log, I can access the board immediately in mobaxterm. The delay time is about 3~4s after login showed.

Yes, I have checked that and it works fine. But don’t turn off the board only unplug and plug the usb, I can access the board with SSH immediately.

the status of ssh server shows as follows

 ssh.service - OpenBSD Secure Shell server
     Loaded: loaded (/lib/systemd/system/ssh.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2023-03-28 01:54:12 CST; 40min ago
       Docs: man:sshd(8)
             man:sshd_config(5)
    Process: 900 ExecStartPre=/usr/sbin/sshd -t (code=exited, status=0/SUCCESS)
   Main PID: 949 (sshd)
      Tasks: 1 (limit: 8137)
     Memory: 5.4M
     CGroup: /system.slice/ssh.service
             └─949 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups

And the log shows that the SSH server has be actived 40 mintues ago when loginshows.(the board time is not set so it’s not realtime)

[2023-11-24 15:16:01]  Ubuntu 20.04.5 LTS nvidia ttyTCU0

[2023-11-24 15:16:01]  

[2023-11-24 15:16:01]  nvidia login: 

I also found that even the serial log shows login,my host can not ping jetson at the same time.
This may be the reason why I can not ssh the board as soon as possible, do you know what reason causes it?

Are you using ssh through ethernet or USB?

If you could not ping the board successfully, then you could not use SSH to access the board.

3~4s is not easy to be detected the issue.
Have you tried to list all system service to check if it might be caused from some services not ready?

In addition, could you reproduce the same behavior on the devkit?

I use USB to ssh the board.
And I think the cause is when system booted, it can not ping.
I have checked some related services such as nv-l4t-usb-device-mode, and it shows that it has been active as soon as the system boot up.

But the network-manager.service shows that after about 11s and l4tbr0 was only then activated.(other services active mostly is in 14:10:17, the time that login showed in debug serial. Is this the reason? And how to fix it?

nvidia@nvidia:~/Program$ systemctl status network-manager.service
● NetworkManager.service - Network Manager
     Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2023-11-27 14:10:16 CST; 1h 50min ago
       Docs: man:NetworkManager(8)
   Main PID: 511 (NetworkManager)
      Tasks: 3 (limit: 8137)
     Memory: 17.8M
     CGroup: /system.slice/NetworkManager.service
             └─511 /usr/sbin/NetworkManager --no-daemon

Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.2261] device (l4tbr0): Activation: starting connection 'l4tbr0' (51d2c32e-7089-405f-a89d-b3f27b325c56)
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.2339] device (l4tbr0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'external')
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.2361] device (l4tbr0): state change: prepare -> config (reason 'none', sys-iface-state: 'external')
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.2549] device (l4tbr0): state change: config -> ip-config (reason 'none', sys-iface-state: 'external')
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.2578] device (l4tbr0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'external')
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.3481] device (l4tbr0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'external')
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.3505] device (l4tbr0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'external')
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.3531] manager: NetworkManager state is now CONNECTED_LOCAL
Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.3583] device (l4tbr0): Activation: successful, device activated.
Nov 27 14:10:41 nvidia NetworkManager[511]: <info>  [1701065441.4841] agent-manager: agent[142a2ac372b9d296,:1.33/org.gnome.Shell.NetworkAgent/1000]: agent registered

sorry, I don’t have a devkit board right now, but I’ll try it when I get one.

And in the boot plot, there is no network-manager in it and using systemctl list-units | grep network can not see it as well. But it is just running when system boot up. That’s so confused.

2.811s nv-l4t-usb-device-mode.service
2.387s apt-daily-upgrade.service
2.145s dev-mmcblk1p1.device
1.935s dev-mmcblk0p1.device
1.775s apt-daily.service
1.295s systemd-udev-trigger.service
1.055s nv-l4t-bootloader-config.service
1.032s nv.service
 990ms udisks2.service
 924ms networkd-dispatcher.service
 869ms user@1000.service
 541ms nvphs.service
 515ms systemd-journald.service
 456ms systemd-resolved.service
 421ms nvpower.service
 384ms nvpmodel.service
 357ms keyboard-setup.service
 335ms systemd-modules-load.service
 334ms NetworkManager.service
 297ms binfmt-support.service
 297ms systemd-udevd.service
 284ms systemd-tmpfiles-setup.service
 280ms upower.service
 270ms nv-l4t-usb-device-mode-runtime.service
 266ms accounts-daemon.service
 266ms ssh.service
 261ms avahi-daemon.service
 246ms kerneloops.service
 231ms ModemManager.service
 213ms systemd-remount-fs.service
 206ms polkit.service
 204ms resolvconf-pull-resolved.service
 200ms systemd-logind.service
 185ms nfs-config.service
 178ms e2scrub_reap.service
 174ms console-setup.service
 171ms colord.service
 169ms systemd-tmpfiles-clean.service
 163ms sys-kernel-debug.mount
 161ms rsyslog.service
 160ms kmod-static-nodes.service
 159ms sys-kernel-tracing.mount
 157ms switcheroo-control.service
 151ms dev-hugepages.mount
 146ms dev-mqueue.mount
 145ms run-rpc_pipefs.mount
 135ms proc-sys-fs-binfmt_misc.mount
 129ms ntp.service
 129ms nvfb-early.service
 128ms nv_nvsciipc_init.service
 122ms systemd-sysusers.service
 117ms ubiquity.service
 103ms wpa_supplicant.service
  96ms systemd-sysctl.service
  96ms systemd-tmpfiles-setup-dev.service
  87ms gdm.service
nvidia@nvidia:~/Program$ systemctl list-units | grep network
  networkd-dispatcher.service                                                                loaded active running   Dispatcher daemon for systemd-networkd                                         
  network-online.target                                                                      loaded active active    Network is Online                                                              
  network-pre.target                                                                         loaded active active    Network (Pre)                                                                  
  network.target                                                                             loaded active active    Network 

Your NetworkManager service is here.

Could you share the full syslog as file here for further check?

Please also check if you would hit the issue with the latest R35.4.1.

kern.log (74.3 KB)
Here is the kernel log after booting up.

I’ll try it, thank you for help!

I found that when host pc identify the usb-to-ether port, it didm’t have the ipv4 address. And after seconds, it have the ipv4 address and subnet mask, until then I can ping the board and ssh it.
maybe there is some problem in usb USB virtual network initialization

what I want to check is /var/log/syslog rather than dmesg.

Do you mean the issue might come from your host PC?
Could you share the block diagram of your connection?
Is something like the following?
Host PC → USB port → USB to ETH adapter → Ethernet cable → Xavier NX

here are the log files, it seems syslog don’t have any information.

screenshot-20231128-161349

Sorry for unclear explaination, I just use micro-usb in jetson and usb in host PC to connect them. What I want to say is maybe the jetson usb virtual network got problem, so my host PC can not get the correct ip address 192.168.55.100 in ipconfig(Windows) as soon as possible.
Host PC → USB port → USB cable → Micro USB port → Xavier NX

Okay, then i would suggest you could verify with another Ubuntu host PC since I could not hit the issue with Xavier NX+Ubuntu host at my local setup.

It’s weird that there’s nothing in your syslog.

Nov 27 14:10:28 nvidia NetworkManager[511]: <info>  [1701065428.3583] device (l4tbr0): Activation: successful, device activated.

How do you get this log?

Thanks, I’ll try

using command systemctl status network-manager

1 Like

Hi, Kevin. I reproduced the same behavior on the devkit board, using L4T R35.3.1. It seems like the same situation. And I get the syslog.
Here is the network-manager status shows the l4tbr0 is actived slower about 10s than the system boot.

nvidia@nvidia:~$ systemctl status network-manager.service
● NetworkManager.service - Network Manager
     Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2022-09-08 09:58:18 UTC; 23min ago
       Docs: man:NetworkManager(8)
   Main PID: 378 (NetworkManager)
      Tasks: 3 (limit: 8136)
     Memory: 14.3M
     CGroup: /system.slice/NetworkManager.service
             └─378 /usr/sbin/NetworkManager --no-daemon

Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5242] device (l4tbr0): state change: unavailable -> disconnected (reason 'connection-assumed', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5324] device (l4tbr0): Activation: starting connection 'l4tbr0' (01904a59-c35b-4c61-887f-4522a5a09653)
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5384] device (l4tbr0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5453] device (l4tbr0): state change: prepare -> config (reason 'none', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5528] device (l4tbr0): state change: config -> ip-config (reason 'none', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5541] device (l4tbr0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5719] device (l4tbr0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5730] device (l4tbr0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'external')
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5747] manager: NetworkManager state is now CONNECTED_LOCAL
Sep 08 09:58:29 nvidia NetworkManager[378]: <info>  [1662631109.5780] device (l4tbr0): Activation: successful, device activated.

syslog.log (1.3 MB)

Are you using the same host PC to verify with the devkit?

Are you using standalone Ubuntu as your host PC? Or virtual machine?

I use the same host Windows PC using Mobaxterm to verify the devkit, not virtual machine.
And there is another question, when I check the system server on devkit. it takes more time on nv-l4t-bootloader-config.service and nvphs.service compared to my custom board. Did these two service is connected to hardware design?

8.336s nv-l4t-bootloader-config.service
7.622s nvphs.service
3.470s systemd-modules-load.service
2.489s nv-l4t-usb-device-mode.service
2.262s dev-mmcblk0p1.device
1.019s systemd-udev-trigger.service
 880ms networkd-dispatcher.service
 873ms nv.service
 675ms nvpmodel.service
 631ms systemd-udevd.service
 584ms udisks2.service
 491ms user@124.service
 485ms systemd-journald.service
 472ms user@1000.service
 433ms accounts-daemon.service
 411ms resolvconf-pull-resolved.service
 406ms systemd-resolved.service
 394ms nvpower.service
 386ms apport.service
 347ms keyboard-setup.service
 293ms kerneloops.service
 286ms ssh.service
 284ms avahi-daemon.service
 276ms NetworkManager.service
 254ms upower.service
 239ms systemd-logind.service
 236ms ModemManager.service
 229ms systemd-timesyncd.service
 223ms nv-l4t-usb-device-mode-runtime.service
 193ms polkit.service
 183ms colord.service
 171ms packagekit.service
 168ms rsyslog.service
 166ms gdm.service
 165ms switcheroo-control.service
 163ms systemd-tmpfiles-setup.service
 157ms dev-mqueue.mount
 156ms modprobe@chromeos_pstore.service
 156ms sys-kernel-tracing.mount
 155ms run-rpc_pipefs.mount
 155ms sys-kernel-debug.mount
 155ms dev-hugepages.mount
 155ms kmod-static-nodes.service
 153ms nvfb-udev.service
 150ms modprobe@ramoops.service
 149ms e2scrub_reap.service
 149ms modprobe@pstore_blk.service
 148ms nvfb-early.service
 147ms modprobe@pstore_zone.service
 147ms nv_nvsciipc_init.service
 146ms modprobe@efi_pstore.service
 138ms binfmt-support.service
 128ms wpa_supplicant.service
 122ms systemd-tmpfiles-setup-dev.service
 116ms systemd-remount-fs.service
 113ms systemd-sysusers.service
.....