The camera occasionally loses a few frames of images during the always-on streaming process

Robotics & Edge Computing Jetson & Embedded Systems Jetson Orin NX
, ,
1 
    We are using ORin NX + max9296 + max9295 + Intel D457. During the long-term streaming test at 10fps, we found that a few frames of images were occasionally lost. Here is the trace.log when the frame loss occurred. Could you please help check what might be the cause of this issue?

    kworker/3:1-485227  [003] .... 408873.990724: rtcpu_vinotify_event: tstamp:12778017171526 cch:4 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:408896540077216 data:0x0000000000000012
     kworker/3:1-485227  [003] .... 408873.990726: rtcpu_vinotify_event: tstamp:12778017171665 cch:4 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:408896540077248 data:0x0000000200000000
     kworker/3:1-485227  [003] .... 408873.990727: rtcpu_vinotify_event: tstamp:12778017171818 cch:4 vi:1 tag:CHANSEL_PXL_SOF channel:0x21 frame:0 vi_tstamp:408896540087808 data:0x0000000000000001
     kworker/3:1-485227  [003] .... 408873.990727: rtcpu_vinotify_event: tstamp:12778017171950 cch:4 vi:1 tag:VIFALC_ACTIONLST channel:0x21 frame:0 vi_tstamp:408896540091712 data:0x000000000802e6fe
     kworker/3:1-485227  [003] .... 408873.990728: rtcpu_vinotify_event: tstamp:12778017172099 cch:4 vi:1 tag:VIFALC_TDSTATE channel:0x21 frame:0 vi_tstamp:408896540205600 data:0x759e240010000000
     kworker/3:1-485227  [003] .... 408873.990728: rtcpu_vinotify_event: tstamp:12778017172230 cch:4 vi:1 tag:VIFALC_TDSTATE channel:0x21 frame:0 vi_tstamp:408896540222016 data:0x000000003100e6ff
     kworker/3:1-485227  [003] .... 408873.990729: rtcpu_vinotify_event: tstamp:12778017293511 cch:3 vi:1 tag:CHANSEL_PXL_EOF channel:0x22 frame:0 vi_tstamp:408896553285568 data:0x0000000001df0002
     kworker/3:1-485227  [003] .... 408873.990729: rtcpu_vinotify_event: tstamp:12778017293647 cch:3 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:408896553286144 data:0x0000000000000022
     kworker/3:1-485227  [003] .... 408873.990729: rtcpu_vinotify_event: tstamp:12778017293807 cch:3 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:408896553286176 data:0x0000000400000000
     kworker/3:1-485227  [003] .... 408873.990730: rtcpu_vinotify_event: tstamp:12778017293940 cch:3 vi:1 tag:ATOMP_FRAME_DONE channel:0x22 frame:0 vi_tstamp:408896553286240 data:0x0000000000000000
     kworker/3:1-485227  [003] .... 408873.990730: rtcpu_vinotify_event: tstamp:12778017503808 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:408896554327616 data:0x0000000001df0002
     kworker/3:1-485227  [003] .... 408873.990731: rtcpu_vinotify_event: tstamp:12778017503944 cch:0 vi:0 tag:FE channel:0x03 frame:0 vi_tstamp:408896554328224 data:0x0000000000000021
     kworker/3:1-485227  [003] .... 408873.990731: rtcpu_vinotify_event: tstamp:12778017504105 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:408896554328256 data:0x0000000800000000
     kworker/3:1-485227  [003] .... 408873.990731: rtcpu_vinotify_event: tstamp:12778017504240 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:408896554328288 data:0x0000000000000000
     kworker/3:1-485227  [003] .... 408873.990731: rtcpu_vinotify_event: tstamp:12778017504393 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:408896554345408 data:0x000000000202d9ee
     kworker/3:1-485227  [003] .... 408873.990732: rtcpu_vinotify_event: tstamp:12778017504525 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:408896554350880 data:0x000000000002d9ee
     kworker/3:1-485227  [003] .... 408873.990732: rtcpu_vinotify_event: tstamp:12778017504677 cch:1 vi:0 tag:FS channel:0x02 frame:0 vi_tstamp:408896560011072 data:0x0000000000000011
     kworker/3:1-485227  [003] .... 408873.990732: rtcpu_vinotify_event: tstamp:12778017504814 cch:1 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:408896560011136 data:0x0000000400000000
     kworker/3:1-485227  [003] .... 408873.990732: rtcpu_vinotify_event: tstamp:12778017504969 cch:1 vi:0 tag:CHANSEL_PXL_SOF channel:0x22 frame:0 vi_tstamp:408896560017280 data:0x0000000000000001
     kworker/3:1-485227  [003] .... 408873.990733: rtcpu_vinotify_event: tstamp:12778017505102 cch:1 vi:0 tag:VIFALC_ACTIONLST channel:0x22 frame:0 vi_tstamp:408896560025152 data:0x000000000802d9f6
     kworker/3:1-485227  [003] .... 408873.990733: rtcpu_vinotify_event: tstamp:12778017641352 cch:3 vi:1 tag:VIFALC_ACTIONLST channel:0x22 frame:0 vi_tstamp:408896553306080 data:0x000000000202e6fe
     kworker/3:1-485227  [003] .... 408873.990733: rtcpu_vinotify_event: tstamp:12778017641488 cch:3 vi:1 tag:VIFALC_ACTIONLST channel:0x22 frame:0 vi_tstamp:408896553311680 data:0x000000000002e6fe
     kworker/3:1-485227  [003] .... 408873.990734: rtcpu_vinotify_event: tstamp:12778017832088 cch:1 vi:0 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:408896560139232 data:0x759d520010000000
     kworker/3:1-485227  [003] .... 408873.990734: rtcpu_vinotify_event: tstamp:12778017832224 cch:1 vi:0 tag:VIFALC_TDSTATE channel:0x22 frame:0 vi_tstamp:408896560156768 data:0x000000003100d9f7
     kworker/3:1-485227  [003] .... 408873.990734: rtcpu_vinotify_event: tstamp:12778017832375 cch:0 vi:0 tag:FS channel:0x03 frame:0 vi_tstamp:408896567319776 data:0x0000000000000011
     kworker/3:1-485227  [003] .... 408873.990734: rtcpu_vinotify_event: tstamp:12778017832510 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:408896567319840
3

What’s aways on streaming process?
Can tell the frame lost from the trace log. How do you check the frame lost?

4

Sorry, we can’t obtain the information about frame loss from the trace.log. Instead, we got it from the dmesg.

[Thu Feb 20 21:34:32 2025] cpufreq: cpu0,cur:1062000,set:729600,set ndiv:57
[Thu Feb 20 21:34:42 2025] cpufreq: cpu0,cur:972000,set:729600,set ndiv:57
[Thu Feb 20 21:34:42 2025] cpufreq: cpu0,cur:1240000,set:1984000,set ndiv:155
[Thu Feb 20 21:35:02 2025] cpufreq: cpu0,cur:1153000,set:729600,set ndiv:57
[Thu Feb 20 21:35:12 2025] cpufreq: cpu4,cur:1833000,set:1984000,set ndiv:155
[Thu Feb 20 21:35:32 2025] cpufreq: cpu0,cur:860000,set:729600,set ndiv:57
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 131072, vc: 3
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 131072, vc: 1
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 131072, vc: 0
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 0
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 1
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 3
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 0, flags: 0, err_data 131072, vc: 2
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=2, csi_port=2
[Thu Feb 20 21:35:52 2025] (NULL device *): vi_capture_control_message: NULL VI channel received
[Thu Feb 20 21:35:52 2025] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 2 vc- 2
[Thu Feb 20 21:35:52 2025] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[Thu Feb 20 21:36:03 2025] cpufreq: cpu0,cur:1045000,set:729600,set ndiv:57
[Thu Feb 20 21:36:23 2025] cpufreq: cpu0,cur:926000,set:729600,set ndiv:57
[Thu Feb 20 21:36:23 2025] cpufreq: cpu4,cur:1867000,set:1984000,set ndiv:155
[Thu Feb 20 21:37:03 2025] cpufreq: cpu0,cur:967000,set:729600,set ndiv:57
[Thu Feb 20 21:37:23 2025] cpufreq: cpu0,cur:1043000,set:729600,set ndiv:57
[Thu Feb 20 21:37:53 2025] cpufreq: cpu0,cur:728000,set:1984000,set ndiv:155
[Thu Feb 20 21:37:53 2025] cpufreq: cpu0,cur:911000,set:729600,set ndiv:57
[Thu Feb 20 21:38:03 2025] cpufreq: cpu4,cur:846000,set:1036800,set ndiv:81
[Thu Feb 20 21:38:13 2025] cpufreq: cpu0,cur:1041000,set:1984000,set ndiv:155
[Thu Feb 20 21:38:13 2025] cpufreq: cpu0,cur:1679000,set:1984000,set ndiv:155
[Thu Feb 20 21:38:23 2025] cpufreq: cpu0,cur:1836000,set:1984000,set ndiv:155
[Thu Feb 20 21:38:33 2025] cpufreq: cpu0,cur:802000,set:1984000,set ndiv:155
[Thu Feb 20 21:38:33 2025] cpufreq: cpu4,cur:1340000,set:1497600,set ndiv:117
[Thu Feb 20 21:38:43 2025] cpufreq: cpu4,cur:1526000,set:1984000,set ndiv:155
[Thu Feb 20 21:38:53 2025] cpufreq: cpu0,cur:1624000,set:1984000,set ndiv:155
[Thu Feb 20 21:38:53 2025] cpufreq: cpu4,cur:1862000,set:1984000,set ndiv:155
[Thu Feb 20 21:39:03 2025] cpufreq: cpu0,cur:1304000,set:1420800,set ndiv:111
[Thu Feb 20 21:39:33 2025] cpufreq: cpu0,cur:908000,set:1984000,set ndiv:155
5

Boost the clocks to verify.

sudo su
echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/isp/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/nvcsi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/emc/mrq_rate_locked
cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate |tee /sys/kernel/debug/bpmp/debug/clk/vi/rate
cat /sys/kernel/debug/bpmp/debug/clk/isp/max_rate | tee  /sys/kernel/debug/bpmp/debug/clk/isp/rate
cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate
cat /sys/kernel/debug/bpmp/debug/clk/emc/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/emc/rate
7

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.