Camera capture stops working after some frames

Hello,

Currently I am working with a GMSL2 ser/des pair (MAX9295, MAX9296) with an AR0234 camera on a Jetson Xavier AGX over Jetpack 4.4. I am able to capture using v4l-ctl but only a few frames, usually 4 or a couple more.

Frames that are captured correctly are valid and look good.

Capture test:

  • 1920x1200
  • RAW12

For example using the following command, it hangs after the fourth frame.

nvidia@localhost:~$ v4l2-ctl --device /dev/video0 --stream-mmap
<<<<^C
nvidia@localhost:~$ 

The behavior is constant on 4 frames, but sometimes I can get more if I specify more in mmap but never more than 8, for example:

nvidia@localhost:~$ v4l2-ctl --device /dev/video0 --stream-mmap=10
<<<<<^C
nvidia@localhost:~$ v4l2-ctl --device /dev/video0 --stream-mmap=10
<<<<<<<<^C

Dmesg only gives the following output:

nvidia@localhost:~$ dmesg
[13903.591809] [RCE] Configuring VI GoS.
[13903.591823] [RCE] VM GOS[#0] addr=0xc2100000
[13903.591874] [RCE] VM GOS[#1] addr=0xc2101000
[13903.591881] [RCE] VM GOS[#2] addr=0xc2102000
[13903.591889] [RCE] VM GOS[#3] addr=0xc2103000
[13903.591895] [RCE] VM GOS[#4] addr=0xc2104000
[13903.591901] [RCE] VM GOS[#5] addr=0xc2105000
[13903.591910] [RCE] vi5_hwinit: firmware CL2018101701 protocol version 2.2
[13903.591922] [RCE] VI GOS[#0] set to VM GOS[4] base 0xc2104000
[13903.829855] ar0234 40-0010: Starting Stream AR0234...
[13906.331662] tegra194-vi5 15c10000.vi: no reply from camera processor
[13906.331849] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[13906.331992] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[13906.334300] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[13906.335699] [RCE] Configuring VI GoS.
[13906.335712] [RCE] VM GOS[#0] addr=0xc2100000
[13906.335719] [RCE] VM GOS[#1] addr=0xc2101000
[13906.335725] [RCE] VM GOS[#2] addr=0xc2102000
[13906.335732] [RCE] VM GOS[#3] addr=0xc2103000
[13906.335738] [RCE] VM GOS[#4] addr=0xc2104000
[13906.335744] [RCE] VM GOS[#5] addr=0xc2105000
[13908.891521] tegra194-vi5 15c10000.vi: no reply from camera processor
[13908.891705] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[13908.891846] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[13908.894217] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[13908.911542] [RCE] Configuring VI GoS.
[13908.911556] [RCE] VM GOS[#0] addr=0xc2100000
[13908.911564] [RCE] VM GOS[#1] addr=0xc2101000
[13908.911571] [RCE] VM GOS[#2] addr=0xc2102000
[13908.911612] [RCE] VM GOS[#3] addr=0xc2103000
[13908.911620] [RCE] VM GOS[#4] addr=0xc2104000
[13908.911641] [RCE] VM GOS[#5] addr=0xc2105000
[13911.451389] tegra194-vi5 15c10000.vi: no reply from camera processor
[13911.451579] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[13911.451720] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[13911.454199] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[13911.491412] [RCE] Configuring VI GoS.
[13911.491428] [RCE] VM GOS[#0] addr=0xc2100000
[13911.491470] [RCE] VM GOS[#1] addr=0xc2101000
[13911.491477] [RCE] VM GOS[#2] addr=0xc2102000
[13911.491483] [RCE] VM GOS[#3] addr=0xc2103000
[13911.491490] [RCE] VM GOS[#4] addr=0xc2104000
[13911.491496] [RCE] VM GOS[#5] addr=0xc2105000

I have enabled the debug trace, which gives the following output:

nvidia@localhost:~$ sudo cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 200/200   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
     kworker/0:4-1923  [000] ....   157.406030: rtos_queue_peek_from_isr_failed: tstamp:5234773339 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   157.517898: rtos_queue_peek_from_isr_failed: tstamp:5239773345 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   157.685913: rtos_queue_peek_from_isr_failed: tstamp:5244773341 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   157.853906: rtos_queue_peek_from_isr_failed: tstamp:5249773341 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.021870: rtos_queue_peek_from_isr_failed: tstamp:5254773345 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.189921: rtos_queue_peek_from_isr_failed: tstamp:5259773341 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.357885: rtos_queue_peek_from_isr_failed: tstamp:5264773349 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.525882: rtos_queue_peek_from_isr_failed: tstamp:5269773349 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.637833: rtos_queue_peek_from_isr_failed: tstamp:5274773341 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.805838: rtos_queue_peek_from_isr_failed: tstamp:5279773341 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   158.977837: rtos_queue_peek_from_isr_failed: tstamp:5284773339 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   159.145805: rtos_queue_peek_from_isr_failed: tstamp:5289773341 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   159.313793: rtos_queue_peek_from_isr_failed: tstamp:5294773339 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   159.481802: rtos_queue_peek_from_isr_failed: tstamp:5299773339 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   159.593791: rtos_queue_peek_from_isr_failed: tstamp:5304773344 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   159.761783: rtos_queue_peek_from_isr_failed: tstamp:5309773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   159.929774: rtos_queue_peek_from_isr_failed: tstamp:5314773344 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   160.097769: rtos_queue_peek_from_isr_failed: tstamp:5319773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   160.265754: rtos_queue_peek_from_isr_failed: tstamp:5324773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   160.433788: rtos_queue_peek_from_isr_failed: tstamp:5329773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   160.601728: rtos_queue_peek_from_isr_failed: tstamp:5334773340 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   160.713707: rtos_queue_peek_from_isr_failed: tstamp:5339773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   160.881738: rtos_queue_peek_from_isr_failed: tstamp:5344773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   161.049690: rtos_queue_peek_from_isr_failed: tstamp:5349773353 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   161.217705: rtos_queue_peek_from_isr_failed: tstamp:5354773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   161.385667: rtos_queue_peek_from_isr_failed: tstamp:5359773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   161.553661: rtos_queue_peek_from_isr_failed: tstamp:5364773337 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   161.721711: rtos_queue_peek_from_isr_failed: tstamp:5369773337 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   161.833637: rtos_queue_peek_from_isr_failed: tstamp:5374773342 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   162.001655: rtos_queue_peek_from_isr_failed: tstamp:5379773340 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   162.169634: rtos_queue_peek_from_isr_failed: tstamp:5384773341 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   162.337659: rtos_queue_peek_from_isr_failed: tstamp:5389773350 queue:0x0bcbcf78
     kworker/0:2-1779  [000] ....   162.449629: rtos_queue_peek_from_isr_failed: tstamp:5392415051 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   164.689507: rtos_queue_peek_from_isr_failed: tstamp:5463264149 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   164.689513: rtcpu_start: tstamp:5463267808
     kworker/0:4-1923  [000] ....   164.689515: rtos_queue_send_from_isr_failed: tstamp:5463397628 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   164.689516: rtos_queue_send_from_isr_failed: tstamp:5463397929 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   164.689517: rtos_queue_send_from_isr_failed: tstamp:5463398228 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   164.689518: rtos_queue_send_from_isr_failed: tstamp:5463398525 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   164.689519: rtos_queue_send_from_isr_failed: tstamp:5463398839 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   164.689520: rtcpu_string: tstamp:5463399687 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/0:4-1923  [000] ....   164.689538: rtcpu_string: tstamp:5463400050 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/0:4-1923  [000] ....   164.689559: rtcpu_string: tstamp:5463400472 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/0:4-1923  [000] ....   164.689564: rtcpu_string: tstamp:5463400967 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/0:4-1923  [000] ....   164.689569: rtcpu_string: tstamp:5463401427 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/0:4-1923  [000] ....   164.689573: rtcpu_string: tstamp:5463401833 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/0:4-1923  [000] ....   164.689577: rtcpu_string: tstamp:5463402238 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/0:4-1923  [000] ....   164.689581: rtcpu_string: tstamp:5463413423 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol versi"
     kworker/0:4-1923  [000] ....   164.689583: rtcpu_string: tstamp:5463413690 id:0x04010000 str:"on 2.2
"
     kworker/0:4-1923  [000] ....   164.689588: rtos_queue_send_from_isr_failed: tstamp:5463447615 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   164.689588: rtos_queue_send_from_isr_failed: tstamp:5463447973 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   164.689589: rtos_queue_send_from_isr_failed: tstamp:5463448275 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   164.689590: rtos_queue_send_from_isr_failed: tstamp:5463448568 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   164.689591: rtos_queue_send_from_isr_failed: tstamp:5463448861 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   164.689591: rtcpu_string: tstamp:5463450386 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
"
     kworker/0:4-1923  [000] ....   164.689597: rtcpu_vinotify_event: tstamp:5463797807 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7326734240 data:0x10000000
     kworker/0:4-1923  [000] ....   164.689598: rtcpu_vinotify_event: tstamp:5463798004 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7326741216 data:0x31000001
     kworker/0:4-1923  [000] ....   164.689599: rtcpu_vinotify_event: tstamp:5463798231 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7326742208 data:0x07020001
     kworker/0:4-1923  [000] ....   164.689599: rtcpu_vinotify_event: tstamp:5463798416 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7326814816 data:0x10000000
     kworker/0:4-1923  [000] ....   164.689600: rtcpu_vinotify_event: tstamp:5463798639 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7326821856 data:0x31000002
     kworker/0:4-1923  [000] ....   164.689622: rtos_queue_send_from_isr_failed: tstamp:5463889006 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   164.689623: rtos_queue_send_from_isr_failed: tstamp:5463889167 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   164.689624: rtos_queue_send_from_isr_failed: tstamp:5463889329 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   164.689625: rtos_queue_send_from_isr_failed: tstamp:5463889486 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   164.689626: rtos_queue_send_from_isr_failed: tstamp:5463889643 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   164.801498: rtcpu_vinotify_event: tstamp:5465967714 tag:FS channel:0x00 frame:0 vi_tstamp:5465717454 data:0x00000012
     kworker/0:4-1923  [000] ....   164.801503: rtcpu_vinotify_event: tstamp:5465967898 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5465717457 data:0x00000000
     kworker/0:4-1923  [000] ....   164.801505: rtcpu_vinotify_event: tstamp:5465968049 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:5465718213 data:0x00000001
     kworker/0:4-1923  [000] ....   164.801506: rtcpu_vinotify_event: tstamp:5465968223 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7399262496 data:0x08020001
     kworker/0:4-1923  [000] ....   164.801507: rtcpu_vinotify_event: tstamp:5466590219 tag:FE channel:0x00 frame:0 vi_tstamp:5466579528 data:0x00000022
     kworker/0:4-1923  [000] ....   164.801508: rtcpu_vinotify_event: tstamp:5466590413 tag:CHANSEL_SHORT_FRAME channel:0x04 frame:0 vi_tstamp:5466579528 data:0x01000000
     kworker/0:4-1923  [000] ....   164.801509: rtcpu_vinotify_event: tstamp:5466590562 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7426838016 data:0x01020001
     kworker/0:4-1923  [000] ....   164.801510: rtcpu_vinotify_event: tstamp:5466590741 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5466579530 data:0x00000000
     kworker/0:4-1923  [000] ....   164.801511: rtcpu_vinotify_event: tstamp:5466590889 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7426870880 data:0x07020002
     kworker/0:4-1923  [000] ....   164.801512: rtcpu_vinotify_event: tstamp:5466591060 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7427057344 data:0x10000000
     kworker/0:4-1923  [000] ....   164.801513: rtcpu_vinotify_event: tstamp:5466591224 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7427087040 data:0x31000003
     kworker/0:4-1923  [000] ....   164.801516: rtos_queue_send_from_isr_failed: tstamp:5466595745 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   164.801518: rtos_queue_send_from_isr_failed: tstamp:5466595909 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   164.801519: rtos_queue_send_from_isr_failed: tstamp:5466596072 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   164.801520: rtos_queue_send_from_isr_failed: tstamp:5466596228 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   164.801522: rtos_queue_send_from_isr_failed: tstamp:5466596383 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   164.801527: rtcpu_vinotify_event: tstamp:5467107528 tag:FS channel:0x00 frame:0 vi_tstamp:5466595481 data:0x00000012
     kworker/0:4-1923  [000] ....   164.801528: rtcpu_vinotify_event: tstamp:5467107685 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5466595485 data:0x00000000
     kworker/0:4-1923  [000] ....   164.801529: rtcpu_vinotify_event: tstamp:5467107860 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:5466597640 data:0x00000001
     kworker/0:4-1923  [000] ....   164.801530: rtcpu_vinotify_event: tstamp:5467108007 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7427404160 data:0x08020002
     kworker/0:4-1923  [000] ....   164.801532: rtcpu_vinotify_event: tstamp:5467531235 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:5467503604 data:0x04af0002
     kworker/0:4-1923  [000] ....   164.801533: rtcpu_vinotify_event: tstamp:5467531388 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:5467503634 data:0x00000000
     kworker/0:4-1923  [000] ....   164.801535: rtcpu_vinotify_event: tstamp:5467531562 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7456398720 data:0x02020002
     kworker/0:4-1923  [000] ....   164.801536: rtcpu_vinotify_event: tstamp:5467531710 tag:FE channel:0x00 frame:0 vi_tstamp:5467505042 data:0x00000022
     kworker/0:4-1923  [000] ....   164.801537: rtcpu_vinotify_event: tstamp:5467531881 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5467505045 data:0x00000000
     kworker/0:4-1923  [000] ....   164.801538: rtcpu_vinotify_event: tstamp:5467532025 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7456451488 data:0x00020002
     kworker/0:4-1923  [000] ....   164.801539: rtcpu_vinotify_event: tstamp:5467532196 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7456472384 data:0x07020003
     kworker/0:4-1923  [000] ....   164.801540: rtcpu_vinotify_event: tstamp:5467532341 tag:FS channel:0x00 frame:0 vi_tstamp:5467520997 data:0x00000012
     kworker/0:4-1923  [000] ....   164.801541: rtcpu_vinotify_event: tstamp:5467532510 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5467520999 data:0x00000000
     kworker/0:4-1923  [000] ....   164.801542: rtcpu_vinotify_event: tstamp:5467532654 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:5467523154 data:0x00000001
     kworker/0:4-1923  [000] ....   164.801543: rtcpu_vinotify_event: tstamp:5467532824 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7457020672 data:0x08020003
     kworker/0:4-1923  [000] ....   164.801545: rtcpu_vinotify_event: tstamp:5467532969 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7457199264 data:0x10000000
     kworker/0:4-1923  [000] ....   164.857481: rtcpu_vinotify_event: tstamp:5468029323 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7457318016 data:0x31000004
     kworker/0:4-1923  [000] ....   164.857487: rtos_queue_peek_from_isr_failed: tstamp:5468264522 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   164.857514: rtcpu_vinotify_event: tstamp:5468572047 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:5468429118 data:0x04af0002
     kworker/0:4-1923  [000] ....   164.857517: rtcpu_vinotify_event: tstamp:5468572223 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:5468429148 data:0x00000000
     kworker/0:4-1923  [000] ....   164.857518: rtcpu_vinotify_event: tstamp:5468572374 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7486015136 data:0x02020003
     kworker/0:4-1923  [000] ....   164.857519: rtcpu_vinotify_event: tstamp:5468572544 tag:FE channel:0x00 frame:0 vi_tstamp:5468430557 data:0x00000022
     kworker/0:4-1923  [000] ....   164.857520: rtcpu_vinotify_event: tstamp:5468572697 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5468430560 data:0x00000000
     kworker/0:4-1923  [000] ....   164.857521: rtcpu_vinotify_event: tstamp:5468572867 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7486067968 data:0x00020003
     kworker/0:4-1923  [000] ....   164.857522: rtcpu_vinotify_event: tstamp:5468573013 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7486088896 data:0x07020004
     kworker/0:4-1923  [000] ....   164.857523: rtcpu_vinotify_event: tstamp:5468573186 tag:FS channel:0x00 frame:0 vi_tstamp:5468446511 data:0x00000012
     kworker/0:4-1923  [000] ....   164.857525: rtcpu_vinotify_event: tstamp:5468573336 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5468446514 data:0x00000000
     kworker/0:4-1923  [000] ....   164.857526: rtcpu_vinotify_event: tstamp:5468573506 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:5468448669 data:0x00000001
     kworker/0:4-1923  [000] ....   164.857527: rtcpu_vinotify_event: tstamp:5468573655 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7486637120 data:0x08020004
     kworker/0:4-1923  [000] ....   164.857528: rtcpu_vinotify_event: tstamp:5468573824 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7486824768 data:0x10000000
     kworker/0:4-1923  [000] ....   164.857529: rtcpu_vinotify_event: tstamp:5468573970 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7486854528 data:0x31000005
     kworker/0:4-1923  [000] ....   164.913482: rtcpu_vinotify_event: tstamp:5469360614 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:5469354633 data:0x04af0002
     kworker/0:4-1923  [000] ....   164.913485: rtcpu_vinotify_event: tstamp:5469360771 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:5469354664 data:0x00000000
     kworker/0:4-1923  [000] ....   164.913490: rtcpu_vinotify_event: tstamp:5469873974 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7515637504 data:0x02020004
     kworker/0:4-1923  [000] ....   164.913491: rtcpu_vinotify_event: tstamp:5469874124 tag:FE channel:0x00 frame:0 vi_tstamp:5469356071 data:0x00000022
     kworker/0:4-1923  [000] ....   164.913493: rtcpu_vinotify_event: tstamp:5469874302 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5469356074 data:0x00000000
     kworker/0:4-1923  [000] ....   164.913494: rtcpu_vinotify_event: tstamp:5469874449 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7515698624 data:0x00020004
     kworker/0:4-1923  [000] ....   164.913519: rtcpu_vinotify_event: tstamp:5469874621 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7515720960 data:0x07020005
     kworker/0:4-1923  [000] ....   164.913520: rtcpu_vinotify_event: tstamp:5469874766 tag:FS channel:0x00 frame:0 vi_tstamp:5469372026 data:0x00000012
     kworker/0:4-1923  [000] ....   164.913521: rtcpu_vinotify_event: tstamp:5469874940 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:5469372028 data:0x00000000
     kworker/0:4-1923  [000] ....   164.913522: rtcpu_vinotify_event: tstamp:5469875085 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:5469374184 data:0x00000001
     kworker/0:4-1923  [000] ....   164.913523: rtcpu_vinotify_event: tstamp:5469875255 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7516253568 data:0x08020005
     kworker/0:4-1923  [000] ....   164.913525: rtcpu_vinotify_event: tstamp:5470299989 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:5470280148 data:0x04af0002
     kworker/0:4-1923  [000] ....   164.913526: rtcpu_vinotify_event: tstamp:5470301654 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:5470280179 data:0x00000000
     kworker/0:4-1923  [000] ....   164.913527: rtcpu_vinotify_event: tstamp:5470301806 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7545248096 data:0x02020005
     kworker/0:4-1923  [000] ....   164.913529: rtcpu_vinotify_event: tstamp:5470301978 tag:FE channel:0x00 frame:0 vi_tstamp:5470281587 data:0x00000022
     kworker/0:4-1923  [000] ....   164.913530: rtcpu_vinotify_event: tstamp:5470302129 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:5470281589 data:0x00000000
     kworker/0:4-1923  [000] ....   164.913531: rtcpu_vinotify_event: tstamp:5470302297 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7545300960 data:0x00020005
     kworker/0:4-1923  [000] ....   164.913532: rtcpu_vinotify_event: tstamp:5470302444 tag:FS channel:0x00 frame:0 vi_tstamp:5470297540 data:0x00000012
     kworker/0:4-1923  [000] ....   164.913534: rtcpu_vinotify_error: tstamp:5470303527 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5470299699 data:0x00000569
     kworker/0:4-1923  [000] ....   164.913535: rtcpu_vinotify_event: tstamp:5470797021 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5470299699 data:0x00000569
     kworker/0:4-1923  [000] ....   164.969485: rtcpu_vinotify_error: tstamp:5471228042 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5471225214 data:0x00000569
     kworker/0:4-1923  [000] ....   164.969489: rtcpu_vinotify_event: tstamp:5471339132 tag:FE channel:0x00 frame:0 vi_tstamp:5471207101 data:0x00000022
     kworker/0:4-1923  [000] ....   164.969490: rtcpu_vinotify_event: tstamp:5471339303 tag:FS channel:0x00 frame:0 vi_tstamp:5471223056 data:0x00000012
     kworker/0:4-1923  [000] ....   164.969492: rtcpu_vinotify_event: tstamp:5471339451 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5471225214 data:0x00000569
     kworker/0:4-1923  [000] ....   164.969493: rtcpu_vinotify_error: tstamp:5472153550 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5472150729 data:0x00000569
     kworker/0:4-1923  [000] ....   164.969494: rtcpu_vinotify_event: tstamp:5472424613 tag:FE channel:0x00 frame:0 vi_tstamp:5472132616 data:0x00000022
     kworker/0:4-1923  [000] ....   164.969495: rtcpu_vinotify_event: tstamp:5472424761 tag:FS channel:0x00 frame:0 vi_tstamp:5472148571 data:0x00000012
     kworker/0:4-1923  [000] ....   164.969496: rtcpu_vinotify_event: tstamp:5472424932 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5472150729 data:0x00000569
     kworker/0:4-1923  [000] ....   164.969499: rtos_queue_send_from_isr_failed: tstamp:5472458996 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   164.969500: rtos_queue_send_from_isr_failed: tstamp:5472459161 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   164.969501: rtos_queue_send_from_isr_failed: tstamp:5472459328 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   164.969503: rtos_queue_send_from_isr_failed: tstamp:5472459489 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   164.969504: rtos_queue_send_from_isr_failed: tstamp:5472459647 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   164.969505: rtos_queue_send_from_isr_failed: tstamp:5472464911 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   164.969537: rtos_queue_send_from_isr_failed: tstamp:5472465071 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   164.969539: rtos_queue_send_from_isr_failed: tstamp:5472465233 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   164.969540: rtos_queue_send_from_isr_failed: tstamp:5472465389 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   164.969541: rtos_queue_send_from_isr_failed: tstamp:5472465546 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   165.025469: rtcpu_vinotify_event: tstamp:5472967017 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7615091456 data:0x10000000
     kworker/0:4-1923  [000] ....   165.025471: rtcpu_vinotify_event: tstamp:5472967222 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7615120832 data:0x31000006
     kworker/0:4-1923  [000] ....   165.025472: rtcpu_vinotify_event: tstamp:5472967375 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7615129408 data:0x07020006
     kworker/0:4-1923  [000] ....   165.025473: rtcpu_vinotify_event: tstamp:5472967548 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7615294912 data:0x10000000
     kworker/0:4-1923  [000] ....   165.025475: rtcpu_vinotify_event: tstamp:5472967697 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7615324608 data:0x31000007
     kworker/0:4-1923  [000] ....   165.025477: rtos_queue_peek_from_isr_failed: tstamp:5473264529 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   165.193448: rtos_queue_peek_from_isr_failed: tstamp:5478264521 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   165.305451: rtos_queue_peek_from_isr_failed: tstamp:5483264519 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   165.473449: rtos_queue_peek_from_isr_failed: tstamp:5488264521 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   165.641448: rtos_queue_peek_from_isr_failed: tstamp:5493264519 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   165.809447: rtos_queue_peek_from_isr_failed: tstamp:5498264517 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   165.977424: rtos_queue_peek_from_isr_failed: tstamp:5503264520 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   166.145414: rtos_queue_peek_from_isr_failed: tstamp:5508264521 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   166.313417: rtos_queue_peek_from_isr_failed: tstamp:5513264520 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   166.425404: rtos_queue_peek_from_isr_failed: tstamp:5518264521 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   166.593404: rtos_queue_peek_from_isr_failed: tstamp:5523264519 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   166.761364: rtos_queue_peek_from_isr_failed: tstamp:5528264520 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   166.929408: rtos_queue_peek_from_isr_failed: tstamp:5533264520 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   167.097361: rtos_queue_peek_from_isr_failed: tstamp:5538264521 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   167.265358: rtos_queue_peek_from_isr_failed: tstamp:5543264519 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   167.433332: rtos_queue_peek_from_isr_failed: tstamp:5548264520 queue:0x0bcbcf78
     kworker/0:4-1923  [000] ....   167.545338: rtos_queue_send_from_isr_failed: tstamp:5552421583 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   167.545342: rtos_queue_send_from_isr_failed: tstamp:5552421750 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   167.545343: rtos_queue_send_from_isr_failed: tstamp:5552421912 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   167.545345: rtos_queue_send_from_isr_failed: tstamp:5552422069 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   167.545346: rtos_queue_send_from_isr_failed: tstamp:5552422225 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   167.545347: rtos_queue_send_from_isr_failed: tstamp:5552484595 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   167.545349: rtos_queue_send_from_isr_failed: tstamp:5552484757 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   167.545350: rtos_queue_send_from_isr_failed: tstamp:5552484918 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   167.545351: rtos_queue_send_from_isr_failed: tstamp:5552485075 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   167.545352: rtos_queue_send_from_isr_failed: tstamp:5552485232 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   167.545355: rtcpu_string: tstamp:5552492514 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/0:4-1923  [000] ....   167.545374: rtcpu_string: tstamp:5552492706 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/0:4-1923  [000] ....   167.545382: rtcpu_string: tstamp:5552492972 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/0:4-1923  [000] ....   167.545388: rtcpu_string: tstamp:5552493254 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/0:4-1923  [000] ....   167.545395: rtcpu_string: tstamp:5552493496 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/0:4-1923  [000] ....   167.545402: rtcpu_string: tstamp:5552493739 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/0:4-1923  [000] ....   167.545409: rtcpu_string: tstamp:5552493982 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/0:4-1923  [000] ....   167.545415: rtos_queue_send_from_isr_failed: tstamp:5552513516 queue:0x0bcb41f8
     kworker/0:4-1923  [000] ....   167.545416: rtos_queue_send_from_isr_failed: tstamp:5552513678 queue:0x0bcb8a60
     kworker/0:4-1923  [000] ....   167.545418: rtos_queue_send_from_isr_failed: tstamp:5552513840 queue:0x0bcba5e0
     kworker/0:4-1923  [000] ....   167.545419: rtos_queue_send_from_isr_failed: tstamp:5552513997 queue:0x0bcbb3a0
     kworker/0:4-1923  [000] ....   167.545420: rtos_queue_send_from_isr_failed: tstamp:5552514154 queue:0x0bcbc160
     kworker/0:4-1923  [000] ....   167.545453: rtcpu_vinotify_event: tstamp:5552522159 tag:FE channel:0x00 frame:0 vi_tstamp:5552515556 data:0x00000022
     kworker/0:4-1923  [000] ....   167.545455: rtcpu_vinotify_event: tstamp:5552522318 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:5881893888 data:0x10000000
     kworker/0:4-1923  [000] ....   167.545456: rtcpu_vinotify_event: tstamp:5552522515 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:5881930976 data:0x31000001
     kworker/0:4-1923  [000] ....   167.545457: rtcpu_vinotify_event: tstamp:5552522663 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:5881941152 data:0x10000000
     kworker/0:4-1923  [000] ....   167.545458: rtcpu_vinotify_event: tstamp:5553045365 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:5882015552 data:0x07020001
     kworker/0:4-1923  [000] ....   167.545459: rtcpu_vinotify_event: tstamp:5553045535 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:5882069088 data:0x31000002
     kworker/0:4-1923  [000] ....   167.545461: rtos_queue_peek_from_isr_failed: tstamp:5553264522 queue:0x0bcbcf78

As seen the trace logs valid steps when getting the frames, but after that it starts throwing CHANSEL_NOMATCH errors.

kworker/0:4-1923  [000] ....   164.969496: rtcpu_vinotify_event: tstamp:5472424932 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:5472150729 data:0x00000569

The data is 0x569, which indicates:

CHANSEL_NOMATCH
bit 0        no_match
bit 1-4      CTYPE
bit 5-10     DTYPE

CTYPE:
    LS = 0x4
DTYPE:
    NvCsiDataType_RAW10 = 43,

So far I have tried the following:

1. Change ‘‘serdes_pix_clk_hz’’ property on device tree to higher values. → Result: No change
2. Capture in other formats (RAW10, RAW12) → Result: Same result on debug trace.
3. Increase ‘‘cil_settletime’’ property on device tree as suggested in this post. → Result: Small values no capture due PHY0 PHY1 error. Higher values same result on debug trace.
4. Increase ‘‘line_length’’ property on device tree. → Result: Same result on debug trace.

We know the camera is configured correctly because the frames that are captured look good. If the capture command is restarted it again captures some frames, and so on.

Questions:

1. What other debug/tool can I use to get more information?
2. Captures starts correctly and after a couple frames throws error what can cause this?
3. Is it possible to disable CHANSEL_NOMATCH verification to force to capture frames?, because all indicates they are correct

Any other suggestion is greatly appreciated.

Thanks,

Fabian

Did you try discontinuous or continuous clock?
Will check if can mask the CHANSEL_NOMATCH later.

Hi @ShaneCCC,

Yes, I did try changing between continuous and discontinuous clock. Currently I am seeing the behavior described using continuous clock in camera, ser/des and device tree settings, otherwise I do not receive frames at all.

Thanks

You can try to set VI_CH*_NOTIFY_MASK_XCPT_0.NOMATCH to 1 to mask the CHANSEL_NOMATCH.

Hi @ShaneCCC,

According to the TRM, bit 9 refers to the NO MATCH

I used the devmem2 tool to read from the register, but bit 9 is already at 1.

nvidia@localhost:~$ sudo devmem2 0x15C1441A h 
/dev/mem opened.
Memory mapped at address 0x7faa4f8000.
Value at address 0x15C1441A (0x7faa4f841a): 0xBADF

image

I also tried to change the value to 0 by writting 0xB8DF to the register, however it reads the same value. I thought it is a w/r register.

nvidia@localhost:~$ sudo devmem2 0x15C1441A h 0xB8DF
/dev/mem opened.
Memory mapped at address 0x7fa384a000.
Value at address 0x15C1441A (0x7fa384a41a): 0xBADF
Written 0xB8DF; readback 0xBADF

Any suggestion?

Thanks

Looks like the address is incorrect. Below are the list of all address.

15f11068: VI_CH0_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f11468: VI_CH1_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f11868: VI_CH2_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f11c68: VI_CH3_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f12068: VI_CH4_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f12468: VI_CH5_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f12868: VI_CH6_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f12c68: VI_CH7_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f13068: VI_CH8_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f13468: VI_CH9_NOTIFY_MASK_XCPT_0                               = 0x00000000 //
15f13868: VI_CH10_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f13c68: VI_CH11_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f14068: VI_CH12_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f14468: VI_CH13_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f14868: VI_CH14_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f14c68: VI_CH15_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f15068: VI_CH16_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f15468: VI_CH17_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f15868: VI_CH18_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f15c68: VI_CH19_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f16068: VI_CH20_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f16468: VI_CH21_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f16868: VI_CH22_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f16c68: VI_CH23_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f17068: VI_CH24_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f17468: VI_CH25_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f17868: VI_CH26_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f17c68: VI_CH27_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f18068: VI_CH28_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f18468: VI_CH29_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f18868: VI_CH30_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f18c68: VI_CH31_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f19068: VI_CH32_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f19468: VI_CH33_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f19868: VI_CH34_NOTIFY_MASK_XCPT_0                              = 0x00000000 //
15f19c68: VI_CH35_NOTIFY_MASK_XCPT_0                              = 0x00000000 //

Thanks for the list, pretty useful information.

From the trace the log indicates Channel 0x04

kworker/0:4-4723  [000] ....  1808.356715: rtcpu_vinotify_event: tstamp:56829734821 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:56829412822 data:0x0000054

So from your list I used 0x15f12068, but it does not change either. I even tried to use another tool (busybox devmem)

nvidia@localhost:~$ sudo busybox devmem 0x15f12068 16
0x0000
nvidia@localhost:~$ sudo busybox devmem 0x15f12068 16 0x0800
nvidia@localhost:~$ sudo busybox devmem 0x15f12068 16
0x0000

Regards

Have a try CH2