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

Crash with UnicodeDecodeError #179

Closed raphaelh closed 8 years ago

raphaelh commented 8 years ago

I'm streaming music wirelessly from my laptop computer to my Raspberry Pi with Kodi thanks to the great pulseaudio-dlna, thanks!

Lately, I've been getting several crashes with UnicodeDecodeError.

I have XUbuntu 15.04 with pulseaudio-dlna package 0.4.7 installed via the following PPA: http://ppa.launchpad.net/qos/pulseaudio-dlna/ubuntu

The error I get is:

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/pulseaudio_dlna/pulseaudio.py", line 540, in _on_new_message
    getattr(self, message_type)(**message)
  File "/usr/lib/python2.7/dist-packages/pulseaudio_dlna/pulseaudio.py", line 623, in on_bridge_disconnected
    self.switch_back(stopped_bridge, reason)
  File "/usr/lib/python2.7/dist-packages/pulseaudio_dlna/pulseaudio.py", line 590, in switch_back
    self.fallback_sink.label)))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3 in position 16: ordinal not in range(128)
raphaelh commented 8 years ago

If I launch pulseaudio-dlna with the --disable-switchback option, it doesn't crash, but the music stops playing quite frequently:

03-04 10:33:34 pulseaudio_dlna.streamserver                   INFO     Client 192.168.1.3 unregistered stream /dWRuPSJ1dWlkOjkxNmY1NjIxLTk1OTgtNjhiYS1iZDI1LTYzMGNlY2Q1NTJjZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3 using method 2.
03-04 10:33:36 pulseaudio_dlna.streamserver                   INFO     Stream closed. Cleaning up remaining processes ...
03-04 10:33:36 pulseaudio_dlna.streamserver                   INFO     Device "Kodi (OpenELEC)" disconnected.
masmu commented 8 years ago

That sounds like a weak wifi connection. When a stream unregistered with method 2 your computer failed to send the stream data to your device. Which codec are you using?

Regarding the Unicode error: A switch back happens when your device disconnects to ensure your pulseaudio stream represent the current device state. Therefore it informs the user about that event and the devices name is needed. But there are bytes in your device description which cannot be decoded to unicode. And since you disabled the switch back function you bypassed the error, but in case the stream fails your sinks are not switched back. Which version of Kodi are you running?

raphaelh commented 8 years ago

Thanks for your quick reply. I'm using Kodi 15.2 on OpenElec (specific version for Wolfson audio card: http://openelec.tv/forum/124-raspberry-pi/69870-wolfson-audio-card-support)

How can I tell which codec I'm using?

I'm currently trying with a ethernet cable instead of Wifi if the problem is still there.

masmu commented 8 years ago

Could you uninstall the PPA version of pulseaudio-dlna and check out that branch? I need a debug.log of the branch version.

bin/pulseaudio-dlna 2>&1 | tee -a debug.log
raphaelh commented 8 years ago

The problem doesn't occur when the RPi is connected via ethernet cable, so I restarted it with the USB wifi dongle plugged and ran the branch you just created.

The produced debug.log is here: https://gist.github.com/raphaelh/f825fb641e7430ba7253

masmu commented 8 years ago

Could you also paste me the content of http://192.168.1.16:52235/dmr/SamsungMRDesc.xml?

raphaelh commented 8 years ago
$ wget http://192.168.1.16:52235/dmr/SamsungMRDesc.xml
--2016-03-04 12:20:09--  http://192.168.1.16:52235/dmr/SamsungMRDesc.xml
Connecting to 192.168.1.16:52235... connected.
HTTP request sent, awaiting response... 401 Unauthorized

Username/Password Authentication Failed.

This is my TV, but I don't use it so I can unplug it and try

masmu commented 8 years ago

No, thank you. You don't have to. There was an additional error (invalid xml). If it responses with 401 this explains it totally.

Could you try out that branch? It is the most recent and uses lxml instead of beautifulsoup for parsing xml. You need python-lxml and python-zeroconf installed for that.

raphaelh commented 8 years ago

Here is the new debug.log https://gist.github.com/raphaelh/315a69996564b2fe837c

masmu commented 8 years ago

Thanks, could you head back to the bug/unicode-decoding branch and try again?

raphaelh commented 8 years ago

Yes, new debug.log : https://gist.github.com/raphaelh/723ce9cddefcf934a84a

masmu commented 8 years ago

Thanks, updated again. Please retry.

raphaelh commented 8 years ago

Kodi doesn't appear any longer in pavucontrol

New debug.log : https://gist.github.com/raphaelh/03cbb3bcdf40aa577eda

masmu commented 8 years ago

Thanks, updated again. Please retry. This should work ...

raphaelh commented 8 years ago

Last debug.log : https://gist.github.com/raphaelh/ce3c4c3e32cd89ca12fd

It seems to work great, there was a minor glitch which can probably be seen in the middle of debug.log

masmu commented 8 years ago

What do you mean? I've updated the branch again. Could you please retry?

raphaelh commented 8 years ago

I'm sorry but I have to go, I'm organizing an install party :)

Thanks a lot, I'll try this branch again and report here.

masmu commented 8 years ago

Ok, looking forward to it. Have fun! :wink:

raphaelh commented 8 years ago

Latest debug.log : https://gist.github.com/raphaelh/241e15104f242b6562a1

Still not perfect :)

masmu commented 8 years ago

Well thats another error. The port used by the HTTP server is in use... Is another instance of pulseaudio-dlna running?

raphaelh commented 8 years ago

No: https://gist.github.com/raphaelh/ecf7f7c2328a70066049

I made sure to kill any pulseaudio-dlna before launching the test

masmu commented 8 years ago

But there is an application using the HTTP port. Please run lsof -t -i :8080 | xargs ps -fp to find out which application is using it. This is for the case that you are using the default port 8080.

raphaelh commented 8 years ago
$ lsof -t -i :8080 | xargs ps -fp
UID        PID  PPID  C STIME TTY          TIME CMD
rhk       3988  1352  0 09:18 ?        00:00:11 stream_server        
masmu commented 8 years ago

This might be a dead instance. Kill it manually. kill -9 3988

raphaelh commented 8 years ago

Yeah, just killed it and launched the test again !

raphaelh commented 8 years ago

It's been running for nearly 20 minutes without a glitch, looks good :)

https://gist.github.com/raphaelh/3ebd5f575f2cdf889c9e

masmu commented 8 years ago

Did the wifi fail in that time? The application should switch back your sinks in that case and display a notification.

raphaelh commented 8 years ago

It just did:

03-05 11:32:38 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOjkxNmY1NjIxLTk1OTgtNjhiYS1iZDI1LTYzMGNlY2Q1NTJjZSIsdHlwZT0iYnJpZGdlIg%3D%3D/stream.mp3" (0xb4570eccL) ...
03-05 11:32:41 pulseaudio_dlna.streamserver                   INFO     No more stream from device "Kodi (OpenELEC)".
03-05 11:32:41 pulseaudio_dlna.notification                   INFO     notify2 failed to display: Device "Kodi (OpenELEC) (DLNA)" - The device disconnected. Your streams were switched back to <b>Audio interne Stéréo analogique</b>
03-05 11:32:41 pulseaudio_dlna.pulseaudio                     INFO     on_device_updated "/org/pulseaudio/core1/sink1"
03-05 11:32:42 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink1
03-05 11:32:42 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink1 finished!
masmu commented 8 years ago

Nice. That looks good. That é were the bytes which could't get decoded. I'll merge everything together for a last test...

raphaelh commented 8 years ago

Is it possible to add a command-line option to automatically reconnect?

I personally prefer a 1 second cut in my audio on my RPi than having it switch back to internal audio on my laptop

masmu commented 8 years ago

Could you try out latest master? I merged everything together which makes this basically v0.5.0.

Regarding to the auto-reconnect feature: The gap would be more than 1 second. More like 5 to 10 seconds. I don't know if this is fun ... Still interested in such a feature?

masmu commented 8 years ago

Well, I made a quick hack. There is no CLI option, that branch always tries to reconnect. Since this is just a quick hack it might produce other problems. Let me know what you think about it.

masmu commented 8 years ago