Interpret debug trace log : PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000080

Hi,

We have a custom carrier board, and we are trying to stream 1080p 50 fps video on CSI -1 (2 data lane) from Lattice FPGA.
The device tree settings are as follows:

 mode0 {
                                mclk_khz = "24000";
                                num_lanes = [32 00];
                                tegra_sinterface = "serial_b";
                                phy_mode = "DPHY";
                                discontinuous_clk = "no";
                                lane_polarity = "6";
                                dpcm_enable = "false";
                                cil_settletime = [30 00];
                                //active_l = [30 00];
                                //active_t = [30 00];
                                active_w = "1920";
                                active_h = "1080";
                                mode_type = "yuv";
                                pixel_phase = "yuyv";
                                csi_pixel_bit_depth = "16";
                                readout_orientation = [30 00];
                                line_length = "3000";
                                inherent_gain = [31 00];
                                mclk_multiplier = "6.67";
                                pix_clk_hz = "123750000";
                                gain_factor = "10";
                                min_gain_val = "10";
                                max_gain_val = "160";
                                step_gain_val = [31 00];
                                default_gain = "10";
                                min_hdr_ratio = [31 00];
                                max_hdr_ratio = [31 00];
                                framerate_factor = "1000000";
                                min_framerate = "1816577";
                                max_framerate = "50000000";
                                step_framerate = [31 00];
                                default_framerate = "30000000";
                                exposure_factor = "1000000";
                                min_exp_time = "34";
                                max_exp_time = "550385";
                                step_exp_time = [31 00];
                                default_exp_time = "33334";
                                embedded_metadata_height = [30 00];
                        };

on cat /dev/video0
we do not receive any dump

V4L2 tests:


$ v4l2-ctl -d /dev/video0 --all
Driver Info:
	Driver name      : tegra-video
	Card type        : vi-output, ov5693 2-0036
	Bus info         : platform:tegra-capture-vi:1
	Driver version   : 5.10.120
	Capabilities     : 0x84200001
		Video Capture
		Streaming
		Extended Pix Format
		Device Capabilities
	Device Caps      : 0x04200001
		Video Capture
		Streaming
		Extended Pix Format
Media Driver Info:
	Driver name      : tegra-camrtc-ca
	Model            : NVIDIA Tegra Video Input Device
	Serial           : 
	Bus info         : 
	Media version    : 5.10.120
	Hardware revision: 0x00000003 (3)
	Driver version   : 5.10.120
Interface Info:
	ID               : 0x03000008
	Type             : V4L Video
Entity Info:
	ID               : 0x00000006 (6)
	Name             : vi-output, ov5693 2-0036
	Function         : V4L2 I/O
	Pad 0x01000007   : 0: Sink
	  Link 0x0200000c: from remote pad 0x1000003 of entity '13e40000.host1x:nvcsi@15a00000-': Data, Enabled
Priority: 2
Video input : 0 (Camera 1: ok)
Format Video Capture:
	Width/Height      : 1920/1080
	Pixel Format      : 'YUYV' (YUYV 4:2:2)
	Field             : None
	Bytes per Line    : 3840
	Size Image        : 4147200
	Colorspace        : sRGB
	Transfer Function : Default (maps to sRGB)
	YCbCr/HSV Encoding: Default (maps to ITU-R 601)
	Quantization      : Default (maps to Limited Range)
	Flags             : 

Camera Controls

                     group_hold 0x009a2003 (bool)   : default=0 value=0 flags=execute-on-write
                     hdr_enable 0x009a2004 (intmenu): min=0 max=1 default=0 value=0
				0: 0 (0x0)
				1: 1 (0x1)
                    eeprom_data 0x009a2005 (str)    : min=0 max=2048 step=2 value='' flags=read-only, has-payload
                       otp_data 0x009a2006 (str)    : min=0 max=1024 step=2 value='' flags=read-only, has-payload
                        fuse_id 0x009a2007 (str)    : min=0 max=16 step=2 value='' flags=read-only, has-payload
                           gain 0x009a2009 (int64)  : min=9 max=160 step=1 default=10 value=9 flags=slider
                       exposure 0x009a200a (int64)  : min=33 max=550385 step=1 default=33334 value=33 flags=slider
                     frame_rate 0x009a200b (int64)  : min=1816577 max=50000000 step=1 default=30000000 value=1816577 flags=slider
                 exposure_short 0x009a200c (int64)  : min=34 max=550385 step=1 default=33334 value=34 flags=slider
           sensor_configuration 0x009a2032 (u32)    : min=0 max=4294967295 step=1 default=0 [22] flags=read-only, volatile, has-payload
         sensor_mode_i2c_packet 0x009a2033 (u32)    : min=0 max=4294967295 step=1 default=0 [1026] flags=read-only, volatile, has-payload
      sensor_control_i2c_packet 0x009a2034 (u32)    : min=0 max=4294967295 step=1 default=0 [1026] flags=read-only, volatile, has-payload
                    bypass_mode 0x009a2064 (intmenu): min=0 max=1 default=0 value=0
				0: 0 (0x0)
				1: 1 (0x1)
                override_enable 0x009a2065 (intmenu): min=0 max=1 default=0 value=0
				0: 0 (0x0)
				1: 1 (0x1)
                   height_align 0x009a2066 (int)    : min=1 max=16 step=1 default=1 value=1
                     size_align 0x009a2067 (intmenu): min=0 max=2 default=0 value=0
				0: 1 (0x1)
				1: 65536 (0x10000)
				2: 131072 (0x20000)
               write_isp_format 0x009a2068 (int)    : min=1 max=1 step=1 default=1 value=1
       sensor_signal_properties 0x009a2069 (u32)    : min=0 max=4294967295 step=1 default=0 [30][18] flags=read-only, has-payload
        sensor_image_properties 0x009a206a (u32)    : min=0 max=4294967295 step=1 default=0 [30][16] flags=read-only, has-payload
      sensor_control_properties 0x009a206b (u32)    : min=0 max=4294967295 step=1 default=0 [30][36] flags=read-only, has-payload
              sensor_dv_timings 0x009a206c (u32)    : min=0 max=4294967295 step=1 default=0 [30][16] flags=read-only, has-payload
               low_latency_mode 0x009a206d (bool)   : default=0 value=0
               preferred_stride 0x009a206e (int)    : min=0 max=65535 step=1 default=0 value=0
                   sensor_modes 0x009a2082 (int)    : min=0 max=30 step=1 default=30 value=1 flags=read-only

And the trace logs are as below with status:0x00000080 and status:0x00000088

  kworker/2:1-104     [002] ....   154.543083: rtcpu_nvcsi_intr: tstamp:6056115634 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543084: rtcpu_nvcsi_intr: tstamp:6056116189 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000080
     kworker/2:1-104     [002] ....   154.543084: rtcpu_nvcsi_intr: tstamp:6056116744 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543084: rtcpu_nvcsi_intr: tstamp:6056117299 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543085: rtcpu_nvcsi_intr: tstamp:6056117857 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543085: rtcpu_nvcsi_intr: tstamp:6056118422 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543085: rtcpu_nvcsi_intr: tstamp:6056118968 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543086: rtcpu_nvcsi_intr: tstamp:6056119523 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543086: rtcpu_nvcsi_intr: tstamp:6056120079 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543086: rtcpu_nvcsi_intr: tstamp:6056121189 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
     kworker/2:1-104     [002] ....   154.543087: rtcpu_nvcsi_intr: tstamp:6056121744 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000080

Please advice, thank you.

Did you try on another camera port CSI-C?

@ShaneCCC

On this setup, we do not have the provision to check on CSI - 2
However this works on another setup with another FPGA on CSI -2

Do you mean another Jetson device or NONE jetson device?

@ShaneCCC

ON NVIDIA Jetson device itself (Orin NX - JP 5.1.2)

The PHY_INTR0 tell the LP sequence error. normally, it should follow by LP11->LP01->LP00->LP11 sequence.

@ShaneCCC

What could be the reason that we are unable to get video dump?

It could be the FPGA output signal didn’t match the MIPI spec.

@ShaneCCC

Can we use YUV422 format - y210 with bit depth as “10” ?
When I do this , the video node is not formed.

Current support YUV422-8bit any others YUV format need modify the nvcsi/vi driver for it.

@ShaneCCC

Hi now we get the below trace:

 kworker/2:2-106     [002] ....   178.408203: rtcpu_nvcsi_intr: tstamp:6430908347 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000004
 kworker/2:2-106     [002] ....   178.408204: rtcpu_nvcsi_intr: tstamp:6430909035 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
 kworker/2:2-106     [002] ....   178.408204: rtcpu_nvcsi_intr: tstamp:6430909729 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x0000008c
 kworker/2:2-106     [002] ....   178.408205: rtcpu_nvcsi_intr: tstamp:6430910446 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000044
 kworker/2:2-106     [002] ....   178.408205: rtcpu_nvcsi_intr: tstamp:6430911117 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x000000cc
 kworker/2:2-106     [002] ....   178.408206: rtcpu_nvcsi_intr: tstamp:6430911814 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x0000008c
 kworker/2:2-106     [002] ....   178.408206: rtcpu_nvcsi_intr: tstamp:6430912509 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000004
 kworker/2:2-106     [002] ....   178.408207: rtcpu_nvcsi_intr: tstamp:6430913196 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
 kworker/2:2-106     [002] ....   178.408208: rtcpu_nvcsi_intr: tstamp:6430913890 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x0000008c
 kworker/2:2-106     [002] ....   178.408208: rtcpu_nvcsi_intr: tstamp:6430914585 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x0000008c
 kworker/2:2-106     [002] ....   178.408208: rtcpu_nvcsi_intr: tstamp:6430915276 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x000000cc
 kworker/2:2-106     [002] ....   178.408209: rtcpu_nvcsi_intr: tstamp:6430915988 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
 kworker/2:2-106     [002] ....   178.408209: rtcpu_nvcsi_intr: tstamp:6430916665 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x000000cc
 kworker/2:2-106     [002] ....   178.408209: rtcpu_nvcsi_intr: tstamp:6430917380 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000044

with different status code and no video dump.
Please assist

@ShaneCCC

Now we consistently get status:0x00000004

I added serdes_pix_clk_hz as the sensor uses DPHY and the rate is < 1.5Gbps

device tree settings:


 mode0 {
                                mclk_khz = "24000";
                                num_lanes = "2";
                                tegra_sinterface = "serial_b";
                                phy_mode = "DPHY";
                                discontinuous_clk = "no";
                                lane_polarity = "6";
                                dpcm_enable = "false";
                                cil_settletime = "0";
                                active_w = "1280"; 
                                active_h = "720";
                                mode_type = "yuv";
                                pixel_phase = "yuyv";
                                csi_pixel_bit_depth = "16";
                                readout_orientation = [30 00];
                                line_length = "2560"; //5488
                                inherent_gain = [31 00];
                                mclk_multiplier = "6.67"; 
                                serdes_pix_clk_hz = "160000000";
                                pix_clk_hz = "80000000"; 
                                gain_factor = "10"; //16
                                min_gain_val = "10"; //16
                                max_gain_val = "160"; //256
                                step_gain_val = [31 00];
                                default_gain = "10";
                                min_hdr_ratio = [31 00];
                                max_hdr_ratio = [31 00]; 
                                framerate_factor = "1000000";
                                min_framerate = "1816577"; 
                                max_framerate = "50000000"; 
                                step_framerate = [31 00];
                                default_framerate = "30000000";
                                exposure_factor = "1000000";
                                min_exp_time = "34";
                                max_exp_time = "550385";
                                step_exp_time = [31 00];
                                default_exp_time = "33334";
                                embedded_metadata_height = [30 00];
                        };

trace log:
trace2.txt (200.3 KB)

Please assist…

Hi @ShaneCCC

We get different trace logs, unable to interpret where exactly the issue is.

cat /dev/video0 does not dump any data.

trace3.txt (8.1 KB)

Kindly assist.

The SPURIOUS_DATA_STREAM_1of CSIMUX_STREAM tell the sensor output un-support user-defined type.

@ShaneCCC

kworker/1:0-20      [001] ....   221.194443: rtcpu_vinotify_event: tstamp:7684031366 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:245888574080 data:0x759d580010000000
     kworker/1:0-20      [001] ....   221.194445: rtcpu_vinotify_event: tstamp:7684031504 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:245888580576 data:0x0000000031000001
     kworker/1:0-20      [001] ....   221.362451: rtcpu_vinotify_event: tstamp:7689102013 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:246046128000 data:0x759d550010000000
     kworker/1:0-20      [001] ....   221.362454: rtcpu_vinotify_event: tstamp:7689102153 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:246046134528 data:0x0000000031000002
     kworker/1:0-20      [001] ....   226.350401: rtcpu_vinotify_event: tstamp:7844264375 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:251007485536 data:0x759d580010000000
     kworker/1:0-20      [001] ....   226.350405: rtcpu_vinotify_event: tstamp:7844264513 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:251007492000 data:0x0000000031000001
     kworker/1:0-20      [001] ....   227.302395: rtcpu_vinotify_event: tstamp:7874350335 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:251971734208 data:0x759d550010000000
     kworker/1:0-20      [001] ....   227.302399: rtcpu_vinotify_event: tstamp:7874350475 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:251971740768 data:0x0000000031000002

we now get this trace log

Looks like didn’t receive any validate data from the MIPI bus.

Thanks

@ShaneCCC

kworker/1:0-20      [001] ....   610.903698: rtcpu_nvcsi_intr: tstamp:19862946326 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000004
     kworker/1:0-20      [001] ....   610.903698: rtcpu_nvcsi_intr: tstamp:19862947157 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000004
     kworker/1:0-20      [001] ....   610.903698: rtcpu_nvcsi_intr: tstamp:19862947991 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000004
     kworker/1:0-20      [001] ....   610.903698: rtcpu_nvcsi_intr: tstamp:19862948826 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000004

now we get status:0x00000004

how do we debug this further?

This tell the SOT multiple bit error.
Could be settle time problem.

@ShaneCCC

I have set the settle time as:

 cil_settletime = "0";

You need to check the sensor output signal to match the settle of MIPI spec.