Debug log of "EngineController not advancing to next track"

Mark Kretschmann kretschmann at kde.org
Wed Feb 11 09:10:31 CET 2009


Hi guys,

I was now lucky and was able to get a debug log from the problem with
the EngineController not advancing to the next track (with an album
from Ampache). Posting it here for reference, and maybe we'll be lucky
and can spot something interesting:



amarok: BEGIN: void EngineController::slotAboutToFinish()
amarok:   [EngineController] Track finished completely, updating statistics
amarok: BEGIN: virtual void MainWindow::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
MainWindow::metadataChanged(Meta::TrackPtr) - Took 0.0007s
amarok: BEGIN: virtual void
LyricsEngine::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
LyricsEngine::metadataChanged(Meta::TrackPtr) - Took 0.00042s
amarok: BEGIN: virtual void
WikipediaEngine::metadataChanged(Meta::TrackPtr)
amarok: BEGIN: void WikipediaEngine::update()
amarok: BEGIN: bool EngineController::isStream()
amarok: END__: bool EngineController::isStream() - Took 0.0012s
amarok:        tmpWikiStr:  "Bertine Zetlitz (band)"
amarok:        Same entry requested again. Ignoring.
amarok: END__: void WikipediaEngine::update() - Took 0.0023s
amarok: END__: virtual void
WikipediaEngine::metadataChanged(Meta::TrackPtr) - Took 0.0028s
amarok: BEGIN: virtual void
Playlist::Model::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.0014s
amarok: BEGIN: virtual void
Amarok::OSD::metadataChanged(Meta::TrackPtr)
amarok: BEGIN: void OSDWidget::show(const QString&, QImage)
amarok: END__: void OSDWidget::show(const QString&, QImage) - Took
0.0038s
amarok: END__: virtual void
Amarok::OSD::metadataChanged(Meta::TrackPtr) - Took 0.0096s
amarok: BEGIN: virtual void
MainWindow::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
MainWindow::metadataChanged(Meta::TrackPtr) - Took 0.00035s
amarok: BEGIN: virtual void
LyricsEngine::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
LyricsEngine::metadataChanged(Meta::TrackPtr) - Took 0.00018s
amarok: BEGIN: virtual void
WikipediaEngine::metadataChanged(Meta::TrackPtr)
amarok: BEGIN: void WikipediaEngine::update()
amarok: BEGIN: bool EngineController::isStream()
amarok: END__: bool EngineController::isStream() - Took 0.00011s
amarok:        tmpWikiStr:  "Bertine Zetlitz (band)"
amarok:        Same entry requested again. Ignoring.
amarok: END__: void WikipediaEngine::update() - Took 0.00047s
amarok: END__: virtual void
WikipediaEngine::metadataChanged(Meta::TrackPtr) - Took 0.00074s
amarok: BEGIN: virtual void
Playlist::Model::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.00052s
amarok: BEGIN: virtual void
Amarok::OSD::metadataChanged(Meta::TrackPtr)
amarok: BEGIN: void OSDWidget::show(const QString&, QImage)
amarok: END__: void OSDWidget::show(const QString&, QImage) - Took
0.0028s
amarok: END__: virtual void
Amarok::OSD::metadataChanged(Meta::TrackPtr) - Took 0.034s
amarok: BEGIN: void Playlist::Actions::play(quint64, bool)
amarok: BEGIN: void EngineController::play(const Meta::TrackPtr&,
uint)
amarok: BEGIN: void EngineController::playUrl(const KUrl&, uint)
amarok: BEGIN: void EngineController::slotStopFadeout()
amarok: END__: void EngineController::slotStopFadeout() - Took
8.7e-05s
amarok:         [EngineController] URL:
"file:///home/mark/Music/Bertine%20Zetlitz-5%20album/Bertine%20Zetlitz-My%20Italian%20Greyhound-2006/Bertine%20Zetlitz%20-%20My%20Italian%20Greyhound%20-%2003%20-%20Obsession.mp3"
amarok: BEGIN: void EngineController::slotNewTrackPlaying(const
Phonon::MediaSource&)
amarok:           [EngineController] Using gain of 0 with relative
peak of 0
amarok: BEGIN: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State)
amarok: BEGIN: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State)
amarok:                LoadingState: clear text
amarok: END__: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State) - Took
0.0012s
amarok: BEGIN: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State)
amarok:                NEWSTATE:  0 OLDSTATE:  0
amarok: END__: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State) - Took 0.0002s
amarok: BEGIN: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State) - Took
0.0002s
amarok: BEGIN: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
- Took 9.6e-05s
amarok:              returning bookmarkcurrenttrack action
amarok: BEGIN: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State)
amarok:                slider disabled!
amarok: END__: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.00058s
amarok: BEGIN: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State)
amarok:               [MainWindow] Phonon state:  0
amarok: END__: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00016s
amarok: END__: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State) - Took 0.23s
amarok: BEGIN: virtual void ScrobblerAdapter::engineNewTrackPlaying()
amarok:             [lastfm] track type: "mp3"
amarok: BEGIN: void ScrobblerAdapter::checkScrobble()
amarok: END__: void ScrobblerAdapter::checkScrobble() - Took 0.00011s
amarok:             [lastfm] nowPlaying:  "Bertine Zetlitz"  -  "My
Italian Greyhound"  -  "Obsession"
amarok: END__: virtual void ScrobblerAdapter::engineNewTrackPlaying()
- Took 0.00065s
amarok:            returning bookmarkcurrenttrack action
amarok: BEGIN: virtual void ProgressWidget::engineNewTrackPlaying()
amarok: BEGIN: virtual void
ProgressWidget::engineTrackLengthChanged(long int)
amarok:                new length:  227
amarok:                slider enabled!
amarok: END__: virtual void
ProgressWidget::engineTrackLengthChanged(long int) - Took 0.00028s
amarok: BEGIN: static BookmarkList
PlayUrlRunner::bookmarksFromUrl(KUrl)
amarok:                query:  "SELECT id, parent_id, name, url,
description FROM bookmarks WHERE url LIKE
'%ZmlsZTovLy9ob21lL21hcmsvTXVzaWMvQmVydGluZSUyMFpldGxpdHotNSUyMGFsYnVtL0JlcnRpbmUlMjBaZXRsaXR6LU15JTIwSXRhbGlhbiUyMEdyZXlob3VuZC0yMDA2L0JlcnRpbmUlMjBaZXRsaXR6JTIwLSUyME15JTIwSXRhbGlhbiUyMEdyZXlob3VuZCUyMC0lMjAwMyUyMC0lMjBPYnNlc3Npb24ubXA%'"
amarok:                [ERROR!] GREPME MySQLe query failed! Table
'amarok.bookmarks' doesn't exist  on  "SELECT id, parent_id, name,
url, description FROM bookmarks WHERE url LIKE
'%ZmlsZTovLy9ob21lL21hcmsvTXVzaWMvQmVydGluZSUyMFpldGxpdHotNSUyMGFsYnVtL0JlcnRpbmUlMjBaZXRsaXR6LU15JTIwSXRhbGlhbiUyMEdyZXlob3VuZC0yMDA2L0JlcnRpbmUlMjBaZXRsaXR6JTIwLSUyME15JTIwSXRhbGlhbiUyMEdyZXlob3VuZCUyMC0lMjAwMyUyMC0lMjBPYnNlc3Npb24ubXA%'"
amarok: END__: static BookmarkList
PlayUrlRunner::bookmarksFromUrl(KUrl) - Took 0.00079s
amarok: END__: virtual void ProgressWidget::engineNewTrackPlaying() -
Took 0.0014s
amarok: END__: void EngineController::slotNewTrackPlaying(const
Phonon::MediaSource&) - Took 0.28s
amarok: END__: void EngineController::playUrl(const KUrl&, uint) -
Took 0.29s
amarok: END__: void EngineController::play(const Meta::TrackPtr&,
uint) - Took 0.29s
amarok: END__: void Playlist::Actions::play(quint64, bool) - Took
0.29s
amarok: END__: void EngineController::slotAboutToFinish() - Took 0.35s
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State,
Phonon::State)
amarok: BEGIN: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State)
amarok: BEGIN: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00061s
amarok: BEGIN: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State)
amarok:        NEWSTATE:  1 OLDSTATE:  2
amarok: END__: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State) - Took 0.00059s
amarok: BEGIN: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00033s
amarok: BEGIN: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
amarok: BEGIN: virtual void LyricsEngine::message(const
Context::ContextState&)
amarok: END__: virtual void LyricsEngine::message(const
Context::ContextState&) - Took 0.00029s
amarok: BEGIN: virtual void CurrentEngine::message(const
Context::ContextState&)
amarok: END__: virtual void CurrentEngine::message(const
Context::ContextState&) - Took 0.00032s
amarok: END__: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
- Took 0.0014s
amarok:      returning bookmarkcurrenttrack action
amarok: BEGIN: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.00021s
amarok: BEGIN: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State)
amarok:       [MainWindow] Phonon state:  1
amarok: END__: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00031s
amarok: END__: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State) - Took 0.09s
amarok: END__: void EngineController::slotStateChanged(Phonon::State,
Phonon::State) - Took 0.091s
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State,
Phonon::State)
amarok: BEGIN: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State)
amarok: BEGIN: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State)
amarok:        LoadingState: clear text
amarok: END__: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State) - Took
0.0022s
amarok: BEGIN: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State)
amarok:        NEWSTATE:  0 OLDSTATE:  1
amarok: END__: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State) - Took 0.00027s
amarok: BEGIN: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State) - Took
0.0001s
amarok: BEGIN: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
- Took 9.3e-05s
amarok:      returning bookmarkcurrenttrack action
amarok: BEGIN: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.00021s
amarok: BEGIN: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State)
amarok:       [MainWindow] Phonon state:  0
amarok: END__: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00015s
amarok: END__: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State) - Took 0.053s
amarok: END__: void EngineController::slotStateChanged(Phonon::State,
Phonon::State) - Took 0.053s
amarok: BEGIN: void EngineController::slotTrackLengthChanged(qint64)
amarok: BEGIN: virtual void
ProgressWidget::engineTrackLengthChanged(long int)
amarok:      new length:  227
amarok:      slider enabled!
amarok: END__: virtual void
ProgressWidget::engineTrackLengthChanged(long int) - Took 0.00021s
amarok: END__: void EngineController::slotTrackLengthChanged(qint64) -
Took 0.00039s
amarok: BEGIN: void EngineController::slotMetaDataChanged()
amarok:   [EngineController] Artist     :  ("Bertine Zetlitz")
amarok:   [EngineController] Album      :  ("My Italian Greyhound")
amarok:   [EngineController] Title      :  ("Obsession")
amarok:   [EngineController] Genre      :  ("Pop")
amarok:   [EngineController] Tracknumber:  ("3")
amarok:   [EngineController] Length     :  ()
amarok:   [EngineController] Track changed:  true
amarok: BEGIN: void EngineSubject::newMetaDataNotify(const QHash<long
long int, QString>&, bool) const
amarok:      returning bookmarkcurrenttrack action
amarok: END__: void EngineSubject::newMetaDataNotify(const QHash<long
long int, QString>&, bool) const - Took 0.025s
amarok: END__: void EngineController::slotMetaDataChanged() - Took
0.026s
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State,
Phonon::State)
amarok: BEGIN: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State)
amarok: BEGIN: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
StatusBar::engineStateChanged(Phonon::State, Phonon::State) - Took
0.0003s
amarok: BEGIN: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State)
amarok:        NEWSTATE:  1 OLDSTATE:  0
amarok: END__: virtual void
Amarok::PlayPauseAction::engineStateChanged(Phonon::State,
Phonon::State) - Took 0.00019s
amarok: BEGIN: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
Amarok::OSD::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00011s
amarok: BEGIN: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
amarok: BEGIN: virtual void LyricsEngine::message(const
Context::ContextState&)
amarok: END__: virtual void LyricsEngine::message(const
Context::ContextState&) - Took 0.0001s
amarok: BEGIN: virtual void CurrentEngine::message(const
Context::ContextState&)
amarok: END__: virtual void CurrentEngine::message(const
Context::ContextState&) - Took 0.00013s
amarok: END__: virtual void
Context::ContextView::engineStateChanged(Phonon::State, Phonon::State)
- Took 0.00057s
amarok:      returning bookmarkcurrenttrack action
amarok: BEGIN: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State)
amarok: END__: virtual void
ProgressWidget::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.0002s
amarok: BEGIN: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State)
amarok:       [MainWindow] Phonon state:  1
amarok: END__: virtual void
MainWindow::engineStateChanged(Phonon::State, Phonon::State) - Took
0.00024s
amarok: END__: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State) - Took 0.024s
amarok: END__: void EngineController::slotStateChanged(Phonon::State,
Phonon::State) - Took 0.025s
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State,
Phonon::State)
amarok: END__: void EngineController::slotStateChanged(Phonon::State,
Phonon::State) - Took 0.00017s
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State,
Phonon::State)
amarok: BEGIN: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State)
amarok: END__: void EngineSubject::stateChangedNotify(Phonon::State,
Phonon::State) - Took 0.0003s
amarok: END__: void EngineController::slotStateChanged(Phonon::State,
Phonon::State) - Took 0.00097s
amarok: BEGIN: void EngineController::slotQueueEnded()
amarok: BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.0011s
amarok: BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void
Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.00094s
amarok: BEGIN: void ScrobblerAdapter::checkScrobble()
amarok:     [lastfm] scrobble:  "Bertine Zetlitz"  -  "My Italian
Greyhound"  -  "Obsession"
HTTP POST: "http://post2.audioscrobbler.com:80/protocol_1.2&a[0]=Bertine%20Zetlitz&t[0]=500&i[0]=1234339453&o[0]=P&r[0]=&l[0]=227&b[0]=My%20Italian%20Greyhound&n[0]=0&m[0]=&a[1]=Bertine%20Zetlitz&t[1]=Obsession&i[1]=1234339555&o[1]=P&r[1]=&l[1]=234&b[1]=My%20Italian%20Greyhound&n[1]=0&m[1]="
amarok(30587) ScrobblerHttp::createRequest: PostOperation:  QUrl(
"http://post2.audioscrobbler.com:80/protocol_1.2" )
amarok:     [lastfm] statusChanged: statusCode= 2
amarok: END__: void ScrobblerAdapter::checkScrobble() - Took 0.013s
amarok: BEGIN: virtual void ProgressWidget::enginePlaybackEnded(int,
int, EngineObserver::PlaybackEndedReason)
amarok: END__: virtual void ProgressWidget::enginePlaybackEnded(int,
int, EngineObserver::PlaybackEndedReason) - Took 0.00036s
amarok: END__: void EngineController::slotQueueEnded() - Took 0.025s
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&)
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&) - Took 0.079s
amarok(30587) KNetworkReply::setMimeType: "text/plain"
"OK"
amarok: [lastfm] statusChanged: statusCode= 3
amarok: BEGIN: void CurrentEngine::stoppedState()
amarok: END__: void CurrentEngine::stoppedState() - Took 0.0012s
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&)
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&) - Took 0.0007s
amarok: BEGIN: void CurrentEngine::resultReady(const QString&, const
Meta::AlbumList&)
amarok: END__: void CurrentEngine::resultReady(const QString&, const
Meta::AlbumList&) - Took 0.00024s
amarok: BEGIN: void CurrentEngine::resultReady(const QString&, const
Meta::TrackList&)
amarok: END__: void CurrentEngine::resultReady(const QString&, const
Meta::TrackList&) - Took 0.00027s
amarok: BEGIN: void CurrentEngine::setupTracksData()
amarok: END__: void CurrentEngine::setupTracksData() - Took 0.00014s
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&)
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&) - Took 0.0002s
amarok: BEGIN: virtual void CurrentTrack::constraintsEvent(Plasma::Constraints)
amarok: END__: virtual void
CurrentTrack::constraintsEvent(Plasma::Constraints) - Took 0.022s
HTTP POST: "http://post.audioscrobbler.com:80/np_1.2&a=Bertine%20Zetlitz&t=Obsession&b=My%20Italian%20Greyhound&l=234&n=0&m="
amarok(30587) ScrobblerHttp::createRequest: PostOperation:  QUrl(
"http://post.audioscrobbler.com:80/np_1.2" )
amarok(30587) KNetworkReply::setMimeType: "text/plain"
"OK"

-- 
Mark Kretschmann
Amarok Developer
www.kde.org - amarok.kde.org


More information about the Amarok-devel mailing list