Unplugging headphones stops the sound

[totaam]

Issue migrated from trac ticket # 987

component: android | priority: major | resolution: fixed | keywords: sound, speaker

2015-09-24 18:21:37: pvenkateswaralu created the issue

---

The default speaker codecs being MP3 on the following xpra versions ---

         Client---0.16.0-[r10655](../commit/9d9338126247b1a1d4d48a09c467c83faf3e3a02)---MacOSX10.10.3
         Server---0.16.0-[r10673](../commit/65a3865650d8b61f5156583c65edd62f413086a6)---Fedora21

I had an xpra session with youtube video. The sound played fine until I unplugged the headphones, at which the sound stopped completely. Plugging back headphones won't give the sound back. Must start a new session entirely if you want the sound back.

Expected behavior: Once the headphones are unplugged, the speaker configuration must change and play the sound through loud speakers.

Here are the client/server logs I grabbed with -d sound

P.S I unplugged the headphones exactly at 2015-09-24 10:02:15,013. so I'll paste the logs starting from 10:02:14, just to show you that there was no difference in logs before and after unplugging headphones.

Client Logs:

2015-09-24 10:02:14,957 sound-sink add_data(208 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134797L}) queue_state=pushing
2015-09-24 10:02:14,957 sound-sink pushed   208 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:14,958 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:14,958 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:14,958 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90
2015-09-24 10:02:14,979 sound-sink add_data(208 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134815L}) queue_state=pushing
2015-09-24 10:02:14,979 sound-sink pushed   208 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:14,979 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:14,979 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:14,979 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90
2015-09-24 10:02:15,011 info_update: {'queue.max': 130, 'pipeline': 'appsrc name=src emit-signals=0 block=0 is-live=0 stream-type=stream format=4 ! mp3parse ! mad ! audioconvert ! audioresample ! volume name=volume volume=1.0 ! queue name=queue min-threshold-time=0 max-size-buffers=0 max-size-bytes=0 max-size-time=450000000 leaky=2 ! osxaudiosink async=True qos=True sync=False', 'queue.pct': 60, 'queue.state': 'pushing', 'codec_description': 'mpeg 1 audio, layer 3 (mp3)', 'bytes': 259895, 'queue.underruns': 0, 'volume': 100, 'state': 'active', 'queue.overruns': 6, 'queue.cur': 78, 'buffers': 1508, 'codec_mode': 'mono', 'bitrate': 50000, 'codec': 'mp3', 'queue.min': 0}
2015-09-24 10:02:15,013 sound-sink add_data(208 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134852L}) queue_state=pushing
2015-09-24 10:02:15,014 sound-sink pushed   208 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:15,014 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:15,014 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:15,014 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90
2015-09-24 10:02:15,034 sound-sink add_data(208 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134876L}) queue_state=pushing
2015-09-24 10:02:15,034 sound-sink pushed   208 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:15,034 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:15,034 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:15,034 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90
2015-09-24 10:02:15,057 sound-sink add_data(208 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134899L}) queue_state=pushing
2015-09-24 10:02:15,057 sound-sink pushed   208 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:15,057 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:15,057 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:15,057 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90
2015-09-24 10:02:15,066 info_update: {'queue.max': 130, 'pipeline': 'appsrc name=src emit-signals=0 block=0 is-live=0 stream-type=stream format=4 ! mp3parse ! mad ! audioconvert ! audioresample ! volume name=volume volume=1.0 ! queue name=queue min-threshold-time=0 max-size-buffers=0 max-size-bytes=0 max-size-time=450000000 leaky=2 ! osxaudiosink async=True qos=True sync=False', 'queue.pct': 60, 'queue.state': 'pushing', 'codec_description': 'mpeg 1 audio, layer 3 (mp3)', 'bytes': 260519, 'queue.underruns': 0, 'volume': 100, 'state': 'active', 'queue.overruns': 6, 'queue.cur': 78, 'buffers': 1511, 'codec_mode': 'mono', 'bitrate': 50000, 'codec': 'mp3', 'queue.min': 0}
2015-09-24 10:02:15,085 sound-sink add_data(208 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134926L}) queue_state=pushing
2015-09-24 10:02:15,085 sound-sink pushed   208 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:15,085 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:15,085 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:15,085 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90
2015-09-24 10:02:15,113 sound-sink add_data(182 bytes, {'duration': 26122449, 'sequence': 0, 'time': 1443114134954L}) queue_state=pushing
2015-09-24 10:02:15,113 sound-sink pushed   182 bytes, new buffer level:  52ms, queue state=pushing
2015-09-24 10:02:15,113 sound-sink set_min_level pct= 0, cmtt=  0, mtt=  0
2015-09-24 10:02:15,113 sound-sink set_max_level lrange= 26, last_max_update=36s
2015-09-24 10:02:15,113 sound-sink set_max_level overrun count=2 , margin= 50, pct= 0, cmst=130, mst= 90

Server Logs:

2015-09-24 10:02:14,926 sound-source emit_buffer data=<type 'str'>, len=208, metadata={'duration': 26122449L, 'timestamp': 39444897959L}
2015-09-24 10:02:14,927 new_sound_buffer(source_subprocess_wrapper(11606), 208, {'duration': 26122449, 'timestamp': 39444897959, 'time': 1443114134926}) suspended=False
2015-09-24 10:02:14,954 sound-source emit_buffer data=<type 'str'>, len=182, metadata={'duration': 26122449L, 'timestamp': 39471020408L}
2015-09-24 10:02:14,955 new_sound_buffer(source_subprocess_wrapper(11606), 182, {'duration': 26122449, 'timestamp': 39471020408, 'time': 1443114134954}) suspended=False
2015-09-24 10:02:14,978 sound-source emit_buffer data=<type 'str'>, len=182, metadata={'duration': 26122449L, 'timestamp': 39497142857L}
2015-09-24 10:02:14,978 info_update: {'pipeline': 'pulsesrc ! volume name=volume volume=1.0 ! lamemp3enc encoding-engine-quality=0 ! appsink name=sink emit-signals=true max-buffers=10 drop=true sync=false async=false qos=false', 'codec_description': '', 'bytes': 260909, 'volume': 100, 'state': 'active', 'codec': 'mp3', 'buffers': 1513}
2015-09-24 10:02:14,979 sound_source_info: {'pipeline': 'pulsesrc ! volume name=volume volume=1.0 ! lamemp3enc encoding-engine-quality=0 ! appsink name=sink emit-signals=true max-buffers=10 drop=true sync=false async=false qos=false', 'codec_description': '', 'pid': 11606, 'bytes': 260909, 'volume': 100, 'state': 'active', 'codec': 'mp3', 'time': 1443114134, 'buffers': 1513}
2015-09-24 10:02:14,980 new_sound_buffer(source_subprocess_wrapper(11606), 182, {'duration': 26122449, 'timestamp': 39497142857, 'time': 1443114134979}) suspended=False
2015-09-24 10:02:15,024 sound-source emit_buffer data=<type 'str'>, len=313, metadata={'duration': 26122449L, 'timestamp': 39523265306L}
2015-09-24 10:02:15,026 sound-source emit_buffer data=<type 'str'>, len=208, metadata={'duration': 26122449L, 'timestamp': 39549387755L}
2015-09-24 10:02:15,027 new_sound_buffer(source_subprocess_wrapper(11606), 313, {'duration': 26122449, 'timestamp': 39523265306, 'time': 1443114135025}) suspended=False
2015-09-24 10:02:15,028 new_sound_buffer(source_subprocess_wrapper(11606), 208, {'duration': 26122449, 'timestamp': 39549387755, 'time': 1443114135026}) suspended=False
2015-09-24 10:02:15,030 info_update: {'pipeline': 'pulsesrc ! volume name=volume volume=1.0 ! lamemp3enc encoding-engine-quality=0 ! appsink name=sink emit-signals=true max-buffers=10 drop=true sync=false async=false qos=false', 'codec_description': '', 'bytes': 261612, 'volume': 100, 'state': 'active', 'codec': 'mp3', 'buffers': 1516}
2015-09-24 10:02:15,031 sound_source_info: {'pipeline': 'pulsesrc ! volume name=volume volume=1.0 ! lamemp3enc encoding-engine-quality=0 ! appsink name=sink emit-signals=true max-buffers=10 drop=true sync=false async=false qos=false', 'codec_description': '', 'pid': 11606, 'bytes': 261612, 'volume': 100, 'state': 'active', 'codec': 'mp3', 'time': 1443114135, 'buffers': 1516}
2015-09-24 10:02:15,060 sound-source emit_buffer data=<type 'str'>, len=156, metadata={'duration': 26122449L, 'timestamp': 39575510204L}
2015-09-24 10:02:15,062 new_sound_buffer(source_subprocess_wrapper(11606), 156, {'duration': 26122449, 'timestamp': 39575510204, 'time': 1443114135061}) suspended=False
2015-09-24 10:02:15,084 sound-source emit_buffer data=<type 'str'>, len=182, metadata={'duration': 26122449L, 'timestamp': 39601632653L}
2015-09-24 10:02:15,086 new_sound_buffer(source_subprocess_wrapper(11606), 182, {'duration': 26122449, 'timestamp': 39601632653, 'time': 1443114135085}) suspended=False
2015-09-24 10:02:15,107 sound-source emit_buffer data=<type 'str'>, len=261, metadata={'duration': 26122449L, 'timestamp': 39627755102L}
2015-09-24 10:02:15,108 new_sound_buffer(source_subprocess_wrapper(11606), 261, {'duration': 26122449, 'timestamp': 39627755102, 'time': 1443114135107}) suspended=False
2015-09-24 10:02:15,112 info_update: {'pipeline': 'pulsesrc ! volume name=volume volume=1.0 ! lamemp3enc encoding-engine-quality=0 ! appsink name=sink emit-signals=true max-buffers=10 drop=true sync=false async=false qos=false', 'codec_description': '', 'bytes': 262211, 'volume': 100, 'state': 'active', 'codec': 'mp3', 'buffers': 1519}
2015-09-24 10:02:15,113 sound_source_info: {'pipeline': 'pulsesrc ! volume name=volume volume=1.0 ! lamemp3enc encoding-engine-quality=0 ! appsink name=sink emit-signals=true max-buffers=10 drop=true sync=false async=false qos=false', 'codec_description': '', 'pid': 11606, 'bytes': 262211, 'volume': 100, 'state': 'active', 'codec': 'mp3', 'time': 1443114135, 'buffers': 1519}

I am also attaching the xpra info I collected throughout the session ----> sound_stops_whenHeadphonesUnplugged.txt

Please let me know if I can use any other debugging flags to fetch the logs.

[totaam]

2015-09-24 18:21:57: pvenkateswaralu uploaded file sound_stops_whenHeadphonesUnplugged.txt (116.7 KiB)

[totaam]

2015-10-23 07:41:49: antoine changed status from new to assigned

[totaam]

2015-10-23 07:41:49: antoine commented

---

Will wait for #970 before looking into this one.

[totaam]

2015-10-28 16:34:02: antoine commented

---

Another thought: it might help to try a different sound sink using:

XPRA_SOUND_SINK=autoaudiosink ./Xpra.app/Contents/MacOS/Xpra attach ...

(I don't think the other sinks work on osx: osssink and oss4sink might.

Otherwise, both 1.0 and 0.10 osxaudiosink plugins have a "device" property. We may need to change this at runtime when we detect that is needed. (and I have no idea how to do that part yet)

[totaam]

2015-10-28 17:59:42: pvenkateswaralu changed status from assigned to new

[totaam]

2015-10-28 17:59:42: pvenkateswaralu commented

---

With Client-16.0-r11077-OSX10.6.8 and Server-16.0-r11058-Fedora21, I performed the test with all the 3 sinks autoaudiosink osssink and oss4sink.

When xpra is launched with XPRA_SOUND_SINK set to one of the 3 values, the sound is OFF by default. I tried turning it ON by changing the settings: Xpra -> Sound -> Speaker -> ON. But this has no impact on Sound. And soon after I click anywhere outside of the xpra menu on the OSX application bar, Xpra -> Sound -> Speaker will change back to OFF.

Without specifying the XPRA_SOUND_SINK, the sound is ON. But the original problem still exits. Unplugging headphones gives no sound, although Xpra -> Sound -> Speaker still says ON.

[totaam]

2015-11-09 10:01:39: antoine changed owner from antoine to pvenkateswaralu

[totaam]

2015-11-09 10:01:39: antoine commented

---

There are no noticeable events in those log samples.

r11159 adds the gst-launch wrapper to the Helpers directory, maybe you can detect the unplug event using:

GST_DEBUG=10 ./Xpra.app/Contents/Helpers/gst-launch-0.10 audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False

Same with GStreamer 1.0: gst-launch-1.0.

Worth trying the different options on osxaudiosink to see if they have any effect. And lower the debug level if there is too much debug data coming out.
You can inspect pipeline elements using the newly packaged gst-inspect, ie:

./Xpra.app/Contents/Helpers/gst-inspect-1.0 osxaudiosink

(and same with gst-launch-0.10)

[totaam]

2015-11-10 23:45:27: pvenkateswaralu changed owner from pvenkateswaralu to antoine

[totaam]

2015-11-10 23:45:27: pvenkateswaralu commented

---

client-16.0-r11176-osx10.6.8
server-16.0-r11160-fedora21

With these versions, I still see that, unplugging headphones does not play audio through loudspeakers. [[BR]][[BR]]

Alex and I sat through to construct a pipeline and detect the unplug event using the command GST_DEBUG=10 ./Xpra.app/Contents/Helpers/gst-launch-0.10 filesink location="/Users/maint/Downloads/music.mp3" audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False and this is the log we got

TestBotBestBot:16.0-[r11176](../commit/0b6dd77c94baf53f258d985597427c9d4a8c4a28).app maint$ GST_DEBUG=10 ./Contents/Helpers/gst-launch-0.10 filesink location="/Users/maint/Downloads/music.mp3" audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False
ERROR: pipeline could not be constructed: no element "filesink".

And with the command GST_DEBUG=10 ./Xpra.app/Contents/Helpers/gst-launch-0.10 location="/Users/maint/Downloads/music.mp3" audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False and this is the log we got

TestBotBestBot:16.0-[r11176](../commit/0b6dd77c94baf53f258d985597427c9d4a8c4a28).app maint$  GST_DEBUG=10 ./Contents/Helpers/gst-launch-0.10 location="/Users/maint/Downloads/music.mp3" audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False
ERROR: pipeline could not be constructed: Unrecoverable syntax error while parsing pipeline location=/Users/maint/Downloads/music.mp3 audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False .

We googled through these sites [https://gist.github.com/wkf/5658578] and [http://manpages.ubuntu.com/manpages/vivid/man1/gst-launch-1.0.1.html] to get the correct syntaxes, but with those, we are getting the above mentioned errors.

Could you please let me know if the syntax is wrong and direct me to any links that might be useful to perform the test.

[totaam]

2015-11-11 01:26:33: antoine changed owner from antoine to pvenkateswaralu

[totaam]

2015-11-11 01:26:33: antoine commented

---

to get the correct syntaxes, but with those, we are getting the above mentioned errors.
[[BR]]

Your pipelines are wrong, you need to either use the example I gave, or copy the examples you find properly: you cannot use a sink as a source (use filesrc instead of filesink), or combine a filesrc and an audiotestsrc in the same element.

Also, some plugins may be missing from the installer images we make.
So either run from the build machine which has a more complete environment with all the plugins, or... just use the example I gave - which is known to work.

[totaam]

2015-11-11 19:49:49: pvenkateswaralu uploaded file 994-logs-with-gst-launch-1.0.txt (72.0 KiB)

[totaam]

2015-11-11 19:56:09: pvenkateswaralu changed owner from pvenkateswaralu to antoine

[totaam]

2015-11-11 19:56:09: pvenkateswaralu commented

---

I ran the exact same command that you mentioned GST_DEBUG=10 ./Xpra.app/Contents/Helpers/gst-launch-0.10 audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False and this is what I got:

Prashanthys-MacBook-Pro:Desktop Prashanthy$ GST_DEBUG=10 ./Xpra.app/Contents/Helpers/gst-launch-0.10 audiotestsrc ! audioconvert ! osxaudiosink async=True qos=True sync=False
ERROR: pipeline could not be constructed: no element "audiotestsrc".

And with gst-launch-1.0, here's what I got -> [/attachment/ticket/987/994-logs-with-gst-launch-1.0.txt]
(I didn't want to post the large set of logs here and mess up the ticket, so I am added it as an attachment).
[[BR]]

So, I googled through a site [http://gstreamer.freedesktop.org/data/doc/gstreamer/head/faq/html/chapter-using.html] to read about GStreamer and check if we have the correct working repository. As mentioned in the site, I ran ./gst-inspect-1.0 fakesrc and here's the log I got:

Prashanthys-MacBook-Pro:Helpers Prashanthy$ ./gst-inspect-1.0 fakesrc
No such element or plugin 'fakesrc'
Prashanthys-MacBook-Pro:Helpers Prashanthy$

I'm not really sure if the GStreamer is not installed correctly, as it is mentioned in the site, or if there is any other problem.

I also tried running from a machine which has a complete environment with all the plugins installed. But, no luck! Could you please suggest me what else I could do?

[totaam]

2015-11-12 02:53:22: antoine changed owner from antoine to pvenkateswaralu

[totaam]

2015-11-12 02:53:22: antoine commented

---

But, no luck!
[[BR]]
Then avoid gambling?
Seriously though, if you have technical issues then please post them. I can't suggest anything without knowing what failed and how. How things were installed, etc.. following the bug reporting guidelines, as always.

My guess is that if it failed in the same way as above, you're not running from an environment which has all the plugins installed and available: if they really are installed on that machine then maybe they are not exposed in your environment (jhbuild shell or other).

r11188 makes it easier to generate "large" builds without stripping all the extra dependencies we don't normally need. ie:

STRIP_GSTREAMER_PLUGINS=0 ./make-all.sh

You can find one such build in the osx beta area. It is about 10MB heavier, and it should include many more gstreamer plugins.

See also #986

[totaam]

2015-11-17 00:12:28: pvenkateswaralu changed owner from pvenkateswaralu to antoine

[totaam]

2015-11-17 00:12:28: pvenkateswaralu commented

---

I tested with 16.0-r11188 on 2 versions of OSX clients (10.6.8 and 10.11.1), with Fedora21-16.0-r11185 on the server side, and these are the things I observed:
[[BR]]

• CASE 1: Connected headphones through USB port.
  As per switch to gstreamer 1.x on osx #970, I explicitly enabled gstreamer 1.0 using

XPRA_GSTREAMER1=1 ./Desktop/Xpra.app/Contents/MacOS/Xpra attach ...

With this, unplugging headphones did play sound on loudspeakers. but plugging them back did not switch the sound back to headphones, instead it continued to play on loudspeakers. Did not notice any unusual activity/event as such in the logs.
[[BR]]

• CASE 2: Connected headphones through Headphone port
  With this, I performed the test by enabling gstreamer 1.0 explicitly and the sound functions as it is expected to. Unplugging headphones plays sound on loudspeakers, and plugging them back switches sound to headphones.
  [[BR]]

Note: In both the cases mentioned above, without explicitly enabling gstreamer 1.0, the original issue exists as it is, i.e., unplugging headphones stops the sound.

[totaam]

2015-11-17 02:53:49: antoine changed owner from antoine to pvenkateswaralu

[totaam]

2015-11-17 02:53:49: antoine commented

---

r11253 makes gstreamer the default on OSX

@pvenkateswaralu: if that works well enough for you, please close.
(I don't think we can or should try to deal with corner cases like USB headphones)

[totaam]

2015-11-23 17:48:51: pvenkateswaralu changed status from new to closed

[totaam]

2015-11-23 17:48:51: pvenkateswaralu set resolution to fixed

[totaam]

2015-11-23 17:48:51: pvenkateswaralu commented

---

It works well with r11304 with osx10.6.8 on the client side and Fedora21 on the server side.
Closing the ticket.