MIPI CSi frame rate issue

We use UB964 connect with TX2. Our sensor frame rate is 25 fps. But after TX2 CSI interface, our test result is 12.5 fps.

We have mereament MIPI clk rate is 25 fps.

We use v4l-ctl & yavta to do testing. Both return frame rate is 12.5 fps. How could cause this problem?

Try to boost the clock to try.

sudo ./jetson_clocks.sh
sudo su
echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate
echo max_rate > /sys/kernel/debug/bpmp/debug/clk/vi/rate

You mean this?

13  echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
   14  cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate
   15  echo max_rate > /sys/kernel/debug/bpmp/debug/clk/vi/rate
   16  echo 1036800000 > /sys/kernel/debug/bpmp/debug/clk/vi/rate

Still doesn’t work.

See below

:~$ v4l2-ctl -d /dev/video0 --set-fmt-video=width=2560,height=720,pixelformat=RG12 --stream-mmap --stream-count=100 --stream-to=test.raw<<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<

How about don’t dump file?

v4l2-ctl -d /dev/video0 --set-fmt-video=width=2560,height=720,pixelformat=RG12 --stream-mmap --stream-count=100

Still seem result.

~$ sudo v4l2-ctl -d /dev/video0 --set-fmt-video=width=2560,height=720,pixelformat=RG12 --stream-mmap --stream-count=100
<<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<<< 12.50 fps
<<<<<<<<<<<

I am also start to debug tegra_channel_kthread_capture_start function.

static int tegra_channel_kthread_capture_start(void *data)
  {
      struct tegra_channel *chan = data;
      struct tegra_channel_buffer *buf;
      int err = 0; 
  
      set_freezable();
  
      while (1) {
  
          try_to_freeze();
  
          wait_event_interruptible(chan->start_wait,
                       !list_empty(&chan->capture) ||
                       kthread_should_stop());
  
          if (kthread_should_stop())
              break;
  
          /* source is not streaming if error is non-zero */
          /* wait till kthread stop and dont DeQ buffers */
          if (err)
              continue;

          buf = dequeue_buffer(chan);
          if (!buf)
              continue;

          err = tegra_channel_capture_frame(chan, buf);
      }    

      return 0;
  }

Found when do dump image, while (1) loop interval time is 80ms not 40ms.
Can you give me some clue to fix this issue?

If you boost the clock still can’t get improve, then I think the problem is the sensor output problem.

@ShaneCCC As mentioned before, we have did measurement MIPI CLK (Discontinuous mode). The interval time is actually 40ms, not 80ms.

We have SCOPE picture, you can get it from #5 attachment 671900850.jpg.

hello 53216142,

you might dig into the VI driver to check the capture events trigger timing.
could you please add debug messages to check each syncpt wait period.
for example,
/kernel_src/kernel/kernel-4.4/drivers/media/platform/tegra/camera/vi/vi4_fops.c

/*
         * Wait for PXL_SOF syncpt
         *
         * Use the syncpt max value we just set as threshold
         */
        for (i = 0; i < chan->valid_ports; i++) {
                err = nvhost_syncpt_wait_timeout_ext(chan->vi->ndev,
                                chan->syncpt[i][SOF_SYNCPT_IDX], thresh[i],
                                250, NULL, NULL);

Does this scope is between UB964 and Tegra CSI?
Could you also probe the MIPI data and clock.

@JerryChang Do you mean this?

/*
       * Wait for PXL_SOF syncpt
       *
       * Use the syncpt max value we just set as threshold                                                                                            
       */
      for (i = 0; i < chan->valid_ports; i++) {
          ts_a = current_kernel_time();
          err = nvhost_syncpt_wait_timeout_ext(chan->vi->ndev,
                  chan->syncpt[i][SOF_SYNCPT_IDX], thresh[i],
                  250, NULL, NULL);
          ts_b = current_kernel_time();
      dev_dbg(&chan->video.dev,
                  "fun %s line %d port %d period %d \n",__func__, __LINE__, i,
                  (ts_b.tv_sec - ts_a.tv_sec)*1000+(ts_b.tv_nsec - ts_a.tv_nsec)/1000000);

@ShaneCCC Yes, the scope between UB964 and Tegra CSI.

I have only take picture of MIPI clock as 671900850.jpg showing.
About MIPI data I remember the frequency is correct(18KHZ the line frequency of 1280*720?). Because I can download correct image picture. Except frame rate is half now!

hello 53216142,

yes, sync-point of PXL_SOF is sending, and waiting for each frame start.
this function timing roughly close to frame processing time of your sensor hardware.
since your sensor frame rate is 25-fps, you should expect nvhost_syncpt_wait_timeout_ext() taking ~40ms here.
looking forward your evaluation results.
thanks

@JerryChange Here is the reuslts. Any useful info. Or if you have any concern I can insert more debug info as needed.

[   56.758696] video4linux video0: fun vi_notify_wait line 217 port 0 period 43ms  
[   56.838789] video4linux video0: fun vi_notify_wait line 217 port 0 period 39ms  
[   56.918872] video4linux video0: fun vi_notify_wait line 217 port 0 period 35ms  
[   56.998959] video4linux video0: fun vi_notify_wait line 217 port 0 period 31ms  
[   57.079051] video4linux video0: fun vi_notify_wait line 217 port 0 period 27ms  
[   57.159191] video4linux video0: fun vi_notify_wait line 217 port 0 period 23ms  
[   57.239254] video4linux video0: fun vi_notify_wait line 217 port 0 period 23ms  
[   57.319336] video4linux video0: fun vi_notify_wait line 217 port 0 period 27ms

hello 53216142,

it surprise me that your syncpt wait returning within 1/fps,
could you please share more details about what’s your environment settings,
for example,

  1. which JetPack release you’re working with.
  2. what’s additional patches you had applied.

below function indicate the actual frame buffer sending to user-space,
please also add some debug messages to check each frame timing here,
thanks

void free_ring_buffers(struct tegra_channel *chan, int frames)
{
...
                vb2_buffer_done(&vbuf->vb2_buf,
                        chan->buffer_state[chan->free_index++]);

JerryChange,
My JetPack tag is tegra-l4t-r28.2.1. For now I didn’t apply any patch. And sure I will apply Jul26_topic1037809.tar.gz laster as you mentioned.
My result is within 1/fps, I guess it maybe caused by compiler FP issue. After test point an function start and end, the period roughly like below. tegra_channel_kthread_capture_start is calculated between two while loop. As you can see vi_notify_wait is about 40ms but tegra_channel_kthread_capture_start extend to 80 ms.

BTW free_ring_buffers is defined in which file, I cannot found it with kernel source code.
I will do some optimize with my test code. And will let you know the new test result for period.

tegra_channel_kthread_capture_start(83ms)-->
    try_to_freeze (11ms)
    wait_event_interruptible(0ms)
    kthread_should_stop(0ms)
    dequeue_buffer(0ms)
    tegra_channel_capture_frame(56ms)-->
        vi_notify_wait(39ms)

@JerryChange
After clear my own test code.
nvhost_syncpt_wait_timeout_ext cost about 75999ns. What is the root cause?

Some of my configuration is incorrect?

After more dig, I found some issue below.
Our signal flow is OV490(1280*720 YUV)–>TI964(MIPI CSI)–>TX2.
OV490 fps is 25. And TI964 is configure as reg(0x71)=0x021 which mean RAW12 mode. And the line Length is detected as 0xf00=3840.

For TX2, FRAME_X(0x30)=2560 FRAME_Y(0x34)=720 PIXFMT_FORMAT(0x84)=0x32.

Whether my own tx2 or ti964 configuration issue cause this problem?

@JerryChang @ShaneCCC Any comment on my latest reply?
Except TRM, whether has more detail document to describe SOF&FRAME_X&FRAME_Y&PIXFMT_FORMAT relationship ?

That means vi/csi get the frame start every 759999ns, Can TI964 gentest pattern for test?

@JerryChang @ShaneCCC
964 test pattern is YUV format. After do some research within form, I found default TX2 BSP don’t support YUV sensor. Therefore so far I cannot get video stream with MIPI CSI for 964 test pattern. Does anybody know how to make YUV test pattern work for TX2?

Furthermore, I have measured both YUV test pattern and OV490+964 MIPI output signal.
I found YUV test pattern has two glitches located at active video start(SOF) and end(EOF) point. But there are only one glitch OV490+964 MIPI at start of active video. I also enlarge this only glitch than I get two glitches. Does that mean OV490+964 MIPI generate SOF and EOF very close? See the attached signal picture.

As mentioned before, I can get correct image picture with half frame rate. But after cat trace, I found below output. Seems there are some rtos_queue_peek_from_isr_failed error. Maybe this is the root cause? Is there any useful info for debug?

What is right trace out if there is nothing wrong? Can you share with me?

worker@slave:~$ sudo cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 257/257   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
 irq/55-tegra_rt-155   [004] ....  1802.371610: tegra_rtc_irq_handler: tegra_rtc_irq_handler: irq time 1455209880727
 irq/55-tegra_rt-155   [004] ....  1802.644606: tegra_rtc_irq_handler: tegra_rtc_irq_handler: irq time 1455209881000
     kworker/0:1-4939  [000] ...1  1811.416100: rtos_queue_peek_from_isr_failed: tstamp:56835225461 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1811.416104: rtcpu_start: tstamp:56835226389
     kworker/0:1-4939  [000] ...1  1811.572108: rtcpu_vinotify_handle_msg: tstamp:56839890171 tag:CSIMUX_STREAM channel:0xff frame:0 vi_tstamp:1005314908 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.572113: rtos_queue_peek_from_isr_failed: tstamp:56840226305 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1811.624110: rtcpu_vinotify_handle_msg: tstamp:56840664447 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1006089046 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.624111: rtcpu_vinotify_handle_msg: tstamp:56840664595 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1006089051 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.624112: rtcpu_vinotify_handle_msg: tstamp:56840868316 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1006293057 data:0x08000000
     kworker/0:1-4939  [000] ...1  1811.624113: rtcpu_vinotify_handle_msg: tstamp:56841653108 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1007077837 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1811.624114: rtcpu_vinotify_handle_msg: tstamp:56841903564 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1007328255 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.676151: rtcpu_vinotify_handle_msg: tstamp:56843168365 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1008592968 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.676156: rtcpu_vinotify_handle_msg: tstamp:56843168512 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1008592974 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.676158: rtcpu_vinotify_handle_msg: tstamp:56843450735 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1008875447 data:0x08000000
     kworker/0:1-4939  [000] ...1  1811.728162: rtcpu_vinotify_handle_msg: tstamp:56844157045 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1009581760 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1811.728166: rtcpu_vinotify_handle_msg: tstamp:56844407503 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1009832177 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.728170: rtos_queue_peek_from_isr_failed: tstamp:56845226855 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1811.780126: rtcpu_vinotify_handle_msg: tstamp:56845670917 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1011095516 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.780132: rtcpu_vinotify_handle_msg: tstamp:56845671101 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1011095522 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.780133: rtcpu_vinotify_handle_msg: tstamp:56845964961 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1011389681 data:0x08000000
     kworker/0:1-4939  [000] ...1  1811.780134: rtcpu_vinotify_handle_msg: tstamp:56846659577 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1012084307 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1811.780136: rtcpu_vinotify_handle_msg: tstamp:56846910049 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1012334725 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.832138: rtcpu_vinotify_handle_msg: tstamp:56848173475 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1013598064 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.832141: rtcpu_vinotify_handle_msg: tstamp:56848173659 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1013598070 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.832142: rtcpu_vinotify_handle_msg: tstamp:56848426983 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1013851708 data:0x08000000
     kworker/0:1-4939  [000] ...1  1811.884123: rtcpu_vinotify_handle_msg: tstamp:56849162141 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1014586855 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1811.884125: rtcpu_vinotify_handle_msg: tstamp:56849412601 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1014837273 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.884129: rtos_queue_peek_from_isr_failed: tstamp:56850227332 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1811.936142: rtcpu_vinotify_handle_msg: tstamp:56850676024 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1016100612 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.936146: rtcpu_vinotify_handle_msg: tstamp:56850676208 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1016100618 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.936148: rtcpu_vinotify_handle_msg: tstamp:56850911523 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1016336243 data:0x08000000
     kworker/0:1-4939  [000] ...1  1811.936149: rtcpu_vinotify_handle_msg: tstamp:56851664690 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1017089402 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1811.936151: rtcpu_vinotify_handle_msg: tstamp:56851915153 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1017339821 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.988142: rtcpu_vinotify_handle_msg: tstamp:56853178573 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1018603161 data:0x00000001
     kworker/0:1-4939  [000] ...1  1811.988146: rtcpu_vinotify_handle_msg: tstamp:56853178757 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1018603165 data:0x00000000
     kworker/0:1-4939  [000] ...1  1811.988147: rtcpu_vinotify_handle_msg: tstamp:56853427137 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1018851863 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.040129: rtcpu_vinotify_handle_msg: tstamp:56854167239 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1019591952 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.040132: rtcpu_vinotify_handle_msg: tstamp:56854417694 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1019842370 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.040135: rtos_queue_peek_from_isr_failed: tstamp:56855227840 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1812.092124: rtcpu_vinotify_handle_msg: tstamp:56855681118 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1021105709 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.092127: rtcpu_vinotify_handle_msg: tstamp:56855681304 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1021105714 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.092128: rtcpu_vinotify_handle_msg: tstamp:56855914550 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1021339276 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.092129: rtcpu_vinotify_handle_msg: tstamp:56856669784 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1022094500 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.144156: rtcpu_vinotify_handle_msg: tstamp:56856920243 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1022344918 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.144161: rtcpu_vinotify_handle_msg: tstamp:56858183667 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1023608257 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.144163: rtcpu_vinotify_handle_msg: tstamp:56858183851 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1023608263 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.144164: rtcpu_vinotify_handle_msg: tstamp:56858413929 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1023838645 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.196170: rtcpu_vinotify_handle_msg: tstamp:56859172333 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1024597046 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.196174: rtcpu_vinotify_handle_msg: tstamp:56859424168 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1024848840 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.248141: rtos_queue_peek_from_isr_failed: tstamp:56860228346 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1812.248146: rtcpu_vinotify_handle_msg: tstamp:56860687593 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1026112180 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.248147: rtcpu_vinotify_handle_msg: tstamp:56860687787 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1026112184 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.248149: rtcpu_vinotify_handle_msg: tstamp:56860953485 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1026378210 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.248150: rtcpu_vinotify_handle_msg: tstamp:56861676256 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1027100968 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.300157: rtcpu_vinotify_handle_msg: tstamp:56861926717 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1027351389 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.300162: rtcpu_vinotify_handle_msg: tstamp:56863190136 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1028614728 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.300164: rtcpu_vinotify_handle_msg: tstamp:56863190321 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1028614733 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.352130: rtcpu_vinotify_handle_msg: tstamp:56863451940 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1028876667 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.352133: rtcpu_vinotify_handle_msg: tstamp:56864178806 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1029603517 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.352135: rtcpu_vinotify_handle_msg: tstamp:56864429263 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1029853934 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.404145: rtos_queue_peek_from_isr_failed: tstamp:56865228854 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1812.404150: rtcpu_vinotify_handle_msg: tstamp:56865692689 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1031117275 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.404152: rtcpu_vinotify_handle_msg: tstamp:56865692874 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1031117281 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.404153: rtcpu_vinotify_handle_msg: tstamp:56865930659 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1031355383 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.456128: rtcpu_vinotify_handle_msg: tstamp:56866681360 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1032106070 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.456131: rtcpu_vinotify_handle_msg: tstamp:56866931807 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1032356483 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.456133: rtcpu_vinotify_handle_msg: tstamp:56868195234 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1033619822 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.456134: rtcpu_vinotify_handle_msg: tstamp:56868195418 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1033619827 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.508164: rtcpu_vinotify_handle_msg: tstamp:56868430425 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1033855148 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.508168: rtcpu_vinotify_handle_msg: tstamp:56869183904 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1034608617 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.508170: rtcpu_vinotify_handle_msg: tstamp:56869434357 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1034859031 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.560148: rtos_queue_peek_from_isr_failed: tstamp:56870229362 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1812.560153: rtcpu_vinotify_handle_msg: tstamp:56870697784 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1036122370 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.560155: rtcpu_vinotify_handle_msg: tstamp:56870697969 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1036122375 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.560156: rtcpu_vinotify_handle_msg: tstamp:56870947137 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1036371857 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.612135: rtcpu_vinotify_handle_msg: tstamp:56871686449 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1037111165 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.612137: rtcpu_vinotify_handle_msg: tstamp:56871936906 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1037361579 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.664119: rtcpu_vinotify_handle_msg: tstamp:56873200329 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1038624918 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.664121: rtcpu_vinotify_handle_msg: tstamp:56873200514 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1038624923 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.664123: rtcpu_vinotify_handle_msg: tstamp:56873428350 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1038853056 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.664124: rtcpu_vinotify_handle_msg: tstamp:56874189002 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1039613713 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.664125: rtcpu_vinotify_handle_msg: tstamp:56874439451 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1039864125 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.716196: rtos_queue_peek_from_isr_failed: tstamp:56875229869 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1812.716202: rtcpu_vinotify_handle_msg: tstamp:56875704254 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1041128841 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.716203: rtcpu_vinotify_handle_msg: tstamp:56875704440 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1041128846 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.716205: rtcpu_vinotify_handle_msg: tstamp:56875917612 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1041342336 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.768152: rtcpu_vinotify_handle_msg: tstamp:56876692926 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1042117635 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.768156: rtcpu_vinotify_handle_msg: tstamp:56876943375 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1042368048 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.820170: rtcpu_vinotify_handle_msg: tstamp:56878206804 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1043631392 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.820175: rtcpu_vinotify_handle_msg: tstamp:56878206990 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1043631397 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.820178: rtcpu_vinotify_handle_msg: tstamp:56878442306 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1043867027 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.820180: rtcpu_vinotify_handle_msg: tstamp:56879195465 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1044620182 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.820181: rtcpu_vinotify_handle_msg: tstamp:56879445924 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1044870595 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.872135: rtos_queue_peek_from_isr_failed: tstamp:56880230376 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1812.872139: rtcpu_vinotify_handle_msg: tstamp:56880709351 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1046133940 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.872141: rtcpu_vinotify_handle_msg: tstamp:56880709544 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1046133946 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.872142: rtcpu_vinotify_handle_msg: tstamp:56880941725 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1046366445 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.924132: rtcpu_vinotify_handle_msg: tstamp:56881698015 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1047122730 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.924134: rtcpu_vinotify_handle_msg: tstamp:56881948469 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1047373141 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.976149: rtcpu_vinotify_handle_msg: tstamp:56883211900 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1048636487 data:0x00000001
     kworker/0:1-4939  [000] ...1  1812.976152: rtcpu_vinotify_handle_msg: tstamp:56883212083 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1048636492 data:0x00000000
     kworker/0:1-4939  [000] ...1  1812.976154: rtcpu_vinotify_handle_msg: tstamp:56883420504 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1048845223 data:0x08000000
     kworker/0:1-4939  [000] ...1  1812.976155: rtcpu_vinotify_handle_msg: tstamp:56884200561 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1049625276 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1812.976157: rtcpu_vinotify_handle_msg: tstamp:56884451015 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1049875690 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.028148: rtos_queue_peek_from_isr_failed: tstamp:56885230880 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1813.028152: rtcpu_vinotify_handle_msg: tstamp:56885714448 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1051139033 data:0x00000001
     kworker/0:1-4939  [000] ...1  1813.028154: rtcpu_vinotify_handle_msg: tstamp:56885714632 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1051139038 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.028155: rtcpu_vinotify_handle_msg: tstamp:56885926246 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1051350970 data:0x08000000
     kworker/0:1-4939  [000] ...1  1813.080127: rtcpu_vinotify_handle_msg: tstamp:56886703114 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1052127824 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1813.080129: rtcpu_vinotify_handle_msg: tstamp:56886953568 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1052378242 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.132140: rtcpu_vinotify_handle_msg: tstamp:56888216990 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1053641581 data:0x00000001
     kworker/0:1-4939  [000] ...1  1813.132142: rtcpu_vinotify_handle_msg: tstamp:56888217174 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1053641586 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.132143: rtcpu_vinotify_handle_msg: tstamp:56888425947 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1053850667 data:0x08000000
     kworker/0:1-4939  [000] ...1  1813.132144: rtcpu_vinotify_handle_msg: tstamp:56889205667 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1054630376 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1813.184158: rtcpu_vinotify_handle_msg: tstamp:56889456115 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1054880788 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.184164: rtos_queue_peek_from_isr_failed: tstamp:56890231389 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1813.184166: rtcpu_vinotify_handle_msg: tstamp:56890719539 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1056144126 data:0x00000001
     kworker/0:1-4939  [000] ...1  1813.184167: rtcpu_vinotify_handle_msg: tstamp:56890719725 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1056144132 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.184171: rtcpu_vinotify_handle_msg: tstamp:56890929471 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1056354194 data:0x08000000
     kworker/0:1-4939  [000] ...1  1813.236148: rtcpu_vinotify_handle_msg: tstamp:56891708208 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1057132922 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1813.236152: rtcpu_vinotify_handle_msg: tstamp:56891960038 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1057384711 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.288164: rtcpu_vinotify_handle_msg: tstamp:56893223468 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1058648055 data:0x00000001
     kworker/0:1-4939  [000] ...1  1813.288169: rtcpu_vinotify_handle_msg: tstamp:56893223653 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1058648061 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.288172: rtcpu_vinotify_handle_msg: tstamp:56893432475 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1058857200 data:0x08000000
     kworker/0:1-4939  [000] ...1  1813.288173: rtcpu_vinotify_handle_msg: tstamp:56894212135 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1059636844 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1813.340159: rtcpu_vinotify_handle_msg: tstamp:56894462585 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1059887257 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.340166: rtos_queue_peek_from_isr_failed: tstamp:56895231896 queue:0x0b4a3c58
     kworker/0:1-4939  [000] ...1  1813.340167: rtcpu_vinotify_handle_msg: tstamp:56895726018 tag:CHANSEL_PXL_SOF channel:0x00 frame:3 vi_tstamp:1061150601 data:0x00000001
     kworker/0:1-4939  [000] ...1  1813.340170: rtcpu_vinotify_handle_msg: tstamp:56895726232 tag:ATOMP_FS channel:0x00 frame:3 vi_tstamp:1061150606 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.392150: rtcpu_vinotify_handle_msg: tstamp:56895944744 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:3 vi_tstamp:1061369470 data:0x08000000
     kworker/0:1-4939  [000] ...1  1813.392153: rtcpu_vinotify_handle_msg: tstamp:56896714675 tag:CHANSEL_PXL_EOF channel:0x00 frame:3 vi_tstamp:1062139391 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1813.392154: rtcpu_vinotify_handle_msg: tstamp:56896965136 tag:ATOMP_FE channel:0x00 frame:3 vi_tstamp:1062389809 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.444164: rtcpu_vinotify_handle_msg: tstamp:56898228559 tag:CHANSEL_PXL_SOF channel:0x00 frame:1 vi_tstamp:1063653147 data:0x00000001
     kworker/0:1-4939  [000] ...1  1813.444167: rtcpu_vinotify_handle_msg: tstamp:56898228744 tag:ATOMP_FS channel:0x00 frame:1 vi_tstamp:1063653153 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.444169: rtcpu_vinotify_handle_msg: tstamp:56898440549 tag:CHANSEL_LOAD_FRAMED channel:0x01 frame:1 vi_tstamp:1063865276 data:0x08000000
     kworker/0:1-4939  [000] ...1  1813.496187: rtcpu_vinotify_handle_msg: tstamp:56899217227 tag:CHANSEL_PXL_EOF channel:0x00 frame:1 vi_tstamp:1064641942 data:0x02cf0002
     kworker/0:1-4939  [000] ...1  1813.496191: rtcpu_vinotify_handle_msg: tstamp:56899467680 tag:ATOMP_FE channel:0x00 frame:1 vi_tstamp:1064892355 data:0x00000000
     kworker/0:1-4939  [000] ...1  1813.496196: rtos_queue_peek_from_isr_failed: tstamp:56900232401 queue:0x0b4a3c58