Rockbox

Tasklist

FS#8993 - Freeze on shutting down.

Attached to Project: Rockbox
Opened by Anthony Mercuri (cool_walking_) - Thursday, 15 May 2008, 10:45 GMT
Last edited by Bertrik Sikken (bertrik) - Wednesday, 04 June 2008, 15:09 GMT
Task Type Bugs
Category Operating System/Drivers
Status Closed
Assigned To No-one
Operating System iPod 5G
Severity Low
Priority Normal
Reported Version Daily build (which?)
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

When shutting down, Rockbox froze with the following message:

*PANIC*
event 257 not foun
d

overlaid on the main menu background image.

I'm using r17310-080503 on my iPod 5G with 100GB hard drive.

It's only happened to me twice, 2 weeks apart. I've been trying to reproduce it for the last hour on r17310-080503 without success, so I don't see the point trying to reproduce it with the current build (although I have now switched to the current build and will try to keep it updated and post here if it happens again).

On both occurrences there was music playing, and from the WPS I held PLAY down to shut it down. Rockbox switched to the main menu, as it usually does before shutting down, and then it froze with the message. The first time it happened the file playing was an MP3, the second time it was Ogg Vorbis. The two files have always played back fine i.e. they don't appear to have any glitches. The characters in the tags are all "normal" characters [A-Za-z ]
This task depends upon

Closed by  Bertrik Sikken (bertrik)
Wednesday, 04 June 2008, 15:09 GMT
Reason for closing:  Fixed
Additional comments about closing:  Closed because problem has no longer been reported since a fix was made a week ago.
Comment by Peter D'Hoye (petur) - Thursday, 15 May 2008, 22:21 GMT
Also seen once on h300

From first looks this appears to be some glitch where probably the audio thread is stopping playback while the rest is performing shutdown. If shutdown is a bit faster the thread tries to clean up something that isn't there anymore.
Comment by Bertrik Sikken (bertrik) - Thursday, 15 May 2008, 22:36 GMT
Event 257 is DISK_EVENT_SPINUP, this event is removed in unregister_ata_idle_func, which is only called from scrobbler_shutdown as far as I can see. This problem can be caused by multiple calls to function scrobbler_shutdown. An obvious simple fix is to prevent the double un-initialisation, see attached patch (compiles, but is untested).
Perhaps more interesting would be to find out why the scrobbler_shutdown function is called multiple times and if this should be allowed.
Comment by Bertrik Sikken (bertrik) - Thursday, 15 May 2008, 23:04 GMT
Patch above committed in r17533. If you suffered from this problem in older versions, please keep an eye on it, to see if it still happens from this version onwards.
Comment by Anthony Mercuri (cool_walking_) - Friday, 16 May 2008, 00:36 GMT
Thanks, will do.
Comment by Anthony Mercuri (cool_walking_) - Friday, 16 May 2008, 00:38 GMT
I meant to also say: I do use the last.fm logging, so this does seem likely.
Comment by Matthieu Robin (macolu) - Tuesday, 20 May 2008, 15:07 GMT
I still get this error with r17585 (on a iAudio x5).
Comment by Bertrik Sikken (bertrik) - Tuesday, 20 May 2008, 15:32 GMT
Matthieu, is it exactly the message "event 257 not found", or is the number slightly different?
Are you using last.fm logging?
Comment by Matthieu Robin (macolu) - Tuesday, 20 May 2008, 15:37 GMT
Yes, exactly the same error number, with the same line break.
I also use last.fm logging.
Comment by Robert Keevil (obo) - Tuesday, 20 May 2008, 18:23 GMT
I might know what's going on here - will test a patch and commit if it fixes the issue for me.
Comment by Bertrik Sikken (bertrik) - Tuesday, 20 May 2008, 18:43 GMT
Hmm, weird. I can think of two things that can cause this:
1) some kind of race condition when two threads on two processors run scrobbler_shutdown at nearly the same time
2) something corrupted the events table
I think 1) is very unlikely. If case 2) is happening, it may also explain some of the "event line full" panics that were reported on the forums.
Comment by Matthieu Robin (macolu) - Wednesday, 21 May 2008, 15:22 GMT
I have another issue that might be related to this one: when restarting Rockbox after getting this error, folders are sometimes sorted reversy (Z-A instead of A-Z). It only applies to folders, not files.

Sometimes I got the freeze and the sorting is okay on next start. However, reversed sorting seems to always happens after a freeze.
Comment by Marc Guay (Marc_Guay) - Wednesday, 21 May 2008, 15:27 GMT
Reversed order seems similar to this: http://www.rockbox.org/tracker/task/8949.
Comment by Matthieu Robin (macolu) - Wednesday, 21 May 2008, 15:49 GMT
In my case, the filesystem hasn't changed, I just restarted the player after getting this "panic" error.
But it is maybe completely unrelated.
Comment by Bertrik Sikken (bertrik) - Monday, 26 May 2008, 06:53 GMT
I think there is a bug in the event/ata_idle_notify system which can explain this problem.
Function register_ata_idle_func installs a *oneshot* event, which means that the event clears itself after it has been fired. So if function unregister_ata_idle_func is called after the event has triggered it tries to remove the event again, but since the event has cleared itself the remove fails and it panics.
Comment by Dmitriy Filyukov (filin) - Tuesday, 27 May 2008, 13:31 GMT
Also got this message several times during automatic shutdown when player had been paused for several minutes.

r17613-080523 on iPod video 5g 30gb.
Comment by Barend Havenga (PsychoCemia) - Tuesday, 27 May 2008, 14:45 GMT
Got this message on an H140 (60gb HD) on trying to shut down manually. It may be related to the fact that I shut down during a player slump on switching between folders during playback.

r17605-080522
Comment by Dmitriy Filyukov (filin) - Tuesday, 27 May 2008, 18:53 GMT
Also got this message several times during automatic shutdown when player had been paused for several minutes.

r17613-080523 on iPod video 5g 30gb.
Comment by Bertrik Sikken (bertrik) - Tuesday, 27 May 2008, 20:59 GMT
Can you try the the following patch and see if it helps?
It fixes the issue I described 4 comments up by removing the call to unregister_ata_idle_func. It also removes some unnecessary checking before calling register_ata_idle_func.
Comment by Robert Keevil (obo) - Wednesday, 28 May 2008, 17:35 GMT
Fixes the issue for me, and a simpler solution than the one I was thinking about.
Comment by Bertrik Sikken (bertrik) - Wednesday, 28 May 2008, 18:15 GMT
Patch committed as svn 17647.
I tested it some more today and the last.fm log still works for me, I'm pretty sure the bug is fixed now.
I propose to leave this task open for another week to see if it's really gone, then close it.

Loading...