Jetpack-6.2 - Uncorr_err: request timed out after 2500 ms

Hi Camera Experts,

I am facing the following error while attempting streaming the the EV9500M camera :

[ 1673.916620] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 1673.916642] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 1673.917894] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

Then I enabled the trace :

    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
    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 1 > /sys/kernel/debug/tracing/events/camera_common/enable
   echo > /sys/kernel/debug/tracing/trace

which gave :

root@ORNN:/home/nvidia# cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 71/71   #P:6
#
#                                _-------=> irqs-off
#                               / _------=> need-resched
#                              | / _-----=> need-resched-lazy
#                              || / _----=> hardirq/softirq
#                              ||| / _---=> preempt-depth
#                              |||| / _--=> preempt-lazy-depth
#                              ||||| / _-=> migrate-disable
#                              |||||| /     delay
#           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
#              | |         |   |||||||      |         |
  gst-launch-1.0-2834    [003] .......  1643.106747: tegra_channel_open: vi-output, ev9500m 7-0010
  gst-launch-1.0-2834    [003] .......  1643.106779: tegra_channel_close: vi-output, ev9500m 7-0010
  gst-launch-1.0-2834    [003] .......  1643.114337: tegra_channel_open: vi-output, ev9500m 7-0010
    v4l2src0:src-2836    [001] .......  1643.124348: tegra_channel_set_power: ev9500m 7-0010 : 0x1
    v4l2src0:src-2836    [001] .......  1643.124360: camera_common_s_power: status : 0x1
    v4l2src0:src-2836    [001] .......  1643.132273: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x1
    v4l2src0:src-2836    [001] .......  1643.132279: csi_s_power: enable : 0x1
    v4l2src0:src-2836    [001] .......  1643.132865: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1643.141056: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1643.141062: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1643.141064: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1643.141065: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
    v4l2src0:src-2836    [002] .......  1643.141098: tegra_channel_set_stream: enable : 0x1
    v4l2src0:src-2836    [002] .......  1643.143231: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x1
    v4l2src0:src-2836    [002] .......  1643.143237: csi_s_stream: enable : 0x1
    v4l2src0:src-2836    [002] .......  1643.143656: tegra_channel_set_stream: ev9500m 7-0010 : 0x1
 vi-output, ev95-2839    [003] .......  1645.789430: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1645.840287: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1645.864403: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1645.888408: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1648.349535: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1648.363926: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1648.388239: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1648.411920: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1650.909558: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1650.924245: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1650.948264: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1650.972214: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [001] .......  1653.469349: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1653.483909: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1653.507930: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1653.531977: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1656.029526: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1656.043867: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1656.067832: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1656.091693: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1658.589340: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [001] .......  1658.603847: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [001] .......  1658.628089: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1658.652114: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1661.149532: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [002] .......  1661.163840: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1661.187827: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1661.211634: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1663.709519: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [002] .......  1663.723982: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1663.748333: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1663.772499: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1666.269582: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [002] .......  1666.283861: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1666.307857: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1666.331941: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1668.829411: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [002] .......  1668.843637: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1668.867592: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1668.891319: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [003] .......  1671.389321: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
 vi-output, ev95-2838    [002] .......  1671.403850: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1671.427838: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1671.451789: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2838    [002] .......  1673.256673: vi_task_submit: class_id:48 ch:0 syncpt_id:26 syncpt_thresh:0 pid:2838 tid:2838
 vi-output, ev95-2839    [001] .......  1673.917518: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1080 fmt 13
  gst-launch-1.0-2834    [001] .......  1673.917964: tegra_channel_set_stream: enable : 0x0
  gst-launch-1.0-2834    [001] .......  1673.917967: tegra_channel_set_stream: ev9500m 7-0010 : 0x0
  gst-launch-1.0-2834    [001] .......  1673.918482: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x0
  gst-launch-1.0-2834    [001] .......  1673.918485: csi_s_stream: enable : 0x0
  gst-launch-1.0-2834    [003] .......  1673.921433: tegra_channel_set_power: ev9500m 7-0010 : 0x0
  gst-launch-1.0-2834    [003] .......  1673.921522: camera_common_s_power: status : 0x0
  gst-launch-1.0-2834    [004] .......  1673.924425: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x0
  gst-launch-1.0-2834    [004] .......  1673.924430: csi_s_power: enable : 0x0
  gst-launch-1.0-2834    [003] .......  1673.952002: tegra_channel_close: vi-output, ev9500m 7-0010

Is it possible to see/interpret any error from above trace, please ?

Thanks in advance,
K.

Hi,

To update, using the debug RCE firmware gave :

     kworker/0:1-45      [000] .......   178.781757: rtcpu_string: tstamp:6174517745 id:0x04010000 str:"ISR PHY 0 CIL_A 0x80
"
     kworker/0:1-45      [000] .......   178.781768: rtcpu_string: tstamp:6174518282 id:0x04010000 str:"ISR PHY 0 CIL_B 0x8

or in dmesg :

[  281.300368] [RCE] ISR PHY 0 CIL_A 0x80
[  281.300370] [RCE] ISR PHY 0 CIL_B 0x8

trace.txt (18.2 KB)

Now that I realized that I am running the Orin Nano on a Xavier NX custom carrier board using the first 4 CSI-2 lanes (Camera 1), there seems to configure the lane_polarity = 6 according to the Design Guide :

However, I still get the green screen with slightly different trace :

"
     kworker/3:2-294     [003] .......   236.805417: rtcpu_string: tstamp:7992739511 id:0x04010000 str:"ISR PHY 0 CIL_A 0x88
"
     kworker/3:2-294     [003] .......   236.805419: rtcpu_string: tstamp:7992740027 id:0x04010000 str:"ISR PHY 0 CIL_B 0x88
"
     kworker/3:2-294     [003] .......   236.805421: rtcpu_string: tstamp:7992740929 id:0x04010000 str:"ISR PHY 0 CIL_A 0x88
"
     kworker/3:2-294     [003] .......   236.805424: rtcpu_string: tstamp:7992741444 id:0x04010000 str:"ISR PHY 0 CIL_B 0x88
"
     kworker/3:2-294     [003] .......   236.805426: rtcpu_string: tstamp:7992742345 id:0x04010000 str:"ISR PHY 0 CIL_A 0x88
"
     kworker/3:2-294     [003] .......   236.805428: rtcpu_string: tstamp:7992742860 id:0x04010000 str:"ISR PHY 0 CIL_B 0x88
"
     kworker/3:2-294     [003] .......   236.805431: rtcpu_string: tstamp:7992743766 id:0x04010000 str:"ISR PHY 0 CIL_A 0x88
"
     kworker/3:2-294     [003] .......   236.805433: rtcpu_string: tstamp:7992744285 id:0x04010000 str:"ISR PHY 0 CIL_B 0x88
"
     kworker/3:2-294     [003] .......   236.805435: rtcpu_string: tstamp:7992745193 id:0x04010000 str:"ISR PHY 0 CIL_A 0x88

...
     kworker/3:2-294     [003] .......   237.084997: rtcpu_string: tstamp:7999984490 id:0x04010000 str:"ISR PHY 0 CIL_A 0x12000000
"
     kworker/3:2-294     [003] .......   237.085006: rtcpu_string: tstamp:7999985055 id:0x04010000 str:"ISR PHY 0 CIL_B 0x4000000
"
     kworker/3:2-294     [003] .......   237.085011: rtcpu_string: tstamp:7999985994 id:0x04010000 str:"ISR PHY 0 CIL_A 0x14000000
"
     kworker/3:2-294     [003] .......   237.085015: rtcpu_string: tstamp:7999991322 id:0x04010000 str:"ISR PHY 0 CIL_A 0x80
...
"
     kworker/3:2-294     [003] .......   236.805438: rtcpu_string: tstamp:7992745710 id:0x04010000 str:"ISR PHY 0 CIL_B 0x88
"

trace_swap_lane_polarity.txt (25.3 KB)

Could someone help to understand what exactly the meaning of the trace, please ?

Best Regards,
Khang

Hi @ShaneCCC,

Could you help to understand what do ISR PHY 0 CIL_A/B in the trace mean, please ? I cannot find relevant information in Jetson/l4t/Camera BringUp - eLinux.org

Thanks in advance and best regards,
Khang

Hi @JerryChang,

I found the answer for the meaning of the ISR PHY 0 CIL_A/B in the trace thanks to your comment. My error seems relevant to intr_cil_data_lane_ctrl_err0_a, intr_cil_data_lane_ctrl_err1_a, intr_cil_data_lane_ctrl_err0_b, and intr_cil_data_lane_ctrl_err1_b for the 4 lanes interfacing with the camera.

Could you help to clarify more about the error, please ? Does it imply that there’s data on the 4 lanes but for some reason they are not good? Knowing that the driver as well as the device-tree are ported from a Xavier NX based working system .

Best Regards,
K.

hello khang.l4es,

FYI,
on Orin Nano carrier board, CSI-1 is CSI-B of J20, (CAM0 slot).
since it used CSI-B instead of CSI-A. it can only be configured as x1 or x2 lane configuration.
please double check the board schematic of your customize board. for instance, is it route to CSI-A actually?

or..
could you please check you’re able to launch the stream with 2-lane configuration?

Hi @JerryChang,

It is a currently working system with a Xavier NX based custom board and we are in the phase of migrating to Orin Nano. And the camera is connected to the 4-lane MIPI-CSI configuration.

We cannot change to x2 lane configuration as it is in the camera’s firmware that we don’t have access.

Best Regards,
K.

hello khang.l4es,

CIL PHY interrupts with 0x80 and 0x88 usually due to LP sequence error. for instance, normally, it should follow by LP11->LP01->LP00->LP11 sequence. you may arrange hardware resources to probe the MIPI signaling for double check.

besides,
please refer to.. Topic 326038, let’s apply JetPack-6.2/l4t-r36.4.3 camera firmware with debug flag enabled to gather more details.

Hi @JerryChang,

The trace of PHY CIL were seen thanks to applying the debug firmware in the topic you mentioned. Unfortunately no more information than that could be provided.

hello khang.l4es,

those RCE debug logs will append to kernel logs.
please check $ dmesg --follow for more details.

Maybe you can verify on CSI-C 4 lanes first.

Hi @JerryChang,

Please find attached the output of dmesg --follow command.

dmesg_follow.txt (1.4 MB)

Could you help to check if there’s something abnormal at the beginning of the streaming, please?

Best Regards,
K.

hello khang.l4es,

there’re several IDACADJ calibration timeout has reported.
even though below logs meant it’s VI engine keep waiting for sensor frames.

[   89.934213] [RCE] nvcsi_stream_enable: enable pixel parser++ Line(3554)
[   89.934214] [RCE] nvcsi_stream_enable: enable pixel parser-- Line(3591)

so.. please apply this rce-fw update, Topic329017_Apr10.zip (250.0 KB)
which has configure higher settle time for testing.

Hi @JerryChang,

Thanks for your support but the only Orin Nano module I have was broken. I am waiting for getting a new one to test your new rce-fw update.

Best Regards,
Khang