Rockbox

Tasklist

FS#11043 - High dircache stack usage after usb connection

Attached to Project: Rockbox
Opened by Michael Chicoine (mc2739) - Saturday, 20 February 2010, 23:24 GMT
Last edited by amaury pouly (pamaury) - Friday, 23 April 2010, 08:08 GMT
Task Type Bugs
Category Operating System/Drivers
Status Closed
Assigned To No-one
Operating System Sansa e200
Severity Low
Priority Normal
Reported Version Daily build (which?)
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

I am seeing high dircache stack usage after USB connection on my e280v1.

I tested as far back as r24419 and up to current (r24794).

Steps to reproduce:

1. Clear all settings on boot
2. Check dircache usage on debug screen
3. Attach USB cable
4. Eject or safely remove
5. Remove USB cable
6. Check dircache usage on debug screen
7. Enable dircache
8. Reboot
9. Check dircache usage on debug screen
10. Attach USB cable
11. Eject or safely remove
12. Remove USB cable
13. Check dircache usage on debug screen

With r24419, the stack usage for steps 2, 6, 9, and 10 were 2%, 3%, 2%, and 82%. This 82% level was also present after rebooting.

With r24657, there was an increase in stack usage. The levels recorded were: 2%, 3%, 2%, and 93%.

With r24708, there was another increase in stack usage. The levels recorded were: 4%, 7%, 4%, and 97%.

Current svn gives the same values as those recorded for r24708.

As I have enabled other features in Rockbox, I have started to see "Stkov dircache (0)" panics. These panics continue after reboot and require editing the config.cfg file in USB mode to disable dircache. After disabling dircache, it will reboot without problems.
This task depends upon

Closed by  amaury pouly (pamaury)
Friday, 23 April 2010, 08:08 GMT
Reason for closing:  Fixed
Additional comments about closing:  r25696, r25697
Comment by amaury pouly (pamaury) - Sunday, 21 February 2010, 10:02 GMT
The high stack usage is normal because I reduced the stack size of dircache but I also heavily modified the way dircache generate its internal structure.
The stack usage of dircache is supposed to be completely independent of all other features of rockbox and depends only the maximum directory depth.
The current code should accomodate a depth of 20 approximately.

What is the maximum depth of your directory tree ?
I will look at the commit you quote however.
Comment by amaury pouly (pamaury) - Sunday, 21 February 2010, 22:57 GMT
I fix a NULL-pointer deference in r24835. I don't really expect it to solve a stkov problem but could you try with this fix to be sure ?
Comment by Michael Chicoine (mc2739) - Sunday, 21 February 2010, 23:29 GMT
That fix did not help.

I was able to get the dircache stack back to 97% from 99% by deleting my .rockbox directory. This helps some, but I will still get a stkov after a disconnect and rolo of a new firmware.
Comment by amaury pouly (pamaury) - Monday, 15 March 2010, 15:21 GMT
Does this bug still exists ?
Comment by Michael Chicoine (mc2739) - Tuesday, 16 March 2010, 23:37 GMT
Yes, the dircache stack usage is still high after USB connection (97% to 99%). Tested with r25217.
Comment by amaury pouly (pamaury) - Wednesday, 17 March 2010, 19:26 GMT
Could you please check your file system for errors ?
I really can't understand how this is possible. I myself have a e280v1 and I get 62% usage with pretty deep structures.

If it continues, you add this line in firmware/common/dircache.c:
#define LOGF_ENABLE
just before
#include "logf.h"

Recompile and paste logf output after usb connection.
Comment by Michael Chicoine (mc2739) - Saturday, 20 March 2010, 20:37 GMT
These are stats from my e270r after formatting and reloading Rockbox (r25259)
dircache os stack usage (dircache disabled)
before USB connection: 4%
after USB connection: 7%
dircache os stack usage (dircache enabled)
before USB connection: 4%
after USB connection: 63%

directory depth: 4

from stats plugin
Files: 319
Music: 0
Dirs: 36
Max files in Dir: 43

from Windows Vista dir listing:
Total Files Listed:
319 File(s) 15,135,905 bytes
104 Dir(s) 5,982,404,608 bytes free

These are stats from my e270r after restoring music (r25259)
dircache os stack usage (dircache disabled)
before USB connection: 4%
after USB connection: 7%
dircache os stack usage (dircache enabled)
before USB connection: 4%
after USB connection: 97%

directory depth: 4

from stats plugin
Files: 671
Music: 298
Dirs: 64
Max files in Dir: 43

from Windows Vista dir listing:
Total Files Listed:
667 File(s) 5,698,753,068 bytes
188 Dir(s) 297,766,912 bytes free

These are stats from my e270r using logf build (r25259M)
dircache os stack usage (dircache disabled)
before USB connection: 4%
after USB connection: 7%
dircache os stack usage (dircache enabled)
before USB connection: 4%
after USB connection: 93%

directory depth: 4

from stats plugin
Files: 672
Music: 298
Dirs: 64
Max files in Dir: 43

from Windows Vista dir listing:
Total Files Listed:
668 File(s) 5,698,753,345 bytes
188 Dir(s) 297,762,816 bytes free
   logf.txt (0.3 KiB)
Comment by Magnus Holmgren (learman) - Sunday, 28 March 2010, 19:49 GMT
I looked at the generated code for an e200, compiled using gcc 4.4.3. The call chain for the dircache scanning looks something like this, in a worst case scenario, stack wise (with the stack usage for each function after it):

dircache.c:
dircache_thread 44
dircache_do_rebuild 28
dircache_scan_and_build 304

sab_process_dir 60

fat.c:
fat_getnext 108
fat_readwrite 92
transfer 28

ata-sd-pp.c:
sd_read_sectors 76
sd_select_bank 580
sd_command 60

The recursive function is sab_process_dir. The non-recursive parts need 1320 bytes. Given that the stack is currently set to 1536 bytes, that leaves some 200 bytes for sab_process_dir. Enough for 3 levels of recursion... If the stack was increased to 2.5 kB (i.e., add 0xA00), it would allow for some 20 levels (a bit overkill perhaps, but better to be on the safe side).
Comment by amaury pouly (pamaury) - Sunday, 28 March 2010, 21:39 GMT
Thank you very much for your findings. I think know understand why the bug happen. There is an ugly buffer in ata-sd-pp.c:sd_select_bank which seems useless to me but I need more information before going on.
The last point I'm still not sure to understand understand is why on my sd card I can go up to 20, the reason for this seems to be that sd_select_bank is only called on big sd cards (code suggest on SDHC cards).

So the solution is:
* either increase stack size as you propose
* try to reduce sd_select_bank buffer size. The buffer size is 512 bytes but a quick look suggest it can be reduced to 32 bytes. Then we could increase stack size if it's still necessary.
Comment by Magnus Holmgren (learman) - Monday, 29 March 2010, 17:09 GMT
Hm, the comment I saw says "Only switch banks with non-SDHC cards". And I do have an SDHC-card plugged (and 8 GB "internally"). In any case, that buffer should be reduced, or write_buf increased in the loop. It does seem a bit odd to need to write 512 bytes, when only one byte is of interest - but then I don't know anything about the protocol.

But adding about 500 bytes would only be enough for 11 levels, at least with gcc 4.4.3, so some stack increase is probably needed too.
Comment by amaury pouly (pamaury) - Monday, 29 March 2010, 17:22 GMT
Yes that's my point. We'll probably end up increasing the stack size a bit (don't know if 11 levels are sufficients) but I'm waiting for the answer of someone who knows the SD code to shrink this buffer.
Comment by amaury pouly (pamaury) - Thursday, 22 April 2010, 08:35 GMT
Hello,
sorry for the delay, I have been busy and forgot this task for a moment :)
I have commited the fix in r25696 and r25697, I would be nice if you could test it because I can't check the ata-sd-pp change, even though I'm pretty sure it works.
Comment by Michael Chicoine (mc2739) - Thursday, 22 April 2010, 23:13 GMT
Thanks for the fixes.

Here are the stack levels I get after USB connection with dircache enabled:

r25695 - 90%
r25696 - 61%
r25697 - 44%

Loading...