Fake camera low+instable frame rate

Using Aravis
1

Hi,

first of all, thanks a lot for this project. We are currently evaluating using aravis and so far, it looks very promising and especially the interface has been a pleasure to work with. :slight_smile:

I am currently experimenting with arv-fake-gv-camera and seing problems with incomplete frames that I have a hard time understanding. I first thought they were due to my implementation, but now I see the same thing in the arv-viewer.

I start the fake camera like this:
arv-fake-gv-camera-0.8 -s 42 --gvsp-lost-ratio=0

and observe the following:

  • the built-in fake camera in the viewer is fast, without any errors
  • a real TIS camera was performing well, too, without errors (at least as far as I remember, unfortunately I do not have it with me to confirm right now)
  • the fake camera via the loopback interface accumulates many errors when the frame rate is set to more than roughly 5fps. At 5 fps, it sometimes performs without errors but often also has phases where it the frame rate drops and error count increases.
  • What’s confusing to me is that I do not see which resource might be maxed out… neither the viewer nor the fake camera are using a significant amount of cpu, bandwith usage on lo, according to bmon, stays rather constant (1.28MiB/s if set to 5fps – interestingly this does not mirror the frame rate drops)

Does anyone have an idea what this might be about, and can maybe point me in a helpful direction?

2

Hi fedro,

Thanks for the kind words.

The built-in fake camera does not use a physical transport, like ethernet or USB, it is expected to always work.

What hardware are you using ?

Could you try tests/arv-camera-test -d all and paste the end of the console log, where it shows statistics about GigEVision packets ?

3

HI Emmanuel, thanks for your quick reply!

I hope this tells you what you need to know about my hardware:

System:    Kernel: 5.10.4-4.g086fc4c-default x86_64 bits: 64 compiler: N/A Desktop: KDE Plasma 5.18.6 
           Distro: openSUSE Leap 15.2 
Machine:   Type: Laptop System: LENOVO product: 20UDCTO1WW v: ThinkPad T14 Gen 1 serial: <filter> 
           Mobo: LENOVO model: 20UDCTO1WW serial: <filter> UEFI: LENOVO v: R1BET58W(1.27 ) date: 10/20/2020 
Battery:   ID-1: BAT0 charge: 50.6 Wh condition: 51.5/50.5 Wh (102%) model: LGC 5B10W139 status: Unknown 
CPU:       Topology: 8-Core model: AMD Ryzen 7 PRO 4750U with Radeon Graphics bits: 64 type: MT MCP arch: Zen rev: 1 
           L2 cache: 4096 KiB 
           flags: avx avx2 lm nx pae sse sse2 sse3 sse4_1 sse4_2 sse4a ssse3 svm bogomips: 54295 
           Speed: 2232 MHz min/max: 1400/1700 MHz Core speeds (MHz): 1: 2197 2: 1400 3: 1397 4: 1397 5: 1397 6: 1396 7: 1397 
           8: 1397 9: 1512 10: 1397 11: 1766 12: 1397 13: 1506 14: 1841 15: 1397 16: 1397 
Graphics:  Device-1: Advanced Micro Devices [AMD/ATI] Renoir vendor: Lenovo driver: amdgpu v: kernel bus ID: 07:00.0 
           Device-2: Chicony type: USB driver: uvcvideo bus ID: 2-2:2 
           Display: x11 server: X.Org 1.20.3 driver: amdgpu,ati unloaded: fbdev,modesetting,vesa resolution: 1920x1080~60Hz 
           OpenGL: renderer: AMD RENOIR (DRM 3.40.0 5.10.4-4.g086fc4c-default LLVM 9.0.1) v: 4.5 Mesa 19.3.4 
           direct render: Yes 
Audio:     Device-1: Advanced Micro Devices [AMD/ATI] vendor: Lenovo driver: snd_hda_intel v: kernel bus ID: 07:00.1 
           Device-2: Advanced Micro Devices [AMD] Raven/Raven2/FireFlight/Renoir Audio Processor vendor: Lenovo 
           driver: snd_rn_pci_acp3x v: kernel bus ID: 07:00.5 
           Device-3: Advanced Micro Devices [AMD] Family 17h HD Audio vendor: Lenovo driver: snd_hda_intel v: kernel 
           bus ID: 07:00.6 
           Device-4: Sennheiser type: USB driver: hid-generic,snd-usb-audio,usbhid bus ID: 6-2:2 
           Sound Server: ALSA v: k5.10.4-4.g086fc4c-default 
Network:   Device-1: Realtek RTL8111/8168/8411 PCI Express Gigabit Ethernet vendor: Lenovo driver: r8169 v: kernel port: 3400 
           bus ID: 02:00.0 
           IF: eth0 state: down mac: <filter> 
           Device-2: Intel Wi-Fi 6 AX200 driver: iwlwifi v: kernel port: 3000 bus ID: 03:00.0 
           IF: wlan0 state: up mac: <filter> 
           Device-3: Realtek RTL8111/8168/8411 PCI Express Gigabit Ethernet vendor: Lenovo driver: r8169 v: kernel port: 2000 
           bus ID: 05:00.0 
           IF: eth1 state: down mac: <filter> 
           IF-ID-1: tun0 state: unknown speed: 10 Mbps duplex: full mac: N/A 
Drives:    Local Storage: total: 476.94 GiB used: 247.66 GiB (51.9%) 
           ID-1: /dev/nvme0n1 vendor: SK Hynix model: HFS512GD9TNI-L2B0B size: 476.94 GiB 
Partition: ID-1: / size: 333.82 GiB used: 232.67 GiB (69.7%) fs: btrfs dev: /dev/nvme0n1p5 
           ID-2: /home size: 333.82 GiB used: 232.67 GiB (69.7%) fs: btrfs dev: /dev/nvme0n1p5 
           ID-3: /opt size: 333.82 GiB used: 232.67 GiB (69.7%) fs: btrfs dev: /dev/nvme0n1p5 
           ID-4: /tmp size: 333.82 GiB used: 232.67 GiB (69.7%) fs: btrfs dev: /dev/nvme0n1p5 
           ID-5: /var size: 333.82 GiB used: 232.67 GiB (69.7%) fs: btrfs dev: /dev/nvme0n1p5 
Swap:      ID-1: swap-1 type: partition size: 2.00 GiB used: 17.5 MiB (0.9%) dev: /dev/nvme0n1p6 
Sensors:   System Temperatures: cpu: 55.9 C mobo: 0.0 C gpu: amdgpu temp: 46 C 
           Fan Speeds (RPM): cpu: 3300 
Info:      Processes: 420 Uptime: 6h 12m Memory: 30.58 GiB used: 8.92 GiB (29.2%) Init: systemd runlevel: 5 Compilers: 
           gcc: 7.5.0 Shell: bash v: 4.4.23 inxi: 3.1.00

(let me know if you need anything else)

The output in the end of tests/arv-camera-test -d all:

Completed buffers = 3123
Failures          = 2483
Underruns         = 0
  bins  ;Buffer r
       0;    3117
    2000;       2
    4000;       0
    6000;       1
    8000;       1
   10000;       4
   12000;       0
   14000;       1
   16000;       0
   18000;     101
   20000;      53
   22000;       2
   24000;       0
   26000;       1
   28000;       1
   30000;       5
   32000;       4
   34000;       0
   36000;       5
   38000;     917
   40000;    1158
   42000;       8
   44000;       0
   46000;       0
   48000;       0
   50000;       1
   52000;       1
   54000;       1
   56000;       1
   58000;       0
   60000;       0
   62000;       0
   64000;       1
   66000;       1
   68000;       1
   70000;       0
   72000;       0
   74000;       0
   76000;       1
   78000;       1
   80000;       0
   82000;       0
   84000;       0
   86000;       2
   88000;       1
   90000;       0
   92000;       0
   94000;       0
   96000;       0
   98000;       1
  100000;      70
  102000;     137
-------------
>=104000;       0
<      0;       0
min     ;     883
max     ;  103221
last max
at:     ;    3871
Counter =     5472
[GvStream::finalize] n_completed_buffers    = 3123
[GvStream::finalize] n_failures             = 2483
[GvStream::finalize] n_timeouts             = 206
[GvStream::finalize] n_aborteds             = 1
[GvStream::finalize] n_underruns            = 0
[GvStream::finalize] n_missing_frames       = 0
[GvStream::finalize] n_size_mismatch_errors = 0
[GvStream::finalize] n_received_packets     = 1019480
[GvStream::finalize] n_missing_packets      = 178552
[GvStream::finalize] n_error_packets        = 0
[GvStream::finalize] n_ignored_packets      = 0
[GvStream::finalize] n_resend_requests      = 0
[GvStream::finalize] n_resent_packets       = 0
[GvStream::finalize] n_resend_ratio_reached = 0
[GvStream::finalize] n_duplicated_packets   = 0
[Stream::finalize] Flush 49 buffer[s] in input queue
[Stream::finalize] Flush 1 buffer[s] in output queue
4

I don’t understand what is happening here. The number of lost packets is quite high. Fake camera does not support packet resend request for now, which means each missing packet is causing the lost of an image.

On my laptop (Intel® Core™ i5-8365U CPU @ 1.60GHz), I can display a 100Hz 512x512 fake GigEVision camera with 1% of missing images.

5

I can confirm that there is something wrong with this particular system. When I compare with an old laptop and also try out different combinations of where the fake camera is running and where the viewer, I get the following numbers:

image
image860×93 14.7 KB

(these values have to be taken with a grain of salt, though, as there seem to be periods where things go relatively well, interrupted by those where they are worse, and I did not sample that systematically)

So the problem seems mostly on the receiving side, although having not only the receiver but also the sender on the new laptop makes things a lot worse, still.
Setting cpu core affinity for the two processes did not help.
I used iperf3 to look at the performance of the loopback device (especially udp packet loss) and that looks perfect even to much higher bandwidths… :man_shrugging:

I sometimes see phases where the sender reports
[GvFakeCamera::thread] Failed to send frame block 167 for frame 197: Resource temporarily unavailable
but for the majority of failures, the frames seem to get send just fine

Any idea for something I might try? Making sure we can get this stable (or at least understand under which conditions it ends up being unstable) would really be important for us before we decide to use aravis, so I’m willing to spend some time digging into this, but I’m at a bit of a loss with respect to where to start, so any hints are appreciated.

6

for the sake of completeness, here are iperf results for the loopback interface:

Connecting to host localhost, port 5678
[  5] local ::1 port 40098 connected to ::1 port 5678
[ ID] Interval           Transfer     Bitrate         Total Datagrams
[  5]   0.00-1.00   sec   119 MBytes   999 Mbits/sec  3812  
[  5]   1.00-2.00   sec   119 MBytes  1.00 Gbits/sec  3815  
[  5]   2.00-3.00   sec   119 MBytes  1000 Mbits/sec  3814  
[  5]   3.00-4.00   sec   119 MBytes  1.00 Gbits/sec  3815  
[  5]   4.00-5.00   sec   119 MBytes  1.00 Gbits/sec  3815  
[  5]   5.00-6.00   sec   119 MBytes  1000 Mbits/sec  3814  
[  5]   6.00-7.00   sec   119 MBytes  1.00 Gbits/sec  3815  
[  5]   7.00-8.00   sec   119 MBytes  1.00 Gbits/sec  3815  
[  5]   8.00-9.00   sec   119 MBytes  1000 Mbits/sec  3814  
[  5]   9.00-10.00  sec   119 MBytes  1.00 Gbits/sec  3816  
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate         Jitter    Lost/Total Datagrams
[  5]   0.00-10.00  sec  1.16 GBytes  1000 Mbits/sec  0.000 ms  0/38145 (0%)  sender
[  5]   0.00-10.00  sec  1.16 GBytes  1000 Mbits/sec  0.017 ms  0/38145 (0%)  receiver