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

[gunbro]

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?

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]

(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]

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]

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

[hzeller]

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]

ok. see you later then =)

[gunbro]

so it looks like a bug in Gstreamer?

[hzeller]

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]

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]

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]

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]

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]

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]

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]

" 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]

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]

" 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]

" 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]

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

[hzeller]

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]

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]

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]

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]

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]

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

[hzeller]

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]

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

[gunbro]

"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]

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]

Wonderful!

[gunbro]

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

[gunbro]

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]

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

[hzeller]

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]

(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]

"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]

"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]

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]

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//issues/12#issuecomment-18298127
.

[gunbro]

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

[hzeller]

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//issues/12#issuecomment-18298666
.

[gunbro]

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]

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]

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]

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

[hzeller]

Interesting, it doesn't seem to receive the time. It always says "Returned
time: 0:00:00"

I'll add a bit more debug info to track this down. Hope you have time to
try another experiment soon.

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

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

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

[hzeller]

Ok, I have enabled more detailed action logging. Also I have found a place
where some XML is not properly quoted even though it used to be that way.

Can you try again ?

(sorry for the inconvenience).

[gunbro]

now its: https://dl.dropboxusercontent.com/u/26402232/gmrenderLPCM.log

[UPnP] Stream address: http://192.168.1.101:58495/stream.l16
[UPnP] transport op: Play
[UPnP] Returned time: 0:00:00.000
[UPnP] transport op OK
[UPnP] Transport state: PLAYING
[UPnP] HTTP request: GET /stream.l16
[UPnP] Source: 192.168.1.111:47765
[UPnP] Connection: close
[UPnP] Host: 192.168.1.101:58495
[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] time query fail: network timeout
[UPnP] Returned time: 0:00:00.000
[UPnP] Transport state: PLAYING
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:00.000
[UPnP] Transport state: PLAYING
[UPnP] transport op: Stop
[UPnP] transport op OK

[gunbro]

for 24bit WAV: https://dl.dropboxusercontent.com/u/26402232/gmrenderWAV.log

[UPnP] Stream address: http://192.168.1.101:59301/stream.wav
[UPnP] transport op: Play
[UPnP] transport op OK
[UPnP] Returned time: 0:00:00.000
[UPnP] Transport state: PLAYING
[UPnP] HTTP request: GET /stream.wav
[UPnP] Source: 192.168.1.111:38696
[UPnP] Connection: close
[UPnP] Host: 192.168.1.101:59301
[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
Audioscrobbler: Handshake successful.
[UPnP] Returned time: 0:00:03.000
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:08.100
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:13.200
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:18.400
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:23.400
[UPnP] Transport state: PLAYING
[UPnP] Transport state: PLAYING
[UPnP] time query fail: could not connect
[UPnP] Returned time: 0:00:42.100
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:47.100
[UPnP] Transport state: PLAYING
[UPnP] transport op: Stop
[UPnP] transport op OK

[hzeller]

So from the logs it looks like it is working now - did you actually hear
something ?

On 22 May 2013 13:18, gunbro notifications@github.com wrote:

for 24bit WAV:
https://dl.dropboxusercontent.com/u/26402232/gmrenderWAV.log

[UPnP] Stream address: http://192.168.1.101:59301/stream.wav
[UPnP] transport op: Play
[UPnP] transport op OK

[UPnP] Returned time: 0:00:00.000
[UPnP] Transport state: PLAYING
[UPnP] HTTP request: GET /stream.wav
[UPnP] Source: 192.168.1.111:38696
[UPnP] Connection: close
[UPnP] Host: 192.168.1.101:59301

[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
Audioscrobbler: Handshake successful.
[UPnP] Returned time: 0:00:03.000
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:08.100
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:13.200
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:18.400
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:23.400

[UPnP] Transport state: PLAYING
[UPnP] Transport state: PLAYING
[UPnP] time query fail: could not connect
[UPnP] Returned time: 0:00:42.100
[UPnP] Transport state: PLAYING
[UPnP] Returned time: 0:00:47.100

[UPnP] Transport state: PLAYING
[UPnP] transport op: Stop
[UPnP] transport op OK

—

Reply to this email directly or view it on GitHubhttps://github.com//issues/12#issuecomment-18305031
.

[gunbro]

Only first few seconds, than sound stops.

[gunbro]

Are you look exactly in this log? > https://dl.dropboxusercontent.com/u/26402232/gmrenderLPCM.log
not wav?

[hzeller]

Are you look exactly in this log:
https://dl.dropboxusercontent.com/u/26402232/gmrenderLPCM.log

I was looking at the wav-log and it seems that foobar actively sent a stop
signal at position 00:17:09.842730

In the LPCM log, there is an "Internal data flow error."; something
internal to gstreamer ( postion 00:11:25.562057 )
Also, apparently there is never the full time of the track that it can
determine. This looks like some trouble with gstreamer and this particular
stream. Did this work before ? (because I didn't change anything there...).
mmh.

[gunbro]

"Did this work before ?"
No, but now sound start to appear for few seconds. Previously there was no sound at all.
We are discuss it here #14 .

"I was looking at the wav-log and it seems that foobar actively sent a stop signal at position 00:17:09.842730"
Its because i just push stop button)

So again something with gstreamer?

[gunbro]

"Also, apparently there is never the full time of the track that it can determine."
This can be foobar related problem?

[hzeller]

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

"Also, apparently there is never the full time of the track that it can
determine."
This can be foobar related problem?

The time is extracted from the stream by gstreamer. Maybe there is no such
data in the stream, so if it is proxied by foobar, then this could be a
foobar problem.
But also, even if it starts playing, it can't figure out the current play
status ... so something within gstreamer is confused about the internal
data format. (this might be worth trying out with gstreamer 1.0)

But to confirm: at least now you don't get any XML errors anymore and
things work at least as before.

[gunbro]

"But to confirm: at least now you don't get any XML errors anymore and things work at least as before."
Can you describe in simple words what you changed in last days in gmrender?

[hzeller]

What I changed:

• I improved the way variable changes are transmitted back to the controller. Whenever there is a variable changed, an XML document with all variable changes is sent back to the controller. That was done somewhat manual before and I improved the code to make this more readable and maintainable.
  • The initial state is transmitted fully. When a controller connects, the current state of the system (are playing currently, what is the piece etc.). That worked before if the controller was asking for this information, not it gets this pushed (can imporve compatilibiy with some players). Here was the XML bug: that was an embedded XML document that was not xml-escaped.
• While playing, the current position is pushed to the controller every second as well. Previously, only if the controller asked for the current time, this wold work, now it gets the time even without active polling.
• All the changes above mean, that the controller now can rely on eventing fully (in BubbleUPnP, this would mean 'use evening' can be checked in the settings).
• Logging: more coherent, can be redirected to a file, and has time stamps associated with it. And is colorful when --logfile=/dev/stdout

BTW, I now reverted one change that I did in the middle of figuring out what was going on with the XML ... that I thought should've been unrelated. So I've submitted that now (see change below) and it should still work.
69a0cd3

[hzeller]

Slightly off-topic (but since I don't have your email address, I'll update this bug)

I have started a wiki page to track the compatibility with control points.
https://github.com/hzeller/gmrender-resurrect/wiki/Comptibility

Since I know that you're using Foobar (and maybe other controllers), can you update the table with controllers you tested ? Thanks!

[gunbro]

I cant update to latest version yet, but i write some info on wiki.