I’m running cameras over GMSL2 on an Xavier NX. Without boosting the clocks, v4l2 will stream at 30fps and the trace looks like this:
vi-output, ox08-1955 [000] .... 248.772092: tegra_channel_capture_frame: sof:269.968555520
vi-output, ox08-1955 [000] .... 248.772096: tegra_channel_capture_frame: eof:270.206176
kworker/2:1-47 [002] .... 248.803766: rtcpu_vinotify_event: tstamp:8437023306 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:269968843552 data:0xcd9ce20010000000
kworker/2:1-47 [002] .... 248.803768: rtcpu_vinotify_event: tstamp:8437023459 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:269968887008 data:0x00000000310009f2
kworker/2:1-47 [002] .... 248.803776: rtcpu_vinotify_event: tstamp:8437567117 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:270000156384 data:0x00000000086f0002
kworker/2:1-47 [002] .... 248.803777: rtcpu_vinotify_event: tstamp:8437567286 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:270000157248 data:0x0000000000000000
kworker/2:1-47 [002] .... 248.803777: rtcpu_vinotify_event: tstamp:8437567459 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:270000177536 data:0x00000000020209f1
kworker/2:1-47 [002] .... 248.803778: rtcpu_vinotify_event: tstamp:8437567612 cch:0 vi:0 tag:FE channel:0x00 frame:0 vi_tstamp:270000206112 data:0x0000000000000020
kworker/2:1-47 [002] .... 248.803778: rtcpu_vinotify_event: tstamp:8437567790 cch:0 vi:0 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:270000206176 data:0x0000000800000000
kworker/2:1-47 [002] .... 248.803779: rtcpu_vinotify_event: tstamp:8437567939 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:270000242560 data:0x00000000000209f1
kworker/2:1-47 [002] .... 248.803786: rtcpu_vinotify_event: tstamp:8437568110 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:270001801280 data:0x0000000000000010
kworker/2:1-47 [002] .... 248.803787: rtcpu_vinotify_event: tstamp:8437568263 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:270001801344 data:0x0000000800000000
kworker/2:1-47 [002] .... 248.803788: rtcpu_vinotify_event: tstamp:8437568433 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:270001863104 data:0x0000000000000001
kworker/2:1-47 [002] .... 248.803789: rtcpu_vinotify_event: tstamp:8437568582 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:270001873888 data:0x00000000080209f2
kworker/2:1-47 [002] .... 248.803789: rtcpu_vinotify_event: tstamp:8438108300 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:270002207360 data:0xcd9ce50010000000
kworker/2:1-47 [002] .... 248.803790: rtcpu_vinotify_event: tstamp:8438108454 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:270002250816 data:0x00000000310009f3
vi-output, ox08-1955 [000] .... 248.805226: tegra_channel_capture_frame: sof:270.1863104
vi-output, ox08-1955 [000] .... 248.805229: tegra_channel_capture_frame: eof:270.33513792
vi-output, ox08-1955 [000] .... 248.838685: tegra_channel_capture_frame: sof:270.35170720
vi-output, ox08-1955 [000] .... 248.838689: tegra_channel_capture_frame: eof:270.66821408
when I boost the clocks to max and limit the rate using
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
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
The v4l2-ctl stream jams up and I get this in the trace:
kworker/2:1-47 [002] .... 161.551789: rtcpu_vinotify_event: tstamp:5711557174 cch:0 vi:0 tag:CSIMUX_FRAME channel:0x00 frame:0 vi_tstamp:182766733440 data:0x00000000000000a0
kworker/2:1-47 [002] .... 161.551790: rtcpu_vinotify_event: tstamp:5711557345 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:182766733440 data:0x0000000000000010
kworker/2:1-47 [002] .... 161.551791: rtcpu_vinotify_event: tstamp:5711557493 cch:0 vi:0 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:182766795552 data:0x0000000000000589
kworker/2:1-47 [002] .... 161.653760: rtcpu_vinotify_error: tstamp:5714589142 cch:0 vi:0 tag:CSIMUX_FRAME channel:0x00 frame:0 vi_tstamp:182866656192 data:0x00000000000000a0
kworker/2:1-47 [002] .... 161.653763: rtcpu_vinotify_error: tstamp:5714590175 cch:0 vi:0 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:182866718304 data:0x0000000000000589
kworker/2:1-47 [002] .... 161.653765: rtcpu_vinotify_event: tstamp:5714812138 cch:0 vi:0 tag:CSIMUX_FRAME channel:0x00 frame:0 vi_tstamp:182866656192 data:0x00000000000000a0
kworker/2:1-47 [002] .... 161.653766: rtcpu_vinotify_event: tstamp:5714812292 cch:0 vi:0 tag:FS channel:0x00 frame:0 vi_tstamp:182866656192 data:0x0000000000000010
echo’ing 0’s back into the files fixes it again
It looks like it gets FE errors? What could be going wrong here?