Tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 0 ms

Hello,

we have an custom carrier board with a Nvidia Orin NX running L4T-36.4 (JP6.1). The ZEDx camera is connected to the board through a MAX96724 GMSL deserializer. The system is running at MAXN.

The modes are listen in nvargus:

nvargus_nvraw version 1.16.0
Number of supported sensor entries 6
Entry  Source Mode      Uniquename             Resolution   FR  BitDepth  Mode
Index  Index  Index                                             CSI Dyn   Type
  0      0      0                 zedx_ar0234   1920x1200   59  10  10    Bayer
  1      0      1                 zedx_ar0234    960x 600  120  10  10    Bayer
  2      0      2                 zedx_ar0234   1920x1080   59  10  10    Bayer
  3      1      0                 zedx_ar0234   1920x1200   59  10  10    Bayer
  4      1      1                 zedx_ar0234    960x 600  120  10  10    Bayer
  5      1      2                 zedx_ar0234   1920x1080   59  10  10    Bayer

When I try to run

v4l2-ctl -c bypass_mode=0 --stream-mmap --stream-count=5

it never terminates and dmesg reports a lot of errors:

[   54.023974] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 0 ms
[   54.023988] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[   54.024848] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[   54.029199] zedx 2-0028: zedx_set_mode: setting the device mode
[   54.651971] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 0 ms
[   54.651985] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[   54.652915] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[   54.656199] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 0 ms
[   54.656217] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[   54.656728] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[   54.659981] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 0 ms
[   54.659991] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[   54.660647] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[   54.664137] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 0 ms
...

I tried to enable kernel tracing:

modprobe rtcpu_debug
echo 1 > /sys/kernel/debug/tracing/tracing_on
echo 30720 > /sys/kernel/debug/tracing/buffer_size_kb
echo 1 > /sys/kernel/debug/tracing/events/tegra_rtcpu/enable
echo 1 > /sys/kernel/debug/tracing/events/freertos/enable
echo 2 > /sys/kernel/debug/camrtc/log-level
echo > /sys/kernel/debug/tracing/trace
cat /sys/kernel/debug/tracing/trace

and the trace shows:

# tracer: nop
#
# entries-in-buffer/entries-written: 573/573   #P:8
#
#                                _-------=> irqs-off
#                               / _------=> need-resched
#                              | / _-----=> need-resched-lazy
#                              || / _----=> hardirq/softirq
#                              ||| / _---=> preempt-depth
#                              |||| / _--=> preempt-lazy-depth
#                              ||||| / _-=> migrate-disable
#                              |||||| /     delay
#           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
#              | |         |   |||||||      |         |
     kworker/4:2-307     [004] .......   123.815361: rtcpu_dbg_set_loglevel: tstamp:4568644062 old:0 new:2
     kworker/4:2-307     [004] .......   129.367206: rtcpu_string: tstamp:4742378463 id:0x04010000 str:"VM0 deactivating."
     kworker/4:2-307     [004] .......   135.863039: rtcpu_string: tstamp:4945340040 id:0x04010000 str:"VM0 activating."
     kworker/4:2-307     [004] .......   135.863044: rtcpu_vinotify_event: tstamp:4946027388 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158256796928 data:0x799e300010000000
     kworker/4:2-307     [004] .......   135.863046: rtcpu_vinotify_event: tstamp:4946027545 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158256803328 data:0x0000000031000001
     kworker/4:2-307     [004] .......   135.863046: rtcpu_vinotify_event: tstamp:4946027702 cch:-1 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:158256806336 data:0x0000000007020001
     kworker/4:2-307     [004] .......   135.863047: rtcpu_vinotify_event: tstamp:4946027834 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158256848608 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   135.863047: rtcpu_vinotify_event: tstamp:4946027986 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158256855104 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.031207: rtcpu_nvcsi_intr: tstamp:4950540962 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/4:2-307     [004] .......   136.031209: rtcpu_nvcsi_intr: tstamp:4950540962 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/4:2-307     [004] .......   136.483024: rtcpu_vinotify_event: tstamp:4965419039 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158883990912 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.483027: rtcpu_vinotify_event: tstamp:4965419197 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158884032960 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.483028: rtcpu_vinotify_event: tstamp:4965419335 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158884051136 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   136.483029: rtcpu_vinotify_event: tstamp:4965419490 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:158884071424 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.483029: rtcpu_vinotify_event: tstamp:4965419626 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158884113824 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.483030: rtcpu_vinotify_event: tstamp:4965419779 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158889476928 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.483031: rtcpu_vinotify_event: tstamp:4965419914 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158889518976 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.483031: rtcpu_vinotify_event: tstamp:4965420066 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158889537152 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   136.483032: rtcpu_vinotify_event: tstamp:4965420199 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:158889557440 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.483032: rtcpu_vinotify_event: tstamp:4965420351 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158889599840 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.483033: rtcpu_vinotify_event: tstamp:4965420485 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158893315328 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.483035: rtcpu_nvcsi_intr: tstamp:4965763039 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x0e000000
     kworker/4:2-307     [004] .......   136.483035: rtcpu_nvcsi_intr: tstamp:4965763039 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000e00
     kworker/4:2-307     [004] .......   136.483036: rtcpu_vinotify_event: tstamp:4965938742 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158893475616 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.483037: rtcpu_vinotify_event: tstamp:4965938879 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158893493792 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   136.483037: rtcpu_vinotify_event: tstamp:4965939034 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:158893514080 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.483038: rtcpu_vinotify_event: tstamp:4965939167 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158893556704 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.483038: rtcpu_vinotify_event: tstamp:4965939323 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158896825824 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.483038: rtcpu_vinotify_event: tstamp:4965939455 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158896867872 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.483039: rtcpu_vinotify_event: tstamp:4965939607 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158896887136 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   136.483039: rtcpu_vinotify_event: tstamp:4965939739 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:158896907456 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.483040: rtcpu_vinotify_event: tstamp:4965939892 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158896949824 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.483040: rtcpu_vinotify_event: tstamp:4965940027 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158904853440 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.483040: rtcpu_vinotify_event: tstamp:4965940181 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158904895488 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.483041: rtcpu_vinotify_event: tstamp:4965940315 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:158904913696 data:0x799e2d0010000000
...
     kworker/4:2-307     [004] .......   136.995039: rtcpu_vinotify_event: tstamp:4981158542 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:159392872736 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.995039: rtcpu_vinotify_event: tstamp:4981158697 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159392915104 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.995040: rtcpu_vinotify_event: tstamp:4981158830 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159396812320 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.995040: rtcpu_vinotify_event: tstamp:4981158982 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159396854368 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.995041: rtcpu_vinotify_event: tstamp:4981159114 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159396872608 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   136.995042: rtcpu_vinotify_event: tstamp:4981159267 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:159396896000 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.995043: rtcpu_vinotify_event: tstamp:4981159402 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159396938400 data:0x0000000031000002
     kworker/4:2-307     [004] .......   136.995043: rtcpu_vinotify_event: tstamp:4981672900 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159400749696 data:0x799e300010000000
     kworker/4:2-307     [004] .......   136.995044: rtcpu_vinotify_event: tstamp:4981673039 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159400791744 data:0x0000000031000001
     kworker/4:2-307     [004] .......   136.995045: rtcpu_vinotify_event: tstamp:4981673197 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159400809888 data:0x799e2d0010000000
     kworker/4:2-307     [004] .......   136.995045: rtcpu_vinotify_event: tstamp:4981673331 cch:-1 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:159400830208 data:0x0000000007020001
     kworker/4:2-307     [004] .......   136.995046: rtcpu_vinotify_event: tstamp:4981673485 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:159400872576 data:0x0000000031000002
     kworker/4:2-307     [004] .......   143.322903: rtcpu_string: tstamp:5179329700 id:0x04010000 str:"VM0 deactivating."

Our devicetree overlay can be found here:
tegra234-roconx-camera-zedx.zip (2.5 KB)

I can’t get any video data from this sensor.

hello marcus.huenerbein,

the PHY interrupt show the DPHY deskew calibration not complete, it might due to the calibration sequence length is not long enough.
please refer to developer guide, SerDes Pixel Clock, you may double check the serdes_pix_clk_hz property settings.

Hello JerryChang,

Thank you for your quick answer.
Setting the correct value for serdes_pix_clk_hz fixed the CORRECTABLE_ERR message.

The VIFALC_TDSTATE message persists and I’m getting no video from this camera.

Am I correct in my assumption that VIFALC_TDSTATE means that no valid buffer data was received ? Is there documentation for the various (error) messages?

Thank you.

hello marcus.huenerbein,

that’s not harmful message.


the issue should be there’s no validate frames received by VI engine,
let me share some VI tracing logs with a success image capture as an example,
here must be one pair of CHANSEL_PXL_SOF/CHANSEL_PXL_EOF to indicate a frame has detected by VI engine.
afterwards, it’s ATOMP_FRAME_DONE to indicate it’s complete writing a frame to memory.
for instance,

rtcpu_vinotify_event: tstamp:4058867917 cch:-1 vi:0 tag:CSIMUX_STREAM channel:0x00 frame:0 vi_tstamp:129874754944 data:0x0000000000000001
rtcpu_vinotify_event: tstamp:4059206674 cch:0 vi:0 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:129891804896 data:0x0000000800000000
rtcpu_vinotify_event: tstamp:4059206818 cch:0 vi:0 tag:CHANSEL_PXL_SOF channel:0x23 frame:1 vi_tstamp:129891808928 data:0x0000000000000001
rtcpu_vinotify_event: tstamp:4059206976 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:1 vi_tstamp:129891815424 data:0x0000000008020001
rtcpu_vinotify_error: tstamp:4060164160 cch:0 vi:0 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:129925171392 data:0x00000000000000a0
rtcpu_vinotify_event: tstamp:4060166846 cch:0 vi:0 tag:CHANSEL_PXL_EOF channel:0x23 frame:1 vi_tstamp:129923836800 data:0x0000000004370002
rtcpu_vinotify_event: tstamp:4060167015 cch:0 vi:0 tag:ATOMP_FRAME_DONE channel:0x23 frame:1 vi_tstamp:129923837312 data:0x0000000000000000

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