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

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.

I found “CSIMUX_STREAM” exists in my log and checked below wiki.
https://elinux.org/Jetson/l4t/Camera_BringUp

Does “tag:CSIMUX_STREAM” with data “data:0x00000001” means “FIFO_OVERFLOW_STREAM_0” ?
If so, should I fix this error at first and what might cause this error?
e.g.) active_w or line_length may be unmatched?

     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

hello tagoshi,

the failure is spurious data stream.
by checking your VI tracing logs again (in comment #18), it looks your 1st FS/FE is missing.
for example, that very beginning of FS/FE is identify with frame:2.

rtcpu_vinotify_error: tstamp:5088379264 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:5088378598 data:0x00000001
rtcpu_vinotify_event: tstamp:5088411848 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:5088378598 data:0x00000001
rtcpu_vinotify_error: tstamp:5088962197 tag:CHANSEL_NOMATCH channel:0x41 frame:2 vi_tstamp:5088961537 data:0x000005a9
rtcpu_vinotify_event: tstamp:5089037853 tag:FS channel:0x01 frame:2 vi_tstamp:5088960727 data:0x00000010
rtcpu_vinotify_event: tstamp:5089663879 tag:FE channel:0x01 frame:2 vi_tstamp:5089630943 data:0x00000020
...

it may due to there’re delay between s_stream and 1st frame coming to CSI brick.
had you try adding set_mode_delay_ms property?

Hi JerryChang,
I added set_mode_delay_ms in DT, whose value is 2000, but result doesn’t change.

cat ./i2c@3180000/imxXXX_a@1b/set_mode_delay_ms
2000

As a test, I grepped in my kernel code tree with string “set_mode_delay_ms”.

grep -r “set_mode_delay_ms”

But there was no match pattern. Could you tell me where this DT value is used in kernel source?
I would like to confirm that my kernel version is correct.

cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 1194/1194   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
     kworker/1:1-796   [001] ....   192.753302: rtos_queue_peek_from_isr_failed: tstamp:6328904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   192.921282: rtos_queue_peek_from_isr_failed: tstamp:6333904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   193.089280: rtos_queue_peek_from_isr_failed: tstamp:6338904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   193.201280: rtos_queue_peek_from_isr_failed: tstamp:6343904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   193.369275: rtos_queue_peek_from_isr_failed: tstamp:6348904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   193.537294: rtos_queue_peek_from_isr_failed: tstamp:6353904366 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   193.705287: rtos_queue_peek_from_isr_failed: tstamp:6358904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   193.873281: rtos_queue_peek_from_isr_failed: tstamp:6363904371 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.041279: rtos_queue_peek_from_isr_failed: tstamp:6368904371 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.209280: rtos_queue_peek_from_isr_failed: tstamp:6373904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.321309: rtos_queue_peek_from_isr_failed: tstamp:6378904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.489289: rtos_queue_peek_from_isr_failed: tstamp:6383904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.657287: rtos_queue_peek_from_isr_failed: tstamp:6388904367 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.825278: rtos_queue_peek_from_isr_failed: tstamp:6393904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   194.993315: rtos_queue_peek_from_isr_failed: tstamp:6398904371 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   195.161277: rtos_queue_peek_from_isr_failed: tstamp:6403904372 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   195.329279: rtos_queue_peek_from_isr_failed: tstamp:6408904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   195.441280: rtos_queue_peek_from_isr_failed: tstamp:6413904371 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   195.609282: rtos_queue_peek_from_isr_failed: tstamp:6418904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   195.777283: rtos_queue_peek_from_isr_failed: tstamp:6423904364 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   195.945326: rtos_queue_peek_from_isr_failed: tstamp:6428904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   196.113282: rtos_queue_peek_from_isr_failed: tstamp:6433904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   196.281275: rtos_queue_peek_from_isr_failed: tstamp:6438904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   196.449282: rtos_queue_peek_from_isr_failed: tstamp:6443904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   196.561274: rtos_queue_peek_from_isr_failed: tstamp:6448904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   196.729278: rtos_queue_peek_from_isr_failed: tstamp:6453904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   196.897280: rtos_queue_peek_from_isr_failed: tstamp:6458904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   197.065281: rtos_queue_peek_from_isr_failed: tstamp:6463904369 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   197.233278: rtos_queue_peek_from_isr_failed: tstamp:6468904366 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   197.401274: rtos_queue_peek_from_isr_failed: tstamp:6473904375 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   197.569321: rtos_queue_peek_from_isr_failed: tstamp:6478904368 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   197.569324: rtos_queue_peek_from_isr_failed: tstamp:6480275024 queue:0x0bcbb8b8
        v4l2-ctl-8455  [003] ....   276.614749: tegra_channel_open: vi-output, imxXXX 2-001b
        v4l2-ctl-8455  [000] ....   276.617771: tegra_channel_set_power: imxXXX 2-001b : 0x1
        v4l2-ctl-8455  [000] ....   276.617784: camera_common_s_power: status : 0x1
        v4l2-ctl-8455  [000] ....   276.618021: tegra_channel_set_power: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-8455  [000] ....   276.618024: csi_s_power: enable : 0x1
        v4l2-ctl-8455  [000] ....   276.628354: tegra_channel_capture_setup: vnc_id 0 W 1920 H 1552 fmt c4
        v4l2-ctl-8455  [003] ....   276.633522: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-8455  [000] ....   276.636001: tegra_channel_set_stream: 15a00000.nvcsi--1 : 0x1
        v4l2-ctl-8455  [000] ....   276.636005: csi_s_stream: enable : 0x1
        v4l2-ctl-8455  [000] ....   276.636014: tegra_channel_set_stream: imxXXX 2-001b : 0x1
     kworker/1:1-796   [001] ....   276.645284: rtos_queue_peek_from_isr_failed: tstamp:8951230417 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   276.645288: rtcpu_start: tstamp:8951232529
     kworker/1:1-796   [001] ....   276.645289: rtos_queue_send_from_isr_failed: tstamp:8951243441 queue:0x0bcb2b38
     kworker/1:1-796   [001] ....   276.645290: rtos_queue_send_from_isr_failed: tstamp:8951243578 queue:0x0bcb73a0
     kworker/1:1-796   [001] ....   276.645291: rtos_queue_send_from_isr_failed: tstamp:8951243715 queue:0x0bcb8f20
     kworker/1:1-796   [001] ....   276.645292: rtos_queue_send_from_isr_failed: tstamp:8951243848 queue:0x0bcb9ce0
     kworker/1:1-796   [001] ....   276.645292: rtos_queue_send_from_isr_failed: tstamp:8951243982 queue:0x0bcbaaa0
     kworker/1:1-796   [001] ....   276.645294: rtcpu_string: tstamp:8951244382 id:0x04010000 str:"Configuring VI GoS.
"
     kworker/1:1-796   [001] ....   276.645299: rtcpu_string: tstamp:8951244563 id:0x04010000 str:"VM GOS[#0] addr=0xc2100000
"
     kworker/1:1-796   [001] ....   276.645322: rtcpu_string: tstamp:8951244803 id:0x04010000 str:"VM GOS[#1] addr=0xc2101000
"
     kworker/1:1-796   [001] ....   276.645324: rtcpu_string: tstamp:8951245032 id:0x04010000 str:"VM GOS[#2] addr=0xc2102000
"
     kworker/1:1-796   [001] ....   276.645327: rtcpu_string: tstamp:8951245247 id:0x04010000 str:"VM GOS[#3] addr=0xc2103000
"
     kworker/1:1-796   [001] ....   276.645329: rtcpu_string: tstamp:8951245518 id:0x04010000 str:"VM GOS[#4] addr=0xc2104000
"
     kworker/1:1-796   [001] ....   276.645331: rtcpu_string: tstamp:8951245744 id:0x04010000 str:"VM GOS[#5] addr=0xc2105000
"
     kworker/1:1-796   [001] ....   276.645333: rtcpu_string: tstamp:8951253279 id:0x04010000 str:"vi5_hwinit: firmware CL2018101701 protocol vers"
     kworker/1:1-796   [001] ....   276.645334: rtcpu_string: tstamp:8951253397 id:0x04010000 str:"on 2.2
"
     kworker/1:1-796   [001] ....   276.645337: rtos_queue_send_from_isr_failed: tstamp:8951282094 queue:0x0bcb2b38
     kworker/1:1-796   [001] ....   276.645338: rtos_queue_send_from_isr_failed: tstamp:8951282248 queue:0x0bcb73a0
     kworker/1:1-796   [001] ....   276.645339: rtos_queue_send_from_isr_failed: tstamp:8951282388 queue:0x0bcb8f20
     kworker/1:1-796   [001] ....   276.645339: rtos_queue_send_from_isr_failed: tstamp:8951282522 queue:0x0bcb9ce0
     kworker/1:1-796   [001] ....   276.645359: rtos_queue_send_from_isr_failed: tstamp:8951282655 queue:0x0bcbaaa0
     kworker/1:1-796   [001] ....   276.645360: rtcpu_string: tstamp:8951283503 id:0x04010000 str:"VI GOS[#0] set to VM GOS[4] base 0xc2104000
"
     kworker/1:1-796   [001] ....   276.645362: rtos_queue_send_from_isr_failed: tstamp:8951285867 queue:0x0bcb2b38
     kworker/1:1-796   [001] ....   276.645363: rtos_queue_send_from_isr_failed: tstamp:8951286003 queue:0x0bcb73a0
     kworker/1:1-796   [001] ....   276.645364: rtos_queue_send_from_isr_failed: tstamp:8951286142 queue:0x0bcb8f20
     kworker/1:1-796   [001] ....   276.645364: rtos_queue_send_from_isr_failed: tstamp:8951286274 queue:0x0bcb9ce0
     kworker/1:1-796   [001] ....   276.645365: rtos_queue_send_from_isr_failed: tstamp:8951286407 queue:0x0bcbaaa0
     kworker/1:1-796   [001] ....   276.645366: rtos_queue_send_from_isr_failed: tstamp:8951289631 queue:0x0bcb2b38
     kworker/1:1-796   [001] ....   276.645366: rtos_queue_send_from_isr_failed: tstamp:8951289768 queue:0x0bcb73a0
     kworker/1:1-796   [001] ....   276.645367: rtos_queue_send_from_isr_failed: tstamp:8951289906 queue:0x0bcb8f20
     kworker/1:1-796   [001] ....   276.645367: rtos_queue_send_from_isr_failed: tstamp:8951290048 queue:0x0bcb9ce0
     kworker/1:1-796   [001] ....   276.645368: rtos_queue_send_from_isr_failed: tstamp:8951290181 queue:0x0bcbaaa0
     kworker/1:1-796   [001] ....   276.645369: rtos_queue_send_from_isr_failed: tstamp:8951294009 queue:0x0bcb2b38
     kworker/1:1-796   [001] ....   276.645369: rtos_queue_send_from_isr_failed: tstamp:8951294144 queue:0x0bcb73a0
     kworker/1:1-796   [001] ....   276.645370: rtos_queue_send_from_isr_failed: tstamp:8951294281 queue:0x0bcb8f20
     kworker/1:1-796   [001] ....   276.645371: rtos_queue_send_from_isr_failed: tstamp:8951294414 queue:0x0bcb9ce0
     kworker/1:1-796   [001] ....   276.645371: rtos_queue_send_from_isr_failed: tstamp:8951294547 queue:0x0bcbaaa0
     kworker/1:1-796   [001] ....   276.645372: rtos_queue_send_from_isr_failed: tstamp:8951360007 queue:0x0bcb2b38
     kworker/1:1-796   [001] ....   276.645373: rtos_queue_send_from_isr_failed: tstamp:8951360141 queue:0x0bcb73a0
     kworker/1:1-796   [001] ....   276.645373: rtos_queue_send_from_isr_failed: tstamp:8951360276 queue:0x0bcb8f20
     kworker/1:1-796   [001] ....   276.645374: rtos_queue_send_from_isr_failed: tstamp:8951360408 queue:0x0bcb9ce0
     kworker/1:1-796   [001] ....   276.645375: rtos_queue_send_from_isr_failed: tstamp:8951360540 queue:0x0bcbaaa0
     kworker/1:1-796   [001] ....   276.645376: rtcpu_nvcsi_intr: tstamp:8951363005 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000001
     kworker/1:1-796   [001] ....   276.645378: rtcpu_vinotify_event: tstamp:8951565970 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7268225664 data:0x10000000
     kworker/1:1-796   [001] ....   276.645379: rtcpu_vinotify_event: tstamp:8951566101 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7268229440 data:0x31000001
     kworker/1:1-796   [001] ....   276.645379: rtcpu_vinotify_event: tstamp:8951566244 tag:RESERVED_19 channel:0x23 frame:0 vi_tstamp:7268230432 data:0x07020001
     kworker/1:1-796   [001] ....   276.645393: rtcpu_vinotify_event: tstamp:8951566370 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7268333120 data:0x10000000
     kworker/1:1-796   [001] ....   276.645394: rtcpu_vinotify_event: tstamp:8951566512 tag:RESERVED_18 channel:0x23 frame:0 vi_tstamp:7268336960 data:0x31000002
     kworker/1:1-796   [001] ....   276.757307: rtcpu_vinotify_error: tstamp:8955136925 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:8955136257 data:0x00000001
     kworker/1:1-796   [001] ....   276.813300: rtcpu_vinotify_event: tstamp:8955322051 tag:CSIMUX_STREAM channel:0x00 frame:1 vi_tstamp:8955136257 data:0x00000001
     kworker/1:1-796   [001] ....   276.813303: rtcpu_vinotify_error: tstamp:8955712593 tag:CHANSEL_NOMATCH channel:0x41 frame:2 vi_tstamp:8955711935 data:0x000005a9
     kworker/1:1-796   [001] ....   276.813304: rtcpu_vinotify_event: tstamp:8955948052 tag:FS channel:0x01 frame:2 vi_tstamp:8955711125 data:0x00000010
     kworker/1:1-796   [001] ....   276.813306: rtcpu_vinotify_event: tstamp:8955948177 tag:CHANSEL_NOMATCH channel:0x41 frame:2 vi_tstamp:8955711935 data:0x000005a9
     kworker/1:1-796   [001] ....   276.813308: rtos_queue_peek_from_isr_failed: tstamp:8956230779 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   276.813310: rtcpu_vinotify_error: tstamp:8956406991 tag:CHANSEL_NOMATCH channel:0x41 frame:3 vi_tstamp:8956406338 data:0x000005a9
     kworker/1:1-796   [001] ....   276.813311: rtcpu_vinotify_event: tstamp:8956574074 tag:FE channel:0x01 frame:2 vi_tstamp:8956381342 data:0x00000020
     kworker/1:1-796   [001] ....   276.813312: rtcpu_vinotify_event: tstamp:8956574200 tag:FS channel:0x01 frame:3 vi_tstamp:8956405527 data:0x00000010
     kworker/1:1-796   [001] ....   276.813313: rtcpu_vinotify_event: tstamp:8956574342 tag:CHANSEL_NOMATCH channel:0x41 frame:3 vi_tstamp:8956406338 data:0x000005a9
     kworker/1:1-796   [001] ....   276.869287: rtcpu_vinotify_error: tstamp:8957101391 tag:CHANSEL_NOMATCH channel:0x41 frame:4 vi_tstamp:8957100739 data:0x000005a9
     kworker/1:1-796   [001] ....   276.869289: rtcpu_vinotify_event: tstamp:8957200103 tag:FE channel:0x01 frame:3 vi_tstamp:8957075743 data:0x00000020
     kworker/1:1-796   [001] ....   276.869291: rtcpu_vinotify_event: tstamp:8957200247 tag:FS channel:0x01 frame:4 vi_tstamp:8957099930 data:0x00000010
     kworker/1:1-796   [001] ....   276.869292: rtcpu_vinotify_event: tstamp:8957200373 tag:CHANSEL_NOMATCH channel:0x41 frame:4 vi_tstamp:8957100739 data:0x000005a9
     kworker/1:1-796   [001] ....   276.869293: rtcpu_vinotify_event: tstamp:8957795710 tag:FE channel:0x01 frame:4 vi_tstamp:8957770146 data:0x00000020
     kworker/1:1-796   [001] ....   276.869294: rtcpu_vinotify_event: tstamp:8957795836 tag:FS channel:0x01 frame:5 vi_tstamp:8957795185 data:0x00000010
     kworker/1:1-796   [001] ....   276.869295: rtcpu_vinotify_error: tstamp:8957796641 tag:CHANSEL_NOMATCH channel:0x41 frame:5 vi_tstamp:8957795997 data:0x000005a9
     kworker/1:1-796   [001] ....   276.869297: rtcpu_vinotify_event: tstamp:8958107773 tag:CHANSEL_NOMATCH channel:0x41 frame:5 vi_tstamp:8957795997 data:0x000005a9
     kworker/1:1-796   [001] ....   276.869298: rtcpu_vinotify_error: tstamp:8958491899 tag:CHANSEL_NOMATCH channel:0x41 frame:6 vi_tstamp:8958491252 data:0x000005a9
     kworker/1:1-796   [001] ....   276.925281: rtcpu_vinotify_event: tstamp:8958733792 tag:FE channel:0x01 frame:5 vi_tstamp:8958465401 data:0x00000020
     kworker/1:1-796   [001] ....   276.925283: rtcpu_vinotify_event: tstamp:8958733939 tag:FS channel:0x01 frame:6 vi_tstamp:8958490442 data:0x00000010
     kworker/1:1-796   [001] ....   276.925284: rtcpu_vinotify_event: tstamp:8958734065 tag:CHANSEL_NOMATCH channel:0x41 frame:6 vi_tstamp:8958491252 data:0x000005a9
     kworker/1:1-796   [001] ....   276.925285: rtcpu_vinotify_error: tstamp:8959187160 tag:CHANSEL_NOMATCH channel:0x41 frame:7 vi_tstamp:8959186509 data:0x000005a9
     kworker/1:1-796   [001] ....   276.925287: rtcpu_vinotify_event: tstamp:8959359817 tag:FE channel:0x01 frame:6 vi_tstamp:8959160658 data:0x00000020
     kworker/1:1-796   [001] ....   276.925289: rtcpu_vinotify_event: tstamp:8959359940 tag:FS channel:0x01 frame:7 vi_tstamp:8959185698 data:0x00000010
     kworker/1:1-796   [001] ....   276.925290: rtcpu_vinotify_event: tstamp:8959360080 tag:CHANSEL_NOMATCH channel:0x41 frame:7 vi_tstamp:8959186509 data:0x000005a9
     kworker/1:1-796   [001] ....   276.925291: rtcpu_vinotify_error: tstamp:8959882417 tag:CHANSEL_NOMATCH channel:0x41 frame:8 vi_tstamp:8959881765 data:0x000005a9
     kworker/1:1-796   [001] ....   276.925293: rtcpu_vinotify_event: tstamp:8959985840 tag:FE channel:0x01 frame:7 vi_tstamp:8959855914 data:0x00000020
     kworker/1:1-796   [001] ....   276.925294: rtcpu_vinotify_event: tstamp:8959985984 tag:FS channel:0x01 frame:8 vi_tstamp:8959880954 data:0x00000010
     kworker/1:1-796   [001] ....   276.925295: rtcpu_vinotify_event: tstamp:8959986108 tag:CHANSEL_NOMATCH channel:0x41 frame:8 vi_tstamp:8959881765 data:0x000005a9
     kworker/1:1-796   [001] ....   276.981280: rtcpu_vinotify_error: tstamp:8960577676 tag:CHANSEL_NOMATCH channel:0x41 frame:9 vi_tstamp:8960577021 data:0x000005a9
     kworker/1:1-796   [001] ....   276.981282: rtcpu_vinotify_event: tstamp:8960611779 tag:FE channel:0x01 frame:8 vi_tstamp:8960551172 data:0x00000020
     kworker/1:1-796   [001] ....   276.981283: rtcpu_vinotify_event: tstamp:8960611906 tag:FS channel:0x01 frame:9 vi_tstamp:8960576211 data:0x00000010
     kworker/1:1-796   [001] ....   276.981285: rtcpu_vinotify_event: tstamp:8960612047 tag:CHANSEL_NOMATCH channel:0x41 frame:9 vi_tstamp:8960577021 data:0x000005a9
     kworker/1:1-796   [001] ....   276.981286: rtos_queue_peek_from_isr_failed: tstamp:8961230774 queue:0x0bcbb8b8
     kworker/1:1-796   [001] ....   276.981287: rtcpu_vinotify_error: tstamp:8961272930 tag:CHANSEL_NOMATCH channel:0x41 frame:10 vi_tstamp:8961272277 data:0x000005a9
     kworker/1:1-796   [001] ....   276.981289: rtcpu_vinotify_event: tstamp:8961273191 tag:FE channel:0x01 frame:9 vi_tstamp:8961246426 data:0x00000020
     kworker/1:1-796   [001] ....   276.981290: rtcpu_vinotify_event: tstamp:8961273333 tag:FS channel:0x01 frame:10 vi_tstamp:8961271467 data:0x00000010
     kworker/1:1-796   [001] ....   276.981291: rtcpu_vinotify_event: tstamp:8961273458 tag:CHANSEL_NOMATCH channel:0x41 frame:10 vi_tstamp:8961272277 data:0x000005a9
     kworker/1:1-796   [001] ....   276.981292: rtcpu_vinotify_event: tstamp:8961957718 tag:FE channel:0x01 frame:10 vi_tstamp:8961941684 data:0x00000020
     kworker/1:1-796   [001] ....   276.981293: rtcpu_vinotify_error: tstamp:8961968187 tag:CHANSEL_NOMATCH channel:0x41 frame:11 vi_tstamp:8961967535 data:0x000005a9
     kworker/1:1-796   [001] ....   277.037280: rtcpu_vinotify_event: tstamp:8962270722 tag:FS channel:0x01 frame:11 vi_tstamp:8961966723 data:0x00000010
     kworker/1:1-796   [001] ....   277.037282: rtcpu_vinotify_event: tstamp:8962270867 tag:CHANSEL_NOMATCH channel:0x41 frame:11 vi_tstamp:8961967535 data:0x000005a9
     kworker/1:1-796   [001] ....   277.037284: rtcpu_vinotify_error: tstamp:8962663445 tag:CHANSEL_NOMATCH channel:0x41 frame:12 vi_tstamp:8962662790 data:0x000005a9
     kworker/1:1-796   [001] ....   277.037285: rtcpu_vinotify_event: tstamp:8962896744 tag:FE channel:0x01 frame:11 vi_tstamp:8962636939 data:0x00000020
     kworker/1:1-796   [001] ....   277.037286: rtcpu_vinotify_event: tstamp:8962896885 tag:FS channel:0x01 frame:12 vi_tstamp:8962661980 data:0x00000010
     kworker/1:1-796   [001] ....   277.037287: rtcpu_vinotify_event: tstamp:8962897012 tag:CHANSEL_NOMATCH channel:0x41 frame:12 vi_tstamp:8962662790 data:0x000005a9
     kworker/1:1-796   [001] ....   277.037288: rtcpu_vinotify_error: tstamp:8963358695 tag:CHANSEL_NOMATCH channel:0x41 frame:13 vi_tstamp:8963358046 data:0x000005a9
     kworker/1:1-796   [001] ....   277.037290: rtcpu_vinotify_event: tstamp:8963522764 tag:FE channel:0x01 frame:12 vi_tstamp:8963332196 data:0x00000020
     kworker/1:1-796   [001] ....   277.037291: rtcpu_vinotify_event: tstamp:8963522887 tag:FS channel:0x01 frame:13 vi_tstamp:8963357236 data:0x00000010
     kworker/1:1-796   [001] ....   277.037292: rtcpu_vinotify_event: tstamp:8963523027 tag:CHANSEL_NOMATCH channel:0x41 frame:13 vi_tstamp:8963358046 data:0x000005a9
     kworker/1:1-796   [001] ....   277.093284: rtcpu_vinotify_error: tstamp:8964053953 tag:CHANSEL_NOMATCH channel:0x41 frame:14 vi_tstamp:8964053303 data:0x000005a9
     kworker/1:1-796   [001] ....   277.093286: rtcpu_vinotify_event: tstamp:8964148791 tag:FE channel:0x01 frame:13 vi_tstamp:8964027452 data:0x00000020
     kworker/1:1-796   [001] ....   277.093288: rtcpu_vinotify_event: tstamp:8964148936 tag:FS channel:0x01 frame:14 vi_tstamp:8964052492 data:0x00000010
     kworker/1:1-796   [001] ....   277.093289: rtcpu_vinotify_event: tstamp:8964149063 tag:CHANSEL_NOMATCH channel:0x41 frame:14 vi_tstamp:8964053303 data:0x000005a9
     kworker/1:1-796   [001] ....   277.093290: rtcpu_vinotify_error: tstamp:8964749211 tag:CHANSEL_NOMATCH channel:0x41 frame:15 vi_tstamp:8964748559 data:0x000005a9
     kworker/1:1-796   [001] ....   277.093291: rtcpu_vinotify_event: tstamp:8964774713 tag:FE channel:0x01 frame:14 vi_tstamp:8964722709 data:0x00000020
     kworker/1:1-796   [001] ....   277.093292: rtcpu_vinotify_event: tstamp:8964774836 tag:FS channel:0x01 frame:15 vi_tstamp:8964747748 data:0x00000010
     kworker/1:1-796   [001] ....   277.093294: rtcpu_vinotify_event: tstamp:8964774975 tag:CHANSEL_NOMATCH channel:0x41 frame:15 vi_tstamp:8964748559 data:0x000005a9

may I know how you access the camera stream?
this set_mode_delay_ms property is used by internal camera stack, i.e. nvarguscamerasrc plugin; v4l2-ctl did not consider this property.