Rockbox

Tasklist

FS#8206 - Resuming playback from end of song after power on confuses playback

Attached to Project: Rockbox
Opened by Richard Sweeney (riksweeney) - Wednesday, 21 November 2007, 19:31 GMT
Last edited by Andree Buschmann (Buschel) - Wednesday, 06 April 2011, 19:22 GMT
Task Type Bugs
Category Music playback
Status Closed
Assigned To Nicolas Pennequin (nicolas_p)
Operating System All players
Severity Low
Priority Normal
Reported Version Daily build (which?)
Due in Version Version 3.1
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Resuming playback of a song that is a few seconds from ending after the player has been powered on confuses the playback.

The simplest way to reproduce this behaviour is to do the following (this works in the simulator too).

Select a song to play and let it play almost to the very end, make sure that another song is in the playlist to be played afterwards.

A few seconds before the end of the song, stop the playback and then shutdown Rockbox.

Start up Rockbox and resume playback. The playback will continue from half to three quarters of the way through the following song on the playlist.

This appears to be buffer related as fast forwarding to the end of the song, shutting down and resuming will not produce this behaviour.
This task depends upon

Closed by  Andree Buschmann (Buschel)
Wednesday, 06 April 2011, 19:22 GMT
Reason for closing:  Fixed
Additional comments about closing:  Fixed with r29682.
Comment by Nicolas Pennequin (nicolas_p) - Tuesday, 27 November 2007, 16:35 GMT
This seems to be another manifestation of the issue causing  FS#2687 ... I think the problem is that you shut down the player in the middle of a track transition.
Comment by Richard Sweeney (riksweeney) - Tuesday, 27 November 2007, 18:26 GMT
I think it is too, a fairly old build that I use at the moment doesn't exhibit this behaviour so I might download that revision and examine it. It's revision 15812 if you're interested...
Comment by Richard Sweeney (riksweeney) - Tuesday, 27 November 2007, 18:44 GMT
Oops, tell a lie, it's 13742
Comment by Steve Bavin (pondlife) - Wednesday, 28 November 2007, 12:02 GMT
Does it still happen with 15841 or later?
Comment by Richard Sweeney (riksweeney) - Wednesday, 28 November 2007, 21:57 GMT
Unfortunately yes, the resuming problem still exists. I have noticed however that simply stopping at the end of the song and resuming playback will also cause this problem.

What I did notice though, is that in apps/playback.c, changing

return &prevtrack_id3;

to

return &curtrack_id3;

on line 525 fix this problem, but the WPS information changes prematurely. I only noticed this because I'd been tinkering with the source code...
Comment by Steve Bavin (pondlife) - Thursday, 29 November 2007, 09:11 GMT
The external interfaces to playback.c generally use the "WPS track" rather than the "codec track" transition point and resulting track name and offset (which is a good thing for keeping the UI correct).

audio_current_track() does this, as do the calls to playlist_update_resume_info(). However, when resuming we have an offset passed in to audio_play which is assumed to be based on the "codec track". I can't think of a way for audio_play() to convert a "WPS offset" into a "codec offset", which would be more correct.

Perhaps instead we should base the resume point on the "codec track/offset"?

One other point - shouldn't codec_get_file_pos() should use the "codec track" (i.e not rely on audio_current_track(), maybe just curtrack_id3 would do)?
Comment by Richard Sweeney (riksweeney) - Wednesday, 02 January 2008, 15:57 GMT
OK, I've been having a root through the code and have more or less found the problem (IMHO). When the playback enters the transition phase, the playlist index is incremented which means that if you press stop during this period then the resume index will be off by 1. This basically means it'll play the following track using the current track's offset which on the simulator can cause segfaults.

I did code a solution by passing in the transition state into playlist_update_resume_info, but it was messy and hacky. I guess I could add another variable to the mp3entry structure and then tell playlist_update_resume_info in playlist.c to use the previous, rather than the current index of the playlist when saving the resume info.

Something like:

int playlist_update_resume_info(const struct mp3entry* id3)
...
global_status.resume_index = id3->transition == 1 ? playlist->index - 1 : playlist->index;
global_status.resume_offset = id3->offset;
status_save();
...

Bit of a mess though
Comment by Richard Sweeney (riksweeney) - Thursday, 03 January 2008, 19:57 GMT
OK, here's a patch based upon the pseudo code I wrote. It appears to work OK but I really need to test it more.

Comment by Alexander Levin (fml2) - Friday, 04 January 2008, 08:09 GMT
Why did you introduce a new field in the mp3 struct? IMHO the transition status is something that is 'global' and doesn't belong to a particular track. I.e. it should be a global state var. I don't know where it's placed best though.
Comment by Steve Bavin (pondlife) - Friday, 04 January 2008, 08:25 GMT
I'd prefer the transition to be entirely hidden. The playlist->index shouldn't be incremented until the transition is completed (i.e. the WPS has moved on rather than when the codec has moved on). Similar should be true for all variables accessible outside of playback.c.

That sound you hear is a can of worms being opened. ;)
Comment by Richard Sweeney (riksweeney) - Friday, 04 January 2008, 09:51 GMT
True, it should probably be a global variable instead, I'm still trying to get my head around the code at the moment. Steve's suggestion of making the playlist increment would probably solve the related problem of "rewinding at the end of a song will rewind the following song rather than the current" as well.

I'll have a look into making the variable global instead.
Comment by Steve Bavin (pondlife) - Friday, 04 January 2008, 10:20 GMT
"transition" should NOT be global, it should be only available within playback.c. Where it's used elsewhere, there's probably playback API that could be used instead (e.g. to get the current track).
Comment by Nicolas Pennequin (nicolas_p) - Friday, 04 January 2008, 12:03 GMT
I once tried moving the playlist index incrementation to after the track transition (it's in the SVN history), but it broke auto folder advance. I guess we could go back to what I had done and then fix the folder advance.
Comment by Steve Bavin (pondlife) - Friday, 04 January 2008, 12:19 GMT
Go for it! ;)
Comment by Nicolas Pennequin (nicolas_p) - Friday, 04 January 2008, 15:57 GMT
This patch is an attempt to handle the playlist updating at the right time, i.e. after the track transition for most skips, but before it for manual skips or automatic dir change skips.
I haven't checked if it solves the actual issue described by this task, but I think it will.
Comment by Richard Sweeney (riksweeney) - Friday, 04 January 2008, 17:21 GMT
Thanks for the patch, I'll have a look at it when I get in after the pub^H^H^H^H^Hwork
Comment by Nicolas Pennequin (nicolas_p) - Friday, 04 January 2008, 17:49 GMT
I just tested and the original issue looks fixed. Please confirm and I'll commit :)
Comment by Richard Sweeney (riksweeney) - Saturday, 05 January 2008, 09:23 GMT
Cool, this appears to have solved the problem, I've only tried it on the simulator but I will put this on my iRiver H120 shortly and see how I get on.
Comment by Richard Sweeney (riksweeney) - Saturday, 05 January 2008, 11:55 GMT
Actually, it looks like there is a problem with the playback. While I was playing an album it played the same song twice after a short hesitation. It only did it once but I'll test it on the simulator and see if I can make it do it again.
Comment by Nicolas Pennequin (nicolas_p) - Sunday, 06 January 2008, 19:46 GMT
Anything new here?
Comment by Richard Sweeney (riksweeney) - Sunday, 06 January 2008, 21:33 GMT
I haven't managed to make it play the same track again so I'm not sure what the problem was. The only other issue I noticed was that stopping during the transition and restarting will resume playback from before where the transition started, or maybe a couple of seconds before that, but it doesn't happen on the simulator (I'm using an iRiver H120). Apart from these two issues I haven't seen anything where the playback corrupts or crashes.
Comment by Nicolas Pennequin (nicolas_p) - Sunday, 06 January 2008, 23:03 GMT
Well I guess I'll commit and wait for the bug reports :)
Comment by Nicolas Pennequin (nicolas_p) - Monday, 07 January 2008, 09:13 GMT
Changing playlist_check() had undesirable side-effects. This new version takes a slightly different approach.
Comment by Brian Hall (brihall) - Monday, 07 January 2008, 15:44 GMT
I've seen a problem similar to this, I added my comment (copied below) to  FS#6215 .

The reason I think I might be seeing this problem is because after listening to a podcast, I will typically stop playback while the host is making his closing remarks, a few seconds before the end of the file. Then I delete the podcast via rockbox and power off. On power on, rockbox tries to resume the podcast and hangs.


-------------------from  FS#6215 :

I see this frequently with podcasts- I will listen to one, delete it via rockbox, and on the next power-up it hangs when trying to resume the file. It looks like it is selecting the next file, but resuming at the position of the last (deleted) file. In the case of podcasts, the new file might be significantly shorter than the previous, maybe trying to resume far enough after the end of a file causes a hang?

The only way I've found to fix this once it occurs is to delete the playlist control file from a PC connection (reset doesn't help).

Player is a H320. I've seen this problem on multiple builds over the last 3-4 months. Currently running r15989-080103.
Comment by Marc Guay (Marc_Guay) - Thursday, 17 April 2008, 23:52 GMT
e200 + r17153 = The first time it displayed a lovely cabbiev2 smear across the screen and required a hard shutdown (something I saw randomly earlier today). The second time it did as described in the original report (playing next track 2/3 the way through).
Comment by Marc Guay (Marc_Guay) - Sunday, 13 July 2008, 01:14 GMT
e200 + r18013 = Still happening.
Comment by Jonas Häggqvist (rasher) - Thursday, 11 December 2008, 03:45 GMT
Not that I'm aware of any work specifically on this bug, but since it's been 5 months - does this happen with a recent build?
Comment by Frank Gevaerts (fg) - Thursday, 11 December 2008, 21:21 GMT
I think I saw this happen a few days ago on my F60 with r19364
Comment by Boris Gjenero (dreamlayers) - Thursday, 05 March 2009, 02:44 GMT
With unmodified r20205 if I stop at the very end of a track (0 s remaining), playback can resume later on in the next track. I can repeatably do this at one track change. Both tracks were in MP3 format. The first track was a smaller file with longer duration. The resume point in the second track may correspond to the file offset of the end of the first file. Attempts to cause problems where the first file is larger didn't succeed.

I was unable to reproduce the problem with r20205 and a resynched and slightly modified playlist_index.patch. However, I got a track to play twice, both for it and its successor, so I guess I shouldn't attach a patch.

If BUFFERING_DEFAULT_FILECHUNK in apps/buffering.c is increased, resuming near the end of a track causes a bigger problem. Audio output just loops one short bit, and playback continues past the end instead of switching tracks. The bit being looped changes once around when the track should end and then it stays the same. Time keeps incrementing, and time remaining goes negative and keeps decrementing (eg. -3:-46). I haven't seen a crash yet, and I can press next track to go to the next track. I am unable to reproduce this problem with the current value of BUFFERING_DEFAULT_FILECHUNK (32k), but if I set it to 256k it happens every time I resume within 10 s or so of the end. Yes, I know the fact I can't reproduce this with unmodified SVN code may make the problem seem unimportant, but I think it is a race condition which needs to be fixed. It still happens with playlist_index-r20205.patch.

This was on a 30GB 5G iPod.
Comment by Thomas Martitz (kugel.) - Monday, 16 March 2009, 16:16 GMT
I'm wondering if http://www.rockbox.org/tracker/task/9795 does any good regarding this bug. It aims to rework the playback-wps-interdependence, particularly w.r.t to track transition.
Comment by Boris Gjenero (dreamlayers) - Monday, 16 March 2009, 17:26 GMT
I applied playback_changes.8c.diff ( FS#9795 ) to r20235 and tested on my 5G 30GB iPod. One chunk was rejected in apps/plugin.h.rej and minor changes were needed in apps/iap.c.
I was easily able to pause with 0 seconds remaining and resume later on in the next track
With BUFFERING_DEFAULT_FILECHUNK set to (1024*256) and a shuffled playlist with 247 MP3 files, after a resume I was easily able to get looping audio and playback continuing past end of file.
Comment by Boris Gjenero (dreamlayers) - Tuesday, 17 March 2009, 00:28 GMT
Here's a fix for the endless repeating audio that happens when BUFFERING_DEFAULT_FILECHUNK is increased. When seeking forward beyond the end of available data, but within one FILECHUNK of the end, h->ridx was being calculated improperly. This does not fix the resume with 0 seconds left issue.
Comment by Thomas Martitz (kugel.) - Tuesday, 17 March 2009, 00:45 GMT
Thanks for the patch, it looks good.

RE:  FS#9795 , it wasn't quite clear. Did you actually say: Yes, it appears to fix the problem?
Comment by Boris Gjenero (dreamlayers) - Tuesday, 17 March 2009, 00:59 GMT
r20235 + playback_changes.8c.diff did not fix either issue
r20238 + long_buffering_filechunk_resume_errors.patch + playback_changes.8c.diff doesn't fix the resume with 0 seconds left issue
It's easy to reproduce the issue with the 5G iPod simulator. You just need two MP3 files. Put the one with smaller file size first in the playlist. Pause with 0 seconds left in the first file. When you resume, you'll end up with something like this on standard output:
Resume index 1 offset 5AE37E
Playback will start at that offset in the second file, instead of at the end of the first file or the beginning of the second file.
Comment by Thomas Martitz (kugel.) - Tuesday, 17 March 2009, 01:04 GMT
Does this only happen with 0 seconds left, or also with 1 or 2 (or even 3)?

Steve already mentioned it: The codec is always a bit advanced. The codec changed already when the wps the audio output is still in the old song. This is due to buffering the pcm data.

 FS#9795  aims to add a proper event on track change (not the codec track change). It might be that we only need to listen to that event in the playlist and nvram.bin code too.

PS: I haven't really looked into this issue yet, I'm just having random ideas. I'm pretty much only guessing.
Comment by Boris Gjenero (dreamlayers) - Tuesday, 17 March 2009, 01:34 GMT
If I pause within 2 seconds of end of track, the WPS changes:
With an unmodified r20238 5G iPod sim, there is a brief flash of the next track and time 0:00 on the whole WPS
With r20238 + playback_changes.8c.diff, "Next Track:" becomes the current track
In both cases, after that point, displayed track is 2 of 2 instead of 1 of 2.
If I stop after that happens, a resume will be into track 2, with the saved offset from track 1.
Comment by Thomas Martitz (kugel.) - Tuesday, 17 March 2009, 01:36 GMT
You mean  FS#9795  shows the next track as current one too early? That would be a bug in that patch, then.
Comment by Boris Gjenero (dreamlayers) - Tuesday, 17 March 2009, 03:08 GMT
Sorry, I keep saying things which can have multiple meanings. Clarifications:

>With an unmodified r20238 5G iPod sim, there is a brief flash of the next track and time 0:00 on the whole WPS
Near the end of track 1, I briefly see ID3 info (ie. track name, artist, etc.) for track 2. During that brief period, I also see a blank time bar and a track time of 0:00. After this, everything except the track number goes back to being correct. The track number is 2 when it should be 1 because track 1 is still playing.
This seems to imply that after curtrack_id3 has been updated to the next track, the WPS sees it. The WPS should instead see prevtrack_id3.

>With r20238 + playback_changes.8c.diff, "Next Track:" becomes the current track
On the WPS, text displayed after "Next Track:" becomes the current track. The ID3 info for the current track is always correct.
(There is no flash of track 2 info near the end of track 1.)

>In both cases, after that point, displayed track is 2 of 2 instead of 1 of 2.
Track 1 is near the end, but it is still playing. However, the WPS says that I am on track 2.
(This seems to come from playlist_get_display_index(), and  FS#9795  doesn't seem to affect it.)
Comment by Thomas Martitz (kugel.) - Tuesday, 17 March 2009, 03:21 GMT
Ok, thanks. This seems to prove my assumption, that  FS#9795  doesn't touch playlist code enough (yet).
"On the WPS, text displayed after "Next Track:" becomes the current track. The ID3 info for the current track is always correct." This seems to be a remaining bug in  FS#9795 .

But anyway, it seems that  FS#9795  doesn't help for this problem (yet, I still think it possibly could), so let's not pollute this task about it further, except you have some findings of course.
Comment by Boris Gjenero (dreamlayers) - Tuesday, 17 March 2009, 06:25 GMT
With playlist_index-v2.patch, if I skip to the next track within about 2 seconds of the end of a track, the next track becomes a copy of the current track. By that I mean same music, same ID3 info in WPS and the name is even overwritten in the playlist viewer. It's then possible to skip back and forth between the two copies.

Without the patch, if I skip to the next track within about 2 seconds of the end, I end up skipping two tracks. This is still wrong but it is better because the playlist is not corrupted.
Comment by Jonathan Gordon (jdgordon) - Tuesday, 17 March 2009, 07:09 GMT
re skipping 2 tracks at the end of the track... it *should* be possible to catch this when it happens and for the moment just ignore the skip request... <2s is no big deal (later we can think about actually skipping in PCM to the correct spot), in my current sleepy state I cant see a clean way of doing that though
Comment by Steve Bavin (pondlife) - Tuesday, 17 March 2009, 07:21 GMT
I reiterate that only playback.c should care about the "codec transition" (internally). All other code (UI, playlist, bookmarks, any saved resume point) should only use the "PCM/UI transition". Currently a mixture is used - this is (probably) the fundamental problem here.

I don't think use of events alone will fix this. I'd suggest that all variables which store a track position/offset are (at least) commented to mark which transition they are based on, so we know the scale of the work.

long_buffering_filechunk_resume_errors.patch ought to be commmitted.

Comment by Boris Gjenero (dreamlayers) - Saturday, 28 March 2009, 14:52 GMT
It seems like advancing h->ridx past h->widx can lead to a problem in prep_bufdata, where "avail = RINGBUF_SUB(h->widx, h->ridx)". If h->ridx passes h->widx, this makes it appear that a lot of data is available, when in fact no data is available. Because of this, long_buffering_filechunk_resume_errors.patch does not fully fix the case it is supposed to fix. There might also be a problem when only moving the handle struct in shrink_handle: "delta = RINGBUF_SUB(h->ridx, h->data)" can advance the handle past h->widx.
Comment by Thomas Martitz (kugel.) - Monday, 06 April 2009, 04:06 GMT
Is this still happening? I cannot reproduce. Stopping within the last 2 seconds doesn't case the wrong track to be resumed anymore here.
Comment by Boris Gjenero (dreamlayers) - Monday, 06 April 2009, 04:27 GMT
I can reproduce with r20635. After stopping within the last 2 seconds of a track, the resume position can be later on in the next track. For this to be reproduced, the next track cannot be a smaller file. The file offset where playback stopped must be a valid offset within the second track.
Pressing next track within the last two seconds also skips two tracks (eg. track 1 to track 3).
Also, the track number increments about two seconds before the end of a track.
Comment by Thomas Martitz (kugel.) - Monday, 06 April 2009, 10:19 GMT
Ahh, ok, I guess my following track was shorter.

Loading...