Rockbox Technical Forums

Rockbox General => Rockbox General Discussion => Topic started by: squidkidd on February 20, 2008, 04:54:25 PM

Title: buggy dircache activity renders ipod almost completely unresponsive
Post by: squidkidd on February 20, 2008, 04:54:25 PM
First a little backstory:  dircache has never worked quite right on my 80gb ipod since I got it back in June '07.  For a long while, the main symptom was that I would get a foreground "scanning disk" on every other boot.  This seemed to stop for me several months ago (probably with the fix to prevent dircache from breaking if interrupted in a background scan) and all seemed well.

A couple of weeks ago about the time I started using the portal player device disable battery builds (and now subsequently the svn builds) the dircache has started to show signs of odd behavior again.  I am not saying at all this is what is causing this behaviour, just that it was about that time I noticed it.

Now when I turn the player on, I do not get the foreground scans any longer, but I get a very long background scan (anywhere from 200-300 seconds).  During this time controls on the player are almost completely unresponsive.  I have it set to resume playback on boot.  Once playback has resumed however it may take up to 30 seconds for the screen to respond to what is being played.  If I hit menu, it can take up to 30 seconds to go there.  If the resumed song finishes in this time frame, the next does not start playing for at least 15 seconds.  After the 200-300 seconds though, all functionality, including dircache, as far as I can tell is back to normal.  

I'm using cabbie2.0 with no eq.  Thoughts?

Regards,
Brian
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: baobab68 on February 20, 2008, 05:04:56 PM
It sounds a bit like this:

http://forums.rockbox.org/index.php?topic=15465.0

only a lot worse.

Out of interest, if you set it to not resume playback on startup, how long does the dircache scan take? On my iRiver H320, that seems to help a lot.

I'm not suggesting that it's a fix, but maybe it's a pointer to what's going wrong. It seems like some kind of thread priority issue or disk contention to me.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: squidkidd on February 20, 2008, 05:43:03 PM
With resume playback stopped it takes 29 seconds.  30 seconds beats 4 minutes, but yeah, definitely not a practical solution.  I don't know if this has anything to do with it, but I have 19000 songs on the ipod.

Regards,
Brian
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: baobab68 on February 20, 2008, 09:02:25 PM
I have over 10000 on my iRiver, with a similar situation (well not quite as pronounced as yours).

I wonder if we should log it as a bug report?
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: GodEater on February 21, 2008, 03:13:13 AM
It doesn't need logging as a bug report, the developers are aware of it. (I get the same issue myself - and as a stopgap measure to make my ipod usable, have used the spinlock revert patch to at least get my ipod into a useable state : FS 8568 (http://www.rockbox.org/tracker/task/8568))

To make the problem less obvious - make sure you're not using a AA enabled theme too. I've gone to BlackGlassNonAA myself - the fight between the buffering code and the dircache update are what make the problem really bad - and leaving the buffering code to only load music, rather than music AND album art goes a long way to alleviating the issue.

Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: baobab68 on February 21, 2008, 04:13:49 AM
Thanks Godeater for the feedback. Does it affect more than iPods though as I see that in that patch you're using the discussion seems to be all about iPod issues.

I am using an iRiver H320, and yes I am using Album Art. That never even occurred to me: Album Art vs Dircache vs Database.

I'll keep checking if things have change on the odd occasion when I update my build.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: GodEater on February 21, 2008, 05:06:33 AM
You'd be the first person reporting the issue (that I'm aware of) on a non-ipod target. Perhaps you should consider getting onto IRC and talking with either (or both) of Nico_P and jhMikes.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: roolku on February 21, 2008, 06:56:40 AM
The issue also exists on gigabeat F.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: GodEater on February 21, 2008, 07:32:27 AM
Can't say I've seen it on my Gigabeat...
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: squidkidd on February 21, 2008, 01:31:25 PM
Ah, great.  Thanks for the point in the right direction.  Looks like we might be close to at least a temporary fix in the svn from the comments in the FS.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on May 24, 2008, 03:09:34 AM
I have about exactly the same issue as described by squidkidd with my Ipod 80GB since about a week ago after installing a new "current build". With the newest one from today, 17617, it is the same thing: it scans for about 5 minutes with "resume playing" as the start screen, during this time Ipod is almost unresponsive.
When "resume playing" turned off it takes considerably shorter, about 30-60 sec.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on May 24, 2008, 02:01:02 PM
I have the same (or at least a similar) effect with my ipod 80GB with the current build.

I do not have the resume playing option turned on but when I turn on my ipod and then immediately start browsing the database the hard drive gets spinning like crazy and the ipod is unresponsive for a long time (about 2-5 minutes). When I first wait until dircache is initialized (takes about 30 seconds) then browsing the database is no problem. When I start browsing the file tree instead of the database immediately after I turned on my ipod (of course after the menu appears) then the ipod remains responsive.

So it seems that the problem with the competing hard disk access seems only appear between initializing dircache and using the database.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: TexasRockbox on May 25, 2008, 01:00:39 AM
I do not have the latest build (r17588) on iPod 5.5G 80GB, 12,000 .ogg files and have noticed similar behavior.  On bootup the hard drive seems to be thrashing incessantly when playing the first song (and it is not from a "resume") and music will even cut in and out every few seconds.  When skipping to the next track (whenever that is -- usually immediately) the continuous disc reading will stop and then behavior seems normal.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on May 25, 2008, 05:33:44 AM
Today i went through older builds and found out that the 'scanning bug' is definitely there (again?) beginning with the IPOD build 17469 from the 12th May 2008.

Everything seems to be OK until the build 17451 (2008-05-11).

So it seems to be one of the builds between 17463 and 17469 that introduced the bug. Where can i get those current builds to check which one excatly it was?

Please take a look and verify:

http://www.rockbox.org/daily/changelogs/changes-20080512.html
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: jhMikeS on May 25, 2008, 06:22:08 AM
 ??? I think this problem has to be investigated out the context of always blaming threading which seems to be the common default position. No signs have ever pointed to any sort of scheduler bug as the root cause and any bug like that would cause similar behavior across all ports. The 30GB 5.5G that uses large sectors had no issues.</end defensive spiel>  8)

I know that increasing the ATA powerup delay fixed the issue of the core hanging during an interrupt wait for at least two main reporters of the issue (and a Nano owner). Perhaps it needs still longer for the large HD or another power issue still exists in regards to the disk.

NOTE:
Of course things like dircache or database updates taking alot longer with playback running are expected since it's placed in the relative background to favor CPU for decoding audio. If they run basically alone, they get pretty much all the CPU time.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: squidkidd on May 28, 2008, 11:16:58 PM
Funny, I had come to post that this problem had returned when I found several others had beat me to it.  Same deal for me, using the current SVN, playback resume, dircache enabled, database update disabled.  I first noticed it on Monday's build.

Regards,
Brian
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on May 29, 2008, 11:49:00 AM
I have now checked build 17451 as mentioned by surfer and can confirm that with this build the problem mentioned in my post of May 24 is gone.

I further noticed that with the present build not only browsing the database makes the ipod unresponsive if at the same time dircache is initialized, but that playback is repeatedly interrupted over several minutes when playing music during dircache is initialized. This does also not happen with build 17451.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: jhMikeS on May 29, 2008, 04:06:13 PM
I would like to know if you could let the disk spin down after boot (wait five or so seconds after that as well) instead of doing all the dircache/database/resume playback right at boot. After that, run the updates manually and start playback to imitate the startup situation as closely as possible and see if the symptoms show at that point as well.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on May 29, 2008, 04:42:49 PM
If I wait after reboot until the disk has stopped spinning (takes about 30-40 sec) I can browse the database and start playback without any problems, that means no lag during browsing and no interruptions during playback. Initializing dircache is shown in dircache info to have taken always about 30 seconds in this case.

In contrast, when I start browsing or playback before disk has stopped spinning, time for initializing dircache is much longer, e.g. indicated between 90 and 300 seconds. Sometimes it is then even indicated that dircache is not initialized.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on May 29, 2008, 05:35:33 PM
http://In contrast, when I start browsing or playback before disk has stopped spinning, time for initializing dircache is much longer, e.g. indicated between 90 and 300 seconds

Yes, i can confirm the same: when i start a song during the initial scan (without 'resume playback' set as start screen) all the symptoms as with 'resume playback' are there again.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: Llorean on May 29, 2008, 05:40:15 PM
What he wants you to do is turn *off* automatic database updates. Then wait for the disk to spin down after booting, start a database update, and then resume playback, to see if you have similar problems then.

Basically, the idea is to see if it's the updates that are causing the problem, or if it's relating to when the updates happen, rather than just what they do. At least, testing this theory as best as reasonably possible.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: jhMikeS on May 29, 2008, 06:21:26 PM
Thanks Llorean. :) More specifically, this allows the HD power to be cycled once and see if things change. The HD power won't be turned off until several seconds after the HD has spun down from no activity. Then we want to have similar activity to the initial boot situation after repowering it and see if unresponsive UI or skipping is there.

I'll state again that it is by design that database update would take longer during playback than not during playback because it is a background update after all and takes a back seat to decoding audio. It will be true regardless of revision used.

The unresponsiveness and skipping that happens without the ata hack is utterly peculiar to the 60/80GB Video.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on May 30, 2008, 04:08:45 AM
Please be aware as well that at least me and the starter of this thread, squidkidd, have this issue independently of the database.

I do not use the db and have never initialized it. It seems to be something related to the scanning for the dircache.

Some changes seem to have been made related to the dircache on one of the builds 17463-9 (2008-05-12) which introduced the problem (again).
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on May 30, 2008, 04:28:17 AM
I have now turned off automatic database updates, rebooted and waited until the disk stopped spinning (which took again about 30 sec. as with automatic database updates on). Then I selected update database now and started immediately browsing (the database not the file tree). In this case there was no lag in browsing although database was updated in the background.

Since I had the impression that the problem could be related to the loading of dircache into RAM I in addition turned off this feature. Only for completeness in a first test I waited after reboot until the disk stopped spinning which took again about 30 seconds. As expected, browsing after disk stopped spinning was slower than before and you could see the "searching... " popup which counts the found albums probably since database had now to be read from disk and not from RAM.

In a second test after a further reboot I started browsing during the disk was spinning. In this case browsing took again much longer and the "searching..." popup counter did not continuously increase but was regularely interrupted. But I had the impression that the ipod was still a little bit faster than when automatic database update and loading dircache to RAM was on.

Then I turned loading dircache to RAM on again and after a reboot I started browsing the database during the disk was spinning. Then I had almost the same bad unresponsivness as at the very beginning.

So it seem to me that there is some disk activity after a reboot which take about 30seconds (after the Rockbox logo dissapears) and which catches almost all disk ressources. This seems not to be the automatic databse update and also not the dircache loading to RAM although the unresponsiveness seem to be even worse when both features are additionally turned on. In the latter case probably browsing has to fight not only with the unknown disk activity process but in addtion with the update process and the loading to RAM process.

Does that make sense?
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: Sherv on May 30, 2008, 01:02:06 PM
Adding my voice to the chorus. Running r17659-080530 and I experience the same problem if I resume playback immediately after booting. Waiting for the disk activity to cease before doing anything else (directory cache is on, database loading to RAM is off, last.fm logging is on [I read at one point that this may be a culprit]) results in clean and responsive playback.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: jhMikeS on May 31, 2008, 02:01:26 AM
Nothing can catch all disk resources. The various threads trying to access the disk at the same time are granted it in first-in-first-out order so anything waiting for it will be given access in turn. The only major disk activity at boot would be the dircache and database scans. If both dircache and database auto update are both off and you're getting 30s of disk activity at boot then that's not right at all. It should stop after the disk spindown timeout which defaults to 5 seconds.

Clearly some things will take longer if the various caching schemes are disabled; that's why they're there. I of course experience that on any of my players as well-- including flash players-- and know it's normal. However, the sorts of changes within the daily build mentioned previously have no negative impact on any of them (look below this post for a list which actually includes an occasionally borrowed 5.5g 30GB).

What's interesting so far is that you don't have a problem with database updating in the backgound after HD has had a chance to cycle off. Now, check with dircache disabled, database auto update on and don't wait for the HD to stop at boot. Compare with the first two tests which sounded normal.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on June 02, 2008, 12:30:32 PM
I have now disabled loading dircache to RAM, set database auto update to on and then started browsing the database without waiting that the HD stopped spinning. The result was the same as when I disabled dircache AND automatic database update (that means it takes ages until the menu entries are shown and the "searching..." popup counter is repeadeatly interrupted). This was expected since why should setting automatic database update on improve the situation.

But then I found (hopefully) the reason for the intial disk spinning. I usually have set the option to show the database after startup. I now have changed that to show the main menu and after the next reboot the initial 30 sec disk spinning was gone. It seems that showing the top level of the database menu after reboot causes the disk spinning which then conflicts with other disk access like browsing the database or playback. Could the be the reason for the problem?
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: squidkidd on June 02, 2008, 12:45:55 PM
I'm using resume playback on startup and I hardly ever use the database, so there is still something in there besides the database access that is spinning the disk and making playback skip.

Regards,
Brian
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on June 02, 2008, 03:48:18 PM
But then I found (hopefully) the reason for the intial disk spinning. I usually have set the option to show the database after startup. I now have changed that to show the main menu and after the next reboot the initial 30 sec disk spinning was gone. It seems that showing the top level of the database menu after reboot causes the disk spinning which then conflicts with other disk access like browsing the database or playback. Could the be the reason for the problem?
Sorry, I was wrong, the problem is independet from the chosen start menu. I double checked and could not reproduce that hd spinning does not occur when start menu is the main menu. So my conclusion was wrong, sorry for that.

There is alwas about 25 sec hd spinning after the rockbox logo disappears when dircache and database update is off. When dircache is on spinning takes about 5 sec longer. And when automatic databse update is in addition on there are another 5 seconds. But the initial 25 seconds are always there and cause the problem
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: jhMikeS on June 02, 2008, 08:12:28 PM
So, the virtual LED is on during this period indicating actual activity? This may be irrelevant depending on the following: be absolutely sure it's not just the HD spindown time set to 25 sec as well under settings|general settings|system|disk|disk spindown.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on June 03, 2008, 01:26:44 AM
The virtual LED is on during this period and you can clearly hear and feel the hd access. Spindown time is set to 5 sec.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: jhMikeS on June 03, 2008, 07:20:48 AM
Thanks for all the input. It starts clarifying things alot. The hack that covers up the problem was added back to the SVN tree to keep things useable in the time being.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: dip on June 03, 2008, 07:42:02 AM
Thank you for all your efforts and this great program  :D

If you need sombody for testing future patches I would be glad to help.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: Sherv on June 03, 2008, 01:14:24 PM
Thanks for all the input. It starts clarifying things alot. The hack that covers up the problem was added back to the SVN tree to keep things useable in the time being.

Thanks man, hopefully the root of the problem can be identified and rectified at some point...in the meantime, the re-introduced hack is functioning perfectly!
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: TexasRockbox on June 03, 2008, 10:33:40 PM
Another "Thank You!", r17684 is behaving nicely.
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on June 04, 2008, 03:55:56 AM
It works for me again since the 3rd June....thanks a lot!
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on July 10, 2008, 06:26:42 AM
since my last posting i've noticed another issue probably related to this thread on my Ipod Video 80GB:

when a track is playling (by resume or manual start of playback) during the inicial scan starting another track from any saved playlist (with about 10-20 track entries on them) renders the player frozen for about 1-2 minutes:

during this time pressing "menu" or the scrollwheel do not work, the inicially started track continues to play but the next one started from a playlist begins to play only after about 1-2 minutes (when the scan is finished)
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: NicolasP on July 11, 2008, 03:18:40 AM
surfer: what biuld/version are you using? Are you sure it's a recent one? This issue should have been "fixed" (actually, hidden under the carpet) a few weeks ago
Title: Re: buggy dircache activity renders ipod almost completely unresponsive
Post by: surfer on July 11, 2008, 03:32:09 AM
i was having this issue since the fix until the newest built 18007 and i know it has normally been fixed as you can see from my post from the 4th June here above.

The issue i'm adressing now is only there when you start another track from a saved playlist (during the time of the inicial scan and when a track is already playing).

there is no problem when you start another track from a directory (or from the actually loaded dynamic playlist).