Good afternoon, Nvidia! We have an issue with the SMMU in the VI driver. Sometimes it fails and we are losing a frame that we must not lose. Sometimes before this there is a crush of the SMMU in the dmesg, sometimes not but we are losing a frame with the exact same symptom.
In the attached log we lost 5 frames.
Before the drop of 2 out of 5 frames, a fall in SMMU was noticed in the log, which is very suspicious. SMMU crashes immediately when the frame starts streaming into the buffer, after which no frame appears in the buffer due to a timeout. The remaining 3 frames disappeared for the same reason, but smmu was not found in the error log, perhaps this is some kind of marker and the reasons are related.
And so the situation is like this - our driver always captures and sends out 1 frame more than requested. It is quite possible that 1 is pushing, but this is strange, because both are honestly captured and sent upstairs, judging by the log. Sometimes the capture function goes into a slip and wakes up when the capture buffer becomes non-zero, but it remains zero forever and we freeze, after which the higher-level software kills V4L2, which kills VI and the whole thing crashing with loss of frame. Moreover, when the system returned to normal, it captures the 2nd frame normally, but, apparently, it no longer gets upstairs to the user space - most likely it needs a pushing 2nd frame.
QUEUED_BUFFERS=1 so we capture every frame without buffering it. It is strange that for 1 frame we needs 2 capture but the user space sees only 1. Before I added prints for every function in the path of the frame I didn’t even realize it. 2 times more frames - 2 times it more dangerous to lose a frame, I think.
What could you tell me about this situation? We have to fix this because if it is impossible to fix this situation I afraid we even have to find another hardware solution. We really strongly have to capture all frames and must lose no one.
dmesg.log (1.4 MB)
For some reason before we lost a frame in tegra_channel_kthread_capture_start we receive kthread_should_stop before we capture a frame. Here is new log with more debug outputs. This time we lost 5 frames of 60 that is unacceptably lot.
dmesg.log (913.7 KB)
I would suspect the sensor unstable signal cause the vi capture failed.
Enable the debug message in csi2_fops.c/vi2_fops.c to check.
How could I enable this?
By below command.
echo file csi2_fops.c +p > /sys/kernel/debug/dynamic_debug/control
echo file vi2_fops.c +p > /sys/kernel/debug/dynamic_debug/control
Thank you! I will try
I don’t have such a option in debug, maybe I should enable some more configs in defconfig to provide such a functionality?
[lecor@lecor: ~]$ sudo ls /sys/kernel/debug/
57000000.gpu clk gpio letim_c nvdec pm_genpd sdhci-tegra.2 tegra-pmc-io-pads tegra_dvfs tegra_mipi_cal tegradc.1
57000000.gpu_scaling cpuidle_t210 gpu.0 letim_e nvjpg pm_qos sdhci-tegra.3 tegra-rtc tegra_ec tegra_pinctrl_reg tsec
70006040.serial debug_enabled hid letim_f nvlink pmc-reset sleep_time tegra_bwmgr tegra_emc tegra_sor0 tsecb
70006200.serial dma-vpr ieee80211 mc nvmap powergate soctherm tegra_camera_platform tegra_gpio tegra_sor1 usb
7000d400.spi dma_buf iio memblock opp pwm split_huge_pages tegra_central_actmon tegra_hdmi tegra_throttle vi
7000d600.spi dri isp mmc0 pcie ras suspend_stats tegra_denver tegra_host tegra_vi vic
70019000.iommu extfrag isp.1 mmc1 pg_domains regmap sync tegra_dfll_fcpu tegra_la_ptsa tegra_xhci virtio-ports
bdi fault_around_bytes letim_a msenc pinctrl regulator system_states tegra_dp1 tegra_latency tegradc.0 wakeup_sources
JP4.x default kernel configure should have enable it.
https://www.kernel.org/doc/html/v4.12/admin-guide/dynamic-debug-howto.html
dmesg.txt (513.4 KB)
Here is new log - I added some more prints.
Ours use case is: there are 4 cameras that doing 1 frames simultaneously. We needs 1 frames from all 4 cameras to assemble 1 frame from this 4. Sometimes 1 frame from 1 camera (every time it is different camera - it is random) not capturing by VI driver. And we cannot assemble full frame because of this.
In log you can see that everything is fine in VI driver and on CSI but during the final capturing (the end of the log) VI[0] (0 is chan->id) stucked at:
[ 89.613893] VI[0]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
And it didn’t received the frame. All of ours hardware logs says that everything was fine and all of framegrubbers successfully done the frame but it was not received by driver.
It is random framegrubber everytime and hardware is alright but drivers stucking at this point and I cannot understand what to do and how could I debug this. Where is the frame and why when this function receives kthread_should_stop it appears that frame was already here and status of this frame is 0x6 but to send this upstairs to userspace V4L2 needs 2 frames not 1 and we are loosing this.
I tried to exchange sleep to polling but it hadn’t worked and I returned everything like it was in the begining.
P.S. When we started to use Cuda SDK and provide to VI driver physical addresses the problem with SMMU disappeared but we are still loosing frames.
Newer log:
dmesg.txt (2.0 MB)
I printed everything on CSI.
In the end of the log we lost frame on the channel 1. We can see that CSI started on this channel like it started on every other channels but then other lines going through tegra_csi_error - how I understood it is something like interruption when a frame had been captured but CSI[1] on this (final) iteration was not in this function - it was not interrupted at all. Now I really don’t know what else to print to understand what is wrong. How we could see in the log - streaming on the CSI[1] was successfully started and ended without any errors but we hadn’t received the frame.
How do you think why is this occur?
You can check why involve the tegra_csi_error.
But error function was triggered only channels that returned frames and this function is not triggering by the channel that not returning frame… Reverse than normal situation.
Maybe check the return value from the tegra_csi_error if any different when frame drop.
When frame drop - that channel that dropping the channel never going into this function. When the frame is dropping channel that dropping frame is not going to the tegra_csi_error - it freezes.
[ 243.154559] VI[0]: tegra_channel_buffer_queue: start
[ 243.154564] VI[0]: tegra_channel_buffer_queue: end
[ 243.154930] VI[0]: tegra_channel_buffer_queue: start
[ 243.154933] VI[0]: tegra_channel_buffer_queue: end
[ 243.155295] VI[0]: tegra_channel_buffer_queue: start
[ 243.155298] VI[0]: tegra_channel_buffer_queue: end
[ 243.155661] VI[0]: tegra_channel_buffer_queue: start
[ 243.155664] VI[0]: tegra_channel_buffer_queue: end
[ 243.156124] VI[0]: tegra_channel_buffer_queue: start
[ 243.156126] VI[0]: tegra_channel_buffer_queue: end
[ 243.156529] VI[3]: tegra_channel_buffer_queue: start
[ 243.156532] VI[3]: tegra_channel_buffer_queue: end
[ 243.156536] VI[1]: tegra_channel_buffer_queue: start
[ 243.156540] VI[1]: tegra_channel_buffer_queue: end
[ 243.156771] VI[2]: tegra_channel_buffer_queue: start
[ 243.156775] VI[2]: tegra_channel_buffer_queue: end
[ 243.156825] VI[0]: tegra_channel_buffer_queue: start
[ 243.156827] VI[0]: tegra_channel_buffer_queue: end
[ 243.156830] VI: vi2_power_on: start
[ 243.156838] VI: tegra_vi2_power_on: start
[ 243.156843] VI: tegra_vi2_power_on: end
[ 243.156845] VI: vi2_power_on: end
[ 243.156926] VI: vi2_channel_start_streaming: start
[ 243.157003] VI: vi2_channel_start_streaming: end
[ 243.157103] VI[0]: tegra_channel_kthread_capture_start: start
[ 243.157109] VI[0]: tegra_channel_kthread_capture_start: try to freeze
[ 243.157112] VI[0]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.157115] VI[0]: dequeue_buffer: start
[ 243.157117] VI[0]: add_buffer_to_ring: start
[ 243.157120] VI[0]: add_buffer_to_ring: end
[ 243.157122] VI[0]: dequeue_buffer: end
[ 243.157126] VI[0]: tegra_channel_capture_frame_single_thread: start
[ 243.157129] VI[0]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.157132] VI[0]: tegra_channel_enable_stream: start
[ 243.157237] VI[3]: tegra_channel_buffer_queue: start
[ 243.157242] VI[1]: tegra_channel_buffer_queue: start
[ 243.157244] VI[1]: tegra_channel_buffer_queue: end
[ 243.157245] VI[3]: tegra_channel_buffer_queue: end
[ 243.157731] VI[3]: tegra_channel_buffer_queue: start
[ 243.157733] VI[3]: tegra_channel_buffer_queue: end
[ 243.157734] VI[1]: tegra_channel_buffer_queue: start
[ 243.157735] VI[1]: tegra_channel_buffer_queue: end
[ 243.158242] VI[3]: tegra_channel_buffer_queue: start
[ 243.158244] VI[3]: tegra_channel_buffer_queue: end
[ 243.158245] VI[1]: tegra_channel_buffer_queue: start
[ 243.158246] VI[1]: tegra_channel_buffer_queue: end
[ 243.158689] CSI[0]: csi2_start_streaming: start
[ 243.158697] CSI[0]: csi2_start_streaming: end
[ 243.158755] VI[0]: tegra_channel_enable_stream: end
[ 243.158758] VI[0]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.158761] VI[0]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 243.158786] VI[1]: tegra_channel_buffer_queue: start
[ 243.158787] VI[3]: tegra_channel_buffer_queue: start
[ 243.158788] VI[3]: tegra_channel_buffer_queue: end
[ 243.158789] VI[1]: tegra_channel_buffer_queue: end
[ 243.159199] VI[1]: tegra_channel_buffer_queue: start
[ 243.159199] VI[3]: tegra_channel_buffer_queue: start
[ 243.159201] VI[3]: tegra_channel_buffer_queue: end
[ 243.159201] VI[1]: tegra_channel_buffer_queue: end
[ 243.159203] VI: vi2_power_on: start
[ 243.159205] VI: vi2_power_on: start
[ 243.159211] VI: vi2_power_on: end
[ 243.159212] VI: vi2_power_on: end
[ 243.159303] VI: vi2_channel_start_streaming: start
[ 243.159331] VI: vi2_channel_start_streaming: start
[ 243.159364] VI: vi2_channel_start_streaming: end
[ 243.159368] VI[1]: tegra_channel_kthread_capture_start: start
[ 243.159372] VI[1]: tegra_channel_kthread_capture_start: try to freeze
[ 243.159374] VI[1]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.159376] VI[1]: dequeue_buffer: start
[ 243.159378] VI: vi2_channel_start_streaming: end
[ 243.159379] VI[1]: add_buffer_to_ring: start
[ 243.159381] VI[1]: add_buffer_to_ring: end
[ 243.159383] VI[1]: dequeue_buffer: end
[ 243.159385] VI[1]: tegra_channel_capture_frame_single_thread: start
[ 243.159388] VI[1]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.159391] VI[1]: tegra_channel_enable_stream: start
[ 243.159423] VI[3]: tegra_channel_kthread_capture_start: start
[ 243.159426] VI[3]: tegra_channel_kthread_capture_start: try to freeze
[ 243.159430] VI[3]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.159432] VI[3]: dequeue_buffer: start
[ 243.159434] VI[3]: add_buffer_to_ring: start
[ 243.159436] VI[3]: add_buffer_to_ring: end
[ 243.159438] VI[3]: dequeue_buffer: end
[ 243.159440] VI[3]: tegra_channel_capture_frame_single_thread: start
[ 243.159443] VI[3]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.159445] VI[3]: tegra_channel_enable_stream: start
[ 243.160027] CSI[1]: csi2_start_streaming: start
[ 243.160035] CSI[1]: csi2_start_streaming: end
[ 243.160075] CSI[3]: csi2_start_streaming: start
[ 243.160081] CSI[3]: csi2_start_streaming: end
[ 243.160094] VI[1]: tegra_channel_enable_stream: end
[ 243.160097] VI[1]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.160099] VI[1]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 243.160139] VI[3]: tegra_channel_enable_stream: end
[ 243.160142] VI[3]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.160144] VI[3]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 243.161287] VI[2]: tegra_channel_buffer_queue: start
[ 243.161290] VI[2]: tegra_channel_buffer_queue: end
[ 243.161650] VI[2]: tegra_channel_buffer_queue: start
[ 243.161652] VI[2]: tegra_channel_buffer_queue: end
[ 243.162011] VI[2]: tegra_channel_buffer_queue: start
[ 243.162013] VI[2]: tegra_channel_buffer_queue: end
[ 243.162373] VI[2]: tegra_channel_buffer_queue: start
[ 243.162377] VI[2]: tegra_channel_buffer_queue: end
[ 243.162736] VI[2]: tegra_channel_buffer_queue: start
[ 243.162737] VI[2]: tegra_channel_buffer_queue: end
[ 243.162740] VI: vi2_power_on: start
[ 243.162746] VI: vi2_power_on: end
[ 243.162809] VI: vi2_channel_start_streaming: start
[ 243.162857] VI: vi2_channel_start_streaming: end
[ 243.162860] VI[2]: tegra_channel_kthread_capture_start: start
[ 243.162863] VI[2]: tegra_channel_kthread_capture_start: try to freeze
[ 243.162865] VI[2]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.162867] VI[2]: dequeue_buffer: start
[ 243.162869] VI[2]: add_buffer_to_ring: start
[ 243.162871] VI[2]: add_buffer_to_ring: end
[ 243.162873] VI[2]: dequeue_buffer: end
[ 243.162876] VI[2]: tegra_channel_capture_frame_single_thread: start
[ 243.162879] VI[2]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.162881] VI[2]: tegra_channel_enable_stream: start
[ 243.162941] CSI[2]: csi2_start_streaming: start
[ 243.162947] CSI[2]: csi2_start_streaming: end
[ 243.163003] VI[2]: tegra_channel_enable_stream: end
[ 243.163005] VI[2]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.163007] VI[2]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 243.654806] CSI[0]: tegra_csi_error: start
[ 243.654810] CSI[3]: tegra_csi_error: start
[ 243.654812] CSI[0]: tegra_csi_error: end
[ 243.654814] VI[0]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 243.654816] CSI[3]: tegra_csi_error: end
[ 243.654818] CSI[2]: tegra_csi_error: start
[ 243.654820] VI[0]: tegra_channel_ring_buffer: start
[ 243.654822] VI[0]: update_state_to_buffer: start
[ 243.654823] VI[3]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 243.654824] CSI[2]: tegra_csi_error: end
[ 243.654825] VI[3]: tegra_channel_ring_buffer: start
[ 243.654827] VI[2]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 243.654828] VI[3]: update_state_to_buffer: start
[ 243.654829] VI[0]: update_state_to_buffer: capture good
[ 243.654831] VI[3]: update_state_to_buffer: capture good
[ 243.654832] VI[0]: free_ring_buffers: start
[ 243.654833] VI[2]: tegra_channel_ring_buffer: start
[ 243.654835] VI[0]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 243.654836] VI[2]: update_state_to_buffer: start
[ 243.654837] VI[3]: free_ring_buffers: start
[ 243.654838] VI[2]: update_state_to_buffer: capture good
[ 243.654839] VI[3]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 243.654841] VI[2]: free_ring_buffers: start
[ 243.654844] VI[2]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 243.655394] VI[0]: free_ring_buffers: chan->released_bufs = 1
[ 243.655395] VI[3]: free_ring_buffers: chan->released_bufs = 1
[ 243.655396] VI[3]: tegra_channel_ring_buffer: end
[ 243.655398] VI[0]: tegra_channel_ring_buffer: end
[ 243.655400] VI[3]: tegra_channel_capture_frame_single_thread: end
[ 243.655401] VI[2]: free_ring_buffers: chan->released_bufs = 1
[ 243.655402] VI[0]: tegra_channel_capture_frame_single_thread: end
[ 243.655403] VI[2]: tegra_channel_ring_buffer: end
[ 243.655404] VI[0]: tegra_channel_kthread_capture_start: try to freeze
[ 243.655405] VI[3]: tegra_channel_kthread_capture_start: try to freeze
[ 243.655406] VI[0]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.655408] VI[3]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.655409] VI[2]: tegra_channel_capture_frame_single_thread: end
[ 243.655410] VI[3]: dequeue_buffer: start
[ 243.655411] VI[2]: tegra_channel_kthread_capture_start: try to freeze
[ 243.655412] VI[0]: dequeue_buffer: start
[ 243.655413] VI[2]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 243.655414] VI[0]: add_buffer_to_ring: start
[ 243.655415] VI[3]: add_buffer_to_ring: start
[ 243.655416] VI[0]: add_buffer_to_ring: end
[ 243.655417] VI[3]: add_buffer_to_ring: end
[ 243.655418] VI[2]: dequeue_buffer: start
[ 243.655419] VI[3]: dequeue_buffer: end
[ 243.655419] VI[2]: add_buffer_to_ring: start
[ 243.655420] VI[0]: dequeue_buffer: end
[ 243.655421] VI[2]: add_buffer_to_ring: end
[ 243.655422] VI[0]: tegra_channel_capture_frame_single_thread: start
[ 243.655423] VI[3]: tegra_channel_capture_frame_single_thread: start
[ 243.655425] VI[0]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.655426] VI[2]: dequeue_buffer: end
[ 243.655427] VI[3]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.655428] VI[2]: tegra_channel_capture_frame_single_thread: start
[ 243.655429] VI[3]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.655431] VI[2]: tegra_channel_capture_frame_single_thread: enabling input stream once the VI registers are configured
[ 243.655432] VI[0]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.655433] VI[2]: tegra_channel_capture_frame_single_thread: ensuring all CSI ports are ready with setup to avoid timing issue
[ 243.655434] VI[3]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 243.655435] VI[2]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 243.655437] VI[0]: tegra_channel_capture_frame_single_thread: nvhost_syncpt_wait_timeout_kthread
[ 244.403530] VI: vi2_channel_stop_streaming: start
[ 244.403551] VI[2]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 244.403553] VI[2]: tegra_channel_ring_buffer: start
[ 244.403556] VI[2]: update_state_to_buffer: start
[ 244.403558] VI: vi2_channel_stop_streaming: start
[ 244.403559] VI[2]: update_state_to_buffer: capture good
[ 244.403560] VI[2]: free_ring_buffers: start
[ 244.403563] VI[2]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 244.403576] VI[3]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 244.403579] VI[3]: tegra_channel_ring_buffer: start
[ 244.403582] VI[3]: update_state_to_buffer: start
[ 244.403584] VI[3]: update_state_to_buffer: capture good
[ 244.403586] VI[3]: free_ring_buffers: start
[ 244.403589] VI[3]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 244.403629] VI: vi2_channel_stop_streaming: start
[ 244.403647] VI[0]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 244.403650] VI[0]: tegra_channel_ring_buffer: start
[ 244.403652] VI[0]: update_state_to_buffer: start
[ 244.403654] VI[0]: update_state_to_buffer: capture good
[ 244.403655] VI: vi2_channel_stop_streaming: start
[ 244.403657] VI[0]: free_ring_buffers: start
[ 244.403659] VI[0]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 244.403669] VI[1]: tegra_channel_capture_frame_single_thread: state = 0x6
[ 244.403671] VI[1]: tegra_channel_ring_buffer: start
[ 244.403673] VI[1]: update_state_to_buffer: start
[ 244.403676] VI[1]: update_state_to_buffer: capture good
[ 244.403678] VI[1]: free_ring_buffers: start
[ 244.403680] VI[1]: free_ring_buffers: chan->buffer_state[chan->free_index] = 0x6
[ 244.404215] VI[2]: free_ring_buffers: chan->released_bufs = 2
[ 244.404217] VI[2]: tegra_channel_ring_buffer: end
[ 244.404220] VI[2]: tegra_channel_capture_frame_single_thread: end
[ 244.404223] VI[2]: tegra_channel_kthread_capture_start: try to freeze
[ 244.404225] VI[2]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 244.404227] VI[2]: tegra_channel_kthread_capture_start: kthread_should_stop
[ 244.404229] VI[2]: tegra_channel_kthread_capture_start: end
[ 244.404255] VI[3]: free_ring_buffers: chan->released_bufs = 2
[ 244.404257] VI[3]: tegra_channel_ring_buffer: end
[ 244.404260] VI[2]: free_ring_buffers: start
[ 244.404261] VI[3]: tegra_channel_capture_frame_single_thread: end
[ 244.404263] VI[2]: tegra_channel_queued_buf_done: start
[ 244.404264] VI[3]: tegra_channel_kthread_capture_start: try to freeze
[ 244.404265] VI[3]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 244.404267] VI[2]: tegra_channel_queued_buf_done_single_thread: start
[ 244.404269] VI[3]: tegra_channel_kthread_capture_start: kthread_should_stop
[ 244.404271] VI[3]: tegra_channel_kthread_capture_start: end
[ 244.404295] VI[3]: free_ring_buffers: start
[ 244.404297] VI[3]: tegra_channel_queued_buf_done: start
[ 244.404299] VI[3]: tegra_channel_queued_buf_done_single_thread: start
[ 244.404341] VI[0]: free_ring_buffers: chan->released_bufs = 2
[ 244.404343] VI[0]: tegra_channel_ring_buffer: end
[ 244.404345] VI[0]: tegra_channel_capture_frame_single_thread: end
[ 244.404347] VI[0]: tegra_channel_kthread_capture_start: try to freeze
[ 244.404349] VI[0]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 244.404351] VI[0]: tegra_channel_kthread_capture_start: kthread_should_stop
[ 244.404353] VI[0]: tegra_channel_kthread_capture_start: end
[ 244.404361] VI[1]: free_ring_buffers: chan->released_bufs = 1
[ 244.404363] VI[1]: tegra_channel_ring_buffer: end
[ 244.404365] VI[1]: tegra_channel_capture_frame_single_thread: end
[ 244.404367] VI[1]: tegra_channel_kthread_capture_start: try to freeze
[ 244.404369] VI[1]: tegra_channel_kthread_capture_start: wait_event_interruptible
[ 244.404371] VI[1]: tegra_channel_kthread_capture_start: kthread_should_stop
[ 244.404372] VI[1]: tegra_channel_kthread_capture_start: end
[ 244.404379] VI[0]: free_ring_buffers: start
[ 244.404381] VI[0]: tegra_channel_queued_buf_done: start
[ 244.404383] VI[0]: tegra_channel_queued_buf_done_single_thread: start
[ 244.404396] VI[1]: free_ring_buffers: start
[ 244.404398] VI[1]: tegra_channel_queued_buf_done: start
[ 244.404400] VI[1]: tegra_channel_queued_buf_done_single_thread: start
[ 244.407095] VI[2]: tegra_channel_queued_buf_done_single_thread: end
[ 244.407098] VI[2]: tegra_channel_queued_buf_done: end
[ 244.407121] VI[3]: tegra_channel_queued_buf_done_single_thread: end
[ 244.407123] VI[3]: tegra_channel_queued_buf_done: end
[ 244.407139] CSI[2]: csi2_stop_streaming: start
[ 244.407141] CSI[2]: csi2_stop_streaming: end
[ 244.407166] CSI[3]: csi2_stop_streaming: start
[ 244.407169] CSI[3]: csi2_stop_streaming: end
[ 244.407192] VI[0]: tegra_channel_queued_buf_done_single_thread: end
[ 244.407194] VI[0]: tegra_channel_queued_buf_done: end
[ 244.407235] CSI[0]: csi2_stop_streaming: start
[ 244.407237] CSI[0]: csi2_stop_streaming: end
[ 244.407256] VI: vi2_channel_stop_streaming: end
[ 244.407631] VI[1]: tegra_channel_queued_buf_done_single_thread: end
[ 244.407633] VI[1]: tegra_channel_queued_buf_done: end
[ 244.407668] CSI[1]: csi2_stop_streaming: start
[ 244.407671] CSI[1]: csi2_stop_streaming: end
[ 244.408108] VI: vi2_channel_stop_streaming: end
[ 244.408776] VI: vi2_channel_stop_streaming: end
[ 244.408796] VI: vi2_channel_stop_streaming: end
VI[1] and CSI[1] - channel that dropped the frame. CSI[0], [2] and [3] after the csi_stop_streaming going to the tegra_csi_error and then corresponding VI channel is unfreezing and get the frame. But in this part of the log we could see that on the CSI[1] channel after the csi_stop_streaming it is no going to the tegra_csi_error and the thread never unfreezing. After this we will not get the frame.
In function tegra_channel_kthread_capture_start is waiting:
wait_event_interruptible(chan->start_wait,
!list_empty(&chan->capture) ||
kthread_should_stop());
But I cannot find where is something writing to the chan->capture? And where can I find this code? I want to understand why is system waiting here forever sometimes? Is frame was received but it didn’t acknowledged by VI driver or it wasn’t received at all - that is what I try to understand. Where this chan->capture is filling?