playlist bug: randomly repeating tracks

Mark Kretschmann kretschmann at kde.org
Thu Aug 7 19:18:50 CEST 2008 

Hi,

I was looking at this bug that Amarok randomly repeats some tracks
sometimes (in normal play mode), and found that there is some
weirdness going on in Playlist::Model::engineNewTrackPlaying().

Basically we are reading Engine::currentTrack() there, and then
checking for 0, and if it's 0 the following code is executed:

            warning() << "engineNewTrackPlaying:: MISS";

            foreach( Item* item, itemList() )
            {
                if( item->track() == track )
                {
                    setActiveItem( item );
                    break;
                }
            }

This looks very bogus to me. It seems that we could just read
Model::activeTrack() instead, which would never return 0.


Here is a log that a user sent me:

This log is from switching from the "Madon laulu" to the "Svart Djup"
track (Svart Djup is the last track on the album and on the playlist
which only contains this album)

amarok: BEGIN: void Playlist::Model::requestNextTrack()
amarok: BEGIN: void Playlist::Model::setNextRow(int)
amarok: END__: void Playlist::Model::setNextRow(int) - Took 6.2e-05s
amarok: END__: void Playlist::Model::requestNextTrack() - Took 0.00013s
amarok: BEGIN: virtual void CurrentEngine::message(const
Context::ContextState&)
amarok:    1
amarok:    2
amarok: BEGIN: void CurrentEngine::update()
amarok:      We got  6  albums for artist  "Finntroll"
amarok:      adding album  "Jaktens Tid"
amarok: BEGIN: void EngineController::slotMetaDataChanged()
amarok:       [EngineController] Artist     :  ("Finntroll")
amarok:       [EngineController] Album      :  ("Visor Om Slutet")
amarok:       [EngineController] Title      :  ("Svart Djup")
amarok:       [EngineController] Genre      :  ("")
amarok:       [EngineController] Tracknumber:  ("10")
amarok:       [EngineController] Length     :  ()
amarok:       [EngineController] Track changed:  true
amarok: BEGIN: virtual void App::engineNewMetaData(const QHash<long
long int, QString>&, bool)
amarok: BEGIN: virtual void Amarok::OSD::show(Meta::TrackPtr)
amarok: BEGIN: virtual void OSDWidget::show()
amarok: END__: virtual void OSDWidget::show() - Took 0.00062s
amarok: END__: virtual void Amarok::OSD::show(Meta::TrackPtr) - Took 0.0017s
amarok: BEGIN: void TrackToolTip::setTrack(Meta::TrackPtr)
amarok: END__: void TrackToolTip::setTrack(Meta::TrackPtr) - Took 0.00024s
amarok: END__: virtual void App::engineNewMetaData(const QHash<long
long int, QString>&, bool) - Took 0.002s
amarok: END__: void EngineController::slotMetaDataChanged() - Took 0.0023s
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&)
amarok(11522) CurrentTrack::dataUpdated: CurrentTrack::dataUpdated
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&) - Took 0.016s
amarok:      adding album  "Jaktens tid"
amarok: BEGIN: void Playlist::Model::requestNextTrack()
amarok: BEGIN: void Playlist::Model::setNextRow(int)
amarok: END__: void Playlist::Model::setNextRow(int) - Took 6.6e-05s
amarok: END__: void Playlist::Model::requestNextTrack() - Took 0.00015s
amarok:      adding album  "Midnattens Widunder"
amarok:      adding album  "Nattfödd"
amarok:      adding album  "Ur Jordens Djup"
amarok:      adding album  "Visor Om Slutet"
amarok: END__: void CurrentEngine::update() - Took 0.092s
amarok: END__: virtual void CurrentEngine::message(const
Context::ContextState&) - Took 0.092s
amarok: BEGIN: virtual void
Playlist::Model::engineStateChanged(Phonon::State, Phonon::State)
amarok:    Phonon currentState:  2
amarok:    Phonon oldState:  2
amarok:    Successfully played track. Resetting failure count.
amarok: END__: virtual void
Playlist::Model::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.00011s
amarok: BEGIN: virtual void
Amarok::StatusBar::engineStateChanged(Phonon::State, Phonon::State)
amarok:    PlayingState: clear text
amarok: END__: virtual void
Amarok::StatusBar::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.00022s
amarok: BEGIN: virtual void Playlist::Model::engineNewTrackPlaying()
amarok: BEGIN: void Playlist::Model::setActiveRow(int)
amarok:      refreshing  "Madon laulu"
amarok:      refreshing  "Svart Djup"
amarok: END__: void Playlist::Model::setActiveRow(int) - Took 0.00063s
amarok: END__: virtual void Playlist::Model::engineNewTrackPlaying() -
Took 0.0007s
amarok: BEGIN: virtual void ScrobblerAdapter::engineNewTrackPlaying()
amarok:   [lastfm] scrobble:  "Finntroll"  -  "Visor Om Slutet"  -
"Madon laulu"
BEGIN: void ScrobblerManager::scrobble(TrackInfo)
  "Finntroll &#8211; Madon laulu"
amarok:   [lastfm] Wrote 1 tracks to
"/home/acc/.kde4.1/share/apps/amarok/acc_submissions.xml"
  BEGIN: void ScrobblerManager::scrobble(const ScrobbleCache&)
    "acc"
    BEGIN: int Scrobbler::submit(const ScrobbleCache&)
      "Finntroll &#8211; Madon laulu"
      BEGIN: void ScrobblerPostRequest::request(const QByteArray&)
        "[id:"
        "0"
        "93"
        "s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a[0]=Finntroll&t[0]=Madon%20laulu&i[0]=1218110365&o[0]=P&r[0]=&l[0]=241&b[0]=Visor%20Om%20Slutet&n[0]=&m[0]="
amarok:   [lastfm] POST:
"s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a[0]=Finntroll&t[0]=Madon%20laulu&i[0]=1218110365&o[0]=P&r[0]=&l[0]=241&b[0]=Visor%20Om%20Slutet&n[0]=&m[0]="
      END:   void ScrobblerPostRequest::request(const QByteArray&)
[elapsed: 0 ms]
    END:   int Scrobbler::submit(const ScrobbleCache&) [elapsed: 1 ms]
amarok:   [lastfm] statusChanged: statusCode= 2
  END:   void ScrobblerManager::scrobble(const ScrobbleCache&) [elapsed: 1 ms]
END:   void ScrobblerManager::scrobble(TrackInfo) [elapsed: 1 ms]
amarok:   [lastfm] nowPlaying:  "Finntroll"  -  "Visor Om Slutet"  -
"Svart Djup"
BEGIN: void ScrobblerManager::nowPlaying(const TrackInfo&)
  "Finntroll &#8211; Svart Djup"
  BEGIN: void Scrobbler::announce(const TrackInfo&)
    "Finntroll &#8211; Svart Djup"
    BEGIN: void ScrobblerPostRequest::request(const QByteArray&)
      "[id:"
      "0"
      "93"
      "s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a=Finntroll&t=Svart%20Djup&b=Visor%20Om%20Slutet&l=238&n=&m="
    END:   void ScrobblerPostRequest::request(const QByteArray&)
[elapsed: 0 ms]
  END:   void Scrobbler::announce(const TrackInfo&) [elapsed: 0 ms]
END:   void ScrobblerManager::nowPlaying(const TrackInfo&) [elapsed: 0 ms]
amarok: END__: virtual void ScrobblerAdapter::engineNewTrackPlaying()
- Took 0.0011s
amarok: BEGIN: virtual void Amarok::StatusBar::engineNewTrackPlaying()
amarok: END__: virtual void Amarok::StatusBar::engineNewTrackPlaying()
- Took 0.0002s
BEGIN: void Scrobbler::onSubmissionReturn(const QString&)
  "[id:"
  "0"
  "]"
  "OK"
  BEGIN: void ScrobblerManager::onScrobbled(const QList<TrackInfo>&)
    "1"
    "tracks were successfully scrobbled"
amarok: [lastfm] 1 toremove count: 1
amarok: [lastfm] Removing "Finntroll &#8211; Madon laulu"
amarok: [lastfm] 0
amarok: [lastfm]
"/home/acc/.kde4.1/share/apps/amarok/acc_submissions.xml" is now empty
  END:   void ScrobblerManager::onScrobbled(const QList<TrackInfo>&)
[elapsed: 0 ms]
END:   void Scrobbler::onSubmissionReturn(const QString&) [elapsed: 0 ms]


Then when amarok should have ended playing it starts to replay the
last track, with this output:
amarok: BEGIN: virtual void CurrentEngine::message(const
Context::ContextState&)
amarok:    1
amarok:    2
amarok: BEGIN: void CurrentEngine::update()
amarok:      We got  6  albums for artist  "Finntroll"
amarok:      adding album  "Jaktens Tid"
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&)
amarok(11522) CurrentTrack::dataUpdated: CurrentTrack::dataUpdated
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const
QHash<QString, QVariant>&) - Took 0.017s
amarok:      adding album  "Jaktens tid"
amarok:      adding album  "Midnattens Widunder"
amarok:      adding album  "Nattfödd"
amarok:      adding album  "Ur Jordens Djup"
amarok:      adding album  "Visor Om Slutet"
amarok: END__: void CurrentEngine::update() - Took 0.082s
amarok: END__: virtual void CurrentEngine::message(const
Context::ContextState&) - Took 0.082s
amarok: BEGIN: virtual void
Playlist::Model::engineStateChanged(Phonon::State, Phonon::State)
amarok:    Phonon currentState:  2
amarok:    Phonon oldState:  2
amarok:    Successfully played track. Resetting failure count.
amarok: END__: virtual void
Playlist::Model::engineStateChanged(Phonon::State, Phonon::State) -
Took 6.2e-05s
amarok: BEGIN: virtual void
Amarok::StatusBar::engineStateChanged(Phonon::State, Phonon::State)
amarok:    PlayingState: clear text
amarok: END__: virtual void
Amarok::StatusBar::engineStateChanged(Phonon::State, Phonon::State) -
Took 0.00019s
amarok: BEGIN: virtual void Playlist::Model::engineNewTrackPlaying()
amarok:    [WARNING!] engineNewTrackPlaying:: MISS
amarok: BEGIN: void Playlist::Model::setActiveRow(int)
amarok:      refreshing  "Svart Djup"
amarok:      refreshing  "Svart Djup"
amarok: END__: void Playlist::Model::setActiveRow(int) - Took 0.00058s
amarok: END__: virtual void Playlist::Model::engineNewTrackPlaying() -
Took 0.00064s
amarok: BEGIN: virtual void ScrobblerAdapter::engineNewTrackPlaying()
amarok:   [lastfm] scrobble:  "Finntroll"  -  "Visor Om Slutet"  -
"Svart Djup"
BEGIN: void ScrobblerManager::scrobble(TrackInfo)
  "Finntroll &#8211; Svart Djup"
amarok:   [lastfm] Wrote 1 tracks to
"/home/acc/.kde4.1/share/apps/amarok/acc_submissions.xml"
  BEGIN: void ScrobblerManager::scrobble(const ScrobbleCache&)
    "acc"
    BEGIN: int Scrobbler::submit(const ScrobbleCache&)
      "Finntroll &#8211; Svart Djup"
      BEGIN: void ScrobblerPostRequest::request(const QByteArray&)
        "[id:"
        "0"
        "93"
        "s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a[0]=Finntroll&t[0]=Svart%20Djup&i[0]=1218110606&o[0]=P&r[0]=&l[0]=238&b[0]=Visor%20Om%20Slutet&n[0]=&m[0]="
amarok:   [lastfm] POST:
"s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a[0]=Finntroll&t[0]=Svart%20Djup&i[0]=1218110606&o[0]=P&r[0]=&l[0]=238&b[0]=Visor%20Om%20Slutet&n[0]=&m[0]="
      END:   void ScrobblerPostRequest::request(const QByteArray&)
[elapsed: 0 ms]
    END:   int Scrobbler::submit(const ScrobbleCache&) [elapsed: 0 ms]
amarok:   [lastfm] statusChanged: statusCode= 2
  END:   void ScrobblerManager::scrobble(const ScrobbleCache&) [elapsed: 0 ms]
END:   void ScrobblerManager::scrobble(TrackInfo) [elapsed: 1 ms]
amarok:   [lastfm] nowPlaying:  "Finntroll"  -  "Visor Om Slutet"  -
"Svart Djup"
BEGIN: void ScrobblerManager::nowPlaying(const TrackInfo&)
  "Finntroll &#8211; Svart Djup"
  BEGIN: void Scrobbler::announce(const TrackInfo&)
    "Finntroll &#8211; Svart Djup"
    BEGIN: void ScrobblerPostRequest::request(const QByteArray&)
      "[id:"
      "0"
      "93"
      "s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a=Finntroll&t=Svart%20Djup&b=Visor%20Om%20Slutet&l=238&n=&m="
    END:   void ScrobblerPostRequest::request(const QByteArray&)
[elapsed: 0 ms]
  END:   void Scrobbler::announce(const TrackInfo&) [elapsed: 0 ms]
END:   void ScrobblerManager::nowPlaying(const TrackInfo&) [elapsed: 0 ms]
amarok: END__: virtual void ScrobblerAdapter::engineNewTrackPlaying()
- Took 0.00073s
amarok: BEGIN: virtual void Amarok::StatusBar::engineNewTrackPlaying()
amarok: END__: virtual void Amarok::StatusBar::engineNewTrackPlaying()
- Took 0.00016s
amarok: BEGIN: void Playlist::Model::requestNextTrack()
amarok: BEGIN: void Playlist::Model::setNextRow(int)
amarok: END__: void Playlist::Model::setNextRow(int) - Took 6.5e-05s
amarok: END__: void Playlist::Model::requestNextTrack() - Took 0.00015s
amarok: [lastfm] ScrobblerHttp(0x2369200)
BEGIN: void Scrobbler::onSubmissionReturn(const QString&)
  "[id:"
  "0"
  "]"
amarok: [lastfm] Scrobbler HTTP error: 0
amarok: [lastfm] Scrobbler hard failure. Retrying in 30 seconds.
END:   void Scrobbler::onSubmissionReturn(const QString&) [elapsed: 0 ms]
amarok: [lastfm] POST:
"s=d54b37f9655d43c9ba6d3ddd6f1d01c3&a=Finntroll&t=Svart%20Djup&b=Visor%20Om%20Slutet&l=238&n=&m="
amarok: [lastfm] onNowPlayingReturn: [id: 0 ] "OK"


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

More information about the Amarok-devel mailing list