Bug 183518 - Last played track of a playlist is not correctly scrobbled to last.fm
Summary: Last played track of a playlist is not correctly scrobbled to last.fm
Status: RESOLVED DUPLICATE of bug 167489
Alias: None
Product: amarok
Classification: Applications
Component: general (show other bugs)
Version: 2.0.1
Platform: unspecified Linux
: NOR normal
Target Milestone: ---
Assignee: Amarok Developers
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-02-07 06:22 UTC by Daniel Mlot
Modified: 2009-03-17 15:03 UTC (History)
4 users (show)

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


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Daniel Mlot 2009-02-07 06:22:00 UTC
Version:           2.0.1 (using 4.1.4 (KDE 4.1.4), 4.1.4-2.fc10 Fedora)
Compiler:          gcc
OS:                Linux (i686) release 2.6.27.12-170.2.5.fc10.i686

The last track of any playlist is not properly scrobbled to last.fm, and ends up not getting stored under the user profile. 

How to reproduce: Set up a playlist of any length in Amarok and play it with the last.fm "plugin" running and properly configured. Then, open the user last.fm profile in a web browser and monitor the submission of the tracks.

Expected behaviour: As soon as a track is loaded, it should be displayed as "Listening Now" under the "Recently Listened Tracks" list. When the track finishes, it should be permanently stored at the list.

Observed behaviour: Scrobbling of all tracks but the very last one works fine. The last track gets shown at "Recently Listened Tracks" as "Listening Now" while it is playing. Once it and the playlist end, however, it vanishes from "Recently Listened Tracks" instead of staying there.

Additional info: It was mentioned (at some last.fm support forum if I remember correctly) that this issue could be caused by Amarok not submitting the "track end" signal to last.fm for the last track. That does seem to be the case, judging from the following console logs, obtained after playing two tracks in a playlist (the first one got scrobbled correctly, the second one not):

amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::setMrl: "file:///mnt/sechlf/Music%20Library/80s/Waterboys%20-%20This%20Is%20The%20Sea.mp3" ,  1
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  MrlChanged                                     
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::createStream: MediaObject is connected to  1  nodes                                            
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::createStream: creating xine_stream with null video port                                        
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::createStream: XINE_PARAM_EARLY_FINISHED_EVENT: 1                                               
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: calling xineOpen from MrlChanged                                                        
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::xineOpen: xine_open succeeded for m_mrl = file:///mnt/sechlf/Music%20Library/80s/Waterboys%20-%20This%20Is%20The%20Sea.mp3                                                                                                                                 
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::getStreamInfo: available titles changed:  0                                                    
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::getStreamInfo: available chapters changed:  0                                                  
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::getStreamInfo: available angles changed:  0                                                    
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::getStreamInfo: available angles changed:  0                                                    
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::getStreamInfo: available angles changed:  1                                                    
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::xineEventListener: XINE_EVENT_UI_CHANNELS_CHANGED
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::xineEventListener: XINE_EVENT_UI_CHANNELS_CHANGED
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  UiChannelsChanged
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: current angle changed:  0
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: current chapter changed:  0
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: current title changed:  0
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  UiChannelsChanged
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::play:  PLAY
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  PlayCommand
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::startToFakeBuffering:  start faking
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::startToFakeBuffering: fake state change: reached BufferingState after  0
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::handleAvailableTitlesChanged: 0
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::handleStateChange:  end faking
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::handleStateChange: reached  2  after  3
HTTP POST: "http://post.audioscrobbler.com:80/np_1.2&a=The%20Waterboys&t=This%20Is%20the%20Sea&b=This%20Is%20The%20Sea&l=391&n=0&m="
"OK"
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::emitAboutToFinish: emitting prefinishMarkReached( 2072 )
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  MediaFinished
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: MediaFinishedEvent m_useGaplessPlayback =  true
QString::arg: Argument missing: Amarok - No track playing., 0:00
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  GaplessSwitch
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: GaplessSwitch new m_mrl = file:///mnt/sechlf/Music%20Library/Etc%20Rock/Santana%20-%20Soul%20Sacrifice.mp3
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::xineEventListener: XINE_EVENT_UI_CHANNELS_CHANGED
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::xineEventListener: XINE_EVENT_UI_CHANNELS_CHANGED
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  UiChannelsChanged
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  UiChannelsChanged
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::emitTick: no useful time information available. skipped.
QString::arg: Argument missing: Amarok - No track playing., 0:00
QString::arg: Argument missing: Amarok - No track playing., 0:00
HTTP POST: "http://post2.audioscrobbler.com:80/protocol_1.2&a[0]=The%20Waterboys&t[0]=This%20Is%20the%20Sea&i[0]=1233975153&o[0]=P&r[0]=&l[0]=391&b[0]=This%20Is%20The%20Sea&n[0]=0&m[0]="
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::emitTick: no useful time information available. skipped.
"OK"
HTTP POST: "http://post.audioscrobbler.com:80/np_1.2&a=Carlos%20Santana&t=Soul%20Sacrifice&b=Aniversario&l=398&n=0&m="
"OK"
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::emitTick: emitting prefinishMarkReached( 2045 )
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  MediaFinished
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: MediaFinishedEvent m_useGaplessPlayback =  true
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: ################################ Event:  GaplessSwitch
amarok(8418)/phonon (xine backend) Phonon::Xine::XineStream::event: no GaplessSwitch
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::handleStateChange: reached  1  after  2
amarok(8418)/phonon (xine backend) Phonon::Xine::MediaObject::handleFinished: emit finished()
QString::arg: Argument missing: Amarok - No track playing., 0:00
QString::arg: Argument missing: Amarok - No track playing., 0:00

Note that data is sent to last.fm ("HTTP POST...") after the first track ends (messages "Argument missing: Amarok - No track playing., 0:00"), but there is nothing like it after the second track ends.
Comment 1 Mark Kretschmann 2009-02-07 08:27:09 UTC
I've heard about this issue before, but it might be fixed in SVN. I'm not sure.

Leo, Dan?
Comment 2 Dan Meltzer 2009-02-07 16:11:16 UTC
This is related to the other enginecontroller issues.... phonon is not properly entering StoppedState at the end of the queue, so we never find out that the track has finished.  
Comment 3 Mark Kretschmann 2009-02-07 16:24:23 UTC
Confirming then, based on Dan's comment.
Comment 4 Casey Link 2009-02-14 13:42:11 UTC
I can confirm this bug. It's annoying.
Comment 5 Casey Link 2009-02-14 13:47:08 UTC
I'm going to hijack this bug, because I believe the underlying issue is the same. The last track in a playlist never reaches the finished state (hence no scrobble). Here's some debug output. amarok(29182) Phonon::Xine::XineStream::emitAboutToFinish: emitting prefinishMarkReached( 2139 ) amarok(29182) Phonon::Xine::XineStream::event: ################################ Event: MediaFinished amarok(29182) Phonon::Xine::XineStream::event: MediaFinishedEvent m_useGaplessPlayback = true amarok: BEGIN: void EngineController::slotAboutToFinish() amarok: [EngineController] Track finished completely, updating statistics 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.00015s amarok: tmpWikiStr: "The Killers (band)" amarok: Same entry requested again. Ignoring. amarok: END__: void WikipediaEngine::update() - Took 0.00068s amarok: END__: virtual void WikipediaEngine::metadataChanged(Meta::TrackPtr) - Took 0.0011s 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.00033s amarok: END__: virtual void Amarok::OSD::metadataChanged(Meta::TrackPtr) - Took 0.025s amarok: BEGIN: virtual void MainWindow::metadataChanged(Meta::TrackPtr) amarok: END__: virtual void MainWindow::metadataChanged(Meta::TrackPtr) - Took 0.00033s amarok: BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) amarok: END__: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.00058s 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.00015s amarok: END__: virtual void Amarok::OSD::metadataChanged(Meta::TrackPtr) - Took 0.0012s amarok: BEGIN: virtual void WikipediaEngine::metadataChanged(Meta::TrackPtr) amarok: BEGIN: void WikipediaEngine::update() amarok: BEGIN: bool EngineController::isStream() amarok: END__: bool EngineController::isStream() - Took 8.5e-05s amarok: tmpWikiStr: "The Killers (band)" amarok: Same entry requested again. Ignoring. amarok: END__: void WikipediaEngine::update() - Took 0.00038s amarok: END__: virtual void WikipediaEngine::metadataChanged(Meta::TrackPtr) - Took 0.0006s amarok: BEGIN: virtual void MainWindow::metadataChanged(Meta::TrackPtr) amarok: END__: virtual void MainWindow::metadataChanged(Meta::TrackPtr) - Took 0.00017s amarok: BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) amarok: END__: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.00038s amarok: BEGIN: void Playlist::Actions::play(quint64, bool) amarok: [Playlist::Actions] [WARNING!] Invalid trackid 0 amarok: END__: void Playlist::Actions::play(quint64, bool) - Took 0.00013s amarok: END__: void EngineController::slotAboutToFinish() - Took 0.07s 
Comment 6 Casey Link 2009-02-14 13:48:04 UTC
That last debug paste was totally unreadable.. lets try again.


amarok(29182) Phonon::Xine::XineStream::emitAboutToFinish: emitting prefinishMarkReached( 2139 )
amarok(29182) Phonon::Xine::XineStream::event: ################################ Event:  MediaFinished
amarok(29182) Phonon::Xine::XineStream::event: MediaFinishedEvent m_useGaplessPlayback =  true       
amarok: BEGIN: void EngineController::slotAboutToFinish()                                            
amarok:   [EngineController] Track finished completely, updating statistics                          
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.00015s                                     
amarok:        tmpWikiStr:  "The Killers (band)"                                                     
amarok:        Same entry requested again. Ignoring.                                                 
amarok: END__: void WikipediaEngine::update() - Took 0.00068s                                        
amarok: END__: virtual void WikipediaEngine::metadataChanged(Meta::TrackPtr) - Took 0.0011s          
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.00033s                          
amarok: END__: virtual void Amarok::OSD::metadataChanged(Meta::TrackPtr) - Took 0.025s               
amarok: BEGIN: virtual void MainWindow::metadataChanged(Meta::TrackPtr)                              
amarok: END__: virtual void MainWindow::metadataChanged(Meta::TrackPtr) - Took 0.00033s              
amarok: BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr)                         
amarok: END__: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.00058s         
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.00015s                          
amarok: END__: virtual void Amarok::OSD::metadataChanged(Meta::TrackPtr) - Took 0.0012s              
amarok: BEGIN: virtual void WikipediaEngine::metadataChanged(Meta::TrackPtr)                         
amarok: BEGIN: void WikipediaEngine::update()                                                        
amarok: BEGIN: bool EngineController::isStream()                                                     
amarok: END__: bool EngineController::isStream() - Took 8.5e-05s                                     
amarok:        tmpWikiStr:  "The Killers (band)"                                                     
amarok:        Same entry requested again. Ignoring.                                                 
amarok: END__: void WikipediaEngine::update() - Took 0.00038s                                        
amarok: END__: virtual void WikipediaEngine::metadataChanged(Meta::TrackPtr) - Took 0.0006s          
amarok: BEGIN: virtual void MainWindow::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void MainWindow::metadataChanged(Meta::TrackPtr) - Took 0.00017s
amarok: BEGIN: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr)
amarok: END__: virtual void Playlist::Model::metadataChanged(Meta::TrackPtr) - Took 0.00038s
amarok: BEGIN: void Playlist::Actions::play(quint64, bool)
amarok:     [Playlist::Actions] [WARNING!] Invalid trackid 0
amarok: END__: void Playlist::Actions::play(quint64, bool) - Took 0.00013s
amarok: END__: void EngineController::slotAboutToFinish() - Took 0.07s
Comment 7 Bram Schoenmakers 2009-03-17 15:03:19 UTC

*** This bug has been marked as a duplicate of bug 167489 ***