GMSL Camera fail on Orin JatPack 5.1.2

Robotics & Edge Computing Jetson & Embedded Systems Jetson AGX Orin
,
1

Hi, all:
We are debugging a custom carrier using 4 pieces of max96712. We are running Jetpack 5.1.2.First(video0~video3),second(video4~video7),third(video8~video11), fourth(video12~video15).

[ 1000.551885] max9xxx 0-000c: [CAMERA]:device node = video8 .
[ 1000.587270] max9xxx 0-000d: [CAMERA]:device node = video9 .
[ 1000.612801] max9xxx 0-000e: [CAMERA]:device node = video10 .
[ 1000.637972] max9xxx 0-000f: [CAMERA]:device node = video11 .
[ 1000.655536] max9xxx 0-0010: [CAMERA]:device node = video12 .
[ 1000.680653] max9xxx 0-0011: [CAMERA]:device node = video13 .
[ 1000.706334] max9xxx 0-0012: [CAMERA]:device node = video14 .
[ 1000.740821] max9xxx 0-0013: [CAMERA]:device node = video15 .
[ 1000.768544] max9xxx 2-0004: [CAMERA]:device node = video0 .
[ 1000.802444] max9xxx 2-0005: [CAMERA]:device node = video1 .
[ 1000.827289] max9xxx 2-0006: [CAMERA]:device node = video2 .
[ 1000.861028] max9xxx 2-0007: [CAMERA]:device node = video3 .
[ 1000.879036] max9xxx 2-0008: [CAMERA]:device node = video4 .
[ 1000.912631] max9xxx 2-0009: [CAMERA]:device node = video5 .
[ 1000.938274] max9xxx 2-000a: [CAMERA]:device node = video6 .
[ 1000.962498] max9xxx 2-000b: [CAMERA]:device node = video7 .

An error occurred when I was debugging /dev/video4 with v4l2-ctl.

 [  357.295904] [RCE] VM0 deactivating.VM0 activating.calibration status1 2928ca52 status2 21194e52
[  357.295907] [RCE] calibration status1 290647b5 status2 2749c031
[  357.295909] [RCE] IDAC CIL A params:
[  357.295911] [RCE] 	ab_trio0 0
               	ab_trio1 0
               	bc_trio0 0
               	bc_trio1 0
[  357.295912] [RCE] 	ca_trio0 0
               	ca_trio1 0
[  357.295914] [RCE] IDAC CIL B params:
[  357.295916] [RCE] 	ab_trio0 0
               	ab_trio1 0
               	bc_trio0 0
               	bc_trio1 0
[  357.295918] [RCE] 	ca_trio0 0
               	ca_trio1 0
[  357.295920] [RCE] IDACADJ calibration timeout, use default static config
[  357.295922] [RCE] calibration status1 2f59b6b1 status2 2a19ce94
[  357.295924] [RCE] NVCSILP clock rate = 408000000 Hz.
[  357.306343] [CAMERA]: cam ts fifo read failed
[  357.306348] [VI5]: cam ts fifo empty
[  357.310841] [CAMERA]: cam ts fifo read failed
[  357.314528] [VI5]: cam ts fifo empty
[  357.319015] [CAMERA]: cam ts fifo read failed
[  357.322701] [VI5]: cam ts fifo empty
[  357.351832] [RCE] tegra_nvcsi_stream_set_config(vm0, stream=5, csi=6)
[  357.355514] [RCE] MIPI clock = 3750000 kHz, tHS-SETTLE = 0, tCLK-SETTLE = 0
[  357.355516] [RCE] ===== NVCSI Stream Configuration =====
[  357.355518] [RCE] stream_id: PP 5, csi_port: PORT G
[  357.355520] [RCE] Brick: PHY 3, Mode: D-PHY
[  357.355522] [RCE] Partition: CIL A, LP bypass: Enabled, Lanes: 4
[  357.355524] [RCE] Clock information:
[  357.355526] [RCE] MIPI clock rate: 3750.00 MHz
[  357.355528] [RCE] T_HS settle: 0, T_CLK settle: 0
[  357.355530] [RCE] ======================================
[  357.355531] [RCE] tegra_nvcsi_stream_open(vm0, stream=5, csi=6)
[  357.355533] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_SW_RESET_0 = 00000003
[  357.355535] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_SW_RESET_0 = 00000003
[  357.355537] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET_0 = 00000001
[  357.355539] [RCE] nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET_0 = 00000000
[  357.355540] [RCE] nvcsi_calc_ths_settle ths_settle 45
[  357.355542] [RCE] nvcsi_calc_ths_settle ths_settle 45
[  357.355543] [RCE] nvcsi_calc_ths_settle ths_settle 45
[  357.355545] [RCE] nvcsi_calc_tclk_settle tclk_settle 75
[  357.355547] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_SW_RESET_0 = 00000000
[  357.355549] [RCE] nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_SW_RESET_0 = 00000000
[  357.355550] [RCE] Deskew setup message sent for port 6 num_lane 4
[  359.843948] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[  359.853097] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  359.863800] (NULL device *): vi_capture_control_message: NULL VI channel received
[  359.871523] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=5, csi_port=6
[  359.882192] (NULL device *): vi_capture_control_message: NULL VI channel received
[  359.889917] t194-nvcsi 13e40000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 5 vc- 0
[  359.900685] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

the trace log as:

# tracer: nop
#
# entries-in-buffer/entries-written: 78/78   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
     kworker/1:4-498     [001] ....    85.787920: rtcpu_string: tstamp:3208213236 id:0x04010000 str:"calibration status1 2928ca52 status2 21194e52
"
     kworker/1:4-498     [001] ....    85.787957: rtcpu_string: tstamp:3208213831 id:0x04010000 str:"calibration status1 21607b5 status2 27498681
"
     kworker/1:4-498     [001] ....    85.787961: rtcpu_string: tstamp:3208214355 id:0x04010000 str:"calibration status1 2589d433 status2 214a52b2
"
     kworker/1:4-498     [001] ....    85.787964: rtcpu_string: tstamp:3208214877 id:0x04010000 str:"calibration status1 2f59b6b1 status2 2b59ceb4
"
     kworker/1:4-498     [001] ....    85.787967: rtcpu_string: tstamp:3208225776 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
     kworker/1:4-498     [001] ....    85.843917: rtcpu_dbg_set_loglevel: tstamp:3208268263 old:0 new:2
     kworker/1:4-498     [001] ....    90.892380: rtcpu_string: tstamp:3367243477 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-5095    [001] ....   123.199115: tegra_channel_open: vi-output, max9xxx 0-0010
        v4l2-ctl-5095    [001] ....   123.203107: tegra_channel_set_power: max9xxx 0-0010 : 0x1
        v4l2-ctl-5095    [001] ....   123.203122: camera_common_s_power: status : 0x1
        v4l2-ctl-5095    [001] ....   123.203906: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-5095    [001] ....   123.203910: csi_s_power: enable : 0x1
        v4l2-ctl-5095    [001] ....   123.204640: tegra_channel_capture_setup: vnc_id 0 W 1280 H 720 fmt 13
        v4l2-ctl-5095    [002] ....   123.214209: tegra_channel_set_stream: enable : 0x1
     kworker/1:4-498     [001] ....   123.217956: rtcpu_string: tstamp:4377615710 id:0x04010000 str:"VM0 activating."
     kworker/1:4-498     [001] ....   123.217957: rtcpu_string: tstamp:4377732943 id:0x04010000 str:"calibration status1 2928ca52 status2 21194e52
"
        v4l2-ctl-5095    [002] ....   123.233715: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-5095    [002] ....   123.233718: csi_s_stream: enable : 0x1
        v4l2-ctl-5095    [002] ....   123.234254: tegra_channel_set_stream: max9xxx 0-0010 : 0x1
     kworker/1:4-498     [001] ....   123.246013: rtcpu_string: tstamp:4377733463 id:0x04010000 str:"calibration status1 4210ba1 status2 5498a81
"
     kworker/1:4-498     [001] ....   123.249727: rtcpu_string: tstamp:4377733984 id:0x04010000 str:"calibration status1 2389d433 status2 214a52b2
"
     kworker/1:4-498     [001] ....   123.249729: rtcpu_string: tstamp:4377734512 id:0x04010000 str:"calibration status1 2f59b6b1 status2 2b59ceb4
"
     kworker/1:4-498     [001] ....   123.249731: rtcpu_string: tstamp:4377745158 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
     kworker/1:4-498     [001] ....   123.304706: rtcpu_vinotify_event: tstamp:4378124268 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:140089909120 data:0x359e300010000000
     kworker/1:4-498     [001] ....   123.304708: rtcpu_vinotify_event: tstamp:4378124529 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:140089915616 data:0x0000000031000001
     kworker/1:4-498     [001] ....   123.304709: rtcpu_vinotify_event: tstamp:4378124800 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:140095054080 data:0x359e2d0010000000
     kworker/1:4-498     [001] ....   123.304709: rtcpu_vinotify_event: tstamp:4378125015 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:140095060640 data:0x0000000031000002
     kworker/1:4-498     [001] ....   123.304711: rtcpu_string: tstamp:4378443112 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=5, csi"
     kworker/1:4-498     [001] ....   123.304712: rtcpu_string: tstamp:4378443214 id:0x04010000 str:"=6)
"
     kworker/1:4-498     [001] ....   123.304719: rtcpu_string: tstamp:4378443586 id:0x04010000 str:"MIPI clock = 3750000 kHz, tHS-SETTLE = 0, tCLK-S"
     kworker/1:4-498     [001] ....   123.304719: rtcpu_string: tstamp:4378443687 id:0x04010000 str:"ETTLE = 0
"
     kworker/1:4-498     [001] ....   123.304721: rtcpu_string: tstamp:4378443900 id:0x04010000 str:"===== NVCSI Stream Configuration =====
"
     kworker/1:4-498     [001] ....   123.304723: rtcpu_string: tstamp:4378444154 id:0x04010000 str:"stream_id: PP 5, csi_port: PORT G
"
     kworker/1:4-498     [001] ....   123.304725: rtcpu_string: tstamp:4378444416 id:0x04010000 str:"Brick: PHY 3, Mode: D-PHY
"
     kworker/1:4-498     [001] ....   123.304727: rtcpu_string: tstamp:4378444698 id:0x04010000 str:"Partition: CIL A, LP bypass: Enabled, Lanes: 4
"
     kworker/1:4-498     [001] ....   123.304729: rtcpu_string: tstamp:4378444876 id:0x04010000 str:"Clock information:
"
     kworker/1:4-498     [001] ....   123.304732: rtcpu_string: tstamp:4378445181 id:0x04010000 str:"MIPI clock rate: 3750.00 MHz
"
     kworker/1:4-498     [001] ....   123.304733: rtcpu_string: tstamp:4378445425 id:0x04010000 str:"T_HS settle: 0, T_CLK settle: 0
"
     kworker/1:4-498     [001] ....   123.304736: rtcpu_string: tstamp:4378445648 id:0x04010000 str:"======================================
"
     kworker/1:4-498     [001] ....   123.304738: rtcpu_string: tstamp:4378447309 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=5, csi=6)
"
     kworker/1:4-498     [001] ....   123.304739: rtcpu_string: tstamp:4378447898 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_"
     kworker/1:4-498     [001] ....   123.304740: rtcpu_string: tstamp:4378447999 id:0x04010000 str:"SW_RESET_0 = 00000003
"
     kworker/1:4-498     [001] ....   123.304742: rtcpu_string: tstamp:4378448354 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_"
     kworker/1:4-498     [001] ....   123.304742: rtcpu_string: tstamp:4378448454 id:0x04010000 str:"SW_RESET_0 = 00000003
"
     kworker/1:4-498     [001] ....   123.304744: rtcpu_string: tstamp:4378449115 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET"
     kworker/1:4-498     [001] ....   123.304744: rtcpu_string: tstamp:4378449215 id:0x04010000 str:"_0 = 00000001
"
     kworker/1:4-498     [001] ....   123.304746: rtcpu_string: tstamp:4378455230 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET"
     kworker/1:4-498     [001] ....   123.304746: rtcpu_string: tstamp:4378455335 id:0x04010000 str:"_0 = 00000000
"
     kworker/1:4-498     [001] ....   123.304748: rtcpu_string: tstamp:4378455898 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 45
"
     kworker/1:4-498     [001] ....   123.304750: rtcpu_string: tstamp:4378456158 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 45
"
     kworker/1:4-498     [001] ....   123.304752: rtcpu_string: tstamp:4378456414 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 45
"
     kworker/1:4-498     [001] ....   123.304754: rtcpu_string: tstamp:4378456668 id:0x04010000 str:"nvcsi_calc_tclk_settle tclk_settle 75
"
     kworker/1:4-498     [001] ....   123.304755: rtcpu_string: tstamp:4378457108 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_"
     kworker/1:4-498     [001] ....   123.304756: rtcpu_string: tstamp:4378457207 id:0x04010000 str:"SW_RESET_0 = 00000000
"
     kworker/1:4-498     [001] ....   123.304758: rtcpu_string: tstamp:4378457558 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_"
     kworker/1:4-498     [001] ....   123.304758: rtcpu_string: tstamp:4378457657 id:0x04010000 str:"SW_RESET_0 = 00000000
"
     kworker/1:4-498     [001] ....   123.304760: rtcpu_string: tstamp:4378458101 id:0x04010000 str:"Deskew setup message sent for port 6 num_lane 4
"
 vi-output, max9-5098    [007] ....   125.929024: tegra_channel_capture_setup: vnc_id 0 W 1280 H 720 fmt 13
     kworker/1:4-498     [001] ....   125.940696: rtcpu_vinotify_event: tstamp:4462973274 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:142805627488 data:0x359e300010000000
     kworker/1:4-498     [001] ....   125.940698: rtcpu_vinotify_event: tstamp:4462973411 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:142805633952 data:0x0000000031000001
     kworker/1:4-498     [001] ....   125.996688: rtcpu_vinotify_event: tstamp:4463311269 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:142823322240 data:0x359e2d0010000000
     kworker/1:4-498     [001] ....   125.996689: rtcpu_vinotify_event: tstamp:4463311408 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:142823328768 data:0x0000000031000002
 vi-output, max9-5098    [004] ....   128.748583: tegra_channel_capture_setup: vnc_id 0 W 1280 H 720 fmt 13
     kworker/1:4-498     [001] ....   128.800707: rtcpu_vinotify_event: tstamp:4551202791 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:145634695904 data:0x359e300010000000
     kworker/1:4-498     [001] ....   128.800710: rtcpu_vinotify_event: tstamp:4551202930 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:145634702336 data:0x0000000031000001
     kworker/1:4-498     [001] ....   128.800710: rtcpu_vinotify_event: tstamp:4551540846 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:145642889184 data:0x359e2d0010000000
     kworker/1:4-498     [001] ....   128.800711: rtcpu_vinotify_event: tstamp:4551540981 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:145642895744 data:0x0000000031000002
        v4l2-ctl-5095    [002] ....   129.805606: tegra_channel_close: vi-output, max9xxx 0-0010
 vi-output, max9-5098    [003] ....   131.340529: tegra_channel_capture_setup: vnc_id 0 W 1280 H 720 fmt 13
        v4l2-ctl-5095    [002] ....   131.350147: tegra_channel_set_stream: enable : 0x0
        v4l2-ctl-5095    [002] ....   131.350149: tegra_channel_set_stream: max9xxx 0-0010 : 0x0
        v4l2-ctl-5095    [002] ....   131.350164: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-5095    [002] ....   131.350165: csi_s_stream: enable : 0x0
        v4l2-ctl-5095    [002] ....   131.362781: tegra_channel_set_power: max9xxx 0-0010 : 0x0
        v4l2-ctl-5095    [002] ....   131.362795: camera_common_s_power: status : 0x0
        v4l2-ctl-5095    [000] ....   131.363185: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x0
        v4l2-ctl-5095    [000] ....   131.363189: csi_s_power: enable : 0x0
     kworker/1:4-498     [001] ....   136.708742: rtcpu_string: tstamp:4798544233 id:0x04010000 str:"VM0 deactivating."

We have also updated the camera firmware with debugging information(Debug_camera-rtcpu-t234-rce.img).

I suspect it is the configuration problem of csi or vi. Attached is the device tree configuration of csi and vi.
tegra234-trunk-atom-camera-modes.txt (120.4 KB)
tegra234-trunk-atom-camera-device.txt (10.7 KB)
tegra234-trunk-atom-camera-csi.txt (12.8 KB)

so any suggestion about this issue, thx

3

Please modify the serdes_pix_clk_hz for below NOTE.

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

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

We changed the configuration so that some of the same cameras worked and some didn’t,can you help us analyze the trace log

In normal operation, the trace log is as follows:

# tracer: nop
#
# entries-in-buffer/entries-written: 2337/2337   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
     kworker/3:1-156     [003] ....   332.694213: rtcpu_string: tstamp:10922868843 id:0x04010000 str:"calibration status1 2928ca52 status2 21194e52
"
     kworker/3:1-156     [003] ....   332.694296: rtcpu_string: tstamp:10922869413 id:0x04010000 str:"calibration status1 281607b5 status2 27398681
"
     kworker/3:1-156     [003] ....   332.694303: rtcpu_string: tstamp:10922869936 id:0x04010000 str:"calibration status1 2379d5b3 status2 214a52b2
"
     kworker/3:1-156     [003] ....   332.694310: rtcpu_string: tstamp:10922870459 id:0x04010000 str:"calibration status1 2f59b6b1 status2 2959ceb4
"
     kworker/3:1-156     [003] ....   332.694316: rtcpu_string: tstamp:10922881078 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
     kworker/3:1-156     [003] ....   332.694330: rtcpu_dbg_set_loglevel: tstamp:10922920862 old:0 new:2
     kworker/3:1-156     [003] ....   338.378214: rtcpu_string: tstamp:11101377350 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-3414    [003] ....   437.425068: tegra_channel_open: vi-output, max9xxx 2-000c
        v4l2-ctl-3414    [003] ....   437.429212: tegra_channel_set_power: max9xxx 2-000c : 0x1
        v4l2-ctl-3414    [003] ....   437.429231: camera_common_s_power: status : 0x1
        v4l2-ctl-3414    [003] ....   437.430104: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3414    [003] ....   437.430108: csi_s_power: enable : 0x1
        v4l2-ctl-3414    [003] ....   437.430838: tegra_channel_capture_setup: vnc_id 0 W 1280 H 720 fmt 13
        v4l2-ctl-3414    [003] ....   437.440258: tegra_channel_set_stream: enable : 0x1
     kworker/3:1-156     [003] ....   437.448495: rtcpu_string: tstamp:14197331359 id:0x04010000 str:"VM0 activating."
     kworker/3:1-156     [003] ....   437.448496: rtcpu_string: tstamp:14197473544 id:0x04010000 str:"calibration status1 2928ca52 status2 21194ed4
"
     kworker/3:1-156     [003] ....   437.456560: rtcpu_string: tstamp:14197474065 id:0x04010000 str:"calibration status1 270647b5 status2 2748c031
"
     kworker/3:1-156     [003] ....   437.456564: rtcpu_string: tstamp:14197474594 id:0x04010000 str:"calibration status1 237955f3 status2 2149d2b2
"
     kworker/3:1-156     [003] ....   437.456566: rtcpu_string: tstamp:14197475114 id:0x04010000 str:"calibration status1 2f59b6b1 status2 2b59ceb4
"
        v4l2-ctl-3414    [002] ....   437.461507: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3414    [002] ....   437.461510: csi_s_stream: enable : 0x1
        v4l2-ctl-3414    [002] ....   437.462302: tegra_channel_set_stream: max9xxx 2-000c : 0x1
     kworker/3:1-156     [003] ....   437.464741: rtcpu_string: tstamp:14197486171 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
     kworker/3:1-156     [003] ....   437.526469: rtcpu_vinotify_event: tstamp:14197865272 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:454321378848 data:0x359e300010000000
     kworker/3:1-156     [003] ....   437.526470: rtcpu_vinotify_event: tstamp:14197865534 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:454321385344 data:0x0000000031000001
     kworker/3:1-156     [003] ....   437.526471: rtcpu_vinotify_event: tstamp:14198203400 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:454333190944 data:0x359e2d0010000000
     kworker/3:1-156     [003] ....   437.526472: rtcpu_vinotify_event: tstamp:14198203535 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:454333197504 data:0x0000000031000002
     kworker/3:1-156     [003] ....   437.526474: rtcpu_string: tstamp:14198205603 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=2, csi"
     kworker/3:1-156     [003] ....   437.526475: rtcpu_string: tstamp:14198205704 id:0x04010000 str:"=2)
"
     kworker/3:1-156     [003] ....   437.526482: rtcpu_string: tstamp:14198206075 id:0x04010000 str:"MIPI clock = 562500 kHz, tHS-SETTLE = 0, tCLK-SE"
     kworker/3:1-156     [003] ....   437.526483: rtcpu_string: tstamp:14198206176 id:0x04010000 str:"TTLE = 0
"
     kworker/3:1-156     [003] ....   437.526485: rtcpu_string: tstamp:14198206386 id:0x04010000 str:"===== NVCSI Stream Configuration =====
"
     kworker/3:1-156     [003] ....   437.526488: rtcpu_string: tstamp:14198206640 id:0x04010000 str:"stream_id: PP 2, csi_port: PORT C
"
     kworker/3:1-156     [003] ....   437.526490: rtcpu_string: tstamp:14198206906 id:0x04010000 str:"Brick: PHY 1, Mode: D-PHY
"
     kworker/3:1-156     [003] ....   437.526492: rtcpu_string: tstamp:14198207188 id:0x04010000 str:"Partition: CIL A, LP bypass: Enabled, Lanes: 4
"
     kworker/3:1-156     [003] ....   437.526494: rtcpu_string: tstamp:14198207366 id:0x04010000 str:"Clock information:
"
     kworker/3:1-156     [003] ....   437.526497: rtcpu_string: tstamp:14198207691 id:0x04010000 str:"MIPI clock rate: 562.50 MHz
"
     kworker/3:1-156     [003] ....   437.526499: rtcpu_string: tstamp:14198207934 id:0x04010000 str:"T_HS settle: 0, T_CLK settle: 0
"
     kworker/3:1-156     [003] ....   437.526501: rtcpu_string: tstamp:14198208159 id:0x04010000 str:"======================================
"
     kworker/3:1-156     [003] ....   437.526504: rtcpu_string: tstamp:14198214258 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=2, csi=2)
"
     kworker/3:1-156     [003] ....   437.526506: rtcpu_string: tstamp:14198214859 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_A_"
     kworker/3:1-156     [003] ....   437.526507: rtcpu_string: tstamp:14198214961 id:0x04010000 str:"SW_RESET_0 = 00000003
"
     kworker/3:1-156     [003] ....   437.526510: rtcpu_string: tstamp:14198215316 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_B_"
     kworker/3:1-156     [003] ....   437.526510: rtcpu_string: tstamp:14198215416 id:0x04010000 str:"SW_RESET_0 = 00000003
"
     kworker/3:1-156     [003] ....   437.526513: rtcpu_string: tstamp:14198216076 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_1_LM_SW_RESET"
     kworker/3:1-156     [003] ....   437.526513: rtcpu_string: tstamp:14198216176 id:0x04010000 str:"_0 = 00000001
"
     kworker/3:1-156     [003] ....   437.526515: rtcpu_string: tstamp:14198222189 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_1_LM_SW_RESET"
     kworker/3:1-156     [003] ....   437.526516: rtcpu_string: tstamp:14198222289 id:0x04010000 str:"_0 = 00000000
"
     kworker/3:1-156     [003] ....   437.526518: rtcpu_string: tstamp:14198222851 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 56
"
     kworker/3:1-156     [003] ....   437.526520: rtcpu_string: tstamp:14198223112 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 56
"
     kworker/3:1-156     [003] ....   437.526523: rtcpu_string: tstamp:14198223366 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 56
"
     kworker/3:1-156     [003] ....   437.526525: rtcpu_string: tstamp:14198223620 id:0x04010000 str:"nvcsi_calc_tclk_settle tclk_settle 75
"
     kworker/3:1-156     [003] ....   437.526527: rtcpu_string: tstamp:14198224061 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_A_"
     kworker/3:1-156     [003] ....   437.526528: rtcpu_string: tstamp:14198224161 id:0x04010000 str:"SW_RESET_0 = 00000000
"
     kworker/3:1-156     [003] ....   437.526530: rtcpu_string: tstamp:14198224511 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_1_NVCSI_CIL_B_"
     kworker/3:1-156     [003] ....   437.526531: rtcpu_string: tstamp:14198224610 id:0x04010000 str:"SW_RESET_0 = 00000000
"
     kworker/3:1-156     [003] ....   439.326315: rtcpu_vinotify_error: tstamp:14256078078 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456194445056 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.326318: rtcpu_vinotify_error: tstamp:14256078452 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456194454560 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.326319: rtcpu_vinotify_error: tstamp:14256079044 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456194473504 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.326321: rtcpu_vinotify_event: tstamp:14256346911 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:456194419136 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.326321: rtcpu_vinotify_event: tstamp:14256347046 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:456194420160 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.326322: rtcpu_vinotify_event: tstamp:14256347200 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:456194428640 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.326322: rtcpu_vinotify_event: tstamp:14256347335 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:456194428640 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.326323: rtcpu_vinotify_event: tstamp:14256347492 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:456194437344 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.326325: rtcpu_vinotify_event: tstamp:14256347622 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456194445056 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.326325: rtcpu_vinotify_event: tstamp:14256347772 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456194454560 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.326326: rtcpu_vinotify_event: tstamp:14256347905 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:456194464032 data:0x0000000000000001
     kworker/3:1-156     [003] ....   439.326326: rtcpu_vinotify_event: tstamp:14256348055 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456194465600 data:0x0000000008020001
     kworker/3:1-156     [003] ....   439.326327: rtcpu_vinotify_event: tstamp:14256348183 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456194473504 data:0x00000000000003c9
 vi-output, max9-3416    [000] ....   439.355519: tegra_channel_capture_frame: sof:456.194464032
 vi-output, max9-3416    [000] ....   439.355594: tegra_channel_capture_frame: eof:456.236454464
     kworker/3:1-156     [003] ....   439.382311: rtcpu_vinotify_event: tstamp:14257389275 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:456236424160 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.382313: rtcpu_vinotify_event: tstamp:14257389406 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:456236434560 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.382314: rtcpu_vinotify_error: tstamp:14257641137 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456244439872 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.382314: rtcpu_vinotify_error: tstamp:14257641508 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456244460640 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.382315: rtcpu_vinotify_error: tstamp:14257642103 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456244470112 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.382316: rtcpu_vinotify_event: tstamp:14257643685 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:456236444032 data:0x0000000002cf0002
     kworker/3:1-156     [003] ....   439.382316: rtcpu_vinotify_event: tstamp:14257643819 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:456236444640 data:0x0000000000000000
     kworker/3:1-156     [003] ....   439.382316: rtcpu_vinotify_event: tstamp:14257643969 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456236449568 data:0x0000000002020001
     kworker/3:1-156     [003] ....   439.382317: rtcpu_vinotify_event: tstamp:14257644109 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:456236454432 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.382317: rtcpu_vinotify_event: tstamp:14257644262 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:456236454464 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.382318: rtcpu_vinotify_event: tstamp:14257644393 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456236459808 data:0x0000000000020001
     kworker/3:1-156     [003] ....   439.382318: rtcpu_vinotify_event: tstamp:14257644542 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:456236455392 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.382318: rtcpu_vinotify_event: tstamp:14257644672 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:456244413920 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.382319: rtcpu_vinotify_event: tstamp:14257644817 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:456244434688 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.382319: rtcpu_vinotify_event: tstamp:14257644944 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:456244435648 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.382320: rtcpu_vinotify_event: tstamp:14257645125 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456244439872 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.382320: rtcpu_vinotify_event: tstamp:14257645259 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:456244449248 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.382320: rtcpu_vinotify_event: tstamp:14257645412 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:456244449248 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.382321: rtcpu_vinotify_event: tstamp:14257645543 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456244460640 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.382321: rtcpu_vinotify_event: tstamp:14257645695 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456244470112 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.382322: rtcpu_vinotify_event: tstamp:14257645827 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:456244479584 data:0x0000000000000001
     kworker/3:1-156     [003] ....   439.382322: rtcpu_vinotify_event: tstamp:14257969649 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456244482816 data:0x0000000008020002
     kworker/3:1-156     [003] ....   439.382322: rtcpu_vinotify_event: tstamp:14257969782 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:456244602816 data:0x359e300010000000
     kworker/3:1-156     [003] ....   439.382323: rtcpu_vinotify_event: tstamp:14257969935 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:456244609376 data:0x0000000031000003
 vi-output, max9-3416    [000] ....   439.405507: tegra_channel_capture_frame: sof:456.244479584
 vi-output, max9-3416    [000] ....   439.405509: tegra_channel_capture_frame: eof:456.286460576
     kworker/3:1-156     [003] ....   439.438307: rtcpu_vinotify_event: tstamp:14258983684 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:456286418976 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.438308: rtcpu_vinotify_event: tstamp:14258983838 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:456286439744 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.438309: rtcpu_vinotify_event: tstamp:14258983973 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:456286450144 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.438309: rtcpu_vinotify_event: tstamp:14258984130 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:456286459616 data:0x0000000002cf0002
     kworker/3:1-156     [003] ....   439.438309: rtcpu_vinotify_event: tstamp:14258984265 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:456286460288 data:0x0000000000000000
     kworker/3:1-156     [003] ....   439.438310: rtcpu_vinotify_event: tstamp:14258984419 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456286463136 data:0x0000000002020002
     kworker/3:1-156     [003] ....   439.438310: rtcpu_vinotify_event: tstamp:14258984551 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:456286460576 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.438311: rtcpu_vinotify_event: tstamp:14258984708 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:456286460576 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.438311: rtcpu_vinotify_event: tstamp:14258984839 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456286469344 data:0x0000000000020002
     kworker/3:1-156     [003] ....   439.438312: rtcpu_vinotify_error: tstamp:14259202973 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456294437216 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.438312: rtcpu_vinotify_error: tstamp:14259203344 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456294446720 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.438313: rtcpu_vinotify_error: tstamp:14259203707 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456294465664 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.438313: rtcpu_vinotify_event: tstamp:14259205275 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:456294411296 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.438314: rtcpu_vinotify_event: tstamp:14259205406 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:456294412224 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.438314: rtcpu_vinotify_event: tstamp:14259205568 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:456294421120 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.438315: rtcpu_vinotify_event: tstamp:14259205708 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:456294421120 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.438315: rtcpu_vinotify_event: tstamp:14259524564 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:456294429536 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.438316: rtcpu_vinotify_event: tstamp:14259524698 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456294437216 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.438316: rtcpu_vinotify_event: tstamp:14259524847 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456294446720 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.438316: rtcpu_vinotify_event: tstamp:14259524983 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:456294456192 data:0x0000000000000001
     kworker/3:1-156     [003] ....   439.438317: rtcpu_vinotify_event: tstamp:14259525141 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456294458400 data:0x0000000008020003
     kworker/3:1-156     [003] ....   439.438317: rtcpu_vinotify_event: tstamp:14259525275 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456294465664 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.438317: rtcpu_vinotify_event: tstamp:14259525437 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:456294578208 data:0x359e2d0010000000
     kworker/3:1-156     [003] ....   439.438318: rtcpu_vinotify_event: tstamp:14259525569 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:456294584736 data:0x0000000031000004
 vi-output, max9-3416    [000] ....   439.455491: tegra_channel_capture_frame: sof:456.294456192
 vi-output, max9-3416    [000] ....   439.455492: tegra_channel_capture_frame: eof:456.336446624
     kworker/3:1-156     [003] ....   439.494306: rtcpu_vinotify_event: tstamp:14260516037 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:456336416288 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.494307: rtcpu_vinotify_event: tstamp:14260516174 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:456336426720 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.494308: rtcpu_vinotify_event: tstamp:14260516333 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:456336436192 data:0x0000000002cf0002
     kworker/3:1-156     [003] ....   439.494308: rtcpu_vinotify_event: tstamp:14260516467 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:456336436832 data:0x0000000000000000
     kworker/3:1-156     [003] ....   439.494308: rtcpu_vinotify_event: tstamp:14260516622 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456336439232 data:0x0000000002020003
     kworker/3:1-156     [003] ....   439.494309: rtcpu_vinotify_event: tstamp:14260516757 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:456336446592 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.494309: rtcpu_vinotify_event: tstamp:14260516909 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:456336446624 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.494310: rtcpu_vinotify_event: tstamp:14260517042 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456336451968 data:0x0000000000020003
     kworker/3:1-156     [003] ....   439.494310: rtcpu_vinotify_error: tstamp:14260765810 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456344452800 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.494310: rtcpu_vinotify_error: tstamp:14260766183 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456344462272 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.494311: rtcpu_vinotify_error: tstamp:14260766774 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456344481248 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.494311: rtcpu_vinotify_event: tstamp:14260842950 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:456336447552 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.494312: rtcpu_vinotify_event: tstamp:14260843128 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:456344426880 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.494312: rtcpu_vinotify_event: tstamp:14260843282 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:456344427808 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.494312: rtcpu_vinotify_event: tstamp:14260843414 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:456344436864 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.494313: rtcpu_vinotify_event: tstamp:14260843572 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:456344436864 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.494313: rtcpu_vinotify_event: tstamp:14260843709 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:456344445120 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.494314: rtcpu_vinotify_event: tstamp:14260843862 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456344452800 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.494314: rtcpu_vinotify_event: tstamp:14260843995 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456344462272 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.494314: rtcpu_vinotify_event: tstamp:14260844152 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:456344471776 data:0x0000000000000001
     kworker/3:1-156     [003] ....   439.494315: rtcpu_vinotify_event: tstamp:14260844284 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456344473344 data:0x0000000008020004
     kworker/3:1-156     [003] ....   439.494315: rtcpu_vinotify_event: tstamp:14260844436 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456344481248 data:0x00000000000003c9
 vi-output, max9-3416    [000] ....   439.505536: tegra_channel_capture_frame: sof:456.344471776
 vi-output, max9-3416    [000] ....   439.505537: tegra_channel_capture_frame: eof:456.386462240
     kworker/3:1-156     [003] ....   439.554303: rtcpu_vinotify_event: tstamp:14262078952 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:456386431904 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.554304: rtcpu_vinotify_event: tstamp:14262079108 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:456386442304 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.554304: rtcpu_vinotify_event: tstamp:14262079244 cch:0 vi:1 tag:CHANSEL_PXL_EOF channel:0x23 frame:0 vi_tstamp:456386451776 data:0x0000000002cf0002
     kworker/3:1-156     [003] ....   439.554306: rtcpu_vinotify_event: tstamp:14262079398 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:456386452416 data:0x0000000000000000
     kworker/3:1-156     [003] ....   439.554307: rtcpu_vinotify_event: tstamp:14262079535 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456386454848 data:0x0000000002020004
     kworker/3:1-156     [003] ....   439.554307: rtcpu_vinotify_error: tstamp:14262327825 cch:0 vi:1 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:456394439520 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554308: rtcpu_vinotify_error: tstamp:14262328199 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456394450880 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554308: rtcpu_vinotify_error: tstamp:14262329181 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456394468416 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554308: rtcpu_vinotify_error: tstamp:14262329563 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456394477888 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554309: rtcpu_vinotify_event: tstamp:14262397981 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:456386462208 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.554309: rtcpu_vinotify_event: tstamp:14262398119 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:456386462240 data:0x0000000800000000
     kworker/3:1-156     [003] ....   439.554310: rtcpu_vinotify_event: tstamp:14262398270 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:456386471776 data:0x0000000000020004
     kworker/3:1-156     [003] ....   439.554310: rtcpu_vinotify_event: tstamp:14262398404 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:456386463136 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.554310: rtcpu_vinotify_event: tstamp:14262398556 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:456394413568 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.554311: rtcpu_vinotify_event: tstamp:14262398685 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:456394421696 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.554311: rtcpu_vinotify_event: tstamp:14262398834 cch:0 vi:1 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:456394439520 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554311: rtcpu_vinotify_event: tstamp:14262398964 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:456394448896 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.554312: rtcpu_vinotify_event: tstamp:14262399113 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:456394449824 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.554312: rtcpu_vinotify_event: tstamp:14262399245 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456394450880 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554313: rtcpu_vinotify_event: tstamp:14262399393 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456394468416 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.554313: rtcpu_vinotify_event: tstamp:14262399523 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456394477888 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.614303: rtcpu_vinotify_event: tstamp:14263640017 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:456436428224 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.614304: rtcpu_vinotify_event: tstamp:14263640158 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:456436429152 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.614305: rtcpu_vinotify_event: tstamp:14263640314 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:456436447488 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.614305: rtcpu_vinotify_event: tstamp:14263640449 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:456436457920 data:0x0000000000000022
     kworker/3:1-156     [003] ....   439.614306: rtcpu_vinotify_error: tstamp:14263890367 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xc4 frame:0 vi_tstamp:456444444960 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.614306: rtcpu_vinotify_error: tstamp:14263890740 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x84 frame:0 vi_tstamp:456444454432 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.614306: rtcpu_vinotify_error: tstamp:14263891722 cch:0 vi:1 tag:CHANSEL_NOMATCH channel:0x04 frame:0 vi_tstamp:456444463936 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.614307: rtcpu_vinotify_error: tstamp:14263892097 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x44 frame:0 vi_tstamp:456444473408 data:0x00000000000003c9
     kworker/3:1-156     [003] ....   439.614307: rtcpu_vinotify_event: tstamp:14263952951 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:456444419040 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.614308: rtcpu_vinotify_event: tstamp:14263953086 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:456444419936 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.614308: rtcpu_vinotify_event: tstamp:14263953238 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:456444429312 data:0x0000000000000012
     kworker/3:1-156     [003] ....   439.614308: rtcpu_vinotify_event: tstamp:14263953368 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:456444437280 data:0x0000000000000012

If an exception occurs, trace log as follows:

# tracer: nop
#
# entries-in-buffer/entries-written: 4841/4841   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
    kworker/0:10-226     [000] ....   280.179484: rtcpu_string: tstamp:9281787436 id:0x04010000 str:"calibration status1 2928c852 status2 4290a52
"
    kworker/0:10-226     [000] ....   280.179562: rtcpu_string: tstamp:9281787968 id:0x04010000 str:"calibration status1 261607b5 status2 2749c031
"
    kworker/0:10-226     [000] ....   280.179567: rtcpu_string: tstamp:9281788517 id:0x04010000 str:"calibration status1 2789d5b3 status2 215a52b2
"
    kworker/0:10-226     [000] ....   280.179570: rtcpu_string: tstamp:9281789045 id:0x04010000 str:"calibration status1 2f59bab2 status2 2b59d2b4
"
    kworker/0:10-226     [000] ....   280.179574: rtcpu_string: tstamp:9281799748 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
    kworker/0:10-226     [000] ....   280.179583: rtcpu_dbg_set_loglevel: tstamp:9281839364 old:0 new:2
    kworker/0:10-226     [000] ....   286.003717: rtcpu_string: tstamp:9465441038 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-3328    [006] ....   374.966605: tegra_channel_open: vi-output, max9xxx 0-000c
        v4l2-ctl-3328    [006] ....   374.970549: tegra_channel_set_power: max9xxx 0-000c : 0x1
        v4l2-ctl-3328    [006] ....   374.970567: camera_common_s_power: status : 0x1
        v4l2-ctl-3328    [006] ....   374.971410: tegra_channel_set_power: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3328    [006] ....   374.971415: csi_s_power: enable : 0x1
        v4l2-ctl-3328    [006] ....   374.972141: tegra_channel_capture_setup: vnc_id 0 W 1280 H 720 fmt 13
        v4l2-ctl-3328    [007] ....   375.012258: tegra_channel_set_stream: enable : 0x1
    kworker/0:10-226     [000] ....   375.013697: rtcpu_string: tstamp:12246671970 id:0x04010000 str:"VM0 activating."
    kworker/0:10-226     [000] ....   375.013701: rtcpu_string: tstamp:12246850112 id:0x04010000 str:"calibration status1 2928ca52 status2 21194e52
"
    kworker/0:10-226     [000] ....   375.019652: rtcpu_string: tstamp:12246850640 id:0x04010000 str:"calibration status1 2905c7b5 status2 2739c031
"
    kworker/0:10-226     [000] ....   375.027852: rtcpu_string: tstamp:12246851196 id:0x04010000 str:"calibration status1 2789d5f3 status2 214a52b2
"
    kworker/0:10-226     [000] ....   375.044135: rtcpu_string: tstamp:12246851720 id:0x04010000 str:"calibration status1 3159b6b1 status2 2b49ceb4
"
    kworker/0:10-226     [000] ....   375.047849: rtcpu_string: tstamp:12246863530 id:0x04010000 str:"NVCSILP clock rate = 408000000 Hz.
"
        v4l2-ctl-3328    [007] ....   375.060361: tegra_channel_set_stream: 13e40000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3328    [007] ....   375.060364: csi_s_stream: enable : 0x1
        v4l2-ctl-3328    [007] ....   375.060911: tegra_channel_set_stream: max9xxx 0-000c : 0x1
    kworker/0:10-226     [000] ....   375.101759: rtcpu_vinotify_event: tstamp:12247254172 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:391902180448 data:0x359e300010000000
    kworker/0:10-226     [000] ....   375.101760: rtcpu_vinotify_event: tstamp:12247254403 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:391902186976 data:0x0000000031000001
    kworker/0:10-226     [000] ....   375.101761: rtcpu_vinotify_event: tstamp:12247254657 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:391910374720 data:0x359e2d0010000000
    kworker/0:10-226     [000] ....   375.101761: rtcpu_vinotify_event: tstamp:12247254876 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:391910381376 data:0x0000000031000002
    kworker/0:10-226     [000] ....   375.101762: rtcpu_string: tstamp:12248470960 id:0x04010000 str:"tegra_nvcsi_stream_set_config(vm0, stream=5, csi"
    kworker/0:10-226     [000] ....   375.101763: rtcpu_string: tstamp:12248471080 id:0x04010000 str:"=6)
"
    kworker/0:10-226     [000] ....   375.101773: rtcpu_string: tstamp:12248471449 id:0x04010000 str:"MIPI clock = 562500 kHz, tHS-SETTLE = 0, tCLK-SE"
    kworker/0:10-226     [000] ....   375.101774: rtcpu_string: tstamp:12248471550 id:0x04010000 str:"TTLE = 0
"
    kworker/0:10-226     [000] ....   375.101781: rtcpu_string: tstamp:12248471763 id:0x04010000 str:"===== NVCSI Stream Configuration =====
"
    kworker/0:10-226     [000] ....   375.101786: rtcpu_string: tstamp:12248472009 id:0x04010000 str:"stream_id: PP 5, csi_port: PORT G
"
    kworker/0:10-226     [000] ....   375.101792: rtcpu_string: tstamp:12248472265 id:0x04010000 str:"Brick: PHY 3, Mode: D-PHY
"
    kworker/0:10-226     [000] ....   375.101798: rtcpu_string: tstamp:12248472546 id:0x04010000 str:"Partition: CIL A, LP bypass: Enabled, Lanes: 4
"
    kworker/0:10-226     [000] ....   375.101803: rtcpu_string: tstamp:12248472725 id:0x04010000 str:"Clock information:
"
    kworker/0:10-226     [000] ....   375.101808: rtcpu_string: tstamp:12248473022 id:0x04010000 str:"MIPI clock rate: 562.50 MHz
"
    kworker/0:10-226     [000] ....   375.101811: rtcpu_string: tstamp:12248473263 id:0x04010000 str:"T_HS settle: 0, T_CLK settle: 0
"
    kworker/0:10-226     [000] ....   375.101815: rtcpu_string: tstamp:12248473486 id:0x04010000 str:"======================================
"
    kworker/0:10-226     [000] ....   375.101817: rtcpu_string: tstamp:12248475639 id:0x04010000 str:"tegra_nvcsi_stream_open(vm0, stream=5, csi=6)
"
    kworker/0:10-226     [000] ....   375.101820: rtcpu_string: tstamp:12248476264 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_"
    kworker/0:10-226     [000] ....   375.101821: rtcpu_string: tstamp:12248476366 id:0x04010000 str:"SW_RESET_0 = 00000003
"
    kworker/0:10-226     [000] ....   375.101825: rtcpu_string: tstamp:12248476721 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_"
    kworker/0:10-226     [000] ....   375.101825: rtcpu_string: tstamp:12248476821 id:0x04010000 str:"SW_RESET_0 = 00000003
"
    kworker/0:10-226     [000] ....   375.101855: rtcpu_string: tstamp:12248477483 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET"
    kworker/0:10-226     [000] ....   375.101856: rtcpu_string: tstamp:12248477584 id:0x04010000 str:"_0 = 00000001
"
    kworker/0:10-226     [000] ....   375.101859: rtcpu_string: tstamp:12248483595 id:0x04010000 str:"nvcsi_reset_lane_merger: NVCSI_PHY_3_LM_SW_RESET"
    kworker/0:10-226     [000] ....   375.101860: rtcpu_string: tstamp:12248483695 id:0x04010000 str:"_0 = 00000000
"
    kworker/0:10-226     [000] ....   375.101863: rtcpu_string: tstamp:12248484249 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 56
"
    kworker/0:10-226     [000] ....   375.101866: rtcpu_string: tstamp:12248484509 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 56
"
    kworker/0:10-226     [000] ....   375.101869: rtcpu_string: tstamp:12248484767 id:0x04010000 str:"nvcsi_calc_ths_settle ths_settle 56
"
    kworker/0:10-226     [000] ....   375.101871: rtcpu_string: tstamp:12248485024 id:0x04010000 str:"nvcsi_calc_tclk_settle tclk_settle 75
"
    kworker/0:10-226     [000] ....   375.101874: rtcpu_string: tstamp:12248485487 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_A_"
    kworker/0:10-226     [000] ....   375.101875: rtcpu_string: tstamp:12248485588 id:0x04010000 str:"SW_RESET_0 = 00000000
"
    kworker/0:10-226     [000] ....   375.101878: rtcpu_string: tstamp:12248485942 id:0x04010000 str:"nvcsi_reset_data_lanes: NVCSI_PHY_3_NVCSI_CIL_B_"
    kworker/0:10-226     [000] ....   375.101879: rtcpu_string: tstamp:12248486043 id:0x04010000 str:"SW_RESET_0 = 00000000
"
    kworker/0:10-226     [000] ....   376.917670: rtcpu_vinotify_error: tstamp:12305255881 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393768126432 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.917673: rtcpu_vinotify_error: tstamp:12305256679 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393768140864 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.917674: rtcpu_vinotify_error: tstamp:12305257270 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393768196768 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.917676: rtcpu_vinotify_event: tstamp:12305258752 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:393768073920 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.917677: rtcpu_vinotify_event: tstamp:12305258889 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:393768073920 data:0x0000000800000000
    kworker/0:10-226     [000] ....   376.917677: rtcpu_vinotify_event: tstamp:12305259041 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:393768087392 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.917677: rtcpu_vinotify_event: tstamp:12305259172 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:393768102048 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.917678: rtcpu_vinotify_event: tstamp:12305259325 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:393768112704 data:0x0000000000000001
    kworker/0:10-226     [000] ....   376.917678: rtcpu_vinotify_event: tstamp:12305259457 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393768114240 data:0x0000000008020001
    kworker/0:10-226     [000] ....   376.917679: rtcpu_vinotify_event: tstamp:12305259610 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393768121120 data:0x0000000000000100
    kworker/0:10-226     [000] ....   376.917679: rtcpu_vinotify_event: tstamp:12305259744 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393768127008 data:0x0000000001020001
    kworker/0:10-226     [000] ....   376.917679: rtcpu_vinotify_event: tstamp:12305259906 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393768126432 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.917680: rtcpu_vinotify_event: tstamp:12305260037 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393768140864 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.917682: rtcpu_vinotify_event: tstamp:12305260182 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:393768181984 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.917682: rtcpu_vinotify_event: tstamp:12305260312 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393768196768 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.917683: rtcpu_vinotify_event: tstamp:12306389237 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393803407712 data:0x0000000002cf0182
    kworker/0:10-226     [000] ....   376.917683: rtcpu_vinotify_event: tstamp:12306389369 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:393803408352 data:0x0000000000000000
    kworker/0:10-226     [000] ....   376.917684: rtcpu_vinotify_event: tstamp:12306389521 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393803450016 data:0x0000000002d001c0
    kworker/0:10-226     [000] ....   376.973667: rtcpu_vinotify_event: tstamp:12306727301 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:393810185600 data:0x0000000000000025
    kworker/0:10-226     [000] ....   376.973668: rtcpu_vinotify_event: tstamp:12306727467 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:393810269024 data:0x0000000000000025
    kworker/0:10-226     [000] ....   376.973668: rtcpu_vinotify_error: tstamp:12306817943 cch:0 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:0 vi_tstamp:393818089088 data:0x00000000000000a5
    kworker/0:10-226     [000] ....   376.973669: rtcpu_vinotify_error: tstamp:12306818362 cch:-1 vi:1 tag:CSIMUX_FRAME channel:0x03 frame:0 vi_tstamp:393818102720 data:0x00000000000000a5
    kworker/0:10-226     [000] ....   376.973670: rtcpu_vinotify_error: tstamp:12306818972 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393818117024 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.973670: rtcpu_vinotify_error: tstamp:12306819848 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393818144544 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.973670: rtcpu_vinotify_error: tstamp:12306820440 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393818214208 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.973671: rtcpu_vinotify_event: tstamp:12306822642 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:393818078272 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.973672: rtcpu_vinotify_event: tstamp:12306822796 cch:0 vi:1 tag:CSIMUX_FRAME channel:0x00 frame:0 vi_tstamp:393818089088 data:0x00000000000000a5
    kworker/0:10-226     [000] ....   376.973672: rtcpu_vinotify_event: tstamp:12306822931 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:393818089088 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.973672: rtcpu_vinotify_event: tstamp:12306823087 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:393818089120 data:0x0000000800000000
    kworker/0:10-226     [000] ....   376.973673: rtcpu_vinotify_event: tstamp:12306823223 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:393818089120 data:0x0000000800000000
    kworker/0:10-226     [000] ....   376.973673: rtcpu_vinotify_event: tstamp:12306823375 cch:-1 vi:1 tag:CSIMUX_FRAME channel:0x03 frame:0 vi_tstamp:393818102720 data:0x00000000000000a5
    kworker/0:10-226     [000] ....   376.973674: rtcpu_vinotify_event: tstamp:12306823511 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:393818102720 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.973674: rtcpu_vinotify_event: tstamp:12306823664 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393818117024 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.973675: rtcpu_vinotify_event: tstamp:12306823810 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:393818130784 data:0x0000000000000001
    kworker/0:10-226     [000] ....   376.973675: rtcpu_vinotify_event: tstamp:12306823967 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393818132288 data:0x0000000008020002
    kworker/0:10-226     [000] ....   376.973675: rtcpu_vinotify_event: tstamp:12306824102 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393818139232 data:0x0000000000000100
    kworker/0:10-226     [000] ....   376.973676: rtcpu_vinotify_event: tstamp:12307132839 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393818146208 data:0x0000000001020002
    kworker/0:10-226     [000] ....   376.973676: rtcpu_vinotify_event: tstamp:12307132974 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393818144544 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.973676: rtcpu_vinotify_event: tstamp:12307133128 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:393818172672 data:0x359e300010000000
    kworker/0:10-226     [000] ....   376.973677: rtcpu_vinotify_event: tstamp:12307133262 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:393818179232 data:0x0000000031000003
    kworker/0:10-226     [000] ....   376.973677: rtcpu_vinotify_event: tstamp:12307133416 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:393818199392 data:0x0000000000000015
    kworker/0:10-226     [000] ....   376.973677: rtcpu_vinotify_event: tstamp:12307133547 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393818214208 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   376.973678: rtcpu_vinotify_event: tstamp:12308140299 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393853655488 data:0x0000000002cf0182
    kworker/0:10-226     [000] ....   376.973678: rtcpu_vinotify_event: tstamp:12308140433 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:393853656128 data:0x0000000000000000
    kworker/0:10-226     [000] ....   376.973679: rtcpu_vinotify_event: tstamp:12308140584 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393853684032 data:0x0000000002d001c0
    kworker/0:10-226     [000] ....   376.973679: rtcpu_vinotify_event: tstamp:12308140715 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:393860216736 data:0x0000000000000025
    kworker/0:10-226     [000] ....   376.973679: rtcpu_vinotify_event: tstamp:12308140864 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:393860313920 data:0x0000000000000025
    kworker/0:10-226     [000] ....   376.973680: rtcpu_vinotify_event: tstamp:12308140995 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:393860383584 data:0x0000000000000025
    kworker/0:10-226     [000] ....   376.973680: rtcpu_vinotify_event: tstamp:12308141148 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:393860383584 data:0x0000000800000000
    kworker/0:10-226     [000] ....   376.973681: rtcpu_vinotify_event: tstamp:12308141281 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:393860399328 data:0x359e2d0010000000
    kworker/0:10-226     [000] ....   376.973681: rtcpu_vinotify_event: tstamp:12308141441 cch:0 vi:1 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:393860405888 data:0x0000000031000004
    kworker/0:10-226     [000] ....   376.973681: rtcpu_vinotify_event: tstamp:12308141576 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:393860466976 data:0x0000000000000025
    kworker/0:10-226     [000] ....   377.033652: rtcpu_vinotify_error: tstamp:12308380872 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393868117760 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033653: rtcpu_vinotify_error: tstamp:12308381856 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393868132384 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033653: rtcpu_vinotify_error: tstamp:12308382227 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393868188320 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033654: rtcpu_vinotify_event: tstamp:12308451270 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:393868078976 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033654: rtcpu_vinotify_event: tstamp:12308451406 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:393868093600 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033654: rtcpu_vinotify_event: tstamp:12308451579 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:393868104224 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033654: rtcpu_vinotify_event: tstamp:12308451716 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:393868104224 data:0x0000000800000000
    kworker/0:10-226     [000] ....   377.033655: rtcpu_vinotify_event: tstamp:12308451869 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393868117760 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033655: rtcpu_vinotify_event: tstamp:12308452001 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393868132384 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033655: rtcpu_vinotify_event: tstamp:12308452155 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:393868146112 data:0x0000000000000001
    kworker/0:10-226     [000] ....   377.033655: rtcpu_vinotify_event: tstamp:12308452289 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393868149536 data:0x0000000008020003
    kworker/0:10-226     [000] ....   377.033656: rtcpu_vinotify_event: tstamp:12308452442 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393868154560 data:0x0000000000000100
    kworker/0:10-226     [000] ....   377.033656: rtcpu_vinotify_event: tstamp:12308452576 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393868161440 data:0x0000000001020003
    kworker/0:10-226     [000] ....   377.033656: rtcpu_vinotify_event: tstamp:12308452735 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:393868173504 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033656: rtcpu_vinotify_event: tstamp:12308452869 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393868188320 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033657: rtcpu_vinotify_event: tstamp:12309694164 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393903694080 data:0x0000000002cf0182
    kworker/0:10-226     [000] ....   377.033657: rtcpu_vinotify_event: tstamp:12309694299 cch:0 vi:1 tag:ATOMP_FRAME_DONE channel:0x23 frame:0 vi_tstamp:393903694688 data:0x0000000000000000
    kworker/0:10-226     [000] ....   377.033657: rtcpu_vinotify_event: tstamp:12309694454 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393903736352 data:0x0000000002d001c0
    kworker/0:10-226     [000] ....   377.033657: rtcpu_vinotify_event: tstamp:12309694588 cch:-1 vi:1 tag:FE channel:0x02 frame:0 vi_tstamp:393910190848 data:0x0000000000000025
    kworker/0:10-226     [000] ....   377.033658: rtcpu_vinotify_error: tstamp:12309943552 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393918133152 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033658: rtcpu_vinotify_error: tstamp:12309943932 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393918147648 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033658: rtcpu_vinotify_error: tstamp:12309945068 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xa0 frame:0 vi_tstamp:393918217312 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033659: rtcpu_vinotify_event: tstamp:12309945790 cch:-1 vi:1 tag:FE channel:0x01 frame:0 vi_tstamp:393910329280 data:0x0000000000000025
    kworker/0:10-226     [000] ....   377.033659: rtcpu_vinotify_event: tstamp:12309945925 cch:0 vi:1 tag:FE channel:0x00 frame:0 vi_tstamp:393910371424 data:0x0000000000000025
    kworker/0:10-226     [000] ....   377.033659: rtcpu_vinotify_event: tstamp:12309946081 cch:0 vi:1 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:393910371424 data:0x0000000800000000
    kworker/0:10-226     [000] ....   377.033659: rtcpu_vinotify_event: tstamp:12309946213 cch:-1 vi:1 tag:FE channel:0x03 frame:0 vi_tstamp:393910468608 data:0x0000000000000025
    kworker/0:10-226     [000] ....   377.033660: rtcpu_vinotify_event: tstamp:12309946362 cch:0 vi:1 tag:FS channel:0x00 frame:0 vi_tstamp:393918080288 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033660: rtcpu_vinotify_event: tstamp:12309946497 cch:0 vi:1 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:393918080320 data:0x0000000800000000
    kworker/0:10-226     [000] ....   377.033660: rtcpu_vinotify_event: tstamp:12309946646 cch:-1 vi:1 tag:FS channel:0x03 frame:0 vi_tstamp:393918094336 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033660: rtcpu_vinotify_event: tstamp:12309946777 cch:-1 vi:1 tag:FS channel:0x01 frame:0 vi_tstamp:393918108864 data:0x0000000000000015
    kworker/0:10-226     [000] ....   377.033661: rtcpu_vinotify_event: tstamp:12309946931 cch:0 vi:1 tag:CHANSEL_PXL_SOF channel:0x23 frame:0 vi_tstamp:393918119104 data:0x0000000000000001
    kworker/0:10-226     [000] ....   377.033661: rtcpu_vinotify_event: tstamp:12309947066 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393918120608 data:0x0000000008020004
    kworker/0:10-226     [000] ....   377.033661: rtcpu_vinotify_event: tstamp:12309947219 cch:0 vi:1 tag:CHANSEL_FAULT channel:0x23 frame:0 vi_tstamp:393918127520 data:0x0000000000000100
    kworker/0:10-226     [000] ....   377.033661: rtcpu_vinotify_event: tstamp:12309947354 cch:0 vi:1 tag:VIFALC_ACTIONLST channel:0x23 frame:0 vi_tstamp:393918133408 data:0x0000000001020004
    kworker/0:10-226     [000] ....   377.033662: rtcpu_vinotify_event: tstamp:12309947507 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0xe0 frame:0 vi_tstamp:393918133152 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033662: rtcpu_vinotify_event: tstamp:12309947639 cch:-1 vi:1 tag:CHANSEL_NOMATCH channel:0x60 frame:0 vi_tstamp:393918147648 data:0x00000000000003c9
    kworker/0:10-226     [000] ....   377.033662: rtcpu_vinotify_event: tstamp:12309947790 cch:-1 vi:1 tag:FS channel:0x02 frame:0 vi_tstamp:393918188768 data:0x0000000000000015
5

Check the CHANSEL_FAULT

https://elinux.org/Jetson/l4t/Camera_BringUp#Steps_to_enable_more_debug_messages

7

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.