masmu / pulseaudio-dlna

A lightweight streaming server which brings DLNA / UPNP and Chromecast support to PulseAudio and Linux
GNU General Public License v3.0
1.25k stars 162 forks source link

version 4.x and switch back to default sink #61

Closed nobanzai closed 9 years ago

nobanzai commented 9 years ago

Hi, is it possible to get a switch for this new behaviour: "If a device stops playing, the streams currently playing on the corresponding sink are switched back to the default sink" Using version 4.1 with my Majik DSM every so often for no apparent reason output is switched back to my hardware sound card. It is possible then to directly switch back to padlna, but if you are not sitting near your computer, this behaviour ist really annoying. Thx and bye. Michael.

masmu commented 9 years ago

Thanks for your detailed instructions. Those explanations really help me better understanding what is going on. And it may be, that the application hangs, but i am not sure at that point.

What i am sure about is, that there is a condition where an update of a sink leads to a stopping instruction, where it normally should not. In 3 of the logs you could see, that in fact pulseaudio-dlna did stop your device.

I wanna know what this condition is about. Thats why i placed additional logs in the branch. But you are not using the branch. Please try the following, line by line.

mkdir tmp
cd tmp/
git clone https://github.com/masmu/pulseaudio-dlna.git
cd pulseaudio-dlna/
git checkout bug/sound-vanishes

Check if you are using the correct branch: git diff HEAD~1 should return the following:

diff --git a/pulseaudio_dlna/pulseaudio.py b/pulseaudio_dlna/pulseaudio.py
index 0cabb7f..dd3b08f 100644
--- a/pulseaudio_dlna/pulseaudio.py
+++ b/pulseaudio_dlna/pulseaudio.py
@@ -551,6 +551,7 @@ class PulseWatcher(PulseAudio):
             return

         for bridge in self.bridges:
+            logger.info('\n{}'.format(str(bridge)))
             if bridge.device.state == bridge.device.PLAYING:
                 if len(bridge.sink.streams) == 0:
                     logger.info(

Then just start it ...

make
bin/pulseaudio-dlna --debug 2>&1 | tee -a debug.log
nobanzai commented 9 years ago

I checked it again. git diff HEAD~1 gives exactly what you showed me above.

cd tmp
git clone https://github.com/masmu/pulseaudio-dlna.git
Cloning into 'pulseaudio-dlna'...
remote: Counting objects: 947, done.
remote: Compressing objects: 100% (39/39), done.
remote: Total 947 (delta 16), reused 0 (delta 0), pack-reused 908
Receiving objects: 100% (947/947), 451.65 KiB | 488.00 KiB/s, done.
Resolving deltas: 100% (603/603), done.
Checking connectivity... done.
cd pulseaudio-dlna/
git checkout bug/sound-vanishes
Branch bug/sound-vanishes set up to track remote branch bug/sound-vanishes from origin.
Switched to a new branch 'bug/sound-vanishes'
git diff HEAD~1
diff --git a/pulseaudio_dlna/pulseaudio.py b/pulseaudio_dlna/pulseaudio.py
index 0cabb7f..dd3b08f 100644
--- a/pulseaudio_dlna/pulseaudio.py
+++ b/pulseaudio_dlna/pulseaudio.py
@@ -551,6 +551,7 @@ class PulseWatcher(PulseAudio):
             return

         for bridge in self.bridges:
+            logger.info('\n{}'.format(str(bridge)))
             if bridge.device.state == bridge.device.PLAYING:
                 if len(bridge.sink.streams) == 0:
                     logger.info(
masmu commented 9 years ago

Ok, looks good. Now just:

make
bin/pulseaudio-dlna --debug 2>&1 | tee -a debug.log

There should be more debug stuff in the log. Look for the word "bridge". If its in there i really like to have that log :smile:

nobanzai commented 9 years ago

did it, but nothing like "bridge" in the log

nobanzai commented 9 years ago

Instead I got

8-09 20:22:14 pulseaudio_dlna.pulseaudio                     ERROR    Could not get "/org/pulseaudio/core1/sink0" from dbus.
08-09 20:22:14 pulseaudio_dlna.pulseaudio                     ERROR    Could not get "/org/pulseaudio/core1/sink16" from dbus.
08-09 20:22:39 dbus.proxies                                   ERROR    Introspect error on None:/org/pulseaudio/core1/sink16: dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
08-09 20:22:39 dbus.proxies                                   DEBUG    Executing introspect queue due to error
08-09 20:22:40 pulseaudio_dlna.pulseaudio                     INFO     _handle_sink_update /org/pulseaudio/core1/sink16
08-09 20:22:40 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" to stop ...
masmu commented 9 years ago

Its odd that you don't see the new debug logs. But don't worry. We switch back to replace instructions, since that went well last time.

Replace the pulseaudio.py with that one please.

Lets see if we can make those logs appear ... :grin:

nobanzai commented 9 years ago

in what version should I replace that file?

masmu commented 9 years ago

Like you did it the last time it worked 6 days ago. So forget about the local copy at tmp/pulseaudio-dlna.

I wrote you: Replace /usr/lib/python2.7/dist-packages/pulseaudio_dlna/pulseaudio.py with that one.

Whatever you did then will work now.

nobanzai commented 9 years ago

is there anything one can see what version is used? can you add some comment when padlna is starting?

masmu commented 9 years ago

The logs we are waiting for are always printed before an action is induced. So, if you read a message such as "Instructing the device ..." right before that they should be there.

nobanzai commented 9 years ago

What I meant ist something like "pulseaudio-dlna version x.y.z-debug-whatever starting". That would make it obvious, what version gets used.

masmu commented 9 years ago

I understand the demand for that. But that's not how python works.

In contrast to compiled binarys python applications consists of several modules and packages, which don't need to be compiled to result in a single application (or binary). You could easily print the version number on start up, but since 95% of the actual code lives in other modules, you would basically just know the version of the start up script. So, in that case you could be sure, you are using about 5% code of the correct version. You would need to have a version for each module to do what you want. But nobody does that. Once your code is stable you ship it, using a version number representative for all the code.

The actual solution for that problem is using a version control system such as git.

nobanzai commented 9 years ago

I never wrote serious python scripts, but I did it in perl and perl's modular concept is quite similar. What I often did was to print the version of the main script on start and to provide a parameter like "-V", which prints out all of the versions of the used modules that I wrote (not the standard perl modules). Of course I don't want to suggest that you do the same, I just wanted to express that it might be possible despite the modular concept.

nobanzai commented 9 years ago

Back to the interrupt problem: Today I didn't have any interrupts while playing music. So you won't get any new log file. The only annoying thing is, that the default sink always switches back to the M-Audio card as soon as an album has finished and I started to play the next album. I have to test if that also will happen with the "--disable-switchback" option.

masmu commented 9 years ago

You are right. And it is the same for php and others.

But i guess the reason why no one does it is that there is a good alternative.

Please don't get this wrong. But I think we are talking about this for another reason in the first place. So, let's focus on the problem, cause it might be that you found a bug where also other people suffer from. Therefore I am really motivated and interested in solving your issue. We just need to go on ...

You were able to add my changes a week ago without any trouble. Basically it is the same task now. Did you figure out why you don't see the logs now?

masmu commented 9 years ago

I am pretty sure that happens because (i assume) Amarok removed every stream on the dlna sink, when there is no music playing any more.

This is the main concept of instructing devices to play and stop. If there are streams which want to play on a dlna sink, instruct the device to play. If there is no stream any more on a device which is playing, stop it.

The --disable-switchback flag should restore the old behaviour. If not, you found a bug and i have to fix it :smile:

nobanzai commented 9 years ago

You were able to add my changes a week ago without any trouble. Basically it is the same task now. Did you figure out why you don't see the logs now?

I see the logs with your latest pulseaudio.py file - I just didn't have any interrupts since then, so I thought, the log isn't of any interest for you. If you are nevertheless interested, I can put in on pastebin again.

masmu commented 9 years ago

No you are right. I need a log where the situation occurs. Just paste one when the issue is back again. :+1:

nobanzai commented 9 years ago

And here we are: http://pastebin.com/x8NMjW9D At 23:14 sound all of a sudden stopped. I had to switch the sink back and forth, after that I got music back.

masmu commented 9 years ago

Could you replace your pulseaudio.py with that one and try again?

I am not sure if that actually helps. I am just catching the exception which prevents further code execution at that point. We have to try and see ... but that one was a very good log.

masmu commented 9 years ago

I tried to make the update process of sinks and streams more robust.

Please replace your pulseaudio.py with that one.

nobanzai commented 9 years ago

See http://pastebin.com/JtDZq75a At 23:22 music stopped and I had to switch the sink manually back and forth to get music back.

nobanzai commented 9 years ago

and another log: http://pastebin.com/2rNG2zM4 I had several interrupts, where I didn't hear any sound, while Amarok and Pulseaudio volume control showed that the song was playing on the padlna sink. Each time I had to switch the sink back and forth to get music back.

masmu commented 9 years ago

I've added the --disable-device-stop flag because of another bug report. It disables device stopping instructions completely.

To test this you have to replace the

nobanzai commented 9 years ago

Do I have to use --disable-device-stop in addition to --disable-switchback or does it include the feature?

masmu commented 9 years ago

No, these are separate features. The --disable-device-stop options just makes pulseaudio-dlna not sending any more STOP instructions.

The --disable-switchback option, makes pulseaudio-dlna not to switch back to the default sink, if a client / device disconnects.

So, you may test these in conjunction with each other or alone. See how just --disable-device-stop works out ...

nobanzai commented 9 years ago

See http://pastebin.com/sD4PEwiG At 16:28 music stopped without anything else happening - Amarok says it is still playing, the same for pulseaudio volume control. The padlna debug log got no entry at all for this event. And switching the sink back and forth didn't help - I had to restart padlna.

nobanzai commented 9 years ago

Ok, after testing the various combinations I have no good news 8-< Using the --disable-device-stop always leads to the situation, that after a few songs no sound can be heard anymore, while Amarok says it is still playing, the same for pulseaudio volume control, and the padlna debug log gets no entries at all. Switching the sink back and forth doesn't help - one has to restart padlna.

masmu commented 9 years ago

To be honest, this was expected. Another user requested that feature although i had serious doubts about the sense of it. The mentioned "Switching the sink back and forth doesn't help - one has to restart padlna." thing is an effect of that flag. But he reported that it works well and i thought, it cannot hurt to let you test it too.

You noticed that there is no event for the music stopping at 16:28. You used the --disable-device-stop option and therefore pulseaudio-dlna did not send a STOP command during the whole streaming session. So it is good that you also tested this. Because what i am really missing is a Client x unregistered stream line ... That line is always printed when your device closes the stream, if instructed to STOP or if you unplug the power does not matter. There will be that line. But it is missing.

So, if your device did not close the connection why did it stop playing sound? Obviously it continued to receive data ...

nobanzai commented 9 years ago

Ok, so I'll continue testing without the "--disable-device-stop" switch.

nobanzai commented 9 years ago

After hours and hours of testing I found some strange problems in at least two of my own components - there was a bug in the firmware of the Majik DSM and there seems to be a problem with the "replay gain" mode of Amarok. Both of them independently could lead to the situation I described, i.e. no sound while every component seems still playing. That also would explain, why you couldn't find the expected message "Client x unregistered stream" - it simply wasn't the fault of padlna, which also assumed to be everything working ok. After updating the firmware of the Majik DSM and switching off replay gain in Amarok I didn't have any interrupt in sound at all - for the whole day of today. Next step will be to also deactivate the "--disable-switchback" switch and continue testing.

nobanzai commented 9 years ago

And of course I should have switched back to padlna 0.3.x a few times to assure this version still working properly 8-< Sorry for that!

masmu commented 9 years ago

Don't worry. Those things can happen. And you indeed found a bug. The event aggregation thing. :+1:

I am glad that it now works for you. Let's hope it stays that way ... :wink:

nobanzai commented 9 years ago

Crossing fingers :)

nobanzai commented 9 years ago

Didn't help - the situation occurred again and this time I got the message "Client x unregistered stream". See http://pastebin.com/LsyQEuuL It happened at 20:36:08. The second time at 20:41:13 happened when I switched off the Majik DSM - so this is not relevant.

masmu commented 9 years ago
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     on_playback_stream_removed "/org/pulseaudio/core1/playback_stream82"
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     trying to update sinks and streams ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_playback_streams of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_sinks of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     on_new_playback_stream "/org/pulseaudio/core1/playback_stream83"
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     trying to update sinks and streams ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_playback_streams of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_sinks of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.

Your device is playing. Everything is fine until here.

08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     on_playback_stream_removed "/org/pulseaudio/core1/playback_stream83"
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     trying to update sinks and streams ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_playback_streams of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_sinks of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     on_new_playback_stream "/org/pulseaudio/core1/playback_stream84"
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     trying to update sinks and streams ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_playback_streams of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:34:53 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_sinks of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:35:18 pulseaudio_dlna.pulseaudio                     ERROR    Could not get "/org/pulseaudio/core1/sink1" from dbus.
08-26 20:35:18 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:35:18 pulseaudio_dlna.pulseaudio                     INFO     _handle_sink_update /org/pulseaudio/core1/sink1
08-26 20:35:18 pulseaudio_dlna.pulseaudio                     INFO     
<Bridge>
    <PulseSink path="/org/pulseaudio/core1/sink1" label="Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" name="wohnzimmermajikdsmmediarenderer_dlna" index="1" module="30">
        -- no streams --
    <CoinedUpnpMediaRenderer name="Wohnzimmer:Majik DSM:MediaRenderer" short="wohnzimmermajikdsmmediarenderer_dlna" state="playing" protocols="audio/x-flac,audio/wav,audio/wave,audio/x-wav,audio/mpeg,audio/x-mpeg,audio/mp1,audio/aiff,audio/x-aiff,audio/x-m4a,audio/x-ms-wma,audio/x-ms-wma,audio/x-scpls,audio/x-mpegurl,audio/x-ms-asf,audio/x-ms-wax,audio/x-ms-wvx,audio/aac,audio/aacp,audio/mp4,audio/ogg,audio/x-ogg">

Amarok removed stream83. I guess the track has finished. Instantly stream84 was re-added, because of a new track start. There is no prove for my following assumtion, but i am pretty sure this stream is running on sink1 (Majik). But DBus fails to update the sink. So pulseaudio-dlna is not in sync with the real situation and will STOP your device because there is no stream running anymore on sink1. But in reality there is and there should be no stopping instruction.

08-26 20:35:18 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" to stop ...
08-26 20:35:18 requests.packages.urllib3.connectionpool       INFO     Starting new HTTP connection (1): 192.168.1.60
08-26 20:35:18 requests.packages.urllib3.connectionpool       DEBUG    "POST /MediaRenderer/AVTransport/control HTTP/1.1" 200 None
08-26 20:35:18 pulseaudio_dlna.plugins.upnp.renderer          DEBUG    sending STOP to http://192.168.1.60:55178/MediaRenderer/AVTransport/control:
08-26 20:35:18 pulseaudio_dlna.pulseaudio                     INFO     The device "Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" was stopped.

Thats what is happening...

08-26 20:35:19 pulseaudio_dlna.streamserver                   INFO     Requested streaming URL was: /wohnzimmermajikdsmmediarenderer_dlna.mp3 (HTTP/1.1)
08-26 20:35:19 pulseaudio_dlna.streamserver                   INFO     Got request from majikdsm.hirmke.de - GET /wohnzimmermajikdsmmediarenderer_dlna.mp3 HTTP/1.1,200,-

Regardless of being stopped, your device instantly tries to play the stream again. I guess this is because of an internal device playlist. This would explain why you got requests for version 0.3.x some time ago.

08-26 20:35:19 pulseaudio_dlna.streamserver                   INFO     Client 192.168.1.60 unregistered stream /wohnzimmermajikdsmmediarenderer_dlna.mp3 using method 2.
08-26 20:35:19 pulseaudio_dlna.streamserver                   INFO     Client 192.168.1.60 registered to stream /wohnzimmermajikdsmmediarenderer_dlna.mp3.
08-26 20:35:19 pulseaudio_dlna.streamserver                   DEBUG    Socket died, releasing request thread.

The device disconnects and reconnects. Depending on the delay, you should have heared a break or pause. Perhaps just a small distortion. Did you?

08-26 20:36:02 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink0"
08-26 20:36:02 pulseaudio_dlna.pulseaudio                     INFO     trying to update sinks and streams ...
08-26 20:36:02 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_playback_streams of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:36:02 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:36:02 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_sinks of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:36:02 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:36:03 pulseaudio_dlna.pulseaudio                     INFO     _handle_sink_update /org/pulseaudio/core1/sink0
08-26 20:36:03 pulseaudio_dlna.pulseaudio                     INFO     
<Bridge>
    <PulseSink path="/org/pulseaudio/core1/sink1" label="Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" name="wohnzimmermajikdsmmediarenderer_dlna" index="1" module="30">
        -- no streams --
    <CoinedUpnpMediaRenderer name="Wohnzimmer:Majik DSM:MediaRenderer" short="wohnzimmermajikdsmmediarenderer_dlna" state="idle" protocols="audio/x-flac,audio/wav,audio/wave,audio/x-wav,audio/mpeg,audio/x-mpeg,audio/mp1,audio/aiff,audio/x-aiff,audio/x-m4a,audio/x-ms-wma,audio/x-ms-wma,audio/x-scpls,audio/x-mpegurl,audio/x-ms-asf,audio/x-ms-wax,audio/x-ms-wvx,audio/aac,audio/aacp,audio/mp4,audio/ogg,audio/x-ogg">

sink0 was updated. But this is your internal soundcard. Does not matter.

08-26 20:36:07 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink1"
08-26 20:36:07 pulseaudio_dlna.pulseaudio                     INFO     trying to update sinks and streams ...
08-26 20:36:07 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_playback_streams of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:36:07 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:36:07 pulseaudio_dlna.pulseaudio                     INFO     method try 1 (<bound method PulseWatcher.update_sinks of <pulseaudio_dlna.pulseaudio.PulseWatcher object at 0x7ff3aa2d4890>>) ...
08-26 20:36:07 pulseaudio_dlna.pulseaudio                     INFO     method was executed successfully.
08-26 20:36:08 pulseaudio_dlna.pulseaudio                     INFO     _handle_sink_update /org/pulseaudio/core1/sink1
08-26 20:36:08 pulseaudio_dlna.pulseaudio                     INFO     
<Bridge>
    <PulseSink path="/org/pulseaudio/core1/sink1" label="Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" name="wohnzimmermajikdsmmediarenderer_dlna" index="1" module="30">
        <PulseStream path="/org/pulseaudio/core1/playback_stream84" device="/org/pulseaudio/core1/sink1" index="84">

    <CoinedUpnpMediaRenderer name="Wohnzimmer:Majik DSM:MediaRenderer" short="wohnzimmermajikdsmmediarenderer_dlna" state="idle" protocols="audio/x-flac,audio/wav,audio/wave,audio/x-wav,audio/mpeg,audio/x-mpeg,audio/mp1,audio/aiff,audio/x-aiff,audio/x-m4a,audio/x-ms-wma,audio/x-ms-wma,audio/x-scpls,audio/x-mpegurl,audio/x-ms-asf,audio/x-ms-wax,audio/x-ms-wvx,audio/aac,audio/aacp,audio/mp4,audio/ogg,audio/x-ogg">

08-26 20:36:08 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" to play ...

sink1 is updated. This time DBus delivers the information about the sink. pulseaudio-dlna is now aware of stream84 (but one minute late). Since your device was stopped before and there is a new stream on sink1 it instructs the device to play.

08-26 20:36:08 requests.packages.urllib3.connectionpool       INFO     Starting new HTTP connection (1): 192.168.1.60
08-26 20:36:08 requests.packages.urllib3.connectionpool       DEBUG    "POST /MediaRenderer/AVTransport/control HTTP/1.1" 200 None
08-26 20:36:08 pulseaudio_dlna.plugins.upnp.renderer          DEBUG    sending REGISTER to http://192.168.1.60:55178/MediaRenderer/AVTransport/control:
08-26 20:36:08 requests.packages.urllib3.connectionpool       INFO     Starting new HTTP connection (1): 192.168.1.60
08-26 20:36:08 requests.packages.urllib3.connectionpool       DEBUG    "POST /MediaRenderer/AVTransport/control HTTP/1.1" 200 None
08-26 20:36:08 pulseaudio_dlna.plugins.upnp.renderer          DEBUG    sending PLAY to http://192.168.1.60:55178/MediaRenderer/AVTransport/control:
08-26 20:36:08 pulseaudio_dlna.pulseaudio                     INFO     The device "Wohnzimmer:Majik DSM:MediaRenderer (DLNA)" is playing.

Not sure if you heared your device playing at that time. I would expect that even if the device was playing it disconnects and reconnects and therefore basically continues to play.

08-26 20:36:08 pulseaudio_dlna.streamserver                   INFO     Requested streaming URL was: /wohnzimmermajikdsmmediarenderer_dlna.mp3 (HTTP/1.1)
08-26 20:36:08 pulseaudio_dlna.streamserver                   INFO     Got request from majikdsm.hirmke.de - GET /wohnzimmermajikdsmmediarenderer_dlna.mp3 HTTP/1.1,200,-
08-26 20:36:08 pulseaudio_dlna.streamserver                   INFO     Client 192.168.1.60 unregistered stream /wohnzimmermajikdsmmediarenderer_dlna.mp3 using method 2.
08-26 20:36:08 pulseaudio_dlna.streamserver                   INFO     Client 192.168.1.60 registered to stream /wohnzimmermajikdsmmediarenderer_dlna.mp3.
08-26 20:36:08 pulseaudio_dlna.streamserver                   DEBUG    Socket died, releasing request thread.

Disconnect and reconnect. But you said your device stopped to play, right? And again we are missing the Client x unregistered stream message. There is one but this is for the stream your device decided to play on its own. After the PLAY instruction, that stream disconnects and the stream unregisteres. But a new stream is registered, so your device is recieving data. You should hear something.

Could you please try the bug/sound-vanishes branch? There are new fixes included.

The reason why i don't give you manual instructions is that is has changed a lot and you would have to change a lot of files. It would be a lot easier if you get git working. Try uninstalling pulseaudio-dlna and then give the git way another try.

nobanzai commented 9 years ago

The device disconnects and reconnects. Depending on the delay, you should have heared a break or pause. Perhaps just a small distortion. Did you?

No, I didn't. I'll give the mentioned branch a try.

nobanzai commented 9 years ago

Sry to tell you, but this version is completely unusable 8-< Every few seconds sound is fading out and back in again - without any log entry during that time. See http://pastebin.com/Qg3W8eTm This test was without the "--disable-switchback" switch, but the same happened with that switch.

masmu commented 9 years ago

We have to find out what i did that causes this to happen.So i will roll back some of my changes until it works again. I just updated the branch with the first roll back.

Please change to the pulseaudio-dlna directory and do a git pull. Just should receive all my changes with that. After that please just test again.

nobanzai commented 9 years ago

To make sure I really get the correct files, isn't it possible to download the zip file from that branch, unpack and instll it? That's what I did the day before yesterday.

nobanzai commented 9 years ago

Ok, I used the zip file as mentioned above. Because the day before yesterday the pulsating sound occured directly when playing the first song after starting padlna, I already can tell you, that it works again in the defined parameters ;) At the moment I use the default encoder plus the "--disable-switchback" switch.

masmu commented 9 years ago

Yes, i guess you can. Never did that myself :wink:

I updated your branch. Has some new related fixes in it, so please check it out.

nobanzai commented 9 years ago

Downloaded the zip file and installed it. This version has a great advantage over the one before: Sound starts as soon as I click on "play". With the version before it took a few seconds before I could here something. And: No vanishing sound yet in 90 minutes.

masmu commented 9 years ago

Where do you find that "play" button?

nobanzai commented 9 years ago

In any music player like amarok :)

nobanzai commented 9 years ago

Just an update: Sound vanished one time yesterday. Stop/play in amarok brought sound back - it was not necessary to switch sinks this time. And: I got no log entries for this event.

nobanzai commented 9 years ago

Ok, in vary rare cases sound still stops, but there are no debug entries for these events, so I assume it is not padlna's fault. Therefore I close this issue.

masmu commented 9 years ago

It was a long way, but we found several bugs. Thanks for your patience :smile:

nobanzai commented 9 years ago

you're welcome :)