DUV3 service (nv_duv3.service) is failing and delaying boot

david8mzkq · October 19, 2021, 11:11am

Please provide the following info (check/uncheck the boxes after creating this topic):
Software Version
DRIVE OS Linux 5.2.6
DRIVE OS Linux 5.2.0
DRIVE OS Linux 5.2.0 and DriveWorks 3.5
NVIDIA DRIVE™ Software 10.0 (Linux)
NVIDIA DRIVE™ Software 9.0 (Linux)
other DRIVE OS version
other

Target Operating System
Linux
QNX
other

Hardware Platform
NVIDIA DRIVE™ AGX Xavier DevKit (E3550)
NVIDIA DRIVE™ AGX Pegasus DevKit (E3550)
other

SDK Manager Version
1.6.1.8175
1.6.0.8170
other

Host Machine Version
native Ubuntu 18.04
other

I am seeing these logs when I run journalctl -b:

Oct 19 09:48:41 ******* systemd[1311]: Reached target Sockets.
Oct 19 09:48:41 ******* systemd[1311]: Reached target Paths.
Oct 19 09:48:41 ******* systemd[1311]: Reached target Basic System.
Oct 19 09:48:41 ******* systemd[1311]: Reached target Default.
Oct 19 09:48:41 ******* systemd[1311]: Startup finished in 191ms.
Oct 19 09:48:41 ******* systemd[1]: Started User Manager for UID 1000.
Oct 19 09:48:41 ******* DUV3[851]: [ERR][dutr_tcp.c:1090]5 can’t connect 127.0.0.1:5001 111(Connection refused)
Oct 19 09:48:41 ******* DUV3[851]: [WARN]Fail 0x100000b at createClientSocket
Oct 19 09:48:41 ******* DUV3[851]: [INFO]Connection to /master/plugins not ready
Oct 19 09:48:41 ******* DUV3[851]: [WARN]Could not register to master, retry in 8 seconds
Oct 19 09:48:42 ******* systemd-networkd[760]: enp3s0: Gained carrier
Oct 19 09:48:42 ******* kernel: atlantic 0000:03:00.0 enp3s0: atlantic: link change old 0 new 10000
Oct 19 09:48:42 ******* kernel: IPv6: ADDRCONF(NETDEV_CHANGE): enp3s0: link becomes ready
Oct 19 09:48:42 ******* DUV3[851]: [ERR][dutr_tcp.c:1090]5 can’t connect 127.0.0.1:5001 111(Connection refused)
Oct 19 09:48:42 ******* DUV3[851]: [WARN]Fail 0x100000b at createClientSocket
Oct 19 09:48:43 ******* DUV3[851]: [ERR][dutr_tcp.c:1090]5 can’t connect 127.0.0.1:5001 111(Connection refused)
Oct 19 09:48:43 ******* DUV3[851]: [WARN]Fail 0x100000b at createClientSocket
Oct 19 09:48:44 ******* systemd-networkd[760]: enp3s0: Gained IPv6LL
Oct 19 09:48:44 ******* systemd-networkd[760]: enp3s0: Configured
Oct 19 09:48:44 ******* DUV3[851]: [ERR][dutr_tcp.c:1090]5 can’t connect 127.0.0.1:5001 111(Connection refused)
Oct 19 09:48:44 ******* DUV3[851]: [WARN]Fail 0x100000b at createClientSocket
Oct 19 09:48:45 ******* DUV3[851]: [ERR][dutr_tcp.c:1090]5 can’t connect 127.0.0.1:5001 111(Connection refused)
Oct 19 09:48:45 ******* DUV3[851]: [WARN]Fail 0x100000b at createClientSocket
[…]
Oct 19 09:48:49 ******* DUV3[851]: [INFO]Connection to /master/plugins not ready
Oct 19 09:48:49 ******* DUV3[851]: [WARN]Could not register to master, retry in 16 seconds
[…]
Oct 19 09:52:48 ******* DUV3[851]: [ERR][dutr_tcp.c:1090]5 can’t connect 127.0.0.1:5001 111(Connection refused)
Oct 19 09:52:48 ******* DUV3[851]: [WARN]Fail 0x100000b at createClientSocket
Oct 19 09:52:49 ******* DUV3[851]: [ERR][content_server.c:309]Failed to register to DU Master
Oct 19 09:52:49 ******* DUV3[851]: [ERR][content_server.c:341]Installer initialization failed

SivaRamaKrishnaNV · October 19, 2021, 12:22pm

Dear @david8mzkq,
Do you see the issue after reflashing DRIVE OS 5.2.0? If so, Could you check the issue on latest release(DRIVE OS 5.2.6)?

david8mzkq · October 19, 2021, 12:32pm

Unfortunately, we cannot upgrade at the moment due to incompatible camera drivers on DriveOS 5.2.6.

What does this service do and is it required? What happens if we disable it?

david8mzkq · October 19, 2021, 12:34pm

Do you see the issue after reflashing DRIVE OS 5.2.0?

Yes.

VickNV · October 19, 2021, 2:33pm

Hi, @david8mzkq

Are those messages from default DRIVE OS 5.2.0?
How do you measure the boot time? What’s the current boot time on your side? Thanks.

SivaRamaKrishnaNV · October 20, 2021, 4:42am

Dear @david8mzkq,
DRIVE Update V3 is used to perform DRIVE AGX Xavier storage updates from the Guest virtual machine. I would expect this to not effect your code development using cameras. You may disable and check.

david8mzkq · October 20, 2021, 1:02pm

How do you measure the boot time?

We get this information from systemd, e.g. ‘systemd-analyze blame’

What’s the current boot time on your side? Thanks.

So the time spent in this particular step is 4 minutes as you can see from the timestamps in ‘journalctl -b’ which I have posted in the original request.

david8mzkq · October 20, 2021, 1:03pm

Are those messages from default DRIVE OS 5.2.0?

Yes.

david8mzkq · October 20, 2021, 1:05pm

DRIVE Update V3 is used to perform DRIVE AGX Xavier storage updates from the Guest virtual machine. I would expect this to not effect your code development using cameras. You may disable and check.

We tried that and it did not seem to cause any issues.

VickNV · October 20, 2021, 1:44pm

I didn’t see the 4 minutes issue on my side.
The below are my DUV3 messages for your information.
However, if no issue without starting the service, that should be okay for you. Thanks for your feedback.

-- Logs begin at Wed 2020-09-02 08:51:07 UTC. --
Oct 19 15:00:56 tegra-ubuntu systemd[1]: Starting startup for DUV3...
Oct 19 15:00:56 tegra-ubuntu systemd[1]: Started startup for DUV3.
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]10 connections detected
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Initializing DU Link Router at path /gos-a
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Client will connect to server
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:0
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Client will connect to server
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:0
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Client will connect to server
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:0
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening UPSTREAM connection to /
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/gos-b
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]CONMGR-IVC: handle Id 0x110000 P2P connection established
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 10.42.0.28:4142
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 10.42.0.28:4142
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/dushell
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:6475
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:6475
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/ddu
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 0.0.0.0:4455
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 0.0.0.0:4455
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/plugin
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:5000
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:5000
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/content
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:5001
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:5001
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/decrypt
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:5002
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:5002
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/fw_aquantia
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:5003
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:5003
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/bhc
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:5008
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:5008
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Opening DOWNSTREAM connection to /gos-a/du-client
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a server 127.0.0.1:5009
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Create a socket 127.0.0.1:5009
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]DU Link Router running...
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Remote node / is connected
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Connection to /master/plugins not ready
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [WARN]Could not register to master, retry in 1 seconds
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Connection to /master/plugins not ready
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [WARN]Could not register to master, retry in 1 seconds
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [INFO]Connection to /master/plugins not ready
Oct 19 15:00:56 tegra-ubuntu DUV3[919]: [WARN]Could not register to master, retry in 1 seconds
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Can't receive magic word from 10.42.0.29:51466, check DUTR version
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Ret 0x100000b on initializeServerSocket
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Connection to /master/plugins not ready
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Could not register to master, retry in 2 seconds
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Connection to /master/plugins not ready
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Could not register to master, retry in 2 seconds
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Connection to /master/plugins not ready
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Could not register to master, retry in 2 seconds
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Can't receive magic word from 127.0.0.1:46352, check DUTR version
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Ret 0x100000b on initializeServerSocket
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Peer is closed. Try to connect with magic word.
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Can't receive magic word from 127.0.0.1:34128, check DUTR version
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Ret 0x100000b on initializeServerSocket
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Peer is closed. Try to connect with magic word.
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Can't receive magic word from 127.0.0.1:44890, check DUTR version
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Ret 0x100000b on initializeServerSocket
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]1, FD: 18, 10.42.0.28:4142 <-> 10.42.0.29:51468 is connected.
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Peer is closed. Try to connect with magic word.
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697db98, client request a connection
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Peer is closed. Can't peek DUTR header.
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697db98, client request a connection
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Handle 0x7f8697db98 dutrWaitForConnectionTcp timeout
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [ERR][dutransport.c:182]Handle Id 0x110001: Error 0x1000009 on alloc buffer
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1145]Could not allocate buffer from DU Transport
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1645]Failed to get remote node name 33554439
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Failed to establish remote connection!
Oct 19 15:00:57 tegra-ubuntu DUV3[919]: [WARN]Trying again in 3 seconds
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Socket 0: 127.0.0.1:46358 <-> 127.0.0.1:5001, FD: 5 is connected.
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]5, FD: 18, 127.0.0.1:5001 <-> 127.0.0.1:46358 is connected.
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7fa9728a88, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697dfd8, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7fa9728a88, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697dfd8, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a is connected
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a/content is connected
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]7, FD: 19, 127.0.0.1:5003 <-> 127.0.0.1:34132 is connected.
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Socket 0: 127.0.0.1:34132 <-> 127.0.0.1:5003, FD: 5 is connected.
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697e1f8, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f87f4ba88, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697e1f8, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f87f4ba88, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a/fw_aquantia is connected
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a is connected
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Socket 0: 127.0.0.1:44898 <-> 127.0.0.1:5008, FD: 5 is connected.
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]8, FD: 20, 127.0.0.1:5008 <-> 127.0.0.1:44898 is connected.
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7fad05ba88, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697e308, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7fad05ba88, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697e308, client request a connection
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a/bhc is connected
Oct 19 15:00:58 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a is connected
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [WARN]Can't receive magic word from 10.42.0.29:51472, check DUTR version
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [WARN]Ret 0x100000b on initializeServerSocket
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [INFO]1, FD: 21, 10.42.0.28:4142 <-> 10.42.0.29:51474 is connected.
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [INFO]Handle 0x7f8697db98, client request a connection
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:227]Connection to /gos-a/gos-b/duvm/tii not ready
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:615]Failed to forward RET message
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1899]Failed to handle incoming return message
Oct 19 15:00:59 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1914]Error in process message buffer, freeing
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [INFO]Installer IDLE state
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:227]Connection to /gos-a/gos-b/bhc not ready
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:615]Failed to forward RET message
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1899]Failed to handle incoming return message
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1914]Error in process message buffer, freeing
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:227]Connection to /gos-a/gos-b/fw_aquantia not ready
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:615]Failed to forward RET message
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1899]Failed to handle incoming return message
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [ERR][dulink_remote_ops.c:1914]Error in process message buffer, freeing
Oct 19 15:01:00 tegra-ubuntu DUV3[919]: [INFO]Remote node /gos-a/gos-b is connected

Topic		Replies	Views
DRIVE AGX : Falshing Failed DRIVE AGX Xavier General drive-platform-setup	4	1355	October 12, 2021
Unable to boot Ubuntu DRIVE AGX Xavier General	32	3388	October 12, 2021
DRIVE AGX Xavier not booting up DRIVE AGX Xavier General drive-platform-bootup	26	797	June 18, 2024
Can't discover dGPU DRIVE AGX Xavier General	10	1244	October 12, 2021
We are observing the Drive Orin boot up issue DRIVE AGX Orin General drive-platform-bootup	34	3267	October 5, 2023
Drive PX2 shut down or freezes randomly. General	15	1397	October 12, 2021
Nvidia SDK Mananger flashed my AGX on USB3 but I can't connect DRIVE AGX Xavier General drive-platform-setup	9	914	October 12, 2021
Problem with driver package upgrade from R31.1 to R32.1 Jetson AGX Xavier	5	1284	July 8, 2019
Drive AGX not booting up after flashing Drive Sdk 10.0 DRIVE AGX Xavier General drive-platform-setup	68	2521	October 12, 2021
Upgraded DRIVE Software 9.0 to 10.0 successfully but OS not configured and is broken DRIVE AGX Xavier General	13	1221	October 12, 2021

DUV3 service (nv_duv3.service) is failing and delaying boot

Related topics