Intermittent PXL_SOF

Hi,
I have a system using 4 single lane CSI cameras.
I have them hooked up to CSI A,B,E,F.

The problem I’m seeing is that SOMETIMES images aren’t captured on a subset of the cameras.
I see “tegra-vi4 15700000.vi: PXL_SOF syncpt timeout!” warnings.

Each of these cameras run simultaneously and are frame synchronized through an external common clock source. But I have some logic in place to synchronize issuing the SINGLESHOT command to each of the vi channel registers.

About half the time there is no problem and everything works properly.
The other half of the time, one or two of the channels will start producing the PXL_SOF messages.

If I get a run that starts successfully, it will continue running without problem.
If it starts running with SOF errors, that error will continue to persist for that particular channel until reset.

I’ve probed the signal and can see the CSI signal on the lines when the error occurs, so it’s not a case of missing signal.

I’ve tried resetting the channel as described in 27.8.1 of the TRM (clear CONTROL.ENABLE, issue LOAD, set CONTROL.ENABLE) after the error starts, but that has no effect.

Is there something that would cause PXL_SOF errors? I don’t think it’s a setting problem as I’ve demonstrated that much of the time capture is successful.

Thanks for any help!

I ran the following from another thread I saw on the forum:

echo 1 > /sys/kernel/debug/tracing/tracing_on
echo 30720 > /sys/kernel/debug/tracing/buffer_size_kb
echo 1 > /sys/kernel/debug/tracing/events/tegra_rtcpu/enable
echo 1 > /sys/kernel/debug/tracing/events/freertos/enable
echo 2 > /sys/kernel/debug/camrtc/log-level
echo > /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 192/192   #P:6
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
     kworker/0:0-1383  [000] ...1   487.343315: rtos_queue_peek_from_isr_failed: tstamp:15365629626 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   487.343319: rtcpu_start: tstamp:15365630339
     kworker/0:0-1383  [000] ...1   487.551306: rtos_queue_peek_from_isr_failed: tstamp:15370630471 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   487.603314: rtcpu_vinotify_handle_msg: tstamp:15373587140 tag:CHANSEL_PXL_SOF channel:0x02 frame:6 vi_tstamp:2488684200 data:0x00000001
     kworker/0:0-1383  [000] ...1   487.603318: rtcpu_vinotify_handle_msg: tstamp:15373587298 tag:CHANSEL_PXL_SOF channel:0x03 frame:6 vi_tstamp:2488684200 data:0x00000001
     kworker/0:0-1383  [000] ...1   487.603319: rtcpu_vinotify_handle_msg: tstamp:15373587441 tag:CHANSEL_PXL_SOF channel:0x01 frame:6 vi_tstamp:2488684201 data:0x00000001
     kworker/0:0-1383  [000] ...1   487.603320: rtcpu_vinotify_handle_msg: tstamp:15373587581 tag:ATOMP_FS channel:0x02 frame:6 vi_tstamp:2488684238 data:0x00000000
     kworker/0:0-1383  [000] ...1   487.603321: rtcpu_vinotify_handle_msg: tstamp:15373587679 tag:ATOMP_FS channel:0x03 frame:6 vi_tstamp:2488684238 data:0x00000000
     kworker/0:0-1383  [000] ...1   487.603322: rtcpu_vinotify_handle_msg: tstamp:15373587780 tag:ATOMP_FS channel:0x01 frame:6 vi_tstamp:2488684238 data:0x00000000
     kworker/0:0-1383  [000] ...1   487.655305: rtcpu_vinotify_handle_msg: tstamp:15373876869 tag:CHANSEL_PXL_EOF channel:0x02 frame:6 vi_tstamp:2488973814 data:0x01df0002
     kworker/0:0-1383  [000] ...1   487.655307: rtcpu_vinotify_handle_msg: tstamp:15373876968 tag:CHANSEL_PXL_EOF channel:0x03 frame:6 vi_tstamp:2488973815 data:0x01df0002
     kworker/0:0-1383  [000] ...1   487.655308: rtcpu_vinotify_handle_msg: tstamp:15373877068 tag:CHANSEL_PXL_EOF channel:0x01 frame:6 vi_tstamp:2488973816 data:0x01df0002
     kworker/0:0-1383  [000] ...1   487.655309: rtcpu_vinotify_handle_msg: tstamp:15373877165 tag:ATOMP_FE channel:0x02 frame:6 vi_tstamp:2488973844 data:0x00000000
     kworker/0:0-1383  [000] ...1   487.655310: rtcpu_vinotify_handle_msg: tstamp:15373877282 tag:ATOMP_FE channel:0x03 frame:6 vi_tstamp:2488973845 data:0x00000000
     kworker/0:0-1383  [000] ...1   487.655310: rtcpu_vinotify_handle_msg: tstamp:15373877399 tag:ATOMP_FE channel:0x01 frame:6 vi_tstamp:2488973846 data:0x00000000
     kworker/0:0-1383  [000] ...1   487.707307: rtos_queue_peek_from_isr_failed: tstamp:15375630981 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   487.863306: rtos_queue_peek_from_isr_failed: tstamp:15380631485 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.019308: rtos_queue_peek_from_isr_failed: tstamp:15385631991 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.175306: rtos_queue_peek_from_isr_failed: tstamp:15390632497 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.331308: rtos_queue_peek_from_isr_failed: tstamp:15395633004 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.487307: rtos_queue_peek_from_isr_failed: tstamp:15400633514 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.643307: rtcpu_vinotify_handle_msg: tstamp:15405119055 tag:CHANSEL_PXL_SOF channel:0x02 frame:66 vi_tstamp:2520216118 data:0x00000001
     kworker/0:0-1383  [000] ...1   488.643310: rtcpu_vinotify_handle_msg: tstamp:15405119203 tag:CHANSEL_PXL_SOF channel:0x03 frame:66 vi_tstamp:2520216118 data:0x00000001
     kworker/0:0-1383  [000] ...1   488.643311: rtcpu_vinotify_handle_msg: tstamp:15405119354 tag:CHANSEL_PXL_SOF channel:0x01 frame:66 vi_tstamp:2520216118 data:0x00000001
     kworker/0:0-1383  [000] ...1   488.643311: rtcpu_vinotify_handle_msg: tstamp:15405119494 tag:ATOMP_FS channel:0x02 frame:66 vi_tstamp:2520216156 data:0x00000000
     kworker/0:0-1383  [000] ...1   488.643312: rtcpu_vinotify_handle_msg: tstamp:15405119592 tag:ATOMP_FS channel:0x03 frame:66 vi_tstamp:2520216156 data:0x00000000
     kworker/0:0-1383  [000] ...1   488.643313: rtcpu_vinotify_handle_msg: tstamp:15405119693 tag:ATOMP_FS channel:0x01 frame:66 vi_tstamp:2520216156 data:0x00000000
     kworker/0:0-1383  [000] ...1   488.643314: rtcpu_vinotify_handle_msg: tstamp:15405408785 tag:CHANSEL_PXL_EOF channel:0x02 frame:66 vi_tstamp:2520505732 data:0x01df0002
     kworker/0:0-1383  [000] ...1   488.643315: rtcpu_vinotify_handle_msg: tstamp:15405408886 tag:CHANSEL_PXL_EOF channel:0x03 frame:66 vi_tstamp:2520505733 data:0x01df0002
     kworker/0:0-1383  [000] ...1   488.643315: rtcpu_vinotify_handle_msg: tstamp:15405408986 tag:CHANSEL_PXL_EOF channel:0x01 frame:66 vi_tstamp:2520505734 data:0x01df0002
     kworker/0:0-1383  [000] ...1   488.643316: rtcpu_vinotify_handle_msg: tstamp:15405409083 tag:ATOMP_FE channel:0x02 frame:66 vi_tstamp:2520505762 data:0x00000000
     kworker/0:0-1383  [000] ...1   488.643317: rtcpu_vinotify_handle_msg: tstamp:15405409200 tag:ATOMP_FE channel:0x03 frame:66 vi_tstamp:2520505763 data:0x00000000
     kworker/0:0-1383  [000] ...1   488.643318: rtcpu_vinotify_handle_msg: tstamp:15405409331 tag:ATOMP_FE channel:0x01 frame:66 vi_tstamp:2520505764 data:0x00000000
     kworker/0:0-1383  [000] ...1   488.643319: rtos_queue_peek_from_isr_failed: tstamp:15405634020 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.799309: rtos_queue_peek_from_isr_failed: tstamp:15410634527 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   488.955307: rtos_queue_peek_from_isr_failed: tstamp:15415635032 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   489.111306: rtos_queue_peek_from_isr_failed: tstamp:15420635540 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   489.267309: rtos_queue_peek_from_isr_failed: tstamp:15425636048 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   489.423314: rtos_queue_peek_from_isr_failed: tstamp:15430636553 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   489.631320: rtos_queue_peek_from_isr_failed: tstamp:15435637061 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   489.631323: rtcpu_vinotify_handle_msg: tstamp:15436650963 tag:CHANSEL_PXL_SOF channel:0x02 frame:126 vi_tstamp:2551748036 data:0x00000001
     kworker/0:0-1383  [000] ...1   489.631324: rtcpu_vinotify_handle_msg: tstamp:15436651105 tag:CHANSEL_PXL_SOF channel:0x03 frame:126 vi_tstamp:2551748036 data:0x00000001
     kworker/0:0-1383  [000] ...1   489.631325: rtcpu_vinotify_handle_msg: tstamp:15436651247 tag:CHANSEL_PXL_SOF channel:0x01 frame:126 vi_tstamp:2551748036 data:0x00000001
     kworker/0:0-1383  [000] ...1   489.631325: rtcpu_vinotify_handle_msg: tstamp:15436651386 tag:ATOMP_FS channel:0x02 frame:126 vi_tstamp:2551748075 data:0x00000000
     kworker/0:0-1383  [000] ...1   489.631326: rtcpu_vinotify_handle_msg: tstamp:15436651484 tag:ATOMP_FS channel:0x03 frame:126 vi_tstamp:2551748075 data:0x00000000
     kworker/0:0-1383  [000] ...1   489.631327: rtcpu_vinotify_handle_msg: tstamp:15436651584 tag:ATOMP_FS channel:0x01 frame:126 vi_tstamp:2551748075 data:0x00000000
     kworker/0:0-1383  [000] ...1   489.631328: rtcpu_vinotify_handle_msg: tstamp:15436940704 tag:CHANSEL_PXL_EOF channel:0x02 frame:126 vi_tstamp:2552037650 data:0x01df0002
     kworker/0:0-1383  [000] ...1   489.631328: rtcpu_vinotify_handle_msg: tstamp:15436940807 tag:CHANSEL_PXL_EOF channel:0x03 frame:126 vi_tstamp:2552037650 data:0x01df0002
     kworker/0:0-1383  [000] ...1   489.631329: rtcpu_vinotify_handle_msg: tstamp:15436940908 tag:CHANSEL_PXL_EOF channel:0x01 frame:126 vi_tstamp:2552037652 data:0x01df0002
     kworker/0:0-1383  [000] ...1   489.631330: rtcpu_vinotify_handle_msg: tstamp:15436941006 tag:ATOMP_FE channel:0x02 frame:126 vi_tstamp:2552037680 data:0x00000000
     kworker/0:0-1383  [000] ...1   489.631330: rtcpu_vinotify_handle_msg: tstamp:15436941126 tag:ATOMP_FE channel:0x03 frame:126 vi_tstamp:2552037681 data:0x00000000
     kworker/0:0-1383  [000] ...1   489.631331: rtcpu_vinotify_handle_msg: tstamp:15436941244 tag:ATOMP_FE channel:0x01 frame:126 vi_tstamp:2552037682 data:0x00000000
     kworker/0:0-1383  [000] ...1   489.787307: rtos_queue_peek_from_isr_failed: tstamp:15440637566 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   489.943311: rtos_queue_peek_from_isr_failed: tstamp:15445638074 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   490.099303: rtos_queue_peek_from_isr_failed: tstamp:15450638583 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   490.255312: rtos_queue_peek_from_isr_failed: tstamp:15455639087 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   490.411326: rtos_queue_peek_from_isr_failed: tstamp:15460639596 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   490.567307: rtos_queue_peek_from_isr_failed: tstamp:15465640100 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   490.671306: rtcpu_vinotify_handle_msg: tstamp:15468182878 tag:CHANSEL_PXL_SOF channel:0x02 frame:186 vi_tstamp:2583279954 data:0x00000001
     kworker/0:0-1383  [000] ...1   490.671309: rtcpu_vinotify_handle_msg: tstamp:15468183034 tag:CHANSEL_PXL_SOF channel:0x03 frame:186 vi_tstamp:2583279954 data:0x00000001
     kworker/0:0-1383  [000] ...1   490.671310: rtcpu_vinotify_handle_msg: tstamp:15468183179 tag:CHANSEL_PXL_SOF channel:0x01 frame:186 vi_tstamp:2583279954 data:0x00000001
     kworker/0:0-1383  [000] ...1   490.671311: rtcpu_vinotify_handle_msg: tstamp:15468183318 tag:ATOMP_FS channel:0x02 frame:186 vi_tstamp:2583279992 data:0x00000000
     kworker/0:0-1383  [000] ...1   490.671311: rtcpu_vinotify_handle_msg: tstamp:15468183418 tag:ATOMP_FS channel:0x03 frame:186 vi_tstamp:2583279993 data:0x00000000
     kworker/0:0-1383  [000] ...1   490.671312: rtcpu_vinotify_handle_msg: tstamp:15468183516 tag:ATOMP_FS channel:0x01 frame:186 vi_tstamp:2583279993 data:0x00000000
     kworker/0:0-1383  [000] ...1   490.671313: rtcpu_vinotify_handle_msg: tstamp:15468472621 tag:CHANSEL_PXL_EOF channel:0x02 frame:186 vi_tstamp:2583569568 data:0x01df0002
     kworker/0:0-1383  [000] ...1   490.671313: rtcpu_vinotify_handle_msg: tstamp:15468472722 tag:CHANSEL_PXL_EOF channel:0x03 frame:186 vi_tstamp:2583569568 data:0x01df0002
     kworker/0:0-1383  [000] ...1   490.671314: rtcpu_vinotify_handle_msg: tstamp:15468472822 tag:CHANSEL_PXL_EOF channel:0x01 frame:186 vi_tstamp:2583569570 data:0x01df0002
     kworker/0:0-1383  [000] ...1   490.671315: rtcpu_vinotify_handle_msg: tstamp:15468472920 tag:ATOMP_FE channel:0x02 frame:186 vi_tstamp:2583569598 data:0x00000000
     kworker/0:0-1383  [000] ...1   490.671315: rtcpu_vinotify_handle_msg: tstamp:15468473037 tag:ATOMP_FE channel:0x03 frame:186 vi_tstamp:2583569599 data:0x00000000
     kworker/0:0-1383  [000] ...1   490.671316: rtcpu_vinotify_handle_msg: tstamp:15468473154 tag:ATOMP_FE channel:0x01 frame:186 vi_tstamp:2583569600 data:0x00000000
     kworker/0:0-1383  [000] ...1   490.723311: rtos_queue_peek_from_isr_failed: tstamp:15470640609 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   490.879305: rtos_queue_peek_from_isr_failed: tstamp:15475641115 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   491.035308: rtos_queue_peek_from_isr_failed: tstamp:15480641622 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   491.191308: rtos_queue_peek_from_isr_failed: tstamp:15485642127 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   491.347309: rtos_queue_peek_from_isr_failed: tstamp:15490642635 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   491.503305: rtos_queue_peek_from_isr_failed: tstamp:15495643140 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   491.659305: rtcpu_vinotify_handle_msg: tstamp:15500240329 tag:CHANSEL_PXL_SOF channel:0x02 frame:247 vi_tstamp:2615337404 data:0x00000001
     kworker/0:0-1383  [000] ...1   491.659308: rtcpu_vinotify_handle_msg: tstamp:15500240486 tag:CHANSEL_PXL_SOF channel:0x03 frame:247 vi_tstamp:2615337404 data:0x00000001
     kworker/0:0-1383  [000] ...1   491.659309: rtcpu_vinotify_handle_msg: tstamp:15500240631 tag:CHANSEL_PXL_SOF channel:0x01 frame:247 vi_tstamp:2615337404 data:0x00000001
     kworker/0:0-1383  [000] ...1   491.659310: rtcpu_vinotify_handle_msg: tstamp:15500240774 tag:ATOMP_FS channel:0x02 frame:247 vi_tstamp:2615337442 data:0x00000000
     kworker/0:0-1383  [000] ...1   491.659311: rtcpu_vinotify_handle_msg: tstamp:15500240874 tag:ATOMP_FS channel:0x03 frame:247 vi_tstamp:2615337442 data:0x00000000
     kworker/0:0-1383  [000] ...1   491.659311: rtcpu_vinotify_handle_msg: tstamp:15500240974 tag:ATOMP_FS channel:0x01 frame:247 vi_tstamp:2615337443 data:0x00000000
     kworker/0:0-1383  [000] ...1   491.659312: rtcpu_vinotify_handle_msg: tstamp:15500530073 tag:CHANSEL_PXL_EOF channel:0x02 frame:247 vi_tstamp:2615627018 data:0x01df0002
     kworker/0:0-1383  [000] ...1   491.659313: rtcpu_vinotify_handle_msg: tstamp:15500530176 tag:CHANSEL_PXL_EOF channel:0x03 frame:247 vi_tstamp:2615627018 data:0x01df0002
     kworker/0:0-1383  [000] ...1   491.659314: rtcpu_vinotify_handle_msg: tstamp:15500530275 tag:CHANSEL_PXL_EOF channel:0x01 frame:247 vi_tstamp:2615627019 data:0x01df0002
     kworker/0:0-1383  [000] ...1   491.659315: rtcpu_vinotify_handle_msg: tstamp:15500530374 tag:ATOMP_FE channel:0x02 frame:247 vi_tstamp:2615627048 data:0x00000000
     kworker/0:0-1383  [000] ...1   491.659315: rtcpu_vinotify_handle_msg: tstamp:15500530492 tag:ATOMP_FE channel:0x03 frame:247 vi_tstamp:2615627049 data:0x00000000
     kworker/0:0-1383  [000] ...1   491.659316: rtcpu_vinotify_handle_msg: tstamp:15500530611 tag:ATOMP_FE channel:0x01 frame:247 vi_tstamp:2615627050 data:0x00000000
     kworker/0:0-1383  [000] ...1   491.711310: rtos_queue_peek_from_isr_failed: tstamp:15500643649 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   491.867306: rtos_queue_peek_from_isr_failed: tstamp:15505644144 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.023315: rtos_queue_peek_from_isr_failed: tstamp:15510644662 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.179309: rtos_queue_peek_from_isr_failed: tstamp:15515645170 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.335310: rtos_queue_peek_from_isr_failed: tstamp:15520645675 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.491309: rtos_queue_peek_from_isr_failed: tstamp:15525646183 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.647310: rtos_queue_peek_from_isr_failed: tstamp:15530646692 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.699306: rtcpu_vinotify_handle_msg: tstamp:15531772259 tag:CHANSEL_PXL_SOF channel:0x02 frame:307 vi_tstamp:2646869323 data:0x00000001
     kworker/0:0-1383  [000] ...1   492.699308: rtcpu_vinotify_handle_msg: tstamp:15531772405 tag:CHANSEL_PXL_SOF channel:0x03 frame:307 vi_tstamp:2646869323 data:0x00000001
     kworker/0:0-1383  [000] ...1   492.699309: rtcpu_vinotify_handle_msg: tstamp:15531772548 tag:CHANSEL_PXL_SOF channel:0x01 frame:307 vi_tstamp:2646869323 data:0x00000001
     kworker/0:0-1383  [000] ...1   492.699310: rtcpu_vinotify_handle_msg: tstamp:15531772688 tag:ATOMP_FS channel:0x02 frame:307 vi_tstamp:2646869360 data:0x00000000
     kworker/0:0-1383  [000] ...1   492.699311: rtcpu_vinotify_handle_msg: tstamp:15531772788 tag:ATOMP_FS channel:0x03 frame:307 vi_tstamp:2646869360 data:0x00000000
     kworker/0:0-1383  [000] ...1   492.699311: rtcpu_vinotify_handle_msg: tstamp:15531772890 tag:ATOMP_FS channel:0x01 frame:307 vi_tstamp:2646869361 data:0x00000000
     kworker/0:0-1383  [000] ...1   492.699312: rtcpu_vinotify_handle_msg: tstamp:15532061987 tag:CHANSEL_PXL_EOF channel:0x02 frame:307 vi_tstamp:2647158936 data:0x01df0002
     kworker/0:0-1383  [000] ...1   492.699313: rtcpu_vinotify_handle_msg: tstamp:15532062088 tag:CHANSEL_PXL_EOF channel:0x03 frame:307 vi_tstamp:2647158936 data:0x01df0002
     kworker/0:0-1383  [000] ...1   492.699314: rtcpu_vinotify_handle_msg: tstamp:15532062188 tag:CHANSEL_PXL_EOF channel:0x01 frame:307 vi_tstamp:2647158937 data:0x01df0002
     kworker/0:0-1383  [000] ...1   492.699314: rtcpu_vinotify_handle_msg: tstamp:15532062285 tag:ATOMP_FE channel:0x02 frame:307 vi_tstamp:2647158966 data:0x00000000
     kworker/0:0-1383  [000] ...1   492.699315: rtcpu_vinotify_handle_msg: tstamp:15532062403 tag:ATOMP_FE channel:0x03 frame:307 vi_tstamp:2647158967 data:0x00000000
     kworker/0:0-1383  [000] ...1   492.699316: rtcpu_vinotify_handle_msg: tstamp:15532062520 tag:ATOMP_FE channel:0x01 frame:307 vi_tstamp:2647158968 data:0x00000000
     kworker/0:0-1383  [000] ...1   492.803307: rtos_queue_peek_from_isr_failed: tstamp:15535647197 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   492.959312: rtos_queue_peek_from_isr_failed: tstamp:15540647705 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   493.115304: rtos_queue_peek_from_isr_failed: tstamp:15545648209 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   493.271316: rtos_queue_peek_from_isr_failed: tstamp:15550648718 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   493.427310: rtos_queue_peek_from_isr_failed: tstamp:15555649226 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   493.583308: rtos_queue_peek_from_isr_failed: tstamp:15560649731 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   493.687313: rtcpu_vinotify_handle_msg: tstamp:15563304166 tag:CHANSEL_PXL_SOF channel:0x02 frame:367 vi_tstamp:2678401241 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.687317: rtcpu_vinotify_handle_msg: tstamp:15563304322 tag:CHANSEL_PXL_SOF channel:0x03 frame:367 vi_tstamp:2678401241 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.687318: rtcpu_vinotify_handle_msg: tstamp:15563304471 tag:CHANSEL_PXL_SOF channel:0x01 frame:367 vi_tstamp:2678401241 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.687318: rtcpu_vinotify_handle_msg: tstamp:15563304611 tag:ATOMP_FS channel:0x02 frame:367 vi_tstamp:2678401278 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687319: rtcpu_vinotify_handle_msg: tstamp:15563304712 tag:ATOMP_FS channel:0x03 frame:367 vi_tstamp:2678401278 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687320: rtcpu_vinotify_handle_msg: tstamp:15563304811 tag:ATOMP_FS channel:0x01 frame:367 vi_tstamp:2678401279 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687321: rtcpu_vinotify_handle_msg: tstamp:15563308639 tag:CHANSEL_LOAD_FRAMED channel:0x10 frame:367 vi_tstamp:2678406133 data:0x18000000
     kworker/0:0-1383  [000] ...1   493.687322: rtcpu_vinotify_handle_msg: tstamp:15563308733 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:367 vi_tstamp:2678406326 data:0x28000000
     kworker/0:0-1383  [000] ...1   493.687323: rtcpu_vinotify_handle_msg: tstamp:15563309041 tag:CHANSEL_LOAD_FRAMED channel:0x02 frame:367 vi_tstamp:2678406866 data:0x38000000
     kworker/0:0-1383  [000] ...1   493.687323: rtcpu_vinotify_handle_msg: tstamp:15563593939 tag:CHANSEL_PXL_EOF channel:0x02 frame:367 vi_tstamp:2678690854 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.687324: rtcpu_vinotify_handle_msg: tstamp:15563594040 tag:CHANSEL_PXL_EOF channel:0x03 frame:367 vi_tstamp:2678690854 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.687325: rtcpu_vinotify_handle_msg: tstamp:15563594140 tag:CHANSEL_PXL_EOF channel:0x01 frame:367 vi_tstamp:2678690855 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.687326: rtcpu_vinotify_handle_msg: tstamp:15563594237 tag:ATOMP_FE channel:0x02 frame:367 vi_tstamp:2678690885 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687327: rtcpu_vinotify_handle_msg: tstamp:15563594352 tag:ATOMP_FE channel:0x03 frame:367 vi_tstamp:2678690885 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687328: rtcpu_vinotify_handle_msg: tstamp:15563594469 tag:ATOMP_FE channel:0x01 frame:367 vi_tstamp:2678690886 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687328: rtcpu_vinotify_handle_msg: tstamp:15563829696 tag:CHANSEL_PXL_SOF channel:0x02 frame:368 vi_tstamp:2678926772 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.687329: rtcpu_vinotify_handle_msg: tstamp:15563829850 tag:CHANSEL_PXL_SOF channel:0x03 frame:368 vi_tstamp:2678926773 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.687330: rtcpu_vinotify_handle_msg: tstamp:15563830003 tag:CHANSEL_PXL_SOF channel:0x01 frame:368 vi_tstamp:2678926773 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.687331: rtcpu_vinotify_handle_msg: tstamp:15563830142 tag:ATOMP_FS channel:0x02 frame:368 vi_tstamp:2678926810 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687332: rtcpu_vinotify_handle_msg: tstamp:15563830245 tag:ATOMP_FS channel:0x03 frame:368 vi_tstamp:2678926810 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687333: rtcpu_vinotify_handle_msg: tstamp:15563830345 tag:ATOMP_FS channel:0x01 frame:368 vi_tstamp:2678926811 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.687333: rtcpu_vinotify_handle_msg: tstamp:15563832761 tag:CHANSEL_LOAD_FRAMED channel:0x10 frame:368 vi_tstamp:2678930458 data:0x18000000
     kworker/0:0-1383  [000] ...1   493.687334: rtcpu_vinotify_handle_msg: tstamp:15563833527 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:368 vi_tstamp:2678931219 data:0x28000000
     kworker/0:0-1383  [000] ...1   493.687335: rtcpu_vinotify_handle_msg: tstamp:15563834178 tag:CHANSEL_LOAD_FRAMED channel:0x02 frame:368 vi_tstamp:2678931881 data:0x38000000
     kworker/0:0-1383  [000] ...1   493.739318: rtcpu_vinotify_handle_msg: tstamp:15564119472 tag:CHANSEL_PXL_EOF channel:0x02 frame:368 vi_tstamp:2679216387 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739322: rtcpu_vinotify_handle_msg: tstamp:15564119573 tag:CHANSEL_PXL_EOF channel:0x03 frame:368 vi_tstamp:2679216387 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739323: rtcpu_vinotify_handle_msg: tstamp:15564119673 tag:CHANSEL_PXL_EOF channel:0x01 frame:368 vi_tstamp:2679216387 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739323: rtcpu_vinotify_handle_msg: tstamp:15564119771 tag:ATOMP_FE channel:0x02 frame:368 vi_tstamp:2679216416 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739324: rtcpu_vinotify_handle_msg: tstamp:15564119889 tag:ATOMP_FE channel:0x03 frame:368 vi_tstamp:2679216417 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739326: rtcpu_vinotify_handle_msg: tstamp:15564120007 tag:ATOMP_FE channel:0x01 frame:368 vi_tstamp:2679216417 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739327: rtcpu_vinotify_handle_msg: tstamp:15564355239 tag:CHANSEL_PXL_SOF channel:0x02 frame:369 vi_tstamp:2679452304 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739328: rtcpu_vinotify_handle_msg: tstamp:15564355406 tag:CHANSEL_PXL_SOF channel:0x03 frame:369 vi_tstamp:2679452305 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739329: rtcpu_vinotify_handle_msg: tstamp:15564355553 tag:CHANSEL_PXL_SOF channel:0x01 frame:369 vi_tstamp:2679452305 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739330: rtcpu_vinotify_handle_msg: tstamp:15564355692 tag:ATOMP_FS channel:0x02 frame:369 vi_tstamp:2679452342 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739331: rtcpu_vinotify_handle_msg: tstamp:15564355796 tag:ATOMP_FS channel:0x03 frame:369 vi_tstamp:2679452342 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739332: rtcpu_vinotify_handle_msg: tstamp:15564355895 tag:ATOMP_FS channel:0x01 frame:369 vi_tstamp:2679452342 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739333: rtcpu_vinotify_handle_msg: tstamp:15564358513 tag:CHANSEL_LOAD_FRAMED channel:0x10 frame:369 vi_tstamp:2679456215 data:0x18000000
     kworker/0:0-1383  [000] ...1   493.739334: rtcpu_vinotify_handle_msg: tstamp:15564359244 tag:CHANSEL_LOAD_FRAMED channel:0x02 frame:369 vi_tstamp:2679456747 data:0x38000000
     kworker/0:0-1383  [000] ...1   493.739335: rtcpu_vinotify_handle_msg: tstamp:15564359339 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:369 vi_tstamp:2679456919 data:0x28000000
     kworker/0:0-1383  [000] ...1   493.739336: rtcpu_vinotify_handle_msg: tstamp:15564645000 tag:CHANSEL_PXL_EOF channel:0x02 frame:369 vi_tstamp:2679741919 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739337: rtcpu_vinotify_handle_msg: tstamp:15564645101 tag:CHANSEL_PXL_EOF channel:0x03 frame:369 vi_tstamp:2679741919 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739338: rtcpu_vinotify_handle_msg: tstamp:15564645201 tag:CHANSEL_PXL_EOF channel:0x01 frame:369 vi_tstamp:2679741920 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739339: rtcpu_vinotify_handle_msg: tstamp:15564645298 tag:ATOMP_FE channel:0x02 frame:369 vi_tstamp:2679741948 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739340: rtcpu_vinotify_handle_msg: tstamp:15564645413 tag:ATOMP_FE channel:0x03 frame:369 vi_tstamp:2679741949 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739340: rtcpu_vinotify_handle_msg: tstamp:15564645529 tag:ATOMP_FE channel:0x01 frame:369 vi_tstamp:2679741950 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739341: rtcpu_vinotify_handle_msg: tstamp:15564880768 tag:CHANSEL_PXL_SOF channel:0x02 frame:370 vi_tstamp:2679977836 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739342: rtcpu_vinotify_handle_msg: tstamp:15564880924 tag:CHANSEL_PXL_SOF channel:0x03 frame:370 vi_tstamp:2679977836 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739343: rtcpu_vinotify_handle_msg: tstamp:15564881074 tag:CHANSEL_PXL_SOF channel:0x01 frame:370 vi_tstamp:2679977837 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739344: rtcpu_vinotify_handle_msg: tstamp:15564881217 tag:ATOMP_FS channel:0x02 frame:370 vi_tstamp:2679977874 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739345: rtcpu_vinotify_handle_msg: tstamp:15564881317 tag:ATOMP_FS channel:0x03 frame:370 vi_tstamp:2679977874 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739346: rtcpu_vinotify_handle_msg: tstamp:15564881415 tag:ATOMP_FS channel:0x01 frame:370 vi_tstamp:2679977874 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739347: rtcpu_vinotify_handle_msg: tstamp:15564884296 tag:CHANSEL_LOAD_FRAMED channel:0x10 frame:370 vi_tstamp:2679982000 data:0x18000000
     kworker/0:0-1383  [000] ...1   493.739348: rtcpu_vinotify_handle_msg: tstamp:15564884943 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:370 vi_tstamp:2679982647 data:0x28000000
     kworker/0:0-1383  [000] ...1   493.739349: rtcpu_vinotify_handle_msg: tstamp:15564885597 tag:CHANSEL_LOAD_FRAMED channel:0x02 frame:370 vi_tstamp:2679983293 data:0x38000000
     kworker/0:0-1383  [000] ...1   493.739350: rtcpu_vinotify_handle_msg: tstamp:15565170564 tag:CHANSEL_PXL_EOF channel:0x02 frame:370 vi_tstamp:2680267450 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739351: rtcpu_vinotify_handle_msg: tstamp:15565170665 tag:CHANSEL_PXL_EOF channel:0x03 frame:370 vi_tstamp:2680267451 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739352: rtcpu_vinotify_handle_msg: tstamp:15565170765 tag:CHANSEL_PXL_EOF channel:0x01 frame:370 vi_tstamp:2680267452 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.739353: rtcpu_vinotify_handle_msg: tstamp:15565170865 tag:ATOMP_FE channel:0x02 frame:370 vi_tstamp:2680267480 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739354: rtcpu_vinotify_handle_msg: tstamp:15565170980 tag:ATOMP_FE channel:0x03 frame:370 vi_tstamp:2680267481 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739355: rtcpu_vinotify_handle_msg: tstamp:15565171099 tag:ATOMP_FE channel:0x01 frame:370 vi_tstamp:2680267482 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739356: rtcpu_vinotify_handle_msg: tstamp:15565406292 tag:CHANSEL_PXL_SOF channel:0x02 frame:371 vi_tstamp:2680503368 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739357: rtcpu_vinotify_handle_msg: tstamp:15565406434 tag:CHANSEL_PXL_SOF channel:0x03 frame:371 vi_tstamp:2680503368 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739358: rtcpu_vinotify_handle_msg: tstamp:15565406575 tag:CHANSEL_PXL_SOF channel:0x01 frame:371 vi_tstamp:2680503369 data:0x00000001
     kworker/0:0-1383  [000] ...1   493.739359: rtcpu_vinotify_handle_msg: tstamp:15565406715 tag:ATOMP_FS channel:0x02 frame:371 vi_tstamp:2680503406 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739360: rtcpu_vinotify_handle_msg: tstamp:15565406815 tag:ATOMP_FS channel:0x03 frame:371 vi_tstamp:2680503406 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.739361: rtcpu_vinotify_handle_msg: tstamp:15565406913 tag:ATOMP_FS channel:0x01 frame:371 vi_tstamp:2680503407 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.791304: rtos_queue_peek_from_isr_failed: tstamp:15565650239 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   493.791307: rtcpu_vinotify_handle_msg: tstamp:15565696037 tag:CHANSEL_PXL_EOF channel:0x02 frame:371 vi_tstamp:2680792982 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.791307: rtcpu_vinotify_handle_msg: tstamp:15565696139 tag:CHANSEL_PXL_EOF channel:0x03 frame:371 vi_tstamp:2680792983 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.791308: rtcpu_vinotify_handle_msg: tstamp:15565696237 tag:CHANSEL_PXL_EOF channel:0x01 frame:371 vi_tstamp:2680792984 data:0x01df0002
     kworker/0:0-1383  [000] ...1   493.791309: rtcpu_vinotify_handle_msg: tstamp:15565696334 tag:ATOMP_FE channel:0x02 frame:371 vi_tstamp:2680793012 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.791310: rtcpu_vinotify_handle_msg: tstamp:15565696452 tag:ATOMP_FE channel:0x03 frame:371 vi_tstamp:2680793013 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.791310: rtcpu_vinotify_handle_msg: tstamp:15565696570 tag:ATOMP_FE channel:0x01 frame:371 vi_tstamp:2680793014 data:0x00000000
     kworker/0:0-1383  [000] ...1   493.947307: rtos_queue_peek_from_isr_failed: tstamp:15570650732 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   494.103313: rtos_queue_peek_from_isr_failed: tstamp:15575651252 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   494.259315: rtos_queue_peek_from_isr_failed: tstamp:15580651757 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   494.415307: rtos_queue_peek_from_isr_failed: tstamp:15585652265 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   494.571307: rtos_queue_peek_from_isr_failed: tstamp:15590652770 queue:0x0b4a3c58
     kworker/0:0-1383  [000] ...1   494.727318: rtos_queue_peek_from_isr_failed: tstamp:15595613026 queue:0x0b4a3c58

Strange… it looks like there are only 3 channels. There should be 4 capturing.

Here is the output from the start of a successful run:

# tracer: nop
#
# entries-in-buffer/entries-written: 2963/2963   #P:6
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
     kworker/0:1-1428  [000] ...1  1844.491311: rtos_queue_peek_from_isr_failed: tstamp:57775616512 queue:0x0b4a3c58
     kworker/0:1-1428  [000] ...1  1844.491315: rtcpu_start: tstamp:57775617301
     kworker/0:1-1428  [000] ...1  1844.647307: rtos_queue_peek_from_isr_failed: tstamp:57780617378 queue:0x0b4a3c58
     kworker/0:1-1428  [000] ...1  1844.751319: rtcpu_vinotify_handle_msg: tstamp:57783599528 tag:CHANSEL_PXL_SOF channel:0x02 frame:6 vi_tstamp:1949023381 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751321: rtcpu_vinotify_handle_msg: tstamp:57783599673 tag:CHANSEL_PXL_SOF channel:0x03 frame:6 vi_tstamp:1949023381 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751322: rtcpu_vinotify_handle_msg: tstamp:57783599816 tag:CHANSEL_PXL_SOF channel:0x01 frame:6 vi_tstamp:1949023382 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751322: rtcpu_vinotify_handle_msg: tstamp:57783599955 tag:CHANSEL_PXL_SOF channel:0x00 frame:6 vi_tstamp:1949023382 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751323: rtcpu_vinotify_handle_msg: tstamp:57783600096 tag:ATOMP_FS channel:0x02 frame:6 vi_tstamp:1949023418 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751324: rtcpu_vinotify_handle_msg: tstamp:57783600194 tag:ATOMP_FS channel:0x03 frame:6 vi_tstamp:1949023419 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751325: rtcpu_vinotify_handle_msg: tstamp:57783600294 tag:ATOMP_FS channel:0x01 frame:6 vi_tstamp:1949023419 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751325: rtcpu_vinotify_handle_msg: tstamp:57783600392 tag:ATOMP_FS channel:0x00 frame:6 vi_tstamp:1949023419 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751326: rtcpu_vinotify_handle_msg: tstamp:57783606123 tag:CHANSEL_LOAD_FRAMED channel:0x20 frame:6 vi_tstamp:1949030403 data:0x08000000
     kworker/0:1-1428  [000] ...1  1844.751327: rtcpu_vinotify_handle_msg: tstamp:57783606220 tag:CHANSEL_LOAD_FRAMED channel:0x10 frame:6 vi_tstamp:1949030536 data:0x18000000
     kworker/0:1-1428  [000] ...1  1844.751328: rtcpu_vinotify_handle_msg: tstamp:57783606321 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:6 vi_tstamp:1949030661 data:0x28000000
     kworker/0:1-1428  [000] ...1  1844.751329: rtcpu_vinotify_handle_msg: tstamp:57783606413 tag:CHANSEL_LOAD_FRAMED channel:0x02 frame:6 vi_tstamp:1949030775 data:0x38000000
     kworker/0:1-1428  [000] ...1  1844.751329: rtcpu_vinotify_handle_msg: tstamp:57783889348 tag:CHANSEL_PXL_EOF channel:0x02 frame:6 vi_tstamp:1949312995 data:0x01df0002
     kworker/0:1-1428  [000] ...1  1844.751330: rtcpu_vinotify_handle_msg: tstamp:57783889450 tag:CHANSEL_PXL_EOF channel:0x03 frame:6 vi_tstamp:1949312995 data:0x01df0002
     kworker/0:1-1428  [000] ...1  1844.751331: rtcpu_vinotify_handle_msg: tstamp:57783889549 tag:CHANSEL_PXL_EOF channel:0x01 frame:6 vi_tstamp:1949312996 data:0x01df0002
     kworker/0:1-1428  [000] ...1  1844.751332: rtcpu_vinotify_handle_msg: tstamp:57783889648 tag:CHANSEL_PXL_EOF channel:0x00 frame:6 vi_tstamp:1949312996 data:0x01df0002
     kworker/0:1-1428  [000] ...1  1844.751332: rtcpu_vinotify_handle_msg: tstamp:57783889746 tag:ATOMP_FE channel:0x02 frame:6 vi_tstamp:1949313025 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751333: rtcpu_vinotify_handle_msg: tstamp:57783889863 tag:ATOMP_FE channel:0x03 frame:6 vi_tstamp:1949313026 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751334: rtcpu_vinotify_handle_msg: tstamp:57783889982 tag:ATOMP_FE channel:0x01 frame:6 vi_tstamp:1949313026 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751334: rtcpu_vinotify_handle_msg: tstamp:57783890098 tag:ATOMP_FE channel:0x00 frame:6 vi_tstamp:1949313027 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751335: rtcpu_vinotify_handle_msg: tstamp:57784125045 tag:CHANSEL_PXL_SOF channel:0x02 frame:7 vi_tstamp:1949548913 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751336: rtcpu_vinotify_handle_msg: tstamp:57784125184 tag:CHANSEL_PXL_SOF channel:0x03 frame:7 vi_tstamp:1949548913 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751337: rtcpu_vinotify_handle_msg: tstamp:57784125326 tag:CHANSEL_PXL_SOF channel:0x01 frame:7 vi_tstamp:1949548914 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751337: rtcpu_vinotify_handle_msg: tstamp:57784125467 tag:CHANSEL_PXL_SOF channel:0x00 frame:7 vi_tstamp:1949548914 data:0x00000001
     kworker/0:1-1428  [000] ...1  1844.751338: rtcpu_vinotify_handle_msg: tstamp:57784125615 tag:ATOMP_FS channel:0x02 frame:7 vi_tstamp:1949548950 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751339: rtcpu_vinotify_handle_msg: tstamp:57784125735 tag:ATOMP_FS channel:0x03 frame:7 vi_tstamp:1949548950 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751340: rtcpu_vinotify_handle_msg: tstamp:57784125835 tag:ATOMP_FS channel:0x01 frame:7 vi_tstamp:1949548951 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751340: rtcpu_vinotify_handle_msg: tstamp:57784125934 tag:ATOMP_FS channel:0x00 frame:7 vi_tstamp:1949548951 data:0x00000000
     kworker/0:1-1428  [000] ...1  1844.751341: rtcpu_vinotify_handle_msg: tstamp:57784130908 tag:CHANSEL_LOAD_FRAMED channel:0x20 frame:7 vi_tstamp:1949555191 data:0x08000000
     kworker/0:1-1428  [000] ...1  1844.751342: rtcpu_vinotify_handle_msg: tstamp:57784131005 tag:CHANSEL_LOAD_FRAMED channel:0x10 frame:7 vi_tstamp:1949555322 data:0x18000000
     kworker/0:1-1428  [000] ...1  1844.751343: rtcpu_vinotify_handle_msg: tstamp:57784131107 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:7 vi_tstamp:1949555444 data:0x28000000

It’s could be the MIPI timing issue. Please try set the sensor output as discontinuous/continuous mode to try.
If still can’t fixed you need to check the MIPI timing. You can find the detail from the MIPI spec

The sensor was already outputting a continuous clock.

Do you really think it’s a timing issue even though I see the failure on 1of 4 cameras about 50% of the time?

And the problem seems to be due to initialization. Once streaming successfully starts it remains working. If it doesn’t work from the start it will continue failing until restarting the capture sequence.

How about try discontinuous clock mode. Most of this issue is caused by timing.

I will try adjusting the timing parameters. Do you have any more details as to what timings I should focus on that would cause missing SOF?

You can check the MIPI spec for the timing.

Interesting observation:

Two single lane MIPI cameras. One on CSI_A the other CSI_B

Start CSI_A, wait one second, start CSI_B -> PXL_SOF error on CSI_A (note: error starts on opposite camera than most recently started)
Try other way:
Start CSI_B, wait one second, start CSI_A -> capture completes with no errors

Similar results with CSI_E/CSI_F

I found two contributing factors to my problem.

  1. In the case where I start one capture, then another one a while later, I found the problem was in ./drivers/media/platform/tegra/camera/csi/csi4_fops.c: csi4_mipi_cal()

Here there are cases for if (chan->numlanes == 2){} and else{}

Now, I have two single lane CSI devices attached.

When I start the second camera, the call to
csi4_phy_write(chan, port >> 1, addr, cila) is causing a problem and stopping the capture of the other channel.

  1. After working around 1) I found a timing issue where simultaneous capture inits are causing race conditions in csi4_phy_config().
    Here we have two threads, both accessing the same phy. I haven’t been able to reproduce the problem after I put a mutex around the accesses to these phy registers.

@phabsch
Did you use 28.1? Have you check with the 28.2?
Could you post your modification here for this forum user reference.

Hello

I’m checking mipi timing issue too.
Could you tell me where can I find it’s timing spec? I want know it’s actual specification value.
I saw similar table in Parker TRM (Chapter “24: Mipi Display Serial Interface(DSI)” - “24.13 Physical Interface Timing Registers”)
But I don’t know it is same with CSI spec.

You should find the MIPI D-PHY spec