Custom Xavier NX board: `no reply from camera processor`

Hi again, following up with trying to get the second IMX477 running on lanes CSI2 D0 and D1.

Firstly I’ve confirmed the sensor isn’t faulty by swapping the sensors and observing the imager on CSI2 persists. Second, I realized that running with the port-index values that Shane recommended did change the the error messages I’m receiving for this CSI port.

First, running sudo bash -c "echo 'file camera_common.c +p' > /sys/kernel/debug/dynamic_debug/control" and then following dmesg gets me:

[  833.286349] imx477 9-001a: camera_common_mclk_enable: enable MCLK with 24000000 Hz
[  833.286391] imx477 9-001a: camera_common_dpd_disable: csi 2
[  833.627869] [RCE] vi5_hwinit: firmware CL2018101701 protocol version 2.2
[  833.733390] tegra194-vi5 15c10000.vi: corr_err: discarding frame 1, flags: 112, err_data 39845986
[  833.766745] tegra194-vi5 15c10000.vi: corr_err: discarding frame 2, flags: 112, err_data 39845986
[  833.800056] tegra194-vi5 15c10000.vi: corr_err: discarding frame 3, flags: 112, err_data 39845986
[  833.833380] tegra194-vi5 15c10000.vi: corr_err: discarding frame 4, flags: 112, err_data 39845986
[  856.355334] imx477 9-001a: camera_common_dpd_enable: csi 2
[  856.355343] imx477 9-001a: camera_common_mclk_disable: disable MCLK

Notably, the no reply from camera processor is gone, and after those first four frames, the corr_err message stops and does NOT output continuously.

Next, going back and enabling the same debug trace output with:

sudo bash -c "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”

and then sudo cat /sys/kernel/debug/tracing/trace gives:

     kworker/1:0-8634  [001] ....   983.156616: rtcpu_nvcsi_intr: tstamp:31128915432 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006                                                                                                                                                         [9465/9485]
     kworker/1:0-8634  [001] ....   983.156616: rtcpu_nvcsi_intr: tstamp:31128915432 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156616: rtcpu_nvcsi_intr: tstamp:31128916044 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156617: rtcpu_nvcsi_intr: tstamp:31128916044 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156617: rtcpu_nvcsi_intr: tstamp:31128916656 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156617: rtcpu_nvcsi_intr: tstamp:31128916656 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156617: rtcpu_nvcsi_intr: tstamp:31128917270 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156617: rtcpu_nvcsi_intr: tstamp:31128917270 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156618: rtcpu_nvcsi_intr: tstamp:31128917884 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156618: rtcpu_nvcsi_intr: tstamp:31128917884 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156618: rtcpu_nvcsi_intr: tstamp:31128918495 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156618: rtcpu_nvcsi_intr: tstamp:31128918495 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:0-8634  [001] ....   983.156618: rtcpu_nvcsi_intr: tstamp:31128918495 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156619: rtcpu_nvcsi_intr: tstamp:31128918495 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:0-8634  [001] ....   983.156619: rtcpu_nvcsi_intr: tstamp:31128919461 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156619: rtcpu_nvcsi_intr: tstamp:31128919461 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156619: rtcpu_nvcsi_intr: tstamp:31128920073 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156619: rtcpu_nvcsi_intr: tstamp:31128920073 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156620: rtcpu_nvcsi_intr: tstamp:31128920689 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156620: rtcpu_nvcsi_intr: tstamp:31128920689 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:0-8634  [001] ....   983.156621: rtcpu_nvcsi_intr: tstamp:31128920689 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156621: rtcpu_nvcsi_intr: tstamp:31128920689 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:0-8634  [001] ....   983.156621: rtcpu_nvcsi_intr: tstamp:31128921656 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156621: rtcpu_nvcsi_intr: tstamp:31128921656 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156622: rtcpu_nvcsi_intr: tstamp:31128922270 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156622: rtcpu_nvcsi_intr: tstamp:31128922270 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156622: rtcpu_nvcsi_intr: tstamp:31128922884 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156622: rtcpu_nvcsi_intr: tstamp:31128922884 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156622: rtcpu_nvcsi_intr: tstamp:31128923495 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156623: rtcpu_nvcsi_intr: tstamp:31128923495 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156623: rtcpu_nvcsi_intr: tstamp:31128924107 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156623: rtcpu_nvcsi_intr: tstamp:31128924107 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156623: rtcpu_nvcsi_intr: tstamp:31128924719 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156623: rtcpu_nvcsi_intr: tstamp:31128924719 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156624: rtcpu_nvcsi_intr: tstamp:31128925331 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156624: rtcpu_nvcsi_intr: tstamp:31128925331 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156624: rtcpu_nvcsi_intr: tstamp:31128925943 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156624: rtcpu_nvcsi_intr: tstamp:31128925943 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156625: rtcpu_nvcsi_intr: tstamp:31128926597 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:0-8634  [001] ....   983.156625: rtcpu_nvcsi_intr: tstamp:31128926597 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002

Based on @ShaneCCC’s recommendation in various posts and the eLinux wiki I went ahead and tried this again while boosting clocks. Reboot, run the previous command to enable trace logs, and now boost clocks to max:

sudo bash -c "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"

This output adds a few more new messages:
sudo cat /sys/kernel/debug/tracing/trace:

     kworker/1:3-2098  [001] ....    77.454435: rtcpu_nvcsi_intr: tstamp:2826656033 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454436: rtcpu_nvcsi_intr: tstamp:2826656033 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454437: rtcpu_nvcsi_intr: tstamp:2826656033 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454438: rtcpu_nvcsi_intr: tstamp:2826656033 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454438: rtcpu_nvcsi_intr: tstamp:2826656033 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454439: rtcpu_nvcsi_intr: tstamp:2826657331 class:GLOBAL type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454440: rtcpu_nvcsi_intr: tstamp:2826657331 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454441: rtcpu_nvcsi_intr: tstamp:2826657331 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454441: rtcpu_nvcsi_intr: tstamp:2826657331 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454442: rtcpu_nvcsi_intr: tstamp:2826657331 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454443: rtcpu_nvcsi_intr: tstamp:2826657331 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454444: rtcpu_nvcsi_intr: tstamp:2826658641 class:GLOBAL type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454444: rtcpu_nvcsi_intr: tstamp:2826658641 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454445: rtcpu_nvcsi_intr: tstamp:2826658641 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454446: rtcpu_nvcsi_intr: tstamp:2826658641 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454447: rtcpu_nvcsi_intr: tstamp:2826658641 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454447: rtcpu_nvcsi_intr: tstamp:2826658641 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454448: rtcpu_nvcsi_intr: tstamp:2826659932 class:GLOBAL type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454449: rtcpu_nvcsi_intr: tstamp:2826659932 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454450: rtcpu_nvcsi_intr: tstamp:2826659932 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454450: rtcpu_nvcsi_intr: tstamp:2826659932 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454451: rtcpu_nvcsi_intr: tstamp:2826659932 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454452: rtcpu_nvcsi_intr: tstamp:2826661060 class:GLOBAL type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454453: rtcpu_nvcsi_intr: tstamp:2826661060 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454453: rtcpu_nvcsi_intr: tstamp:2826661060 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454454: rtcpu_nvcsi_intr: tstamp:2826661060 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454455: rtcpu_nvcsi_intr: tstamp:2826661060 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454456: rtcpu_nvcsi_intr: tstamp:2826661060 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454456: rtcpu_nvcsi_intr: tstamp:2826662356 class:GLOBAL type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454457: rtcpu_nvcsi_intr: tstamp:2826662356 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454458: rtcpu_nvcsi_intr: tstamp:2826662356 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454459: rtcpu_nvcsi_intr: tstamp:2826662356 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
     kworker/1:3-2098  [001] ....    77.454459: rtcpu_nvcsi_intr: tstamp:2826662356 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454460: rtcpu_nvcsi_intr: tstamp:2826662356 class:CORRECTABLE_ERR type:PHY_INTR phy:1 cil:0 st:0 vc:0 status:0x00000002
     kworker/1:3-2098  [001] ....    77.454461: rtcpu_nvcsi_intr: tstamp:2826663651 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
     kworker/1:3-2098  [001] ....    77.454462: rtcpu_nvcsi_intr: tstamp:2826663651 class:GLOBAL

Between some Shane’s past posts[3][4] and the Xavier technical reference, it seems like these are the main takeways from this output:

  • rtcpu_nvcsi_intr: tstamp:31128915432 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000006
    • STREAM_VC is register NVCSI_STREAM_0_INTR_STATUS_VC0_0
    • Getting error bits 2 and 1 named intr_stat_pd_crc_err_vc0 and intr_stat_ph_ecc_single_bit_err_vc0
  • rtcpu_nvcsi_intr: tstamp:2826656033 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000002
    • PHY_INTRO is register NVCSI_PHY_0_CILA_INTR_0_STATUS_CILA_0
    • Bit 1 is intr_cil_data_lane_sot_sb_err0_a, which from Shane’s comments I assume sb means single bit?
  • rtcpu_nvcsi_intr: tstamp:2826661060 class:CORRECTABLE_ERR type:STREAM_NOVC phy:0 cil:0 st:2 vc:0 status:0x00000001
    • STREAM_NOVC is register NVCSI_STREAM_0_INTR_STATUS_NOVC_0
    • Bit 0 is intr_stat_ph_ecc_multi_bit_err

Clearly the SoC is unhappy about CRC/ECC issues. Any guidance for debugging this would be much appreciated.

Is the next step to mask these error bits as was recommended in Problem with capturing images by Video4Linux - #13 by ShaneCCC ? I’d like to understand why the integrity checks are failing…

Thanks again.

[3] How to interpret CSI debug information - #3 by ShaneCCC
[4] GMSL camera return “STREAM_NOVC" error and no image - #3 by ShaneCCC