Jetson_Linux 34.1 : vi_capture_control_message: NULL VI channel received

use v35.3.1 … The same result only occasionally succeeds

v3531_rgb88_err.log (11.2 KB)

v3531_rgb88_ok.log (13.5 KB)

hello channinglan,

there shows PHY interrupts, 0x110 means the data-lane FIFO overflow failures.
kworker/1:2-137 [001] .... 927.461628: rtcpu_nvcsi_intr: tstamp:29792054485 class:GLOBAL type:PHY_INTR0 phy:0 cil:0 st:0 vc:0 status:0x00000110

also,
it’s reported CHANSEL_SHORT_FRAME, which due to the senosr signaling mismatch with the active_h settings.
kworker/1:2-137 [001] .... 927.517714: rtcpu_vinotify_event: tstamp:29794617973 cch:-1 vi:0 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:0 vi_tstamp:953419521760 data:0x0000200001000000

however,
it looks your OK results also contain PHY interrupt error and SHORT_FRAME messges,
may I know the status when it works Occasionally.
for example, what’s your test steps, how you determine sensor output correct streams.

I updated the version 32.6.1 and it can display the screen normally

CHANSEL_SHORT_FRAME In this version also appears

v3261_rgb888_v0.log (19.5 KB)

In v35.3.1, the chances of displaying normally are very low! It seems that the first time after each re-flashing is more likely to appear

hello channinglan,

the root cause should be PHY interrupt which related to data-lane FIFO overflow failures.
could you please based-on r35.3.1, and running below commands to boost all the VI/CSI/ISP clocks for testing.
for example,

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

My test script already contains those settings
but the situation remains the same

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

v4l2-ctl -d /dev/video0 --list-formats-ext

 v4l2-ctl -d /dev/video0 \
            --set-fmt-video=width=400,height=400,pixelformat=AR24 \
            --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 \
            --stream-skip=0 --stream-to=AR24_400_c0.raw

 ffplay -f rawvideo -video_size 400*400 -pixel_format  rgba -i AR24_400_c0.raw

please see-also similar topics for digging into data-lane FIFO overflow failures.
such as… Topic 209574, Topic 242054.

can’t read NVCSI_STREAM_0_PH_WC_0
How to fix ???

  1. in 32.6.1 can display the screen normally …
    But I still get this message, so should I fix this before testing the port to r35.3.1?
306.374283: rtcpu_vinotify_event: tstamp:10079137698 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:0 vi_tstamp:10078897441 data:0x01000000

You stated earlier that the CHANSEL_SHORT_FRAME error is related to active_h, but I don’t know how to fix it??

						active_w = "400";
						active_h = "400";

						mode_type = "rgb";
						pixel_phase = "rgb888";
						csi_pixel_bit_depth = "24";
						line_length = "2000";
						readout_orientation = "0";
						inherent_gain = "1";
						mclk_multiplier = "1";						
  						pix_clk_hz = "625000000";//1250000000 * 4 / 8

hello channinglan,

you should put the camera stream enabled for reading register.
there’s also an error due to reading blocked by firewall.
so, let me double check what’s the platform you’re working with, for example, it looks you worked with Xavier series, is it AGX Xavier or Xavier NX?

SHORT_FRAME, this error introduced by VI receives less lines than expected, it may due to blanking lines, usually you could try reducing active_h for some trial-n-error testing.
or, this error may caused by a FS_FAULT would insert a FE packet to terminate the frame. you may examine tracing logs to check whether it’s sending SOF/EOF…EOF in the expected sequence.

  1. use AGX Xavier
  2. reducing active_h ??
    Need to modify the supported size of the driver simultaneously?

hello channinglan,

you should simply revise active_h in device tree for a quick try, and, it should pop-up different failure once the VI receives more lines.

blanking lines ??? my source is FPGA …should be no blanking lines

set active_h = “380”;

v4l2-ctl -d /dev/video0 \
            --set-fmt-video=width=400,height=400,pixelformat=AR24 \
            --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 \
            --stream-skip=0 --stream-to=AR24_c0.raw
     kworker/0:5-193     [000] ....    39.064824: rtcpu_string: tstamp:2027694703 id:0x04010000 str:"VM0 deactivating."
        v4l2-ctl-3107    [000] ....    84.068370: tegra_channel_open: vi-output, gen3 0-001e
        v4l2-ctl-3107    [000] ....    84.069434: tegra_channel_close: vi-output, gen3 0-001e
        v4l2-ctl-3108    [000] ....    84.075606: tegra_channel_open: vi-output, gen3 0-001e
        v4l2-ctl-3108    [000] ....    84.078404: tegra_channel_set_power: gen3 0-001e : 0x1
        v4l2-ctl-3108    [000] ....    84.078417: camera_common_s_power: status : 0x1
        v4l2-ctl-3108    [000] ....    84.078454: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3108    [000] ....    84.078457: csi_s_power: enable : 0x1
        v4l2-ctl-3108    [000] ....    84.078927: tegra_channel_capture_setup: vnc_id 0 W 400 H 400 fmt 9
        v4l2-ctl-3108    [002] ....    84.089768: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-3108    [002] ....    84.091442: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3108    [002] ....    84.091447: csi_s_stream: enable : 0x1
        v4l2-ctl-3108    [002] ....    84.091974: tegra_channel_set_stream: gen3 0-001e : 0x1
     kworker/0:7-195     [000] ....    84.139774: rtcpu_string: tstamp:3434828737 id:0x04010000 str:"VM0 activating."
     kworker/0:7-195     [000] ....    84.139779: rtcpu_vinotify_event: tstamp:3435270613 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109919178720 data:0xcd9ce50010000000
     kworker/0:7-195     [000] ....    84.139780: rtcpu_vinotify_event: tstamp:3435270753 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109919184224 data:0x0000000031000001
     kworker/0:7-195     [000] ....    84.139780: rtcpu_vinotify_event: tstamp:3435270907 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109919239008 data:0xcd9ce20010000000
     kworker/0:7-195     [000] ....    84.139781: rtcpu_vinotify_event: tstamp:3435271042 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:109919244576 data:0x0000000031000002

you should also revise v4l command-line to reduce the height settings.

v4l2-ctl -d /dev/video0 \
            --set-fmt-video=width=400,height=380,pixelformat=AR24 \
            --set-ctrl bypass_mode=0 --stream-mmap --stream-count=1 \
            --stream-skip=0 --stream-to=AR24_400_c0.raw
        v4l2-ctl-3199    [000] ....   299.917303: tegra_channel_open: vi-output, gen3 0-001e
        v4l2-ctl-3199    [000] ....   299.918261: tegra_channel_close: vi-output, gen3 0-001e
        v4l2-ctl-3200    [000] ....   299.926181: tegra_channel_open: vi-output, gen3 0-001e
        v4l2-ctl-3200    [000] ....   299.929851: tegra_channel_set_power: gen3 0-001e : 0x1
        v4l2-ctl-3200    [000] ....   299.929865: camera_common_s_power: status : 0x1
        v4l2-ctl-3200    [000] ....   299.929896: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3200    [000] ....   299.929898: csi_s_power: enable : 0x1
        v4l2-ctl-3200    [000] ....   299.930511: tegra_channel_capture_setup: vnc_id 0 W 400 H 400 fmt 9
        v4l2-ctl-3200    [003] ....   299.939634: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-3200    [003] ....   299.941227: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3200    [003] ....   299.941231: csi_s_stream: enable : 0x1
        v4l2-ctl-3200    [003] ....   299.941721: tegra_channel_set_stream: gen3 0-001e : 0x1
     kworker/2:2-136     [002] ....   299.943728: rtcpu_string: tstamp:10174398204 id:0x04010000 str:"VM0 activating."
     kworker/2:2-136     [002] ....   299.999706: rtcpu_vinotify_event: tstamp:10174834165 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:325585174496 data:0xcd9ce50010000000
     kworker/2:2-136     [002] ....   299.999709: rtcpu_vinotify_event: tstamp:10174834305 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:325585179968 data:0x0000000031000001
     kworker/2:2-136     [002] ....   299.999710: rtcpu_vinotify_event: tstamp:10174834459 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:325585238880 data:0xcd9ce20010000000
     kworker/2:2-136     [002] ....   299.999710: rtcpu_vinotify_event: tstamp:10174834593 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:325585244384 data:0x0000000031000002
 vi-output, gen3-3202    [000] ....   302.558401: tegra_channel_capture_setup: vnc_id 0 W 400 H 400 fmt 9
     kworker/2:2-136     [002] ....   302.575688: rtcpu_vinotify_event: tstamp:10256619985 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:328204188768 data:0xcd9ce50010000000
     kworker/2:2-136     [002] ....   302.575691: rtcpu_vinotify_event: tstamp:10256620125 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:328204194592 data:0x0000000031000001
     kworker/2:2-136     [002] ....   302.575692: rtcpu_vinotify_event: tstamp:10256620280 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:328204244832 data:0xcd9ce20010000000
     kworker/2:2-136     [002] ....   302.575692: rtcpu_vinotify_event: tstamp:10256620414 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:328204250400 data:0x0000000031000002
[  397.781487] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  397.786066] (NULL device *): vi_capture_control_message: NULL VI channel received
[  397.786257] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[  397.786487] (NULL device *): vi_capture_control_message: NULL VI channel received
[  397.786651] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[  397.787116] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channe

modify driver to 400x380

        v4l2-ctl-3167    [000] ....   273.557381: tegra_channel_open: vi-output, gen3 0-001e
        v4l2-ctl-3167    [000] ....   273.558809: tegra_channel_close: vi-output, gen3 0-001e
        v4l2-ctl-3168    [000] ....   273.568626: tegra_channel_open: vi-output, gen3 0-001e
        v4l2-ctl-3168    [000] ....   273.570864: tegra_channel_set_power: gen3 0-001e : 0x1
        v4l2-ctl-3168    [000] ....   273.570875: camera_common_s_power: status : 0x1
        v4l2-ctl-3168    [000] ....   273.570915: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3168    [000] ....   273.570917: csi_s_power: enable : 0x1
        v4l2-ctl-3168    [000] ....   273.571449: tegra_channel_capture_setup: vnc_id 0 W 400 H 380 fmt 9
        v4l2-ctl-3168    [001] ....   273.579240: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-3168    [001] ....   273.580866: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3168    [001] ....   273.580870: csi_s_stream: enable : 0x1
        v4l2-ctl-3168    [000] ....   273.581838: tegra_channel_set_stream: gen3 0-001e : 0x1
     kworker/0:5-1182    [000] ....   273.590772: rtcpu_string: tstamp:9283948715 id:0x04010000 str:"VM0 activating."
     kworker/0:5-1182    [000] ....   273.590777: rtcpu_vinotify_event: tstamp:9284386291 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:297090775328 data:0xcd9ce50010000000
     kworker/0:5-1182    [000] ....   273.590778: rtcpu_vinotify_event: tstamp:9284386431 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:297090780832 data:0x0000000031000001
     kworker/0:5-1182    [000] ....   273.590779: rtcpu_vinotify_event: tstamp:9284386585 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:297090835584 data:0xcd9ce20010000000
     kworker/0:5-1182    [000] ....   273.590779: rtcpu_vinotify_event: tstamp:9284386720 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:297090841184 data:0x0000000031000002

hello channinglan,

I don’t see any failures with 400x380, is it capture the frames?

same error!!!

ioctl: VIDIOC_ENUM_FMT
        Type: Video Capture

        [0]: 'AR24' (32-bit BGRA 8-8-8-8)
                Size: Discrete 400x380
                        Interval: Discrete 0.033s (30.000 fps)
                Size: Discrete 800x800
                        Interval: Discrete 0.033s (30.000 fps)
                Size: Discrete 1920x1080
                        Interval: Discrete 0.017s (60.000 fps)
                Size: Discrete 1920x1920
                        Interval: Discrete 0.017s (60.000 fps)

--- active_h ---
380
        v4l2-ctl-3094    [003] ....   158.402963: camera_common_s_power: status : 0x1
        v4l2-ctl-3094    [003] ....   158.402999: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3094    [003] ....   158.403001: csi_s_power: enable : 0x1
        v4l2-ctl-3094    [003] ....   158.406022: tegra_channel_capture_setup: vnc_id 0 W 400 H 380 fmt 9
        v4l2-ctl-3094    [000] ....   158.414975: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-3094    [000] ....   158.416089: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-3094    [000] ....   158.416093: csi_s_stream: enable : 0x1
        v4l2-ctl-3094    [000] ....   158.416467: tegra_channel_set_stream: gen3 0-001e : 0x1
     kworker/0:5-159     [000] ....   158.455551: rtcpu_string: tstamp:5688327719 id:0x04010000 str:"VM0 activating."
     kworker/0:5-159     [000] ....   158.455555: rtcpu_vinotify_event: tstamp:5688762801 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:182030822528 data:0xcd9ce50010000000
     kworker/0:5-159     [000] ....   158.455556: rtcpu_vinotify_event: tstamp:5688762946 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:182030828000 data:0x0000000031000001
     kworker/0:5-159     [000] ....   158.455557: rtcpu_vinotify_event: tstamp:5688763102 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:182030882688 data:0xcd9ce20010000000
     kworker/0:5-159     [000] ....   158.455557: rtcpu_vinotify_event: tstamp:5688763237 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:182030888288 data:0x0000000031000002
 vi-output, gen3-3096    [003] ....   160.989838: tegra_channel_capture_setup: vnc_id 0 W 400 H 380 fmt 9
     kworker/0:0-5       [000] ....   161.007582: rtcpu_vinotify_event: tstamp:5768953344 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:184605990656 data:0xcd9ce50010000000
     kworker/0:0-5       [000] ....   161.007585: rtcpu_vinotify_event: tstamp:5768953483 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:184605996160 data:0x0000000031000001
     kworker/0:0-5       [000] ....   161.007586: rtcpu_vinotify_event: tstamp:5768953637 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:184606050528 data:0xcd9ce20010000000
     kworker/0:0-5       [000] ....   161.007586: rtcpu_vinotify_event: tstamp:5768953772 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:184606056096 data:0x0000000031000002
root@user-desktop:/home/user# [  163.551664] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms```


[ 168.667804] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 2500 ms
[ 168.668035] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[ 168.668978] (NULL device *): vi_capture_control_message: NULL VI channel received
[ 168.669129] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[ 168.669323] (NULL device *): vi_capture_control_message: NULL VI channel received
[ 168.669463] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[ 168.669914] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel

hello channinglan,

I don’t see SHORT_FRAME messages.
anyways…
could you please try disable sensor controls, such as gain/exposure/frame-length settings.
since you’ve mentioned it works occasionally, it doubts different register settings writing to sensor cause such failure.

My video source is FPGA
So no any gain/exposure/frame-length settings …
I don’t need to control the FPGA, the data will be automatically output when the power is turned on, and it can be displayed normally in r32.6.1 (although there is a SHORT_FRAME)… But it is difficult to display normally in r35.3.1. I would like to ask the difference between the two versions ??

the major difference is kernel version. as you can see… Camera Driver Porting, it’s now using kernel-5.10

you may check VI-5 driver, please configure a higher timeout value. #define CAPTURE_TIMEOUT_MS 2500
and… for your video source, is it possible to trigger a reset when you execute v4l pipeline?

  1. I can’t control video soures (FPGA) …

modify CAPTURE_TIMEOUT_MS to 5500 … same error

      v4l2-ctl-4097    [003] ....  1285.603084: camera_common_s_power: status : 0x1
        v4l2-ctl-4097    [003] ....  1285.603119: tegra_channel_set_power: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-4097    [003] ....  1285.603122: csi_s_power: enable : 0x1
        v4l2-ctl-4097    [003] ....  1285.603687: tegra_channel_capture_setup: vnc_id 0 W 400 H 400 fmt 9
        v4l2-ctl-4097    [001] ....  1285.616384: tegra_channel_set_stream: enable : 0x1
        v4l2-ctl-4097    [001] ....  1285.617865: tegra_channel_set_stream: 13e10000.host1x:nvcsi@15a00000- : 0x1
        v4l2-ctl-4097    [001] ....  1285.617868: csi_s_stream: enable : 0x1
        v4l2-ctl-4097    [001] ....  1285.618449: tegra_channel_set_stream: gen3 0-001e : 0x1
     kworker/3:0-4003    [003] ....  1285.627927: rtcpu_string: tstamp:41020230581 id:0x04010000 str:"VM0 activating."
     kworker/3:0-4003    [003] ....  1285.627932: rtcpu_vinotify_event: tstamp:41020665056 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1312651705184 data:0xcd9ce50010000000
     kworker/3:0-4003    [003] ....  1285.627932: rtcpu_vinotify_event: tstamp:41020665196 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1312651710688 data:0x0000000031000001
     kworker/3:0-4003    [003] ....  1285.627933: rtcpu_vinotify_event: tstamp:41020665350 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1312651769536 data:0xcd9ce20010000000
     kworker/3:0-4003    [003] ....  1285.627933: rtcpu_vinotify_event: tstamp:41020665485 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1312651775104 data:0x0000000031000002
 vi-output, gen3-4099    [001] ....  1288.357268: tegra_channel_capture_setup: vnc_id 0 W 400 H 400 fmt 9
     kworker/3:0-4003    [003] ....  1288.371778: rtcpu_vinotify_event: tstamp:41106181206 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1315395718656 data:0xcd9ce50010000000
     kworker/3:0-4003    [003] ....  1288.371781: rtcpu_vinotify_event: tstamp:41106181346 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1315395724192 data:0x0000000031000001
     kworker/3:0-4003    [003] ....  1288.371782: rtcpu_vinotify_event: tstamp:41106181500 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1315395778784 data:0xcd9ce20010000000
     kworker/3:0-4003    [003] ....  1288.371782: rtcpu_vinotify_event: tstamp:41106181635 cch:0 vi:0 tag:VIFALC_TDSTATE channel:0x23 frame:0 vi_tstamp:1315395784352 data:0x0000000031000002
 vi-output, gen
[  116.675272] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  116.675690] (NULL device *): vi_capture_control_message: NULL VI channel received
[  116.675865] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[  116.676120] (NULL device *): vi_capture_control_message: NULL VI channel received
[  116.676284] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[  116.676770] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel
[  122.328327] tegra-camrtc-capture-vi tegra-capture-vi: uncorr_err: request timed out after 5500 ms
[  122.328583] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: attempting to reset the capture channel
[  122.329725] (NULL device *): vi_capture_control_message: NULL VI channel received
[  122.329916] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_close: Error in closing stream_id=0, csi_port=0
[  122.330167] (NULL device *): vi_capture_control_message: NULL VI channel received
[  122.330334] t194-nvcsi 13e10000.host1x:nvcsi@15a00000: csi5_stream_open: VI channel not found for stream- 0 vc- 0
[  122.330785] tegra-camrtc-capture-vi tegra-capture-vi: err_rec: successfully reset the capture channel