Porting GREY8 sensor from Xavier NX to Orin NX

Robotics & Edge Computing Jetson Systems Jetson Orin NX
1

Hey all, following my recent post at:

We’ve successfully managed to get our custom orin NX carrier board working, and have tested its mipi-csi ports (4 of them) with 1->4 IMX219 cameras without issues, so that hardware itself is validated.

Now we are attempting to port our custom GREY8 1280x480 output camera:

  • we’ve ported our attached .dts from xavier to orin following the successful DTS we’ve established for the IMX219
  • the driver was updated to respect the new register conventions and general api changes between xavier and orin nx (it has very few responsibilities besides sending start/stop stream which have been validated)
  • we’ve modified the source files sensor_common.c (pixel_t string parser), vi5_formats.h (adding our own GREY8 format), and camera_common.c to add GREY to the color table (the three modified files are attached, this modification was a requirement back on Xavier as well.
  • we have thoroughly confirmed that the I2C exchange works (from our fpga-sided logs, stream begins exactly as needed, we do see mipi-LS activity on the data lines, HS is too fast to be viewable).

So right now hardware wise all is set, but we’re hitting an issue with actually getting the frames in, we’re getting timed out:

v4l2-ctl -d /dev/video0 --set-fmt-video=width=1280,height=480,pixelformat=GREY --stream-mmap --stream-count=5
[  124.266749] atto640 9-0055: atto640_start_streaming: Successfully set ATTO640D SoS 
[  126.945559] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  126.945582] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  126.946470] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  129.505335] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
...
[  144.833341] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  144.833361] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  144.834779] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  144.835100] atto640 9-0055: atto640_stop_streaming: Successfully set ATTO640D EoS

unlike the VI wiring issue from the IMX219, here the rtcpu log does show that some activity is found on the data lines, so ti’s not just a mere mis-wiring issue (which would be strange given the same mipi topology has been validated with IMX219).

RCE logs:

root@tegra-ubuntu:~# cat /sys/kernel/debug/tracing/trace | head -n 80
# tracer: nop
#
# entries-in-buffer/entries-written: 159556/159556   #P:4
#
#                                _-------=> irqs-off
#                               / _------=> need-resched
#                              | / _-----=> need-resched-lazy
#                              || / _----=> hardirq/softirq
#                              ||| / _---=> preempt-depth
#                              |||| / _--=> preempt-lazy-depth
#                              ||||| / _-=> migrate-disable
#                              |||||| /     delay
#           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
#              | |         |   |||||||      |         |
     kworker/3:1-48      [003] .......  1270.605347: rtcpu_string: tstamp:40374326286 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-2628    [000] .......  1295.603268: tegra_channel_open: vi-output, atto640 9-0055
        v4l2-ctl-2628    [003] .......  1295.614929: tegra_channel_set_power: atto640 9-0055 : 0x1
        v4l2-ctl-2628    [003] .......  1295.615000: camera_common_s_power: status : 0x1
        v4l2-ctl-2628    [003] .......  1295.615006: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-2628    [003] .......  1295.615008: csi_s_power: enable : 0x1
        v4l2-ctl-2628    [003] .......  1295.615612: tegra_channel_capture_setup: vnc_id 0 W 1280 H 480 fmt 5
 vi-output, atto-2629    [000] .......  1295.624419: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:2629 tid:2629
 vi-output, atto-2629    [000] .......  1295.624430: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:2629 tid:2629
 vi-output, atto-2629    [000] .......  1295.624431: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:2629 tid:2629
 vi-output, atto-2629    [000] .......  1295.624432: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:2629 tid:2629
        v4l2-ctl-2628    [003] .......  1295.624587: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-2628    [003] .......  1295.625984: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-2628    [003] .......  1295.625986: csi_s_stream: enable : 0x1
        v4l2-ctl-2628    [003] .......  1295.626285: tegra_channel_set_stream: atto640 9-0055 : 0x1
     kworker/3:1-48      [003] .......  1295.653336: rtcpu_string: tstamp:41156696718 id:0x04010000 str:"VM0 activating."
     kworker/3:1-48      [003] .......  1295.653341: rtcpu_vinotify_event: tstamp:41157216613 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1317020441824 data:0x799d580010000000
     kworker/3:1-48      [003] .......  1295.653341: rtcpu_vinotify_event: tstamp:41157216752 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1317020448224 data:0x0000000031000001
     kworker/3:1-48      [003] .......  1295.653341: rtcpu_vinotify_event: tstamp:41157216906 cch:0 vi:0 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:1317020451232 data:0x0000000007020001
     kworker/3:1-48      [003] .......  1295.653342: rtcpu_vinotify_event: tstamp:41157217040 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1317020493472 data:0x799d550010000000
     kworker/3:1-48      [003] .......  1295.653342: rtcpu_vinotify_event: tstamp:41157217191 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1317020500000 data:0x0000000031000002
     kworker/3:1-48      [003] .......  1296.717559: rtcpu_nvcsi_intr: tstamp:41190182072 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x10000000
...
     kworker/3:1-48      [003] .......  1296.717578: rtcpu_nvcsi_intr: tstamp:41190232058 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x10000000

This camera worked just fine on Xavier NX, and we know the orin carrier is good since the IMX219 work at much higher frequencies, so why does the RCE trace indicate a potential MIPI signaling issue? Does orin have tighter mipi csi signaling requirements that may not be met by our soft mipi fpga IP?

Bit 28 of this error code seems to be INTR_CIL_DATA_LANE_CONTROL_ERR which would indicate an illegal mipi-csi state during the initial handshake, did the behaviour of this part of the PHY change between xavier and orin?

I did attempt to change the settle time in the DTS from auto (0) to a manual value (33) without any clear change.

Or is it maybe like on Xavier where some type of CRC checking is active? on Xavier we needed a custom RTCPU firmware image supplied by nvidia to disable it, could it be the source of the issue here as well?

I have attached the relevant DTS, as well as the old DTS of our xavier platform.

dtsi1.zip (9.2 KB)

2

*** Please note that this reply is generated by LLM automatically ***

The issue you’re experiencing with your custom GREY8 1280x480 output camera on the Jetson Orin NX module seems to be related to MIPI CSI signaling. The RCE logs indicate a potential MIPI signaling issue, and the error code suggests an illegal MIPI CSI state during the initial handshake.

Comparing the behavior of the MIPI CSI PHY between Xavier and Orin, it’s possible that the Orin module has tighter MIPI CSI signaling requirements that may not be met by your soft MIPI FPGA IP. The Orin module’s MIPI CSI PHY may be more sensitive to signal quality, timing, or other parameters that affect the signaling.

One possible cause of the issue is the settle time in the DTS. You’ve tried changing the settle time from auto (0) to a manual value (33), but it didn’t seem to make a difference. However, it’s worth exploring other values or configurations for the settle time to see if it resolves the issue.

Another possibility is that the Orin module has CRC checking enabled on the MIPI CSI interface, similar to the Xavier module. On Xavier, you needed a custom RTCPU firmware image supplied by NVIDIA to disable CRC checking. It’s possible that a similar issue is occurring on the Orin module, and you may need to obtain a custom firmware image or modify the existing one to disable CRC checking.

To troubleshoot the issue further, you can try the following:

  1. Verify the MIPI CSI signal quality: Use a logic analyzer or an oscilloscope to verify that the MIPI CSI signals are within the specified limits for voltage, timing, and signal integrity.
  2. Check the FPGA IP configuration: Review the configuration of your soft MIPI FPGA IP to ensure that it’s set up correctly for the Orin module’s MIPI CSI interface.
  3. Experiment with different settle times: Try different values for the settle time in the DTS to see if it resolves the issue.
  4. Investigate CRC checking: Research whether CRC checking is enabled on the Orin module’s MIPI CSI interface and whether it can be disabled through a custom firmware image or other means.

In comparison to the IMX219 camera, which works fine on the same carrier board, the issue with the custom GREY8 camera may be related to the specific requirements of the MIPI CSI interface on the Orin module. The IMX219 camera may be more tolerant of signal quality or timing issues, while the custom GREY8 camera may be more sensitive to these parameters.

Overall, the issue seems to be related to the MIPI CSI signaling on the Orin module, and further investigation is needed to determine the root cause and find a solution.

*** Please give the thumbs up if you get answers you like. Or provide feedback to help us improve the answer. ***

4

Confirm the pix_clk_hz/serdes_pix_clk_hz to make sure the output data rate less than 1.5G

Skew calibration is required if sensor or deserializer is using DPHY, and the output data rate is > 1.5Gbps.
An initiation deskew signal should be sent by sensor or deserializer to perform the skew calibration. If the deskew signals is not sent, the receiver will stall, and the capture will time out.
You can calculate the output data rate with the following equation:

Output data rate = (sensor or deserializer pixel clock in hertz) * (bits per pixel) / (number of CSI lanes)
5

On the camera side we’re running 1280x480x8bpp @60hz so that is:
614,400 pixels * 8 = 4,915,200 bits per frame
4,915,200 * 60 = 294,912,000 bits per second = 0.294Gbps / 2 lanes = 0.147 Gbps/lane

So our frequency is far, far too low for link training to actually be required?

Actually the link training might be getting triggered because the serializer clocks i specified in the DTS are overkill for this sensor, i’ll try lowering them so it doesn’t trigger training.

6

It matter with the serdes_pix_clk_hz/pix_clk_hz in your device tree doesn’t matter with sensor real output data rate.

7

Yes, after recalculating the values to something lower than the 1.5Gbps limit, i’m getting correctable errors now:

     kworker/2:3-552     [002] .......   146.321181: rtcpu_nvcsi_intr: tstamp:5206133602 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:3-552     [002] .......   146.321182: rtcpu_nvcsi_intr: tstamp:5206135752 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:3-552     [002] .......   146.321182: rtcpu_nvcsi_intr: tstamp:5206135752 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004

Since we don’t output valid CRC, could this be related? I’ll have to check our “black box” fpga ip for mipi in more detail, as of now the serializer input clock appears to be 200Mhz

the DTS was updated to these clock values:

                           mclk_khz = "24000";
                            num_lanes = "2";
                            tegra_sinterface = "serial_c";
                            phy_mode = "DPHY";
                            discontinuous_clk = "yes";
                            dpcm_enable = "false";
                            cil_settletime = "0";
                            lane_polarity = "0";

                            active_w = "1280";
                            active_h = "480";
                            mode_type = "gray";
                            pixel_phase = "gray";
                            csi_pixel_bit_depth = "8";
                            pixel_t = "gray8";
                            readout_orientation = "90";
                            line_length = "2780";
                            inherent_gain = "1";
                            mclk_multiplier = "1.67";
                            pix_clk_hz = "40000000";

                            gain_factor = "1";
                            min_gain_val = "0";
                            max_gain_val = "64";
                            step_gain_val = "1";
                            default_gain = "1";
                            min_hdr_ratio = "1";
                            max_hdr_ratio = "1";

                            framerate_factor = "1000000";
                            min_framerate = "20000000";
                            max_framerate = "60000000";
                            step_framerate = "1";
                            default_framerate = "30000000";

                            exposure_factor = "1000000";
                            min_exp_time = "13";
                            max_exp_time = "683709";
                            step_exp_time = "1";
                            default_exp_time = "2495";
                            embedded_metadata_height = "0";
8

Yes, this error tell the CRC error.

9

On xavier we had to request a custom rtcpu image that disabled the CRC checking, is the situation the same on Orin?

10

Even with the CRC error some case still able to capture well.

Any error from the dmesg?

11

Letting it run for a bit longer we actually get clearer v4L2 sided errors:

v4l2-ctl -d /dev/video0 --set-fmt-video=width=1280,height=480,pixelformat=GREY --stream-mmap --stream-count=5
  65.523076] loop1: detected capacity change from 0 to 8
[   70.258604] atto640 12-0055: atto640_start_streaming: Successfully set ATTO640D SoS 
[   71.338979] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 350, flags: 0, err_data 4194402
[   71.372305] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 351, flags: 0, err_data 4194402
[   71.405639] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 352, flags: 0, err_data 4194402
[   71.438988] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 353, flags: 0, err_data 4194402
[   71.472337] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 354, flags: 0, err_data 4194402
[   71.505692] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 355, flags: 0, err_data 4194402
[   71.539032] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 356, flags: 0, err_data 4194402
[   71.572380] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 357, flags: 0, err_data 4194402
[   71.605739] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 358, flags: 0, err_data 4194402
[   71.639085] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 359, flags: 0, err_data 4194402
[   71.672437] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 360, flags: 0, err_data 4194402
[   71.705774] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 361, flags: 0, err_data 4194402
[   71.739138] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 362, flags: 0, err_data 4194402
[   71.772678] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 363, flags: 0, err_data 4194402
[   71.805846] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 364, flags: 0, err_data 4194402
[   71.839187] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 365, flags: 0, err_data 4194402
[   71.872526] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 366, flags: 0, err_data 4194402
[   71.905879] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 367, flags: 0, err_data 4194402
[   71.939227] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 368, flags: 0, err_data 4194402
[   71.972590] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 369, flags: 0, err_data 4194402
[   72.005930] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 370, flags: 0, err_data 4194402
[   72.039272] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 371, flags: 0, err_data 4194402
[   72.072624] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 372, flags: 0, err_data 4194402
[   72.105969] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 373, flags: 0, err_data 4194402
[   72.139318] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 374, flags: 0, err_data 4194402
[   72.172695] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 375, flags: 0, err_data 4194402
[   72.206025] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 376, flags: 0, err_data 4194402
[   72.239359] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 377, flags: 0, err_data 4194402
[   72.272739] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 378, flags: 0, err_data 4194402
[   72.306274] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 379, flags: 0, err_data 4194402
[   72.339406] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 380, flags: 0, err_data 4194402
[   72.373176] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 381, flags: 0, err_data 4194402
[   72.406116] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 382, flags: 0, err_data 4194402
[   72.406498] atto640 12-0055: atto640_stop_streaming: Successfully set ATTO640D EoS 
tegra@tegra-ubuntu:~$

Seems like it’s not happy about the amount of lines / word count / general mipi format we’re sending out.

12

Since we modify sensor_common.c, vi5_formats.h and camera_common.c to support GREY8, do you think that perhaps the pixel format could be causing these issues as well? I’ve attached our modified versions, on a high level we modified:

${KERNEL_OUT_DIR}/nvidia-oot/drivers/media/platform/tegra/camera/sensor_common.c

       if (strncmp(pixel_t, "gray8", size) == 0)
		*format = V4L2_PIX_FMT_GREY;
	else if (strncmp(pixel_t, "bayer_rggb8", size) == 0)
		*format = V4L2_PIX_FMT_SRGGB8;
	else `

${KERNEL_OUT_DIR}/nvidia-oot/drivers/media/platform/tegra/camera/vi/vi5_formats.h

TEGRA_VIDEO_FORMAT(RAW8, 8, Y8_1X8, 1, 1, T_R8,
				RAW8, GREY, "GREY"),

${KERNEL_OUT_DIR}/nvidia-oot/drivers/media/platform/tegra/camera/camera_common.c

{
		MEDIA_BUS_FMT_Y8_1X8,
		V4L2_COLORSPACE_SRGB,
		V4L2_PIX_FMT_GREY,
},

grey.zip (12.6 KB)

13

Looking into rtcpu log we seem to be hitting a CHANSEL fault as well for some reason:

root@tegra-ubuntu:~# cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 21555/21555   #P:4
#
#                                _-------=> irqs-off
#                               / _------=> need-resched
#                              | / _-----=> need-resched-lazy
#                              || / _----=> hardirq/softirq
#                              ||| / _---=> preempt-depth
#                              |||| / _--=> preempt-lazy-depth
#                              ||||| / _-=> migrate-disable
#                              |||||| /     delay
#           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
#              | |         |   |||||||      |         |
     kworker/0:3-488     [000] .......    58.540771: rtcpu_string: tstamp:2461482033 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-3181    [000] .......    78.466271: tegra_channel_open: vi-output, atto640 12-0055
        v4l2-ctl-3181    [000] .......    78.476850: tegra_channel_set_power: atto640 12-0055 : 0x1
        v4l2-ctl-3181    [000] .......    78.476925: camera_common_s_power: status : 0x1
        v4l2-ctl-3181    [000] .......    78.476932: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3181    [000] .......    78.476934: csi_s_power: enable : 0x1
        v4l2-ctl-3181    [000] .......    78.477737: tegra_channel_capture_setup: vnc_id 0 W 640 H 480 fmt 5
 vi-output, atto-3182    [002] .......    78.486402: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
 vi-output, atto-3182    [002] .......    78.486410: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
 vi-output, atto-3182    [002] .......    78.486411: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
 vi-output, atto-3182    [002] .......    78.486412: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
        v4l2-ctl-3181    [000] .......    78.486584: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-3181    [000] .......    78.487217: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3181    [000] .......    78.487219: csi_s_stream: enable : 0x1
        v4l2-ctl-3181    [000] .......    78.487518: tegra_channel_set_stream: atto640 12-0055 : 0x1
     kworker/0:3-488     [000] .......    78.513014: rtcpu_string: tstamp:3086144793 id:0x04010000 str:"VM0 activating."
     kworker/0:3-488     [000] .......    78.513018: rtcpu_vinotify_event: tstamp:3086627281 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:98761587040 data:0x799e300010000000
     kworker/0:3-488     [000] .......    78.513019: rtcpu_vinotify_event: tstamp:3086627512 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:98761593472 data:0x0000000031000001
     kworker/0:3-488     [000] .......    78.513020: rtcpu_vinotify_event: tstamp:3086627669 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:98761596480 data:0x0000000007020001
     kworker/0:3-488     [000] .......    78.513020: rtcpu_vinotify_event: tstamp:3086627802 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:98761638752 data:0x799e2d0010000000
     kworker/0:3-488     [000] .......    78.513021: rtcpu_vinotify_event: tstamp:3086627955 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:98761645216 data:0x0000000031000002
 vi-output, atto-3183    [001] .......    79.502315: tegra_channel_capture_frame: sof:99.777040320
 vi-output, atto-3183    [001] .......    79.502318: tegra_channel_capture_frame: eof:99.777056096
 vi-output, atto-3182    [002] .......    79.502378: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
     kworker/0:3-488     [000] .......    79.524855: rtcpu_nvcsi_intr: tstamp:3118033506 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524858: rtcpu_nvcsi_intr: tstamp:3118033506 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524860: rtcpu_nvcsi_intr: tstamp:3118035048 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524860: rtcpu_nvcsi_intr: tstamp:3118035048 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524861: rtcpu_nvcsi_intr: tstamp:3118037190 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524862: rtcpu_nvcsi_intr: tstamp:3118037190 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524862: rtcpu_nvcsi_intr: tstamp:3118039341 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
...
     kworker/0:3-488     [000] .......    79.524877: rtcpu_nvcsi_intr: tstamp:3118062990 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524877: rtcpu_nvcsi_intr: tstamp:3118065178 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524878: rtcpu_nvcsi_intr: tstamp:3118065178 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524881: rtcpu_vinotify_event: tstamp:3118065814 cch:0 vi:1 tag:FS channel:0x00 frame:1 vi_tstamp:99777037888 data:0x0000000100000012
     kworker/0:3-488     [000] .......    79.524881: rtcpu_vinotify_event: tstamp:3118065974 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:99777037888 data:0x0000000800000000
     kworker/0:3-488     [000] .......    79.524882: rtcpu_vinotify_event: tstamp:3118066110 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:1 vi_tstamp:99777040320 data:0x0000000000000001
     kworker/0:3-488     [000] .......    79.524883: rtcpu_vinotify_event: tstamp:3118066264 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:1 vi_tstamp:99777043680 data:0x0000000008020001
     kworker/0:3-488     [000] .......    79.524884: rtcpu_vinotify_event: tstamp:3118066399 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:1 vi_tstamp:99777046560 data:0x0000000000000100
     kworker/0:3-488     [000] .......    79.524884: rtcpu_vinotify_event: tstamp:3118066552 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:1 vi_tstamp:99777056320 data:0x0000000001020001
     kworker/0:3-488     [000] .......    79.524885: rtcpu_nvcsi_intr: tstamp:3118067290 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524886: rtcpu_nvcsi_intr: tstamp:3118067290 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.524886: rtcpu_nvcsi_intr: tstamp:3118069441 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
...
     kworker/0:3-488     [000] .......    79.525186: rtcpu_nvcsi_intr: tstamp:3118746679 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.525186: rtcpu_nvcsi_intr: tstamp:3118746679 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
 vi-output, atto-3183    [001] .......    79.535444: tegra_channel_capture_frame: sof:99.810389152
 vi-output, atto-3183    [001] .......    79.535446: tegra_channel_capture_frame: eof:99.810402784
 vi-output, atto-3182    [001] .......    79.535484: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
 vi-output, atto-3183    [001] .......    79.568790: tegra_channel_capture_frame: sof:99.843737984
 vi-output, atto-3183    [001] .......    79.568792: tegra_channel_capture_frame: eof:99.843754976
 vi-output, atto-3182    [000] .......    79.568873: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:0 pid:3182 tid:3182
     kworker/0:3-488     [000] .......    79.580844: rtcpu_nvcsi_intr: tstamp:3118748829 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.580845: rtcpu_nvcsi_intr: tstamp:3118748829 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
...
     kworker/0:3-488     [000] .......    79.580999: rtcpu_nvcsi_intr: tstamp:3119062724 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581000: rtcpu_nvcsi_intr: tstamp:3119062724 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581001: rtcpu_vinotify_error: tstamp:3119064135 cch:0 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:99810007680 data:0x0000000100400062
     kworker/0:3-488     [000] .......    79.581002: rtcpu_vinotify_event: tstamp:3119064690 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:1 vi_tstamp:99809998976 data:0x0000000001df0182
     kworker/0:3-488     [000] .......    79.581003: rtcpu_vinotify_event: tstamp:3119064844 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:1 vi_tstamp:99809999488 data:0x0000000000000000
     kworker/0:3-488     [000] .......    79.581003: rtcpu_vinotify_event: tstamp:3119064979 cch:0 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:99810007680 data:0x0000000100400062
     kworker/0:3-488     [000] .......    79.581004: rtcpu_vinotify_event: tstamp:3119065132 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:99810007680 data:0x0000000800000000
     kworker/0:3-488     [000] .......    79.581004: rtcpu_vinotify_event: tstamp:3119065267 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:99810013600 data:0x0000000007020002
     kworker/0:3-488     [000] .......    79.581005: rtcpu_nvcsi_intr: tstamp:3119075590 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581005: rtcpu_nvcsi_intr: tstamp:3119075590 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
...
   kworker/0:3-488     [000] .......    79.581120: rtcpu_nvcsi_intr: tstamp:3119380337 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581121: rtcpu_nvcsi_intr: tstamp:3119382487 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581121: rtcpu_nvcsi_intr: tstamp:3119382487 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581122: rtcpu_vinotify_event: tstamp:3119383698 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:99810036160 data:0x799e300010000000
     kworker/0:3-488     [000] .......    79.581122: rtcpu_vinotify_event: tstamp:3119383842 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:99810046720 data:0x0000000031000003
     kworker/0:3-488     [000] .......    79.581123: rtcpu_vinotify_event: tstamp:3119383995 cch:0 vi:1 tag:FS channel:0x00 frame:2 vi_tstamp:99810386720 data:0x0000000200000012
     kworker/0:3-488     [000] .......    79.581124: rtcpu_vinotify_event: tstamp:3119384131 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:99810386720 data:0x0000000800000000
     kworker/0:3-488     [000] .......    79.581125: rtcpu_vinotify_event: tstamp:3119384284 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:2 vi_tstamp:99810389152 data:0x0000000000000001
     kworker/0:3-488     [000] .......    79.581125: rtcpu_vinotify_event: tstamp:3119384446 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:2 vi_tstamp:99810392480 data:0x0000000008020002
     kworker/0:3-488     [000] .......    79.581126: rtcpu_vinotify_event: tstamp:3119385136 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:2 vi_tstamp:99810395392 data:0x0000000000000100
     kworker/0:3-488     [000] .......    79.581126: rtcpu_nvcsi_intr: tstamp:3119384634 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581126: rtcpu_nvcsi_intr: tstamp:3119384634 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581127: rtcpu_vinotify_event: tstamp:3119385276 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:2 vi_tstamp:99810403008 data:0x0000000001020002
     kworker/0:3-488     [000] .......    79.581127: rtcpu_nvcsi_intr: tstamp:3119386788 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:3-488     [000] .......    79.581128: rtcpu_nvcsi_intr: tstamp:3119386788 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
...
     kworker/0:1-47      [000] .......    80.265153: rtcpu_nvcsi_intr: tstamp:3140975267 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:1-47      [000] .......    80.265153: rtcpu_nvcsi_intr: tstamp:3140977413 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:1-47      [000] .......    80.265154: rtcpu_nvcsi_intr: tstamp:3140977413 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/0:1-47      [000] .......    80.265154: rtcpu_vinotify_error: tstamp:3141009887 cch:-1 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:23 vi_tstamp:100511994976 data:0x0000000000000122
     kworker/0:1-47      [000] .......    80.265155: rtcpu_vinotify_event: tstamp:3141255222 cch:-1 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:100510340320 data:0x0000000007020017
     kworker/0:1-47      [000] .......    80.265155: rtcpu_vinotify_event: tstamp:3141255442 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:100510350400 data:0x799e2d0010000000
     kworker/0:1-47      [000] .......    80.265155: rtcpu_vinotify_event: tstamp:3141255700 cch:-1 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:100510369568 data:0x0000000031000018
     kworker/0:1-47      [000] .......    80.265156: rtcpu_vinotify_event: tstamp:3141255926 cch:-1 vi:1 tag:FS channel:0x00 frame:23 vi_tstamp:100510712320 data:0x0000001700000012
     kworker/0:1-47      [000] .......    80.265156: rtcpu_vinotify_event: tstamp:3141256184 cch:-1 vi:1 tag:ATOMP_FS channel:0x00 frame:23 vi_tstamp:100510712320 data:0x0000000800000000
     kworker/0:1-47      [000] .......    80.265157: rtcpu_vinotify_event: tstamp:3141256407 cch:-1 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:23 vi_tstamp:100510714720 data:0x0000000000000001
     kworker/0:1-47      [000] .......    80.265157: rtcpu_vinotify_event: tstamp:3141256661 cch:-1 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:23 vi_tstamp:100510718080 data:0x0000000008020017
     kworker/0:1-47      [000] .......    80.265157: rtcpu_vinotify_event: tstamp:3141256883 cch:-1 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:23 vi_tstamp:100510720992 data:0x0000000000000100
     kworker/0:1-47      [000] .......    80.265158: rtcpu_vinotify_event: tstamp:3141257134 cch:-1 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:23 vi_tstamp:100510728576 data:0x0000000001020017
     kworker/0:1-47      [000] .......    80.265158: rtcpu_vinotify_event: tstamp:3141257354 cch:-1 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:23 vi_tstamp:100511994976 data:0x0000000000000122
     kworker/0:1-47      [000] .......    80.265159: rtcpu_vinotify_event: tstamp:3141257609 cch:-1 vi:1 tag:CHANSEL_SHORT_FRAME channel:0x04 frame:23 vi_tstamp:100511994976 data:0x0009200001000000
     kworker/0:1-47      [000] .......    80.265159: rtcpu_vinotify_event: tstamp:3141257828 cch:-1 vi:1 tag:ATOMP_FE channel:0x00 frame:23 vi_tstamp:100511995008 data:0x0000000800000000
     kworker/0:1-47      [000] .......    86.355977: rtcpu_string: tstamp:3331847435 id:0x04010000 str:"VM0 deactivating."
14

It says the PIXEL_RUNAWAY boost the clocks to try.

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
15

Boosting the clocks doesn’t seem to help in this particular case?

gra-ubuntu:~$ sudo su
[sudo] password for tegra: 
root@tegra-ubuntu:/home/tegra# 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
832000000
1011200000
642900000
3199000000
root@tegra-ubuntu:/home/tegra# v4l2-ctl -d /dev/video0 --set-fmt-video=width=1280,height=480,pixelformat=GREY --stream-mmap --stream-count=5
^C
root@tegra-ubuntu:/home/tegra# ^C
root@tegra-ubuntu:/home/tegra# sudo tail dmesg
tail: cannot open 'dmesg' for reading: No such file or directory
root@tegra-ubuntu:/home/tegra# sudo dmesg | tail
[  231.608439] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 106, flags: 0, err_data 256
[  231.641997] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 107, flags: 0, err_data 256
[  231.675159] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 108, flags: 0, err_data 256
[  231.708495] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 109, flags: 0, err_data 256
[  231.742238] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 110, flags: 0, err_data 256
[  231.775186] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 111, flags: 0, err_data 256
[  231.808535] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 112, flags: 0, err_data 256
[  231.842084] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 113, flags: 0, err_data 256
[  231.875243] tegra-camrtc-capture-vi tegra-capture-vi: corr_err: discarding frame 114, flags: 0, err_data 256
[  231.875631] atto640 12-0055: atto640_stop_streaming: Successfully set ATTO640D EoS 
root@tegra-ubuntu:/home/tegra# 
root@tegra-ubuntu:/home/tegra# modprobe rtcpu_debug
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
export enableCamPclLogs=5
export enableCamScfLogs=5
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
832000000
1011200000
642900000
root@tegra-ubuntu:/home/tegra# v4l2-ctl -d /dev/video0 --stream-mmap --stream-count=5
^C
root@tegra-ubuntu:/home/tegra# cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 22515/22515   #P:4
#
#                                _-------=> irqs-off
#                               / _------=> need-resched
#                              | / _-----=> need-resched-lazy
#                              || / _----=> hardirq/softirq
#                              ||| / _---=> preempt-depth
#                              |||| / _--=> preempt-lazy-depth
#                              ||||| / _-=> migrate-disable
#                              |||||| /     delay
#           TASK-PID     CPU#  |||||||  TIMESTAMP  FUNCTION
#              | |         |   |||||||      |         |
     kworker/2:0-26      [002] .......  3839.499135: rtcpu_dbg_set_loglevel: tstamp:120650942273 old:0 new:2
     kworker/2:0-26      [002] .......  3845.603474: rtcpu_string: tstamp:120843154419 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-2842    [003] .......  3855.639288: tegra_channel_open: vi-output, atto640 12-0055
        v4l2-ctl-2842    [003] .......  3855.650621: tegra_channel_set_power: atto640 12-0055 : 0x1
        v4l2-ctl-2842    [003] .......  3855.650692: camera_common_s_power: status : 0x1
        v4l2-ctl-2842    [003] .......  3855.650698: tegra_channel_set_power: 13e00000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-2842    [003] .......  3855.650699: csi_s_power: enable : 0x1
        v4l2-ctl-2842    [003] .......  3855.651841: tegra_channel_capture_setup: vnc_id 0 W 640 H 480 fmt 5
 vi-output, atto-2843    [001] .......  3855.659266: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:456 pid:2843 tid:2843
 vi-output, atto-2843    [001] .......  3855.659274: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:456 pid:2843 tid:2843
 vi-output, atto-2843    [001] .......  3855.659275: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:456 pid:2843 tid:2843
 vi-output, atto-2843    [001] .......  3855.659276: vi_task_submit: class_id:48 ch:0 syncpt_id:36 syncpt_thresh:456 pid:2843 tid:2843
        v4l2-ctl-2842    [003] .......  3855.659301: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-2842    [003] .......  3855.659900: tegra_channel_set_stream: 13e00000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-2842    [003] .......  3855.659901: csi_s_stream: enable : 0x1
        v4l2-ctl-2842    [003] .......  3855.660199: tegra_channel_set_stream: atto640 12-0055 : 0x1
     kworker/2:0-26      [002] .......  3855.683115: rtcpu_string: tstamp:121157398720 id:0x04010000 str:"VM0 activating."
     kworker/2:0-26      [002] .......  3855.683120: rtcpu_vinotify_event: tstamp:121157857548 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3877040946112 data:0x799e300010000000
     kworker/2:0-26      [002] .......  3855.683121: rtcpu_vinotify_event: tstamp:121157857687 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3877040952928 data:0x0000000031000001
     kworker/2:0-26      [002] .......  3855.683122: rtcpu_vinotify_event: tstamp:121157857842 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:3877040955968 data:0x0000000007020001
     kworker/2:0-26      [002] .......  3855.683122: rtcpu_vinotify_event: tstamp:121157857976 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3877041003104 data:0x799e2d0010000000
     kworker/2:0-26      [002] .......  3855.683123: rtcpu_vinotify_event: tstamp:121157858129 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:3877041009600 data:0x0000000031000002
     kworker/2:0-26      [002] .......  3856.691106: rtcpu_nvcsi_intr: tstamp:121189253575 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691110: rtcpu_nvcsi_intr: tstamp:121189253575 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691111: rtcpu_nvcsi_intr: tstamp:121189255801 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691112: rtcpu_nvcsi_intr: tstamp:121189255801 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691112: rtcpu_nvcsi_intr: tstamp:121189258029 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691113: rtcpu_nvcsi_intr: tstamp:121189258029 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691114: rtcpu_nvcsi_intr: tstamp:121189260258 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691115: rtcpu_nvcsi_intr: tstamp:121189260258 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691116: rtcpu_nvcsi_intr: tstamp:121189262485 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691117: rtcpu_nvcsi_intr: tstamp:121189262485 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691117: rtcpu_nvcsi_intr: tstamp:121189264712 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691118: rtcpu_nvcsi_intr: tstamp:121189264712 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691119: rtcpu_nvcsi_intr: tstamp:121189266940 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691120: rtcpu_nvcsi_intr: tstamp:121189266940 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691121: rtcpu_nvcsi_intr: tstamp:121189269161 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691122: rtcpu_nvcsi_intr: tstamp:121189269161 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3856.691123: rtcpu_nvcsi_intr: tstamp:121189271366 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004

Since the camera worked perfectly on xavier i wouldn’t excpect it to be the source of the issue unless something deeply changed between xavier and orin on the mipi d-phy side.

16

At least I don’t see the CHANNEL_FAULT after boost the clocks.

17

Looking at the longer trace it definitely still happens, but may not be the initial failure cause…

     kworker/2:0-26      [002] .......  3857.483352: rtcpu_nvcsi_intr: tstamp:121213198755 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483353: rtcpu_nvcsi_intr: tstamp:121213200905 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483353: rtcpu_nvcsi_intr: tstamp:121213200905 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483354: rtcpu_nvcsi_intr: tstamp:121213203056 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483354: rtcpu_nvcsi_intr: tstamp:121213203056 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483354: rtcpu_nvcsi_intr: tstamp:121213205206 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483355: rtcpu_nvcsi_intr: tstamp:121213205206 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483355: rtcpu_nvcsi_intr: tstamp:121213207356 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483356: rtcpu_nvcsi_intr: tstamp:121213207356 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483356: rtcpu_nvcsi_intr: tstamp:121213209506 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483356: rtcpu_nvcsi_intr: tstamp:121213209506 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483357: rtcpu_nvcsi_intr: tstamp:121213211656 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483357: rtcpu_nvcsi_intr: tstamp:121213211656 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483359: rtcpu_vinotify_error: tstamp:121213212889 cch:0 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:136 vi_tstamp:3878822773440 data:0x0000008800400062
     kworker/2:0-26      [002] .......  3857.483360: rtcpu_vinotify_event: tstamp:121213213434 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:136 vi_tstamp:3878822764736 data:0x0000000001df0182
     kworker/2:0-26      [002] .......  3857.483361: rtcpu_vinotify_event: tstamp:121213213570 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:136 vi_tstamp:3878822765248 data:0x0000000000000000
     kworker/2:0-26      [002] .......  3857.483361: rtcpu_vinotify_event: tstamp:121213213724 cch:0 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:136 vi_tstamp:3878822773440 data:0x0000008800400062
     kworker/2:0-26      [002] .......  3857.483362: rtcpu_vinotify_event: tstamp:121213213860 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:136 vi_tstamp:3878822773440 data:0x0000000800000000
     kworker/2:0-26      [002] .......  3857.483362: rtcpu_nvcsi_intr: tstamp:121213224523 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483363: rtcpu_nvcsi_intr: tstamp:121213224523 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483364: rtcpu_nvcsi_intr: tstamp:121213226115 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483364: rtcpu_nvcsi_intr: tstamp:121213226115 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483365: rtcpu_nvcsi_intr: tstamp:121213228273 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483365: rtcpu_nvcsi_intr: tstamp:121213228273 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483366: rtcpu_nvcsi_intr: tstamp:121213230422 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483366: rtcpu_nvcsi_intr: tstamp:121213230422 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483367: rtcpu_nvcsi_intr: tstamp:121213232571 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483367: rtcpu_nvcsi_intr: tstamp:121213232571 class:CORRECTABLE_ERR type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004
     kworker/2:0-26      [002] .......  3857.483368: rtcpu_nvcsi_intr: tstamp:121213234721 class:GLOBAL type:STREAM_VC phy:0 cil:0 st:2 vc:0 status:0x00000004

attached the actual full trace, + boot log.
tmplog.zip (152.7 KB)

Since only one out of 4 camera devices are wired the few driver errors at boot for the other 3 are excpected, but we’re certain at this point that camera ↔ orin communication works, and that mipi TX begins.

18

Here’s the CHANNEL_FAULT error bit map.

CHANSEL_FAULT data bit field
    bit 16:31  LINE_NUMBER
    bit 15	DTYPE_MISMATCH
    bit 14	EMBED_INFRINGE
    bit 13	EMBED_LONG_LINE
    bit 12	EMBED_SPURIOUS
    bit 11	EMBED_RUNAWAY
    bit 10	EMBED_MISSING_LE
    bit 9	PIXEL_SHORT_LINE
    bit 8	PIXEL_LONG_LINE
    bit 7	PIXEL_SPURIOUS
    bit 6	PIXEL_RUNAWAY
    bit 5	PIXEL_MISSING_LE
    bit 4	PIXEL_LINE_TIMER
    bit 3	EMBED_EOF
    bit 2	EMBED_SOF
    bit 1	PIXEL_EOF
    bit 0	PIXEL_SOF
19

We’ve run many tests at this point over multiple test points such as CIL settle time, frequency, and the only behaviour that seems to come back every single time as an issue is the CRC, are you sure it would work even with all the CRC errors coming out of the VI?

I’ve attached our 0 → 128 CIL settle time test logs should they provide any value to figure this out… is there no way to disable the CRC as we did on xavier?

Since we don’t send out the 2 byte CRC, it feels like the orin is mostly seeing
| 18424 | NVCSI_ERR_WC_SHORT |
as the main issue, causing the further crashes. The other errors seem more spurious and only occur after many lines / frames attempt, we mostly get runaway pixel errors along with the CRC ones…
results_cil.zip (16.0 MB)

20

In our case, CIL 48 yielded the least amount of errors, it seems to be the minimum CIL that will be stable with our cameras besides autocalc (0).

 CIL | NVCSI Error Signatures (Count) | VI Chansel Signatures (Count) |
|---|---|---|
| 0 | **3837x** `CRC_ERR` | **479x** `L64:RUNAWAY|MISSING_LE|EOF` |
| 12 | **130145x** `SOT_MBIT`<br>**130144x** `SOT_SYNC`<br>**120824x** `NONE`<br>**38976x** `SOT_MBIT|SP_SYNC`<br>**38976x** `SOT_SYNC|SP_SYNC`<br>**596x** `CRC_ERR`<br>**328x** `SOT_MBIT|CRC_ERR`<br>**328x** `SOT_SYNC|CRC_ERR`<br>**200x** `SP_SYNC|CRC_ERR`<br>**1x** `SOT_MBIT|SP_SYNC|CRC_ERR`<br>**1x** `SOT_SYNC|SP_SYNC|CRC_ERR` | NONE |
| 14 | **194657x** `SOT_MBIT`<br>**194656x** `SOT_SYNC`<br>**38872x** `SOT_MBIT|SP_SYNC`<br>**38872x** `SOT_SYNC|SP_SYNC`<br>**818x** `CRC_ERR`<br>**184x** `SP_SYNC|CRC_ERR`<br>**2x** `SOT_MBIT|CRC_ERR`<br>**2x** `SOT_SYNC|CRC_ERR` | NONE |
| 16 | **184499x** `SOT_MBIT`<br>**184498x** `SOT_SYNC`<br>**44365x** `SOT_MBIT|SP_SYNC`<br>**44365x** `SOT_SYNC|SP_SYNC`<br>**894x** `CRC_ERR`<br>**238x** `SP_SYNC|CRC_ERR`<br>**2x** `SOT_MBIT|CRC_ERR`<br>**2x** `SOT_SYNC|CRC_ERR`<br>**2x** `SOT_MBIT|SP_SYNC|CRC_ERR`<br>**2x** `SOT_SYNC|SP_SYNC|CRC_ERR` | NONE |
| 18 | **228193x** `SOT_MBIT|SP_SYNC`<br>**228193x** `SOT_SYNC|SP_SYNC`<br>**872x** `SP_SYNC|CRC_ERR`<br>**789x** `SOT_MBIT`<br>**789x** `SOT_SYNC`<br>**744x** `NONE`<br>**9x** `SOT_MBIT|SP_SYNC|CRC_ERR`<br>**9x** `SOT_SYNC|SP_SYNC|CRC_ERR`<br>**4x** `CRC_ERR`<br>**2x** `SOT_MBIT|CRC_ERR`<br>**2x** `SOT_SYNC|CRC_ERR` | NONE |
| 20 | **187048x** `SOT_MBIT`<br>**187048x** `SOT_SYNC`<br>**41952x** `SOT_MBIT|SP_SYNC`<br>**41952x** `SOT_SYNC|SP_SYNC`<br>**1576x** `CRC_ERR`<br>**376x** `SP_SYNC|CRC_ERR`<br>**4x** `SOT_MBIT|CRC_ERR`<br>**4x** `SOT_SYNC|CRC_ERR`<br>**2x** `SOT_MBIT|SP_SYNC|CRC_ERR`<br>**2x** `SOT_SYNC|SP_SYNC|CRC_ERR` | NONE |
| 32 | **187080x** `SOT_MBIT`<br>**187079x** `SOT_SYNC`<br>**43815x** `SOT_MBIT|SP_SYNC`<br>**43815x** `SOT_SYNC|SP_SYNC` | NONE |
| 48 | **18424x** `CRC_ERR`<br>**18392x** `SP_SYNC|CRC_ERR` | NONE |
| 64 | **3822x** `CRC_ERR` | **479x** `L64:RUNAWAY|MISSING_LE|EOF` |
| 80 | **3790x** `CRC_ERR` | **477x** `L64:RUNAWAY|MISSING_LE|EOF` |
| 96 | **3890x** `CRC_ERR` | **490x** `L64:RUNAWAY|MISSING_LE|EOF` |
| 112 | **3823x** `CRC_ERR` | **480x** `L64:RUNAWAY|MISSING_LE|EOF` |
| 128 | **3872x** `CRC_ERR` | **486x** `L64:RUNAWAY|MISSING_LE|EOF` |

The DTS clocks have been increased since the old ones were indeed too low, triggering CHANSEL_FAULT errors.

21

This is our current DTS at CIL 48 and 100M pixclk
orinnx_atom_kx-quad.zip (1.9 KB)

This ends up being the same timing value that worked on Xavier.

Critically as you’ll see on the CIL=48 test log, we get no visible errors besides the CRC ones, no CHANSEL for instance.

We recalculated our D-phy timings on the fpga side, they’re marginal in some parts, but should still go through at these scales:

| Parameter         | Localparam       | Cycles | Actual Time | D-PHY 1.2 Minimum (@ 400 Mbps)          | Status        |
|-------------------|------------------|--------|-------------|-----------------------------------------|---------------|
| `t_lpx`           | t_lpx_i          | 3      | 60 ns       | 50 ns                                   | OK            |
| `t_clk_prepare`   | t_clk_prepare_i  | 2      | 40 ns       | 38 ns                                   | OK (marginal) |
| `t_hs_prepare`    | t_hs_prepare_i   | 3      | 60 ns       | 40 ns + 4×UI = 50 ns                    | OK            |
| `t_clk_zero`      | t_clk_zero_i     | 39     | 780 ns      | 300 ns − t_clk_prepare = 260 ns         | OK (excess)   |
| `t_hs_zero`       | t_hs_zero_i      | 18     | 360 ns      | 145 ns + 10×UI − t_hs_prepare = 110 ns  | OK (excess)   |
| `t_clk_trail`     | t_clk_trail_i    | 3      | 60 ns       | 60 ns                                   | OK (exact)    |
| `t_hs_trail`      | t_hs_trail_i     | 4      | 80 ns       | max(8×UI, 60 ns + 4×UI) = 70 ns         | OK            |
| `t_clk_pre`       | t_clk_pre_i      | 1      | 20 ns       | 8×UI = 20 ns                            | OK (exact)    |
| `t_clk_post`      | t_clk_post_i     | 10     | 200 ns      | 60 ns + 52×UI = 190 ns                  | OK (marginal) |
| `t_wakeup`        | t_wakeup_i       | 50500  | 1.01 ms     | 1 ms                                    | OK            |