Bug 201233 - Last.fm stream stops after playing a few tracks
Summary: Last.fm stream stops after playing a few tracks
Status: RESOLVED FIXED
Alias: None
Product: Phonon
Classification: Frameworks and Libraries
Component: Xine backend (show other bugs)
Version: 4.4.2 (KDE 4.5)
Platform: unspecified Linux
: NOR normal
Target Milestone: ---
Assignee: Martin Sandsmark
URL:
Keywords:
: 176997 (view as bug list)
Depends on:
Blocks:
 
Reported: 2009-07-23 15:38 UTC by chris
Modified: 2012-12-02 11:52 UTC (History)
12 users (show)

See Also:
Latest Commit:
Version Fixed In: 4.4.4
Sentry Crash Report:


Attachments
Amarok debug output (308.13 KB, text/plain)
2009-10-25 19:03 UTC, Dan
Details
Another debug (327.63 KB, text/plain)
2009-10-31 22:06 UTC, Dan
Details
Correct debug (357.83 KB, text/plain)
2009-10-31 22:08 UTC, Dan
Details
Related backtraces. (10.27 KB, application/octet-stream)
2011-04-09 22:27 UTC, Michal Srb
Details
Recent backtrack (344.94 KB, text/plain)
2012-11-09 10:24 UTC, Chris Wales
Details

Note You need to log in before you can comment on or make changes to this bug.
Description chris 2009-07-23 15:38:55 UTC
Version:           2.1.1 (using 4.2.4 (KDE 4.2.4) "release 2", KDE:42 / openSUSE_11.1)
Compiler:          gcc
OS:                Linux (i686) release 2.6.27.23-0.1-pae

Hello,
I'm using amarok 2.1.1 with kde 4.2.4 "release 2"...totally updated today, so latest (todays) version
First of all, I am a subscriber to lastfm and I have paid.
I'm using the lastfm script embedded in the amarok internet-section.
After adding a lastfm playlist to the amarok playlist, amarok will start to play the first song to the end, then he shows the next song in line but will stop playing ,with progression bar at -0.00

I have to push the 'forward song button', but mark..the little Lastfm-forward button,to play a new song...but amarok will skip the already listed next (second) song and jumps to the third.
then amarok will play this one song, after which amarok will stop again, and so on...It reproduces every time.
This will occure in any playlist.
Shuffle and Repeat-options are off.
Because amarok did not crash, I don't have this backtrace-info.

Normal playing of music (on file) through Playlist works fine.

Hope this is enough information
and thanks for looking into it
chris
Comment 1 Myriam Schweingruber 2009-07-23 18:26:09 UTC
Works here, with Amarok 2.2-git. Consider this solved.
Comment 2 Gael Beaudoin 2009-10-22 23:42:15 UTC
It still happens all the time to me, using 2.2.0 from OpenSUSE packages, reopening. Lastfm plays one, sometime two or three, and then stops. I have to hit play again. I no longer use lastfm with amarok for now.
Comment 3 Mark Kretschmann 2009-10-23 08:33:07 UTC
I have to say this sometimes happens here too, with 2.2-GIT. What's strange about this is, when you want to exit Amarok after this, it gets stuck, so you have to kill it.

I'm suspecting that this might actually be a Phonon bug, because Amarok refuses to play anything at all after that.
Comment 4 Mark Kretschmann 2009-10-23 08:33:57 UTC
Leo, can you reproduce this issue too? Or got any idea what might be causing it?
Comment 5 Mark Kretschmann 2009-10-25 18:35:31 UTC
*** Bug 176997 has been marked as a duplicate of this bug. ***
Comment 6 Dan 2009-10-25 18:41:14 UTC
Ok, this is the "real" one. So, I'll wait for instructions in order to help you to debug this. This is the worst bug ever, the most *annoying* bug I've ever experienced in my life. But I hope we can fix it definitely.
Comment 7 Leo Franchi 2009-10-25 18:47:18 UTC
really weird. what radio stations are you listening to?

if you could capture the full debug output (start amarok, play a lastfm stream until it automatically stops):

amarok -d > log.txt 2>&1 

and attach it to this bug, it would help
Comment 8 Dan 2009-10-25 19:02:56 UTC
Ok, I'll do that. Before I'd like to just comment that Amarok gets completely "lost" when the last.fm track finishes. Sometimes the progress slider stays stuck in the middle and the remaing time shows a non-sense value like "-0:0-45".

The debug output file log.txt is attached. Thank you.
Comment 9 Dan 2009-10-25 19:03:30 UTC
Created attachment 37828 [details]
Amarok debug output
Comment 10 Dan 2009-10-25 19:06:53 UTC
What yo want is here but I don't see any useful information:

amarok(28016) Phonon::Xine::XineStream::event: ################################ Event:  MediaFinished
amarok(28016) Phonon::Xine::XineStream::event: MediaFinishedEvent m_useGaplessPlayback =  true
amarok: BEGIN: void EngineController::slotAboutToFinish() 
amarok:   [EngineController] Track finished completely, updating statistics 
amarok:   BEGIN: void Meta::StatisticsProvider::played(double) 
amarok:      called with playedFraction =  1 
amarok:   END__: void Meta::StatisticsProvider::played(double) - Took 0.0031s 
amarok:   [Playlist::Model] Metadata updated for track "Weekend Overdrive" 
amarok(28016) EngineController::slotAboutToFinish: "  " Line:  836
amarok:   BEGIN: virtual void MultiPlayableCapabilityImpl::fetchNext() 
amarok(28016) KNetworkAccessManager::createRequest: PostOperation:  QUrl( "http://ws.audioscrobbler.com/2.0/" )
amarok:     BEGIN: void LastFm::Track::Private::setTrackInfo(const lastfm::Track&) 
amarok:       [Playlist::Model] Metadata updated for track "Ayreon's Fate" 
amarok:       BEGIN: void EngineController::slotPlayableUrlFetched(const KUrl&) 
amarok:         [EngineController] Fetched url:  KUrl("http://play.last.fm/user/52e287c6f5ca3c037e44a17e4021d10f.mp3") 
amarok(28016) EngineController::slotPlayableUrlFetched: "        " Line:  1054
amarok:         [EngineController] The next url we're playing is:  KUrl("http://play.last.fm/user/52e287c6f5ca3c037e44a17e4021d10f.mp3") 
amarok:       END__: void EngineController::slotPlayableUrlFetched(const KUrl&) - Took 0.00034s 
amarok:       BEGIN: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) 
amarok:       END__: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) - Took 0.0063s 
amarok:       [Playlist::Model] Album metadata changed 
amarok:       BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok:       END__: void OSDWidget::show(const QString&, QImage) - Took 0.0069s 
amarok(28016) KNetworkAccessManager::createRequest: PostOperation:  QUrl( "http://ws.audioscrobbler.com/2.0/" )
amarok:     END__: void LastFm::Track::Private::setTrackInfo(const lastfm::Track&) - Took 0.046s 
amarok:   END__: virtual void MultiPlayableCapabilityImpl::fetchNext() - Took 0.047s 
amarok:   [EngineController] The queue has:  0  tracks in it 
amarok: END__: void EngineController::slotAboutToFinish() - Took 0.053s 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) - Took 0.0011s 
amarok(28016) KNetworkReply::setMimeType: "text/xml"
amarok: [Playlist::Model] Metadata updated for track "Ayreon's Fate" 
amarok: BEGIN: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) 
amarok: END__: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) - Took 0.00036s 
amarok: [Playlist::Model] Album metadata changed 
amarok: BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok: END__: void OSDWidget::show(const QString&, QImage) - Took 0.0028s 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) - Took 0.0024s 
amarok(28016) KNetworkReply::setMimeType: "text/xml"
amarok: [Playlist::Model] Metadata updated for track "Ayreon's Fate" 
amarok: BEGIN: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) 
amarok: END__: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) - Took 0.025s 
amarok: [Playlist::Model] Album metadata changed 
amarok: BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok: END__: void OSDWidget::show(const QString&, QImage) - Took 0.0037s 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) - Took 0.0038s
Comment 11 chris 2009-10-26 07:00:48 UTC
Because I originally reported the bug, I like to say that with the first update I made shortly after reporting..the bug disappeared...and it never showed up again...so I considered this solved.
And I constantly updated..every possible update-version passed this computer.
But surely this will not help you at all resolving the bug that I experienced as solved.
good luck
chris
linux 2.6.27.29-0.1-pae
openSUSE 11.1
Kde 4.3.2 release 5
amarok 2.2.0 release2--compile 24-10
Comment 12 Dan 2009-10-26 15:56:24 UTC
The interesting thing about this bug is that we really don't know if it's a:

a) Amarok bug

b) Phonon bug

c) Xine bug

This makes things more complicated.
Comment 13 Mark Kretschmann 2009-10-26 17:38:20 UTC
d) Liblastfm bug
Comment 14 Dan 2009-10-26 18:56:39 UTC
(In reply to comment #13)
> d) Liblastfm bug

I tend to believe it is a Phonon bug because I remember when I used an old phonon version and everything worked fine. Then I upgraded to a new phonon version and problems started to appear. Of course it doesn't mean it's phonon's fault, but... Phonon always seems to me very unreliable.

Anyway, I'm trying to install the mplayer phonon backend, since I can't use the gstreamer backend (no sound at all). If the problem is fixed using mplayer backend, I'll just use that instead of xine.
Comment 15 Mark Kretschmann 2009-10-27 13:54:20 UTC
Might possibly be related to BUG 192114
Comment 16 Mark Kretschmann 2009-10-30 11:51:19 UTC
commit 3cd1f531e10c01accd5527865dd9bb27f9467129
Author: Mark Kretschmann <kretschmann@kde.org>
Date:   Fri Oct 30 11:49:27 2009 +0100

    Fix possible logic bug in engine error handling.

    This might help with the "Last.fm stops playing" issue. Please test.

    BUG: 201233
Comment 17 Mark Kretschmann 2009-10-30 13:40:21 UTC
commit 72ad49cfb77d342eabebc3b5063e719b4ba2529d
Author: Mark Kretschmann <kretschmann@kde.org>
Date:   Fri Oct 30 13:39:14 2009 +0100

    Another attempt at fixing the "Last.fm stuck" issue.

    BUG: 201233
Comment 18 Dan 2009-10-30 19:17:07 UTC
(In reply to comment #17)
> commit 72ad49cfb77d342eabebc3b5063e719b4ba2529d
> Author: Mark Kretschmann <kretschmann@kde.org>
> Date:   Fri Oct 30 13:39:14 2009 +0100
> 
>     Another attempt at fixing the "Last.fm stuck" issue.
> 
>     BUG: 201233

Hi Mark. I updated Amarok to the latest GIT, recompiled and at the end of the track, Amarok still gets stuck. So I assume the bug wasn't fixed yet.
Comment 19 Mark Kretschmann 2009-10-31 08:56:09 UTC
After my second patch, I let a Last.fm stream play for approximately 3 hours. It didn't exhibit any problems.

But then this might have been coincidence. Such Heisenbugs are incredibly hard to debug...

What I need from you is some new debug output (from while the radio was playing. Do this: "amarok --debug --nofork &> amarok_debug.txt"
Comment 20 Dan 2009-10-31 22:06:32 UTC
Created attachment 37998 [details]
Another debug

I uploaded this debug just after last.fm got stuck.
Comment 21 Dan 2009-10-31 22:07:27 UTC
Comment on attachment 37998 [details]
Another debug

Please ignore, wrong attachment.
Comment 22 Dan 2009-10-31 22:08:09 UTC
Created attachment 37999 [details]
Correct debug
Comment 23 Dan 2009-10-31 22:10:38 UTC
I attached the full debug log, but the relevant part is here:

amarok(4167) Phonon::Xine::XineStream::event: ################################ Event:  MediaFinished
amarok(4167) Phonon::Xine::XineStream::event: MediaFinishedEvent m_useGaplessPlayback =  true
amarok: BEGIN: void EngineController::slotAboutToFinish() 
amarok:   [EngineController] Track finished completely, updating statistics 
amarok:   BEGIN: void Meta::StatisticsProvider::played(double) 
amarok:      called with playedFraction =  1 
amarok:   END__: void Meta::StatisticsProvider::played(double) - Took 0.0031s 
amarok:   [Playlist::Model] Metadata updated for track "Turn Away" 
amarok(4167) EngineController::slotAboutToFinish: "  " Line:  836
amarok:   BEGIN: virtual void MultiPlayableCapabilityImpl::fetchNext() 
amarok:     BEGIN: void LastFm::Track::Private::setTrackInfo(const lastfm::Track&) 
amarok:       BEGIN: void EngineController::slotPlayableUrlFetched(const KUrl&) 
amarok:         [EngineController] Fetched url:  KUrl("http://play.last.fm/user/3ffc47e187c17423bde73742f70915cf.mp3") 
amarok(4167) EngineController::slotPlayableUrlFetched: "        " Line:  1054
amarok:         [EngineController] The next url we're playing is:  KUrl("http://play.last.fm/user/3ffc47e187c17423bde73742f70915cf.mp3") 
amarok:       END__: void EngineController::slotPlayableUrlFetched(const KUrl&) - Took 0.00032s 
amarok:       [Playlist::Model] Metadata updated for track "Morning Star"
Comment 24 Dan 2009-10-31 22:12:11 UTC
And this of course:

amarok:       BEGIN: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) 
amarok:       END__: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) - Took 0.0047s 
amarok:       BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok:       END__: void OSDWidget::show(const QString&, QImage) - Took 0.0069s 
amarok:       [Playlist::Model] Album metadata changed 
amarok(4167) KNetworkAccessManager::createRequest: PostOperation:  QUrl( "http://ws.audioscrobbler.com/2.0/" )
amarok:     END__: void LastFm::Track::Private::setTrackInfo(const lastfm::Track&) - Took 0.098s 
amarok:   END__: virtual void MultiPlayableCapabilityImpl::fetchNext() - Took 0.099s 
amarok:   [EngineController] The queue has:  0  tracks in it 
amarok: END__: void EngineController::slotAboutToFinish() - Took 0.13s 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) - Took 0.0031s 
amarok(4167) KNetworkReply::setMimeType: "text/xml"
amarok: [Playlist::Model] Metadata updated for track "Morning Star" 
amarok: BEGIN: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) 
amarok: END__: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) - Took 0.00033s 
amarok: BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok: END__: void OSDWidget::show(const QString&, QImage) - Took 0.003s 
amarok: [Playlist::Model] Album metadata changed 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) - Took 0.0025s 
amarok: [Playlist::Model] Metadata updated for track "Morning Star" 
amarok: BEGIN: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) 
amarok: END__: virtual void CurrentEngine::metadataChanged(Meta::AlbumPtr) - Took 0.0038s 
amarok: BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok: END__: void OSDWidget::show(const QString&, QImage) - Took 0.0024s 
amarok: [Playlist::Model] Album metadata changed
Comment 25 Dan 2009-10-31 22:13:28 UTC
In other words, it just update the metadata and gets stuck without playing anything... Isn't there a way to make this debug much more verbose?
Comment 26 Mark Kretschmann 2009-11-01 11:41:31 UTC
Daniel, the interesting part is that there appears to be no error on playback at all in your log. Normally when these problems happen, I get output like this:

"Error, can not play this track. Failure count: [xy]"


I think there might be some else very wrong on your system. Phonon? I can't say. Are you using a HTTP proxy or some such?
Comment 27 Dan 2009-11-01 16:02:27 UTC
(In reply to comment #26)
> I think there might be some else very wrong on your system. Phonon? I can't
> say. Are you using a HTTP proxy or some such?

I understand Mark. I don't use any proxy. The phonon I use is from kdesupport, latest svn. I'd like to try with another phonon backend, just to test, but the gstreamer backend doesn't work at all (no sound) and the mplayer backend just compiles against QT phonon and not against KDE4 phonon... So, I'm stuck with xine backend... :(
Comment 28 Myriam Schweingruber 2009-11-16 16:03:57 UTC
Setting correct version.
Comment 29 Dan 2009-11-22 16:03:36 UTC
Well, let's vote on this bug. This should be considered a ultra-high-super-top priority!

How can a bug like this persist for such a long time without any developer being able to debug it? And the most amazing is reading about some people who are not affected at all by this... But it's a pitty for those who are always affected like me :(

Again: using latest kde svn, Amarok svn, latest xine, latest phonon svn etc... and Amarok simply can't change lat.fm tracks without stopping... 

If nobody is able to fix it, then probably we will have to write all the last.fm streaming stuff from scratch...

I know that it's impossible to use Amarok without Phonon, but if we could at least simulate the streaming without phonon, just to test, I'm almost sure it would behave another way... there're too many third-party in the process, like Phonon, Xine etc... I know it was designed this way, but if a bug is so difficult to debug, then I don't see the reason for such complexity.

Couldn't KDE apps just use ALSA directly like all other apps do? It would much more simpler. Or at least if we had this option...

Sorry about my message sounding "rude" but it's very annoying having to use the official last.fm client when we can just use Amarok which is much better.

Ps: I get gstreamer backend working and the problem remain, so it probably isn't related to backend... So we're left with Phonon or Amarok...

Ps2: the most strange thing is when Amarok gets to the end of last.fm track, it operates very slowly, like as the speed of the computer is dragging it down. It would be good if we could activate an extra verbosity mode when the track changes... a much more verbose mode than the current one Amarok have.
Comment 30 Nikolaj Hald Nielsen 2009-11-30 22:10:14 UTC
I have not experienced this in 2.2.1 and beyond, and I use last.fm quite extensively.

Which also answers your question about how it can be allowed to persist for so long. None of us devs can reproduce it, which unfortunately makes it very hard to solve.
Comment 31 Dan 2009-12-01 04:24:00 UTC
(In reply to comment #30)
> I have not experienced this in 2.2.1 and beyond, and I use last.fm quite
> extensively.
> 
> Which also answers your question about how it can be allowed to persist for so
> long. None of us devs can reproduce it, which unfortunately makes it very hard
> to solve.

Ok, so please answer me which components Amarok uses for last.fm streaming. For example, besides Amarok, I have phonon, xine and what else? If the bug is not in Amarok, should I look only in Xine or Phonon? Or other components?
Comment 32 Mark Kretschmann 2009-12-01 09:26:29 UTC
"Vote on this bug"? Daniel, are you out of your mind?

1) You are not the most important person in this universe.
2) A bug that you have doesn't automatically make it the most important bug, just because it's you (see 1).
3) Your arrogant attitude is starting to rub us the wrong way. Stop it.
4) Make sure to read this list carefully again.
Comment 33 Dan 2009-12-01 18:10:27 UTC
(In reply to comment #32)
> "Vote on this bug"? Daniel, are you out of your mind?
> 
> 1) You are not the most important person in this universe.
> 2) A bug that you have doesn't automatically make it the most important bug,
> just because it's you (see 1).
> 3) Your arrogant attitude is starting to rub us the wrong way. Stop it.
> 4) Make sure to read this list carefully again.

Mark, how can you tell I am the only person in the world who is affected by this bug? Just because there are no more comments here?

Do you really think that just because the developers are not hit by this bug it simply does not exist?

If I have to wait until the developer is hit by a bug, then maybe I would wait forever.

BUT OK. If you are not interested in this, I completely understand and I WILL NOT bother you anymore with this. I was here just to solve a very annoying bug, but if the developers are not hit by it and so you assume it does not exist, so be this way. Let's forget this. You can mark it as invalid and I will not bother you anymore with this.

I still think Amarok is a great app and could be even greater, but if I can't fix this bug, I can't use Amarok for my purpose. So sorry about wasting your time. I thought here it was a place to report bugs and try to convince developers to try to debug bugs we have, no matter if the developer can reproduce or not... anyway, nevermind. Keep developing Amarok and I will for now use the last.fm client since I cannot use Amarok for last.fm and nobody can give any clue about what is happening.

Ps: and no, I don't think I'm the only one facing this bug. It probably is deep inside Amarok/xine/phonon/whatever. If I'm out of luck to be hit by this, the only thing I can do is report and try to convince developers to debug it even if you can't reproduce it. I offered all my time and testing. I can compile anything here, apply any patches etc. With a more verbose patch it would be very easy to debug... but I really need such a patch.

BUT OK, I will not bother any developer with this. Let's put an end on it. Time will tell if I'm really wrong...

Ps: and you can mark it as invalid or resolved, anyway you want.
Comment 34 Will Stephenson 2010-09-07 13:48:43 UTC
I'm trying to fix this for Amarok 2.1.1 + gstreamer since we shipped this with SLE11SP1.  

I notice that after playing the first track, the progress bar moves to (2nd track's length - first track's length) instead of 0 to begin the second track.  Does that mean anything to an Amarok hacker?
Comment 35 Myriam Schweingruber 2010-09-07 16:11:32 UTC
Will, I just had a conversation with Christian Müehlhauser, who worked for last.fm, and Leo Franchi:

[15:27] <muesli> Mamarok: i don't think it's really last.fm related to be honest
[15:41] <Mamarok> phonon backend then? It only happens with last.fm streams, not with other streams
[15:47] <muesli> here's the deal: every single last.fm song amarok plays is a separate stream
[15:47] <muesli> so if it skips a song
[15:47] <muesli> it just doesn't load the next track correctly
[15:47] <muesli> the stream as such doesn't abort tho
[15:47] <muesli> it's over once a track finishes
[15:47] <muesli> and you need to start the connection to the next song
[15:48] <muesli> a few scenarios i could imagine:
[15:48] <muesli> phonon detects that the first song (read: stream) is over soonish and tries to connect to the second track way too early
[15:48] <muesli> last.fm would drop this connection then iirc
[15:49] <muesli> you mix up the order of tracks somehow and don't connect in the right order
[15:49] <muesli> actually, that's the only two cases i could think of right now
and
[15:51] <lfranchi> the second case is veryvery unlikely,i can't see how it could get them out of order
[15:51] <lfranchi> the first case seems possible
[15:51] <muesli> lfranchi: agreed

So I reassign this to phonon, let's hope Martin finds time to give a hand with this.
Comment 36 Michal Srb 2011-04-09 22:27:52 UTC
Created attachment 58748 [details]
Related backtraces.

I was able to reproduce this in SLES 11 SP1 (amarok 2.1.1, phonon 4.3.1) and not in openSUSE 11.4 (amarok 2.4.0, phonon 4.4.4), so I tried to find a difference:

Observations from debugging in Phonon::Gstreamer::MediaObject class on SLES11
SP1:
1) MediaObject::handleEndOfStream is called as a result of message from
gstreamer backend.
2) MediaObject::finished signal is emitted by MediaObject::handleEndOfStream.
3) EngineController::slotQueueEnded slot in Amarok is synchronously called as
it is connected to the MediaObject::finished.
4) EngineController let phonon play another track, resulting in:
5) MediaObject::setState(PlayingState) is called. Because it is streamed
medium, current state is not changed yet, but m_pendingState is set to
PlayingState. Buffering starts in background.

6) Back in the MediaObject::handleEndOfStream,
MediaObject::setState(StoppedState) is called!!! And the m_pendingState is set
to StoppedState.

7) Later MediaObject::loadingComplete happens and state is changed to
m_pendingState which is StoppedState. Fail.

The only difference I observed in openSUSE 11.4 is that the signal-slot call
MediaObject::finished-EngineController::slotQueueEnded is done asynchronously.
Then the order of execution is 1,2,6,3,4,5,7 and all works fine.

The asynchronous call can be caused by Qt::QueuedConnection being set or
transmitter and receiver being in different threads. I didn't found any related
use of Qt::QueuedConnection, so I guess the threading model was changed in
Amarok or Phonon which accidentally fixed this issue...
Comment 37 Myriam Schweingruber 2011-04-10 15:10:17 UTC
Thank you for the feedback, closing then.
Comment 38 Will Stephenson 2011-04-12 13:37:59 UTC
@Myriam I would appreciate an actual review from someone who knows the code before closing this down.  Reopening so that Harald or Martin may comment.
Comment 39 Will Stephenson 2011-04-12 14:17:50 UTC
[13:52] <apachelogger> the very same issue that made amarok crash when phonon gst changed to error state it apparently is
[13:54] <apachelogger> wstephenson: https://projects.kde.org/projects/kdesupport/phonon/phonon/repository/revisions/febb6135f5137bdaafbf9ce7502a5a3a8c264d83/diff/phonon/mediaobject.cpp
[13:55] <wstephenson> apachelogger: ok, so the queuedconnection is a valid workaround for amarok not having any clearly defined object lifecycle?
[13:57] <apachelogger> yes
[13:57] <apachelogger> generally speaking it is valid behaviour though
[13:58] <apachelogger> as a backend object *must* be in a solid state whenever the API consumer *could* do something (such as on signal emission)
[13:59] <apachelogger> since backend objects *can* emit signals at any point they want, libphonon *must* queue the signal in order to ensure that the backend objects are in a predictable state once the API consumer does things to libphonon again

Local fix for amarok 2.1 (thanks to Michal):

diff -ur amarok-2.1.1.orig/src/EngineController.cpp amarok-2.1.1/src/EngineController.cpp
--- amarok-2.1.1.orig/src/EngineController.cpp	2011-04-12 12:22:15.570639000 +0200
+++ amarok-2.1.1/src/EngineController.cpp	2011-04-12 12:25:26.040166000 +0200
@@ -124,7 +124,7 @@
     // Get the next track when there is 2 seconds left on the current one.
     m_media->setPrefinishMark( 2000 );
 
-    connect( m_media, SIGNAL( finished() ), SLOT( slotQueueEnded() ) );
+    connect( m_media, SIGNAL( finished() ), SLOT( slotQueueEnded() ), Qt::QueuedConnection );
     connect( m_media, SIGNAL( aboutToFinish()), SLOT( slotAboutToFinish() ) );
     connect( m_media, SIGNAL( metaDataChanged() ), SLOT( slotMetaDataChanged() ) );
     connect( m_media, SIGNAL( stateChanged( Phonon::State, Phonon::State ) ), SLOT( slotStateChanged( Phonon::State, Phonon::State ) ) );
Comment 40 Chris Wales 2012-11-09 10:24:36 UTC
Created attachment 75124 [details]
Recent backtrack

Another vote for this. I tried both GStreamer and Phonon as backends, but that doesn't have any effect. In the attached log, the trouble started at line 3009.

A good way for me to know when this has happened is that I use the widget PlayWolf on my desktop - when the stream has crashed, PlayWolf will not show the album cover, or occasionally will show the cover from the last track that successfully played, with a progress bar indicating that it's part-way through.

It seems to mainly happen when skipping tracks regularly, or after leaving it on pause for a long time. When it happens, nothing seems to solve it other than a restart of Amarok (I've had problems in previous versions where it could be fixed by stopping play and reclicking on the the Personal Radio stream). Stopping and re-playing, or just re-clicking the Personal Radio, will bring up new track details in Amarok but it won't actually play.
Comment 41 Myriam Schweingruber 2012-11-09 11:26:24 UTC
(In reply to comment #40)
> Created attachment 75124 [details]
> Recent backtrack

Well, first of all, you do comment on a bug closed as fixed since over a year, without even providing the versions of the application you use. That doesn't make much sense since you most likely are not using the 4..3 version of Phonon anymore, and a lot of code changed since this was closed.

Please provide more information on what you did exactly, what you expect it to do and of course the exact version of Amarok, KDE and the Phonon backends you tried. The best would be actually to open a new report, I don't think this makes much sense here.
Comment 42 Chris Wales 2012-11-09 11:46:15 UTC
Sorry; I always forget something in bug reports!
KDE: 4.9.3 (same bug definitely present on 4.9.2)
Amarok: 2.6.0
Distro: openSUSE 12.2
Machine: x86_64
libphonon4 (4.6.0-90.1), phonon-backend-gstreamer-0_10 (4.6.2-30.1), phonon-backend-xine (4.4.4-8.1.2).

What I did was play "Personal Radio" stream from Last.fm; after playing an unspecified number of tracks (anywhere from 1 to 6), the stream stops working and cannot be made to play again without restarting Amarok. It seems to occur more frequently/sooner if skipping the current track often, or if leaving a track paused for a long time.

Happy to make it a new bug report - I defer to your judgement here. I have experienced this problem in the past (c. early versions of KDE 4.5) but it has never been the case that the stream could not be restarted without restarting the application, until now.
Comment 43 Myriam Schweingruber 2012-11-09 11:53:53 UTC
Thank you for the fast feedback. It makes not much sense to even consider the xine backend anymore, it has been deprecated since almost two years now. So you have two things that would be advisable here:

1. Test the phonon-backend-vlc to see if this is reproducible,
2. if it is reproducible with both the gstreamer and the vlc backend, then please file a new bug for the Amarok product, else this should be a new bug against the phonon-backend-gstreamer product.
Comment 44 Chris Wales 2012-12-02 10:10:39 UTC
Thanks Myriam - I have now tried it with the VLC backend and it works fine, so I will raise a new issue for phonon-backend-gstreamer as you suggest
Comment 45 Myriam Schweingruber 2012-12-02 11:52:26 UTC
Thank you for the feedback.