nextcloud / spreed

🗨️ Nextcloud Talk – chat, video & audio calls for Nextcloud
https://nextcloud.com/talk
GNU Affero General Public License v3.0
1.6k stars 424 forks source link

Talk periodically gives bandwidth warning without any reason #6277

Closed jacotec closed 2 years ago

jacotec commented 2 years ago

Description

Sometimes when I start a Talk video call, Talk shows the "bandwitdh warning" to me without any reason. It tells me that I should disable the camera and continuously shows the red "bandwith warning" icon in the lower right corner of my own video picture.

IMHO it does this without any reason because:

So all connections are pretty fast and there should be absolutely no reason for a bandwidth warning.

In addition, the warning stays active all over the call (which works fully fine with all participants). That means that Talk thinks it has a bad connection during the complete call. When I leave the call and immediately rejoin there is a chance that the warning is gone, although nothing has changed.

This is distracting other users as well.

Steps to reproduce

  1. Open a call
  2. Sometimes right after opening a bandwidth warning appears in the own video preview without any reason (explanation above)

Expected behaviour

Actual behaviour

Talk app

Talk app version: (see apps admin page: /index.php/settings/apps) 12.1.2

Custom Signaling server configured: yes/no and version (see additional admin settings: /index.php/index.php/settings/admin/talk#signaling_server) yes

Custom TURN server configured: yes/no (see additional admin settings: /index.php/settings/admin/talk#turn_server) yes

Custom STUN server configured: yes/no (see additional admin settings: /index.php/settings/admin/talk#stun_server) yes

Browser

Microphone available: yes/no yes

Camera available: yes/no yes

Operating system: Windows/Ubuntu/... Windows 10, MacOS 11.5

Browser name: Firefox/Chrome/... Edge, Firefox, Chrome

Browser version: 50.1/55/... Edge 93.0.961.52 , Chrome 93.0.4577.82

Browser log

Server configuration

Operating system: Ubuntu/RedHat/... Ubuntu 20.04

Web server: Apache/Nginx Apache

Database: MySQL/Maria/SQLite/PostgreSQL MariaDB

PHP version: 7.2/7.3/7.4 7.4

Nextcloud Version: (see admin page) 22.1.1

List of activated apps:

``` Enabled: - accessibility: 1.7.0 - activity: 2.15.0 - admin_audit: 1.11.0 - apporder: 0.13.0 - bbb: 2.0.0 - bookmarks: 10.0.0 - bruteforcesettings: 2.2.0 - calendar: 2.3.3 - camerarawpreviews: 0.7.12 - circles: 22.1.1 - cloud_federation_api: 1.4.0 - comments: 1.11.0 - contacts: 4.0.3 - contactsinteraction: 1.2.0 - dashboard: 7.1.0 - dav: 1.18.0 - deck: 1.5.3 - drawio: 1.0.1 - extract: 1.3.2 - facerecognition: 0.8.3 - federatedfilesharing: 1.11.0 - federation: 1.11.0 - files: 1.16.0 - files_accesscontrol: 1.12.0 - files_automatedtagging: 1.12.0 - files_downloadactivity: 1.11.1 - files_external: 1.12.1 - files_fulltextsearch: 22.0.1 - files_fulltextsearch_tesseract: 21.0.0 - files_inotify: 0.1.10 - files_pdfviewer: 2.3.0 - files_retention: 1.11.1 - files_rightclick: 1.1.0 - files_sharing: 1.13.2 - files_trashbin: 1.11.0 - files_versions: 1.14.0 - files_videoplayer: 1.11.0 - firstrunwizard: 2.11.0 - forms: 2.3.0 - fulltextsearch: 22.0.1 - fulltextsearch_elasticsearch: 22.0.1 - groupfolders: 10.0.0 - logreader: 2.7.0 - lookup_server_connector: 1.9.0 - maps: 0.1.9 - metadata: 0.14.0 - music: 1.3.3 - news: 16.0.1 - nextcloud_announcements: 1.11.0 - notes: 4.1.1 - notifications: 2.10.1 - notify_push: 0.2.4 - oauth2: 1.9.0 - ocdownloader: 1.7.12 - password_policy: 1.12.0 - photos: 1.4.0 - polls: 3.2.0 - previewgenerator: 3.1.1 - privacy: 1.6.0 - provisioning_api: 1.11.0 - qownnotesapi: 21.7.0 - quicknotes: 0.7.2 - quota_warning: 1.11.0 - ransomware_protection: 1.11.0 - recommendations: 1.1.0 - richdocuments: 4.2.3 - serverinfo: 1.12.0 - settings: 1.3.0 - sharebymail: 1.11.0 - spreed: 12.1.2 - support: 1.5.0 - survey_client: 1.10.0 - systemtags: 1.11.0 - talk_matterbridge: 1.22.4 - tasks: 0.14.2 - text: 3.3.0 - theming: 1.12.0 - twofactor_backupcodes: 1.10.1 - twofactor_totp: 6.1.0 - updatenotification: 1.11.0 - user_ldap: 1.11.0 - user_status: 1.1.1 - video_converter: 1.0.3 - viewer: 1.6.0 - weather_status: 1.1.0 - workflow_pdf_converter: 1.7.0 - workflow_script: 1.7.0 - workflowengine: 2.3.1 ```

Nextcloud configuration:

``` { "system": { "instanceid": "***REMOVED SENSITIVE VALUE***", "passwordsalt": "***REMOVED SENSITIVE VALUE***", "secret": "***REMOVED SENSITIVE VALUE***", "trusted_domains": [ "10.0.1.6", "***REMOVED SENSITIVE VALUE***" ], "trusted_proxies": "***REMOVED SENSITIVE VALUE***", "forwarded_for_headers": [ "HTTP_X_FORWARDED_FOR", "HTTP_FORWARDED_FOR" ], "overwrite.cli.url": "https:\/\/***REMOVED SENSITIVE VALUE***.de", "htaccess.RewriteBase": "\/", "datadirectory": "***REMOVED SENSITIVE VALUE***", "dbtype": "mysql", "version": "22.1.1.2", "dbname": "***REMOVED SENSITIVE VALUE***", "dbhost": "***REMOVED SENSITIVE VALUE***", "dbport": "", "dbtableprefix": "oc_", "mysql.utf8mb4": true, "dbuser": "***REMOVED SENSITIVE VALUE***", "dbpassword": "***REMOVED SENSITIVE VALUE***", "installed": true, "maintenance": false, "enable_avatars": true, "filesystem_check_changes": 1, "theme": "", "default_language": "de", "default_locale": "de_DE", "default_phone_region": "DE", "defaultapp": "files", "skeletondirectory": "\/var\/www\/skeleton", "share_folder": "\/Shared", "log_type": "file", "logfile": "\/var\/log\/nextcloud\/nextcloud.log", "loglevel": "2", "mail_smtpmode": "smtp", "remember_login_cookie_lifetime": 2592000, "session_lifetime": 604800, "session_keepalive": true, "log_rotate_size": "10485760", "trashbin_retention_obligation": "30, 60", "versions_retention_obligation": "auto, 365", "check_for_working_webdav": true, "simpleSignUpLink.shown": false, "music.lastfm_api_key": "***REMOVED SENSITIVE VALUE***", "memcache.local": "\\OC\\Memcache\\APCu", "filelocking.enabled": true, "memcache.distributed": "\\OC\\Memcache\\Redis", "memcache.locking": "\\OC\\Memcache\\Redis", "redis": { "host": "***REMOVED SENSITIVE VALUE***", "port": 0, "timeout": 0.5, "dbindex": 0 }, "logtimezone": "Europe\/Berlin", "enable_previews": true, "enabledPreviewProviders": [ "OC\\Preview\\PNG", "OC\\Preview\\JPEG", "OC\\Preview\\GIF", "OC\\Preview\\BMP", "OC\\Preview\\MarkDown", "OC\\Preview\\MP3", "OC\\Preview\\TXT", "OC\\Preview\\Movie", "OC\\Preview\\Photoshop", "OC\\Preview\\SVG", "OC\\Preview\\TIFF", "OC\\Preview\\HEIC", "OC\\Preview\\MKV", "OC\\Preview\\MOV", "OC\\Preview\\MP4", "OC\\Preview\\AVI" ], "preview_max_x": "2048", "preview_max_y": "2048", "jpeg_quality": "60", "mail_from_address": "***REMOVED SENSITIVE VALUE***", "mail_sendmailmode": "smtp", "mail_domain": "***REMOVED SENSITIVE VALUE***", "mail_smtphost": "***REMOVED SENSITIVE VALUE***", "mail_smtpport": "587", "ldapIgnoreNamingRules": false, "ldapProviderFactory": "OCA\\User_LDAP\\LDAPProviderFactory", "ldapUserCleanupInterval": 51, "app_install_overwrite": [ "files_external_dropbox", "bookmarks_fulltextsearch", "files_inotify", "files_fulltextsearch_tesseract", "previewgenerator" ], "updater.release.channel": "stable", "mail_smtpauth": 1, "mail_smtpname": "***REMOVED SENSITIVE VALUE***", "mail_smtppassword": "***REMOVED SENSITIVE VALUE***", "mail_smtpsecure": "tls", "mail_smtpauthtype": "LOGIN" } } ```

Server log (data/nextcloud.log)

``` Insert your server log here ```
nickvergessen commented 2 years ago

If it's happening periodically you might want to check on devices (not server) network connection. The warning is shown based on analysis of your own browsers connection not by the server. You can see the details in https://nextcloud-talk.readthedocs.io/en/latest/call-experience/#judging-the-connection-quality

I guess either your connection is spiking giving you a huge ping for some moments or dropping some packages.

After seeing the message you can open your browsers console (F12) and enter the following code to check for the reason:

OCA.Talk.SimpleWebRTC.webrtc.peers.forEach(peer => {
    peer.pc.getStats().then(stats => {
        for (stat of stats.values()) {
            if (typeof stat.totalRoundTripTime === 'number') {
                        console.log('RTT:' + ((stat.totalRoundTripTime / stat.responsesReceived) * 1000))
            }
            if (typeof stat.packetsLost === 'number') {
                        console.log('Packets lost:' + stat.packetsLost)
            }
        }
    })
})
jacotec commented 2 years ago

@nickvergessen I really dont't see a reason here ... ?!? No packet loss and RTT 21ms as is seems.

image

This was the console output before, if this is needed:

image

nickvergessen commented 2 years ago

I guess the RTT of NaN (Not a number) is the issue here, can you try again with:

OCA.Talk.SimpleWebRTC.webrtc.peers.forEach(peer => {
    peer.pc.getStats().then(stats => {
        for (stat of stats.values()) {
            if (typeof stat.totalRoundTripTime === 'number') {
                        console.log('RTT:' + ((stat.totalRoundTripTime / stat.responsesReceived) * 1000))
                        console.log('RTT:totalRoundTripTime:' + stat.totalRoundTripTime)
                        console.log('RTT:responsesReceived:' + stat.responsesReceived)
            }
            if (typeof stat.packetsLost === 'number') {
                        console.log('Packets lost:' + stat.packetsLost)
            }
        }
    })
})
jacotec commented 2 years ago

@nickvergessen

image

jacotec commented 2 years ago

This is a connection without the warning, also "RTT:NaN" in there. I don't see a real difference in the output compared to the connection with the warning.

image

nickvergessen commented 2 years ago

So on the first screenshot there is a section with responsesReceived:0 and that is the reason why you see the warning I think. Because something was so busy that you did not manage to receive any responses

jacotec commented 2 years ago

How can we track down what this is? I see no reason for this. Regardless if I ping the NC server or the HPB server, I'm always getting all pings immediately without any packet loss.

Any things I can check with Wireshark? Is responsesReceived:0 reflecting communication to the NC server, the HPB or the TURN server?

And even if something was busy during setup, why does the warning not disappear once the issue is gone? It seems if that flag is raised at some point during call setup, it's not cleared again if all is back to green condition.

nickvergessen commented 2 years ago

Any things I can check with Wireshark? Is responsesReceived:0 reflecting communication to the NC server, the HPB or the TURN server?

It should be the connection to the TURN/Janus server

And even if something was busy during setup, why does the warning not disappear once the issue is gone? It seems if that flag is raised at some point during call setup, it's not cleared again if all is back to green condition.

I think the main idea is to even notify people when it's on/off/on/off kinda situation. Because if you freeze every now and then it's not a good experience either, but it should vanish at some point

How can we track down what this is? I see no reason for this. Regardless if I ping the NC server or the HPB server, I'm always getting all pings immediately without any packet loss.

I don't know, will ask a colleague for some input

jacotec commented 2 years ago

Looking at some Wireshark logs, the first strange thing is that I see a lot of STUN Binding Requests being sent to the IP address of the HPB server. The HPB is not running a STUN at all, nor on the strange port where these requests are sent to (Port 55153)

image

To the real TURN/STUN Server it really "hammers" out tons of Binding Request Packets within 2-3 ms. On all network interfaces. I don't see why this is necessary. I have a local-only IP here, the others is a VPN connection ... and none of them are having Internet access at all. Only the primary IP (192.168.0.21 in this case). It should send only via the Interface who owns the route / standard gateway to the internet? And why tons of requests in such a short time?

image

In parallel it does the same on TCP (looks like it shoots panically "with all it has" to get a TURN connection).

It might be that this all is correct and intentionally, I'm a noob in these things, but I can't really see a difference here between a "good" and a "warning" connection. The complete environment, paths and server/client loads are the same. However, with this "chaos" to the TURN server it's hard to find any difference in Wireshark. ;-)

But I never saw the warning state disappear, not even after 10 mins of perfect communication. On the other hand I never saw the warning appearing during a conversaion. It really feels as some short point in call setup determines if the warning is set or not, and this state stays the same during the complete call.

danxuliu commented 2 years ago

@jacotec When the connection warning is shown the browser console should show the current stat values that triggered the connection warning. Could you provide us the browser logs when the connection warning is shown to check them? Thanks.

jacotec commented 2 years ago

@danxuliu Here is a log where the warning appeared.

Suddenly the "Packets lost ratio" is jumping to 1.5 although I did not see any packet loss count other than 0. And the call works fine, but this "ratio" never decreases (as more packets are fine, as lower should this ratio go). Ratio seems to be stuck during all the call, not changing in any way.

Bug?

talk-main.js?v=1a7fde89-23:1 setVisualLastReadMessageId token=4mmq6g23 id=996
talk-main.js?v=1a7fde89-23:1 Joining call
talk-main.js?v=1a7fde89-23:1 The request has been canceled e {message: 'canceled'}
talk-main.js?v=1a7fde89-23:1 The request has been canceled e {message: 'canceled'}
talk-main.js?v=1a7fde89-23:1 [Violation] 'requestAnimationFrame' handler took 94ms
[Violation] Forced reflow while executing JavaScript took 98ms
preview:1 GET https://********.de/core/preview?fileId=810479&x=-1&y=384&a=1 404 (Not Found)
Image (async)
mounted @ talk-main.js?v=1a7fde89-23:1
Gt @ talk-main.js?v=1a7fde89-23:1
en @ talk-main.js?v=1a7fde89-23:1
insert @ talk-main.js?v=1a7fde89-23:1
k @ talk-main.js?v=1a7fde89-23:1
ca.nodeOps @ talk-main.js?v=1a7fde89-23:1
t._update @ talk-main.js?v=1a7fde89-23:1
i @ talk-main.js?v=1a7fde89-23:1
fn.get @ talk-main.js?v=1a7fde89-23:1
fn.run @ talk-main.js?v=1a7fde89-23:1
pn @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
Jt @ talk-main.js?v=1a7fde89-23:1
Promise.then (async)
Vt @ talk-main.js?v=1a7fde89-23:1
ie @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
fn.update @ talk-main.js?v=1a7fde89-23:1
dt.notify @ talk-main.js?v=1a7fde89-23:1
set @ talk-main.js?v=1a7fde89-23:1
mn.set @ talk-main.js?v=1a7fde89-23:1
joinCall @ talk-main.js?v=1a7fde89-23:1
Gt @ talk-main.js?v=1a7fde89-23:1
n @ talk-main.js?v=1a7fde89-23:1
r._wrapper @ talk-main.js?v=1a7fde89-23:1
talk-main.js?v=1a7fde89-23:1 localMediaStarted
talk-main.js?v=1a7fde89-23:1 Peer created c {…}
talk-main.js?v=1a7fde89-23:1 Enabling Simulcasting for Chrome (SDP munging)
talk-main.js?v=1a7fde89-23:1 Changed quality to 4
talk-main.js?v=1a7fde89-23:1 Connecting own peer... c {…}
talk-main.js?v=1a7fde89-23:1 Playing join sound because of self joining
talk-main.js?v=1a7fde89-23:1 Playing waiting sound
talk-main.js?v=1a7fde89-23:1 Connection established (own peer). c {…}
talk-main.js?v=1a7fde89-23:1 status datachannel is open
talk-main.js?v=1a7fde89-23:1 simplewebrtc datachannel is open
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.019, 0.019, 0.022]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 999, 1000, 1001, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.022, 0.02, 0.02]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1001, 1000, 999, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.022, 0.02, 0.02, 0.019, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 999, 1000, 1001, 999]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.02, 0.019, 0.019, 0.019, 0.02]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1001, 999, 1000, 1001]
talk-main.js?v=1a7fde89-23:1 Playing waiting sound
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.02, 0.019, 0.02]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [999, 1000, 1001, 999, 1001]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.02, 0.019, 0.02, 0.019, 0.024]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1001, 999, 1001, 998, 1002]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.02, 0.019, 0.024, 0.02, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1001, 998, 1002, 999, 1001]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.024, 0.02, 0.019, 0.019, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1002, 999, 1001, 1000, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.019, 0.02, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1001, 1000, 1000, 1000, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.02, 0.019, 0.019, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1000, 1000, 999, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.019, 0.019, 0.02]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 999, 1000, 1000, 1001]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.02, 0.019, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1000, 1001, 999, 1000]
talk-main.js?v=1a7fde89-23:1 Playing waiting sound
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.02, 0.019, 0.019, 0.019, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1001, 999, 1000, 1000, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.019, 0.019, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1000, 1000, 1001, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.019, 0.019, 0.02, 0.019]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1001, 1000, 1000, 1000]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: No transmitted data, packet lost ratio: 1.5
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets lost ratio: [1.5, 1.5, 1.5, 1.5, 1.5]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Packets per second: [0, 0, 0, 0, 0]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Round trip time: [0.019, 0.02, 0.019, 0.019, 0.02]
talk-main.js?v=1a7fde89-23:1 PeerConnectionAnalyzer: video: Timestamps: [1000, 1000, 1000, 999, 1000]
talk-main.js?v=1a7fde89-23:1 Leaving call
talk-main.js?v=1a7fde89-23:1 Playing leave sound because of self leaving
talk-main.js?v=1a7fde89-23:1 The request has been canceled e {message: 'canceled'}
talk-main.js?v=1a7fde89-23:1 The request has been canceled e {message: 'canceled'}
talk-main.js?v=1a7fde89-23:1 [Violation] 'requestAnimationFrame' handler took 92ms
[Violation] Forced reflow while executing JavaScript took 97ms
preview:1 GET https://********.de/core/preview?fileId=810479&x=-1&y=384&a=1 404 (Not Found)
Image (async)
mounted @ talk-main.js?v=1a7fde89-23:1
Gt @ talk-main.js?v=1a7fde89-23:1
en @ talk-main.js?v=1a7fde89-23:1
insert @ talk-main.js?v=1a7fde89-23:1
k @ talk-main.js?v=1a7fde89-23:1
ca.nodeOps @ talk-main.js?v=1a7fde89-23:1
t._update @ talk-main.js?v=1a7fde89-23:1
i @ talk-main.js?v=1a7fde89-23:1
fn.get @ talk-main.js?v=1a7fde89-23:1
fn.run @ talk-main.js?v=1a7fde89-23:1
pn @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
Jt @ talk-main.js?v=1a7fde89-23:1
Promise.then (async)
Vt @ talk-main.js?v=1a7fde89-23:1
ie @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
fn.update @ talk-main.js?v=1a7fde89-23:1
dt.notify @ talk-main.js?v=1a7fde89-23:1
set @ talk-main.js?v=1a7fde89-23:1
updateParticipant @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
p._withCommit @ talk-main.js?v=1a7fde89-23:1
p.commit @ talk-main.js?v=1a7fde89-23:1
commit @ talk-main.js?v=1a7fde89-23:1
leaveCall @ talk-main.js?v=1a7fde89-23:1
async function (async)
leaveCall @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
(anonymous) @ talk-main.js?v=1a7fde89-23:1
p.dispatch @ talk-main.js?v=1a7fde89-23:1
dispatch @ talk-main.js?v=1a7fde89-23:1
leaveCall @ talk-main.js?v=1a7fde89-23:1
Gt @ talk-main.js?v=1a7fde89-23:1
n @ talk-main.js?v=1a7fde89-23:1
r._wrapper @ talk-main.js?v=1a7fde89-23:1
talk-main.js?v=1a7fde89-23:1 clearLastReadMessage because of isSticky token=4mmq6g23
danxuliu commented 2 years ago

Thanks for the logs. They show why the connection warning appears: according to the stats, there were no transmitted video packets. A packet lost ratio of 1.5 means that, but you can also see the packets values, which are 0.

Now the question is why the transmitted packets are 0 according to the stats.

Just to be fully sure, can you repeat the test and, once you get the connection warning, join the call from a private window or from a different browser? Even if you see yourself fine in the local video that does not mean that the video is being properly sent to the HPB. You should verify that by joining the call with another participant (a guest or another user) and checking if the video is visible in the other window.

jacotec commented 2 years ago

@danxuliu I've joined the call with the warning from my iPad and all is fine in both directions (except the warning in the browser). Movement is fluid, voice is in sync to video, no stuttering. Lost ratio stays 1.5 all the time and this "penalty" does not change back even when there are no video issues. I assume there is an issue that it thinks it detects loss where all is fine.

danxuliu commented 2 years ago

Thanks for the confirmation. Please note that the packet lost ratio is a value derived from the number of packets and lost packets; from the logs provided above the number of packets is always 0 so, unless you have seen the lost ratio stuck at 1.5 while the number of packets increased, the actual issue would be that no sent packets are reported.

This could be caused by a bug in the way that the PeerConnectionAnalyzer class gets the stats, or it could be that the stats returned by the browser (or, maybe, Janus) for some reason do not report sent packets.

Once you see the connection warning and the PeerConnectionAnalyzer logs, could you run the following in your browser console and provide us the results?:

OCA.Talk.SimpleWebRTC.webrtc.peers[0].pc.getSenders()[0].getStats().then(stats => {
    for (stat of stats.values()) {
        if (stat.type === 'outbound-rtp' || stat.type === 'remote-inbound-rtp' || (stat.type === 'candidate-pair' && stat.selected)) {
            console.log(stat);
        }
    }
})

This will directly get the sender stats, independently of what PeerConnectionAnalyzer uses. Please expand each of the printed objects so all the information can be seen.

Thanks.

jacotec commented 2 years ago

I'm getting two objects then:

{
    "id": "RTCOutboundRTPAudioStream_1511011486",
    "timestamp": 1632828120370,
    "type": "outbound-rtp",
    "ssrc": 1511011486,
    "kind": "audio",
    "trackId": "RTCMediaStreamTrack_sender_11",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_0_Outbound_111",
    "mediaType": "audio",
    "mediaSourceId": "RTCAudioSource_11",
    "remoteId": "RTCRemoteInboundRtpAudioStream_1511011486",
    "packetsSent": 659,
    "retransmittedPacketsSent": 0,
    "bytesSent": 49623,
    "headerBytesSent": 15862,
    "retransmittedBytesSent": 0,
    "nackCount": 0
}
{
    "id": "RTCRemoteInboundRtpAudioStream_1511011486",
    "timestamp": 1632828119543,
    "type": "remote-inbound-rtp",
    "ssrc": 1511011486,
    "kind": "audio",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_0_Outbound_111",
    "jitter": 0.0007291666666666667,
    "packetsLost": 0,
    "localId": "RTCOutboundRTPAudioStream_1511011486",
    "roundTripTime": 0.021,
    "fractionLost": 0,
    "totalRoundTripTime": 0.232,
    "roundTripTimeMeasurements": 11
}

image

The "Protoype: Object" paths in these elements have around a million subpaths and sub-sub-paths ... opening all sends the browser in a kind of infinite loop ...

Do you also need any of them?

jacotec commented 2 years ago

@danxuliu Maybe also interesting that both appearing outputs are talking about "AudioStream". There is no debug output which mentions "VideoStream". Not sure if this is by design.

However, the test call was from my Admin user to my personal user, so I've joined the call with my iPhone and can confirm that the Video was definitely fine in both directions for this call.

jacotec commented 2 years ago

@danxuliu Do you have any idea or do you need more information?

danxuliu commented 2 years ago

Sorry a lot of the delay.

The "Protoype: Object" paths in these elements have around a million subpaths and sub-sub-paths ... opening all sends the browser in a kind of infinite loop ...

Do you also need any of them?

No, only the first level is needed (what you did :-) ). Sorry for not describing that in a clearer way.

Maybe also interesting that both appearing outputs are talking about "AudioStream". There is no debug output which mentions "VideoStream". Not sure if this is by design.

I made a mistake in the command above :facepalm:. When the local participant is sending both audio and video the participant has two senders: the first one is for audio and the second one is for video. In the command above the stats are got for the first sender, therefore, the audio sender (getSenders()[0]). But you are having the issues with the video stats, so the queried stats do not include the video. Instead of getting the stats for the second sender it would be better to get the stats for the full connection, which should include the stats for both audio and video:

OCA.Talk.SimpleWebRTC.webrtc.peers[0].pc.getStats().then(stats => {
   for (stat of stats.values()) {
       if (stat.type === 'outbound-rtp' || stat.type === 'remote-inbound-rtp' || (stat.type === 'candidate-pair' && stat.selected)) {
           console.log(stat);
       }
   }
})

Sorry for the confusion. Could you repeat the test and, once you see the connection warning and the PeerConnectionAnalyzer logs, run the (updated) command again? Please remember to expand the first level of the stat objects to see their values and, if possible, please provide us the PeerConnectionAnalyzer logs too to compare the values. Thanks!

jacotec commented 2 years ago

@danxuliu

Here are the outputs of this command in a session where the warning appears:

{
    "id": "RTCOutboundRTPAudioStream_1355199200",
    "timestamp": 1634728003099,
    "type": "outbound-rtp",
    "ssrc": 1355199200,
    "kind": "audio",
    "trackId": "RTCMediaStreamTrack_sender_1",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_0_Outbound_111",
    "mediaType": "audio",
    "mediaSourceId": "RTCAudioSource_1",
    "remoteId": "RTCRemoteInboundRtpAudioStream_1355199200",
    "packetsSent": 2822,
    "retransmittedPacketsSent": 0,
    "bytesSent": 159048,
    "headerBytesSent": 67728,
    "retransmittedBytesSent": 0,
    "nackCount": 0
}

{
    "id": "RTCOutboundRTPVideoStream_2223278249",
    "timestamp": 1634728003099,
    "type": "outbound-rtp",
    "ssrc": 2223278249,
    "kind": "video",
    "trackId": "RTCMediaStreamTrack_sender_2",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_1_Outbound_96",
    "mediaType": "video",
    "mediaSourceId": "RTCVideoSource_2",
    "remoteId": "RTCRemoteInboundRtpVideoStream_2223278249",
    "packetsSent": 2263,
    "retransmittedPacketsSent": 0,
    "bytesSent": 1732598,
    "headerBytesSent": 48864,
    "retransmittedBytesSent": 0,
    "framesEncoded": 1679,
    "keyFramesEncoded": 2,
    "totalEncodeTime": 9.175,
    "totalEncodedBytesTarget": 0,
    "frameWidth": 360,
    "frameHeight": 270,
    "framesPerSecond": 30,
    "framesSent": 1679,
    "hugeFramesSent": 0,
    "totalPacketSendDelay": 55.32,
    "qualityLimitationReason": "none",
    "qualityLimitationDurations": {
        "other": 0,
        "cpu": 0,
        "bandwidth": 73,
        "none": 57165
    },
    "qualityLimitationResolutionChanges": 1,
    "encoderImplementation": "libvpx",
    "firCount": 0,
    "pliCount": 0,
    "nackCount": 0,
    "qpSum": 24762
}

{
    "id": "RTCOutboundRTPVideoStream_36041280",
    "timestamp": 1634728003099,
    "type": "outbound-rtp",
    "ssrc": 36041280,
    "kind": "video",
    "trackId": "RTCMediaStreamTrack_sender_2",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_1_Outbound_96",
    "mediaType": "video",
    "mediaSourceId": "RTCVideoSource_2",
    "remoteId": "RTCRemoteInboundRtpVideoStream_36041280",
    "packetsSent": 4723,
    "retransmittedPacketsSent": 0,
    "bytesSent": 4605440,
    "headerBytesSent": 111620,
    "retransmittedBytesSent": 0,
    "framesEncoded": 1676,
    "keyFramesEncoded": 1,
    "totalEncodeTime": 9.03,
    "totalEncodedBytesTarget": 0,
    "frameWidth": 720,
    "frameHeight": 540,
    "framesPerSecond": 30,
    "framesSent": 1676,
    "hugeFramesSent": 0,
    "totalPacketSendDelay": 201.269,
    "qualityLimitationReason": "none",
    "qualityLimitationDurations": {
        "other": 0,
        "cpu": 0,
        "bandwidth": 73,
        "none": 57165
    },
    "qualityLimitationResolutionChanges": 1,
    "encoderImplementation": "libvpx",
    "firCount": 0,
    "pliCount": 0,
    "nackCount": 0,
    "qpSum": 30348
}

{
    "id": "RTCOutboundRTPVideoStream_3712109353",
    "timestamp": 1634728003099,
    "type": "outbound-rtp",
    "ssrc": 3712109353,
    "kind": "video",
    "trackId": "RTCMediaStreamTrack_sender_2",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_1_Outbound_96",
    "mediaType": "video",
    "mediaSourceId": "RTCVideoSource_2",
    "packetsSent": 0,
    "retransmittedPacketsSent": 0,
    "bytesSent": 0,
    "headerBytesSent": 0,
    "retransmittedBytesSent": 0,
    "framesEncoded": 0,
    "keyFramesEncoded": 0,
    "totalEncodeTime": 0,
    "totalEncodedBytesTarget": 0,
    "framesSent": 0,
    "hugeFramesSent": 0,
    "totalPacketSendDelay": 0,
    "qualityLimitationReason": "none",
    "qualityLimitationDurations": {
        "other": 0,
        "cpu": 0,
        "bandwidth": 73,
        "none": 57165
    },
    "qualityLimitationResolutionChanges": 1,
    "encoderImplementation": "libvpx",
    "firCount": 0,
    "pliCount": 0,
    "nackCount": 0
}

{
    "id": "RTCRemoteInboundRtpAudioStream_1355199200",
    "timestamp": 1634728002397,
    "type": "remote-inbound-rtp",
    "ssrc": 1355199200,
    "kind": "audio",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_0_Outbound_111",
    "jitter": 0.0027708333333333335,
    "packetsLost": 0,
    "localId": "RTCOutboundRTPAudioStream_1355199200",
    "roundTripTime": 0.02,
    "fractionLost": 0,
    "totalRoundTripTime": 1.137,
    "roundTripTimeMeasurements": 55
}

{
    "id": "RTCRemoteInboundRtpVideoStream_2223278249",
    "timestamp": 1634728002397,
    "type": "remote-inbound-rtp",
    "ssrc": 2223278249,
    "kind": "video",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_1_Outbound_96",
    "jitter": 0.006733333333333333,
    "packetsLost": 0,
    "localId": "RTCOutboundRTPVideoStream_2223278249",
    "roundTripTime": 0.02,
    "fractionLost": 0,
    "totalRoundTripTime": 1.153,
    "roundTripTimeMeasurements": 55
}

{
    "id": "RTCRemoteInboundRtpVideoStream_36041280",
    "timestamp": 1634728002397,
    "type": "remote-inbound-rtp",
    "ssrc": 36041280,
    "kind": "video",
    "transportId": "RTCTransport_0_1",
    "codecId": "RTCCodec_1_Outbound_96",
    "jitter": 0.009611111111111112,
    "packetsLost": 0,
    "localId": "RTCOutboundRTPVideoStream_36041280",
    "roundTripTime": 0.02,
    "fractionLost": 0,
    "totalRoundTripTime": 1.149,
    "roundTripTimeMeasurements": 55
}

One different thing which I've noticed: Sometimes in Nextcloud Talk the video and audio are getting out of sync (video is late to the audio), also when no warning is active. That's pretty distracting and does not fix itself. Is that a known issue, or do I need to open a new issue for this? I have a BigBlueButton instance and a Jitsi instance on my same physical machine in the datacenter as the High Performance Backend for talk - and zero issues with anything here (so it's the same hardware, same routing, same TURN server, same clients, same browsers).

danxuliu commented 2 years ago

Thanks for the results. They are very interesting. It seems that the issue is related to simulcast (sending several video streams in different qualities so the receivers can use one or the other depending on their needs).

As you can see there are several outbound-rtp stats, and for the last one bytesSent is 0. The last value is the one used to verify the connection status, so Talk assumes that no video data is being sent and shows the warning (and, indeed, no data is sent in that video stream, although it is in the others).

Could you close your browser, open it again (as if you had a call before it could affect the results) and run the following command? You do not need to run it on any special page, just open a private window and run it there, without visting any URL:

navigator.mediaDevices.getUserMedia({ video: true }).then(stream => {
    console.log(stream.getVideoTracks()[0].getSettings())

    stream.getTracks().forEach(track => {
        track.stop()
    })
})

Then, could you start a call and run the following command when you see the warning? It would be interesting to know if the issue is somehow related to your camera:

OCA.Talk.SimpleWebRTC.webrtc.peers[0].pc.getSenders().forEach(sender => {
    if (sender.track) {
        console.log(sender.kind, sender.track.getSettings())
    } else {
        console.log(sender.kind + ": no track")
    }
})

Thanks.

Sometimes in Nextcloud Talk the video and audio are getting out of sync (video is late to the audio), also when no warning is active. That's pretty distracting and does not fix itself. Is that a known issue, or do I need to open a new issue for this?

I have never seen that :shrug: Feel free to open a new issue, but please keep in mind that nothing special is done in Talk regarding synchronization of audio and video (and as far as I am aware it can not be controlled either from the WebRTC APIs, the synchronization is transparent to the application). This could be related as well to the simulcast issue, or to how simulcast is handled by the browser and Janus.

jacotec commented 2 years ago

Could you close your browser, open it again (as if you had a call before it could affect the results) and run the following command? You do not need to run it on any special page, just open a private window and run it there, without visting any URL:

navigator.mediaDevices.getUserMedia({ video: true }).then(stream => {
    console.log(stream.getVideoTracks()[0].getSettings())

    stream.getTracks().forEach(track => {
        track.stop()
    })
})

This returns:

{
    "aspectRatio": 1.3333333333333333,
    "brightness": 128,
    "colorTemperature": 4601,
    "contrast": 128,
    "deviceId": "b562c9e73b1afc4a1204bf0dc4c0d1904ca753adefde43dda79292df9c1a3e37",
    "exposureCompensation": 134,
    "exposureMode": "continuous",
    "exposureTime": 156.25,
    "focusDistance": 0,
    "focusMode": "continuous",
    "frameRate": 30,
    "groupId": "f56b28c38bf9bd3064aa8ebc28b0dbd29797a5995bc6c8eaa629b2b2e701026a",
    "height": 480,
    "resizeMode": "none",
    "saturation": 128,
    "sharpness": 128,
    "whiteBalanceMode": "continuous",
    "width": 640
}

Then, could you start a call and run the following command when you see the warning? It would be interesting to know if the issue is somehow related to your camera:

OCA.Talk.SimpleWebRTC.webrtc.peers[0].pc.getSenders().forEach(sender => {
    if (sender.track) {
        console.log(sender.kind, sender.track.getSettings())
    } else {
        console.log(sender.kind + ": no track")
    }
})

I'm getting two objects then:

{
    "autoGainControl": true,
    "channelCount": 1,
    "deviceId": "default",
    "echoCancellation": true,
    "groupId": "8edba09e959890e698e9c2ff5959f227ddfcbe73efc01bd2766e59d5b9a2c366",
    "latency": 0.01,
    "noiseSuppression": true,
    "sampleRate": 48000,
    "sampleSize": 16
}

{
    "aspectRatio": 1.3333333333333333,
    "brightness": 128,
    "colorTemperature": 4586,
    "contrast": 128,
    "deviceId": "4e848a0711f0f1dac0fc34f138d866b2c5cad4db94a010cbbcec6743ab60d603",
    "exposureCompensation": 129,
    "exposureMode": "continuous",
    "exposureTime": 312.5,
    "focusDistance": 0,
    "focusMode": "continuous",
    "frameRate": 30,
    "groupId": "e269184ddb51e6de4b027ac8ea7d7d7018a98c4a99bccea5edb2fe6ded507161",
    "height": 540,
    "resizeMode": "crop-and-scale",
    "saturation": 128,
    "sharpness": 128,
    "whiteBalanceMode": "continuous",
    "width": 720
}

More interesting stuff:

danxuliu commented 2 years ago

Thanks for the information.

I have finally been able to reproduce the issue :-) It is not related to the camera; as previously suspected it is related to simulcast and how the stats are reported in that case. It is not exactly what I described before (the problematic stat is packetsSent, not bytesSent, and its value may not be 0), but the problem is anyway that according to the stats nothing is sent in that stream (I do not know if in fact nothing is sent in that stream (even if it is sent in the others) or if the stats are wrong). I will work on a fix for that.

Also in the no-warning-calls I see the same video stream with these 0 packets sent.

There are two possible reasons for that. One is that the last stream reported in the stats is not the stalled one, so the one analyzed is an active one and it works as expected.

The second reason is that, even if the last stream reported in the stats is the stalled one, the warning would not be shown if the first analyzed stats did not include a remote-inbound-rtp element; this would cause packetsLost to become NaN and this value would be dragged through the rest of the computed values, preventing the analyzer from noticing a stalled stream. I will work on a fix for that too.

Regarding the not-in-sync issue: As BBB and Jitsi are also using Web-RTC and we're talking about the same machine, same browser and same webcam (Logitech C920) they should receive the same streams as well. Strangely I never see any async issues here.

As far as I know neither BBB nor Jitsi use Janus as their WebRTC gateway, so even if it is the same machine, browser and webcam the underlying system would be different, and Chromium may handle the streams in a different way. As mentioned, feel free to open a new issue about that.