Bug 268892

Which Phonon backend do you use?

gstreamer

Could you please run Amarok in debug mode with

amarok -d --nofork

twice, then give us the lines when it stops from the second output?

Just to make sure I understand the request correctly: I should run

amarok -d --nofork

quit, and then run it this way again? And how many lines of output should I send? Should I play some music?

Yes, because debugging is only collected in the second run. Just reproduce the bug, then stop Amarok and give us the last ~100-300 lines of the output

Created attachment 58205 [details]
Debug output from amarok.

Attached the last ~200 lines of debug output. I think I already see what's happening: Near the end of the output, metadata of the next track is shown, but the URL is empty:

amarok: BEGIN: void EngineController::slotMetaDataChanged() 
amarok:   [EngineController] Artist     :  ("Anonymph") 
amarok:   [EngineController] Album      :  ("Terrarium") 
amarok:   [EngineController] Title      :  ("You Undone") 
amarok:   [EngineController] Genre      :  ("Pop") 
amarok:   [EngineController] Tracknumber:  () 
amarok:   [EngineController] Length     :  () 
amarok:   [EngineController] Track changed:  true current: 0x7fde1c013e70 url "" 
amarok:   [EngineController] no spam 
amarok: END__: void EngineController::slotMetaDataChanged() [Took: 0s] 

This is not the case for the first track, where it looks like:

amarok: BEGIN: void EngineController::slotMetaDataChanged() 
amarok:   [EngineController] Artist     :  ("Anonymph") 
amarok:   [EngineController] Album      :  ("Terrarium") 
amarok:   [EngineController] Title      :  ("You Undone") 
amarok:   [EngineController] Genre      :  ("Pop") 
amarok:   [EngineController] Tracknumber:  () 
amarok:   [EngineController] Length     :  () 
amarok:   [EngineController] Track changed:  true current: 0x7fde1c005770 url "http://he3.magnatune.com/all/01-You Undone-Anonymph.ogg" 
amarok:   [EngineController] no spam 
amarok: END__: void EngineController::slotMetaDataChanged() [Took: 0s]

Oh, and it's also the wrong metadata, because the next track is named "Filtered", not "You Undone".

Thank you for the feedback.

I have same problem, but It appears when I play local songs (I don't use Magnatune)

Here is my debug output, I hope it helps


amarok:   BEGIN: void ScrobblerAdapter::trackMetadataChanged(Meta::TrackPtr) 
amarok:   END__: void ScrobblerAdapter::trackMetadataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:   BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok:   END__: void OSDWidget::show(const QString&, QImage) [Took: 0s] 
amarok:   BEGIN: void Context::ContextView::slotMetadataChanged(Meta::TrackPtr) 
amarok:     BEGIN: bool EngineController::isStream() 
amarok:     END__: bool EngineController::isStream() [Took: 0s] 
amarok:   END__: void Context::ContextView::slotMetadataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:   BEGIN: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) 
amarok:   END__: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:   BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) 
amarok:     BEGIN: void StatusBar::updateTotalPlaylistLength() 
amarok:     END__: void StatusBar::updateTotalPlaylistLength() [Took: 0s] 
amarok:     [Playlist::Model] Metadata updated for track "Magic Carpet" 
amarok:   END__: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) [Took: 0s] 
stateChangedInternal newState: "StoppedState" previousState: "PlayingState" 
stateChangedInternal newState: "StoppedState" previousState: "StoppedState" 
setSource 

setSource Error: MediaSource is empty. 
amarok:   BEGIN: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:     [EngineController] Using gain of -1 with relative peak of -1 
amarok:     BEGIN: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) 
amarok:     END__: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) [Took: 0s] 
amarok:     BEGIN: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) 
amarok:     END__: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:     BEGIN: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) 
amarok:       BEGIN: void StatusBar::updateTotalPlaylistLength() 
amarok:       END__: void StatusBar::updateTotalPlaylistLength() [Took: 0s] 
amarok:       BEGIN: void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() 
amarok:         BEGIN: void Playlist::PrettyListView::scrollToActiveTrack() 
amarok:         END__: void Playlist::PrettyListView::scrollToActiveTrack() [Took: 0s] 
amarok:       END__: void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() [Took: 0.002s] 
amarok:     END__: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) [Took: 0.003s] 
amarok:     BEGIN: void TimecodeObserver::trackPlaying(Meta::TrackPtr) 
amarok:       current track name:  "Dusty Roads" 
amarok:       Track timecodeable 
amarok:     END__: void TimecodeObserver::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:     BEGIN: void ProgressWidget::trackLengthChanged(qint64) 
amarok:       new length:  197000 
amarok:       slider enabled! 
amarok:       BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:         found  0  timecodes on this track 
amarok:       END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0s] 
amarok:     END__: void ProgressWidget::trackLengthChanged(qint64) [Took: 0s] 
amarok:     BEGIN: void ScrobblerAdapter::trackPlaying(Meta::TrackPtr) 
amarok:       [lastfm] track type: "mp3" 
amarok:       BEGIN: void ScrobblerAdapter::checkScrobble() 
amarok:         [lastfm] total played 9597 duration 136500 isNull false submit? true 
amarok:       END__: void ScrobblerAdapter::checkScrobble() [Took: 0s] 
amarok:       [lastfm] nowPlaying:  "Oi Va Voi"  -  "Travelling The Face Of The G.."  -  "Dusty Roads" 
HTTP POST:  QUrl( "http://post.audioscrobbler.com:80/np_1.2" )  "s=08442e8480d34c18994d214c59a9e9e2&a=Oi%20Va%20Voi&t=Dusty%20Roads&b=Travelling%20The%20Face%20Of%20The%20G..&l=197&n=0&m=" 
amarok:     END__: void ScrobblerAdapter::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:     BEGIN: void OSDWidget::show(const QString&, QImage) 
amarok:     END__: void OSDWidget::show(const QString&, QImage) [Took: 0s] 
amarok:     BEGIN: void CurrentEngine::trackPlaying(Meta::TrackPtr) 
amarok:       [CurrentEngine] updating track "Dusty Roads" 
amarok:     END__: void CurrentEngine::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:   END__: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [Took: 0.026s] 
amarok: END__: void EngineController::slotFinished() [Took: 0.048s] 
stateChangedInternal newState: "StoppedState" previousState: "StoppedState" 
amarok: BEGIN: void LyricsEngine::update() 
amarok:   [LyricsEngine] current track is "Dusty Roads" 
amarok:   BEGIN: bool EngineController::isStream() 
amarok:   END__: bool EngineController::isStream() [Took: 0s] 
amarok:   BEGIN: virtual void LyricsEngine::newLyrics(QStringList&) 
amarok:   END__: virtual void LyricsEngine::newLyrics(QStringList&) [Took: 0s] 
amarok: END__: void LyricsEngine::update() [Took: 0.001s] 
amarok: BEGIN: void LyricsEngine::update() 
amarok:   [LyricsEngine] current track is "Dusty Roads" 
amarok:   BEGIN: bool LyricsEngine::testLyricsChanged(const QString&, const QString&, QStringList) const 
amarok:     [LyricsEngine] compared lyrics are the same =  false 
amarok:   END__: bool LyricsEngine::testLyricsChanged(const QString&, const QString&, QStringList) const [Took: 0s] 
amarok: END__: void LyricsEngine::update() [Took: 0s] 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
amarok: BEGIN: void LyricsEngine::update() 
amarok:   [LyricsEngine] current track is "Dusty Roads" 
amarok:   BEGIN: bool LyricsEngine::testLyricsChanged(const QString&, const QString&, QStringList) const 
amarok:     [LyricsEngine] compared lyrics are the same =  false 
amarok:   END__: bool LyricsEngine::testLyricsChanged(const QString&, const QString&, QStringList) const [Took: 0s] 
amarok: END__: void LyricsEngine::update() [Took: 0s] 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0.21s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok:   BEGIN: void LyricsAppletPrivate::showLyrics(const QString&, bool) 
amarok:   END__: void LyricsAppletPrivate::showLyrics(const QString&, bool) [Took: 0.001s] 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0.002s] 
"OK"

Sorry Maxim, but that is a bit of a guess of yours. Nothing in your paste indicates it is related to this report.

Which Amarok version do you use, which Phonon backend? Did you try changing the Phonon backend?

Well I found that my issue is reproduced with some specific files on VLC backend

Maxim: then it should be reported against the Phonon vlc backend, the OR is about gstreamer

reassigning to the new bugzilla product for better bug tracing of the various backends. Sorry for the noise.

I've got something to add here:

1) It's stillpresent in 2.4.1.

2) When I klick on "Next" while listening to the first track in the playlist, amarok jumps to the second track, but doesn't start playback. If I click "Next" again, it jumps to the third and starts playback, then for the forth again it doesn't start, and so on.

Dirk, this is not Amarok, but Phonon-backend-gstreamer related, so it doesn't depend on the Amarok version, but on the version of the gstreamer backend you use.

Forgot about that. Sorry for the noise.

*** Bug 278265 has been marked as a duplicate of this bug. ***

Confirmed by duplicates.

*** Bug 262779 has been marked as a duplicate of this bug. ***

*** Bug 291639 has been marked as a duplicate of this bug. ***

*** Bug 284288 has been marked as a duplicate of this bug. ***

Changing priority, this does happen with tracks played from streaming sources, be their internet services or local ones like DAAP or NFS shares.

*** Bug 292788 has been marked as a duplicate of this bug. ***

http://techbase.kde.org/Development/Tutorials/Debugging/Phonon

We'll still need a proper debug log, please also make sure you have the appropriate environment variables defined (see link above).

Btw, best log would be a complete one from amarok's start to a bit past the point when it skipped a track. You can of course compress the log using gzip or something.

TIA

Created attachment 68400 [details]
amarok debug log

Thank you for the feedback.

*** Bug 292183 has been marked as a duplicate of this bug. ***

Is this still valid with phonon-backend-gstreamer 4.6.0?

Works for me now with
phonon 4:4.6.0.0-1 (debian/sid)
phonon-backend-gstreamer 4:4.6.0.0-1 (debian/sid)

4.6.0 isn't available on Kubuntu 11.10 (yet)... As soon as it is, I'll give it a try.

I don't have this gstreamer version (yet). When OpenSUSE Tumbleweed moves
to it I'll test it.

Jon

On Fri, Mar 2, 2012 at 10:06 AM, Myriam Schweingruber <myriam@kde.org>wrote:

> https://bugs.kde.org/show_bug.cgi?id=268892
>
>
> Myriam Schweingruber <myriam@kde.org> changed:
>
>           What    |Removed                     |Added
>
> ----------------------------------------------------------------------------
>              Status|NEW                         |NEEDSINFO
>         Resolution|                            |WAITINGFORINFO
>
>
>
>
> --- Comment #28 from Myriam Schweingruber <myriam kde org>  2012-03-02
> 10:06:10 ---
> Is this still valid with phonon-backend-gstreamer 4.6.0?
>
> --
> Configure bugmail: https://bugs.kde.org/userprefs.cgi?tab=email
> ------- You are receiving this mail because: -------
> You are on the CC list for the bug.
>

I had the same problem (playing songs from DAAP share) using phonon-gstreamer-4.5.0 on gentoo.
As suggested, i upgraded to phonon-4.6.0 and phonon-gstreamer-4.6.0, which seems to fix the problem, as i listened to several tracks in a row now, without having to press "play" after every song.
I also tried Magnatune.com, which does work now, too.

Makes me think this bug is fixed with phonon-gstreamer-4.6.0.

Thank you for the feedback, closing as fixed in version 4.6

*** Bug 296884 has been marked as a duplicate of this bug. ***

I've compiled Phonon 4.6 and Phonon-GStreamer 4.6 from sources and still have this problem on Kubuntu.

Reopening based on comment #35

Having upgraded to Kubuntu 12.04, this bug seems half-fixed.

In regard to Magnatune.com and other online streaming services in Amarok, this appears to be fixed - after one track finishes playing, the next successfully starts playing.

However, in regard to offline media - both in Amarok and in Dragon player - changing from one file to another seems unreliable. The first "track"-change appears to work, however there seems to be an issue with consecutive track-changes - the second track-change fails; a third (manual) track-change succeeds; the fourth fails etc.

I believe this is an issue with GStreamer - either the back-end or GStreamer itself - as the Phonon VLC back-end behaves as expected, and as previously mentioned this is the case in both Amarok and Dragon player.

*** Bug 303252 has been marked as a duplicate of this bug. ***

Git commit e1d2ea6ce3ef61af5dcd4f99db9fb407c95ccb2d by Matěj Laitl.
Committed on 24/07/2012 at 10:59.
Pushed by laitl into branch 'master'.

EngineController: don't do serious work in slotAboutToFinish()

...because slotAboutToFinish() may be called twice (or not at all) per
track by some Phonon backends (hi, vlc) - increase play count rather in
slotNewTrackPlaying() or in slotFinished(). This also needs to change
how m_currentTrack is handled, because slotNewTrackPlaying() needs to
have the old one in m_currentTrack.

Also, PlaylistActions::requestNextTrack() is changed to be a read-only
method that shouldn't change playlist state especially when there is no
next track. PlaylistActions::reflectPlaybackFinished() is introduced to
do the thing and is called from EngineController::slotFinished(), which
is a much better place for it than slotAboutToFinish().

Reporters of CCed bugs, please re-test your bug with this commit
applied, it is possible it has been resolved by this patch.
Related: bug 299890, bug 277197, bug 302652, bug 303580, bug 302240
FIXED-IN: 2.6

M  +1    -0    ChangeLog
M  +44   -35   src/EngineController.cpp
M  +17   -16   src/playlist/PlaylistActions.cpp
M  +8    -0    src/playlist/PlaylistActions.h

http://commits.kde.org/amarok/e1d2ea6ce3ef61af5dcd4f99db9fb407c95ccb2d

I tried this again with 2.6.0 on KDE 4.9.1 and it works fine for me now. However, I'll soon open another one :(

Thank you for the feedback.

*** Bug 296926 has been marked as a duplicate of this bug. ***