bibikurosawa / dokan

Automatically exported from code.google.com/p/dokan
0 stars 0 forks source link

Some applications have very slow read access to files. #34

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago
<pre>
<B>What steps will reproduce the problem?</B>

1. Run mirror.exe at any folder as any drive
2. Open a *.txt file in notepad.exe
3. Wait

<B>What is the expected output? What do you see instead?</B>

It just takes much longer to read in notepad.exe then using 'type' from the
command prompt or notepad++.

I read some where that notepad.exe uses memmapping when openning files. I
was also reading up on why there is CleanUp and Close (cacheing), and saw
the calls CcFlushCache, CcPurgeCacheSection and CcUninitializeCacheMap in
DokanCompleteCleanup. Comment out these calls and recompiling solves the
problem. Notepad.exe reads files suddenly at the speed you would expect.
I'm guessing that what needs to happen is these three calls need to happen
only when the last reference to the file is released so that IRP_MJ_CLOSE
is forced. I'm looking further into this but I thought I should log where I am.

<B>What version of the product are you using? On what operating system?</B>

dokan - 0.3.9.1191 under Windows XP sp2

</pre>

Original issue reported on code.google.com by joe.a.bu...@gmail.com on 10 Nov 2008 at 4:34

GoogleCodeExporter commented 9 years ago
I never did get to the bottom of this as my kernel debugging skills aren't up 
to what
is required yet.

Here's what I'm seeing and doing to fix it.

Open a file from a Dokan filesystem in notepad.
Wait, wait, wait, wait, wait, yep your seeing it, wait, wait.
It's open!

Shutdown the Dokan filesystem and do "dokanctl /r a" and reboot.
In DokanCompleteCleanup of sys\cleanup.c comment out the three lines:

    CcFlushCache(&fcb->SectionObjectPointers, NULL, 0, NULL);
    CcPurgeCacheSection(&fcb->SectionObjectPointers, NULL, 0, FALSE);
    CcUninitializeCacheMap(fileObject, NULL, NULL);

and recompile, copy the files to where they need to be and do "dokanctl /i a".

Restart the Dokan filesystem.
Open a file from a Dokan filesystem in notepad.
It's open!

I'm guessing these lines are down to enforcing close being called after 
cleanup. My
guess is it's a step towards Dokan filesystem implimentors not having to know 
about
windows filesystem driver cleanup/close and just having a single call.

I tried only calling these three lines only when FileCount of DokanFCB was 0, 
but
couldn't get Kernel debugging working properly.

To get kernel debugging I followed:
http://silverstr.ufies.org/lotr0/windbg-vmware.html

But I found the code:

"
DDbgPrint("  DokanFreeFCB File (%wZ) FileCount = %lu\n",
Fcb->FileName, Fcb->FileCount);

InterlockedDecrement(&Fcb->FileCount);

if (Fcb->FileCount == 0)
{

       DDbgPrint("DokanFreeFCB fcb->FileCount == 0\n");
"

was outputting:

Wed Nov 12 17:37:03.183 2008 (GMT+0):  DokanFreeFCB File () FileCount
= 2184802360
Wed Nov 12 17:37:03.183 2008 (GMT+0):
Wed Nov 12 17:37:03.183 2008 (GMT+0): DokanFreeFCB fcb->FileCount == 0

which I couldn't work out......

I would put it down to different instances and threading, but it seamed to be 
every time.

So I'm stuck.

Original comment by joe.a.bu...@gmail.com on 19 Nov 2008 at 12:22

GoogleCodeExporter commented 9 years ago
I got unstuck. Coming back to this I don't know what my debug issue was, but
everything is working like it should so I'm not seeing any debug weirdness. 
Maybe I
was doing something silly unknowingly.

I'm not seeing fcb->FileCount ever as anything lower then 1 in 
DokanCompleteCleanup.

If you call the three cache clearing lines when fcb->FileCount is 1 then you 
are back
to really slow loads in some programs such as notepad. During the really slow 
load
(and even crash) while notepad is loading there are many of the normal
DokanCreate,DokanCleanup,DokanClose messages, but two new ones stick out:

wait notification event timeout
DokanReleaseTimeoutPendingIRP

When testing this in the virtual machine connected to windbg,  before notepad 
has
finished, it dies with:

*** Fatal System Error: 0x0000000a
                       (0x00000004,0x00000002,0x00000000,0x804F3700)

Mon Nov 24 11:58:08.283 2008 (GMT+0): Break instruction exception - code 
80000003
(first chance)

A fatal system error has occurred.
Debugger entered on first try; Bugcheck callbacks have not been invoked.

However, with the three lines just commented out, the pattern of DokanClose 
being
called after DokanCleanUp doesn't seam any different. So what purpose do these 
three
lines serve and can't they just be removed as they only seam to cause problems.

Original comment by joe.a.bu...@gmail.com on 24 Nov 2008 at 12:07

GoogleCodeExporter commented 9 years ago
Hello,
Thank you so much for your many challenges.

> I'm not seeing fcb->FileCount ever as anything lower
> then 1 in DokanCompleteCleanup.
In my program, fcb->FileCount is decremented in FreeFCB which is called in 
DokanDispatchClose 
(create.c), so it is never reached in cleanup but in close.

BTW
> DDbgPrint("  DokanFreeFCB File (%wZ) FileCount = %lu\n",
> Fcb->FileName, Fcb->FileCount);
This code is wrong.
DDbgPrint("  DokanFreeFCB File (%wZ) FileCount = %lu\n", &Fcb->FileName, 
Fcb->FileCount);
and you should change %lu to meet the actual type of FileCount. Sorry I don't 
remember now.
In my environment, notpad can read more than 45M file and never be crashed. But 
this takes a lot of
time when you enable debug output.
Can you elaborate it a little more?

You can break the debugger, and type "!analyze -v", then you can get much 
information.

Original comment by asa...@gmail.com on 24 Nov 2008 at 2:03

GoogleCodeExporter commented 9 years ago
Hi,

> Thank you so much for your many challenges.

Just trying to help. Sorry if I'm not.

> In my program, fcb->FileCount is decremented in FreeFCB which is called in
> DokanDispatchClose (create.c), so it is never reached in cleanup but in close.

Ah, sorry should have seen that.

The DDbgPrint syntax is probably why it all started making sense when I tried 
again,
got it right this time. ;-)

I can't get it to crash again. It was doing it every time when I looked at this
earlier. The file is just a text file (test.txt) containing the text "test ". 
It's
still taking a long time to load (25 seconds).

Selecting properties from the explorer context menu also is taking a long time 
(56
seconds).

(Times are from VMWare player running XP Pro sp2 with 512 MB RAM. The real 
machine is
Intel(R) Core(TM)2 CPU 2.67GHz 3.37GB RAM.)

The crash might have been caused by me, so ignore that until I can reproduce it 
and
show it's not me. ;-)

But the slow load times is defenently the three cache clearing lines in
DokanCompleteCleanup. I'm not seeing an effect of them not being in other then a
speed up. What do they do? I've tried putting in CcFlushCache and 
CcPurgeCacheSection
in DokanFreeFCB for when Fcb->FileCount is 0, but again I still don't see an 
effect
other than a speed up.

Original comment by joe.a.bu...@gmail.com on 24 Nov 2008 at 4:49