Bug 299890

Summary: Bug #188330 is back: Playcount increased by 2 by "Stop Playing After Track"
Product: [Applications] amarok Reporter: Stefan Becker <chemobejk>
Component: PlaybackAssignee: Amarok Developers <amarok-bugs-dist>
Status: RESOLVED FIXED    
Severity: normal CC: dietrichmathias, edward.hades, matej, ralf-engels, sam, sitter, tdfischer
Priority: NOR Keywords: regression, release_blocker
Version: 2.5-git   
Target Milestone: 2.6   
Platform: Fedora RPMs   
OS: Linux   
Latest Commit: Version Fixed In: 2.6
Sentry Crash Report:
Attachments: Debug log when playcount is double-incremented
fix from master backported to 2.5.0
fix from master backported to 2.5.0
fix from master backported to 2.5.0 (V2)

Description Stefan Becker 2012-05-12 15:49:13 UTC
It seems that bug #188330 is back. I'm using Amarok 2.5.0 on KDE 4.8.3, QT 4.8.1, Fedora 17:

  kdelibs-4.8.3-1.fc17.x86_64
  qt-4.8.1-5.fc17.x86_64
  amarok-2.5.0-7.fc17.x86_64

I'm using a dynamic playllist and pulseaudio (if that matters)

How to reproduce:
   - initial state: stopped
   - note the Playcount of the current song (N)
   - press Play
   - Right mouse button on currently playing song and select "Stop Playing After Track"
   - shortly before song stops, playlist gets updated, i.e. the next song moves to the current position. Playcount of the currently played song gets increased to N+1
   - after playback has stopped: Playcount of the song gest increased to N+2
Comment 1 Myriam Schweingruber 2012-05-13 20:46:22 UTC
Confirmed with current 2.5-git
Comment 2 Ralf Engels 2012-05-29 19:03:45 UTC
For me the count even seemed to have increased by 3.
Strange...
Comment 3 Matěj Laitl 2012-06-13 11:40:02 UTC
(In reply to comment #0)
> How to reproduce:
>    - initial state: stopped
>    - note the Playcount of the current song (N)
>    - press Play
>    - Right mouse button on currently playing song and select "Stop Playing After Track"
>    - shortly before song stops, playlist gets updated, i.e. the next song moves to the current position. Playcount of the currently played song gets increased to N+1
>    - after playback has stopped: Playcount of the song gest increased to N+2

I cannot reproduce this with:
 * Amarok v2.5.90-47-ge357d4b, dynamic mode enabled
 * phonon 4.5.1-r1 + phonon-gstreamer 4.5.0 backend + gstreamer-0.10.35 + pulseaudio

Anyone who is able to still reproduce this (with current Amarok git) please make a similar report.
Comment 4 Matěj Laitl 2012-06-13 11:41:40 UTC
Setting to NEEDSINFO, dr_lepper is neither able to reproduce.
Comment 5 Sam Lade 2012-06-13 11:59:59 UTC
I can reproduce this. Current git versions of Amarok, Phonon and Phonon-GStreamer. GStreamer 0.10 from the Ubuntu repos. The dynamic playlist being enabled is not required to reproduce.
Comment 6 Sam Lade 2012-06-13 15:08:18 UTC
Update after further testing: I can also reproduce this with Phonon GStreamer 4.6.0 (the version currently shipped with Ubuntu) and with Phonon VLC (git version).
Comment 7 Edward Hades 2012-06-13 19:34:49 UTC
Could you please attach amarok debug output (`amarok -d`)?
Comment 8 Sam Lade 2012-06-13 19:56:38 UTC
Created attachment 71807 [details]
Debug log when playcount is double-incremented

This is a log from setting "stop playing after this track" until the track has stopped playing. I removed a little irrelevant cruft from ScanManager and so forth.

The aboutToFinish signal appears to be emitted twice, which I suspect is the cause.
Comment 9 Edward Hades 2012-06-14 09:16:46 UTC
Sam, thanks for the debug log.

Still can't reproduce; neither with phonon 4.5 nor with 4.6. Apparently there is something system-specific. We should probably get phonon guys to have a look at it.
Comment 10 Mathias Dietrich 2012-06-14 13:33:28 UTC
Cannot reproduce this issue with Phonon Gstreamer 4.6 and Amarok 2.5.90.
Comment 11 Myriam Schweingruber 2012-06-15 07:50:03 UTC
Subscribing the Phonon devs.
Comment 12 Harald Sitter 2012-06-15 10:52:00 UTC
slotAboutToFinish is called twice in comment 8

while that should probably not happen I'd argue that the signal is not discrete to begin with, in fact a backend that does not support volumefading or gapless playback might perhaps not even emit it, therefore it probably should not be used for that sort of thing (mind me: I think in phonon vlc the signals is reasonably certain emitted twice to ensure it is emitted at all)

stats and whatnot should only be updated on a state change to stopped/loading (assuming the previous state was not stopped/loading/error). those 2 (3) states are the non-playback states, whenever one goes from a playback state (playing/paused/buffering) to a non-playback state that is the discrete end of playback in phonon's world.

https://projects.kde.org/projects/kdesupport/phonon/phonon/repository/revisions/master/changes/doc/state-machine.svg

simply put abouttofinish is good for one thing and one thing only: queuing the next track so that the transition can be gapless.
Comment 13 Ralf Engels 2012-06-25 14:08:01 UTC
Harald: You seem to have found the problem:

EngineController::slotAboutToFinish()
        m_currentTrack->finishedPlaying( 1.0 ); // If we reach aboutToFinish, the track is done as far as we are concerned.

That will claim that the song has been completely played without really checking the time.
I was confused by the double count increase since the code does not regard a song to be played until it was played until the end, but that one would really explain it.

Now if somebody would just explain the state diagram to me.
Comment 14 Harald Sitter 2012-06-25 14:34:04 UTC
If only I could explain the state diagram ^^

Trever is the guy to ask.

Anyhow, a least invasive fix for Amarok may be listening to the sourceChanged signal, this signal only gets emitted when the internal source actually was changed, which is independent of queuing and the state of the pipeline altogether. Which might also make it a not exactly nice solution as the source change is not technically bound to a state, so it may appear when the backend already transited to playing or it may appear before it stopped, which might mess up certain expectations within other parts of Amarok.

The most appropriate solution would be to consider a statechange from Playing|Paused|Buffering to Stopped|Loading as end of the track (Error probably requiring special handling because in most cases no playback actually occurred). I am reasonable certain both backends at least obey this most basic case that when you switch sources you actually need to go from the playing superstate to the stopped superstate and back.
Comment 15 Ralf Engels 2012-06-26 12:28:53 UTC
The line came in with this commit:

commit e258d1a8ff17aa95c63454ad834c0b97ba8fc5b5
Author: Dan Meltzer <parallelgrapefruit@gmail.com>
Date:   Sun Feb 1 17:22:25 2009 +0000

    Fix calculation of statistics.
    
    Calculating statistics in slotNewTrackPlaying is a bad idea because trackPosition() is undefined in that case.  Instead we should calculate it in PlaylistActions before we start playing the next t
    BUG: 182025
    
    svn path=/trunk/extragear/multimedia/amarok/; revision=919847

I will try what happens if I do it correctly.
Comment 16 Matěj Laitl 2012-07-18 20:30:34 UTC
There is a proposed fix to this bug in https://git.reviewboard.kde.org/r/105524/ - you may want to test it and report whether it fixes the bug for you.
Comment 17 Stefan Becker 2012-07-20 12:35:34 UTC
Created attachment 72646 [details]
fix from master backported to 2.5.0

Matěj: I guess you meant https://git.reviewboard.kde.org/r/105610/

I backported this to amarok 2.5.0 and in my short testing the problem seems to be gone. Thanks.
Comment 18 Matěj Laitl 2012-07-20 12:47:38 UTC
Comment on attachment 72646 [details]
fix from master backported to 2.5.0


(In reply to comment #17)
> Matěj: I guess you meant https://git.reviewboard.kde.org/r/105610/

Yes, right, thanks for pointing it out.

> I backported this to amarok 2.5.0 and in my short testing the problem seems
> to be gone. Thanks.

Good.

> Created attachment 72646 [details]
> fix from master backported to 2.5.0

You don't need or should to port whole patch series, just the "EngineController: fix play count increased by 2 in some cases" patch, which is avaiable at git://anongit.kde.org/clones/amarok/laitl/amarok.git, branch enginecontroller-fixes.
Comment 19 Stefan Becker 2012-07-20 20:10:25 UTC
Created attachment 72651 [details]
fix from master backported to 2.5.0

*sigh* would I have known that, it would have saved me some work.

The changes in the patch are obviously fixing the problem, which my tests confirm. Thanks again.

Are you planning to backport this to 2.5.x branch?
Comment 20 Matěj Laitl 2012-07-21 07:59:46 UTC
(In reply to comment #19)
> Created attachment 72651 [details]
> fix from master backported to 2.5.0
> 
> *sigh* would I have known that, it would have saved me some work.

Sorry. If you see a branch name in my review request next time, it is a branch name in my personal clone mentioned above. http://quickgit.kde.org/?p=clones%2Famarok%2Flaitl%2Famarok.git&a=summary is the web interface, but it has some problems with updating itself lately.

> The changes in the patch are obviously fixing the problem, which my tests
> confirm. Thanks again.
> 
> Are you planning to backport this to 2.5.x branch?

No, we don't plan to release any 2.5.x versions. We do plan to release 2.6 soon that would contain this (or alternative) fix, however distributions may decide to back-port this to 2.5. I should note however that 2.5 has much more shortcomings compared to 2.6 and that we will prefer if distributions just moved to 2.6.
Comment 21 Matěj Laitl 2012-07-30 14:07:18 UTC
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 268892, 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
Comment 22 Stefan Becker 2012-08-04 15:14:06 UTC
Created attachment 72954 [details]
fix from master backported to 2.5.0 (V2)

I backported commits 824652cc & e1d2ea6c to 2.5.0. This also fixes the problem for me. It also seems that the incrementing behaves more sensible now, i.e. only when that track is finished does the counter increment, not 10-15 seconds before the end.
Comment 23 Stefan Becker 2012-08-04 18:49:12 UTC
Looks like this fixes also another issue: no longer duplicate notifications of played songs in the system tray. Yeah!