Closed Bug 1636614 Opened 4 years ago Closed 4 years ago

meet.google.com takes 10 seconds until others start hearing my audio

Categories

(Core :: WebRTC: Audio/Video, defect, P2)

Product:
Core
Component:
WebRTC: Audio/Video
Version:
78 Branch
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Tracking Flags:
Tracking Status
firefox-esr68 --- unaffected
firefox-esr78 --- fixed
firefox76 --- wontfix
firefox77 --- wontfix
firefox78 --- wontfix
firefox79 --- fixed
firefox80 --- fixed

People

(Reporter: hmitsch, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: regression)

Attachments

(9 files)

logs-firefox.child-11.moz_log
1.56 MB, application/octet-stream
Details
logs-firefox.child-7.moz_log
112.00 KB, application/octet-stream
Details
aboutsupport.txt
25.35 KB, application/octet-stream
Details
logs-firefox.child-1.moz_log
504.00 KB, application/octet-stream
Details
hmitsch-about-support.txt
14.70 KB, text/plain
Details
hmitsch-logs-firefox.child-4.moz_log
996.00 KB, application/octet-stream
Details
hmitsch-aboutWebrtc.html
42.04 KB, text/html
Details
about:support for Firefox Nightly also showing the issue
22.24 KB, text/plain
Details
duncan-about-support-20200610.txt
24.38 KB, text/plain
Details

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:78.0) Gecko/20100101 Firefox/78.0

Steps to reproduce:

  • Join a Google Meet meeting
  • Start talking after you are successfully logged in

Actual results:

It takes about 10 seconds until the other meeting participants start hearing my audio

Expected results:

Audio should be heard immediately

I can confirm I also have this problem with Firefox 76 on Ubuntu 20.04. I can always hear other people but it takes 10 or 15 seconds before anyone can hear me.

Component: Untriaged → WebRTC: Audio/Video
Product: Firefox → Core

Hi, thanks for filing an issue. Would you mind trying to reproducing with
logging enabled, so we can look into this?

Here are the steps, depending on if you are comfortable with the terminal:

Without the terminal

  • Open a new tab, and type about:config in the address bar
  • Type security.sandbox.content.level, and change the value to 0
  • Restart Firefox
  • Open a new tab, and type about:networking in the address bar
  • Click on the Logging section on the left hand side of the page
  • In the input Current Log Modules, copy and paste the following instead of
    what’s present:

timestamp,sync,cubeb:5

  • Click Start Logging
  • Reproduce the bug
  • Get all the files indicated on the about:logging page (ending with numbers),
    zip them up, and attach them to the bug
  • Open a new tab, and type about:config in the address bar
  • Type security.sandbox.content.level, and change the value to what it was
    with the little arrow on the right
  • Restart Firefox

With the terminal

  • Close Firefox
  • Open a terminal
  • On macOS:
    • Run MOZ_DISABLE_CONTENT_SANDBOX=1 MOZ_LOG=cubeb:4,MediaManager:4 MOZ_LOG_FILE=logs-firefox /Applications/Firefox.app/Contents/MacOS/firefox, or another path if it's a pre-release Firefox, such as FirefoxNightly.app, etc.
  • On Linux Desktop:
    • Run MOZ_DISABLE_CONTENT_SANDBOX=1 MOZ_LOG=cubeb:4,MediaManager:4 MOZ_LOG_FILE=logs-firefox /usr/bin/firefox, or another path if Firefox is installed in a non-standard location
  • Reproduce the problem
  • Gather the files that have appeared in the current directory, starting by logs-firefox with numbers at the end and attach them to the bug

Thanks again!

Flags: needinfo?(weston.sam)
Flags: needinfo?(mitsch)

Because this bug's Severity is normal and has not been changed, and this bug's priority is -- (none,) indicating it has has not been previously triaged, the bug's Severity is being updated to -- (default, untriaged.)

Severity: normal → --

Hi. Sorry for the slow reply. I've managed to capture logs for a call I joined this morning and have verified that this definitely happens with every call I join on both my Ubuntu 20.04 machines running Firefox.

Flags: needinfo?(weston.sam)

Would it be possible to try getting logs with the following modules:

MOZ_DISABLE_CONTENT_SANDBOX=1 RUST_LOG=audioipc=debug MOZ_LOG=cubeb:4,MediaManager:4,timestamp MOZ_LOG_FILE=logs-firefox /usr/bin/firefox

this might log in the console, if you can copy paste that or redirect to a file.

Can you also try going to about:config, flip media.cubeb.sandbox to false, restart, and try again? And also attach your about:support.

Thanks!

Flags: needinfo?(weston.sam)

Ok here is the main log from the call I just had.

Only console log was:
[2020-05-13T13:00:28Z WARN audioipc_server::server] Promotion of content process thread to real-time error

And logs-firefox.moz_log:
2020-05-13 13:00:20.214521 UTC - [Parent 316281: Main Thread]: D/cubeb Starting cubeb server...
2020-05-13 13:00:28.363375 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/media/libcubeb/src/cubeb.c:572: DeviceID: "alsa_output.pci-0000_00_1f.3.analog-stereo.monitor"
Name: "Monitor of Built-in Audio Analogue Stereo"
Group: "/devices/pci0000:00/0000:00:1f.3/sound/card0"
Vendor: "
2020-05-13 13:00:28.363386 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/media/libcubeb/src/cubeb.c:572: DeviceID: "alsa_input.pci-0000_00_1f.3.analog-stereo" (PREFERRED)
Name: "Built-in Audio Analogue Stereo"
Group: "/devices/pci0000:00/0000:00:1f.3/sound/card0"
Vendor: "Intel Co
2020-05-13 13:00:28.363671 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/media/libcubeb/src/cubeb.c:572: DeviceID: "alsa_output.pci-0000_00_1f.3.analog-stereo" (PREFERRED)
Name: "Built-in Audio Analogue Stereo"
Group: "/devices/pci0000:00/0000:00:1f.3/sound/card0"
Vendor: "Intel C
2020-05-13 13:00:28.773798 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/third_party/rust/cubeb-pulse/src/backend/stream.rs:476: Output buffer attributes maxlength 4194304, tlength 11016, prebuf 8824, minreq 2200, fragsize 4294967295
2020-05-13 13:00:29.450293 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/third_party/rust/cubeb-pulse/src/backend/stream.rs:764: Layout undefined, PulseAudio will use its default.
2020-05-13 13:00:29.462415 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/third_party/rust/cubeb-pulse/src/backend/stream.rs:476: Output buffer attributes maxlength 4194304, tlength 11016, prebuf 8824, minreq 2200, fragsize 4294967295
2020-05-13 13:00:29.462420 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/third_party/rust/cubeb-pulse/src/backend/stream.rs:489: Input buffer attributes maxlength 4194304, tlength 8816, prebuf 4294967295, minreq 8816, fragsize 8816
2020-05-13 13:00:32.862316 UTC - [Parent 316281: Unnamed thread 0x7ff4d6acd040]: E/cubeb /build/firefox-wENs9o/firefox-76.0.1+build1/third_party/rust/cubeb-pulse/src/backend/stream.rs:476: Output buffer attributes maxlength 4194304, tlength 48000, prebuf 38408, minreq 9600, fragsize 4294967295

Attached file aboutsupport.txt —

about support.txt

With media.cubeb.sandbox set to false (no difference to bug unfortunately). No other cli output or log files.

Flags: needinfo?(weston.sam)

Hrm this all looks reasonably normal unfortunately. Can you try to bump cubeb logs to 5 (this will output a LOT of data, up to date command below). Can you repro on https://mozilla.github.io/webrtc-landing/gum_test.html, when clicking "Microphone" (that should just pipe the mic into the output device, maybe we can repro the delay there?).

MOZ_DISABLE_CONTENT_SANDBOX=1 RUST_LOG=audioipc=debug MOZ_LOG=cubeb:5,MediaManager:4,timestamp MOZ_LOG_FILE=logs-firefox /usr/bin/firefox

Do you know if you have anything strange on this computer? How do other browser/program that use the mic perform?

When you have this delay, and then finally the people in your call hear you, does the latency between participant sound OK? Like maybe a few hundreds millisecond between talking and the other person hearing you, or is there a delay buildup that makes the whole system unusable, like, you talk, and then the person hear you a entire seconds later ?

Flags: needinfo?(weston.sam)

So that page works fine straight away. Just to be clear this isn't a latency issue but rather that I am effectively on mute for 10-15 seconds after joining the call (although the gui suggests I'm not). I can hear everyone else and the moment the problem resolves the latency is fine as far as I'm aware.

I don't think it's just this machine or a Linux issue as the original reporter was on OSX. If I make a Slack call from the Electron app on this machine that works just fine. I also had this issue on Ubuntu 19.10 with Firefox but not Chromium. Although I don't have Chromium installed at the moment since I upgraded. Unfortunately Slack calls don't work in Firefox so I need to find something other than Hangouts Meet to try in browser.

I'll grab those debug logs tomorrow morning when I join my standup.

The gum_test works fine for me, too.

I have the exact same issue Sam describes and I am on macOS. Slack calls, Telegram calls, Zoom calls all work flawlessly.

Flags: needinfo?(mitsch)

First of all, thanks for all the help. This is amazing.

I finally ran the tests you requested.

  • Created a new Firefox profile
  • Verified that media.cubeb.sandbox is set to false (no change needed)
  • Launched firefox with this command MOZ_DISABLE_CONTENT_SANDBOX=1 RUST_LOG=audioipc=debug MOZ_LOG=cubeb:5,MediaManager:4,timestamp MOZ_LOG_FILE=logs-firefox /Applications/Firefox\ Nightly.app/Contents/MacOS/firefox
  • Logged into Google Meet from my phone.
  • Joined that Google Meet from the Firefox session.
  • Firefox takes about 10-15 seconds until audio is transmitted.
    • In the Firefox session, the audio equalizer icon shows that audio is being received.
    • On the phone app, the audio equalizer icon is NOT moving, indicating that the other end (Firefox session) does not transmit sound.
    • After 10-15 seconds sound kicks in and the equalizer on the phone app moves accordingly.
  • Once sound works there are no weird latency or sound delay issues.

about:support and logs-firefox.child-4.moz_log are attached. Hope this helps to track down the issue.

-Henrik

Flags: needinfo?(padenot)
Blocks: meet
Severity: -- → S3
Priority: -- → P2

Ok. This means the issue lies further down, and not at the audio IO layer. Nico, would you mind shepherding this further ?

Flags: needinfo?(padenot) → needinfo?(na-g)
Summary: meet.google.com audio starts delayed → meet.google.com takes 10 seconds until others start hearing my audio

Henrick, thanks for your help so far, if you have time could you reproduce this in a freshly opened browser, and check about:webrtc. There should be information for your call. There is a Save Page button at the top of that page. Uploading that would allow me to look at the SDP.

The fact that there is a 10 second delay for one type of media after the other has started is quite odd as we don't have any timers after we have set up the transports, which are obviously set up as video is being transported. This may be an issue on Meet's end.

Flags: needinfo?(na-g) → needinfo?(mitsch)

Hi Nico,

sorry it took so long to generate the file. This is captured with the latest nightly on macOS.

Best regards,
Henrik

Flags: needinfo?(mitsch) → needinfo?(na-g)

I think bug 1556277 is a duplicate of this one.

I wonder if something changed? With recent Nightlies (currently on 78.0a1 (2020-05-27)) I can't reproduce the issue.

-Henrik

This is now working perfectly on Ubuntu on 76.0.1. I didn't even need to install the nightly, I guess Google fixed it in Meet?

Flags: needinfo?(weston.sam)

Apologies, I may have jumped the gun. It didn't happen on my first call of the day but happened on at least some of the later ones (not certain if all). I'll do some further testing.

I think the issue becoming intermittent a week ago was Google rolling the fix out gradually. I haven't had it in a few days now. Is anyone still having this problem?

Hi. I'm still having this problem. I'm on Win 10. Happens every Google Meet call on both Firefox and Firefox Developer.

Thought I'd test Nightly as well. I found the same issue there. I'll attach my about:support info. Let me know if you want anything else.

Suspected S1 bug. I've even had external reports of this directly to me.

Severity: S3 → S1

The issue is present on old versions going back to:

Name: Firefox
Version: 65.0.2
Build ID: 20190225143501
Update Channel: release
User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0
OS: Windows_NT 10.0
Multiprocess Windows: 1/1 (Enabled by default)
Web Content Processes: 4/4
Enterprise Policies: Inactive
Google Key: Found
Mozilla Location Service Key: Found
Safe Mode: false

Unless my testing is flawed, there is something else going on here. [I don't recall this issue going this far back]

How I tested:

At all times, my Firefox Developer and Firefox Nightly installations were still present on my machine.

Let me know how else I can help test.

Duncan, thank you for regression testing this, that was extremely helpful. I think the next step will be us following up with the Meet team.

Flags: needinfo?(na-g)

Yeah, this sounds like a problem in meet.

I have also attempted to reproduce it and find a regression window:

24:58.09 INFO: Got as far as we can go bisecting nightlies...
24:58.09 INFO: Last good revision: 9131063a5ce0676336736f15d01bb5d9a2b9ad32 (2019-05-29)
24:58.09 INFO: First bad revision: e09471d136599b68f40f6bb9ec7fcc419732948e (2019-05-30)
24:58.09 INFO: Pushlog:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=9131063a5ce0676336736f15d01bb5d9a2b9ad32&tochange=e09471d136599b68f40f6bb9ec7fcc419732948e

This is all I could get with the available builds (using mozregression). It was done on Ubuntu 18.04.4LTS.
I DO WORRY that it might be an intermittent issue, so the result may not be correct. I did restart the call a few times for every build to make sure whether it's a bad or a good built at, every step. If it does seem incorrect, please NI me and I'll reattempt to obtain a regression window.

status-firefox76: --- → affected
status-firefox77: --- → affected
status-firefox78: --- → affected
status-firefox79: --- → affected
Keywords: regressionwindow-wanted → regression

So bug 1333879 is in that window from comment 31; let me check if meet answering with multiple codecs.

Yeah, meet is answering with multiple audio codecs. We should verify that we are sending opus, just to make sure.

We're sending opus, which is what the answer prefers, so I'm not sure what could be going on here that meet does not like.

Any ideas here?

Flags: needinfo?(saeed)

We started looking into this. I'll let you know what we find.

So far we haven't been able to reproduce this with Firefox 76 and 77 on macOS Catalina.

If you have a repro, would you mind filing feedback from inside that Meet call? Click the "..." menu > "Report a problem", and include "saeed" in the feedback description.

Hi. I just reproduced it, reported a problem from with the Meet call, and added the comment:

The initial audio on this call was delayed by 10-15 seconds.

I believe it's a bug between Meet and Firefox.

cc saeed

In case it helps, I'll attach my support info again.

Byron, comment 32 seems to imply we might have regressed/provoked this due to another change. As this is an S1, should we consider mitigating on our side?

Flags: needinfo?(docfaraday)

We still have no idea what is actually going on here. On our side, everything looks fine.

Flags: needinfo?(docfaraday)

Hi again. Thought I might add some info here - the behaviour seems reproducible.

Scenario:

  1. Join a meet.google.com call. Initial audio is delayed (as we're discussing here). But now...
  2. Click "Leave call" (the red phone button)
  3. Click the "Rejoin" button
  4. Click the "Join now" button. You join the same call again - audio begins immediately.

Even if you don't wait the 10-15 seconds at step 1, audio begins immediately at step 4.

I hope that helps narrow down something.

(In reply to Saeed Jahed from comment #37)

So far we haven't been able to reproduce this with Firefox 76 and 77 on macOS Catalina.

If you have a repro, would you mind filing feedback from inside that Meet call? Click the "..." menu > "Report a problem", and include "saeed" in the feedback description.

I can repro every time on Catalina with 76 and 77.

I am double-checking the regression range, and with the nightly from 5/30/19 (the first bad nightly from comment 31), audio never starts flowing. Nightlies after that have a 10 second (or so delay).

So the regression range in comment 31 is valid on OS X Catalina. I'm going to try to bisect further with local builds, but that's going to take a while.

Well, it looks like building anything from a year ago is impossible due to changes in rust...

Finally! Someone in our team was able to repro this as well. So we'll do some debugging and see if we can identify the root cause.

Flags: needinfo?(saeed)

Just to update, we are working on a fix for this. I'll ping again once it's available.

Let me know if there's anything we can/should do on our end.

Wanted to share a funny-not-so-funny story on this thread:

In our team, we started to adopt the term foxmuted to indicate the first 10 seconds until the voices of our Firefox users can be heard.

Saeed from Meet here.

We think we have a fix for this issue. Can those of you who were having this issue, take a look and see if they're still running into the issue still?

Hi Saeed.

Just letting you know the fix seems to work for me.

I've tried both on Firefox Developer (version 79.0b6) and Firefox (version 78.0.2).

Thanks for your effort here.

Duncan.

Hi Saeed,

I can confirm that Meet is now working fine on Firefox Nightly, 80.0a1 (2020-07-12) on MacOS.

Thanks for taking care of the issue!

Best regards,
Henrik

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED

Awesome! Thanks!

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: