Bug 83704 – [GTK] media/event-attributes.html fails if mixer is not at 100%

• Status: RESOLVED
• Resolution: FIXED
• Component: Tools / Tests

[Gustavo Noronha (kov)]

This is not that problematic for our bots, since we can control that, but it means the test won't pass locally in some cases, which is bad.

[Simon Pena]

I guess we could probably use amixer: <http://linux.die.net/man/1/amixer>,
the same way we're using pactl, and set the master volume to 100% before
running the tests, and restoring it afterwards.

[Simon Pena]

Created attachment 137073 [details]
Patch

[Simon Pena]

(In reply to comment #2)
> Created an attachment (id=137073) [details]
> Patch

It's worth noting that I've been unable to reproduce the claimed bug :-/. In my
system, with the mixer either muted or at non-100% volume, it doesn't result on
that test failing.

Before applying, it would be worth trying if this patch is really helping in
your case, Gustavo.

Also, we would need to state in the wiki at
<https://trac.webkit.org/wiki/WebKitGtkLayoutTests> that alsa-utils are now
also recommended.

Let's not hurry pushing this, since Phil also said this test was failing in his
environment, so he can confirm whether this helps or not.

[Philippe Normand]

In my Debian setup alsactl is in /usr/sbin which is not in my PATH. This needs to be double-checked before deployment of this patch, the GTK bots run on Debian.

[Philippe Normand]

Hum even with the patch and my PATH fixed I get those 2 failing :(


  media/event-attributes.html = TEXT
  media/sources-fallback-codecs.html = TEXT

[Philippe Normand]

Comment on attachment 137073 [details]
Patch

Marking r- as it doesn't seem to totally fix the issue, although I liked this approach :/

[Raphael Kubo da Costa (:rakuco)]

What does the failure look like? We've been experiencing some failures on the EFL bot for a few revisions in this test.

[Philippe Normand]

(In reply to comment #7)
> What does the failure look like? We've been experiencing some failures on the EFL bot for a few revisions in this test.

Volume value mismatches.

[Raphael Kubo da Costa (:rakuco)]

Like this?


@@ -13,14 +13,14 @@
 
 *** changing playback rate
 RUN(video.playbackRate = 2)
+EVENT(volumechange)
+
+*** pausing playback
+RUN(video.pause())
 EVENT(ratechange)
 
 *** setting volume
 RUN(video.volume = 0.5)
-EVENT(volumechange)
-
-*** pausing playback
-RUN(video.pause())
 EVENT(pause)
 
 *** seeking

[Philippe Normand]

Yep!

[Raphael Kubo da Costa (:rakuco)]

Hmm, both ports seem to be affected then, thanks for the answers. Retitling the bug.

[Jussi Kukkonen (jku)]

I think there's an actual bug here: unless the system volume is 100% there's an extra volumechange event (as can be seen in rakucos diff).

Originally the volume is 1.0. Then, apparently after play(), the volume is changed to the actual system volume (triggering the volumechange event if the system volume is something else than 100%). If I was a html app developer I'd find this very surprising.

Others, (chromium, firefox) do not expose the system volume through HTMLMediaElement.volume: HTMLMediaElement.volume 1.0 effectively means "the current system volume" and changing the system volume does not trigger volumechange events

Now, a case could be made for exposing system volume in the HTMLMediaElement (spec says "user agents may remember the last set value across sessions, on a per-site basis or otherwise, so the volume may start at other values"): in that case the original value "1.0" was wrong, it should always start at system volume.

[Jussi Kukkonen (jku)]

Created attachment 163124 [details]
test volumechange event

test that shows the extra volumechange event (if system volume is < 100%).


Output on my machine, EFL port:
--- 
Log:
* canplaythrough event, mute is false, volume is 1. Now calling play()
* volumechange event, mute is false, volume is 0.4220733642578125
---

[Philippe Normand]

(In reply to comment #12)
> I think there's an actual bug here: unless the system volume is 100% there's an extra volumechange event (as can be seen in rakucos diff).
> 
> Originally the volume is 1.0. Then, apparently after play(), the volume is changed to the actual system volume (triggering the volumechange event if the system volume is something else than 100%). If I was a html app developer I'd find this very surprising.
> 

Yes, this is due to PulseAudio's flat volumes feature combined with its modules to restore stream and device volume values I'm afraid.

I think we get an extra volumechange event because of that. Before running your test case can you disable the module-device-restore and module-stream-restore modules? And also disable the Flat volumes thing?

Speaking of a solution... maybe we should be more careful when monitoring the playbin2 volume property. Not sure what to do though, ideas welcome!

[Jussi Kukkonen (jku)]

(In reply to comment #14)
> Yes, this is due to PulseAudio's flat volumes feature combined with its modules to restore stream and device volume values I'm afraid.
> 
> I think we get an extra volumechange event because of that. Before running your test case can you disable the module-device-restore and module-stream-restore modules? And also disable the Flat volumes thing?

I still get the volumechange. but I think I failed to disable everything as pulseaudio clearly restores the volume for something (the element always gets the volume that was last set to a mediaelement). But you are right, it's not system volume, it's definitely "app-specific".

> Speaking of a solution... maybe we should be more careful when monitoring the playbin2 volume property. Not sure what to do though, ideas welcome!

Originally I thought we should just do what everyone else does (let HTMLElement volume=1.0 represent "current master volume")... but now I'd rather we fixed whatever goes wrong here and have pulseaudio handle this, it really does feel like a well working solution with Flat volumes and as far as I understand should be compliant as well.

So I think we just need to initialize the MediaElement properties as early as possible. It's not acceptable that muted and volume change drastically _after_ the player app calls MediaElement.play(). It's been a while since I've done anything with gstreamer so I'll have to read up on that...

[Jussi Kukkonen (jku)]

(In reply to comment #14)
> Yes, this is due to PulseAudio's flat volumes feature combined with its modules to restore stream and device volume values I'm afraid.

I've now re-tested, and it happens without any "-restore" modules (just flat volume feature seems to be enough). Without flat volume the htmlelement volume stayed at 1.0


(In reply to comment #15)
> So I think we just need to initialize the MediaElement properties as early 
> as possible. It's not acceptable that muted and volume change drastically 
> _after_ the player app calls MediaElement.play(). 

Based on looking at playbin2 and asking on #gstreamer, it seems this is the best we can get... playbin2 cannot know the volume it will have until it's playing.

Also, "muted" property does not actually change as I claimed, it's just "volume" that is adjusted.

[Jussi Kukkonen (jku)]

Oh, there's a bug in the patch: it sets the volume to "100" (without units): the result depends on the hardware (on my HW it ends up as <0.01%). should be "100%".

Patch WFM after fixing that -- although it's a nasty hack: setting system volume to 100% even for a short time is just wrong.


Also, documenting what I've learned on this for the benefit of anyone else trying to figure it out:
* This phenomenon of extra volume events is a feature of Pulseaudio as Philippe says (flat volumes + stream volume restore): we cannot tell beforehand what the volume of a stream will be.
* It seems to be spec compliant
* We as a pulseaudio using app cannot really avoid this even if we wanted to (at least I have not figured out how that is possible). The volume we show in UI and JS has to be the playbin volume (which usually, but not necessarily, is a PA stream volume).
* The additional volumechange and mutechange events are _unavoidable_, but we can make them happen in a more reasonable point in time: the data is available when we reach GST_STATE_PAUSED (instead of getting them after playback starts). This is a different bug though, I'll file that.

[Philippe Normand]

(In reply to comment #17)
> Oh, there's a bug in the patch: it sets the volume to "100" (without units): the result depends on the hardware (on my HW it ends up as <0.01%). should be "100%".
> 
> Patch WFM after fixing that -- although it's a nasty hack: setting system volume to 100% even for a short time is just wrong.
> 
> 

Well this is for tests purpose.

> * The additional volumechange and mutechange events are _unavoidable_, but we can make them happen in a more reasonable point in time: the data is available when we reach GST_STATE_PAUSED (instead of getting them after playback starts). This is a different bug though, I'll file that.

Please CC me :)

[Jussi Kukkonen (jku)]

I came back to thinking about this because we really should have unskipped tests before poking things like bug 96912.

I'm not very familiar with the test system itself but... would it be ok to compile a PA-using app that modifies the saved stream volume for this process  (based on the name "WebProcess" or whatever) before starting the test (so we could make sure the volume is 100% or another value), and then puts it back to what it was after testing? 

This would have the least effect on the system: no "system volume" changes and no changes to already running WebProcesses: only WebProcesses started after running this setup-app would be affected. The code itself is not complex (couple of call to pulse/ext-stream-restore.h and the logic to save the old values) and I believe it would replace both the amixer trick in the patch and PulseAudioSanitizer class already in the repo.

Unfortunately there's no python api for this and doing this with ctypes would require more knowledge than I have... So, is adding compiled test-setup-apps that depend on libpulse a bad idea? If it is then let's just get that amixer patch committed.

[Jussi Kukkonen (jku)]

(In reply to comment #19)
> would it be ok to compile a PA-using app...

philn had some understandable reservations on exactly this and pointed me to pulseaudio module-match, which does look like it might do the trick.

Unfortunately the only thing I can do with module-match is crash the daemon: https://bugs.freedesktop.org/show_bug.cgi?id=55135. At this point this looks like a pulseaudio bug.

[Jussi Kukkonen (jku)]

So, the pulseaudio module approach might work, once we can rely on the crash fix to be there... But that might take a long while.

In the meantime should we go with the brute force method as in Simons patch for now -- forcing the system volume to 100% at test startup either using alsautils like here or with pulseaudio scripts (I assume that has to be possible)?

(In reply to comment #5)
> Hum even with the patch and my PATH fixed I get those 2 failing :(
>   media/event-attributes.html = TEXT
>   media/sources-fallback-codecs.html = TEXT

I'm guessing this is because of the typo, "100" instead of "100%"

[Philippe Normand]

Which typo? When calling amixer?

[Jussi Kukkonen (jku)]

(In reply to comment #22)
> Which typo? When calling amixer?

Yes, mentioned it in comment 17. Should be: 
    amixer_process = subprocess.Popen(["amixer", "set", "Master", "100%", "unmute"], stderr=devnull, stdout=devnull)

otherwise the value will be handled as hardware value.

[Philippe Normand]

Oh right I forgot about comment 17 :)

[Philippe Normand]

This is no longer an issue because the test harness relies on fakeaudiosink.

[Xabier Rodríguez Calvar]

Even with fakeaudiosink, I see some extra volume events, that need study. Test still fails.

[Xabier Rodríguez Calvar]

Created attachment 432601 [details]
Patch

[Xabier Rodríguez Calvar]

Created attachment 432602 [details]
Patch

[Philippe Normand]

Comment on attachment 432602 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=432602&action=review

> Tools/WebKitTestRunner/TestController.cpp:990
> +    // GStreamer uses fakesink to avoid sound output during testing and doing this creates trouble with volume events.
> +#if !USE(GSTREAMER)
>      WKPageSetMediaVolume(m_mainWebView->page(), 0);
> +#endif

That feels like closing our eyes on a real bug though :( fakeaudiosink is used as a mock renderer, it should however handle volume/mute properties reliably. So I wonder if there's a real issue in our code handling volume events.

[Xabier Rodríguez Calvar]

(In reply to Philippe Normand from comment #29)
> Comment on attachment 432602 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=432602&action=review
> 
> > Tools/WebKitTestRunner/TestController.cpp:990
> > +    // GStreamer uses fakesink to avoid sound output during testing and doing this creates trouble with volume events.
> > +#if !USE(GSTREAMER)
> >      WKPageSetMediaVolume(m_mainWebView->page(), 0);
> > +#endif
> 
> That feels like closing our eyes on a real bug though :( fakeaudiosink is
> used as a mock renderer, it should however handle volume/mute properties
> reliably. So I wonder if there's a real issue in our code handling volume
> events.

I don't know what others port to regarding volume management but we do rely on what GStreamer is telling us. If we set page volume to 0, we eventually set GStreamer volume to 0, which ends up triggering volume changes. It is not closing our eyes on a real bug, it is a different way of mocking among different ports. We have fakeaudiosink that does everything that a real renderer does but without sending anything to the sound card and it also handles the volume changes as expected.

Actually, while testing I am going to unflag several other bugs that were failing because of this.

[Xabier Rodríguez Calvar]

Created attachment 432694 [details]
Patch

[Xabier Rodríguez Calvar]

If this patch lands, I'll close the related bugs for the expectations I removed.

[EWS]

Committed r279499 (239351@main): <https://commits.webkit.org/239351@main>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 432694 [details].

[Radar WebKit Bug Importer]

<rdar://problem/80067853>