Received MIPI data, but cannot get any image from video I/F

Hello NVIDIA Developers,

I am developing JETSON AGX camera system on carrier board with JetPack 4.6.2, L4T 32.7.2.
I would like to get RAW14 image from cmos sensor whose driver is based on imx185.c.
In our system, sensor is configured via I2C userland app, not by device driver, so almost of functions implemented in original imx185 driver is modified as dummy function.

According to this post, I added v4l2 RAW14 format into related code. (v4l2-ioctl.c, videocodecv2.h, camera_common.c, sensor_common.c, vi2_formats.h, vi5_format.h)
https://forums.developer.nvidia.com/t/raw14-raw16-in-isp-pipeline/108116/3

After modified device tree and device driver, I could confirm that video I/F (/dev/video0) is appeared and 4-lane MIPI data signal seems to be properly output from sensor on CSI-A & CSI-B (tegra_sinterface = “serial_a”, bus-width = <4>, port-index = <0>) checked by using oscilloscope.

But I cannot still get any image data from video I/F by using v4l2-tool.
Bellows are result of my v4l2 error logs.

  • check port binding
$ media-ctl -p -d /dev/media0
Media controller API version 0.1.0

Media device information
------------------------
driver          tegra194-vi5
model           NVIDIA Tegra Video Input Device
serial
bus info
hw revision     0x3
driver version  0.0.0

Device topology
- entity 1: 15a00000.nvcsi--2 (2 pads, 2 links)
            type V4L2 subdev subtype Unknown flags 0
            device node name /dev/v4l-subdev0
        pad0: Sink
                <- "imxXXX 2-001b":0 [ENABLED]
        pad1: Source
                -> "vi-output, imxXXX 2-001b":0 [ENABLED]

- entity 4: 15a00000.nvcsi--1 (2 pads, 2 links)
            type V4L2 subdev subtype Unknown flags 0
            device node name /dev/v4l-subdev1
        pad0: Sink
                <- "imxXXX 1-001b":0 [ENABLED]
        pad1: Source
                -> "vi-output, imxXXX 1-001b":0 [ENABLED]

- entity 7: imxXXX 1-001b (1 pad, 1 link)
            type V4L2 subdev subtype Sensor flags 0
            device node name /dev/v4l-subdev2
        pad0: Source
                [fmt:SRGGB14_1X14/1920x1536 field:none colorspace:srgb]
                -> "15a00000.nvcsi--1":0 [ENABLED]

- entity 9: vi-output, imxXXX 1-001b (1 pad, 1 link)
            type Node subtype V4L flags 0
            device node name /dev/video0
        pad0: Sink
                <- "15a00000.nvcsi--1":1 [ENABLED]

- entity 23: imxXXX 2-001b (1 pad, 1 link)
             type V4L2 subdev subtype Sensor flags 0
             device node name /dev/v4l-subdev3
        pad0: Source
                [fmt:SRGGB14_1X14/1920x1536 field:none colorspace:srgb]
                -> "15a00000.nvcsi--2":0 [ENABLED]

- entity 25: vi-output, imxXXX 2-001b (1 pad, 1 link)
             type Node subtype V4L flags 0
             device node name /dev/video1
        pad0: Sink
                <- "15a00000.nvcsi--2":1 [ENABLED]

  • v4l2 info
$ v4l2-ctl -d0 --l
ioctl: VIDIOC_ENUM_FMT
        Index       : 0
        Type        : Video Capture
        Pixel Format: 'RG14'
        Name        : 14-bit Bayer RGRG/GBGB
                Size: Discrete 1920x1536
                        Interval: Discrete 0.022s (45.000 fps)

$ v4l2-ctl -d /dev/video0 --all
Driver Info (not using libv4l2):
        Driver name   : tegra-video
        Card type     : vi-output, imxXXX 1-001b
        Bus info      : platform:15c10000.vi:2
        Driver version: 4.9.253
        Capabilities  : 0x84200001
                Video Capture
                Streaming
                Extended Pix Format
                Device Capabilities
        Device Caps   : 0x04200001
                Video Capture
                Streaming
                Extended Pix Format
Priority: 2
Video input : 0 (Camera 2: no power)
Format Video Capture:
        Width/Height      : 1920/1536
        Pixel Format      : 'RG14'
        Field             : None
        Bytes per Line    : 3840
        Size Image        : 5898240
        Colorspace        : sRGB
        Transfer Function : Default (maps to sRGB)
        YCbCr/HSV Encoding: Default (maps to ITU-R 601)
        Quantization      : Default (maps to Full 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
                        fuse_id 0x009a2007 (str)    : min=0 max=12 step=2 value='' flags=read-only, has-payload
                    sensor_mode 0x009a2008 (int64)  : min=0 max=0 step=0 default=0 value=0 flags=slider
                           gain 0x009a2009 (int64)  : min=0 max=0 step=0 default=0 value=0 flags=slider
                       exposure 0x009a200a (int64)  : min=0 max=0 step=0 default=0 value=30 flags=update, slider
                     frame_rate 0x009a200b (int64)  : min=0 max=0 step=0 default=0 value=1500000 flags=update, slider
           sensor_configuration 0x009a2032 (u32)    : min=0 max=0 step=0 default=0 flags=read-only, volatile, has-payload
         sensor_mode_i2c_packet 0x009a2033 (u32)    : min=0 max=0 step=0 default=0 flags=read-only, volatile, has-payload
      sensor_control_i2c_packet 0x009a2034 (u32)    : min=0 max=0 step=0 default=0 flags=read-only, volatile, has-payload
                    bypass_mode 0x009a2064 (intmenu): min=0 max=1 default=0 value=0
                override_enable 0x009a2065 (intmenu): min=0 max=1 default=0 value=0
                   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
               write_isp_format 0x009a2068 (int)    : min=1 max=1 step=1 default=1 value=1
       sensor_signal_properties 0x009a2069 (u32)    : min=0 max=0 step=0 default=0 flags=read-only, has-payload
        sensor_image_properties 0x009a206a (u32)    : min=0 max=0 step=0 default=0 flags=read-only, has-payload
      sensor_control_properties 0x009a206b (u32)    : min=0 max=0 step=0 default=0 flags=read-only, has-payload
              sensor_dv_timings 0x009a206c (u32)    : min=0 max=0 step=0 default=0 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

  • video stream test
$ v4l2-ctl -d /dev/video0 --set-fmt-video=width=1920,height=1536,pixelformat=RG14 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 --stream-to=test14.raw  --verbose

VIDIOC_QUERYCAP: ok
VIDIOC_S_EXT_CTRLS: ok
VIDIOC_G_FMT: ok
VIDIOC_S_FMT: ok
Format Video Capture:
        Width/Height      : 1920/1536
        Pixel Format      : 'RG14'
        Field             : None
        Bytes per Line    : 3840
        Size Image        : 5898240
        Colorspace        : sRGB
        Transfer Function : Default (maps to sRGB)
        YCbCr/HSV Encoding: Default (maps to ITU-R 601)
        Quantization      : Default (maps to Full Range)
        Flags             :
VIDIOC_REQBUFS: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_STREAMON: ok
        Index    : 0
        Type     : Video Capture
        Flags    : mapped, error
        Field    : None
        Sequence : 0
        Length   : 5898240
        Bytesused: 5898240
        Timestamp: 0.000000s (Monotonic, End-of-Frame)

        Index    : 0
        Type     : Video Capture
        Flags    : mapped, error
        Field    : None
        Sequence : 0
        Length   : 5898240
        Bytesused: 5898240
        Timestamp: 0.000000s (Monotonic, End-of-Frame)

        Index    : 1
        Type     : Video Capture
        Flags    : mapped, error
        Field    : None
        Sequence : 1
        Length   : 5898240
        Bytesused: 5898240
        Timestamp: 0.000000s (Monotonic, End-of-Frame)

        Index    : 2
        Type     : Video Capture
        Flags    : mapped, error
        Field    : None
        Sequence : 2
        Length   : 5898240
        Bytesused: 5898240
        Timestamp: 0.000000s (Monotonic, End-of-Frame)

        Index    : 3
        Type     : Video Capture
        Flags    : mapped, error
        Field    : None
        Sequence : 3
        Length   : 5898240
        Bytesused: 5898240
        Timestamp: 0.000000s (Monotonic, End-of-Frame)

  • appeared kernel message when try to get video stream
[  404.461995] tegra194-vi5 15c10000.vi: no reply from camera processor
[  404.462165] tegra194-vi5 15c10000.vi: uncorr_err: request timed out after 2500 ms
[  404.462308] tegra194-vi5 15c10000.vi: err_rec: attempting to reset the capture channel
[  404.466001] tegra-capture-ivc ivc-bc00000.rtcpu:ivccontrol@3: No callback found for msg id: 0x39
[  404.466174] tegra-capture-ivc ivc-bc00000.rtcpu:ivccontrol@3: No callback found for msg id: 0x41
[  404.466317] tegra-capture-ivc ivc-bc00000.rtcpu:ivccontrol@3: No callback found for msg id: 0x37
[  404.466919] tegra194-vi5 15c10000.vi: err_rec: successfully reset the capture channel
[  407.022034] tegra194-vi5 15c10000.vi: no reply from camera processor

- Camera debug messages
https://elinux.org/Jetson/l4t/Camera_BringUp

echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/isp/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/nvcsi/mrq_rate_locked
cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate |tee /sys/kernel/debug/bpmp/debug/clk/vi/rate
cat /sys/kernel/debug/bpmp/debug/clk/isp/max_rate | tee  /sys/kernel/debug/bpmp/debug/clk/isp/rate
cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate

echo 1 > /sys/kernel/debug/tracing/tracing_on
echo 30720 > /sys/kernel/debug/tracing/buffer_size_kb
echo 1 > /sys/kernel/debug/tracing/events/tegra_rtcpu/enable
echo 1 > /sys/kernel/debug/tracing/events/freertos/enable
echo 2 > /sys/kernel/debug/camrtc/log-level
echo 1 > /sys/kernel/debug/tracing/events/camera_common/enable
echo > /sys/kernel/debug/tracing/trace
cat /sys/kernel/debug/tracing/trace

# tracer: nop
#
# entries-in-buffer/entries-written: 371/371   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
     kworker/0:1-798   [000] ....   288.405947: rtos_queue_peek_from_isr_failed: tstamp:9358277491 queue:0x0bcbb8b8
     kworker/0:1-798   [000] ....   288.517935: rtos_queue_peek_from_isr_failed: tstamp:9361336798 queue:0x0bcbb8b8
        v4l2-ctl-21005 [002] ....   355.015825: tegra_channel_open: vi-output, imxXXX 1-001b
        v4l2-ctl-21005 [000] ....   355.019919: tegra_channel_set_power: imxXXX 1-001b : 0x1
        v4l2-ctl-21005 [000] ....   355.019932: camera_common_s_power: status : 0x1
        v4l2-ctl-21005 [000] ....   355.020027: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-21005 [000] ....   355.020031: csi_s_power: enable : 0x1
        v4l2-ctl-21005 [000] ....   355.024612: tegra_channel_close: vi-output, imxXXX 1-001b
        v4l2-ctl-21005 [000] ....   355.024624: tegra_channel_set_power: imxXXX 1-001b : 0x0
        v4l2-ctl-21005 [000] ....   355.024631: camera_common_s_power: status : 0x0
        v4l2-ctl-21005 [000] ....   355.024881: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x0
        v4l2-ctl-21005 [000] ....   355.024886: csi_s_power: enable : 0x0
        v4l2-ctl-21006 [002] ....   401.890699: tegra_channel_open: vi-output, imxXXX 1-001b
        v4l2-ctl-21006 [000] ....   401.893702: tegra_channel_set_power: imxXXX 1-001b : 0x1
        v4l2-ctl-21006 [000] ....   401.893721: camera_common_s_power: status : 0x1
        v4l2-ctl-21006 [000] ....   401.893817: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-21006 [000] ....   401.893852: csi_s_power: enable : 0x1
        v4l2-ctl-21006 [001] ....   401.908696: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1536 fmt c4
        v4l2-ctl-21006 [002] ....   401.933055: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-21006 [003] ....   401.943497: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-21006 [003] ....   401.943503: csi_s_stream: enable : 0x1
        v4l2-ctl-21006 [003] ....   401.943512: tegra_channel_set_stream: imxXXX 1-001b : 0x1
     kworker/0:0-21004 [000] ....   401.977959: rtos_queue_peek_from_isr_failed: tstamp:12906146554 queue:0x0bcbb8b8
     kworker/0:0-21004 [000] ....   401.977964: rtcpu_start: tstamp:12906148759
     kworker/0:0-21004 [000] ....   401.977967: rtos_queue_send_from_isr_failed: tstamp:12906269755 queue:0x0bcb2b38
     kworker/0:0-21004 [000] ....   401.977969: rtos_queue_send_from_isr_failed: tstamp:12906269958 queue:0x0bcb73a0
     kworker/0:0-21004 [000] ....   401.977970: rtos_queue_send_from_isr_failed: tstamp:12906270159 queue:0x0bcb8f20
     kworker/0:0-21004 [000] ....   401.977970: rtos_queue_send_from_isr_failed: tstamp:12906270356 queue:0x0bcb9ce0
     kworker/0:0-21004 [000] ....   401.977971: rtos_queue_send_from_isr_failed: tstamp:12906270556 queue:0x0bcbaaa0
     kworker/0:0-21004 [000] ....   401.977973: rtcpu_string: tstamp:12906271129 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/0:0-21004 [000] ....   401.978023: rtcpu_string: tstamp:12906271410 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/0:0-21004 [000] ....   401.978033: rtcpu_string: tstamp:12906271715 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/0:0-21004 [000] ....   401.978040: rtcpu_string: tstamp:12906272008 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/0:0-21004 [000] ....   401.978046: rtcpu_string: tstamp:12906272288 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/0:0-21004 [000] ....   401.978053: rtcpu_string: tstamp:12906272598 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/0:0-21004 [000] ....   401.978059: rtcpu_string: tstamp:12906272878 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/0:0-21004 [000] ....   401.978066: rtcpu_string: tstamp:12906280836 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
     kworker/0:0-21004 [000] ....   401.978067: rtcpu_string: tstamp:12906281003 id:0x04010000 str:"on 2.2
"
     kworker/0:0-21004 [000] ....   401.978074: rtos_queue_send_from_isr_failed: tstamp:12906304718 queue:0x0bcb2b38
     kworker/0:0-21004 [000] ....   401.978075: rtos_queue_send_from_isr_failed: tstamp:12906304950 queue:0x0bcb73a0
     kworker/0:0-21004 [000] ....   401.978076: rtos_queue_send_from_isr_failed: tstamp:12906305162 queue:0x0bcb8f20
     kworker/0:0-21004 [000] ....   401.978077: rtos_queue_send_from_isr_failed: tstamp:12906305360 queue:0x0bcb9ce0
     kworker/0:0-21004 [000] ....   401.978077: rtos_queue_send_from_isr_failed: tstamp:12906305557 queue:0x0bcbaaa0
     kworker/0:0-21004 [000] ....   401.978078: rtcpu_string: tstamp:12906306737 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
"
     kworker/0:0-21004 [000] ....   401.978085: rtcpu_vinotify_event: tstamp:12906593559 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:13569892864 data:0x10000000
     kworker/0:0-21004 [000] ....   401.978086: rtcpu_vinotify_event: tstamp:12906593716 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:13569896608 data:0x31000001
     kworker/0:0-21004 [000] ....   401.978087: rtcpu_vinotify_event: tstamp:12906593891 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:13569897600 data:0x07020001
     kworker/0:0-21004 [000] ....   401.978088: rtcpu_vinotify_event: tstamp:12906594038 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:13569950912 data:0x10000000
     kworker/0:0-21004 [000] ....   401.978089: rtcpu_vinotify_event: tstamp:12906594210 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:13569954720 data:0x31000002
     kworker/0:0-21004 [000] ....   401.978089: rtos_queue_send_from_isr_failed: tstamp:12906634941 queue:0x0bcb2b38
     kworker/0:0-21004 [000] ....   401.978090: rtos_queue_send_from_isr_failed: tstamp:12906635102 queue:0x0bcb73a0
     kworker/0:0-21004 [000] ....   401.978091: rtos_queue_send_from_isr_failed: tstamp:12906635264 queue:0x0bcb8f20
     kworker/0:0-21004 [000] ....   401.978092: rtos_queue_send_from_isr_failed: tstamp:12906635422 queue:0x0bcb9ce0
     kworker/0:0-21004 [000] ....   401.978108: rtos_queue_send_from_isr_failed: tstamp:12906635579 queue:0x0bcbaaa0
     kworker/0:0-21004 [000] ....   401.978110: rtcpu_nvcsi_intr: tstamp:12906638171 class:GLOBAL type:PHY_INTR0 phy:1 cil:0 st:0 vc:0 status:0x00000089
     kworker/0:0-21004 [000] ....   401.978111: rtcpu_nvcsi_intr: tstamp:12906638171 class:GLOBAL type:PHY_INTR0 phy:1 cil:1 st:0 vc:0 status:0x00000088
     kworker/0:0-21004 [000] ....   402.089940: rtos_queue_peek_from_isr_failed: tstamp:12911146934 queue:0x0bcbb8b8
     kworker/0:0-21004 [000] ....   402.257935: rtos_queue_peek_from_isr_failed: tstamp:12916146936 queue:0x0bcbb8b8
     kworker/0:0-21004 [000] ....   402.425934: rtos_queue_peek_from_isr_failed: tstamp:12921146934 queue:0x0bcbb8b8

My question is

  • I guess “no reply from camera processor” and other massages told that JETSON AGX detected no valid MIPI data on CSI bus in , is that correct?
  • Is this error possible to be caused by parameter mismatch between DT parameters and actual MIPI data signal? For example, pix_clk_hz, line_length, cil_settletime, and so on.

hello tagoshi,

>>> I guess “no reply from camera processor” and other massages told that JETSON AGX detected no valid MIPI data on CSI bus in , is that correct?

yes, that means VI engine cannot receive the signaling.

>>> Is this error possible to be caused by parameter mismatch between DT parameters and actual MIPI data signal? For example, pix_clk_hz, line_length, cil_settletime, and so on.

since you’ve already probe the signal by oscilloscope. there shows high-speed signaling.
you’ll need to review DT properties settings. please start with Sensor Pixel Clock.

there’s also DT property, set_mode_delay_ms, it configure the maximum wait time for the first frame after capture starts, the unit is in milliseconds.

BTW,
you may also try below commands to boost all the VI/CSI/ISP clocks for quick testing.
for example,

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

Hi, JerryChang,

Thank you for your advice.
I tried your VI/CSI/ISP clocks commands, but unfortunately log message unchanged. i.e.) “no reply from camera processor”.

I also reviewed DT settings and fixed “embedded_metadata_height” in DT, because our sensor has header and footer embedded data.
I suppose that “embedded_metadata_height” need to match with the number of the header embedded data lines.

In addition to that, I confirmed that “pix_clk_hz” is correct, but still got no valid data from /dev/video0.

BTW, should I include both of optical black(OB) and footer embedded lines in active_h as below?
active_h = vertical active area height + OB + footer embedded data line

hello tagoshi,

please note that, we only support embedded metadata ahead of pixel active regions.
so, this embedded_metadata_height configuration only consider header embedded data.

this is incorrect. active_h should be the vertical active area height.
besides, footer embedded data line is not supported. please ignore this to bring-up your driver.

so, this embedded_metadata_height configuration only consider header embedded data.

this is incorrect. active_h should be the vertical active area height.

Thank you for concrete answer, it so helpful.

Please let me ask you more questions.

Q1 : If I set incorrect value into active_w, active_h, does it cause "no reply from camera processor” error?

If any MIPI signal which has Frame Start(FS) and Frame End(FE) comes to NVCSI port and our fundamental DT parameters such as pix_clk_hz, csi_pixel_bit_depth, mode_type, pixel_phase are set correctly, other log message should be found in VI/CSI log?

I tried to fix DT parameters, but I still have gotten only “no reply from camera processor” error.
So I would like to know why it seems that no MIPI data is detected on NVCSI port.

Q2 : I couldn’t find set_mode_delay_ms parameter in my kernel source tree.
Which driver actually read this parameter from DT and apply it?

I removed some channels from VI & CSI Device Tree node temporarily, and fixed DT parameter again such as embedded_metadata_height, default_exp_time.

As a result, VI/SCI log seemed to change.
“CSIMUX_STREAM”, “CHANSEL_NOMATCH”, and other messages appeared after I tried to get RAW14 image below command.

v4l2-ctl -d /dev/video0 --set-fmt-video=width=1920,height=1536,pixelformat=RG14 --set-ctrl bypass_mode=0 --stream-mmap --stream-ccount=1 --stream-to=test14.raw --verbosecat /sys/kernel/debug/tracing/trace

Please give me some advice, what does these messages mean?

[2022-11-24 10:15:34.871] # tracer: nop
[2022-11-24 10:15:34.872] #
[2022-11-24 10:15:34.872] # entries-in-buffer/entries-written: 1720/1720   #P:4
[2022-11-24 10:15:34.872] #
[2022-11-24 10:15:34.872] #                              _-----=> irqs-off
[2022-11-24 10:15:34.872] #                             / _----=> need-resched
[2022-11-24 10:15:34.872] #                            | / _---=> hardirq/softirq
[2022-11-24 10:15:34.872] #                            || / _--=> preempt-depth
[2022-11-24 10:15:34.872] #                            ||| /     delay
[2022-11-24 10:15:34.872] #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
[2022-11-24 10:15:34.872] #              | |       |   ||||       |         |
[2022-11-24 10:15:34.872]      kworker/0:4-1894  [000] ....   207.582082: rtos_queue_peek_from_isr_failed: tstamp:6912117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.872]      kworker/0:4-1894  [000] ....   207.750054: rtos_queue_peek_from_isr_failed: tstamp:6917117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.872]      kworker/0:4-1894  [000] ....   207.918063: rtos_queue_peek_from_isr_failed: tstamp:6922117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.872]      kworker/0:4-1894  [000] ....   208.086089: rtos_queue_peek_from_isr_failed: tstamp:6927117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.872]      kworker/0:4-1894  [000] ....   208.198041: rtos_queue_peek_from_isr_failed: tstamp:6932117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   208.366051: rtos_queue_peek_from_isr_failed: tstamp:6937117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   208.534055: rtos_queue_peek_from_isr_failed: tstamp:6942117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   208.702042: rtos_queue_peek_from_isr_failed: tstamp:6947117928 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   208.870049: rtos_queue_peek_from_isr_failed: tstamp:6952117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   209.038045: rtos_queue_peek_from_isr_failed: tstamp:6957117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   209.206080: rtos_queue_peek_from_isr_failed: tstamp:6962117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   209.318039: rtos_queue_peek_from_isr_failed: tstamp:6967117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   209.486048: rtos_queue_peek_from_isr_failed: tstamp:6972117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.881]      kworker/0:4-1894  [000] ....   209.654039: rtos_queue_peek_from_isr_failed: tstamp:6977117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   209.822045: rtos_queue_peek_from_isr_failed: tstamp:6982117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   209.990039: rtos_queue_peek_from_isr_failed: tstamp:6987117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   210.158040: rtos_queue_peek_from_isr_failed: tstamp:6992117928 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   210.326051: rtos_queue_peek_from_isr_failed: tstamp:6997117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   210.438044: rtos_queue_peek_from_isr_failed: tstamp:7002117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   210.606045: rtos_queue_peek_from_isr_failed: tstamp:7007117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   210.774044: rtos_queue_peek_from_isr_failed: tstamp:7012117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   210.942053: rtos_queue_peek_from_isr_failed: tstamp:7017117928 queue:0x0bcbb8b8
[2022-11-24 10:15:34.899]      kworker/0:4-1894  [000] ....   211.110043: rtos_queue_peek_from_isr_failed: tstamp:7022117925 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   211.278054: rtos_queue_peek_from_isr_failed: tstamp:7027117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   211.446041: rtos_queue_peek_from_isr_failed: tstamp:7032117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   211.558047: rtos_queue_peek_from_isr_failed: tstamp:7037117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   211.726041: rtos_queue_peek_from_isr_failed: tstamp:7042117928 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   211.894043: rtos_queue_peek_from_isr_failed: tstamp:7047117926 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   212.062039: rtos_queue_peek_from_isr_failed: tstamp:7052117929 queue:0x0bcbb8b8
[2022-11-24 10:15:34.904]      kworker/0:4-1894  [000] ....   212.230043: rtos_queue_peek_from_isr_failed: tstamp:7057117926 queue:0x0bcbb8b8
[2022-11-24 10:15:35.213]      kworker/0:4-1894  [000] ....   212.398046: rtos_queue_peek_from_isr_failed: tstamp:7062117926 queue:0x0bcbb8b8
[2022-11-24 10:15:35.213]      kworker/0:4-1894  [000] ....   212.510050: rtos_queue_peek_from_isr_failed: tstamp:7066091010 queue:0x0bcbb8b8
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [003] ....   226.704162: tegra_channel_open: vi-output, imx623 2-001b
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.706284: tegra_channel_set_power: imx623 2-001b : 0x1
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.706301: camera_common_s_power: status : 0x1
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.706408: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.706411: csi_s_power: enable : 0x1
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.715311: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1536 fmt c4
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.721407: tegra_channel_set_stream: enable : 0x1
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.723956: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x1
[2022-11-24 10:15:35.213]         v4l2-ctl-8316  [000] ....   226.723961: csi_s_stream: enable : 0x1
[2022-11-24 10:15:35.223]         v4l2-ctl-8316  [000] ....   226.723976: tegra_channel_set_stream: imx623 2-001b : 0x1
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734051: rtos_queue_peek_from_isr_failed: tstamp:7511135674 queue:0x0bcbb8b8
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734055: rtcpu_start: tstamp:7511137300
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734058: rtos_queue_send_from_isr_failed: tstamp:7511169218 queue:0x0bcb2b38
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734060: rtos_queue_send_from_isr_failed: tstamp:7511169354 queue:0x0bcb73a0
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734061: rtos_queue_send_from_isr_failed: tstamp:7511169490 queue:0x0bcb8f20
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734062: rtos_queue_send_from_isr_failed: tstamp:7511169628 queue:0x0bcb9ce0
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734064: rtos_queue_send_from_isr_failed: tstamp:7511169761 queue:0x0bcbaaa0
[2022-11-24 10:15:35.223]      kworker/0:4-1894  [000] ....   226.734066: rtcpu_string: tstamp:7511170172 id:0x04010000 str:"Configuring VI GoS.
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734095: rtcpu_string: tstamp:7511170355 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734106: rtcpu_string: tstamp:7511170598 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734146: rtcpu_string: tstamp:7511170827 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734153: rtcpu_string: tstamp:7511171045 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734160: rtcpu_string: tstamp:7511171277 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734166: rtcpu_string: tstamp:7511171492 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
[2022-11-24 10:15:35.231] "
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734172: rtcpu_string: tstamp:7511179009 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
[2022-11-24 10:15:35.231]      kworker/0:4-1894  [000] ....   226.734174: rtcpu_string: tstamp:7511179114 id:0x04010000 str:"on 2.2
[2022-11-24 10:15:35.239] "
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734182: rtos_queue_send_from_isr_failed: tstamp:7511193188 queue:0x0bcb2b38
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734183: rtos_queue_send_from_isr_failed: tstamp:7511193340 queue:0x0bcb73a0
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734184: rtos_queue_send_from_isr_failed: tstamp:7511193480 queue:0x0bcb8f20
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734186: rtos_queue_send_from_isr_failed: tstamp:7511193612 queue:0x0bcb9ce0
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734187: rtos_queue_send_from_isr_failed: tstamp:7511193746 queue:0x0bcbaaa0
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734188: rtcpu_string: tstamp:7511194581 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
[2022-11-24 10:15:35.239] "
[2022-11-24 10:15:35.239]      kworker/0:4-1894  [000] ....   226.734195: rtos_queue_send_from_isr_failed: tstamp:7511275343 queue:0x0bcb2b38
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734196: rtos_queue_send_from_isr_failed: tstamp:7511275481 queue:0x0bcb73a0
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734197: rtos_queue_send_from_isr_failed: tstamp:7511275620 queue:0x0bcb8f20
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734198: rtos_queue_send_from_isr_failed: tstamp:7511275753 queue:0x0bcb9ce0
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734200: rtos_queue_send_from_isr_failed: tstamp:7511275885 queue:0x0bcbaaa0
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734202: rtcpu_nvcsi_intr: tstamp:7511278361 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000089
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734203: rtcpu_nvcsi_intr: tstamp:7511278361 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000088
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734205: rtcpu_vinotify_error: tstamp:7511282868 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:7511282252 data:0x00000001
[2022-11-24 10:15:35.571]      kworker/0:4-1894  [000] ....   226.734235: rtcpu_vinotify_error: tstamp:7511434958 tag:CHANSEL_NOMATCH channel:0x41 frame:5727 vi_tstamp:7511434288 data:0x00000249
[2022-11-24 10:15:35.587]      kworker/0:4-1894  [000] ....   226.734237: rtcpu_vinotify_event: tstamp:7511491766 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:8430020736 data:0x10000000
[2022-11-24 10:15:35.587]      kworker/0:4-1894  [000] ....   226.734238: rtcpu_vinotify_event: tstamp:7511491896 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:8430024512 data:0x31000001
[2022-11-24 10:15:35.587]      kworker/0:4-1894  [000] ....   226.734240: rtcpu_vinotify_event: tstamp:7511492042 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:8430025536 data:0x07020001
[2022-11-24 10:15:35.587]      kworker/0:4-1894  [000] ....   226.734241: rtcpu_vinotify_event: tstamp:7511492165 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:8430061248 data:0x10000000
[2022-11-24 10:15:35.587]      kworker/0:4-1894  [000] ....   226.734242: rtcpu_vinotify_event: tstamp:7511492307 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:8430065056 data:0x31000002
[2022-11-24 10:15:35.587]      kworker/0:4-1894  [000] ....   226.734243: rtcpu_vinotify_event: tstamp:7511492440 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:7511282252 data:0x00000001
[2022-11-24 10:15:35.601]      kworker/0:4-1894  [000] ....   226.734244: rtcpu_vinotify_event: tstamp:7511492580 tag:FS channel:0x01 frame:5727 vi_tstamp:7511433478 data:0x00000010
[2022-11-24 10:15:35.601]      kworker/0:4-1894  [000] ....   226.734246: rtcpu_vinotify_event: tstamp:7511492702 tag:CHANSEL_NOMATCH channel:0x41 frame:5727 vi_tstamp:7511434288 data:0x00000249
[2022-11-24 10:15:35.601]      kworker/0:4-1894  [000] ....   226.790073: rtcpu_vinotify_event: tstamp:7512117694 tag:FE channel:0x01 frame:5727 vi_tstamp:7512103698 data:0x00000020
[2022-11-24 10:15:35.601]      kworker/0:4-1894  [000] ....   226.790106: rtcpu_vinotify_error: tstamp:7512130194 tag:CHANSEL_NOMATCH channel:0x41 frame:5728 vi_tstamp:7512129550 data:0x00000249
[2022-11-24 10:15:35.601]      kworker/0:4-1894  [000] ....   226.790108: rtcpu_vinotify_event: tstamp:7512430703 tag:FS channel:0x01 frame:5728 vi_tstamp:7512128738 data:0x00000010
[2022-11-24 10:15:35.601]      kworker/0:4-1894  [000] ....   226.790109: rtcpu_vinotify_event: tstamp:7512430844 tag:CHANSEL_NOMATCH channel:0x41 frame:5728 vi_tstamp:7512129550 data:0x00000249
[2022-11-24 10:15:35.606]      kworker/0:4-1894  [000] ....   226.790111: rtcpu_vinotify_error: tstamp:7512825464 tag:CHANSEL_NOMATCH channel:0x41 frame:5729 vi_tstamp:7512824812 data:0x00000249
[2022-11-24 10:15:35.606]      kworker/0:4-1894  [000] ....   226.790112: rtcpu_vinotify_event: tstamp:7513056722 tag:FE channel:0x01 frame:5728 vi_tstamp:7512798960 data:0x00000020
[2022-11-24 10:15:35.606]      kworker/0:4-1894  [000] ....   226.790113: rtcpu_vinotify_event: tstamp:7513056863 tag:FS channel:0x01 frame:5729 vi_tstamp:7512824001 data:0x00000010
[2022-11-24 10:15:35.606]      kworker/0:4-1894  [000] ....   226.790114: rtcpu_vinotify_event: tstamp:7513056989 tag:CHANSEL_NOMATCH channel:0x41 frame:5729 vi_tstamp:7512824812 data:0x00000249
[2022-11-24 10:15:35.606]      kworker/0:4-1894  [000] ....   226.846054: rtcpu_vinotify_event: tstamp:7513519785 tag:FE channel:0x01 frame:5729 vi_tstamp:7513494224 data:0x00000020
[2022-11-24 10:15:35.606]      kworker/0:4-1894  [000] ....   226.846057: rtcpu_vinotify_event: tstamp:7513519918 tag:FS channel:0x01 frame:5730 vi_tstamp:7513519264 data:0x00000010
[2022-11-24 10:15:35.912]      kworker/0:4-1894  [000] ....   226.846059: rtcpu_vinotify_error: tstamp:7513520717 tag:CHANSEL_NOMATCH channel:0x41 frame:5730 vi_tstamp:7513520075 data:0x00000249
[2022-11-24 10:15:35.912]      kworker/0:4-1894  [000] ....   226.846060: rtcpu_vinotify_event: tstamp:7513807946 tag:CHANSEL_NOMATCH channel:0x41 frame:5730 vi_tstamp:7513520075 data:0x00000249
[2022-11-24 10:15:35.912]      kworker/0:4-1894  [000] ....   226.846090: rtcpu_vinotify_error: tstamp:7514215987 tag:CHANSEL_NOMATCH channel:0x41 frame:5731 vi_tstamp:7514215336 data:0x00000249
[2022-11-24 10:15:35.912]      kworker/0:4-1894  [000] ....   226.846091: rtcpu_vinotify_event: tstamp:7514433970 tag:FE channel:0x01 frame:5730 vi_tstamp:7514189486 data:0x00000020
[2022-11-24 10:15:35.912]      kworker/0:4-1894  [000] ....   226.846092: rtcpu_vinotify_event: tstamp:7514434110 tag:FS channel:0x01 frame:5731 vi_tstamp:7514214525 data:0x00000010
[2022-11-24 10:15:35.912]      kworker/0:4-1894  [000] ....   226.846094: rtcpu_vinotify_event: tstamp:7514434236 tag:CHANSEL_NOMATCH channel:0x41 frame:5731 vi_tstamp:7514215336 data:0x00000249
[2022-11-24 10:15:35.929]      kworker/0:4-1894  [000] ....   226.846095: rtcpu_vinotify_error: tstamp:7514911245 tag:CHANSEL_NOMATCH channel:0x41 frame:5732 vi_tstamp:7514910598 data:0x00000249
[2022-11-24 10:15:35.929]      kworker/0:4-1894  [000] ....   226.846096: rtcpu_vinotify_event: tstamp:7515059991 tag:FE channel:0x01 frame:5731 vi_tstamp:7514884748 data:0x00000020
[2022-11-24 10:15:35.929]      kworker/0:4-1894  [000] ....   226.846097: rtcpu_vinotify_event: tstamp:7515060115 tag:FS channel:0x01 frame:5732 vi_tstamp:7514909789 data:0x00000010
[2022-11-24 10:15:35.929]      kworker/0:4-1894  [000] ....   226.846099: rtcpu_vinotify_event: tstamp:7515060255 tag:CHANSEL_NOMATCH channel:0x41 frame:5732 vi_tstamp:7514910598 data:0x00000249
[2022-11-24 10:15:35.929]      kworker/0:4-1894  [000] ....   226.902051: rtcpu_vinotify_error: tstamp:7515606514 tag:CHANSEL_NOMATCH channel:0x41 frame:5733 vi_tstamp:7515605861 data:0x00000249
[2022-11-24 10:15:35.929]      kworker/0:4-1894  [000] ....   226.902054: rtcpu_vinotify_event: tstamp:7515686016 tag:FE channel:0x01 frame:5732 vi_tstamp:7515580009 data:0x00000020
[2022-11-24 10:15:35.944]      kworker/0:4-1894  [000] ....   226.902056: rtcpu_vinotify_event: tstamp:7515686160 tag:FS channel:0x01 frame:5733 vi_tstamp:7515605050 data:0x00000010
[2022-11-24 10:15:35.944]      kworker/0:4-1894  [000] ....   226.902057: rtcpu_vinotify_event: tstamp:7515686286 tag:CHANSEL_NOMATCH channel:0x41 frame:5733 vi_tstamp:7515605861 data:0x00000249
[2022-11-24 10:15:35.944]      kworker/0:4-1894  [000] ....   226.902060: rtos_queue_peek_from_isr_failed: tstamp:7516136020 queue:0x0bcbb8b8
[2022-11-24 10:15:35.944]      kworker/0:4-1894  [000] ....   226.902085: rtcpu_vinotify_error: tstamp:7516301779 tag:CHANSEL_NOMATCH channel:0x41 frame:5734 vi_tstamp:7516301123 data:0x00000249
[2022-11-24 10:15:35.944]      kworker/0:4-1894  [000] ....   226.902087: rtcpu_vinotify_event: tstamp:7516311945 tag:FE channel:0x01 frame:5733 vi_tstamp:7516275271 data:0x00000020
[2022-11-24 10:15:35.944]      kworker/0:4-1894  [000] ....   226.902088: rtcpu_vinotify_event: tstamp:7516312069 tag:FS channel:0x01 frame:5734 vi_tstamp:7516300311 data:0x00000010
[2022-11-24 10:15:35.953]      kworker/0:4-1894  [000] ....   226.902089: rtcpu_vinotify_event: tstamp:7516312212 tag:CHANSEL_NOMATCH channel:0x41 frame:5734 vi_tstamp:7516301123 data:0x00000249
[2022-11-24 10:15:35.953]      kworker/0:4-1894  [000] ....   226.958072: rtcpu_vinotify_error: tstamp:7516997038 tag:CHANSEL_NOMATCH channel:0x41 frame:5735 vi_tstamp:7516996385 data:0x00000249
[2022-11-24 10:15:35.953]      kworker/0:4-1894  [000] ....   226.958075: rtcpu_vinotify_event: tstamp:7516997304 tag:FE channel:0x01 frame:5734 vi_tstamp:7516970534 data:0x00000020
[2022-11-24 10:15:35.953]      kworker/0:4-1894  [000] ....   226.958077: rtcpu_vinotify_event: tstamp:7516997445 tag:FS channel:0x01 frame:5735 vi_tstamp:7516995574 data:0x00000010
[2022-11-24 10:15:35.953]      kworker/0:4-1894  [000] ....   226.958078: rtcpu_vinotify_event: tstamp:7516997569 tag:CHANSEL_NOMATCH channel:0x41 frame:5735 vi_tstamp:7516996385 data:0x00000249
[2022-11-24 10:15:35.953]      kworker/0:4-1894  [000] ....   226.958079: rtcpu_vinotify_event: tstamp:7517689167 tag:FE channel:0x01 frame:5735 vi_tstamp:7517665796 data:0x00000020
[2022-11-24 10:15:36.271]      kworker/0:4-1894  [000] ....   226.958081: rtcpu_vinotify_error: tstamp:7517692288 tag:CHANSEL_NOMATCH channel:0x41 frame:5736 vi_tstamp:7517691647 data:0x00000249
[2022-11-24 10:15:36.271]      kworker/0:4-1894  [000] ....   226.958082: rtcpu_vinotify_event: tstamp:7518002169 tag:FS channel:0x01 frame:5736 vi_tstamp:7517690836 data:0x00000010
[2022-11-24 10:15:36.271]      kworker/0:4-1894  [000] ....   226.958084: rtcpu_vinotify_event: tstamp:7518002313 tag:CHANSEL_NOMATCH channel:0x41 frame:5736 vi_tstamp:7517691647 data:0x00000249
[2022-11-24 10:15:36.271]      kworker/0:4-1894  [000] ....   226.958085: rtcpu_vinotify_error: tstamp:7518387567 tag:CHANSEL_NOMATCH channel:0x41 frame:5737 vi_tstamp:7518386909 data:0x00000249
[2022-11-24 10:15:36.271]      kworker/0:4-1894  [000] ....   227.014046: rtcpu_vinotify_event: tstamp:7518628192 tag:FE channel:0x01 frame:5736 vi_tstamp:7518361058 data:0x00000020
[2022-11-24 10:15:36.271]      kworker/0:4-1894  [000] ....   227.014048: rtcpu_vinotify_event: tstamp:7518628336 tag:FS channel:0x01 frame:5737 vi_tstamp:7518386097 data:0x00000010
[2022-11-24 10:15:36.286]      kworker/0:4-1894  [000] ....   227.014049: rtcpu_vinotify_event: tstamp:7518628461 tag:CHANSEL_NOMATCH channel:0x41 frame:5737 vi_tstamp:7518386909 data:0x00000249
[2022-11-24 10:15:36.286]      kworker/0:4-1894  [000] ....   227.014075: rtcpu_vinotify_error: tstamp:7519082820 tag:CHANSEL_NOMATCH channel:0x41 frame:5738 vi_tstamp:7519082170 data:0x00000249
[2022-11-24 10:15:36.286]      kworker/0:4-1894  [000] ....   227.014076: rtcpu_vinotify_event: tstamp:7519254218 tag:FE channel:0x01 frame:5737 vi_tstamp:7519056320 data:0x00000020
[2022-11-24 10:15:36.286]      kworker/0:4-1894  [000] ....   227.014078: rtcpu_vinotify_event: tstamp:7519254341 tag:FS channel:0x01 frame:5738 vi_tstamp:7519081361 data:0x00000010
[2022-11-24 10:15:36.286]      kworker/0:4-1894  [000] ....   227.014079: rtcpu_vinotify_event: tstamp:7519254481 tag:CHANSEL_NOMATCH channel:0x41 frame:5738 vi_tstamp:7519082170 data:0x00000249
[2022-11-24 10:15:36.286]      kworker/0:4-1894  [000] ....   227.014080: rtcpu_vinotify_error: tstamp:7519778083 tag:CHANSEL_NOMATCH channel:0x41 frame:5739 vi_tstamp:7519777434 data:0x00000249
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.014081: rtcpu_vinotify_event: tstamp:7519880241 tag:FE channel:0x01 frame:5738 vi_tstamp:7519751582 data:0x00000020
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.014083: rtcpu_vinotify_event: tstamp:7519880381 tag:FS channel:0x01 frame:5739 vi_tstamp:7519776622 data:0x00000010
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.014084: rtcpu_vinotify_event: tstamp:7519880504 tag:CHANSEL_NOMATCH channel:0x41 frame:5739 vi_tstamp:7519777434 data:0x00000249
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.070053: rtcpu_vinotify_error: tstamp:7520473347 tag:CHANSEL_NOMATCH channel:0x41 frame:5740 vi_tstamp:7520472696 data:0x00000249
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.070056: rtcpu_vinotify_event: tstamp:7520506273 tag:FE channel:0x01 frame:5739 vi_tstamp:7520446845 data:0x00000020
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.070058: rtcpu_vinotify_event: tstamp:7520506402 tag:FS channel:0x01 frame:5740 vi_tstamp:7520471883 data:0x00000010
[2022-11-24 10:15:36.300]      kworker/0:4-1894  [000] ....   227.070059: rtcpu_vinotify_event: tstamp:7520506544 tag:CHANSEL_NOMATCH channel:0x41 frame:5740 vi_tstamp:7520472696 data:0x00000249

hello tagoshi,

to reply your questions in comment #6.
>>Q1
VI reporting… no reply from camera processor, such error is related to VI engine cannot recognize a frame.
FYI,
VI engine it’s using line-length and frame-height to indicate width and height signal. in theory, if there’s mismatch to active_w, or active_h, you’ll see CHANSEL error reported. such as… PIXEL_LONG_LINE, PIXEL_SHORT_FRAME…etc.

>>Q2
this set_mode_delay_ms property is used to override the default capture timeout value, this is used by internal camera stack.
may I also know which JetPack release you’re working with?
please see-also developer guide, Sensor Software Driver Programming for [Device Properties].


regarding to your latest VI tracing logs…
for example.

rtcpu_vinotify_event: tstamp:7511492440 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:7511282252 data:0x00000001
rtcpu_vinotify_event: tstamp:7511492580 tag:FS channel:0x01 frame:5727 vi_tstamp:7511433478 data:0x00000010
rtcpu_vinotify_event: tstamp:7511492702 tag:CHANSEL_NOMATCH channel:0x41 frame:5727 vi_tstamp:7511434288 data:0x00000249
rtcpu_vinotify_event: tstamp:7512117694 tag:FE channel:0x01 frame:5727 vi_tstamp:7512103698 data:0x00000020

it’s CHANSEL_NOMATCH to indicate the signal mismatch to your DT settings.
it usually caused by your pixel format configurations.
it’s bit:0 for no_match. bit:1-4 for CTYPE (internal usage), and bit:5-10 for DTYPE.
so,
CHANSEL_NOMATCH = 0x249 is means… DTYPE= 0x12 = 18d
this is not defined NVCSI datatypes, as you can see in the kernel header.
for example,
$public_sources/kernel_src/kernel/nvidia/include/soc/tegra/camrtc-capture.h

/**
 * @defgroup NvCsiDataType NVCSI datatypes
 * @{
 */
#define NVCSI_DATATYPE_UNSPECIFIED      MK_U32(0)
...
#define NVCSI_DATATYPE_RAW6             MK_U32(40)
#define NVCSI_DATATYPE_RAW7             MK_U32(41)
#define NVCSI_DATATYPE_RAW8             MK_U32(42)
#define NVCSI_DATATYPE_RAW10            MK_U32(43)

Thank you for prompt reply, I really appreciate.

may I also know which JetPack release you’re working with?

I use JetPack 4.6.2, L4T 32.7.2.
My kernel is provided from carrier board vendor, so it might differ from original NVIDIA kernel, but I guess the difference is just Device Tree contents(dts).

CHANSEL_NOMATCH = 0x249 is means… DTYPE= 0x12 = 18d

0x12 is the datatype of “header embedded data” in our system.
“header embedded data” has just 1 line in a frame, so I set embedded_metadata_height as “1”.
But does this error imply that my embedded_metadata_height is still wrong?

BTW, could you tell me how AGX detect and ignore OB data in frame?
It seems that no OB information appears in DT property.
If OB has “N” lines in a frame, should I set this “N” value into some DT parameters?

hello tagoshi,

may I know what’s the actual camera hardware connections.
for example, are you using a SerDes chip, or it is a bayer camera sensor that connect to camera connector directly?

since you’ve already probe the signal, and MIPI data signal seems to be properly output from sensor.
please ignore embedded metadata for a quick testing, you can configure embedded_metadata_height = 0; in DT, driver side will ignore embedded data.

>> If OB has “N” lines in a frame, should I set this “N” value into some DT parameters?

partially correct, with a SDR camera sensor. if you’re using DOL-WDR camera sensor, optical black is considered.
moreover,
it’s camera stack to load ISP tuning file for optical black. it’s don’t care term in the bring-up stage.

it’s camera stack to load ISP tuning file for optical black. it’s don’t care term in the bring-up stage.

Thanks, I undersood.

for example, are you using a SerDes chip, or it is a bayer camera sensor that connect to camera connector directly?

I use SerDes(gvif) chip, but only one CMOS is connected to a SerDes chip on current port.
CSI(AGX) <-> SerDes <-> CMOS

I’ll connect 2 cmos to a serdes chip in next step, but currently I’m focusing on a serdes chip with 1 cmos port.
SerDes and CMOS parameter settings are done by I2C user application, not by device driver.
CMOS/SerDes Steaming output is started before IMX driver is loaded(insmod) and keeps always ON.

please ignore embedded metadata for a quick testing, you can configure embedded_metadata_height = 0; in DT, driver side will ignore embedded data.

Thanks, I tried this, but result seemed to be unchanged.

rtcpu_vinotify_error: tstamp:2437045955 tag:CHANSEL_NOMATCH channel:0x41 frame:1522 vi_tstamp:2437045301 data:0x00000249

In addition to that, I modified data type of OB and header/footer embedded data to RAW14(0x2D) by changing CMOS register settings, just for debugging.
Therefore, there is only 0x2D datatype on my MIPI data lane.

Then, I executed this v4l2 command.

v4l2-ctl -d /dev/video0 --set-fmt-video=width=1920,height=1552,pixelformat=RG14 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 --stream-to=test14.raw --verbose

But result log still shows "tag:CHANSEL_NOMATCH ", instead of its DTYPE of 0x000005a90, it means 0x2D.
I think it means that arrived data is recognized as RAW14(0x2D) format data on CSI bus.

I have already added RG14(RAW14) format as below, why cannot get 0x2D MIPI data from video I/F?
https://forums.developer.nvidia.com/t/should-i-add-mipi-data-type-0x2d-in-kernel-code-to-support-raw14-format/235155/6

[2022-11-24 16:52:52.328]      kworker/0:0-4     [000] ....   194.381080: rtos_queue_peek_from_isr_failed: tstamp:6394658590 queue:0x0bcbb8b8
[2022-11-24 16:52:52.328]      kworker/0:0-4     [000] ....   194.549091: rtos_queue_peek_from_isr_failed: tstamp:6399658588 queue:0x0bcbb8b8
[2022-11-24 16:52:52.328]      kworker/0:0-4     [000] ....   194.661081: rtos_queue_peek_from_isr_failed: tstamp:6404103506 queue:0x0bcbb8b8
[2022-11-24 16:52:52.328]         v4l2-ctl-8362  [002] ....   235.635166: tegra_channel_open: vi-output, imx623 2-001b
[2022-11-24 16:52:52.328]         v4l2-ctl-8362  [001] ....   235.637136: tegra_channel_set_power: imx623 2-001b : 0x1
[2022-11-24 16:52:52.328]         v4l2-ctl-8362  [001] ....   235.637151: camera_common_s_power: status : 0x1
[2022-11-24 16:52:52.328]         v4l2-ctl-8362  [001] ....   235.637242: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
[2022-11-24 16:52:52.343]         v4l2-ctl-8362  [001] ....   235.637245: csi_s_power: enable : 0x1
[2022-11-24 16:52:52.343]         v4l2-ctl-8362  [002] ....   235.644812: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1552 fmt c4
[2022-11-24 16:52:52.343]         v4l2-ctl-8362  [000] ....   235.650039: tegra_channel_set_stream: enable : 0x1
[2022-11-24 16:52:52.343]         v4l2-ctl-8362  [000] ....   235.651246: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x1
[2022-11-24 16:52:52.343]         v4l2-ctl-8362  [000] ....   235.651264: csi_s_stream: enable : 0x1
[2022-11-24 16:52:52.343]         v4l2-ctl-8362  [000] ....   235.651275: tegra_channel_set_stream: imx623 2-001b : 0x1
[2022-11-24 16:52:52.343]      kworker/0:1-796   [000] ....   235.657109: rtos_queue_peek_from_isr_failed: tstamp:7685041914 queue:0x0bcbb8b8
[2022-11-24 16:52:52.343]      kworker/0:1-796   [000] ....   235.657113: rtcpu_start: tstamp:7685044276
[2022-11-24 16:52:52.343]      kworker/0:1-796   [000] ....   235.657115: rtos_queue_send_from_isr_failed: tstamp:7685081247 queue:0x0bcb2b38
[2022-11-24 16:52:52.343]      kworker/0:1-796   [000] ....   235.657116: rtos_queue_send_from_isr_failed: tstamp:7685081386 queue:0x0bcb73a0
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657117: rtos_queue_send_from_isr_failed: tstamp:7685081523 queue:0x0bcb8f20
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657117: rtos_queue_send_from_isr_failed: tstamp:7685081659 queue:0x0bcb9ce0
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657118: rtos_queue_send_from_isr_failed: tstamp:7685081793 queue:0x0bcbaaa0
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657120: rtcpu_string: tstamp:7685082205 id:0x04010000 str:"Configuring VI GoS.
[2022-11-24 16:52:52.363] "
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657141: rtcpu_string: tstamp:7685082388 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
[2022-11-24 16:52:52.363] "
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657149: rtcpu_string: tstamp:7685082631 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
[2022-11-24 16:52:52.363] "
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657156: rtcpu_string: tstamp:7685082860 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
[2022-11-24 16:52:52.363] "
[2022-11-24 16:52:52.363]      kworker/0:1-796   [000] ....   235.657183: rtcpu_string: tstamp:7685083078 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
[2022-11-24 16:52:52.377] "
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657189: rtcpu_string: tstamp:7685083309 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
[2022-11-24 16:52:52.377] "
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657195: rtcpu_string: tstamp:7685083525 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
[2022-11-24 16:52:52.377] "
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657201: rtcpu_string: tstamp:7685091038 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657202: rtcpu_string: tstamp:7685091143 id:0x04010000 str:"on 2.2
[2022-11-24 16:52:52.377] "
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657208: rtos_queue_send_from_isr_failed: tstamp:7685121977 queue:0x0bcb2b38
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657209: rtos_queue_send_from_isr_failed: tstamp:7685122129 queue:0x0bcb73a0
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657210: rtos_queue_send_from_isr_failed: tstamp:7685122270 queue:0x0bcb8f20
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657210: rtos_queue_send_from_isr_failed: tstamp:7685122405 queue:0x0bcb9ce0
[2022-11-24 16:52:52.377]      kworker/0:1-796   [000] ....   235.657211: rtos_queue_send_from_isr_failed: tstamp:7685122537 queue:0x0bcbaaa0
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657211: rtcpu_string: tstamp:7685123375 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
[2022-11-24 16:52:52.387] "
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657217: rtos_queue_send_from_isr_failed: tstamp:7685171352 queue:0x0bcb2b38
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657218: rtos_queue_send_from_isr_failed: tstamp:7685171501 queue:0x0bcb73a0
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657219: rtos_queue_send_from_isr_failed: tstamp:7685171641 queue:0x0bcb8f20
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657219: rtos_queue_send_from_isr_failed: tstamp:7685171775 queue:0x0bcb9ce0
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657220: rtos_queue_send_from_isr_failed: tstamp:7685171907 queue:0x0bcbaaa0
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657221: rtcpu_nvcsi_intr: tstamp:7685174373 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000001
[2022-11-24 16:52:52.387]      kworker/0:1-796   [000] ....   235.657222: rtcpu_nvcsi_intr: tstamp:7685178110 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000110
[2022-11-24 16:52:52.403]      kworker/0:1-796   [000] ....   235.657223: rtcpu_nvcsi_intr: tstamp:7685178110 class:GLOBAL type:PHY_INTR0 phy:0 cil:1 st:0 vc:0 status:0x00000110
[2022-11-24 16:52:52.403]      kworker/0:1-796   [000] ....   235.657223: rtcpu_nvcsi_intr: tstamp:7685178110 class:CORRECTABLE_ERR type:PHY_INTR phy:0 cil:0 st:0 vc:0 status:0x00000110
[2022-11-24 16:52:52.403]      kworker/0:1-796   [000] ....   235.657224: rtcpu_nvcsi_intr: tstamp:7685178110 class:CORRECTABLE_ERR type:PHY_INTR phy:0 cil:1 st:0 vc:0 status:0x00000110
[2022-11-24 16:52:52.403]      kworker/0:1-796   [000] ....   235.657226: rtcpu_vinotify_error: tstamp:7685179482 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:7685178463 data:0x00000001
[2022-11-24 16:52:52.403]      kworker/0:1-796   [000] ....   235.713102: rtcpu_vinotify_event: tstamp:7685403773 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:9700775424 data:0x10000000
[2022-11-24 16:52:52.403]      kworker/0:1-796   [000] ....   235.713106: rtcpu_vinotify_event: tstamp:7685403909 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:9700779232 data:0x31000001
[2022-11-24 16:52:52.417]      kworker/0:1-796   [000] ....   235.713107: rtcpu_vinotify_event: tstamp:7685404054 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:9700780224 data:0x07020001
[2022-11-24 16:52:52.417]      kworker/0:1-796   [000] ....   235.713108: rtcpu_vinotify_event: tstamp:7685404180 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:9700816096 data:0x10000000
[2022-11-24 16:52:52.417]      kworker/0:1-796   [000] ....   235.713109: rtcpu_vinotify_event: tstamp:7685404324 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:9700819936 data:0x31000002
[2022-11-24 16:52:52.417]      kworker/0:1-796   [000] ....   235.713110: rtcpu_vinotify_event: tstamp:7685404456 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:7685178463 data:0x00000001
[2022-11-24 16:52:52.417]      kworker/0:1-796   [000] ....   235.713137: rtcpu_vinotify_error: tstamp:7685434089 tag:CHANSEL_NOMATCH channel:0x41 frame:6000 vi_tstamp:7685433421 data:0x000005a9
[2022-11-24 16:52:52.417]      kworker/0:1-796   [000] ....   235.713138: rtcpu_vinotify_event: tstamp:7685716759 tag:FS channel:0x01 frame:6000 vi_tstamp:7685432610 data:0x00000010
[2022-11-24 16:52:52.434]      kworker/0:1-796   [000] ....   235.713140: rtcpu_vinotify_event: tstamp:7685716884 tag:CHANSEL_NOMATCH channel:0x41 frame:6000 vi_tstamp:7685433421 data:0x000005a9
[2022-11-24 16:52:52.434]      kworker/0:1-796   [000] ....   235.713141: rtcpu_vinotify_error: tstamp:7686129338 tag:CHANSEL_NOMATCH channel:0x41 frame:6001 vi_tstamp:7686128681 data:0x000005a9
[2022-11-24 16:52:52.434]      kworker/0:1-796   [000] ....   235.713142: rtcpu_vinotify_event: tstamp:7686342781 tag:FE channel:0x01 frame:6000 vi_tstamp:7686102831 data:0x00000020
[2022-11-24 16:52:52.434]      kworker/0:1-796   [000] ....   235.713143: rtcpu_vinotify_event: tstamp:7686342906 tag:FS channel:0x01 frame:6001 vi_tstamp:7686127872 data:0x00000010
[2022-11-24 16:52:52.434]      kworker/0:1-796   [000] ....   235.713145: rtcpu_vinotify_event: tstamp:7686343048 tag:CHANSEL_NOMATCH channel:0x41 frame:6001 vi_tstamp:7686128681 data:0x000005a9
[2022-11-24 16:52:52.434]      kworker/0:1-796   [000] ....   235.713146: rtcpu_vinotify_error: tstamp:7686824596 tag:CHANSEL_NOMATCH channel:0x41 frame:6002 vi_tstamp:7686823944 data:0x000005a9
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.713147: rtcpu_vinotify_event: tstamp:7686968804 tag:FE channel:0x01 frame:6001 vi_tstamp:7686798094 data:0x00000020
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.713148: rtcpu_vinotify_event: tstamp:7686968944 tag:FS channel:0x01 frame:6002 vi_tstamp:7686823134 data:0x00000010
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.713149: rtcpu_vinotify_event: tstamp:7686969069 tag:CHANSEL_NOMATCH channel:0x41 frame:6002 vi_tstamp:7686823944 data:0x000005a9
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.769100: rtcpu_vinotify_event: tstamp:7687518917 tag:FE channel:0x01 frame:6002 vi_tstamp:7687493355 data:0x00000020
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.769103: rtcpu_vinotify_event: tstamp:7687519049 tag:FS channel:0x01 frame:6003 vi_tstamp:7687518396 data:0x00000010
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.769105: rtcpu_vinotify_error: tstamp:7687519857 tag:CHANSEL_NOMATCH channel:0x41 frame:6003 vi_tstamp:7687519206 data:0x000005a9
[2022-11-24 16:52:52.450]      kworker/0:1-796   [000] ....   235.769106: rtcpu_vinotify_event: tstamp:7687813936 tag:CHANSEL_NOMATCH channel:0x41 frame:6003 vi_tstamp:7687519206 data:0x000005a9
[2022-11-24 16:52:52.466]      kworker/0:1-796   [000] ....   235.769107: rtcpu_vinotify_error: tstamp:7688215119 tag:CHANSEL_NOMATCH channel:0x41 frame:6004 vi_tstamp:7688214467 data:0x000005a9

hello tagoshi,

rtcpu_nvcsi_intr: tstamp:7685178110 class:CORRECTABLE_ERR type:PHY_INTR phy:0 cil:0 st:0 vc:0 status:0x00000110
rtcpu_nvcsi_intr: tstamp:7685178110 class:CORRECTABLE_ERR type:PHY_INTR phy:0 cil:1 st:0 vc:0 status:0x00000110

there’re correctable errors for PHY interrupt.
these PHY_INTR status:0x00000110 it means there’s data lane [A/B] 0, and 1 Rx FIFO overflow.

I see,
for using a SerDes chip, it’s suggested to toggle a reset signal when you launching camera application. to be more specific, you may reset the signal before s_stream.
please have a try, you may ignore CHANSEL_NOMATCH for now since it’s minor to SerDes use-case.

Hi, JerryChang,
Thank you for reply.

there’re correctable errors for PHY interrupt.
these PHY_INTR status:0x00000110 it means there’s data lane [A/B] 0, and 1 Rx FIFO overflow.

How can I fix this overflow issue? Does it mean that my DT parameters, for example active_w, active_h, line_length , might be wrong?

for using a SerDes chip, it’s suggested to toggle a reset signal when you launching camera application. to be more specific, you may reset the signal before s_stream.
please have a try, you may ignore CHANSEL_NOMATCH for now since it’s minor to SerDes use-case.

Thanks, currently I implemented dummy sensor ops in IMX device driver as followings, so I’ll fix start_streaming and stop_streaming function to work it.
I’ll try it and report that result.

static struct camera_common_sensor_ops imxXXX_common_ops_dummy = {
	.numfrmfmts = ARRAY_SIZE(imxXXX_frmfmt),
	.frmfmt_table = imxXXX_frmfmt,
	.power_on = imxXXX_power_on_dummy,
	.power_off = imxXXX_power_off_dummy,
	.write_reg = imxXXX_write_reg_dummy,
	.read_reg = imxXXX_read_reg_dummy,
	.parse_dt = imxXXX_parse_dt,
	.power_get = imxXXX_power_get_dummy,
	.power_put = imxXXX_power_put_dummy,
	.set_mode = imxXXX_set_mode_dummy,
	.start_streaming = imxXXX_start_streaming_dummy,
	.stop_streaming = imxXXX_stop_streaming_dummy,
};

hello tagoshi,

that might caused by you keep streaming always-on, so please try toggle a reset signal for confirmation.

After implemented start_streaming and stop_streaming function, PHY interrupt error seemed to disappear from log.
But still has error. "tag:CHANSEL_NOMATCH " by below commnad.

v4l2-ctl -d /dev/video0 --set-fmt-video=width=1920,height=1552,pixelformat=RG14 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 --stream-to=test14.raw --verbose

Please kindly give some advice.

[2022-11-25 16:04:42.642]      kworker/0:2-1710  [000] ....    91.371102: rtos_queue_peek_from_isr_failed: tstamp:3536442268 queue:0x0bcbb8b8
[2022-11-25 16:04:42.642]      kworker/0:2-1710  [000] ....    91.371105: rtos_queue_peek_from_isr_failed: tstamp:3536565179 queue:0x0bcbb8b8
[2022-11-25 16:04:42.642]         v4l2-ctl-8310  [003] ....   140.903360: tegra_channel_open: vi-output, imx623 2-001b
[2022-11-25 16:04:42.642]         v4l2-ctl-8310  [000] ....   140.905747: tegra_channel_set_power: imx623 2-001b : 0x1
[2022-11-25 16:04:42.642]         v4l2-ctl-8310  [000] ....   140.905759: camera_common_s_power: status : 0x1
[2022-11-25 16:04:42.642]         v4l2-ctl-8310  [000] ....   140.905869: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
[2022-11-25 16:04:42.642]         v4l2-ctl-8310  [000] ....   140.905872: csi_s_power: enable : 0x1
[2022-11-25 16:04:42.642]         v4l2-ctl-8310  [002] ....   140.916769: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1552 fmt c4
[2022-11-25 16:04:42.656]         v4l2-ctl-8310  [003] ....   140.922649: tegra_channel_set_stream: enable : 0x1
[2022-11-25 16:04:42.656]         v4l2-ctl-8310  [002] ....   140.926109: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x1
[2022-11-25 16:04:42.656]         v4l2-ctl-8310  [002] ....   140.926114: csi_s_stream: enable : 0x1
[2022-11-25 16:04:42.656]         v4l2-ctl-8310  [002] ....   140.926127: tegra_channel_set_stream: imx623 2-001b : 0x1
[2022-11-25 16:04:42.656]      kworker/0:2-1710  [000] ....   140.935129: rtos_queue_peek_from_isr_failed: tstamp:5085879868 queue:0x0bcbb8b8
[2022-11-25 16:04:42.656]      kworker/0:2-1710  [000] ....   140.935134: rtcpu_start: tstamp:5085881419
[2022-11-25 16:04:42.656]      kworker/0:2-1710  [000] ....   140.935137: rtos_queue_send_from_isr_failed: tstamp:5085898316 queue:0x0bcb2b38
[2022-11-25 16:04:42.656]      kworker/0:2-1710  [000] ....   140.935138: rtos_queue_send_from_isr_failed: tstamp:5085898453 queue:0x0bcb73a0
[2022-11-25 16:04:42.656]      kworker/0:2-1710  [000] ....   140.935139: rtos_queue_send_from_isr_failed: tstamp:5085898592 queue:0x0bcb8f20
[2022-11-25 16:04:42.656]      kworker/0:2-1710  [000] ....   140.935140: rtos_queue_send_from_isr_failed: tstamp:5085898726 queue:0x0bcb9ce0
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935141: rtos_queue_send_from_isr_failed: tstamp:5085898859 queue:0x0bcbaaa0
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935143: rtcpu_string: tstamp:5085899261 id:0x04010000 str:"Configuring VI GoS.
[2022-11-25 16:04:42.667] "
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935174: rtcpu_string: tstamp:5085899442 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
[2022-11-25 16:04:42.667] "
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935191: rtcpu_string: tstamp:5085899680 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
[2022-11-25 16:04:42.667] "
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935207: rtcpu_string: tstamp:5085899907 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
[2022-11-25 16:04:42.667] "
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935222: rtcpu_string: tstamp:5085900122 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
[2022-11-25 16:04:42.667] "
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935237: rtcpu_string: tstamp:5085900370 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
[2022-11-25 16:04:42.667] "
[2022-11-25 16:04:42.667]      kworker/0:2-1710  [000] ....   140.935252: rtcpu_string: tstamp:5085900586 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
[2022-11-25 16:04:42.672] "
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935267: rtcpu_string: tstamp:5085908111 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935269: rtcpu_string: tstamp:5085908216 id:0x04010000 str:"on 2.2
[2022-11-25 16:04:42.672] "
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935284: rtos_queue_send_from_isr_failed: tstamp:5085922002 queue:0x0bcb2b38
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935285: rtos_queue_send_from_isr_failed: tstamp:5085922142 queue:0x0bcb73a0
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935286: rtos_queue_send_from_isr_failed: tstamp:5085922285 queue:0x0bcb8f20
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935287: rtos_queue_send_from_isr_failed: tstamp:5085922417 queue:0x0bcb9ce0
[2022-11-25 16:04:42.672]      kworker/0:2-1710  [000] ....   140.935288: rtos_queue_send_from_isr_failed: tstamp:5085922550 queue:0x0bcbaaa0
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935289: rtcpu_string: tstamp:5085923421 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
[2022-11-25 16:04:42.980] "
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935304: rtos_queue_send_from_isr_failed: tstamp:5086033936 queue:0x0bcb2b38
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935305: rtos_queue_send_from_isr_failed: tstamp:5086034081 queue:0x0bcb73a0
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935306: rtos_queue_send_from_isr_failed: tstamp:5086034221 queue:0x0bcb8f20
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935307: rtos_queue_send_from_isr_failed: tstamp:5086034353 queue:0x0bcb9ce0
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935308: rtos_queue_send_from_isr_failed: tstamp:5086034489 queue:0x0bcbaaa0
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935310: rtcpu_nvcsi_intr: tstamp:5086037009 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000001
[2022-11-25 16:04:42.980]      kworker/0:2-1710  [000] ....   140.935313: rtcpu_vinotify_event: tstamp:5086220815 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:3835787488 data:0x10000000
[2022-11-25 16:04:42.997]      kworker/0:2-1710  [000] ....   140.935314: rtcpu_vinotify_event: tstamp:5086220947 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:3835791296 data:0x31000001
[2022-11-25 16:04:42.997]      kworker/0:2-1710  [000] ....   140.935315: rtcpu_vinotify_event: tstamp:5086221090 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:3835792288 data:0x07020001
[2022-11-25 16:04:42.997]      kworker/0:2-1710  [000] ....   140.935316: rtcpu_vinotify_event: tstamp:5086221215 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:3835828032 data:0x10000000
[2022-11-25 16:04:42.997]      kworker/0:2-1710  [000] ....   140.935317: rtcpu_vinotify_event: tstamp:5086221357 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:3835831840 data:0x31000002
[2022-11-25 16:04:42.997]      kworker/0:2-1710  [000] ....   141.047122: rtcpu_vinotify_error: tstamp:5088379264 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:5088378598 data:0x00000001
[2022-11-25 16:04:42.997]      kworker/0:2-1710  [000] ....   141.047126: rtcpu_vinotify_event: tstamp:5088411848 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:5088378598 data:0x00000001
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047128: rtcpu_vinotify_error: tstamp:5088962197 tag:CHANSEL_NOMATCH channel:0x41 frame:2 vi_tstamp:5088961537 data:0x000005a9
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047129: rtcpu_vinotify_event: tstamp:5089037853 tag:FS channel:0x01 frame:2 vi_tstamp:5088960727 data:0x00000010
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047130: rtcpu_vinotify_event: tstamp:5089037978 tag:CHANSEL_NOMATCH channel:0x41 frame:2 vi_tstamp:5088961537 data:0x000005a9
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047132: rtcpu_vinotify_error: tstamp:5089656595 tag:CHANSEL_NOMATCH channel:0x41 frame:3 vi_tstamp:5089655940 data:0x000005a9
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047133: rtcpu_vinotify_event: tstamp:5089663879 tag:FE channel:0x01 frame:2 vi_tstamp:5089630943 data:0x00000020
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047134: rtcpu_vinotify_event: tstamp:5089664003 tag:FS channel:0x01 frame:3 vi_tstamp:5089655129 data:0x00000010
[2022-11-25 16:04:43.011]      kworker/0:2-1710  [000] ....   141.047136: rtcpu_vinotify_event: tstamp:5089664145 tag:CHANSEL_NOMATCH channel:0x41 frame:3 vi_tstamp:5089655940 data:0x000005a9
[2022-11-25 16:04:43.014]      kworker/0:2-1710  [000] ....   141.103111: rtcpu_vinotify_error: tstamp:5090350998 tag:CHANSEL_NOMATCH channel:0x41 frame:4 vi_tstamp:5090350343 data:0x000005a9
[2022-11-25 16:04:43.014]      kworker/0:2-1710  [000] ....   141.103114: rtcpu_vinotify_event: tstamp:5090602917 tag:FE channel:0x01 frame:3 vi_tstamp:5090325347 data:0x00000020
[2022-11-25 16:04:43.014]      kworker/0:2-1710  [000] ....   141.103116: rtcpu_vinotify_event: tstamp:5090603075 tag:FS channel:0x01 frame:4 vi_tstamp:5090349532 data:0x00000010
[2022-11-25 16:04:43.014]      kworker/0:2-1710  [000] ....   141.103147: rtcpu_vinotify_event: tstamp:5090603199 tag:CHANSEL_NOMATCH channel:0x41 frame:4 vi_tstamp:5090350343 data:0x000005a9
[2022-11-25 16:04:43.014]      kworker/0:2-1710  [000] ....   141.103149: rtos_queue_peek_from_isr_failed: tstamp:5090880267 queue:0x0bcbb8b8
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.103151: rtcpu_vinotify_event: tstamp:5091045305 tag:FE channel:0x01 frame:4 vi_tstamp:5091019749 data:0x00000020
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.103152: rtcpu_vinotify_event: tstamp:5091045431 tag:FS channel:0x01 frame:5 vi_tstamp:5091044789 data:0x00000010
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.103154: rtcpu_vinotify_error: tstamp:5091046245 tag:CHANSEL_NOMATCH channel:0x41 frame:5 vi_tstamp:5091045600 data:0x000005a9
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.103155: rtcpu_vinotify_event: tstamp:5091354139 tag:CHANSEL_NOMATCH channel:0x41 frame:5 vi_tstamp:5091045600 data:0x000005a9
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.159122: rtcpu_vinotify_error: tstamp:5091741511 tag:CHANSEL_NOMATCH channel:0x41 frame:6 vi_tstamp:5091740856 data:0x000005a9
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.159127: rtcpu_vinotify_event: tstamp:5091980073 tag:FE channel:0x01 frame:5 vi_tstamp:5091715006 data:0x00000020
[2022-11-25 16:04:43.341]      kworker/0:2-1710  [000] ....   141.159128: rtcpu_vinotify_event: tstamp:5091980213 tag:FS channel:0x01 frame:6 vi_tstamp:5091740046 data:0x00000010
[2022-11-25 16:04:43.350]      kworker/0:2-1710  [000] ....   141.159130: rtcpu_vinotify_event: tstamp:5091980336 tag:CHANSEL_NOMATCH channel:0x41 frame:6 vi_tstamp:5091740856 data:0x000005a9
[2022-11-25 16:04:43.350]      kworker/0:2-1710  [000] ....   141.159131: rtcpu_vinotify_error: tstamp:5092436765 tag:CHANSEL_NOMATCH channel:0x41 frame:7 vi_tstamp:5092436114 data:0x000005a9
[2022-11-25 16:04:43.350]      kworker/0:2-1710  [000] ....   141.159132: rtcpu_vinotify_event: tstamp:5092606100 tag:FE channel:0x01 frame:6 vi_tstamp:5092410263 data:0x00000020
[2022-11-25 16:04:43.350]      kworker/0:2-1710  [000] ....   141.159133: rtcpu_vinotify_event: tstamp:5092606223 tag:FS channel:0x01 frame:7 vi_tstamp:5092435303 data:0x00000010
[2022-11-25 16:04:43.350]      kworker/0:2-1710  [000] ....   141.159134: rtcpu_vinotify_event: tstamp:5092606366 tag:CHANSEL_NOMATCH channel:0x41 frame:7 vi_tstamp:5092436114 data:0x000005a9
[2022-11-25 16:04:43.350]      kworker/0:2-1710  [000] ....   141.159135: rtcpu_vinotify_error: tstamp:5093132022 tag:CHANSEL_NOMATCH channel:0x41 frame:8 vi_tstamp:5093131370 data:0x000005a9
[2022-11-25 16:04:43.365]      kworker/0:2-1710  [000] ....   141.159136: rtcpu_vinotify_event: tstamp:5093232128 tag:FE channel:0x01 frame:7 vi_tstamp:5093105520 data:0x00000020
[2022-11-25 16:04:43.365]      kworker/0:2-1710  [000] ....   141.159137: rtcpu_vinotify_event: tstamp:5093232270 tag:FS channel:0x01 frame:8 vi_tstamp:5093130559 data:0x00000010
[2022-11-25 16:04:43.365]      kworker/0:2-1710  [000] ....   141.159139: rtcpu_vinotify_event: tstamp:5093232395 tag:CHANSEL_NOMATCH channel:0x41 frame:8 vi_tstamp:5093131370 data:0x000005a9
[2022-11-25 16:04:43.365]      kworker/0:2-1710  [000] ....   141.215134: rtcpu_vinotify_error: tstamp:5093827280 tag:CHANSEL_NOMATCH channel:0x41 frame:9 vi_tstamp:5093826628 data:0x000005a9
[2022-11-25 16:04:43.365]      kworker/0:2-1710  [000] ....   141.215137: rtcpu_vinotify_event: tstamp:5093858154 tag:FE channel:0x01 frame:8 vi_tstamp:5093800777 data:0x00000020
[2022-11-25 16:04:43.365]      kworker/0:2-1710  [000] ....   141.215139: rtcpu_vinotify_event: tstamp:5093858280 tag:FS channel:0x01 frame:9 vi_tstamp:5093825817 data:0x00000010
[2022-11-25 16:04:43.375]      kworker/0:2-1710  [000] ....   141.215141: rtcpu_vinotify_event: tstamp:5093858422 tag:CHANSEL_NOMATCH channel:0x41 frame:9 vi_tstamp:5093826628 data:0x000005a9
[2022-11-25 16:04:43.375]      kworker/0:2-1710  [000] ....   141.215142: rtcpu_vinotify_error: tstamp:5094522535 tag:CHANSEL_NOMATCH channel:0x41 frame:10 vi_tstamp:5094521885 data:0x000005a9
[2022-11-25 16:04:43.375]      kworker/0:2-1710  [000] ....   141.215143: rtcpu_vinotify_event: tstamp:5094522795 tag:FE channel:0x01 frame:9 vi_tstamp:5094496034 data:0x00000020
[2022-11-25 16:04:43.375]      kworker/0:2-1710  [000] ....   141.215144: rtcpu_vinotify_event: tstamp:5094522937 tag:FS channel:0x01 frame:10 vi_tstamp:5094521073 data:0x00000010
[2022-11-25 16:04:43.375]      kworker/0:2-1710  [000] ....   141.215146: rtcpu_vinotify_event: tstamp:5094523061 tag:CHANSEL_NOMATCH channel:0x41 frame:10 vi_tstamp:5094521885 data:0x000005a9
[2022-11-25 16:04:43.375]      kworker/0:2-1710  [000] ....   141.271108: rtcpu_vinotify_event: tstamp:5095204113 tag:FE channel:0x01 frame:10 vi_tstamp:5095191291 data:0x00000020
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271111: rtcpu_vinotify_error: tstamp:5095217787 tag:CHANSEL_NOMATCH channel:0x41 frame:11 vi_tstamp:5095217141 data:0x000005a9
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271113: rtcpu_vinotify_event: tstamp:5095517101 tag:FS channel:0x01 frame:11 vi_tstamp:5095216331 data:0x00000010
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271115: rtcpu_vinotify_event: tstamp:5095517241 tag:CHANSEL_NOMATCH channel:0x41 frame:11 vi_tstamp:5095217141 data:0x000005a9
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271118: rtos_queue_peek_from_isr_failed: tstamp:5095880269 queue:0x0bcbb8b8
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271119: rtcpu_vinotify_error: tstamp:5095913054 tag:CHANSEL_NOMATCH channel:0x41 frame:12 vi_tstamp:5095912397 data:0x000005a9
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271121: rtcpu_vinotify_event: tstamp:5096143037 tag:FE channel:0x01 frame:11 vi_tstamp:5095886548 data:0x00000020
[2022-11-25 16:04:43.674]      kworker/0:2-1710  [000] ....   141.271122: rtcpu_vinotify_event: tstamp:5096143179 tag:FS channel:0x01 frame:12 vi_tstamp:5095911589 data:0x00000010
[2022-11-25 16:04:43.694]      kworker/0:2-1710  [000] ....   141.271123: rtcpu_vinotify_event: tstamp:5096143304 tag:CHANSEL_NOMATCH channel:0x41 frame:12 vi_tstamp:5095912397 data:0x000005a9
[2022-11-25 16:04:43.694]      kworker/0:2-1710  [000] ....   141.271125: rtcpu_vinotify_error: tstamp:5096608313 tag:CHANSEL_NOMATCH channel:0x41 frame:13 vi_tstamp:5096607656 data:0x000005a9
[2022-11-25 16:04:43.694]      kworker/0:2-1710  [000] ....   141.271126: rtcpu_vinotify_event: tstamp:5096769060 tag:FE channel:0x01 frame:12 vi_tstamp:5096581805 data:0x00000020
[2022-11-25 16:04:43.694]      kworker/0:2-1710  [000] ....   141.271127: rtcpu_vinotify_event: tstamp:5096769185 tag:FS channel:0x01 frame:13 vi_tstamp:5096606844 data:0x00000010
[2022-11-25 16:04:43.694]      kworker/0:2-1710  [000] ....   141.271158: rtcpu_vinotify_event: tstamp:5096769325 tag:CHANSEL_NOMATCH channel:0x41 frame:13 vi_tstamp:5096607656 data:0x000005a9
[2022-11-25 16:04:43.694]      kworker/0:2-1710  [000] ....   141.327117: rtcpu_vinotify_error: tstamp:5097303564 tag:CHANSEL_NOMATCH channel:0x41 frame:14 vi_tstamp:5097302913 data:0x000005a9

hello tagoshi,

by checking… CHANSEL_NOMATCH = 0x5a9; DTYPE= 0x2D = 45d
the NVCSI datatypes is… #define NVCSI_DATATYPE_RAW14 U32_C(45)

may I know what’s your device tree settings.
is it looking like below?

                                mode_type = "bayer";
                                pixel_phase = "rggb";
                                csi_pixel_bit_depth = "14";

is it able to enable v4l utility for checking?
may I also know the format dumps by… $ v4l2-ctl -d /dev/video0 --list-formats- ext

this is my DT parameter, I think it is correct…

			mode0 {
				mclk_khz = "24000";
				num_lanes = "4";
				tegra_sinterface = "serial_a";
				phy_mode = "DPHY";
				discontinuous_clk = "no";
				dpcm_enable = "false";
				cil_settletime = "0";
				dynamic_pixel_bit_depth = "14";
				csi_pixel_bit_depth = "14";
				mode_type = "bayer";
				pixel_phase = "rggb";

may I also know the format dumps by… $ v4l2-ctl -d /dev/video0 --list-formats-ext

This result is as below

 v4l2-ctl -d /dev/video0 --list-formats-ext
ioctl: VIDIOC_ENUM_FMT
        Index       : 0
        Type        : Video Capture
        Pixel Format: 'RG14'
        Name        : 14-bit Bayer RGRG/GBGB
                Size: Discrete 1920x1552
                        Interval: Discrete 0.022s (45.000 fps)

hello tagoshi,

ya, that looks correct.

please follow below commands to boost all the VI/CSI/ISP clocks.
this may workaround the issue related to pixel clock settings.
for example,

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

Thank you prompt reply,

I have already done following setting before v4l2-ctl command.

killall nvargus-daemon
export enableCamPclLogs=5
export enableCamScfLogs=5

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

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
cat /sys/kernel/debug/tracing/trace

BTW, after modified RAW14 code and rebuild kernel, is it needed to add some .ko file which is related with RAW14 format?
Currently, I just add only two files into JETSON rootfs after rebuild kernel.
It is, kernel image file to /boot/image, and imx driver(.ko) to specific directory. (if needed, update dtb file too, of course)

Are some v4l2 or CSI drivers for RAW14 built as kernel module (.ko)?
If so, I might not add it my JETSON rootfs.

after modified RAW14 code and rebuild kernel, is it needed to add some .ko file which is related with RAW14 format?

It seems that camera_common.c, sensor_common.c, and v4l2-ioctl.c are built as built-in module.
No kernel module(.ko) is affected by RAW14 modification except for mods.ko.

I have never updated mods.ko located under “/lib/modules/”, but I suppose it doesn’t matter.

Hi JerryChang,
To check if datatype is set correctly in kernel, I added simple debug code as below.

diff --git a/sources/kernel/nvidia/drivers/media/platform/tegra/camera/nvcsi/csi5_fops.c b/sources/kernel/nvidia/drivers/media/platform/tegra/camera/nvcsi/csi5_fops.c
index 73b2ad7c4..fb4a713aa 100644
--- a/sources/kernel/nvidia/drivers/media/platform/tegra/camera/nvcsi/csi5_fops.c
+++ b/sources/kernel/nvidia/drivers/media/platform/tegra/camera/nvcsi/csi5_fops.c
@@ -213,6 +213,7 @@ static int csi5_stream_tpg_start(struct tegra_csi_channel *chan, u32 stream_id,
 
 	tpg_config->t194.virtual_channel_id = virtual_channel_id;
 	tpg_config->t194.datatype = port->core_format->img_dt;
+	dev_info(csi->dev, "chk [%s:%d] datatype=0x%x.\n", __func__, __LINE__, tpg_config->t194.datatype);
 
 	tpg_config->t194.lane_count = TPG_BLANK;
 	tpg_config->t194.flags = NVCSI_TPG_FLAG_PATCH_MODE;
diff --git a/sources/kernel/nvidia/drivers/media/platform/tegra/camera/vi/vi5_fops.c b/sources/kernel/nvidia/drivers/media/platform/tegra/camera/vi/vi5_fops.c
index b88a3802d..fbc813189 100644
--- a/sources/kernel/nvidia/drivers/media/platform/tegra/camera/vi/vi5_fops.c
+++ b/sources/kernel/nvidia/drivers/media/platform/tegra/camera/vi/vi5_fops.c
@@ -307,6 +307,7 @@ static void vi5_setup_surface(struct tegra_channel *chan,
 	desc->ch_cfg.frame.frame_x = width;
 	desc->ch_cfg.frame.frame_y = height;
 	desc->ch_cfg.match.datatype = data_type;
+	dev_info(chan->vi->dev, "chk [%s:%d] datatype=0x%x.\n", __func__, __LINE__, data_type);
 	desc->ch_cfg.match.datatype_mask = 0x3f;
 	desc->ch_cfg.pixfmt_enable = 1;
 	desc->ch_cfg.pixfmt.format = format;

Then, executed this command.

v4l2-ctl -d /dev/video0 --set-fmt-video=width=1920,height=1552,pixelformat=RG14 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 --stream-to=test14.raw --verbose

It seemed that kernel log told that datatype is set correctly, 0x2d.

[  418.369753] tegra194-vi5 15c10000.vi: chk [vi5_setup_surface:310] datatype=0x2d.
[  418.369906] tegra194-vi5 15c10000.vi: chk [vi5_setup_surface:310] datatype=0x2d.

But CHANSEL_NOMATCH error for 0x2D still appeared.

     kworker/1:3-2041  [001] ....   418.428478: rtcpu_nvcsi_intr: tstamp:13383340423 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000001
     kworker/1:3-2041  [001] ....   418.428479: rtcpu_vinotify_event: tstamp:13383573796 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:11653246784 data:0x10000000
     kworker/1:3-2041  [001] ....   418.428480: rtcpu_vinotify_event: tstamp:13383573926 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:11653250560 data:0x31000001
     kworker/1:3-2041  [001] ....   418.428481: rtcpu_vinotify_event: tstamp:13383574070 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:11653251552 data:0x07020001
     kworker/1:3-2041  [001] ....   418.428481: rtcpu_vinotify_event: tstamp:13383574194 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:11653383296 data:0x10000000
     kworker/1:3-2041  [001] ....   418.428482: rtcpu_vinotify_event: tstamp:13383574334 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:11653387104 data:0x31000002
     kworker/1:3-2041  [001] ....   418.483206: rtcpu_vinotify_error: tstamp:13385685091 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:13385684427 data:0x00000001
     kworker/1:3-2041  [001] ....   418.483209: rtcpu_vinotify_event: tstamp:13385764877 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:13385684427 data:0x00000001
     kworker/1:3-2041  [001] ....   418.483211: rtcpu_vinotify_error: tstamp:13386279553 tag:CHANSEL_NOMATCH channel:0x41 frame:2 vi_tstamp:13386278899 data:0x000005a9
     kworker/1:3-2041  [001] ....   418.483212: rtcpu_vinotify_event: tstamp:13386390894 tag:FS channel:0x01 frame:2 vi_tstamp:13386278087 data:0x00000010

Does this messages mean that VI/CSI definitely recieved MIPI data with 0x2D datatype?
If so, what might cause unmatch issue? what VI/CSI kernel parameter may be wrong?

May I ask you give me advice to debug this issue?
I can add more kernel printk or other debug code in kernel, if needed.