Camera driver doesn't work over GMSL

akhil.veeraghanta · March 4, 2023, 2:34am

We have an omnivision sensor, for which we wrote a camera driver that works just fine over MIPI.

When we plug the same camera into the serdes pair (MAX9295 ↔ MAX9296), it stops working with the following error

     kworker/1:3-1781  [001] ....   154.537183: rtcpu_vinotify_event: tstamp:4983168766 tag:FE channel:0x00 frame:0 vi_tstamp:4982877829 data:0x00000020                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.537185: rtcpu_vinotify_event: tstamp:4983168924 tag:FS channel:0x00 frame:0 vi_tstamp:4982917174 data:0x00000010                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.537187: rtcpu_vinotify_event: tstamp:4983169063 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4982919096 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.588149: rtcpu_vinotify_error: tstamp:4983961199 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4983960358 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.588152: rtcpu_vinotify_event: tstamp:4984185954 tag:FE channel:0x00 frame:0 vi_tstamp:4983919092 data:0x00000020                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.588154: rtcpu_vinotify_event: tstamp:4984186092 tag:FS channel:0x00 frame:0 vi_tstamp:4983958436 data:0x00000010                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.588156: rtcpu_vinotify_event: tstamp:4984186254 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4983960358 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.588159: rtcpu_vinotify_error: tstamp:4985002482 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4985001621 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.588160: rtcpu_vinotify_event: tstamp:4985002804 tag:FE channel:0x00 frame:0 vi_tstamp:4984960354 data:0x00000020                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.588162: rtcpu_vinotify_event: tstamp:4985002962 tag:FS channel:0x00 frame:0 vi_tstamp:4984999699 data:0x00000010                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.588164: rtcpu_vinotify_event: tstamp:4985003098 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4985001621 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.639146: rtcpu_vinotify_event: tstamp:4986017131 tag:FE channel:0x00 frame:0 vi_tstamp:4986001617 data:0x00000020                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.639149: rtcpu_vinotify_error: tstamp:4986043727 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4986042884 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.639151: rtcpu_vinotify_event: tstamp:4986356166 tag:FS channel:0x00 frame:0 vi_tstamp:4986040961 data:0x00000010                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.639153: rtcpu_vinotify_event: tstamp:4986356325 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4986042884 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.690145: rtcpu_vinotify_error: tstamp:4987084988 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:4987084146 data:0x00000589                                                                                                                     
     kworker/1:3-1781  [001] ....   154.690148: rtcpu_vinotify_event: tstamp:4987373354 tag:FE channel:0x00 frame:0 vi_tstamp:4987042880 data:0x00000020                                                                                                                                  
     kworker/1:3-1781  [001] ....   154.690150: rtcpu_vinotify_event: tstamp:4987373511 tag:FS channel:0x00 frame:0 vi_tstamp:4987082223 data:0x00000010

We’ve tried all the debugging tips here: Jetson/l4t/Camera BringUp - eLinux.org
We’ve also set the embedded_data_height correctly because it works on the other board
I’m also not configuring any virtual channel to data type remapping on the MAX929* chips

I would appreciate any tips on what could be wrong here? Thanks!

Update

The embedded data was somehow getting dropped over the GMSL link (the driver is exactly the same in the two setups, we configure GMSL through a userspace program), not really sure how thats happening. Setting embedded_data_height to zero allows me to get a couple frames through

  34      kworker/1:1-620   [001] ....   350.371593: rtcpu_vinotify_event: tstamp:10822169549 tag:FS channel:0x00 frame:0 vi_tstamp:10821840302 data:0x00000010                                                                                                                           
  33      kworker/1:1-620   [001] ....   350.371594: rtcpu_vinotify_event: tstamp:10822169715 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:10821840303 data:0x00000000                                                                                                                     
  32      kworker/1:1-620   [001] ....   350.371594: rtcpu_vinotify_event: tstamp:10822169860 tag:CHANSEL_PXL_SOF channel:0x22 frame:0 vi_tstamp:10821842225 data:0x00000001                                                                                                              
  31      kworker/1:1-620   [001] ....   350.371594: rtcpu_vinotify_event: tstamp:10822170026 tag:RESERVED_19 channel:0x22 frame:0 vi_tstamp:11291503200 data:0x08020033                                                                                                                  
  30      kworker/1:1-620   [001] ....   350.371596: rtcpu_vinotify_event: tstamp:10822847734 tag:CHANSEL_PXL_EOF channel:0x22 frame:0 vi_tstamp:10822840580 data:0x086f0002                                                                                                              
  29      kworker/1:1-620   [001] ....   350.371596: rtcpu_vinotify_event: tstamp:10822847897 tag:ATOMP_FRAME_DONE channel:0x22 frame:0 vi_tstamp:10822840596 data:0x00000000                                                                                                             
  28      kworker/1:1-620   [001] ....   350.371596: rtcpu_vinotify_event: tstamp:10822848035 tag:RESERVED_19 channel:0x22 frame:0 vi_tstamp:11323451424 data:0x02020033                                                                                                                  
  27      kworker/1:1-620   [001] ....   350.371597: rtcpu_vinotify_event: tstamp:10822848194 tag:FE channel:0x00 frame:0 vi_tstamp:10822842225 data:0x00000020                                                                                                                           
  26      kworker/1:1-620   [001] ....   350.371597: rtcpu_vinotify_event: tstamp:10822848334 tag:ATOMP_FE channel:0x00 frame:0 vi_tstamp:10822842226 data:0x00000000                                                                                                                     
  25      kworker/1:1-620   [001] ....   350.371597: rtcpu_vinotify_event: tstamp:10822848491 tag:RESERVED_19 channel:0x22 frame:0 vi_tstamp:11323505792 data:0x00020033                                                                                                                  
  24      kworker/1:1-620   [001] ....   350.371597: rtcpu_vinotify_event: tstamp:10822848627 tag:RESERVED_19 channel:0x22 frame:0 vi_tstamp:11323511104 data:0x07020034                                                                                                                  
  23      kworker/1:1-620   [001] ....   350.371598: rtcpu_vinotify_event: tstamp:10822884768 tag:FS channel:0x00 frame:0 vi_tstamp:10822881569 data:0x00000010                                                                                                                           
  22      kworker/1:1-620   [001] ....   350.371598: rtcpu_vinotify_event: tstamp:10822884911 tag:ATOMP_FS channel:0x00 frame:0 vi_tstamp:10822881570 data:0x00000000                                                                                                                     
  21      kworker/1:1-620   [001] ....   350.371598: rtcpu_vinotify_event: tstamp:10822885069 tag:CHANSEL_PXL_SOF channel:0x22 frame:0 vi_tstamp:10822883493 data:0x00000001                                                                                                              
  20      kworker/1:1-620   [001] ....   350.371599: rtcpu_vinotify_event: tstamp:10822885204 tag:RESERVED_19 channel:0x22 frame:0 vi_tstamp:11324823776 data:0x08020034

But it eventually falls back to the same problem

 11      kworker/1:3-1640  [001] ....   258.423567: rtcpu_vinotify_error: tstamp:8225677731 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8225676280 data:0x00000589 
 12      kworker/1:3-1640  [001] ....   258.423568: rtcpu_vinotify_event: tstamp:8225788702 tag:FE channel:0x00 frame:0 vi_tstamp:8225635013 data:0x00000020 
 13      kworker/1:3-1640  [001] ....   258.423569: rtcpu_vinotify_event: tstamp:8225788861 tag:FS channel:0x00 frame:0 vi_tstamp:8225674357 data:0x00000010 
 14      kworker/1:3-1640  [001] ....   258.423570: rtcpu_vinotify_event: tstamp:8225789000 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8225676280 data:0x00000589 
 15      kworker/1:3-1640  [001] ....   258.423571: rtcpu_vinotify_event: tstamp:8226716831 tag:FE channel:0x00 frame:0 vi_tstamp:8226676278 data:0x00000020 
 16      kworker/1:3-1640  [001] ....   258.423572: rtcpu_vinotify_event: tstamp:8226716969 tag:FS channel:0x00 frame:0 vi_tstamp:8226715622 data:0x00000010 
 17      kworker/1:3-1640  [001] ....   258.423573: rtcpu_vinotify_error: tstamp:8226718675 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8226717544 data:0x00000589 
 18      kworker/1:3-1640  [001] ....   258.423574: rtcpu_vinotify_event: tstamp:8227020163 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8226717544 data:0x00000589 
 19      kworker/1:3-1640  [001] ....   258.423575: rtcpu_vinotify_error: tstamp:8227760259 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8227758809 data:0x00000589 
 20      kworker/1:3-1640  [001] ....   258.423576: rtcpu_vinotify_event: tstamp:8228019372 tag:FE channel:0x00 frame:0 vi_tstamp:8227717542 data:0x00000020 
 21      kworker/1:3-1640  [001] ....   258.423577: rtcpu_vinotify_event: tstamp:8228019530 tag:FS channel:0x00 frame:0 vi_tstamp:8227756886 data:0x00000010 
 22      kworker/1:3-1640  [001] ....   258.423578: rtcpu_vinotify_event: tstamp:8228019669 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8227758809 data:0x00000589 
 23      kworker/1:3-1640  [001] ....   258.525470: rtcpu_vinotify_event: tstamp:8230016731 tag:FE channel:0x00 frame:0 vi_tstamp:8229800073 data:0x00000020 
 24      kworker/1:3-1640  [001] ....   258.525474: rtcpu_vinotify_event: tstamp:8230016892 tag:FS channel:0x00 frame:0 vi_tstamp:8229839417 data:0x00000010 
 25      kworker/1:3-1640  [001] ....   258.525475: rtcpu_vinotify_event: tstamp:8230017032 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8229841339 data:0x00000589 
 26      kworker/1:3-1640  [001] ....   258.525478: rtcpu_vinotify_error: tstamp:8230884053 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8230882604 data:0x00000589 
 27      kworker/1:3-1640  [001] ....   258.525484: rtcpu_vinotify_event: tstamp:8231015617 tag:FE channel:0x00 frame:0 vi_tstamp:8230841337 data:0x00000020 
 28      kworker/1:3-1640  [001] ....   258.525485: rtcpu_vinotify_event: tstamp:8231015756 tag:FS channel:0x00 frame:0 vi_tstamp:8230880681 data:0x00000010 
 29      kworker/1:3-1640  [001] ....   258.525486: rtcpu_vinotify_event: tstamp:8231015915 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8230882604 data:0x00000589 
 30      kworker/1:3-1640  [001] ....   258.576467: rtcpu_vinotify_error: tstamp:8231925380 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8231923868 data:0x00000589 
 31      kworker/1:3-1640  [001] ....   258.576471: rtcpu_vinotify_event: tstamp:8231925692 tag:FE channel:0x00 frame:0 vi_tstamp:8231882602 data:0x00000020
 32      kworker/1:3-1640  [001] ....   258.576473: rtcpu_vinotify_event: tstamp:8231925853 tag:FS channel:0x00 frame:0 vi_tstamp:8231921946 data:0x00000010
 33      kworker/1:3-1640  [001] ....   258.576474: rtcpu_vinotify_event: tstamp:8231925989 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8231923868 data:0x00000589
 34      kworker/1:3-1640  [001] ....   258.576475: rtcpu_vinotify_event: tstamp:8232946282 tag:FE channel:0x00 frame:0 vi_tstamp:8232923867 data:0x00000020
 35      kworker/1:3-1640  [001] ....   258.576476: rtcpu_vinotify_error: tstamp:8232966220 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8232965133 data:0x00000589
 36      kworker/1:3-1640  [001] ....   258.627478: rtcpu_vinotify_event: tstamp:8233279617 tag:FS channel:0x00 frame:0 vi_tstamp:8232963211 data:0x00000010
 37      kworker/1:3-1640  [001] ....   258.627480: rtcpu_vinotify_event: tstamp:8233279782 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8232965133 data:0x00000589
 38      kworker/1:3-1640  [001] ....   258.627481: rtcpu_vinotify_error: tstamp:8234007847 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8234006399 data:0x00000589
 39      kworker/1:3-1640  [001] ....   258.627482: rtcpu_vinotify_event: tstamp:8234278462 tag:FE channel:0x00 frame:0 vi_tstamp:8233965131 data:0x00000020
 40      kworker/1:3-1640  [001] ....   258.627483: rtcpu_vinotify_event: tstamp:8234278620 tag:FS channel:0x00 frame:0 vi_tstamp:8234004475 data:0x00000010
 41      kworker/1:3-1640  [001] ....   258.627484: rtcpu_vinotify_event: tstamp:8234278758 tag:CHANSEL_NOMATCH channel:0x01 frame:0 vi_tstamp:8234006399 data:0x00000589

the frame number doesn’t seem to increment at all, would that be an issue as well? With just one camera, I can get a consistent “stream” of just frame 0. Its always the same data though

Thanks in advance!

JerryChang · March 6, 2023, 8:36am

hello akhil.veeraghanta,

please ignore those CHANSEL_NOMATCH messages,
are you able to see camera frames by disabling embedded metadata?

please try below commands to boost all the VI/CSI/ISP clocks.
for example,

sudo su
echo 1 > /sys/kernel/debug/bpmp/debug/clk/vi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/isp/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/nvcsi/mrq_rate_locked
echo 1 > /sys/kernel/debug/bpmp/debug/clk/emc/mrq_rate_locked

cat /sys/kernel/debug/bpmp/debug/clk/vi/max_rate |tee /sys/kernel/debug/bpmp/debug/clk/vi/rate
cat /sys/kernel/debug/bpmp/debug/clk/isp/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/isp/rate
cat /sys/kernel/debug/bpmp/debug/clk/nvcsi/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/nvcsi/rate
cat /sys/kernel/debug/bpmp/debug/clk/emc/max_rate | tee /sys/kernel/debug/bpmp/debug/clk/emc/rate

akhil.veeraghanta · March 6, 2023, 4:35pm

Hey Jerry, thanks for the response

Yeah I have tried that as well, disabling embedded metadata does let 1 frame through, but its always stuck on frame 0 and it still errors out after ~5/6 seconds of streaming

JerryChang · March 7, 2023, 5:21am

hello akhil.veeraghanta,

had you boost all the VI/CSI/ISP clocks for testing?
could you please double check VI tracing logs, is the frame number still keep at zero? you may try review the SerDes chip to issue frame counts.

akhil.veeraghanta · March 7, 2023, 5:56pm

yeah I did boost all clocks and the frame number is still zero

does the frame number come from the camera/serdes or does anything on nvidias side increment the frame number?

and if the frame number doesn’t increment, does the tegra vi system timeout?

[80.735002] fence timeout on [ffffffc181052b40] after 1500ms
[80.735007] tegra194-vi5 15c10000.vi: no reply from camera processor

I see this after boosting clocks + receiving a bunch of valid frames with frame number 0

JerryChang · March 8, 2023, 1:54am

hello akhil.veeraghanta,

frame counts came from serdes side.

by checking your logs, it seems FS/FE that’s actually sending out.
however, the issue you seen, i.e. no reply from camera processor. that’s due to VI engine cannot recognize start-of-frame within 1500ms.

questions…

as you could get couple frames by setting embedded_data_height to zero. what’s the tracing logs look like from the beginning of capture success?
is there any other signals between FE till FS?

system · April 5, 2023, 1:20am

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.