hzeller / gmrender-resurrect

Resource efficient UPnP/DLNA renderer, optimal for Raspberry Pi, CuBox or a general MediaServer. Fork of GMediaRenderer to add some features to make it usable.
GNU General Public License v2.0
839 stars 204 forks source link

audio stops after some ammount of listening + strange thing with threads #12

Open gunbro opened 11 years ago

gunbro commented 11 years ago

Thank you for gmrender! I use it on Raspberry Pi but i have one problem. Please help me! When i listen to 2 or 3 albums in a row or long gapless mix (like this for example http://goo.gl/PmMAk) using BubbleUPnP on phone or tablet , its never plays till then end, just stops on random time but mostly about more than 1 hour. If i restart gmrender than its just well play again for next ~2 hours. I try to push songs from MiniDLNA on Pi, Home Media Server on Win7 or just directly from BubbleUPnP local media server and always same problem. Also gmrender create new thread after each song. Is this OK?

threads

here is the log file i can get, dont know where to see else:

Action 'GetPositionInfo' was a success! Action 'GetPositionInfo' was a success! Action 'GetPositionInfo' was a success! GStreamer: Got tags from element flacparse18 Action 'GetPositionInfo' was a success! Action 'GetPositionInfo' was a success! Action 'GetPositionInfo' was a success! GStreamer: Got tags from element flacparse18 Action 'GetPositionInfo' was a success! Action 'GetPositionInfo' was a success! GStreamer: Got tags from element flacparse18 HZ: about-to-finish cb: setting uri http://192.168.1.111:8200/MediaItems/7295.flac ---------------------------------- Done playing....1 HZ: notify all uris changed ------

##

HZ:

upnp:classobject.item.audioItem.musicTrack/upnp:classdc:titleInner Disbelief (Acapella)/dc:titledc:creatorD-Bridge/dc:creatorupnp:artistD-Bridge/upnp:artistupnp:albumArtURIhttp://192.168.1.111:8200/AlbumArt/4613-7295.jpg/upnp:albumArtURIupnp:genreExperimental/upnp:genreupnp:albumFabricLive. 50/upnp:albumupnp:originalTrackNumber19/upnp:originalTrackNumberdc:date2010-01-01/dc:datehttp://192.168.1.111:8200/MediaItems/7295.flac

GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: src: unhandled message type 8192 (stream-status) GStreamer: source: unhandled message type 262144 (duration)

hzeller commented 11 years ago

(Sorry for the delay. Was travelling and had limited access to the computer). Thanks for the report. I'll have to look what happens with these threads, that is clearly not ok. I'll have some more coding time this weekend, I'll try to track this one down.

hzeller commented 11 years ago

I verified, that the thread-increase even happens with the latest gstreamer1.0 version. I'll try to boild it down to a simple binary to be able to debug what is going on gstreamer (gmrender does not explicitly create new threads).

(This could as well be the reason for the random stops of gmrender you observe, but I couldn't reproduce that yet on my development machine.)

gunbro commented 11 years ago

thank you for your investigation! maybe i can send you any logs to help?

hzeller commented 11 years ago

At least the thread increase I can reproduce, so no need for logs for that.

But I haven't reproduced when it stops working (crashing?). It could be due to many threads (essentially running out of resources), but maybe there is another reason. I will try to do that on my RPi later. If I can't reproduce, then I'll ask you to run it in gdb to gather some evidence.

gunbro commented 11 years ago

ok. see you later then =)

gunbro commented 11 years ago

so it looks like a bug in Gstreamer?

hzeller commented 11 years ago

Yes; I could reproduce this and made an example code https://github.com/hzeller/gstreamer-gapless-test

gstreamer0.10 (most common in current distributions) shows this behavior with the thread leak, but unfortunately, this version is not supported anymore, so didn't file a bug. I'll try see if I can find the reason and provide a patch.

So I tried it with the upcoming gstreamer1.0 version - this one is broken for gapless playing of URIs it seems, so I filed a bug https://bugzilla.gnome.org/show_bug.cgi?id=698306

gunbro commented 11 years ago

Yes please if you can find a problem in 0.10 version and fix it would be cool! Because it must take some time for Gstreamer team to fix that bug you filed for 1.0 version. Official repositories for RPi's Debian Weezy dont have even 1.0 version yet.

gunbro commented 11 years ago

found 2 more bug reports like yours:

https://bugzilla.gnome.org/show_bug.cgi?id=673305

https://bugzilla.gnome.org/show_bug.cgi?id=686153

hzeller commented 11 years ago

found 2 more bug reports like yours:

https://bugzilla.gnome.org/show_bug.cgi?id=673305

Interesting. This seems to see trouble in 0.10, which seems to work though for us (in that version, we only leak threads).

https://bugzilla.gnome.org/show_bug.cgi?id=686153

This could indeed be related to our https://bugzilla.gnome.org/show_bug.cgi?id=698306 - but here, they see problems even with file-URIs, which is not what we see. So maybe related, but this something different.

gunbro commented 11 years ago

Hi! Any news on gstreamer? I have a one question. When i restart gmrender when he stuck full of threads i need also restart bubbleupnp because it wont play, it tells "timeout action". What you can advise?

hzeller commented 11 years ago

On 5 May 2013 19:27, gunbro notifications@github.com wrote:

Hi! Any news on gstreamer?

Someone from the gstreamer team was at least confirming the gstreamer 1.0 bug; they're not working on the 0.10 because it reached EOL. However, I am playing around with gstreamer 1.0 now and it looks as well like it eats threads :/

I have a one question. When i restart gmrender when he stuck full of

threads i need also restart bubbleupnp because it wont play, it tells "timeout action". What you can advise?

Unfortunately: Restart BubbleUPnP. Luckily, it has an option to 'Exit' (many other Android programs don't have that). It would be good if BubbleUPnP does an automatic attempt re-connect on error... (maybe contact the author ?)

gunbro commented 11 years ago

Ok i will try to ask him, seems like he a nice guy, maybe he help with this. Maybe its a stupid question, but can you fool gstreamer somehow by transforming http file to local? =)

gunbro commented 11 years ago

" However, I am playing around with gstreamer 1.0 now and it looks as well like it eats threads :/" Damn! Maybe another bug report is needed for this?

hzeller commented 11 years ago

On 5 May 2013 19:54, gunbro notifications@github.com wrote:

Ok i will try to ask him, seems like he a nice guy, maybe he help with this. Maybe its a stupid question, but can you fool gstreamer somehow by transforming http file to local? =)

All that streaming logic is built into gstreamer, that I don't want to rebuild; also for gapless, this would mean a potentially infinite file. One would need to essentially second guess what gstreamer is doing with that file.

One could think of a fuse filesystem that does that transparently. However, I think it is easer to fix directly in gstreamer as it is clearly broken, so that should be fixed there.

hzeller commented 11 years ago

" However, I am playing around with gstreamer 1.0 now and it looks as well like it eats threads :/"

Damn! Maybe another bug report is needed for this?

Yes, working on a program to reproduce this.

gunbro commented 11 years ago

" However, I think it is easer to fix directly in gstreamer as it is clearly broken, so that should be fixed there. Yes, working on a program to reproduce this." Thank you. I hope they fix it soon.

hzeller commented 11 years ago

Filed https://bugzilla.gnome.org/show_bug.cgi?id=699794

hzeller commented 11 years ago

So good news: The gstreamer bug https://bugzilla.gnome.org/show_bug.cgi?id=699794 is fixed! That means: no more thread leakage. (Of course, right now, it requires to compile gstreamer from git to get the fix. And it will only be in > 1.0)

If it is possible to compile gstreamer from git, you can try that (the fix is in gst-plugins-base); otherwise we've to wait until packages show up to see if the 'audio stops after some amount of listening' is fixed with it as well.

gunbro commented 11 years ago

Yeah i saw, i was watching for this bug almost every day!) "Gapless playback using "about-to-finish" doesn't work with http URIs" must be fixed too for normal using? Shame on me i don't have skills to compile it from git. I found this repository on raspberrypi.org forum deb http://vontaene.de/raspbian-updates/ . main but there are only 1.0.6 for now. Also do i need to recompile gmrender-ressurect to use it with new Gstreamer and how to change this strings for gstreamer 1.0? $ gconftool-2 -t string --set /system/gstreamer/0.10/default/audiosink pulsesink $ gconftool-2 -t string --set /system/gstreamer/0.10/default/audiosrc pulsesrc

hzeller commented 11 years ago

I presume, the change will show up in 1.0.8 (at least this is the target milestone marked in the bug).

The 'about-to-finish' bug is more subtle and will probably not affect things in daily use (at home, i am using 1.0.6 now and it seems to work for regular use).

You will have to re-compile gmrender-resurrect to make use of 1.0 library (the ./configure script will check for different versions). Once compiled for 1.0, incremental changes in updates to gstreamer will be picked up by virtue of dynamic linking.

Regarding the configuration strings: yes, probably this is the case; personally, I like to set the sink directly via commandline flags, such as --gstout-audiosink=pulsesink

gunbro commented 11 years ago

So 'about-to-finish' bug must not affect gapless playing?? Also want to ask how to set default volume for gmrender? Now it set for 100% every time. For configuration strings i should just add in init.d script /usr/local/bin/gmediarender -c pi:audio -S -- -f "RPi" -u "11144e5e-926c-11e2-9a57-db5742b0f9ac" -d --gstout-audiosink=pulsesink ?

hzeller commented 11 years ago

about-to-finish might affect the gapless playing, yes. But if you don't use that feature, things should be fine (and even if, as this is a race condition that might, uhm, often work).

gmrender starts with the volume the system has initially, and I don't remember providing an option to pre-set it to something else.

The configuration flags look about right.

gunbro commented 11 years ago

Maybe any chance to add that patch they used for 1.0 version to 0.10?

hzeller commented 11 years ago

Maybe any chance to add that patch they used for 1.0 version to 0.10?

The patch was a one-liner. So if the 0.10 code in that area is very similar, then this should be fairly simple.

gunbro commented 11 years ago

Can you look in code of 0.10 and fix it when you have a time?

gunbro commented 11 years ago

"gmrender starts with the volume the system has initially, and I don't remember providing an option to pre-set it to something else." please, can you add such option if its possible? -v 70 for example =) because 100% was to much and i use alsa mixer and move all volume sliders down, but now i can't make volume louder with bubbleupnp, only by remote controller of my amp :-/ also found some related ''bug'' for Rygel https://bugzilla.gnome.org/show_bug.cgi?id=683277

gunbro commented 11 years ago

I just fix 0.10 by adding decoder->queue = queue; in the same file gsturidecodebin.c like in 1.0 and compile it to .deb and thread leaks stops now! :P You could try https://dl.dropboxusercontent.com/u/26402232/gstreamer0.10-plugins-base.zip

hzeller commented 11 years ago

Wonderful!

hzeller commented 11 years ago

FYI, I've now added an initial volume setting. See documentation at https://github.com/hzeller/gmrender-resurrect/blob/master/INSTALL.md#--gstout-initial-volume-db

gunbro commented 11 years ago

Wow thanks! Things gets better and better!) Do i need to reinstall for this option?

hzeller commented 11 years ago

On 12 May 2013 11:36, gunbro notifications@github.com wrote:

Wow thanks! Things gets better and better!) Do i need to reinstall for this option?

You need to get a fresh git pull and re-compile and re-make install gmrender-resurrect, yes. Then you can use the option.

gunbro commented 11 years ago

Thank you, now it is more convenient with this volume option. Now need to do gapless stress test for RPi for whole night)

hzeller commented 11 years ago

So, did it survive the night ?

gunbro commented 11 years ago

Actually no. But seems it was old tablet on honeycomb related problem. It stops after 4 or 5 albums, but i just push play in the morning on bubbleupnp and its continue playing again. I try again on ICS phone this night.

gunbro commented 11 years ago

How about your gstreamer-gapless-test ? Did you try it?

gunbro commented 11 years ago

Im also get rid of unnecessary pulseaudio. But alsa was resample by default to 16bit & 48khz and sound clicks and pops on usb dac, especially when i used foobar @ 24 bits.

So i add:
pcm.!default { type hw card 0 }

ctl.!default { type hw card 0 } to asound.conf and now any sound plays as it is:

cat /proc/asound/card0/pcm0p/sub0/hw_params access: RW_INTERLEAVED format: S16_LE subformat: STD channels: 2 rate: 44100 (44100/1) period_size: 441 buffer_size: 8820

cat /proc/asound/card0/pcm0p/sub0/hw_params access: RW_INTERLEAVED format: S24_3LE subformat: STD channels: 2 rate: 44100 (44100/1) period_size: 441 buffer_size: 8820 ^^ this is from foobar Also there was high load on processor, around 40% before i turn off resampling, now its around 10-15%

gunbro commented 11 years ago

I tried again on ICS phone this night and all was ok!

hzeller commented 11 years ago

Can you write up a bit more in default what you configured on the RPi to make things work smoothly in Alsa ? So what files to edit, what parameters to give to gmrender-resurrect. I'd like to have that as a reference to point people to.

How are things otherwise, does the player still work with gapless and no-threads collecting and stuff ? If so, we can probably close this particular issue (we're still waiting for the gstreamer folks to catch up on the 1.0 bugs, but that is probably orthogonal).

hzeller commented 11 years ago

(Also, I did a lot of little changes recently, can you test if things still work fine in your set-up with a fresh git checkout ?)

gunbro commented 11 years ago

"Can you write up a bit more in default what you configured on the RPi to make things work smoothly in Alsa ? So what files to edit, what parameters to give to gmrender-resurrect. I'd like to have that as a reference to point people to."

1> I install https://github.com/Hexxeh/rpi-update and then update to special test branch sudo BRANCH=fiq_split rpi-update that containing the USB FIQ driver, this is meant to fix problems like:

1) Keyboards dropping keys 2) Strange 'resetting' USB devices whilst enumerating 3) Anything which uses low speed for Full Speed devices and drops packets or does strange stuff! (thread on raspi forum -> http://www.raspberrypi.org/phpBB3/viewtopic.php?f=28&t=39175)

2> i connect small usb dac (http://goo.gl/lxGea) to powered usb-hub 3> change string options snd-usb-audio index=-2 in /etc/modprobe.d/alsa-base.conf to options snd-usb-audio index=0 to set usb-card as system default. 4> add this to /etc/asound.conf to prevent resampling to 16bit & 48 KHz:

pcm.!default { type hw card 0 }

ctl.!default { type hw card 0 }

5> set gstreamer to use alsa: $ gconftool-2 -t string --set /system/gstreamer/0.10/default/audiosink alsasink $ gconftool-2 -t string --set /system/gstreamer/0.10/default/audiosrc alsasrc 6> start gmrender: gmediarender -c pi:audio -S -- -f "RPi" -u "11144e5e-926c-11e2-9a57-db5742b0f9ac" --gstout-initial-volume-db=-20 -d

So i think thats all.

gunbro commented 11 years ago

"How are things otherwise, does the player still work with gapless and no-threads collecting and stuff ?" Yes, still works well!

"(Also, I did a lot of little changes recently, can you test if things still work fine in your set-up with a fresh git checkout ?)" Ok i will check it later!

gunbro commented 11 years ago

I try now fresh git and first problem appears that foobar cant play to gmrender again like some time ago, i tells:

[UPnP] Stream address: http://192.168.1.109:50057/stream.wav [UPnP] transport op: Play [UPnP] transport op "Play" fail: XML error [UPnP] transport op: Stop [UPnP] transport op "Stop" fail: XML error Unrecoverable playback error: UPnP device error: XML error

hzeller commented 11 years ago

ah, interesting. I changed the LastChange event to be proper XML with <?xml version="1.0"> header ... apparently foobar doesn't like this.

(can you give me an output of a logfile as described in https://github.com/hzeller/gmrender-resurrect/blob/master/INSTALL.md#misc-options? )

I'll change that and let you know.

On 22 May 2013 11:31, gunbro notifications@github.com wrote:

I try now fresh git and first problem appears that foobar cant play to gmrender again like some time ago, i tells:

[UPnP] Stream address: http://192.168.1.109:50057/stream.wav [UPnP] transport op: Play [UPnP] transport op "Play" fail: XML error [UPnP] transport op: Stop [UPnP] transport op "Stop" fail: XML error Unrecoverable playback error: UPnP device error: XML error

— Reply to this email directly or view it on GitHubhttps://github.com/hzeller/gmrender-resurrect/issues/12#issuecomment-18298127 .

gunbro commented 11 years ago

https://dl.dropboxusercontent.com/u/26402232/gmrender.log

hzeller commented 11 years ago

I have now changed the XML output. Can you try again ?

On 22 May 2013 11:39, gunbro notifications@github.com wrote:

https://dl.dropboxusercontent.com/u/26402232/gmrender.log

— Reply to this email directly or view it on GitHubhttps://github.com/hzeller/gmrender-resurrect/issues/12#issuecomment-18298666 .

gunbro commented 11 years ago

now its just: Opening track for playback: "D:\Music\tempo\Abakus - Silent Geometry\07. Abakus - We Need Those Papers.flac" Unrecoverable playback error: UPnP device error: XML error https://dl.dropboxusercontent.com/u/26402232/gmrender2.log

hzeller commented 11 years ago

On 22 May 2013 12:00, gunbro notifications@github.com wrote:

now its just: Opening track for playback: "D:\Music\tempo\Abakus - Silent Geometry\07. Abakus - We Need Those Papers.flac"

Unrecoverable playback error: UPnP device error: XML error

Ok, did another change that might be related. Can you try again ? (I have another idea, but let's try this first).

Do you know if there is a way to get more log information out of foobar ? In particular I'd like to know which XML it thinks is broken.

gunbro commented 11 years ago

Now i works with 24bits: https://dl.dropboxusercontent.com/u/26402232/gmrender24bits.log [UPnP] Stream address: http://192.168.1.109:51896/stream.wav [UPnP] transport op: Play [UPnP] transport op OK [UPnP] Returned time: 0:00:00.000 [UPnP] HTTP request: GET /stream.wav [UPnP] Source: 192.168.1.111:40868 [UPnP] Connection: close [UPnP] Host: 192.168.1.109:51896 [UPnP] icy-metadata: 1 [UPnP] transferMode.dlna.org: Streaming [UPnP] User-Agent: GStreamer souphttpsrc libsoup/2.38.1 [UPnP] Serving WAV [UPnP] Connection: close [UPnP] Content-Type: audio/wav [UPnP] TransferMode.dlna.org: Streaming [UPnP] User-Agent: Windows/7.0 UPnP/1.1 foobar2000/1.x [UPnP] Transport state: PLAYING [UPnP] Returned time: 0:00:04.200 [UPnP] Transport state: PLAYING [UPnP] transport op: Stop [UPnP] transport op OK

But also it starts to work with 16bit LPCM but for first seconds, and then it stops: https://dl.dropboxusercontent.com/u/26402232/gmrender16bitsLPCM.log

[UPnP] Stream address: http://192.168.1.109:52679/stream.l16 [UPnP] transport op: Play [UPnP] Returned time: 0:00:00.000 [UPnP] Transport state: PLAYING [UPnP] transport op OK [UPnP] HTTP request: GET /stream.l16 [UPnP] Source: 192.168.1.111:47507 [UPnP] Connection: close [UPnP] Host: 192.168.1.109:52679 [UPnP] icy-metadata: 1 [UPnP] transferMode.dlna.org: Streaming [UPnP] User-Agent: GStreamer souphttpsrc libsoup/2.38.1 [UPnP] Serving LPCM [UPnP] Connection: close [UPnP] Content-Type: audio/L16;rate=44100;channels=2 [UPnP] TransferMode.dlna.org: Streaming [UPnP] User-Agent: Windows/7.0 UPnP/1.1 foobar2000/1.x Audioscrobbler: Handshake successful. [UPnP] Returned time: 0:00:00.000 [UPnP] Transport state: PLAYING [UPnP] Returned time: 0:00:00.000 [UPnP] Transport state: PLAYING [UPnP] Returned time: 0:00:00.000 [UPnP] Transport state: PLAYING [UPnP] Returned time: 0:00:00.000 [UPnP] Transport state: PLAYING [UPnP] Returned time: 0:00:00.000 [UPnP] Transport state: PLAYING [UPnP] transport op: Stop [UPnP] transport op OK

gunbro commented 11 years ago

"Do you know if there is a way to get more log information out of foobar ?" Its only i can get i think :\