1444567 - speechd/speech-dispatcher affects all system audio (was: Opening Google Translate corrupts audio for all other tabs)

Status: NEW

(Core :: Web Speech, defect, P3)

Description

[Vash63]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101 Firefox/60.0
Build ID: 20180309100425

Steps to reproduce:

1. Play a video on Youtube (Other audio sources work also).
2. Open up https://www.google.com/search?q=dutch+to+english&ie=utf-8&oe=utf-8&client=firefox-b-1-ab

Note, this cannot be duplicated on translate.google.com - only on the search results page with the google translate card widget at the top.


Actual results:

Audio in Youtube continues playing but with horrible crackling noises and a delayed echo of everything. If I pause or stop the YT playback, the corrupted echo continues at about a 1-2s delay. This issue continues until I fully close Firefox and start the browser again.


Expected results:

Audio should continue to play without corruption.

Comment 1

[Vash63]

I cannot duplicate this in either Chromium on the same system, or if I boot to Windows and try it in Firefox on Windows. I can duplicate this on 58 Stable in Linux.

Comment 2

[David Olah]

Managed to reproduce the bug on Ubuntu 16.04, Nightly 61.0a1 (2018-03-13) only at first try.

Comment 3

[Maire Reavy [:mreavy]]

p1 at least for investigation of what the URL in point 2 of comment 0 is doing, audio-wise (I presume GetUserMedia or equivalent).  Given this is apparently linux-only (worth testing on Mac), this may be a Pulse issue.

Comment 4

[Vash63]

I also have a Mac running High Sierra on Nightly 2018-05-09 and cannot reproduce it there.

Comment 5

[Nico Grunbaum [:ng, @chew:mozilla.org]]

On Ubuntu 17.10, I can not reproduce this on today's nightly 2018-05-10, but I can reproduce it in yesterday's nightly.

Comment 6

[Nico Grunbaum [:ng, @chew:mozilla.org]]

I take that back, I can reproduce it on nightly if I use a different video. The problem doesn't seem to present it self with low audio levels. Here is a video that demonstrates that behavior:  https://www.youtube.com/watch?v=SBljWDJFe7c with both quiet and loud audio.

Comment 7

[Alex Chronopoulos [:achronop]]

Hi and sorry for the late response, do you still have the issue? If yes can you try to reproduce it with a custom binary that I will give you?

Comment 8

[Nico Grunbaum [:ng, @chew:mozilla.org]]

I tried today's nightly in Ubuntu 18.04 and can no longer reproduce this.

Comment 9

[Alex Chronopoulos [:achronop]]

Maybe David is able to test something for me if he is able to repro reliable?

Comment 10

[Vash63]

Hey guys, I'm still able to reproduce. Sorry for the delay, I didn't have access to my PC for a few days.

Comment 11

[Vash63]

And yes, I could test a custom firefox binary.

Comment 12

[Alex Chronopoulos [:achronop]]

Thanks, this is a x64 Linux build:
https://queue.taskcluster.net/v1/task/E469gmYHS9WHP3i_yNN-Sg/runs/0/artifacts/public/build/target.tar.bz2

Comment 13

[Vash63]

I can still duplicate the issue on that build.

Comment 14

[Alex Chronopoulos [:achronop]]

Thanks for checking, can you please post the info from about:support page?

Comment 15

[Vash63]

Attachment: about:support text output

Support output attached.

Comment 16

[David Olah]

Alex, do you still need me to help you with the testing?

Comment 17

[Alex Chronopoulos [:achronop]]

Since Vash63 tested my built it's not necessary for you to do anything right now. If you can repro though, you could help in the future.

Comment 18

[Alex Chronopoulos [:achronop]]

I'm afraid I cannot see a clear indication of the problem. One thing we could test is to turn off the "media.cubeb.sandbox" (set to false) and try to repro. In order to do that please go to about:config page and search for this parameter, set it to false and restart the browser.

If that does not change anything I will ask you to obtain logs. Thanks!

Comment 19

[David Olah]

I also downloaded the build that you uploaded and tried the following cases:

- accessed a youtube video
- in a new tab accessed the translate link
1. write text to translate
2. copy short text multiple times
3. copy long text
Note: I tried with different youtube resolutions, even 4k.

I could not reproduce the issue in neither of the cases above, neither with media.cubeb.sandbox set to false.
I also tried on the latest Nightly 63.0a1 (2018-07-31), and didn't managed to reproduce there neither.

Comment 20

[Vash63]

media.cubeb.sandbox doesn't appear to have any impact on it, still the same thing.

A note for testing methodology, you don't need to type anything in the translate link - simply clicking the link and displaying it on screen is enough for the audio in all tabs to get corrupted permanently until the browser is closed and then restarted. Also this isn't specific to Youtube, I just used that as an example - playing audio in Google Music, Vimeo or other sites with audio also get corrupted. The only constant is that I can only trigger it by asking Google to translate one language to another, I haven't found any other pages that trigger the browser's audio to stop working properly. And as mentioned in the initial report, this *only* occurs on the Google search pages, using translate.google.com does not cause the same problem.

Strangely, middle clicking the link and letting it stay in the background does not cause the issue - the issue occurs only once the tab is focused the first time.

Regarding comment #18, what logs would you need? Running 'firefox' from a terminal doesn't provide much in stderr or stdout that looks useful.

Comment 21

[Alex Chronopoulos [:achronop]]

So strange behavior ...

Can you please try changing another param: security.sandbox.content.level set it to 0.

Thank you for checking the logs. In order to make firefox produce more logs you need to set the following env var:
MOZ_LOG=cubeb:4,MediaStreamGraph:4,AudioStream:4
Logs will appear in your stdout, if you can copy to a file and attach here would be great.

Comment 22

[Vash63]

Attachment: fflog.txt

Still happens. Some additional testing:

The corruption specifically seems to be causing an echo, if I pause and resume the audio playback I can tell that it is repeating the same source audio twice about a second apart, though they sound pretty different (different volumes at very least, it's pretty distorted). 

Finally, I played some audio with Steam (which uses Chromium) after bringing up the web page in Firefox and was able to duplicate it there also... so it seems that Firefox is somehow putting Pulse or alsa in a bad state. As before the issue immediately clears up when the browser is closed though.

Comment 23

[Alex Chronopoulos [:achronop]]

Sorry not a clear evident of an error in the logs too. I see the the audio starting. I see also some IPC errors but I am not  sure how to evaluate them.

One more thing to try would be to test using a fresh new (empty) profile. I see you have 2 google translate extension on your current profile. I would not expect to affect it but you never know.

Comment 24

[Alex Chronopoulos [:achronop]]

Matthew, can you have a look at this one in case you have any better idea.

Comment 25

[Vash63]

I was able to reproduce this on a fresh profile also. I've had this issue longer than those extensions so I knew it wasn't those but this should also rule out any about:config changes.

I'm using a stock default config shipped with Arch right now. Looking over the PKGBUILD the only settings change I see is:

  sed -e '/flat-volumes/iflat-volumes = no' \
      -i etc/pulse/daemon.conf

  sed -e '/autospawn/iautospawn = no' \
      -i etc/pulse/client.conf

Which I don't think either of these settings should be problematic. 

source: https://git.archlinux.org/svntogit/packages.git/tree/trunk/PKGBUILD?h=packages/pulseaudio

Also, given that two others here were able to reproduce it I don't suspect it's an issue with my pulse config but I'll try toggling these back to default and report back if that fixes it.

Comment 26

[Matthew Gregan [:kinetik]]

(In reply to Vash63 from comment #20)
> media.cubeb.sandbox doesn't appear to have any impact on it, still the same
> thing.

Just to clarify, did you restart Firefox after changing this pref?  It requires a restart to take effect.

Which version of Firefox were you using to produce the fflog.txt file in comment #22?

Can you also try setting the media.cubeb.backend pref (you'll need to create it, it doesn't exist by default) to "pulse", restart, and see if the issue is still present?  You can delete the pref safely after testing.

Comment 27

[Matthew Gregan [:kinetik]]

(In reply to Matthew Gregan [:kinetik] from comment #26)
> Which version of Firefox were you using to produce the fflog.txt file in
> comment #22?

It looks like it must've been 61? If you could retry the logging with a current Nightly that might be useful.

[Parent 30463: Unnamed thread 0x7f0822b40700]: E/cubeb media/libcubeb/cubeb-pulse-rs/src/backend/stream.rsattempt to divide by zero:51: Requested buffer attributes maxlength {}, tlength {}, prebuf {}, minreq {}, fragsize {}
[Parent 30463: Unnamed thread 0x7f0822b40700]: E/cubeb media/libcubeb/cubeb-pulse-rs/src/backend/stream.rsattempt to divide by zero:51: Output buffer attributes maxlength {}, tlength {}, prebuf {}, minreq {}, fragsize {}

The logging in cubeb-rs is fixed in Nightly, so we should get actual values instead of {} for these messages.

I'm suspicious about the "attempt to divide by zero" messages there too, but it's not clear where they're originating from.

Comment 28

[Vash63]

Attachment: Nightly 2018-08-10 w/ MOZ_LOG=cubeb:4,MediaStreamGraph:4,AudioStream:4

The initial log was from the build provided in this thread. I've made a new one with the latest nightly build, this was with media.cubeb.backend = "pulse" and the default security.sandbox.content.level = 0. Strangely, I noticed the AudioStream init lines go when I started playing music on play.google.com, but *zero* lines logged when I opened the page on Google's search results page that triggers the issue. Whatever that page does doesn't seem to log with these flags.

And yes, I have restarted Firefox after every pref change when testing.

Comment 29

[Alex Chronopoulos [:achronop]]

I am afraid logs are not the expected and it is not your fault. We haven't clarified that you need to have both "media.cubeb.sandbox" = false and media.cubeb.backend = "pulse" in order to get the desired result (always restart). Sorry for the inconvenience!

Comment 30

[Vash63]

Attachment: Nightly 2018-08-10 w/ media.cubeb.sandbox = false, media.cubeb.backend = "pulse", MOZ_LOG=cubeb:4,MediaStreamGraph:4,AudioStream:4

Okay, new one is uploaded. I did notice this time when opening up the Google Translate window it added one extra line, but not any different than the one when I started the app or song playback:

[Child 15225: Main Thread]: I/cubeb media.cubeb.sandbox: false

pid 15225's creation is when the audio became garbled. The pipe errors didn't come up until I closed the tab and aren't related.

Comment 31

[Matthew Gregan [:kinetik]]

Thanks for the logs.  It's not clear what's going on from what we can see.  Would you mind also attaching PulseAudio verbose logs (instructions here: https://wiki.ubuntu.com/PulseAudio/Log) - that might allows us to see what's changing in the PA server around the time the process creation is logged and the audio becomes corrupted.

Comment 32

[Vash63]

Attachment: pulselog2.log

Okay, new log attached. It's started by a systemd user service so the formatting is a bit ugly after journalctl parsed it (couldn't get it to boot with just the 'pulseaudio' command, was still being autostarted). 

It's pretty difficult for me to follow, but I do see a lot of 'rewinds' being requested that seem potentially dangerous. The audible corruption *is* a heavily distorted repeat about 100ms later (though both the repeat and the original are distorted).

Comment 33

[Matthew Gregan [:kinetik]]

Sorry, I didn't see your response until just now.  So it looks like Firefox's media code (media.name = AudioStream, application.name = Nightly) created a stream for playback at 14:15:42 and behaves normally for ~8 seconds and then something else (media.name = playback, application.name = speech-dispatcher) creates a stream at 14:15:50 and requests an incredibly low latency:

Aug 16 14:15:50 vashnix pulseaudio[20200]: (  20.866|   0.000) D: [pulseaudio] protocol-native.c: Requested latency=0.29 ms, Received latency=0.50 ms

...after which, PulseAudio's server fails to work correctly until it's restarted (under-running and rewinding to recover).  That's an unrealistically low latency to request, but I'm also not sure why the PA server honours it since there's not much chance it'll work correctly.

There are a bunch more connections from "speech-dispatcher" made around the same time.

I'd guess the Google results page is using the Web Speech API, which triggers usage of libspeechd via SpeechDispatcherService (https://searchfox.org/mozilla-central/source/dom/media/webspeech/synth/speechd/SpeechDispatcherService.cpp).  It doesn't look like we pass any latency-related parameters to libspeechd, so I suspect a configuration issue with libspeechd at the Linux distro level, perhaps?  I see similar sounding problems reported on Arch before, although with no clear resolution: https://bbs.archlinux.org/viewtopic.php?id=215987

I'll needinfo Eitan, who implemented this, in case he has any ideas.

Comment 34

[Matthew Gregan [:kinetik]]

Forgot to mention: to test the theory that libspeechd via the Web Speech API is involved, you could try setting the pref media.webspeech.synth.enabled to false and see if the problem is still reproducible.

Comment 35

[Matthew Gregan [:kinetik]]

FWIW, it looks like libspeechd/speech-dispatcher behaves the same way on my Fedora 27 setup (i.e. requesting an unusually small latency), but it doesn't cause the PA server to underrun - so possibly the difference is at the PA level or below (hardware accepting different params?).

Comment 36

[Vash63]

Yes! I can confirm that media.webspeech.synth.enabled toggled to 'false' fixes the issue for me. For my purposes that's all I'm going to be needing as I don't even use the text to speech part, so this is great.

And for what it's worth I don't _remember_ this happening with my old motherboard, so this definitely might be sound definitely vary by hardware/driver.

Comment 37

[Matthew Gregan [:kinetik]]

Filed a bug against speech-dispatcher: https://github.com/brailcom/speechd/issues/45

Comment 38

[Eitan Isaacson [:eeejay]]

Thanks Matthew for debugging this.

speech dispatcher uses a low latency because it is designed for screen reader use.

Maybe a longer term goal would be to not use speech dispatcher on Linux, but maybe espeak directly. It would give us a few more advantages like concurrent speech (instead of a single queue), word boundary events, and bugs like this.

Something to think about.

Comment 39

[Alex Chronopoulos [:achronop]]

That was a great finding Matthew thanks a lot. Do you know which component/person is the best to own this bug?

Comment 40

[Matthew Gregan [:kinetik]]

(In reply to Alex Chronopoulos [:achronop] from comment #39)
> That was a great finding Matthew thanks a lot. Do you know which
> component/person is the best to own this bug?

It's triggered by our use of speechd, so I guess Web Speech is a better component than Audio/Video: Playback, but the actual bug is not in Gecko code, so the best we could do is find a workaround (if that's possible).

It'd be great if the owners of the Web Speech component could work with upstream to resolve this; the bug I filed against speechd hasn't been touched for nearly a month now.  Eitan, is that you or can you point us to a suitable owner for this issue?

Comment 41

[Eitan Isaacson [:eeejay]]

Sorry, I have no pull here. I think we need to port this stuff away from speech dispatcher. It is highly specialized for screen readers. I opened a bug 1496122 for this.

Comment 43

[Timur Davletshin]

Both stock FF build and official Mozilla FF 68.0.2 works according expectations in Debian 10 Buster.

Comment 45

[Matthew Gregan [:kinetik]]

This should be fixed upstream via https://github.com/brailcom/speechd/pull/76, but the Ubuntu bug tracking this still has recent reports of similar issues.

edit: https://github.com/brailcom/speechd/issues/198 is a recent related fix

Comment 46

[lruzicka]

I am still experiencing this issue on Fedora 34 in Firefox 87 and 88. Some youtube videos, especially classical music, have slight distortion on quiet sounds in the background, usually audible when they play piano or mezzopiano (quiet to mid-quiet).

When I set the webspeech variable to false, the issue went away. So, I think it is related.

I am on Fedora 34, Gnome Wayland, Firefox 88, system updated with testing versions.

Comment 48

[BugBot [:suhaib / :marco/ :calixte]]

The severity field for this bug is relatively low, S3. However, the bug has 3 duplicates and 6 See Also bugs.
:anatal, could you consider increasing the bug severity?

For more information, please visit auto_nag documentation.

Comment 49

[BugBot (nomail) [:suhaib / :marco/ :calixte]]

The last needinfo from me was triggered in error by recent activity on the bug. I'm clearing the needinfo since this is a very old bug and I don't know if it's still relevant.