Raumfeld speaker refuses to play stream - Unregistered stream message

[fbnrst]

I fail to stream audio to my Raumfeld speaker. It used to work before (like half a year ago). Starting pulseaudio-dlna the output is:

fabian@fabian-ThinkPad-X250:~$ pulseaudio-dlna 
07-09 22:47:20 pulseaudio_dlna.application                    INFO     Using version: 0.5.2
07-09 22:47:20 pulseaudio_dlna.application                    INFO     Using localhost: 192.168.178.50:8080
07-09 22:47:20 pulseaudio_dlna.application                    INFO     Encoder settings:
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvAacEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvFlacEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvL16Encoder available="True" sample-rate="44100" channels="2">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvMp3Encoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvOggEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvOpusEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AVConvWavEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegAacEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegFlacEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegL16Encoder available="True" sample-rate="44100" channels="2">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegMp3Encoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegOggEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegOpusEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FFMpegWavEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FaacAacEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FlacFlacEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <LameMp3Encoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <NullEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <OggencOggEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <OpusencOpusEncoder available="True" bit-rate="192">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <SoxL16Encoder available="True" sample-rate="44100" channels="2">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <SoxWavEncoder available="True">
07-09 22:47:20 pulseaudio_dlna.application                    INFO     Codec settings:
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <AacCodec enabled="True" priority="12" mime_type="audio/aac" backend="generic">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <L16Codec enabled="True" priority="0" mime_type="audio/L16" backend="generic">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <OpusCodec enabled="True" priority="3" mime_type="audio/opus" backend="generic">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <Mp3Codec enabled="True" priority="18" mime_type="audio/mp3" backend="generic">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <FlacCodec enabled="True" priority="9" mime_type="audio/flac" backend="generic">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <WavCodec enabled="True" priority="15" mime_type="audio/wav" backend="generic">
07-09 22:47:20 pulseaudio_dlna.application                    INFO       <OggCodec enabled="True" priority="6" mime_type="audio/ogg" backend="generic">
07-09 22:47:23 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Speaker Wohnzimmer (DLNA)".

Then, when I start to send a stream to the player (I tried an mp3 from VLC and a youtube video from Firefox) I get the following kind of message:

07-09 22:47:27 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink6"
07-09 22:47:28 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink6
07-09 22:47:28 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Speaker Wohnzimmer (DLNA)" to play ...
07-09 22:47:29 pulseaudio_dlna.plugins.upnp.renderer          WARNING  Updating device state unsuccessful! Sending play command.
07-09 22:47:29 pulseaudio_dlna.pulseaudio                     INFO     The device "Speaker Wohnzimmer (DLNA)" is playing.
07-09 22:47:29 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink6 finished!
07-09 22:47:29 pulseaudio_dlna.streamserver                   INFO     URL settings: /dWRuPSJ1dWlkOmU0M2VhNTllLTIxYzYtNDM4OC1iZGM2LWUzY2E3OWUyOWJiNCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 (udn="uuid:e43ea59e-21c6-4388-bdc6-e3ca79e29bb4",type="bridge")
07-09 22:47:29 pulseaudio_dlna.streamserver                   INFO     Registered stream "/dWRuPSJ1dWlkOmU0M2VhNTllLTIxYzYtNDM4OC1iZGM2LWUzY2E3OWUyOWJiNCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f6f90342d50) ...
07-09 22:47:29 pulseaudio_dlna.streamserver                   INFO     Starting processes "parec --format=s16le -d speakerwohnzimmer_dlna.monitor | lame -b 192 -r -"
07-09 22:47:29 pulseaudio_dlna.streamserver                   INFO     Processes of /dWRuPSJ1dWlkOmU0M2VhNTllLTIxYzYtNDM4OC1iZGM2LWUzY2E3OWUyOWJiNCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 initialized ...
07-09 22:47:29 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOmU0M2VhNTllLTIxYzYtNDM4OC1iZGM2LWUzY2E3OWUyOWJiNCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f6f90342d50) ...
07-09 22:47:32 pulseaudio_dlna.streamserver                   INFO     No more stream from device "Speaker Wohnzimmer".
07-09 22:47:32 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink1"
07-09 22:47:33 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink1
07-09 22:47:33 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink1 finished!

I'm on Kubuntu 16.04, I use multiple Raumfeld speakers and a Raumfeld Extend. All Raumfeld speakers have the current firmware.

Here's a full debug.log: http://pastebin.com/zrkky5GD

[eppelmania]

I have the same problem. I'm on Ubuntu 16.04.

[masmu]

Just from reading the logs it seems that your devices close the connection by them self.

streamserver.py

    def run(self):
        while True:
            if not self.do_processes_exist():
                self.create_processes()
                logger.info(
                    'Processes of {path} initialized ...'.format(
                        path=self.path))
            if not self.do_processes_respond():
                if self.reinitialize_count < 3:
                    self.reinitialize_count += 1
                    self.terminate_processes()
                    self.create_processes()
                    logger.info(
                        'Processes of {path} reinitialized ...'.format(
                            path=self.path))
                else:
                    logger.error(
                        'There were more than {} attempts to reinitialize '
                        'the record process. Aborting.'.format(
                            self.reinitialize_count))
                    break

            data = self.encoder_process.stdout.read(self.chunk_size)
            r, w, e = select.select([self.sock], [self.sock], [], 0)

            if self.sock in w:
                try:
                    self._send_data(self.sock, data)
                except socket.error:
                    break # <- here ---------------------------------------------

            if self.sock in r:
                try:
                    data = self.sock.recv(1024)
                    if len(data) == 0:
                        break # <- or here ---------------------------------------------
                except socket.error:
                    break # <- or here ---------------------------------------------
        self.terminate_processes()

After that the encoder processes are terminated as it should be.

[MMaus]

I have the same problem, Raumfeld (Speaker L and Speaker S) both disconnect directly after connecting (~5 sec). Might be a problem on the System. Has anyone found a solution for this problem?

[masmu]

@MMaus did you try to use the --fake-http-content-length flag?

Perhaps this is necessary for the devices. Please give it a try like:

pulseaudio-dlna --fake-http-content-length

[MMaus]

I just tried again, it did not work with the --fake-http-content-length flag.

Some error (log) info I think which is relevant: INFO Starting processes "parec --format=s16le -d speakerstube_dlna.monitor | lame -b 192 -r -" WARNING Updating device state unsuccessful! Sending play command. INFO Processes of /dWRuP[...]nJpZGdlIg%3D%3D/stream.mp3 initialized ... INFO The device "Speaker Stube (DLNA)" is playing. INFO _async_handle_sink_update /org/pulseaudio/core1/sink5 finished!

I'm not sure if the parec command is right? Esp: I selected mp3 (flac: the same), but it's something with 's16le' which sounds like a non-supported codec by Raumfeld (or am I completely mistaken here??)

UPDATE (1) I'm using Ubuntu 16.04 - I know it's not officially supported, but is this a known problem? (2) When I start pulseaudio-dlna without any sound playing, I can select the DLNA output and it stays connected. When I start a sound, it drops the connection.

[masmu]

The command is okay. It reads the audio stream as s16le from pulseaudio and then converts it via lame to mp3.

(1) I'm using Ubuntu 16.04 - I know it's not officially supported, but is this a known problem?

Supported, using the same.

(2) When I start pulseaudio-dlna without any sound playing, I can select the DLNA output and it stays connected. When I start a sound, it drops the connection.

That is very interesting. I have some ideas I want to try out. But there is always that problem that the device is not here and therefore inaccessible to me.

So things we can do:

• You test my changes (you should have some developing knowledge otherwise this is no fun for both of us)
• You provide access to the device (VPN or port forwarding and skype because I need your ears)
• You sent it to me (I don't want this myself)

If this is really important to you to get the device working, we also could do a remote developing session. But I do this just in rare cases, because we both would spent a few hours in skype together you watching me using your computer and being my ears.

[MMaus]

Great, let's go for option 1 (test your changes). I have some development skills (Python included), but absolutely no knowledge about pulseaudio (and it might take me a few days to do in-depth tests, 'cause spare time is rare time, but I certainly will).

[masmu]

@MMaus I created a test branch. Could you please check it out, test it with your device and paste the output here?

[MMaus]

I just downloaded and ran. Here is the stderr:

11-06 19:25:16 pulseaudio_dlna.application                    INFO     Using version: 0.5.2+git-b8519cb4a7d86a92a1ac456d7c833d65492d649f (raumfeld-speaker)
11-06 19:25:16 pulseaudio_dlna.application                    INFO     Using localhost: 192.168.178.20:8080
11-06 19:25:16 pulseaudio_dlna.application                    ERROR    Unable to parse "/home/moritz/.local/share/pulseaudio-dlna/devices.json"! Check the file for syntax errors ...
11-06 19:25:16 pulseaudio_dlna.application                    INFO     Encoder settings:
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvAacEncoder available="False" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvFlacEncoder available="False">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvL16Encoder available="False" sample-rate="44100" channels="2">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvMp3Encoder available="False" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvOggEncoder available="False" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvOpusEncoder available="False" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AVConvWavEncoder available="False">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegAacEncoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegFlacEncoder available="True">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegL16Encoder available="True" sample-rate="44100" channels="2">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegMp3Encoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegOggEncoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegOpusEncoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FFMpegWavEncoder available="True">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FaacAacEncoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FlacFlacEncoder available="True">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <LameMp3Encoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <NullEncoder available="True">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <OggencOggEncoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <OpusencOpusEncoder available="True" bit-rate="192">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <SoxL16Encoder available="True" sample-rate="44100" channels="2">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <SoxWavEncoder available="True">
11-06 19:25:16 pulseaudio_dlna.application                    INFO     Codec settings:
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <AacCodec enabled="True" priority="12" mime_type="audio/aac" backend="generic">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <L16Codec enabled="True" priority="0" mime_type="audio/L16" backend="generic">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <OpusCodec enabled="True" priority="3" mime_type="audio/opus" backend="generic">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <Mp3Codec enabled="True" priority="18" mime_type="audio/mp3" backend="generic">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <FlacCodec enabled="True" priority="9" mime_type="audio/flac" backend="generic">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <WavCodec enabled="True" priority="15" mime_type="audio/wav" backend="generic">
11-06 19:25:16 pulseaudio_dlna.application                    INFO       <OggCodec enabled="True" priority="6" mime_type="audio/ogg" backend="generic">
11-06 19:25:17 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Speaker Stube (DLNA)".
11-06 19:25:18 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Stube (DLNA)".
11-06 19:25:30 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink5"
11-06 19:25:31 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink5
11-06 19:25:31 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Speaker Stube (DLNA)" to play ...
11-06 19:25:31 pulseaudio_dlna.plugins.upnp.renderer          WARNING  Updating device state unsuccessful! Sending play command.
11-06 19:25:32 pulseaudio_dlna.streamserver                   INFO     URL settings: /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 (udn="uuid:92b63125-87a2-4336-8d15-b51b5ed14a2e",type="bridge")
11-06 19:25:32 pulseaudio_dlna.streamserver                   INFO     Registered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f922b10f8d0) ...
11-06 19:25:32 pulseaudio_dlna.streamserver                   INFO     Starting processes "parec --format=s16le -d speakerstube_dlna.monitor | lame -b 192 -r -"
11-06 19:25:32 pulseaudio_dlna.pulseaudio                     INFO     The device "Speaker Stube (DLNA)" is playing.
11-06 19:25:32 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink5 finished!
11-06 19:25:32 pulseaudio_dlna.streamserver                   INFO     Processes of /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 initialized ...
11-06 19:25:32 pulseaudio_dlna.streamserver                   INFO     socket error while reading zero data
11-06 19:25:32 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f922b10f8d0) ...
11-06 19:25:34 pulseaudio_dlna.streamserver                   INFO     No more stream from device "Speaker Stube".
11-06 19:25:34 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink0"
11-06 19:25:35 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0
11-06 19:25:35 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0 finished!
11-06 19:25:44 pulseaudio_dlna.pulseaudio                     INFO     on_playback_stream_removed "/org/pulseaudio/core1/playback_stream5"
11-06 19:25:45 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0
11-06 19:25:45 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0 finished!
11-06 19:26:04 pulseaudio_dlna.pulseaudio                     INFO     on_new_playback_stream "/org/pulseaudio/core1/playback_stream6"
11-06 19:26:06 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink5
11-06 19:26:06 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Speaker Stube (DLNA)" to play ...
11-06 19:26:06 pulseaudio_dlna.streamserver                   INFO     URL settings: /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 (udn="uuid:92b63125-87a2-4336-8d15-b51b5ed14a2e",type="bridge")
11-06 19:26:06 pulseaudio_dlna.streamserver                   INFO     Registered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f922a8aa110) ...
11-06 19:26:06 pulseaudio_dlna.streamserver                   INFO     Starting processes "parec --format=s16le -d speakerstube_dlna.monitor | lame -b 192 -r -"
11-06 19:26:06 pulseaudio_dlna.plugins.upnp.renderer          WARNING  Updating device state unsuccessful! Sending play command.
11-06 19:26:06 pulseaudio_dlna.streamserver                   INFO     Processes of /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 initialized ...
11-06 19:26:06 pulseaudio_dlna.pulseaudio                     INFO     The device "Speaker Stube (DLNA)" is playing.
11-06 19:26:06 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink5 finished!
11-06 19:26:07 pulseaudio_dlna.streamserver                   INFO     socket error while reading zero data
11-06 19:26:07 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f922a8aa110) ...
11-06 19:26:09 pulseaudio_dlna.streamserver                   INFO     No more stream from device "Speaker Stube".
11-06 19:26:09 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink0"
11-06 19:26:10 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0
11-06 19:26:10 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0 finished!
11-06 19:26:17 pulseaudio_dlna.pulseaudio                     INFO     Remove "speakerstube_dlna" sink ...
11-06 19:26:17 pulseaudio_dlna.pulseaudio                     INFO     Remove "stube_dlna" sink ...

[masmu]

Great, it reads zero data from the socket which normally means the remote host closed the connection. Lets see what happens when we ignore this. I've updated the branch.

[MMaus]

There are some changes in the log (this time I tried only once), but still an error. I'll check if I can somehow access information from the system (speaker). Is there some standard (DLNA etc.) way to access information from the speaker, e.g. log files?

11-06 20:04:56 pulseaudio_dlna.application                    INFO     Using version: 0.5.2+git-f88f97c2912bbd5dd8a7705b5700eff6f5012be3 (raumfeld-speaker)
11-06 20:04:56 pulseaudio_dlna.application                    INFO     Using localhost: 192.168.178.20:8080
11-06 20:04:56 pulseaudio_dlna.application                    ERROR    Unable to parse "/home/moritz/.local/share/pulseaudio-dlna/devices.json"! Check the file for syntax errors ...
11-06 20:04:56 pulseaudio_dlna.application                    INFO     Encoder settings:
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvAacEncoder available="False" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvFlacEncoder available="False">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvL16Encoder available="False" sample-rate="44100" channels="2">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvMp3Encoder available="False" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvOggEncoder available="False" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvOpusEncoder available="False" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AVConvWavEncoder available="False">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegAacEncoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegFlacEncoder available="True">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegL16Encoder available="True" sample-rate="44100" channels="2">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegMp3Encoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegOggEncoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegOpusEncoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FFMpegWavEncoder available="True">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FaacAacEncoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FlacFlacEncoder available="True">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <LameMp3Encoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <NullEncoder available="True">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <OggencOggEncoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <OpusencOpusEncoder available="True" bit-rate="192">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <SoxL16Encoder available="True" sample-rate="44100" channels="2">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <SoxWavEncoder available="True">
11-06 20:04:56 pulseaudio_dlna.application                    INFO     Codec settings:
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <AacCodec enabled="True" priority="12" mime_type="audio/aac" backend="generic">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <L16Codec enabled="True" priority="0" mime_type="audio/L16" backend="generic">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <OpusCodec enabled="True" priority="3" mime_type="audio/opus" backend="generic">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <Mp3Codec enabled="True" priority="18" mime_type="audio/mp3" backend="generic">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <FlacCodec enabled="True" priority="9" mime_type="audio/flac" backend="generic">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <WavCodec enabled="True" priority="15" mime_type="audio/wav" backend="generic">
11-06 20:04:56 pulseaudio_dlna.application                    INFO       <OggCodec enabled="True" priority="6" mime_type="audio/ogg" backend="generic">
11-06 20:04:57 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Speaker Stube (DLNA)".
11-06 20:04:57 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Stube (DLNA)".
11-06 20:05:15 pulseaudio_dlna.pulseaudio                     INFO     on_new_playback_stream "/org/pulseaudio/core1/playback_stream9"
11-06 20:05:16 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink7
11-06 20:05:16 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Speaker Stube (DLNA)" to play ...
11-06 20:05:16 pulseaudio_dlna.plugins.upnp.renderer          WARNING  Updating device state unsuccessful! Sending play command.
11-06 20:05:16 pulseaudio_dlna.streamserver                   INFO     URL settings: /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 (udn="uuid:92b63125-87a2-4336-8d15-b51b5ed14a2e",type="bridge")
11-06 20:05:16 pulseaudio_dlna.streamserver                   INFO     Registered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f0b89108710) ...
11-06 20:05:16 pulseaudio_dlna.streamserver                   INFO     Starting processes "parec --format=s16le -d speakerstube_dlna.monitor | lame -b 192 -r -"
11-06 20:05:16 pulseaudio_dlna.streamserver                   INFO     Processes of /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 initialized ...
11-06 20:05:16 pulseaudio_dlna.pulseaudio                     INFO     The device "Speaker Stube (DLNA)" is playing.
11-06 20:05:16 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink7 finished!
11-06 20:05:17 pulseaudio_dlna.streamserver                   INFO     socket error while reading zero data, ignoring this
11-06 20:05:17 pulseaudio_dlna.streamserver                   INFO     socket error while sending
11-06 20:05:17 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f0b89108710) ...
11-06 20:05:19 pulseaudio_dlna.streamserver                   INFO     No more stream from device "Speaker Stube".
11-06 20:05:19 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink0"
11-06 20:05:20 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0
11-06 20:05:20 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0 finished!
11-06 20:05:38 pulseaudio_dlna.pulseaudio                     INFO     Remove "speakerstube_dlna" sink ...
11-06 20:05:38 pulseaudio_dlna.pulseaudio                     INFO     Remove "stube_dlna" sink ...

[masmu]

Nope, no way I know of.

Your device kills the connection by itself. Thats why after reading zero data also sending data fails. So, we have to find out what it does not like. I updated the branch again and added logs for probing the protocol state. That was one thing which was added a few releases ago and there is a warning for it in the current log.

[MMaus]

here's the latest log

11-06 20:20:47 pulseaudio_dlna.application                    INFO     Using version: 0.5.2+git-8b55986e956b86ffaf5f32291b0308ce8ec90c18 (raumfeld-speaker)
11-06 20:20:47 pulseaudio_dlna.application                    INFO     Using localhost: 192.168.178.20:8080
11-06 20:20:47 pulseaudio_dlna.application                    ERROR    Unable to parse "/home/moritz/.local/share/pulseaudio-dlna/devices.json"! Check the file for syntax errors ...
11-06 20:20:47 pulseaudio_dlna.application                    INFO     Encoder settings:
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvAacEncoder available="False" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvFlacEncoder available="False">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvL16Encoder available="False" sample-rate="44100" channels="2">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvMp3Encoder available="False" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvOggEncoder available="False" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvOpusEncoder available="False" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AVConvWavEncoder available="False">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegAacEncoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegFlacEncoder available="True">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegL16Encoder available="True" sample-rate="44100" channels="2">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegMp3Encoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegOggEncoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegOpusEncoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FFMpegWavEncoder available="True">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FaacAacEncoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FlacFlacEncoder available="True">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <LameMp3Encoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <NullEncoder available="True">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <OggencOggEncoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <OpusencOpusEncoder available="True" bit-rate="192">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <SoxL16Encoder available="True" sample-rate="44100" channels="2">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <SoxWavEncoder available="True">
11-06 20:20:47 pulseaudio_dlna.application                    INFO     Codec settings:
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <AacCodec enabled="True" priority="12" mime_type="audio/aac" backend="generic">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <L16Codec enabled="True" priority="0" mime_type="audio/L16" backend="generic">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <OpusCodec enabled="True" priority="3" mime_type="audio/opus" backend="generic">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <Mp3Codec enabled="True" priority="18" mime_type="audio/mp3" backend="generic">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <FlacCodec enabled="True" priority="9" mime_type="audio/flac" backend="generic">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <WavCodec enabled="True" priority="15" mime_type="audio/wav" backend="generic">
11-06 20:20:47 pulseaudio_dlna.application                    INFO       <OggCodec enabled="True" priority="6" mime_type="audio/ogg" backend="generic">
11-06 20:20:48 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Stube (DLNA)".
11-06 20:20:49 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Speaker Stube (DLNA)".
11-06 20:21:12 pulseaudio_dlna.pulseaudio                     INFO     on_new_playback_stream "/org/pulseaudio/core1/playback_stream10"
11-06 20:21:13 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink10
11-06 20:21:13 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Speaker Stube (DLNA)" to play ...
11-06 20:21:13 pulseaudio_dlna.plugins.upnp.renderer          INFO     _get_transport_info: code 500
11-06 20:21:13 pulseaudio_dlna.plugins.upnp.renderer          INFO     <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><s:Fault><faultcode>s:Client</faultcode><faultstring>UPnPError</faultstring><detail><UPnPError xmlns="urn:schemas-upnp-org:control-1-0"><errorCode>401</errorCode><errorDescription>Invalid Action</errorDescription></UPnPError></detail></s:Fault></s:Body></s:Envelope>
11-06 20:21:13 pulseaudio_dlna.plugins.upnp.renderer          INFO     _update_current_state: state is None
11-06 20:21:13 pulseaudio_dlna.plugins.upnp.renderer          WARNING  Updating device state unsuccessful! Sending play command.
11-06 20:21:13 pulseaudio_dlna.streamserver                   INFO     URL settings: /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 (udn="uuid:92b63125-87a2-4336-8d15-b51b5ed14a2e",type="bridge")
11-06 20:21:13 pulseaudio_dlna.streamserver                   INFO     Registered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f8f295d2650) ...
11-06 20:21:13 pulseaudio_dlna.streamserver                   INFO     Starting processes "parec --format=s16le -d speakerstube_dlna.monitor | lame -b 192 -r -"
11-06 20:21:13 pulseaudio_dlna.streamserver                   INFO     Processes of /dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 initialized ...
11-06 20:21:13 pulseaudio_dlna.pulseaudio                     INFO     The device "Speaker Stube (DLNA)" is playing.
11-06 20:21:13 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink10 finished!
11-06 20:21:14 pulseaudio_dlna.streamserver                   INFO     socket error while reading zero data, ignoring this
11-06 20:21:14 pulseaudio_dlna.streamserver                   INFO     socket error while sending
11-06 20:21:14 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOjkyYjYzMTI1LTg3YTItNDMzNi04ZDE1LWI1MWI1ZWQxNGEyZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f8f295d2650) ...
11-06 20:21:16 pulseaudio_dlna.streamserver                   INFO     No more stream from device "Speaker Stube".
11-06 20:21:16 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink0"
11-06 20:21:17 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0
11-06 20:21:17 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink0 finished!
11-06 20:21:21 pulseaudio_dlna.pulseaudio                     INFO     Remove "stube_dlna" sink ...
11-06 20:21:21 pulseaudio_dlna.pulseaudio                     INFO     Remove "speakerstube_dlna" sink ...

[MMaus]

It works now - VERY strangely (explanation follows)

My system showed that there were two devices, "Stube" and "Speaker Stube". "Stube" did not have any valid codecs, but "Speaker Stube" had. This is related to [#219], it gave the encoding error.

Now I fixed the config file (3rd line in the log), and added the codecs to "Stube", and now I can use it.

To sum up, as far as I understand it at the moment:

• There appear two logical devices "Stube" and "Speaker Stube", where there is only one physical device (active).
• Only one of them, "Stube", is usable (maybe that's the intended way?)
• "Stube" does not work out-of-the-box because of Raumfeld's mime issue (workaround: [#219])

Thanks, and sorry for the hassle... I hope this might help other Raumfeld users as well.

[MMaus]

Well, I think it was because I fixed the config file, which made the device "Stube" usable. So it is, kind of, a configuration problem. It is unrelated to code changes. In fact is was accientially that this problem was solved:

My overall setup includes another Raumfeld System (Raumfeld One S, "Stube" is Raumfeld Stereo L). When all devices are online, I see:

• Stube (DLNA)
• Speaker Stube (DLNA)
• Speaker Babybox (DLNA)

The device "Stube" acts as Raumfeld server, so I thought the audio sink "Stube (DLNA)" is irrelevant and "somehow" relates to that server function. When I tried to select it, the error messages as in [#219] appeared immediately, not just when trying to play sound. I thought "Speaker Stube" and "Speaker Babybox" are the sinks to select when trying to play sound on either of these devices.

The solution (for now) is:

• Fix the config file, add codecs to "Stube (DLNA)" as described in [#219]
• Use "Stube (DLNA)"

The open question is whether I can somehow use "Babybox" - I'll figure this out tomorrow (or this week) and comment here.

[masmu]

Great! I really like to understand this more to prevent other users find them self in that hassle. Could you please first revert your config changes (so that we ran in that problem again) and then provide 2 full debug.logs? One for using the first device (Stube), one for the other (Speaker Stube). And after that I would also need a third one, with your workaround.

You can easily create a full debug.log with the following command: pulseaudio-dlna --debug 2>&1 | tee -a debug.log

And since those will be huge, please use a pastebin service.

[masmu]

I just created a branch where you can disable the mime type check. I still want your devices make work out of the box though.

[DanielSan85]

Hi there,

i am just running into the same problem with a Raumfeld One M. I will test your branch as soon as possible.

Faster than i thought. Here is my pastebin link

[masmu]

@DanielSan85 Does it work? What's your experience?

[MMaus]

I did the testing you asked for. Here are the results:

Scenario 1: config broken, thus skipped according to log A) Selected "Stube (DLNA)". Result: got error immediately, automatically switched back to Build-in Audio log output B) Selected "Speaker Stube (DLNA)" without any sound active, waited several seconds, then started some sound. Result: At the moment when the sound should start, an error occurs and the sound output is automatically switched back to Build-in Audio log output

Scenario 2: Proper config file, starting from pulseaudio-dlna --create-device-config. I edited that file, adding "flac" and "mp3" codecs to "Stube (DLNA)" which had no codecs before, according to issue [#219]. Then I started playback, and heard it on the speaker. log output

(Still, I'm not able to stream directly to my second system "Babybox", which appears in the log file, but that's ok since I can switch that in the Raumfeld control. I guess "Stube (DLNA)" is kind of a master, which forwards the actual stream to any speaker that is selected by the Raumfeld controller).

[MMaus]

I think it would be helpful if (1) only the Raumfeld main System ("Stube DLNA") would appear as audio sink, and (2) the config file would be automatically adjusted to cope with the currently corrupted mime-types (corrupted by Raumfeld as far as I understand)...

[masmu]

@MMaus Does the device "Babybox" appear as a sink in your sound control? I am a little bit confused about this, because in your logs the device is found and added but it is missing in your screenshot.

When selecting "Speaker Stube" your device is being instructed to play, but a state check (GET_TRANSPORT_INFO) is failing. The process of instructing a device to play consists of 2 steps:

• Registering the stream url. It is like setting the device playlist (SetAVTransportURI)
• Sending the play command if necessary (Play)

Some devices start to play on their own when you set the stream url and some need that additional play command. To find out if it is necessary, we check the current transport state. If the device reports being in idle state, a play command is being send. If it is already playing that step is being skipped.

Now to the problem: Your device does respond with Invalid Action to that check, which results in sending that play command nevertheless. But your device is one of those devices which start to play on their own when the stream url was set. When the device receives the unnecessary play command it closes the first stream and initiates a second one. Since pulseaudio-dlna cannot know if there will be a second stream it switches back the applications stream to the default sink and that prevents the second stream from being established.

The reason for that switch back is that the sound control should always represent the actual playing state. E.g. when you see that you an application stream is set to play on the device 'Babybox' it really should be that way. Otherwise this could be really confusing.

So, what do we do? First, we should verify that it really is that way. Please get the feature/ignore-mime-types branch.

• Test your device 'Stube' with pulseaudio-dlna --disable-mimetype-check
• Test your devices 'Speaker Babybox' and 'Speaker Stube' with pulseaudio-dlna --disable-switchback

I am very confident that this will work and I think we can make all of your devices play perfectly. So, if that works we need to find out why the GET_TRANSPORT_INFO check is failing. That could have various reasons.

• As far as I understood Raumfeld provides a virtual device representing all connected speakers. Perhaps that process locks those speakers for that. Try disabling the device grouping.
• The operation is really not available. Please pastebin a copy of http://<device-ip>:<port>/avtransport.xml for the device 'Speaker Stube'. If the IP and port did not change it should be http://192.168.178.37:34261/avtransport.xml The available actions are being listed there.
• Use a good UPnP tool like Android's BubbleUPnP and record a working instruction set with wireshark. Don't hesitate to ask for additional information on this. It is very easy with a Fritzbox.

[MMaus]

The device "Babybox" does appear as a sink. In the screenshots, the device was just switched off... I think you're right that Raumfeld provides a virtual device, which should be used as (single?) DMR. I checked out the branch and rebuilt, but the results were the same. I can prepare and send the corresponding log files if you want, and of course both avtransport.xml files (I can do this tonight). Regarding the wireshark action: I think I would need some help with that - can you send me some instructions? I almost never used wireshark or BubbleUPnP (will have to install it first). I have a Fritzbox.

[masmu]

I take the logs, perhaps I can find some new stuff there. A copy of avtransport.xml would be very interesting, as I said, it contains the supported actions of your device.

Regarding BubbleUPnP: First make sure you are able to stream a mp3 file stored on your phone to a single speaker. If that works, shutdown BubbleUPnP completely, setup the capturing and repeat the process. Our mission is to record a complete working session consisting of several GET and POST requests. If you like you can write a .pcap file you can attach here, but since there might be some sensitive information in there I can totally understand when you prefer not to do so.

In wireshark you are looking especially for a POST request to your speaker sent by BubbleUPnP on your phone, containing the string GET_TRANSPORT_INFO. But all POSTs and GETs are interesting to get an idea of the whole communication.

• Setup wireshark

sudo apt-get install wireshark
sudo dpkg-reconfigure wireshark-common # yes, you want to allow package capturing for non root users
sudo adduser $USER wireshark
sudo shutdown -r now # a reboot is required to make the group changes take effect

• Download and run capture.sh

It will connect to your Fritzbox and pipe all data directly to wireshark. For that it asks you which interface you want to capture from. For my Fritzbox this is interface #13 (AP 2,4 GHz ath0, Interface 1) for the Fritzbox of a friend this is #12 (ath0). Play a little bit with that script to find the correct interface and get familiar with wireshark.

[MMaus]

I have installed wireshark and did the following:

• copied the avtransport.xml files. I took two from "Stube" (IP ... .37) and one from "Babybox" (IP: ... .32), but all were identical (says diff), so I put only one into the archive
• run bin/pulseaudio-dlna --disable-mimetype-check --debug 2> stube_working.log, switched to "Stube", and played a song (worked). The wireshark log is also referring to this event only.
• run bin/pulseaudio-dlna --disable-switchback --debug 2> speaker_stube_...log, switched to "Speaker Stube", and played a song (did not work, but did also not switched back)
• run bin/pulseaudio-dlna --disable-switchback --debug 2> speaker_babybox_...log, switched to "Speaker Babybox", and played a song (also didn't work) The full wireshark log is also attached.

All data are here: logs and wireshark output

[masmu]

Thanks for all the stuff, but I guess there was a misunderstanding regarding the wireshark capture. I need a recording for BubbleUPnP and "Speaker Stube". But it seems as the provided capture is for pulseaudio-dlna and "Stube". I would like to compare what BubbleUPnP does different in contrast to my implementation.

I checked the actions both "Speaker" devices provide and GetTransportInfo is really missing. The problem with that is that regarding to the official DLNA specification this action is required. I really have no idea why this is missing. So, I deleted the old bug/raumfeld-speaker branch and created a new one with the same name. This one just registers the stream but does not send play commands. Please test your speakers with that.

[MMaus]

I'll check this out (also: BubbleUPNP) in the next few days!

[MMaus]

I tried the new Branch. It did not change things; "Stube" works but "Speaker Stube" doesn't. I tried BubbleUPNP, and this works (well, for "Stube" I had to disable the mime type check). With BubbleUPNP I can play on Stube, Speaker Stube and Speaker Babybox. I can even play different stuff on Speaker Stube and Speaker Babybox. I have a wireshark capture from BubbleUPNP, hope this time it's correct and informative. Here are the logs and wireshark capture Ps: sorry for the late reply..

[masmu]

No problem.

I am glad that BubbleUPnP is able to stream to your device. So I was very curious to see the capture... But there is no DLNA conversation in it.

• Did you use the script I provided? If not and you just started wireshark on your own you will just record the data between your computer and other hosts. But not from your phone and the speakers.
• Another thing I can imagine is that you selected the wrong interface while starting up the script. Please test another one.
• Or you started the recording too late. So BubbleUPnP was still running and already did the interesting stuff before you actually started the script.

[MMaus]

Yes, I used the script you provided. I chose interface 13 from these

What do you want to capture?
INTERNET:
   1) Internet
   2) Interface 0
   3) Routing Interface
INTERFACES:
   4) tunl0
   5) eth0
   6) eth1
   7) eth2
   8) eth3
   9) lan
  10) hotspot
  11) wifi0
  12) ath0
WIFI:
  13) AP 2,4 GHz ath0, Interface 1
  14) AP 2,4 GHz ath0, Interface 0
  15) HW 2,4 GHz wifi0, Interface 0

There is a repeater in the network - does this change anything? I actually started and stopped several stream during the recording, so there should be at least a bit DLNA on the network.

I can try different interfaces. As there was some traffic, which was apparently not initiated by my computer, I thought I had the "right" interface. How do I recognize that there is DLNA activity from wireshark? Btw, wireshark starts with an error MsgBox "End of file on pipe magic during open" - is this message relevant for us? I have no idea what pipe magic would be here...

[masmu]

I've experienced the "End of file on pipe magic during open" some time ago too. It might be that the HTTP connection to your fritzbox just broke. I've tried my own instructions on my machine and in a fresh vm. I could not reproduce that error there. So, if that happens: Close wireshark and the script and just start it again.

Try interface 12 (ath0). Thats working for me.

There is a repeater in the network - does this change anything?

Depends on the setup... If you want to make sure it is not affecting you, disable it and move the devices closer to each other ensuring a strong fritzbox wifi signal.

How do I recognize that there is DLNA activity from wireshark?

DLNA packets are HTTP packets transporting XML. Look out for POST, GET requests like the following:

POST /5c3ad024-28b6-4651-aff5-4d502210ac10/AVTransport/control HTTP/1.1
Soapaction: "urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo"
Content-type: text/xml;charset=utf-8
Content-Length: 329
Host: 192.168.178.43:42928
Connection: Keep-Alive
User-Agent: Android/6.0.1 UPnP/1.0 BubbleUPnP/2.8.2

<?xml version="1.0" encoding="utf-8" standalone="yes"?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
    <s:Body>
        <u:GetTransportInfo xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
            <InstanceID>0</InstanceID>
        </u:GetTransportInfo>
    </s:Body>
</s:Envelope>

[MMaus]

Finally I managed to get something - here is the wireshark capture I've removed the repeater, used IF 12 and checked that there are DLNA packages from BubbleUPNP inside.

There are two (short) streams played: "Speaker Stube" and "Stube". I tried to play on "Speaker Stube" first, which somehow did not work; then switched to "Stube" (worked), and then switched to "Speaker Stube again" (worked - strangely). So I'm not sure what happened technically under the hood (if BubbleUPnP switched back to "Stube")

[masmu]

@MMaus Thanks for the capture. You did a great job! What BubbleUPnP sends is in there.

I took me a few hours to look to all through this. And the following can be seen as a summary:

stream(8,26)  - 192.168.178.37:56056    Stube   Virtual Media Player           urn:schemas-upnp-org:device:MediaRenderer:1
stream(9,29)  - 192.168.178.37:60223    Raumfeld MediaServer                   urn:schemas-upnp-org:device:MediaServer:1
stream(19,27) - 192.168.178.37:54257    Speaker Stube, Digital Media Player    urn:schemas-upnp-org:device:MediaRenderer:1
stream(19)    - 192.168.178.28:58933    RaumfeldControl/3.6 RaumfeldProtocol/399 Build/10703 Android/5.1.1
stream(31,33) - 192.168.178.28:58645    BubbleUPnP Media Renderer              urn:schemas-upnp-org:device:MediaRenderer:1
stream(34)    - 192.168.178.28:58645    BubbleUPnP Media Server                urn:schemas-upnp-org:device:MediaServer:1

stream(30)    - 192.168.178.37:56056    Content-Type: image/png
stream(49)    - 192.168.178.37:54257    Content-Type: image/png
stream(50)    - 192.168.178.37:60223    Content-Type: image/png

stream(51)?     BubbleUPnP with Speaker Stube
    SUBSCRIBE /RenderingControl/evt 
    urn:schemas-upnp-org:service:AVTransport:1#Stop
    urn:schemas-upnp-org:service:RenderingControl:1#SetVolume 45
    urn:schemas-upnp-org:service:RenderingControl:1#SetVolume 46
    urn:schemas-upnp-org:service:RenderingControl:1#SetVolume 47
    urn:schemas-upnp-org:service:RenderingControl:1#SetVolume 48
    urn:schemas-upnp-org:service:RenderingControl:1#SetVolume 49
    UNSUBSCRIBE /RenderingControl/evt
    SUBSCRIBE /RenderingControl/evt
    urn:schemas-upnp-org:service:AVTransport:1#Stop
    urn:schemas-upnp-org:service:AVTransport:1#Stop
    urn:schemas-upnp-org:service:AVTransport:1#SetAVTransportURI http://192.168.178.28:57645/external/audio/media/9782.mp3
    urn:schemas-upnp-org:service:AVTransport:1#Play
    urn:schemas-upnp-org:service:AVTransport:1#Stop

stream(69)?    BubbleUPnP with Stube
    SUBSCRIBE /RenderingService/Event
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#Stop
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo
    urn:schemas-upnp-org:service:AVTransport:1#Stop
    urn:schemas-upnp-org:service:AVTransport:1#SetAVTransportURI
    urn:schemas-upnp-org:service:AVTransport:1#Play
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo -> PLAYING
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#Stop
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetPositionInfo
    urn:schemas-upnp-org:service:AVTransport:1#GetTransportInfo
    UNSUBSCRIBE /RenderingService/Event

stream(73)?  BubbleUPnP with Device?
    GET /external/audio/media/9782.mp3 HTTP/1.1
    Host: 192.168.178.28:57645
    Icy-MetaData: 1
    Connection: Keep-Alive

    HTTP/1.1 200 OK
    Date: Fri, 25 Nov 2016 19:55:25 GMT
    Server: Android, UPnP/1.0 DLNADOC/1.50, BubbleUPnP/2.8.2
    Cache-Control: no-cache
    transferMode.dlna.org: Streaming
    Accept-Ranges: bytes
    Content-Type: audio/mpeg
    Content-Length: 1587729
    Last-Modified: Sat, 19 Nov 2016 19:21:35 GMT

stream(86)?  BubbleUPnP with Device
    GET /external/audio/media/9782.mp3 HTTP/1.1
    Host: 192.168.178.28:57645
    Connection: close
    icy-metadata: 1
    User-Agent: GStreamer souphttpsrc libsoup/2.52.1

    HTTP/1.1 200 OK
    Date: Fri, 25 Nov 2016 19:55:41 GMT
    Server: Android, UPnP/1.0 DLNADOC/1.50, BubbleUPnP/2.8.2
    Cache-Control: no-cache
    transferMode.dlna.org: Streaming
    Accept-Ranges: bytes
    Content-Type: audio/mpeg
    Content-Length: 1587729
    Last-Modified: Sat, 19 Nov 2016 19:21:35 GMT
    Connection: close

When comparing the headers pulseaudio-dlna sends with those of BubbleUPnP the most noticeable difference is the Content-Length field. So, I would please you to try the --fake-http-content-length flag in combination with the device Speaker Stube.

[hartmans]

Hi. I'm seeing the same issue and would be happy to perform testing/any additional debugging if you need more than what you're getting. It looks like the most recent request is to try --fake-http-content-length. On stock code, that does not help at least.

[hartmans]

I'll also note that if I use chromecast, it works reasonably well.

[masmu]

@hartmans: MMaus and me did a 2 hours debug session over the internet on monday. But in that time we could just figure out how to stream to the virtual device Raumfeld provides via device grouping. But we failed for each individual speaker. What I really need is a testing device for a larger time period than those 2 hours. I have a setup in my mind which is ... lets call it creative. But it would do the job ...

The setup would be like the following:

• A port forwarding in your router to be able to access the device and the devices control url.
• A running computer with a microphone placed next to the speakers. On the computer would be a Teamspeak client running, connected to a specific Teamspeak server so that I hear something on success.

That setup should be accessible to me for 1-2 days.

[svenfoo]

@masmu Streaming to a Raumfeld device directly via UPnP is not really supported. The UPnP device that the Raumfeld speaker offers is not intended to by used by third-party control-points, it's considered an internal API. If you want to stream to Raumfeld devices, please use the virtual devices Raumfeld provides. If there are interoperability issues with these, feel free to contact me. I can certainly give you advice and safe you a lot of time by answering your questions. We may even be able to provide you a Raumfeld device and we can consider adjustments to the Raumfeld firmware to make sure that pulseaudio-dlna works well with it. Just contact me, I'll be glad to help.

[hartmans]

Hi. I realized that I failed to reply to this. I brought up the question of giving external network access to the speakers through our internal security process, and I can set up such access. If that would be valuable feel free to contact me at hartmans@debian.org.

For myself, pulseaudio-dlna works fine with the chromecast device. I'm not sure that I'm seeing the virtual devices that are talked about here on my speakers.

That said, if you do have an opportunity to get one of these for better pulseaudio-dlna support, they are truly amazing speakers, and I'd go that route:-)

[masmu]

@svenfoo Thanks for your kind offering. I have just completed a refactoring to verify the device's action capabilities each UPnP service provides. And a testing device would make it much more easy to test the new code base.

I already have some questions :grin:

• Why do Virtual Media Player's just specify dlna-playcontainer:*:application/xml:*,http-get:*:application/xspf+xml:*,http-get:*:audio/x-mpegurl:*,rhapsody-radio:*:audio/rhapsody-radio:*,rhapsody-track:*:audio/rhapsody-track:*,wimp-track:*:audio/wimp-track:*,tidal-track:*:audio/tidal-track:* as supported protocols? Missing mime types such as audio/mp3, audio/ogg etc make it necessary to launch pulseaudio-dlna with the --disable-mimetype-check flag or in case of BubbleUPnP you have to set a similar option in the application's settings. That prevents the virtual devices to work out of the box, which is a little bit unfortunate.

• A Digital Media Player's AVTransport service does not implement the UPnP action GetTransportInfo. I guess those services are considered as internal API. Is there any particular reason for not implementing that action? I am asking because we found out that streaming to those devices works in general. The problem is here that probing for the current transport state fails. I got a wireshark capture where BubbleUPnP was able to determine the actual transport state somehow, but I found no clue of how that actually works... because BubbleUPnP does also not use that function.

@hartmans Also thank you very much for the offering. But as you stated out yourself, a real testing device is better. That way I could also use the results of different testing applications which do not work over VPN or port forwarding.

[svenfoo]

OK, so GetTransportInfo is not implemented because we don't need it. Our implementation relies on the LastChange events and never polls any states. But if it helps you, adding this action is straight-forward, so I just went ahead and added it. It will take a while of course until this change makes it into a firmware release.

The virtual media renderers should actually list the supported protocols of the renderers in the group plus some additional protocols, which happen to be the protocols that you listed. So it seems there is a bug in the code that collects the supported protocols from the renderers. I'll have a look at fixing this issue. Again, this is a feature that we do not need, but if it helps to improve compatibility and isn't too much effort, we can certainly have a look at fixing it.

@masmu Please get in contact with me in private mail so we can discuss the details of getting you a device for testing.

[svenfoo]

Found the cause of the problem today and it should be fixed on the Raumfeld devices with the next Raumfeld firmware update.

[xvello]

I can confirm flac streaming is working on master with a Raumfeld One M device on 1.62 firmware. This issue can be closed. Thumbs up to Taufel for working with the community!

[masmu]

@xvello Raumfeld wanted to provide a testing device but they don't reply anymore. So could you please test current master to make sure everything works?

[xvello]

Hi! Will do on Friday. Any specific testing instructions?

[masmu]

@xvello Thank you! No specific testing, the whole DLNA code is new and is being used when testing normal streaming.

[xvello]

Hi!

Just tested master today with my One M. It works flawlessly with both mp3 (default) and flac on ffmpeg encoder. Both the DLNA and Cast endpoints are detected and work.

Thanks for your work!

[xavier:/opt/git/pulseaudio-dlna] master ± bin/pulseaudio-dlna --disable-workarounds 
05-13 19:13:54 pulseaudio_dlna.application                    INFO     Using version: 0.5.2+git-360bfcba983df3c7d6ea52ee0e6b974137bfad5a (master)
05-13 19:13:54 pulseaudio_dlna.application                    INFO     Binding to *:8080
05-13 19:13:54 pulseaudio_dlna.application                    INFO     Encoder settings:
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvAacEncoder available="False" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvFlacEncoder available="False">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvL16Encoder available="False" sample-rate="44100" channels="2">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvMp3Encoder available="False" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvOggEncoder available="False" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvOpusEncoder available="False" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AVConvWavEncoder available="False">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegAacEncoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegFlacEncoder available="True">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegL16Encoder available="True" sample-rate="44100" channels="2">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegMp3Encoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegOggEncoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegOpusEncoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FFMpegWavEncoder available="True">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FaacAacEncoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FlacFlacEncoder available="True">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <LameMp3Encoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <NullEncoder available="True">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <OggencOggEncoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <OpusencOpusEncoder available="True" bit-rate="192">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <SoxL16Encoder available="False" sample-rate="44100" channels="2">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <SoxWavEncoder available="False">
05-13 19:13:54 pulseaudio_dlna.application                    INFO     Codec settings:
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <AacCodec enabled="True" priority="12" mime_type="audio/aac" backend="generic">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <L16Codec enabled="True" priority="1" mime_type="audio/L16" backend="generic">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <OpusCodec enabled="True" priority="3" mime_type="audio/opus" backend="generic">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <Mp3Codec enabled="True" priority="18" mime_type="audio/mp3" backend="generic">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <FlacCodec enabled="True" priority="9" mime_type="audio/flac" backend="generic">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <WavCodec enabled="True" priority="15" mime_type="audio/wav" backend="generic">
05-13 19:13:54 pulseaudio_dlna.application                    INFO       <OggCodec enabled="True" priority="6" mime_type="audio/ogg" backend="generic">
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Module "module-dbus-protocol" already loaded.
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Probing for $PULSE_DBUS_SERVER unsuccessful.
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Probing for /run/pulse/dbus-socket unsuccessful.
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Probing for $XDG_RUNTIME_DIR successful (unix:path=/run/user/1000/pulse/dbus-socket).
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Probing for org.PulseAudio.ServerLookup1 successful (unix:path=/run/user/1000/pulse/dbus-socket).
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Found the following pulseaudio server addresses: unix:path=/run/user/1000/pulse/dbus-socket
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Connecting to pulseaudio on "unix:path=/run/user/1000/pulse/dbus-socket" ...
05-13 19:13:54 pulseaudio_dlna.pulseaudio                     INFO     Could not get default sink. Perhaps there is no one set?
05-13 19:13:55 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Chopin (Chromecast)".
05-13 19:13:55 pulseaudio_dlna.pulseaudio                     INFO     Added the device "Speaker Chopin (DLNA)".
05-13 19:14:02 pulseaudio_dlna.discover                       INFO     SSDPDiscover.search()
05-13 19:14:11 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink21"
05-13 19:14:12 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink21
05-13 19:14:12 pulseaudio_dlna.pulseaudio                     INFO     Instructing the device "Speaker Chopin (DLNA)" to play ...
05-13 19:14:12 pulseaudio_dlna.streamserver                   INFO     URL settings: /dWRuPSJ1dWlkOjkxYmFjN2NjLThlODAtNDc0MS04NWFlLWU2YzJiMmRlZTVmOCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 (udn="uuid:91bac7cc-8e80-4741-85ae-e6c2b2dee5f8",type="bridge")
05-13 19:14:12 pulseaudio_dlna.streamserver                   INFO     Registered stream "/dWRuPSJ1dWlkOjkxYmFjN2NjLThlODAtNDc0MS04NWFlLWU2YzJiMmRlZTVmOCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0x7f7aeb14e6d0) ...
05-13 19:14:12 pulseaudio_dlna.streamserver                   INFO     Starting processes "parec --format=s16le -d speakerchopin_dlna.2.monitor | lame -b 192 -r -"
05-13 19:14:12 pulseaudio_dlna.streamserver                   INFO     Processes of /dWRuPSJ1dWlkOjkxYmFjN2NjLThlODAtNDc0MS04NWFlLWU2YzJiMmRlZTVmOCIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 initialized ...
05-13 19:14:28 pulseaudio_dlna.plugins.dlna.renderer          WARNING  Updating device state unsuccessful! Sending play command.
05-13 19:14:28 pulseaudio_dlna.pulseaudio                     INFO     The device "Speaker Chopin (DLNA)" is playing.
05-13 19:14:28 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink21 finished!
05-13 19:39:34 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/source2"
05-13 19:39:54 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/source2
05-13 19:39:54 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/source2 finished!

[masmu]

@xvello Thank you very much! Would you mind to also provide a full debug.log? pulseaudio-dlna --debug 2>&1 | tee -a debug.log

The following line is worrying me. As far as I know this should have been fixed by Raumfeld.

05-13 19:14:28 pulseaudio_dlna.plugins.dlna.renderer          WARNING  Updating device state unsuccessful! Sending play command.

[xvello]

Here it is, with no other option than --debug. I used the following outputs, switching back to internal audio between them:

• Chopin (DLNA): the room's virtual player (preferred interface)
• Speaker Chopin (DLNA): the physical player
• Choping (Chromecast): emulated cast

The warning only appears when using the speaker output, but the device plays nonetheless.

chopin.log.txt