pjsip / pjproject

PJSIP project
http://www.pjsip.org
GNU General Public License v2.0
2.06k stars 781 forks source link

Partially grey video on Android for several simultaneous video calls #2701

Closed ArtsemKurantsou closed 1 year ago

ArtsemKurantsou commented 3 years ago

Describe the bug When I try to start several video calls simultaneously on Android I get partially (or even completely) grey picture on some of them. At the end of the call, I also dump statistics for the call and it shows really huge packet loss but when I try to analyze packets using Wireshark I don't see that huge packet loss. I tried to dig deep in the code to see what can lead to such issues but haven't spotted anything that can cause such issues to me. Is there any chance that packets got lost by ioqueue?

To Reproduce Steps to reproduce the behavior:

  1. Start several video calls simultaneously on Android
  2. Check the video from the ongoing calls
  3. Check the statistics of the calls at the end

Expected behavior The video should not be corrupted (if all packets are reaching the device) and packet loss should be correct.

Logs/Screenshots Here are screenshots of the wireshark analyze and statistics from the dump of 3 simultaneous video calls: 1.

      Call time: 00h:01m:23s, 1st res in 1732 ms, conn in 7076ms
      #0 audio opus @16kHz, sendrecv, peer=server_ip:25532
         SRTP status: Active Crypto-suite: AES_CM_128_HMAC_SHA1_80
         RX pt=100, last update:00h:00m:01.486s ago
            total 1.1Kpkt 93.6KB (140.4KB +IP hdr) @avg=8.4Kbps/12.6Kbps
            pkt loss=2287 (66.2%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                  (msec)    min     avg     max     last    dev
            loss period: 3500.000 7623.333 11960.000 11960.000  64.486
            jitter     :   3.750 115.009 1373.000  60.000  19.430
         TX pt=100, ptime=20, last update:00h:00m:07.673s ago
            total 4.4Kpkt 355.5KB (533.2KB +IP hdr) @avg=31.9Kbps/47.9Kbps
            pkt loss=1 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
                  (msec)    min     avg     max     last    dev 
            loss period:  20.000  20.000  20.000  20.000   0.000
            jitter     :   0.500   9.127  25.687   2.062   6.107
         RTT msec      : 1979.000 7124.440 14268.000 2010.000   9.607
      #1 video H264, sendrecv, peer=server_ip:29616
         SRTP status: Active Crypto-suite: AES_CM_128_HMAC_SHA1_80
         RX pt=96, size=1280x720, fps=24.39, last update:00h:00m:00.402s ago
            total 1.2Kpkt 892.7KB (944.2KB +IP hdr) @avg=80.3Kbps/85.0Kbps
            pkt loss=3491 (73.1%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                  (msec)    min     avg     max     last    dev
            loss period:   0.000   5.286  12.000  12.000   4.589
            jitter     :   2.566 300.490 1123.000 250.000  10.573
         TX pt=96, size=352x288, fps=15.00, last update:00h:00m:13.869s ago
            total 0pkt 0B (0B +IP hdr) @avg=0bps/0bps
            pkt loss=1 (inf%), dup=0 (0.0%), reorder=0 (0.0%)
                  (msec)    min     avg     max     last    dev 
            loss period:   0.000   0.000   0.000   0.000   0.000
            jitter     :   0.000   0.000   0.000   0.000   0.000
         RTT msec      :   0.000   0.000   0.000   0.000   0.000

29616 2.

      Call time: 00h:01m:30s, 1st res in 1313 ms, conn in 2265ms
      #0 audio opus @16kHz, sendrecv, peer=serever_ip:19782
         SRTP status: Active Crypto-suite: AES_CM_128_HMAC_SHA1_80
         RX pt=100, last update:00h:00m:00.055s ago
            total 2.0Kpkt 165.6KB (248.4KB +IP hdr) @avg=14.5Kbps/21.7Kbps
            pkt loss=2117 (50.6%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                  (msec)    min     avg     max     last    dev
            loss period: 2120.000 3849.091 8580.000 2120.000  62.348
            jitter     :   2.187  87.477 1298.000  59.937  21.886
         TX pt=100, ptime=20, last update:00h:00m:01.413s ago
            total 4.5Kpkt 365.4KB (548.1KB +IP hdr) @avg=32.0Kbps/48.0Kbps
            pkt loss=1 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
                  (msec)    min     avg     max     last    dev 
            loss period:  20.000  20.000  20.000  20.000   0.000
            jitter     :   9.687  24.643  63.062  19.875  13.661
         RTT msec      : 1384.000 4651.445 11291.000 1764.000  17.879
      #1 video H264, sendrecv, peer=serever_ip:21542
         SRTP status: Active Crypto-suite: AES_CM_128_HMAC_SHA1_80
         RX pt=96, size=1280x720, fps=25.00, last update:00h:00m:08.842s ago
            total 2.0Kpkt 863.2KB (944.3KB +IP hdr) @avg=75.6Kbps/82.7Kbps
            pkt loss=2458 (54.8%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                  (msec)    min     avg     max     last    dev
            loss period:   0.000   1.643   6.000   0.000   2.125
            jitter     :   1.722 152.277 911.000  71.000   7.880
         TX pt=96, size=352x288, fps=15.00, last update:00h:00m:08.687s ago
            total 0pkt 0B (0B +IP hdr) @avg=0bps/0bps
            pkt loss=1 (inf%), dup=0 (0.0%), reorder=0 (0.0%)
                  (msec)    min     avg     max     last    dev 
            loss period:   0.000   0.000   0.000   0.000   0.000
            jitter     :   0.000   0.000   0.000   0.000   0.000
         RTT msec      :   0.000   0.000   0.000   0.000   0.000

21542 3.

      Call time: 00h:01m:34s, 1st res in 1487 ms, conn in 1619ms
      #0 audio opus @16kHz, sendrecv, peer=serever_ip:25184
         SRTP status: Active Crypto-suite: AES_CM_128_HMAC_SHA1_80
         RX pt=100, last update:00h:00m:00.969s ago
            total 2.3Kpkt 184.5KB (276.8KB +IP hdr) @avg=15.5Kbps/23.3Kbps
            pkt loss=1978 (46.2%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                  (msec)    min     avg     max     last    dev
            loss period:  40.000 3043.077 7140.000 2860.000  61.006
            jitter     :   2.312  92.625 969.000  59.937  26.559
         TX pt=100, ptime=20, last update:00h:00m:03.552s ago
            total 4.7Kpkt 379.3KB (569.0KB +IP hdr) @avg=32.0Kbps/48.0Kbps
            pkt loss=1 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
                  (msec)    min     avg     max     last    dev 
            loss period:  20.000  20.000  20.000  20.000   0.000
            jitter     :   0.000  11.735  36.562   7.437   9.828
         RTT msec      : 461.000 3419.010 8546.250 2976.000  16.906
      #1 video H264, sendrecv, peer=serever_ip:26720
         SRTP status: Active Crypto-suite: AES_CM_128_HMAC_SHA1_80
         RX pt=96, size=1920x1072, fps=24.39, last update:00h:00m:00.929s ago
            total 6.7Kpkt 5.23MB (5.50MB +IP hdr) @avg=441.9Kbps/464.8Kbps
            pkt loss=614 (8.3%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                  (msec)    min     avg     max     last    dev
            loss period:   0.000   0.029   1.000   0.000   0.166
            jitter     :   5.200  25.646 225.000  15.577  13.989
         TX pt=96, size=352x288, fps=15.00, last update:00h:00m:04.686s ago
            total 0pkt 0B (0B +IP hdr) @avg=0bps/0bps
            pkt loss=1 (inf%), dup=0 (0.0%), reorder=0 (0.0%)
                  (msec)    min     avg     max     last    dev 
            loss period:   0.000   0.000   0.000   0.000   0.000
            jitter     :   0.000   0.000   0.000   0.000   0.000
         RTT msec      :   0.000   0.000   0.000   0.000   0.000

26720 Desktop/Smartphone (please complete the following information):

Smartphone (please also complete the following information):

ArtsemKurantsou commented 3 years ago

Hi @sauwming , @nanangizz Could you please help with the issue or add an appropriate member to the issue? Thanks in advance

ArtsemKurantsou commented 3 years ago

Hi @sauwming @nanangizz Could you please help with this issue?

sauwming commented 3 years ago

Unfortunately I don't see any other possible cause other than the packet loss. If the problem doesn't happen with fewer number of calls, then it's a resource/network issue.

ArtsemKurantsou commented 3 years ago

Hi @sauwming Sometimes it happens even for a single call. The phone is connected to 5Gh WiFi and has a high-speed connection. The calling device also has a good connection so it doesn't look like the issue is that the connection is slow. Another thing is that packets dump analysis also doesn't show the packet loss. So it looks like the problem is that PjSip drops the packets for some reason. BTW sometimes when it happens I get openh264.cpp Unpacketize error: Ignored (PJ_EIGNORED). Could you please give me advice on where should I take a look and how I can be sure that all the incoming packets are handled by PjSip?

ArtsemKurantsou commented 3 years ago

Hi, @sauwming. Could you please check my previous message?

sauwming commented 3 years ago

You can try to do some debugging: https://developer.android.com/studio/debug

Based on the info you provided, some places to look into:

ArtsemKurantsou commented 3 years ago

Hi @sauwming. I tried to profile the app and I think I have an idea why I see the issue. In the profiler, I see that one thread is folded with work when I start 3 video calls simultaneously. I think that the problem is with ioqueue using a single thread for sockets polling (please correct me if I'm wrong). I tried to use epoll version but it didn't help. I also tried to use AMediacodec decoder and it helps but with 3 calls this thread also has a pretty high load. Are there any configurations or other things that I can try to fix the problem? Thanks in advance

sauwming commented 3 years ago

In my opinion, the video processing is the more likely cause, especially if using a high res and/or fps (such as 1280x720, 25 fps as in the log). You can check by changing the decode to no-op and/or the encode to no-op, to find out how much CPU those need. When both are set to no-op, and audio is disabled, the remaining CPU is the one used by polling. If it's still high, then yes, it's because of the polling as you suspected. But if it's low, then it is the video.

ArtsemKurantsou commented 3 years ago

Hi @sauwming I've commented out everything in decode_h264 in the and_vid_mediacodec.c and checked with it and load seems to be a bit less but still looks a bit too high.

image

Is there any way to have a separate thread for each call? Another thing is overall CPU load is less than 50% so it looks like the device should be able to handle this load.