I’ve run sudo lsof | grep "mutex" on Xavier-A while our processes were running and figured out that multiple threads and processes are accessing this file(/dev/shm/nvccpmutex). Can anyone please explain what this file is and what is the impact of using it by the nvidia libraries. The name suggests that it is some type of mutex and because it is in shm I guess that it is a shared object between different processes to synchronize accessing to the sensors?
Can it be a performance bottleneck?
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.0.8170
other
Host Machine Version
native Ubuntu 18.04
other
Dear @ebrahim4o8qh,
Yes. The name nvccpmutex seems to be corresponding to NVIDIA Camera Control Protocol(NVCCP).
Which processes are you running? Do you notice any issue? why do you think it cause performance bottleneck?
Thanks for the answer. We have multiple processes(one per camera) that streams video from the cameras. These are not the only processes that has access to the mutex file. There are some other processes that use other sensors. Once in a while we see that camera inter frame latency goes up to 300ms(it can be any number above 60) and this happens to all camera processes at the same time. This suggests that some shared resources is causing this(which can be this mutex since mutex can put the process into the wait queue). We can see that the wait time(scheduler stats) increases for these processes at the same time. These camera processes are running using realtime scheduler(RR).
Dear @ebrahim4o8qh,
There are some other processes that use other sensors
May I know what are the sensor used apart from cameras in your setup.
Could you share reproducible steps to verify on our end? Also, we have released DRIVE OS 5.2.6. Is it possible to test on DRIVE OS 5.2.6?
Hi @SivaRamaKrishnaNV
We removed the other processes that uses other sensors and the issue is still there.
We didn’t upgrade to 5.2.6 but we have some plans to do so
Hi @SivaRamaKrishnaNV
Do you know what these logs mean? I found it in the logs(/var/log/syslog) when the camera stream became frozen for about 5 seconds. This doesn’t happen in all tries:
Sep 8 21:12:20 xavier-a kernel: [ 5828.547032] tegra-xusb 3610000.xhci: Frame ID 580 (reg 4652, index 5) beyond range (584, 1476)
Sep 8 21:12:20 xavier-a kernel: [ 5828.547040] tegra-xusb 3610000.xhci: Ignore frame ID field, use SIA bit instead
After 2 minutes these logs were also visible:
Sep 8 22:14:00 xavier-a kernel: [ 9527.851331] vhost-client 15a80000.nvenc1: host1x_vm_init: host1x_vm_init active waiting for 5001 ms
Sep 8 22:14:00 xavier-a kernel: [ 9527.851331]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858196] ---- mlocks ----
Sep 8 22:14:00 xavier-a kernel: [ 9527.858203]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858209] ---- syncpts ----
Sep 8 22:14:00 xavier-a kernel: [ 9527.858243] id 17 (camera_node) min 631242 max 631242 refs 2 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858251] id 18 (camera_node) min 631164 max 631164 refs 4 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858259] id 19 (camera_node) min 631119 max 631119 refs 2 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858266] id 20 (camera_node) min 631041 max 631041 refs 2 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858272] id 21 (camera_node) min 631227 max 631227 refs 2 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858278] id 22 (camera_node) min 631149 max 631149 refs 4 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858306] id 23 (camera_node) min 631212 max 631212 refs 2 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858313] id 24 (camera_node) min 631134 max 631134 refs 4 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858321] id 25 (15a80000.nvenc1_queue_raw_strea_0) min 422998 max 422998 refs 1 (previous client : 15a80000.nvenc1_camera_node_0)
Sep 8 22:14:00 xavier-a kernel: [ 9527.858329] id 28 (15a80000.nvenc1_queue_raw_strea_0) min 422926 max 422926 refs 1 (previous client : 15a80000.nvenc1_camera_node_0)
Sep 8 22:14:00 xavier-a kernel: [ 9527.858336] id 29 (154c0000.nvenc_queue_raw_strea_0) min 422988 max 422988 refs 1 (previous client : 154c0000.nvenc_camera_node_0)
Sep 8 22:14:00 xavier-a kernel: [ 9527.858342] id 30 (154c0000.nvenc_queue_raw_strea_0) min 423008 max 423008 refs 1 (previous client : 154c0000.nvenc_camera_node_0)
Sep 8 22:14:00 xavier-a kernel: [ 9527.858348] id 31 (progress) min 630072 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858354] id 32 (embdata) min 210024 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858377] id 33 (progress) min 840068 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858384] id 34 (stats_progress) min 1260102 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858390] id 35 (progress) min 630057 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858396] id 36 (embdata) min 210019 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858402] id 37 (progress) min 840048 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858408] id 38 (stats_progress) min 1260072 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858413] id 39 (progress) min 630042 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858419] id 40 (embdata) min 210014 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858425] id 41 (progress) min 840028 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858431] id 42 (stats_progress) min 1260042 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858437] id 43 (progress) min 629946 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858443] id 44 (embdata) min 209982 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858449] id 45 (progress) min 839904 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858455] id 46 (stats_progress) min 1259856 max 0 refs 1 (previous client : )
Sep 8 22:14:00 xavier-a kernel: [ 9527.858760]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858763] ---- channels ----
Sep 8 22:14:00 xavier-a kernel: [ 9527.858768] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858772] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858776] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858779] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858783] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858787] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858790] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858794] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858798] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858802] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858805] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858809] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858812] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858816] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858819] unable to lock channel list
Sep 8 22:14:00 xavier-a kernel: [ 9527.858823]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858823] ---- host general irq ----
Sep 8 22:14:00 xavier-a kernel: [ 9527.858823]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858829] sync_intc0mask = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858832] sync_intmask = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858836]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858836] ---- host syncpt irq mask ----
Sep 8 22:14:00 xavier-a kernel: [ 9527.858836]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858839]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858839] ---- host syncpt irq status ----
Sep 8 22:14:00 xavier-a kernel: [ 9527.858839]
Sep 8 22:14:00 xavier-a kernel: [ 9527.858845] syncpt_thresh_cpu0_int_status(0) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858850] syncpt_thresh_cpu0_int_status(1) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858854] syncpt_thresh_cpu0_int_status(2) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858859] syncpt_thresh_cpu0_int_status(3) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858863] syncpt_thresh_cpu0_int_status(4) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858867] syncpt_thresh_cpu0_int_status(5) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858872] syncpt_thresh_cpu0_int_status(6) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858876] syncpt_thresh_cpu0_int_status(7) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858881] syncpt_thresh_cpu0_int_status(8) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858886] syncpt_thresh_cpu0_int_status(9) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858891] syncpt_thresh_cpu0_int_status(10) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858895] syncpt_thresh_cpu0_int_status(11) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858900] syncpt_thresh_cpu0_int_status(12) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858905] syncpt_thresh_cpu0_int_status(13) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858909] syncpt_thresh_cpu0_int_status(14) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858914] syncpt_thresh_cpu0_int_status(15) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858918] syncpt_thresh_cpu0_int_status(16) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858923] syncpt_thresh_cpu0_int_status(17) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858928] syncpt_thresh_cpu0_int_status(18) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858933] syncpt_thresh_cpu0_int_status(19) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858937] syncpt_thresh_cpu0_int_status(20) = 0x00000000
Sep 8 22:14:00 xavier-a kernel: [ 9527.858942] syncpt_thresh_cpu0_int_status(21) = 0x00000000
The same run started with these logs:
Sep 8 20:17:14 xavier-a kernel: [ 2522.702472] vhost-client 15340000.vic: Direct firmware load for nvhost_vic042.fw failed with error -2
Sep 8 20:17:14 xavier-a kernel: [ 2522.702482] vhost-client 15340000.vic: Falling back to user helper
Sep 8 20:17:14 xavier-a kernel: [ 2522.705750] vhost-client 15340000.vic: looking for firmware in subdirectory
Sep 8 20:17:14 xavier-a kernel: [ 2522.705788] vhost-client 15340000.vic: Direct firmware load for tegra19x/nvhost_vic042.fw failed with error -2
Sep 8 20:17:14 xavier-a kernel: [ 2522.705794] vhost-client 15340000.vic: Falling back to user helper
Sep 8 20:17:14 xavier-a kernel: [ 2522.709404] vhost-client 15340000.vic: failed to get firmware
Sep 8 20:17:14 xavier-a kernel: [ 2522.713470] vhost-client 15340000.vic: failed to get firmware
Sep 8 20:17:14 xavier-a kernel: [ 2522.717119] vhost-client 15340000.vic: nvhost_flcn_init_sw: failed : 0xfffffffe