Porting i2c camera driver 4.4->4.9

Hi,

I am in the process of porting a (working) driver from 4.4 (28.2.1) to 4.9(32.4.3) for the ov5640
It is already in a good shape, the devicetree modifications are done, the driver modifications are done
i have 2 variants of the driver types v1.0 and 2.0, they both deliver the same results.
There is also a tc358748 in the system, this driver is working and is type v1.0.

However, the csi reports errors, which i do not know how to read.
Can someone help me out how to read/decode the csi errors/logs (below) ?

command used to run:

gst-launch-1.0 nvv4l2camerasrc device=${CURRENT_DEV} ! video/x-raw,width=640,height=480 ! nvvidconv !
filesink location=bla

output:

[ 17.093426] tc358748 8-000e: tc358748_open:
[ 17.097990] ov5640 2-003c: ov5640_open
[ 17.105094] tc358748 8-000e: tc358748_power_on
[ 17.109568] tc358748 8-000e: tc358748_write_table
[ 17.116004] tc358748 8-000e: tc358748_i2c_read
[ 17.120672] tc358748 8-000e: chipID=0x4401.
[ 17.125370] tc358748 8-000e: tc358748_power_off
[ 17.134291] ov5640 2-003c: ov5640_power_on: power on
[ 17.144607] ov5640 2-003c: ov5640_i2c_read
[ 17.148887] ov5640 2-003c: ov5640_i2c_read
[ 17.153167] ov5640 2-003c: chipID=0x5640.
[ 17.157216] ov5640 2-003c: ov5640_power_off
[ 17.219246] tc358748 8-000e: tc358748_open:
[ 17.223753] ov5640 2-003c: ov5640_open
[ 17.227723] tc358748 8-000e: tc358748_power_on
[ 17.232197] tc358748 8-000e: tc358748_write_table
[ 17.238154] tc358748 8-000e: tc358748_i2c_read
[ 17.242804] tc358748 8-000e: chipID=0x4401.
[ 17.247170] tc358748 8-000e: tc358748_power_off
[ 17.252364] ov5640 2-003c: ov5640_power_on: power on
[ 17.262714] ov5640 2-003c: ov5640_i2c_read
[ 17.267065] ov5640 2-003c: ov5640_i2c_read
[ 17.271449] ov5640 2-003c: chipID=0x5640.
[ 17.275502] ov5640 2-003c: ov5640_power_off
[ 17.298245] mods: driver opened
Setting pipeline to PAUSED …
[ 17.318834] ov5640 2-003c: ov5640_power_on: power on
[ 17.331215] ov5640 2-003c: ov5640_i2c_read
[ 17.335512] ov5640 2-003c: ov5640_i2c_read
[ 17.339840] ov5640 2-003c: chipID=0x5640.
Pipeline is live and does not need PREROLL …
Setting pipeline to PLAYING …
New clock: GstSystemClock
[ 17.349452] ov5640 2-003c: ov5640_set_mode mode 0
/GstPipeline:pipeline0/GstV4l2Src:v4l2src0.GstPad:src: caps = video/x-raw, width=(int)640, height=(int)480, framerate=(fraction)15/1, format=(string)UYVY, colorimetry=(string)2:4:7:1, interlace-mode=(string)progressive
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-raw, width=(int)640, height=(int)480, framerate=(fraction)15/1, format=(string)UYVY, colorimetry=(string)2:4:7:1, interlace-mode=(string)progressive
/GstPipeline:pipeline0/Gstnvvconv:nvvconv0.GstPad:src: caps = video/x-raw(memory:NVMM), width=(int)640, height=(int)480, framerate=(fraction)15/1, interlace-mode=(string)progressive, format=(string)UYVY
/GstPipeline:pipeline0/GstFileSink:filesink0.GstPad:sink: caps = video/x-raw(memory:NVMM), width=(int)640, height=(int)480, framerate=(fraction)15/1, interlace-mode=(string)progressive, format=(string)UYVY
/GstPipeline:pipeline0/Gstnvvconv:nvvconv0.GstPad:sink: caps = video/x-raw, width=(int)640, height=(int)480, framerate=(fraction)15/1, format=(string)UYVY, colorimetry=(string)2:4:7:1, interlace-mode=(string)progressive
/GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-raw, width=(int)640, height=(int)480, framerate=(fraction)15/1, format=(string)UYVY, colorimetry=(string)2:4:7:1, interlace-mode=(string)progressive
[ 17.427861] ov5640 2-003c: ov5640_start_streaming
[ 17.435856] ov5640 2-003c: ov5640_i2c_read
[ 17.442849] ov5640 2-003c: ov5640_i2c_read
[ 17.450473] ov5640 2-003c: REG_SYSTEM_RESET02 0x1c00
[ 17.458763] ov5640 2-003c: ov5640_i2c_read
[ 17.465812] ov5640 2-003c: ov5640_i2c_read
[ 17.473297] ov5640 2-003c: REG_SYSTEM_RESET03 0x00cf
[ 17.481485] ov5640 2-003c: ov5640_i2c_read
[ 17.487830] ov5640 2-003c: ov5640_i2c_read
[ 17.495408] ov5640 2-003c: REG_SYSTEM_CTROL0 0x4201
[ 17.504216] ov5640 2-003c: ov5640_i2c_read
[ 17.511480] ov5640 2-003c: ov5640_i2c_read
[ 17.518872] ov5640 2-003c: REG_SYSTEM_RESET02 0x1c01
[ 17.527115] ov5640 2-003c: ov5640_i2c_read
[ 17.533189] ov5640 2-003c: ov5640_i2c_read
[ 17.537461] ov5640 2-003c: REG_SYSTEM_RESET03 0x01cf
[ 17.542474] ov5640 2-003c: ov5640_i2c_read
[ 17.546941] ov5640 2-003c: ov5640_i2c_read
[ 17.551361] ov5640 2-003c: REG_SYSTEM_CTROL0 0x0201
[ 17.556250] (NULL device *): ov5640_show_setup
[ 17.761865] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 17.768327] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 17.778204] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 17.786956] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x00000002
[ 17.795675] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x00000002
[ 17.804385] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 17.813119] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001e22a
[ 17.820964] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001e22a
[ 18.029999] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 18.036483] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 18.046538] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 18.055281] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
[ 18.064008] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x00000002
[ 18.072723] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 18.081440] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001e2aa
[ 18.089280] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001e2aa
[ 18.297876] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 18.304408] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 18.315100] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 18.323960] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
[ 18.332770] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000a
[ 18.341588] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 18.350373] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001eaaa
[ 18.358264] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001eaaa
[ 18.569874] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 18.576331] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 18.586225] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 18.594966] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
[ 18.603701] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000a
[ 18.612412] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 18.621120] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001eaaa
[ 18.628960] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001eaaa
[ 18.837874] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 18.844327] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 18.854871] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 18.863601] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
[ 18.872308] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 18.881013] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 18.889724] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001eeaa
[ 18.897673] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001eeaa
^Chandling interrupt.
Interrupt: Stopping pipeline …
Execution ended after 0:00:01.620018656
Setting pipeline to PAUSED …
Setting pipeline to READY …
[ 19.109880] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[ 19.116348] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[ 19.126729] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 19.135470] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
[ 19.144208] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 19.153048] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 19.161885] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001aaaa
[ 19.169770] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001aaaa
^C[ 19.178522] tegra-ivc-vi-notify ivc-b000000.rtcpu:vinotify@12c0: no reply from camera processor
[ 19.187354] tegra-ivc-vi-notify ivc-b000000.rtcpu:vinotify@12c0: no reply from camera processor
[ 19.196661] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
[ 19.205468] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
[ 19.214290] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 19.223096] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
[ 19.231919] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001222a
[ 19.239805] nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001222a
[ 19.252641] ov5640 2-003c: ov5640_power_off
[ 19.257574] mods: driver closed

any help is appreciated
kind regards,
Ron

up to now i only have TEGRA_CAMERA_CID_SENSOR_MODE_ID in the ctrl_cid_list
could these errors occur if the set_frame_rate fnc is not implemented? (from the old ctrl_ops?)

Check the REG NVCSI_STREAM_4_ERROR_STATUS2VI_VC0_0 for the ERROR_STATUS2VI_VCx, that tell PH ECC single bit error and Packet Payload is less than WC in PH.

Have a check the trace log if can get more information.

kworker/4:1-56 [004] .... 1190.581757: rtcpu_vinotify_event: tstamp:37415094277 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:37415093888 data:0x00000100 SPURIOUS_DATA_STREAM_2, which reports that the next packet after a frame end was not a frame start

kworker/4:1-56 [004] … 1190.637752: rtcpu_vinotify_event: tstamp:37418095400 tag:CSIMUX_FRAME channel:0x64 frame:62536 vi_tstamp:37418095019 data:0x00000402
bit 0:2 STREAM_ID
bit 10 PXL_ENABLE_FAULT

kworker/4:1-56 [004] … 1193.529804: rtcpu_vinotify_event: tstamp:37507489498 tag:CSIMUX_FRAME channel:0x02 frame:14395 vi_tstamp:37507489112 data:0x00a00062
bit 5 FE_flag
bit 6 FE_CSI_FAULT
bit 21 PH single bit error repaired
bit 23 Line short error

kworker/4:1-56 [004] … 1192.793813: rtcpu_vinotify_event: tstamp:37485530353 tag:CHANSEL_SHORT_FRAME channel:0x04 frame:57530 vi_tstamp:37485528646 data:0x00000001
CHANSEL_SHORT_FRAME is the output active_h didn’t as expect. Make the the output size to modify the height in the kernel driver and active_h in DT.

kworker/4:1-56 [004] … 1192.739065: rtcpu_vinotify_event: tstamp:37483905072 tag:CHANSEL_LOAD_FRAMED channel:0x04 frame:57530 vi_tstamp:37483903548 data:0x08000000

kworker/4:1-56 [004] … 1194.089819: rtcpu_vinotify_event: tstamp:37523081391 tag:CHANSEL_FAULT channel:0x00 frame:57530 vi_tstamp:37523080878 data:0x00004004
trace.log (60.5 KB)

the active_h is set in the dt and is 480, is there a new definition in the dt associated with this, or is there something in the kernel driver that requires porting?

     snippet of dt 
mode0 { mclk_khz = "24000"; num_lanes = "1"; tegra_sinterface = "serial_c"; discontinuous_clk = "no"; dpcm_enable = "false"; cil_settletime = "0"; phy_mode = "DPHY";
            active_w = "640";
            active_h = "480";
            csi_pixel_bit_depth = "16";
            mode_type = "yuv";
            pixel_phase = "uyvy";
            readout_orientation = "0";
            line_length = "640";
            inherent_gain = "1";
            mclk_multiplier = "0.2";
            pix_clk_hz = "4608000";

            min_gain_val = "1.0";
            max_gain_val = "16";
            min_hdr_ratio = "1";
            max_hdr_ratio = "64";
            min_framerate = "1.0";
            max_framerate = "120";
            min_exp_time = "34";
            max_exp_time = "550385";
        };

The log show the CHANSEL_SHORT_FRAME that tell the sensor output line less than expect.
You can try to reduce the active_h one by one to try.
Also you can confirm the resolution by v4l2-ctl --list-formats-ext to confirm the dt modification.

~# v4l2-ctl --list-formats-ext -d /dev/video1

ioctl: VIDIOC_ENUM_FMT
Type: Video Capture
[0]: ‘UYVY’ (UYVY 4:2:2)
Size: Discrete 640x480
Interval: Discrete 0.067s (15.000 fps)
Size: Discrete 800x600
Interval: Discrete 0.067s (15.000 fps)
Size: Discrete 1066x800
Interval: Discrete 0.067s (15.000 fps)
[1]: ‘NV16’ (Y/CbCr 4:2:2)
Size: Discrete 640x480
Interval: Discrete 0.067s (15.000 fps)
Size: Discrete 800x600
Interval: Discrete 0.067s (15.000 fps)
Size: Discrete 1066x800
Interval: Discrete 0.067s (15.000 fps)
[2]: ‘UYVY’ (UYVY 4:2:2)
Size: Discrete 640x480
Interval: Discrete 0.067s (15.000 fps)
Size: Discrete 800x600
Interval: Discrete 0.067s (15.000 fps)
Size: Discrete 1066x800
Interval: Discrete 0.067s (15.000 fps)

hmm, we only want uyvy , why its there 2x, plus the CbCr is unknown to me

also in the previous logs

vi-output, ov56-1063 [005] … 759.163458: tegra_channel_capture_setup: vnc_id 0 W 640 H 480 fmt cb

tells me fmt cb is the wrong one.

That’s tells you driver have report incorrect format. You may need take time to review your driver or device tree.

removed the other fmt’s , now have the correct one, and only one
(so removed CbCr NV16 and UYVY_2x8)

same result, further digging required :)

Modify the driver to report less line to try.

these register settings of the camera are exactly the same as this driver with the 4.4 kernel, so the camera is OK. here are some of the timing regs of the cam

[ 21.555101] ov5640 2-003c: 0: REG16_TIMING_HS @ 0x3800 = 0x00
[ 21.561381] ov5640 2-003c: 1: REG16_TIMING_VS @ 0x3802 = 0x04
[ 21.567491] ov5640 2-003c: 2: REG16_TIMING_HW @ 0x3804 = 0xa3f
[ 21.573692] ov5640 2-003c: 3: REG16_TIMING_VH @ 0x3806 = 0x79b
[ 21.579879] ov5640 2-003c: 4: REG16_TIMING_DVPHO @ 0x3808 = 0x280
[ 21.586353] ov5640 2-003c: 5: REG16_TIMING_DVPVO @ 0x380a = 0x1e0
[ 21.593005] ov5640 2-003c: 6: REG16_TIMING_HTS @ 0x380c = 0x768
[ 21.599399] ov5640 2-003c: 7: REG16_TIMING_VTS @ 0x380e = 0x3d8
[ 21.605660] ov5640 2-003c: 8: REG16_TIMING_HOFFSET @ 0x3810 = 0x10
[ 21.612403] ov5640 2-003c: 9: REG16_TIMING_VOFFSET @ 0x3812 = 0x06
[ 21.619048] ov5640 2-003c: 10: REG16_HSYNC_START @ 0x3816 = 0x00
[ 21.625400] ov5640 2-003c: 11: REG16_HSYNC_WIDTH @ 0x3818 = 0x00
[ 21.631975] ov5640 2-003c: 12: REG16_CHIP_ID @ 0x300a = 0x5640
[ 21.638326] ov5640 2-003c: 13: REG16_MIN_HS_ZERO @ 0x4818 = 0x96
[ 21.644674] ov5640 2-003c: 14: REG16_MIN_MIPI_HS_TRAIL @ 0x481a = 0x3c
[ 21.651764] ov5640 2-003c: 15: REG16_MIN_MIPI_CLK_ZERO @ 0x481c = 0x186
[ 21.658839] ov5640 2-003c: 16: REG16_MIN_MIPI_CLK_PREPARE @ 0x481e = 0x3c
[ 21.665969] ov5640 2-003c: 17: REG16_MIN_CLK_POST @ 0x4820 = 0x56
[ 21.672402] ov5640 2-003c: 18: REG16_MIN_CLK_TRAIL @ 0x4822 = 0x3c
[ 21.679141] ov5640 2-003c: 19: REG16_MIN_LPX_PCLK @ 0x4824 = 0x32
[ 21.685704] ov5640 2-003c: 20: REG16_MIN_HS_PREPARE @ 0x4826 = 0x32
[ 21.692313] ov5640 2-003c: 21: REG16_MIN_HS_EXIT @ 0x4828 = 0x64
[ 21.698660] ov5640 2-003c: 22: REG16_X_START @ 0x5680 = 0x00
[ 21.704659] ov5640 2-003c: 23: REG16_Y_START @ 0x5682 = 0x00
[ 21.710869] ov5640 2-003c: 24: REG16_X_WINDOW @ 0x5684 = 0x10a0
[ 21.717408] ov5640 2-003c: 25: REG16_Y_WINDOW @ 0x5686 = 0xc78

I know it’s working for K4.4, however K4.9 have much checking for the frame size.
So I would suggest to report less height to avoid the short frame error cause the capture failed.

ah, thats the reason, i will try

tried, active_h with 1,240,900 and 9000 , there is no change in the logs
btw, the SHORT_FRAME error is a rare event,

the main error cycle when the stream is started is this (which can also be seen in the logs attached above)
(i have interleaved kernel messages + trace messages this time):

1609.754423: tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
1609.760917: tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
1609.770666: nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC0 = 0x0000000a
1609.779521: nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC1 = 0x0000000a
1609.782355: rtos_queue_send_from_isr_failed: tstamp:50515869919 queue:0x0b4a7258
1609.782357: rtos_queue_send_from_isr_failed: tstamp:50515870045 queue:0x0b4aad68
1609.782359: rtos_queue_send_from_isr_failed: tstamp:50515870158 queue:0x0b4ac998
1609.782360: rtos_queue_send_from_isr_failed: tstamp:50515870268 queue:0x0b4ae518
1609.782361: rtos_queue_send_from_isr_failed: tstamp:50515870377 queue:0x0b4af2d8
1609.782362: rtos_queue_send_from_isr_failed: tstamp:50515870486 queue:0x0b4b0098
1609.782364: rtos_queue_send_from_isr_failed: tstamp:50515870595 queue:0x0b4b0e58
1609.782365: rtos_queue_send_from_isr_failed: tstamp:50515870704 queue:0x0b4b1c18
1609.782367: rtos_queue_send_failed: tstamp:50515871342 queue:0x0b4a7258
1609.782369: rtos_queue_send_failed: tstamp:50515871675 queue:0x0b4a7258
1609.788278: nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000a
1609.797019: nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERROR_STATUS2VI_VC2 = 0x0000000e
1609.805792: nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) INTR_STATUS 0x0001eaaa
1609.813680: nvcsi 150c0000.nvcsi: csi4_stream_check_status (2) ERR_INTR_STATUS 0x0001eaaa
1609.821927: tegra_channel_capture_setup: vnc_id 0 W 640 H 480 fmt cb
1609.822004: tegra_channel_capture_frame: sof:-549620759684.-266794562240
1609.838350: rtos_queue_peek_from_isr_failed: tstamp:50516449005 queue:0x0b4b4500
1609.838355: rtos_queue_send_from_isr_failed: tstamp:50517475372 queue:0x0b4a7258
1609.838357: rtos_queue_send_from_isr_failed: tstamp:50517475485 queue:0x0b4aad68
1609.838360: rtos_queue_send_from_isr_failed: tstamp:50517475597 queue:0x0b4ac998
1609.838362: rtos_queue_send_from_isr_failed: tstamp:50517475707 queue:0x0b4ae518
1609.838365: rtos_queue_send_from_isr_failed: tstamp:50517475816 queue:0x0b4af2d8
1609.838367: rtos_queue_send_from_isr_failed: tstamp:50517475923 queue:0x0b4b0098
1609.838370: rtos_queue_send_from_isr_failed: tstamp:50517476035 queue:0x0b4b0e58
1609.838372: rtos_queue_send_from_isr_failed: tstamp:50517476144 queue:0x0b4b1c18
1609.838375: rtos_queue_send_failed: tstamp:50517476629 queue:0x0b4a7258
1609.838377: rtos_queue_send_failed: tstamp:50517477473 queue:0x0b4a7258
1609.838380: rtcpu_vinotify_event: tstamp:50517489253 tag:CSIMUX_STREAM channel:0xff frame:32 vi_tstamp:50517488872 data:0x00000100
1609.838383: rtcpu_vinotify_event: tstamp:50517497705 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:50517497325 data:0x00000100
1609.950393: rtcpu_vinotify_event: tstamp:50520811644 tag:CSIMUX_STREAM channel:0xff frame:16 vi_tstamp:50520811259 data:0x00000100
1609.950399: rtos_queue_peek_from_isr_failed: tstamp:50521449016 queue:0x0b4b4500
1610.006387: rtcpu_vinotify_event: tstamp:50521893747 tag:CSIMUX_STREAM channel:0xff frame:48 vi_tstamp:50521893362 data:0x00000100

this cycle keeps on going
the CSIMUX_STREAM error (0x100) is a SPURIOUS_DATA_STREAM_2 error whatever that means
the CSIMUX_FRAME error (0xa2) are bits FE_FLAG and FS_FAULT (is that frame sync fault?)

Spurious data means VI sees some other packets before FS packet, as VI alwasy expect the 1st packet to be frame start

Apply below patch for it.

cool, thanks, will try that to see whats going on.

frame

finally something usefull out of the camera.

the culprit was the cil_settletime & mclk_multiplier.
i had it tweaked before, but immediately too high.
manually tweaking/trial’n’error from 1-10 resulted in 5 being the least errorous.

apparently cil_settletime = 0 to use the auto mipi calibration did not work,
which means mclk_multiplier is too low (not enough headroom) or the mipi auto calibration is not enabled

playing with mclk_multiplier: no matter what value i take there ( pix_clk/mclk and then that times 1.3 or 2 or 4) does not result in any better behavior