TX2 CSI Capture with Jetpack 4.5.1

Please have a check the TRM find the REG NVCSI_STREAM_0_ERROR_STATUS2VI_VC2_0 for the detail.
You can download TRM from download center.

Shane,

I applied the patch and it has changed something, but still no video.

The dmesg output has changed to:

[  289.882573] v4fpga 2-0010: charm100_camera_power_on: power on
[  289.896067] v4fpga 2-0010: charm100_camera_power_on: powered on
[  290.115623] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[  290.122085] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[  290.132798] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[  290.347617] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[  290.354028] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[  290.364827] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000004
[  290.575617] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[  290.582071] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[  290.591818] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000006
[  290.803612] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[  290.810020] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[  290.819999] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000006
[  291.047643] tegra-vi4 15700000.vi: PXL_SOF syncpt timeout! err = -11
[  291.054018] tegra-vi4 15700000.vi: tegra_channel_error_recovery: attempting to reset the capture channel
[  291.063801] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000006
[  291.073042] nvcsi 150c0000.nvcsi: csi4_stream_check_status (0) ERROR_STATUS2VI_VC0 = 0x00000006

I had to modify the patch slightly to take account of the port number variable being called csi_port, not port_num.

Some of the errors are now not reported, but the VI is still not happy.

Do you have any other ideas where to look?

Thanks,
Ratbert

What’s the trace log.

https://elinux.org/Jetson_TX2_Camera_BringUp

It repeats, so this is 1 and a bit cycles:

 kworker/4:0-36    [004] ....  3861.575179: rtos_queue_send_failed: tstamp:120820256795 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.575181: rtcpu_vinotify_event: tstamp:120820505607 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:120820505092 data:0x00000001
 kworker/4:0-36    [004] ....  3861.575181: rtcpu_vinotify_event: tstamp:120820505766 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:120820505107 data:0x00000000
 kworker/4:0-36    [004] ....  3861.575182: rtcpu_vinotify_event: tstamp:120820507408 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:120820507041 data:0x08000000
 kworker/4:0-36    [004] ....  3861.575182: rtcpu_vinotify_event: tstamp:120821026556 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:120821025847 data:0x000000a0
 kworker/4:0-36    [004] ....  3861.575183: rtcpu_vinotify_event: tstamp:120821026758 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:120821025847 data:0x00000001
 kworker/4:0-36    [004] ....  3861.575183: rtcpu_vinotify_event: tstamp:120821026895 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:120821025850 data:0x00000000
 kworker/4:0-36    [004] ....  3861.631211: rtos_queue_peek_from_isr_failed: tstamp:120823100342 queue:0x0b4b4500
 kworker/4:0-36    [004] ....  3861.799170: rtos_queue_send_from_isr_failed: tstamp:120827341731 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799174: rtos_queue_send_from_isr_failed: tstamp:120827341846 queue:0x0b4aad68
 kworker/4:0-36    [004] ....  3861.799174: rtos_queue_send_from_isr_failed: tstamp:120827341951 queue:0x0b4ac998
 kworker/4:0-36    [004] ....  3861.799175: rtos_queue_send_from_isr_failed: tstamp:120827342055 queue:0x0b4ae518
 kworker/4:0-36    [004] ....  3861.799176: rtos_queue_send_from_isr_failed: tstamp:120827342155 queue:0x0b4af2d8
 kworker/4:0-36    [004] ....  3861.799176: rtos_queue_send_from_isr_failed: tstamp:120827342257 queue:0x0b4b0098
 kworker/4:0-36    [004] ....  3861.799177: rtos_queue_send_from_isr_failed: tstamp:120827342357 queue:0x0b4b0e58
 kworker/4:0-36    [004] ....  3861.799178: rtos_queue_send_from_isr_failed: tstamp:120827342459 queue:0x0b4b1c18
 kworker/4:0-36    [004] ....  3861.799179: rtos_queue_send_failed: tstamp:120827343074 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799180: rtos_queue_send_from_isr_failed: tstamp:120827346196 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799180: rtos_queue_send_from_isr_failed: tstamp:120827346299 queue:0x0b4aad68
 kworker/4:0-36    [004] ....  3861.799181: rtos_queue_send_from_isr_failed: tstamp:120827346401 queue:0x0b4ac998
 kworker/4:0-36    [004] ....  3861.799182: rtos_queue_send_from_isr_failed: tstamp:120827346506 queue:0x0b4ae518
 kworker/4:0-36    [004] ....  3861.799182: rtos_queue_send_from_isr_failed: tstamp:120827346607 queue:0x0b4af2d8
 kworker/4:0-36    [004] ....  3861.799183: rtos_queue_send_from_isr_failed: tstamp:120827346710 queue:0x0b4b0098
 kworker/4:0-36    [004] ....  3861.799183: rtos_queue_send_from_isr_failed: tstamp:120827346811 queue:0x0b4b0e58
 kworker/4:0-36    [004] ....  3861.799184: rtos_queue_send_from_isr_failed: tstamp:120827346912 queue:0x0b4b1c18
 kworker/4:0-36    [004] ....  3861.799184: rtos_queue_send_failed: tstamp:120827347328 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799185: rtos_queue_send_from_isr_failed: tstamp:120827623868 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799186: rtos_queue_send_from_isr_failed: tstamp:120827623973 queue:0x0b4aad68
 kworker/4:0-36    [004] ....  3861.799186: rtos_queue_send_from_isr_failed: tstamp:120827624078 queue:0x0b4ac998
 kworker/4:0-36    [004] ....  3861.799187: rtos_queue_send_from_isr_failed: tstamp:120827624182 queue:0x0b4ae518
 kworker/4:0-36    [004] ....  3861.799187: rtos_queue_send_from_isr_failed: tstamp:120827624284 queue:0x0b4af2d8
 kworker/4:0-36    [004] ....  3861.799188: rtos_queue_send_from_isr_failed: tstamp:120827624386 queue:0x0b4b0098
 kworker/4:0-36    [004] ....  3861.799188: rtos_queue_send_from_isr_failed: tstamp:120827624487 queue:0x0b4b0e58
 kworker/4:0-36    [004] ....  3861.799189: rtos_queue_send_from_isr_failed: tstamp:120827624588 queue:0x0b4b1c18
 kworker/4:0-36    [004] ....  3861.799190: rtos_queue_send_failed: tstamp:120827625043 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799190: rtos_queue_send_from_isr_failed: tstamp:120827626373 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799191: rtos_queue_send_from_isr_failed: tstamp:120827626477 queue:0x0b4aad68
 kworker/4:0-36    [004] ....  3861.799191: rtos_queue_send_from_isr_failed: tstamp:120827626582 queue:0x0b4ac998
 kworker/4:0-36    [004] ....  3861.799192: rtos_queue_send_from_isr_failed: tstamp:120827626685 queue:0x0b4ae518
 kworker/4:0-36    [004] ....  3861.799193: rtos_queue_send_from_isr_failed: tstamp:120827626786 queue:0x0b4af2d8
 kworker/4:0-36    [004] ....  3861.799193: rtos_queue_send_from_isr_failed: tstamp:120827626887 queue:0x0b4b0098
 kworker/4:0-36    [004] ....  3861.799194: rtos_queue_send_from_isr_failed: tstamp:120827626988 queue:0x0b4b0e58
 kworker/4:0-36    [004] ....  3861.799194: rtos_queue_send_from_isr_failed: tstamp:120827627089 queue:0x0b4b1c18
 kworker/4:0-36    [004] ....  3861.799195: rtos_queue_send_failed: tstamp:120827627979 queue:0x0b4a7258
 kworker/4:0-36    [004] ....  3861.799197: rtcpu_vinotify_event: tstamp:120827797264 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:120827796753 data:0x00000001
 kworker/4:0-36    [004] ....  3861.799197: rtcpu_vinotify_event: tstamp:120827797423 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:120827796769 data:0x00000000
 kworker/4:0-36    [004] ....  3861.799197: rtcpu_vinotify_event: tstamp:120827799534 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:120827799168 data:0x08000000
 kworker/4:0-36    [004] ....  3861.799199: rtos_queue_peek_from_isr_failed: tstamp:120828100338 queue:0x0b4b4500
 kworker/4:0-36    [004] ....  3861.799199: rtcpu_vinotify_event: tstamp:120828318221 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:120828317508 data:0x000000a0
 kworker/4:0-36    [004] ....  3861.799200: rtcpu_vinotify_event: tstamp:120828318419 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:120828317509 data:0x00000001
 kworker/4:0-36    [004] ....  3861.799200: rtcpu_vinotify_event: tstamp:120828318557 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:120828317512 data:0x00000000

The trace log show the “tag:CHANSEL_SHORT_FRAME” that tell the output size didn’t as expect.
You can adjust the active_y in device tree to try. Can confirm the modify by v4l2-ctl --list-formats-ext

Interesting. These sizes appear correct (below) and using 3.2.1, we know this video is 720p. 1280x720 is what V4L reports as well. You mentioned the metadata lines above, but I assumed that was a cut and paste error from the original post. Should I try 4 lines as shown there?

root@nvidia-desktop:~# v4l2-ctl --list-formats-ext
ioctl: VIDIOC_ENUM_FMT
    Index       : 0
    Type        : Video Capture	
    Pixel Format: 'UYVY'
    Name        : UYVY 4:2:2
        Size: Discrete 1920x1080
        Size: Discrete 1280x720
        Size: Discrete 720x289
	    Size: Discrete 720x245
        Size: Discrete 1920x541
        Size: Discrete 640x512
        Size: Discrete 640x480
        Size: Discrete 1280x1024

    Index       : 1
    Type        : Video Capture
    Pixel Format: 'NV16'
    Name        : Y/CbCr 4:2:2
        Size: Discrete 1920x1080
        Size: Discrete 1280x720
        Size: Discrete 720x289
        Size: Discrete 720x245
        Size: Discrete 1920x541
        Size: Discrete 640x512
        Size: Discrete 640x480
        Size: Discrete 1280x1024

    Index       : 2
    Type        : Video Capture
    Pixel Format: 'UYVY'
    Name        : UYVY 4:2:2
        Size: Discrete 1920x1080
        Size: Discrete 1280x720
        Size: Discrete 720x289
        Size: Discrete 720x245
        Size: Discrete 1920x541
        Size: Discrete 640x512
        Size: Discrete 640x480
        Size: Discrete 1280x1024

I know some of these sizes are odd looking, but they are correct, for our use case. SDI has interlaced options, which we transport over the CSI as two “frames (fields)” and recombine the fields to get a full frame.

I would suggest to modify the resolution to check and check the trace log.
I only can check the trace and give advice.

I tried 360 lines and saw no difference. I will try some smaller sizes. Above you said “active_y”. Did you mean “active_h”? Am I missing some extra or renamed parameters? grep showed nothing for “active_y”.

Yes, right it’s active_h
Did you confirm the modify by the v4l2-crl --list-formats-ext?

I confirmed with:

nvidia@nvidia-desktop:~/fpga_tools$ cat /proc/device-tree/i2c@3180000/v4fpga@10/mode1/active_h
10

I thought the V4L sizes formats came from the driver (for mode matching)? E.g.:

static const struct camera_common_frmfmt charm100_camera_frmfmt[] = {
	{{1920, 1080}, NULL, 0, 0, CHARM100_MODE_1920x1080},
	{{1280, 720},  NULL, 0, 0, CHARM100_MODE_1280x720},
	{{720, 289},  NULL, 0, 0, CHARM100_MODE_720x576i},
	{{720, 245},  NULL, 0, 0, CHARM100_MODE_720x487i},
	{{1920, 541},  NULL, 0, 0, CHARM100_MODE_1920x1080i},
	{{640, 512},  NULL, 0, 0, CHARM100_MODE_640x512},
	{{640, 480},  NULL, 0, 0, CHARM100_MODE_640x480},
	{{1280, 1024},  NULL, 0, 0, CHARM100_MODE_1280x1024},
};

v4l2-ctl still shows 720 lines.

If v4l2-ctl still show the same that tell you need to modify the width of the sensor mode in sensor driver.

I’ve changed the format in the driver as well and list-formats-ext now shows:

root@nvidia-desktop:~# v4l2-ctl --list-formats-ext
ioctl: VIDIOC_ENUM_FMT
	Index       : 0
	Type        : Video Capture
	Pixel Format: 'UYVY'
	Name        : UYVY 4:2:2
		Size: Discrete 1920x1080
		Size: Discrete 1280x10
		Size: Discrete 720x289
		Size: Discrete 720x245
		Size: Discrete 1920x541
		Size: Discrete 640x512
		Size: Discrete 640x480
		Size: Discrete 1280x1024

I’ve snipped of the NV16 and repeated UYVY parts above, but they are there.

Using v4l2-ctl to stream the data and requesting 1280x10 as the resolution results in the following trace:

 kworker/5:3-5169  [005] ....   564.549830: rtcpu_vinotify_event: tstamp:17789075823 tag:CSIMUX_STREAM channel:0xff frame:1 vi_tstamp:17789075143 data:0x00000001
 kworker/5:3-5169  [005] ....   564.549834: rtcpu_vinotify_event: tstamp:17789125819 tag:CSIMUX_STREAM channel:0xff frame:2 vi_tstamp:17789125143 data:0x00000001
 kworker/5:3-5169  [005] ....   564.549838: rtcpu_vinotify_event: tstamp:17789295518 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:17789294586 data:0x00000001
 kworker/5:3-5169  [005] ....   564.549842: rtcpu_vinotify_event: tstamp:17789296408 tag:CHANSEL_FAULT channel:0x00 frame:1 vi_tstamp:17789294590 data:0x00000200
 kworker/5:3-5169  [005] ....   564.549846: rtcpu_vinotify_event: tstamp:17789297349 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:17789294593 data:0x00000000
 kworker/5:3-5169  [005] ....   564.549850: rtcpu_vinotify_event: tstamp:17789298289 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:17789296801 data:0x08000000
 kworker/5:3-5169  [005] ....   564.549854: rtcpu_vinotify_event: tstamp:17789298945 tag:CHANSEL_FAULT_FE channel:0x01 frame:1 vi_tstamp:17789297366 data:0x00000001
 kworker/5:3-5169  [005] ....   564.549859: rtcpu_vinotify_event: tstamp:17789299625 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:17789297369 data:0x00000000
 kworker/5:3-5169  [005] ....   564.605796: rtos_queue_peek_from_isr_failed: tstamp:17791368709 queue:0x0b4b4500
 kworker/5:3-5169  [005] ....   564.777575: rtos_queue_send_from_isr_failed: tstamp:17796242772 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.777579: rtos_queue_send_from_isr_failed: tstamp:17796242951 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   564.777581: rtos_queue_send_from_isr_failed: tstamp:17796243129 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   564.777582: rtos_queue_send_from_isr_failed: tstamp:17796243305 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   564.777583: rtos_queue_send_from_isr_failed: tstamp:17796243479 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   564.777584: rtos_queue_send_from_isr_failed: tstamp:17796243654 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   564.777586: rtos_queue_send_from_isr_failed: tstamp:17796243828 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   564.777587: rtos_queue_send_from_isr_failed: tstamp:17796244003 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   564.777589: rtos_queue_send_failed: tstamp:17796244874 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.777590: rtos_queue_send_from_isr_failed: tstamp:17796247649 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.777591: rtos_queue_send_from_isr_failed: tstamp:17796247867 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   564.777592: rtos_queue_send_from_isr_failed: tstamp:17796248043 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   564.777593: rtos_queue_send_from_isr_failed: tstamp:17796248221 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   564.777595: rtos_queue_send_from_isr_failed: tstamp:17796248396 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   564.777596: rtos_queue_send_from_isr_failed: tstamp:17796248571 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   564.777597: rtos_queue_send_from_isr_failed: tstamp:17796248745 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   564.777598: rtos_queue_send_from_isr_failed: tstamp:17796248918 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   564.777600: rtos_queue_send_failed: tstamp:17796249633 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.777601: rtos_queue_peek_from_isr_failed: tstamp:17796368270 queue:0x0b4b4500
 kworker/5:3-5169  [005] ....   564.829672: rtos_queue_send_from_isr_failed: tstamp:17797694788 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.829693: rtos_queue_send_from_isr_failed: tstamp:17797694964 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   564.829699: rtos_queue_send_from_isr_failed: tstamp:17797695141 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   564.829705: rtos_queue_send_from_isr_failed: tstamp:17797695316 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   564.829714: rtos_queue_send_from_isr_failed: tstamp:17797695488 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   564.829718: rtos_queue_send_from_isr_failed: tstamp:17797695662 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   564.829725: rtos_queue_send_from_isr_failed: tstamp:17797695836 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   564.829729: rtos_queue_send_from_isr_failed: tstamp:17797696015 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   564.829742: rtos_queue_send_failed: tstamp:17797696729 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.829748: rtos_queue_send_from_isr_failed: tstamp:17797703240 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.829754: rtos_queue_send_from_isr_failed: tstamp:17797703413 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   564.829761: rtos_queue_send_from_isr_failed: tstamp:17797703587 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   564.829767: rtos_queue_send_from_isr_failed: tstamp:17797703762 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   564.829773: rtos_queue_send_from_isr_failed: tstamp:17797703935 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   564.829779: rtos_queue_send_from_isr_failed: tstamp:17797704107 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   564.829785: rtos_queue_send_from_isr_failed: tstamp:17797704281 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   564.829791: rtos_queue_send_from_isr_failed: tstamp:17797704453 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   564.829797: rtos_queue_send_failed: tstamp:17797706374 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   564.829810: rtcpu_vinotify_event: tstamp:17797712354 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:17797711950 data:0x00000001
 kworker/5:3-5169  [005] ....   564.829816: rtcpu_vinotify_event: tstamp:17797811214 tag:CSIMUX_STREAM channel:0xff frame:1 vi_tstamp:17797810560 data:0x00000001
 kworker/5:3-5169  [005] ....   564.829820: rtcpu_vinotify_event: tstamp:17797844314 tag:CSIMUX_STREAM channel:0xff frame:2 vi_tstamp:17797843893 data:0x00000001
 kworker/5:3-5169  [005] ....   564.941691: rtos_queue_peek_from_isr_failed: tstamp:17801368699 queue:0x0b4b4500
 kworker/5:3-5169  [005] ....   565.054248: rtos_queue_send_from_isr_failed: tstamp:17804585442 queue:0x0b4a7258

The trace repeats every 16.6ms (60hz is still my video frame rate) but those last few lines repeat more often, continuing until the next frame is due. Here is a fragment containg two:

 kworker/5:3-5169  [005] ....   564.829810: rtcpu_vinotify_event: tstamp:17797712354 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:17797711950 data:0x00000001
 kworker/5:3-5169  [005] ....   564.829816: rtcpu_vinotify_event: tstamp:17797811214 tag:CSIMUX_STREAM channel:0xff frame:1 vi_tstamp:17797810560 data:0x00000001
 kworker/5:3-5169  [005] ....   564.829820: rtcpu_vinotify_event: tstamp:17797844314 tag:CSIMUX_STREAM channel:0xff frame:2 vi_tstamp:17797843893 data:0x00000001
 kworker/5:3-5169  [005] ....   564.941691: rtos_queue_peek_from_isr_failed: tstamp:17801368699 queue:0x0b4b4500
 kworker/5:3-5169  [005] ....   565.054248: rtos_queue_send_from_isr_failed: tstamp:17804585442 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.054252: rtos_queue_send_from_isr_failed: tstamp:17804585728 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   565.054253: rtos_queue_send_from_isr_failed: tstamp:17804585998 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   565.054255: rtos_queue_send_from_isr_failed: tstamp:17804586267 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   565.054256: rtos_queue_send_from_isr_failed: tstamp:17804586533 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   565.054257: rtos_queue_send_from_isr_failed: tstamp:17804586797 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   565.054259: rtos_queue_send_from_isr_failed: tstamp:17804587063 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   565.054260: rtos_queue_send_from_isr_failed: tstamp:17804587329 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   565.054263: rtos_queue_send_failed: tstamp:17804588554 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.054264: rtos_queue_send_from_isr_failed: tstamp:17804594210 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.054266: rtos_queue_send_from_isr_failed: tstamp:17804594477 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   565.054267: rtos_queue_send_from_isr_failed: tstamp:17804594744 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   565.054269: rtos_queue_send_from_isr_failed: tstamp:17804595013 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   565.054270: rtos_queue_send_from_isr_failed: tstamp:17804595277 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   565.054271: rtos_queue_send_from_isr_failed: tstamp:17804595543 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   565.054273: rtos_queue_send_from_isr_failed: tstamp:17804595810 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   565.054274: rtos_queue_send_from_isr_failed: tstamp:17804596077 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   565.054276: rtos_queue_send_failed: tstamp:17804597169 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.109740: rtos_queue_send_from_isr_failed: tstamp:17805958689 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.109757: rtos_queue_send_from_isr_failed: tstamp:17805958862 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   565.109772: rtos_queue_send_from_isr_failed: tstamp:17805959036 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   565.109780: rtos_queue_send_from_isr_failed: tstamp:17805959210 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   565.109789: rtos_queue_send_from_isr_failed: tstamp:17805959382 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   565.109795: rtos_queue_send_from_isr_failed: tstamp:17805959555 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   565.109801: rtos_queue_send_from_isr_failed: tstamp:17805959727 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   565.109810: rtos_queue_send_from_isr_failed: tstamp:17805959900 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   565.109817: rtos_queue_send_failed: tstamp:17805960600 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.109825: rtos_queue_send_from_isr_failed: tstamp:17805965507 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.109831: rtos_queue_send_from_isr_failed: tstamp:17805965775 queue:0x0b4aad68
 kworker/5:3-5169  [005] ....   565.109838: rtos_queue_send_from_isr_failed: tstamp:17805966042 queue:0x0b4ac998
 kworker/5:3-5169  [005] ....   565.109844: rtos_queue_send_from_isr_failed: tstamp:17805966312 queue:0x0b4ae518
 kworker/5:3-5169  [005] ....   565.109850: rtos_queue_send_from_isr_failed: tstamp:17805966637 queue:0x0b4af2d8
 kworker/5:3-5169  [005] ....   565.109859: rtos_queue_send_from_isr_failed: tstamp:17805966906 queue:0x0b4b0098
 kworker/5:3-5169  [005] ....   565.109866: rtos_queue_send_from_isr_failed: tstamp:17805967214 queue:0x0b4b0e58
 kworker/5:3-5169  [005] ....   565.109872: rtos_queue_send_from_isr_failed: tstamp:17805967483 queue:0x0b4b1c18
 kworker/5:3-5169  [005] ....   565.109879: rtos_queue_send_failed: tstamp:17805970969 queue:0x0b4a7258
 kworker/5:3-5169  [005] ....   565.109891: rtcpu_vinotify_event: tstamp:17805973415 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:17805970282 data:0x00000001
 kworker/5:3-5169  [005] ....   565.109895: rtcpu_vinotify_event: tstamp:17806144576 tag:CSIMUX_STREAM channel:0xff frame:1 vi_tstamp:17806143895 data:0x00000001
 kworker/5:3-5169  [005] ....   565.109899: rtcpu_vinotify_event: tstamp:17806177880 tag:CSIMUX_STREAM channel:0xff frame:2 vi_tstamp:17806177226 data:0x00000001

Note that the short frame has gone.

v4l2-ctl doesn’t capture any frames.

Now it show PIXEL_SHORT_LINE, you can use binary search to find the real size.

tag:CHANSEL_FAULT

I had line_length set to 2200. It should be 1650 for 720p60 over SDI. Fixed that and short lines appear to be gone.

I’m left with short frames. I have active_h set to 720, and I don’t think there is a equivalent to line_length for vertical lines including blanking, and I assume FS and FE packets are used to frame the video height.

After filtering with grep, VI notifications are:

 kworker/5:1-7430  [005] ....  2933.792092: rtcpu_vinotify_event: tstamp:91827613176 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:91827612426 data:0x00000001
 kworker/5:1-7430  [005] ....  2933.792098: rtcpu_vinotify_event: tstamp:91827613820 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:91827612442 data:0x00000000
 kworker/5:1-7430  [005] ....  2933.792100: rtcpu_vinotify_event: tstamp:91827618378 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:91827617828 data:0x08000000
 kworker/5:1-7430  [005] ....  2933.792102: rtcpu_vinotify_event: tstamp:91828133927 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91828133180 data:0x000000a0
 kworker/5:1-7430  [005] ....  2933.792104: rtcpu_vinotify_event: tstamp:91828134164 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91828133180 data:0x00000001
 kworker/5:1-7430  [005] ....  2933.792106: rtcpu_vinotify_event: tstamp:91828134338 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91828133184 data:0x00000000
 kworker/5:1-7430  [005] ....  2934.016348: rtcpu_vinotify_event: tstamp:91834904621 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:91834904091 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.016351: rtcpu_vinotify_event: tstamp:91834904834 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:91834904105 data:0x00000000
 kworker/5:1-7430  [005] ....  2934.016354: rtcpu_vinotify_event: tstamp:91834907658 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:91834907273 data:0x08000000
 kworker/5:1-7430  [005] ....  2934.016356: rtcpu_vinotify_event: tstamp:91835425791 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91835424843 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.016359: rtcpu_vinotify_event: tstamp:91835426369 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91835424843 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.016363: rtcpu_vinotify_event: tstamp:91835426862 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91835424846 data:0x00000000
 kworker/5:1-7430  [005] ....  2934.296184: rtcpu_vinotify_event: tstamp:91843238362 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91843237412 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.296192: rtcpu_vinotify_event: tstamp:91843238894 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91843237412 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.296195: rtcpu_vinotify_event: tstamp:91843239383 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91843237416 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.296199: rtcpu_vinotify_event: tstamp:91844279706 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91844279077 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.352170: rtcpu_vinotify_event: tstamp:91845321505 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91845320741 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.408175: rtcpu_vinotify_event: tstamp:91846363096 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91846362409 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.408197: rtcpu_vinotify_event: tstamp:91847404691 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91847404074 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.464107: rtcpu_vinotify_event: tstamp:91848446353 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91848445742 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.464320: rtcpu_vinotify_event: tstamp:91849487967 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:91849487416 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.464325: rtcpu_vinotify_event: tstamp:91849488236 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:91849487432 data:0x00000000
 kworker/5:1-7430  [005] ....  2934.464330: rtcpu_vinotify_event: tstamp:91849492773 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:91849492369 data:0x08000000
 kworker/5:1-7430  [005] ....  2934.520146: rtcpu_vinotify_event: tstamp:91850009101 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91850008170 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.520153: rtcpu_vinotify_event: tstamp:91850009681 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91850008170 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.520157: rtcpu_vinotify_event: tstamp:91850010171 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91850008173 data:0x00000000
 kworker/5:1-7430  [005] ....  2934.744186: rtcpu_vinotify_event: tstamp:91857821684 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91857820737 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.744189: rtcpu_vinotify_event: tstamp:91857822215 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91857820737 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.744193: rtcpu_vinotify_event: tstamp:91857822704 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91857820740 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.800147: rtcpu_vinotify_event: tstamp:91858863018 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91858862402 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.800154: rtcpu_vinotify_event: tstamp:91859904764 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91859904070 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.856130: rtcpu_vinotify_event: tstamp:91860946345 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91860945735 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.856145: rtcpu_vinotify_event: tstamp:91861988013 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91861987403 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.912081: rtcpu_vinotify_event: tstamp:91863029677 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91863029068 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.968119: rtcpu_vinotify_event: tstamp:91865113210 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91865112400 data:0x000000a0
 kworker/5:1-7430  [005] ....  2934.968126: rtcpu_vinotify_event: tstamp:91865113457 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91865112401 data:0x00000001
 kworker/5:1-7430  [005] ....  2934.968128: rtcpu_vinotify_event: tstamp:91865113665 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91865112404 data:0x00000001
 kworker/5:1-7430  [005] ....  2935.024168: rtcpu_vinotify_event: tstamp:91866154680 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91866154066 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.024187: rtcpu_vinotify_event: tstamp:91867196344 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91867195733 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.080171: rtcpu_vinotify_event: tstamp:91868238010 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91868237399 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.138005: rtcpu_vinotify_event: tstamp:91869279672 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91869279064 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.138009: rtcpu_vinotify_event: tstamp:91870321340 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91870320731 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.420250: rtcpu_vinotify_event: tstamp:91878133793 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:91878133236 data:0x00000001
 kworker/5:1-7430  [005] ....  2935.420253: rtcpu_vinotify_event: tstamp:91878134094 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91878133251 data:0x00000000
 kworker/5:1-7430  [005] ....  2935.420256: rtcpu_vinotify_event: tstamp:91878136874 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:91878136466 data:0x08000000
 kworker/5:1-7430  [005] ....  2935.420258: rtcpu_vinotify_event: tstamp:91878654811 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91878653991 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.420261: rtcpu_vinotify_event: tstamp:91878655189 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91878653991 data:0x00000001
 kworker/5:1-7430  [005] ....  2935.420263: rtcpu_vinotify_event: tstamp:91878655494 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91878653994 data:0x00000000
 kworker/5:1-7430  [005] ....  2935.644361: rtcpu_vinotify_event: tstamp:91885425646 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:91885424898 data:0x00000001
 kworker/5:1-7430  [005] ....  2935.644364: rtcpu_vinotify_event: tstamp:91885426419 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91885424915 data:0x00000000
 kworker/5:1-7430  [005] ....  2935.644370: rtcpu_vinotify_event: tstamp:91885433042 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:91885432489 data:0x08000000
 kworker/5:1-7430  [005] ....  2935.644375: rtcpu_vinotify_event: tstamp:91885946594 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91885945654 data:0x000000a0
 kworker/5:1-7430  [005] ....  2935.644379: rtcpu_vinotify_event: tstamp:91885947183 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91885945654 data:0x00000001
 kworker/5:1-7430  [005] ....  2935.644385: rtcpu_vinotify_event: tstamp:91885947678 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91885945658 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.092366: rtcpu_vinotify_event: tstamp:91900008803 tag:CHANSEL_FAULT channel:0x00 frame:2 vi_tstamp:91900008223 data:0x00000201
 kworker/5:1-7430  [005] ....  2936.092370: rtcpu_vinotify_event: tstamp:91900009000 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91900008226 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.148184: rtcpu_vinotify_event: tstamp:91901050826 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91901049883 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.148193: rtcpu_vinotify_event: tstamp:91901051343 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91901049883 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.148196: rtcpu_vinotify_event: tstamp:91901051836 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91901049886 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.148210: rtcpu_vinotify_event: tstamp:91902092137 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91902091550 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.204162: rtcpu_vinotify_event: tstamp:91903133878 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91903133216 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.260257: rtcpu_vinotify_event: tstamp:91904175469 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91904174882 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.260274: rtcpu_vinotify_event: tstamp:91905217212 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91905216548 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.316175: rtcpu_vinotify_event: tstamp:91906258798 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91906258215 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.316397: rtcpu_vinotify_event: tstamp:91907300710 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:91907299888 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.316403: rtcpu_vinotify_event: tstamp:91907301436 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91907299903 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.316408: rtcpu_vinotify_event: tstamp:91907307298 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:91907306751 data:0x08000000
 kworker/5:1-7430  [005] ....  2936.372150: rtcpu_vinotify_event: tstamp:91907821598 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91907820644 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.372166: rtcpu_vinotify_event: tstamp:91907822179 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91907820644 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.372170: rtcpu_vinotify_event: tstamp:91907822809 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91907820647 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.540177: rtcpu_vinotify_event: tstamp:91914592061 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:91914591551 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.540179: rtcpu_vinotify_event: tstamp:91914592220 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91914591566 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.540180: rtcpu_vinotify_event: tstamp:91914594089 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:91914593722 data:0x08000000
 kworker/5:1-7430  [005] ....  2936.596170: rtcpu_vinotify_event: tstamp:91915113040 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91915112306 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.596188: rtcpu_vinotify_event: tstamp:91915113281 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91915112306 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.596192: rtcpu_vinotify_event: tstamp:91915113459 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91915112309 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.820166: rtcpu_vinotify_event: tstamp:91921883959 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:91921883215 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.820168: rtcpu_vinotify_event: tstamp:91921884610 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91921883229 data:0x00000000
 kworker/5:1-7430  [005] ....  2936.820170: rtcpu_vinotify_event: tstamp:91921890591 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:91921890038 data:0x08000000
 kworker/5:1-7430  [005] ....  2936.820172: rtcpu_vinotify_event: tstamp:91922404793 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91922403970 data:0x000000a0
 kworker/5:1-7430  [005] ....  2936.820174: rtcpu_vinotify_event: tstamp:91922405171 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91922403971 data:0x00000001
 kworker/5:1-7430  [005] ....  2936.820177: rtcpu_vinotify_event: tstamp:91922405474 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91922403974 data:0x00000000
 kworker/5:1-7430  [005] ....  2937.044391: rtcpu_vinotify_event: tstamp:91929175459 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:91929174878 data:0x00000001
 kworker/5:1-7430  [005] ....  2937.044395: rtcpu_vinotify_event: tstamp:91929175713 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:91929174892 data:0x00000000
 kworker/5:1-7430  [005] ....  2937.044398: rtcpu_vinotify_event: tstamp:91929178016 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:91929177610 data:0x08000000
 kworker/5:1-7430  [005] ....  2937.044401: rtcpu_vinotify_event: tstamp:91929696579 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:91929695632 data:0x000000a0
 kworker/5:1-7430  [005] ....  2937.044405: rtcpu_vinotify_event: tstamp:91929697160 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:91929695633 data:0x00000001
 kworker/5:1-7430  [005] ....  2937.044408: rtcpu_vinotify_event: tstamp:91929697654 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:91929695636 data:0x00000000
 kworker/5:1-7430  [005] ....  2938.444177: rtcpu_vinotify_event: tstamp:91973446509 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91973445682 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.444185: rtcpu_vinotify_event: tstamp:91973446894 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91973445682 data:0x00000001
 kworker/5:1-7430  [005] ....  2938.444188: rtcpu_vinotify_event: tstamp:91973447197 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91973445685 data:0x00000001
 kworker/5:1-7430  [005] ....  2938.500168: rtcpu_vinotify_event: tstamp:91974488061 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91974487348 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.500176: rtcpu_vinotify_event: tstamp:91975529629 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91975529015 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.556159: rtcpu_vinotify_event: tstamp:91976571296 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91976570679 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.556176: rtcpu_vinotify_event: tstamp:91977612952 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91977612346 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.612138: rtcpu_vinotify_event: tstamp:91978654707 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91978654013 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.668270: rtcpu_vinotify_event: tstamp:91980738299 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91980737345 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.668273: rtcpu_vinotify_event: tstamp:91980738813 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91980737345 data:0x00000001
 kworker/5:1-7430  [005] ....  2938.668276: rtcpu_vinotify_event: tstamp:91980739309 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91980737349 data:0x00000001
 kworker/5:1-7430  [005] ....  2938.724163: rtcpu_vinotify_event: tstamp:91981779621 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91981779010 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.724181: rtcpu_vinotify_event: tstamp:91982821319 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91982820678 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.780155: rtcpu_vinotify_event: tstamp:91983862951 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91983862342 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.840067: rtcpu_vinotify_event: tstamp:91984904630 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91984904007 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.840072: rtcpu_vinotify_event: tstamp:91985946283 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91985945675 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.892331: rtcpu_vinotify_event: tstamp:91986987907 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:91986987350 data:0x00000001
 kworker/5:1-7430  [005] ....  2938.892334: rtcpu_vinotify_event: tstamp:91986988166 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:91986987365 data:0x00000000
 kworker/5:1-7430  [005] ....  2938.892338: rtcpu_vinotify_event: tstamp:91986991277 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:91986990862 data:0x08000000
 kworker/5:1-7430  [005] ....  2938.892343: rtcpu_vinotify_event: tstamp:91987509053 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91987508104 data:0x000000a0
 kworker/5:1-7430  [005] ....  2938.892347: rtcpu_vinotify_event: tstamp:91987509629 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91987508104 data:0x00000001
 kworker/5:1-7430  [005] ....  2938.892352: rtcpu_vinotify_event: tstamp:91987510124 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91987508108 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.116422: rtcpu_vinotify_event: tstamp:91994279569 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:91994279012 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.116425: rtcpu_vinotify_event: tstamp:91994279834 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:91994279028 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.116428: rtcpu_vinotify_event: tstamp:91994283071 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:91994282666 data:0x08000000
 kworker/5:1-7430  [005] ....  2939.116432: rtcpu_vinotify_event: tstamp:91994800793 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:91994799767 data:0x000000a0
 kworker/5:1-7430  [005] ....  2939.116435: rtcpu_vinotify_event: tstamp:91994801452 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:91994799768 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.116438: rtcpu_vinotify_event: tstamp:91994801949 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:91994799771 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.340236: rtcpu_vinotify_event: tstamp:92001571227 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:92001570676 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.340238: rtcpu_vinotify_event: tstamp:92001571494 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:92001570691 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.340239: rtcpu_vinotify_event: tstamp:92001574404 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:92001573987 data:0x08000000
 kworker/5:1-7430  [005] ....  2939.340244: rtcpu_vinotify_event: tstamp:92002092236 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92002091429 data:0x000000a0
 kworker/5:1-7430  [005] ....  2939.340246: rtcpu_vinotify_event: tstamp:92002092626 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92002091430 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.340248: rtcpu_vinotify_event: tstamp:92002092943 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92002091433 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.564406: rtcpu_vinotify_event: tstamp:92008862896 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:92008862338 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.564410: rtcpu_vinotify_event: tstamp:92008863155 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:92008862355 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.564413: rtcpu_vinotify_event: tstamp:92008865682 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:92008865278 data:0x08000000
 kworker/5:1-7430  [005] ....  2939.620177: rtcpu_vinotify_event: tstamp:92009384040 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92009383093 data:0x000000a0
 kworker/5:1-7430  [005] ....  2939.620184: rtcpu_vinotify_event: tstamp:92009384693 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92009383093 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.620188: rtcpu_vinotify_event: tstamp:92009385196 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92009383096 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.844178: rtcpu_vinotify_event: tstamp:92016154555 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:92016154002 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.844187: rtcpu_vinotify_event: tstamp:92016154818 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:92016154017 data:0x00000000
 kworker/5:1-7430  [005] ....  2939.844190: rtcpu_vinotify_event: tstamp:92016158659 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:92016158256 data:0x08000000
 kworker/5:1-7430  [005] ....  2939.844194: rtcpu_vinotify_event: tstamp:92016675702 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92016674755 data:0x000000a0
 kworker/5:1-7430  [005] ....  2939.844197: rtcpu_vinotify_event: tstamp:92016676272 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92016674756 data:0x00000001
 kworker/5:1-7430  [005] ....  2939.844202: rtcpu_vinotify_event: tstamp:92016676762 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92016674759 data:0x00000000
 kworker/5:1-7430  [005] ....  2940.068197: rtcpu_vinotify_event: tstamp:92024488087 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92024487323 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.068199: rtcpu_vinotify_event: tstamp:92024488321 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92024487323 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.068201: rtcpu_vinotify_event: tstamp:92024488528 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92024487326 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.124169: rtcpu_vinotify_event: tstamp:92025529606 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92025528989 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.124176: rtcpu_vinotify_event: tstamp:92026571282 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92026570654 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.180230: rtcpu_vinotify_event: tstamp:92027612933 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92027612322 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.238292: rtcpu_vinotify_event: tstamp:92028654617 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92028653987 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.238297: rtcpu_vinotify_event: tstamp:92029696263 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92029695654 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.292264: rtcpu_vinotify_event: tstamp:92030737856 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:92030737327 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.292267: rtcpu_vinotify_event: tstamp:92030738085 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:92030737343 data:0x00000000
 kworker/5:1-7430  [005] ....  2940.292269: rtcpu_vinotify_event: tstamp:92030740161 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:92030739776 data:0x08000000
 kworker/5:1-7430  [005] ....  2940.292271: rtcpu_vinotify_event: tstamp:92031258906 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92031258083 data:0x000000a0
 kworker/5:1-7430  [005] .n..  2940.292273: rtcpu_vinotify_event: tstamp:92031259288 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92031258083 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.292377: rtcpu_vinotify_event: tstamp:92031259595 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92031258086 data:0x00000000
 kworker/5:1-7430  [005] ....  2940.516358: rtcpu_vinotify_event: tstamp:92038029521 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:92038028990 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.516361: rtcpu_vinotify_event: tstamp:92038029731 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:92038029006 data:0x00000000
 kworker/5:1-7430  [005] ....  2940.516365: rtcpu_vinotify_event: tstamp:92038032000 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:92038031616 data:0x08000000
 kworker/5:1-7430  [005] ....  2940.516369: rtcpu_vinotify_event: tstamp:92038550694 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92038549745 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.516373: rtcpu_vinotify_event: tstamp:92038551280 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92038549746 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.516376: rtcpu_vinotify_event: tstamp:92038551786 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92038549749 data:0x00000000
 kworker/5:1-7430  [005] ....  2940.796155: rtcpu_vinotify_event: tstamp:92046363138 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92046362311 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.796164: rtcpu_vinotify_event: tstamp:92046363456 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92046362311 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.796167: rtcpu_vinotify_event: tstamp:92046363759 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92046362315 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.796180: rtcpu_vinotify_event: tstamp:92047404591 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92047403978 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.852181: rtcpu_vinotify_event: tstamp:92048446255 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92048445644 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.908178: rtcpu_vinotify_event: tstamp:92049487923 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92049487311 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.908190: rtcpu_vinotify_event: tstamp:92050529587 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92050528977 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.964213: rtcpu_vinotify_event: tstamp:92051571249 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92051570644 data:0x000000a0
 kworker/5:1-7430  [005] ....  2940.964426: rtcpu_vinotify_event: tstamp:92052612865 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:92052612317 data:0x00000001
 kworker/5:1-7430  [005] ....  2940.964432: rtcpu_vinotify_event: tstamp:92052613131 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:92052612331 data:0x00000000
 kworker/5:1-7430  [005] ....  2940.964435: rtcpu_vinotify_event: tstamp:92052615785 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:92052615381 data:0x08000000
 kworker/5:1-7430  [005] ....  2941.020184: rtcpu_vinotify_event: tstamp:92053134075 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92053133070 data:0x000000a0
 kworker/5:1-7430  [005] ....  2941.020194: rtcpu_vinotify_event: tstamp:92053134729 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92053133071 data:0x00000001
 kworker/5:1-7430  [005] ....  2941.020198: rtcpu_vinotify_event: tstamp:92053135228 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92053133074 data:0x00000000
 kworker/5:1-7430  [005] ....  2941.244232: rtcpu_vinotify_event: tstamp:92060946591 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92060945638 data:0x000000a0
 kworker/5:1-7430  [005] ....  2941.244250: rtcpu_vinotify_event: tstamp:92060947261 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:92060945638 data:0x00000001
 kworker/5:1-7430  [005] ....  2941.244254: rtcpu_vinotify_event: tstamp:92060947746 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:92060945641 data:0x00000001
 kworker/5:1-7430  [005] ....  2941.300213: rtcpu_vinotify_event: tstamp:92061987919 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92061987304 data:0x000000a0
 kworker/5:1-7430  [005] ....  2941.300217: rtcpu_vinotify_event: tstamp:92063029584 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92063028971 data:0x000000a0
 kworker/5:1-7430  [005] ....  2941.356186: rtcpu_vinotify_event: tstamp:92064071327 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92064070637 data:0x000000a0
 kworker/5:1-7430  [005] ....  2941.356195: rtcpu_vinotify_event: tstamp:92065112912 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92065112302 data:0x000000a0
 kworker/5:1-7430  [005] ....  2941.412149: rtcpu_vinotify_event: tstamp:92066154579 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:92066153968 data:0x000000a0

Does the driver try to resync to the ongoing video stream, or does it attempt a sensor reset or stop/start during retries?

The short frame doesn’t matter with the frame length it’s about output line. You can reduce the line from 720 to narrow down it.

I binary chopped down from 720 to 22 lines. At 45 lines I was still getting short frames. At 22 lines, something goes wrong and the driver defaults back to it’s 1920/1080 default resolution.

This is a shame as SHORT_FRAME timestamp is about 521000us after PXL_SOF, which is in the region of 22 lines.

Please boost the nvcsi/vi clocks to verify.

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
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

Tried clock boost as you suggested. It doesn’t appear to change anything. SOF to SHORT_FRAME is still ~521000ns and the other messages remain the same:

 kworker/4:2-8102  [004] ....  8030.286814: rtcpu_vinotify_event: tstamp:251093643117 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:251093642586 data:0x00000001
 kworker/4:2-8102  [004] ....  8030.286818: rtcpu_vinotify_event: tstamp:251093643352 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:251093642596 data:0x00000000
 kworker/4:2-8102  [004] ....  8030.286820: rtcpu_vinotify_event: tstamp:251093647448 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:251093647073 data:0x08000000
 kworker/4:2-8102  [004] ....  8030.286821: rtcpu_vinotify_event: tstamp:251094164080 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:251094163342 data:0x000000a0
 kworker/4:2-8102  [004] ....  8030.286823: rtcpu_vinotify_event: tstamp:251094164356 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:251094163342 data:0x00000001
 kworker/4:2-8102  [004] ....  8030.286824: rtcpu_vinotify_event: tstamp:251094164581 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:251094163343 data:0x00000000
 kworker/4:2-8102  [004] ....  8030.342922: rtos_queue_peek_from_isr_failed: tstamp:251094944170 queue:0x0b4b4500

The FPGA CSI output clock is always on and the FPGA only sends FS/FE, LS/LE and Active Data (no blanking packets). I mention this as our line_length, which was set to 2200, is now 1650 (1280 + blanking on SDI video). There are clock cycles but no data packets for blanking. Is 1650 the correct setting if there is no blanking data? In Jetpack 3.2.1, 720p60 worked, despite having the line_length wrong, and ingesting 720p50 also worked with 2200 despite having a expected line length (active+blanking) of 1980.

I’m not seeing any line length error logs now and don’t think these small discrepancies are enough to explain the SHORT_FRAME “timeout” I’m seeing in terms of lines received. But maybe we are sliding out of sync line-by-line and finding something that looks like an FE?

Get the camera firmware from below link to collect the trace to confirm if any FS/FE didn’t pair.

With the different firmware, there seem to be three variants of trace over the retries:

 kworker/3:1-1151  [003] ....   220.076256: rtcpu_vinotify_event: tstamp:7024453233 tag:FS channel:0x00 frame:2 vi_tstamp:7024452468 data:0x00000010
 kworker/3:1-1151  [003] ....   220.076259: rtcpu_vinotify_event: tstamp:7024453455 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:7024452546 data:0x00000001
 kworker/3:1-1151  [003] ....   220.076262: rtcpu_vinotify_event: tstamp:7024453710 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:7024452563 data:0x00000000
 kworker/3:1-1151  [003] ....   220.076266: rtcpu_vinotify_event: tstamp:7024456690 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:7024456287 data:0x08000000
 kworker/3:1-1151  [003] ....   220.076269: rtcpu_vinotify_event: tstamp:7024974380 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:7024973302 data:0x000000a0
 kworker/3:1-1151  [003] ....   220.076273: rtcpu_vinotify_event: tstamp:7024974955 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:7024973302 data:0x00000001
 kworker/3:1-1151  [003] ....   220.076277: rtcpu_vinotify_event: tstamp:7024975447 tag:FS channel:0x00 frame:1 vi_tstamp:7024973302 data:0x00000010
 kworker/3:1-1151  [003] ....   220.076280: rtcpu_vinotify_event: tstamp:7024975929 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:7024973306 data:0x00000000

I also see:

 kworker/3:1-1151  [003] ....   219.404140: rtcpu_vinotify_event: tstamp:7002393520 tag:FE channel:0x00 frame:1 vi_tstamp:7002391211 data:0x00000020
 kworker/3:1-1151  [003] ....   219.404144: rtcpu_vinotify_event: tstamp:7002578185 tag:FS channel:0x00 frame:2 vi_tstamp:7002577423 data:0x00000010
 kworker/3:1-1151  [003] ....   219.404148: rtcpu_vinotify_event: tstamp:7002578409 tag:CHANSEL_PXL_SOF channel:0x00 frame:2 vi_tstamp:7002577502 data:0x00000001
 kworker/3:1-1151  [003] ....   219.404153: rtcpu_vinotify_event: tstamp:7002578663 tag:ATOMP_FS channel:0x00 frame:2 vi_tstamp:7002577516 data:0x00000000
 kworker/3:1-1151  [003] ....   219.404156: rtcpu_vinotify_event: tstamp:7002581246 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:2 vi_tstamp:7002580839 data:0x08000000
 kworker/3:1-1151  [003] ....   219.404160: rtcpu_vinotify_event: tstamp:7003099191 tag:CSIMUX_FRAME channel:0x00 frame:2 vi_tstamp:7003098257 data:0x000000a0
 kworker/3:1-1151  [003] ....   219.404163: rtcpu_vinotify_event: tstamp:7003099570 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:2 vi_tstamp:7003098257 data:0x00000001
 kworker/3:1-1151  [003] ....   219.404168: rtcpu_vinotify_event: tstamp:7003099875 tag:FS channel:0x00 frame:1 vi_tstamp:7003098257 data:0x00000010
 kworker/3:1-1151  [003] ....   219.404172: rtcpu_vinotify_event: tstamp:7003100174 tag:ATOMP_FE channel:0x00 frame:2 vi_tstamp:7003098260 data:0x00000000

And the last interesting case:

kworker/3:1-1151  [003] ....   217.768355: rtcpu_vinotify_event: tstamp:6951552293 tag:FE channel:0x00 frame:1 vi_tstamp:6951550094 data:0x00000020
 kworker/3:1-1151  [003] ....   217.768358: rtcpu_vinotify_event: tstamp:6952057153 tag:FS channel:0x00 frame:1 vi_tstamp:6952056524 data:0x00000010
 kworker/3:1-1151  [003] ....   217.768366: rtos_queue_peek_from_isr_failed: tstamp:6952142826 queue:0x0b4b4500
 kworker/3:1-1151  [003] ....   217.824134: rtcpu_vinotify_event: tstamp:6953099304 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:6953098227 data:0x000000a0
 kworker/3:1-1151  [003] ....   217.824142: rtcpu_vinotify_event: tstamp:6953099817 tag:CHANSEL_SHORT_FRAME channel:0x01 frame:1 vi_tstamp:6953098227 data:0x00000001
 kworker/3:1-1151  [003] ....   217.824145: rtcpu_vinotify_event: tstamp:6953100310 tag:FS channel:0x00 frame:1 vi_tstamp:6953098227 data:0x00000010
 kworker/3:1-1151  [003] ....   217.824149: rtcpu_vinotify_event: tstamp:6953100791 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:6953098230 data:0x00000001
 kworker/3:1-1151  [003] ....   217.824152: rtcpu_vinotify_event: tstamp:6954140646 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:6954139897 data:0x000000a0
 kworker/3:1-1151  [003] ....   217.824156: rtcpu_vinotify_event: tstamp:6954141296 tag:FS channel:0x00 frame:1 vi_tstamp:6954139897 data:0x00000010
 kworker/3:1-1151  [003] ....   217.880138: rtcpu_vinotify_event: tstamp:6955182296 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:6955181565 data:0x000000a0
 kworker/3:1-1151  [003] ....   217.880144: rtcpu_vinotify_event: tstamp:6955182806 tag:FS channel:0x00 frame:1 vi_tstamp:6955181565 data:0x00000010
 kworker/3:1-1151  [003] ....   217.880148: rtcpu_vinotify_event: tstamp:6956223981 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:6956223233 data:0x000000a0
 kworker/3:1-1151  [003] ....   217.880151: rtcpu_vinotify_event: tstamp:6956224495 tag:FS channel:0x00 frame:1 vi_tstamp:6956223233 data:0x00000010
 kworker/3:1-1151  [003] ....   217.940355: rtos_queue_peek_from_isr_failed: tstamp:6957142949 queue:0x0b4b4500
 kworker/3:1-1151  [003] ....   217.940362: rtcpu_vinotify_event: tstamp:6957265637 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:6957264903 data:0x000000a0
 kworker/3:1-1151  [003] ....   217.940363: rtcpu_vinotify_event: tstamp:6957266148 tag:FS channel:0x00 frame:1 vi_tstamp:6957264903 data:0x00000010
 kworker/3:1-1151  [003] ....   217.940366: rtcpu_vinotify_event: tstamp:6958307189 tag:CSIMUX_FRAME channel:0x00 frame:1 vi_tstamp:6958306571 data:0x000000a0
 kworker/3:1-1151  [003] ....   217.940367: rtcpu_vinotify_event: tstamp:6958307503 tag:FS channel:0x00 frame:1 vi_tstamp:6958306571 data:0x00000010