Bug 168389

Created attachment 84585 [details]
nps snapshot

Build: NetBeans IDE Dev (Build 090709)
VM: Java HotSpot(TM) Client VM, 14.0-b16, Java(TM) SE Runtime Environment, 1.6.0_14-b08
OS: Windows XP, 5.1, x86

User Comments: 
This is related to http://statistics.netbeans.org/analytics/exception.do?id=225822.

This time the file which takes a long time is C:\DOCUME~1\daniels\LOCALS~1\Temp\vcs-1247222892286 (which exists and is currently empty).  As an aside, in the 30 minutes that the IDE has been up, org.openide.filesystems.FileUtil.normalizeFileOnWindows() has been called 76362 times which is about 42 times a second.
Maximal alredy reported slowness was 64077 ms, average is 39757

Created attachment 84591 [details]
nps snapshot

From profiler snapshots I see the time is spent in WinNTFileSystem.getBooleanAttributes. I am afraid we can't do more if
two such calls take 127840 ms. It might be caused by overloading of your hard drive or operating system. Are you able to
describe any reproducible scenario with daily build?

This issue already has 5 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

Build: NetBeans IDE Dev (Build 090712)
VM: Java HotSpot(TM) Client VM, 14.0-b16, Java(TM) SE Runtime Environment, 1.6.0_14-b08
OS: Windows XP, 5.1, x86

User Comments: 

Maximal alredy reported slowness was 64077 ms, average is 28347

Created attachment 84653 [details]
nps snapshot

This issue already has 6 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

Feel free to reopen, if you provide requested information. I can reproduce such delays.

Sorry for the delay.  I originally found this with an unmodified DEV version of NB.   My colleagues also see this with
NB 6.5.  In each case the only significant load would seem to come from the NetBeans IDE.  In my experimentation is have
removed networked drives and disabled the no-access scan of the virus scanner.

There is no reliable set of steps that reproduces the problem, although I do encounter it a few times each day.  The
most common place where the delay occurs are for files/directories in java.io.tmpdir.  This is typically full with
NetBeans-related files that are largely no longer used (listed below with *** representing a time-stamp).  I wonder how
good WXP is at dealing with large directories (my guess is not very well).  My expectation is that if NetBeans was to
tidy-up after itself then this directory would stay small and may allow the issue to be side-stepped.

There are many directories (can be thousands) named vcs-*** which are empty (I have a patch for this which I will test
tomorrow).  They are created by an inner-class in DiffSidebar.java.  This class could safely delete these directories
when it has finished with them rather than leaving it to system shutdown.  Leaving these directories for delete-on-exit
may also slow down the closing of the IDE and I guess may account for users perceiving a slowing of the IDE over up-time.

groovy-generated-***-java-source directories are left with sub-directories, but without any java source.

There are many binary files named output***, many of which seem to be safe to be removed.  I'm guessing that they relate
to the tabs in the Output window and aren't being deleted when the tabs are closed or perhaps also when the content gets
overwritten.  These files can get quite big as well as being numerous.

I should also note that I'm suing Java 1.6.0_14; Java HotSpot(TM) Client VM 14.0-b16 on Windows XP version 5.1 running
on x86; Cp1252; en_GB

> The most common place where the delay occurs are for files/directories in java.io.tmpdir.

What do you mean by this sentence? Does the delay occur when you open a file from temp folder? Or when?

I am not doing anything directly with the temp folder.  I am however frequently running database queries.  Looking at a
generated Profile in front of my it seems I am locking in SQLHistoryPersistenceManager.create().  It seems reasonable
that the "SQL Command X" editor tabs put their returned data into the output*** files (rather than the Output window
tabs, which would explain why they are binary).

I have however also seem lock-ups whilst typing into the editor.  I'll pay more attention to the generated profile the
next time that happens.

BTW, development builds have turned assertions on. If you use FCS builds or turn it off in netbeans.conf (just remove
-J-ea), you can "improve" performance.

Build: NetBeans IDE Dev (Build 200907170201)
VM: Java HotSpot(TM) Client VM, 14.0-b16, Java(TM) SE Runtime Environment, 1.6.0_14-b08
OS: Windows XP, 5.1, x86

User Comments: 
I stepped into (Control+Mouceklick) a java-source-file (~11000 Rows).
Maximal alredy reported slowness was 64077 ms, average is 24771

Created attachment 84918 [details]
nps snapshot

This issue already has 7 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

This issue already has 8 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

Created attachment 84919 [details]
The Thread-dump for the latest Slowness detection

This issue already has 10 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

This issue already has 10 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

This issue already has 11 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

This issue already has 14 duplicates 
see http://statistics.netbeans.org/exceptions/detail.do?id=153566

WinNTFileSystem.getBooleanAttributes is a known bottleneck on Windows;  much worse if you're using a remote filesystem
or zip drive.  Unfortunately, File.isDirectory(), File.isFile() and File.toURI() all trigger invocations of it.

See issue 65135 - probably that should be reopened and this closed as a duplicate, or a dependency set on that one from
this one.  I know work has been done to reduce I/O during startup, but there are some other possible optimizations (URL
caching for APIs that require URLs to files), etc. which could be done successfully and impact runtime performance.

Lots of new information -> I think this issue is no longer INCOMPLETE.

There is a lot of duplicate reports. Each of them ends in WinNTFileSystem.getBooleanAttributes but they have different
origins. As Tim summarized it is Windows or JDK problem we can hardly workaround in filesystems. If you feel such calls
should be moved out of AWT thread, please, sort duplicates and assign them to appropriate module.

Pavel, this seems important and you are the owner of issue 65135. Can you lower the time from those 30s to less than 
10ms, please?

Created attachment 85714 [details]
Can we lower the presure on WinNT filesystem by caching the results? Btw. the final patch woudl need to clear the cache on fileRename

I think that my experience is in part down to the fact that I am currently creating some directories with a large number
of files and NTFS doesn't handle this well.  Perhaps NB could check for when File access is taking a long time and then
warn the user that this is the case?

I don't think we need additional cache. FileUtil.toFile() is already optimized and the call below skips time consuming
URLMapper processing for files.

(File) fo.getAttribute("java.io.File")

My cache was there to prevent FileUtil.normalizeFile(...) which is the most expensive call on Windows. If we can 
guarantee that masterfs returns normalized file from (File) fo.getAttribute("java.io.File") and that it caches the 
normalized variant, then we do not need my cache. However I am not sure if this is compatible with the original 
intention. I thought that fo.getAttribute("java.io.File").getPath().equals(fo.getPath()) for masterfs.

Anyway I just want to find out if my cache can lower the disk I/O. If so, we can seek for better implementation.

I suppose fo.getAttribute("java.io.File") returns normalized file. But I don't think it is too much expensive (just 15%
from toFile execution on my computer). Anyway it doesn't solve this issue. I didn't see FileUtil.normalizeFile() calls
in attached snapshots.

Created attachment 85763 [details]
Today I installed NB6.8m1. The IDE made a rebuild of the index. Here´s the Snapshot of this rebuild. Maybe this helps at the discussion.

I can say this is not definitely NetBeans issue. From the information provided, it hangs in native call. When you look around the Internet, the same problem is 
reported in different products (even the competitive products are not an exception). Problem can occur in different calls. We saw this problem several times.
Usage of cache does not guarantee that problem will disappear, it could reduce the number of hangs, but I doubt about such a solution.

For the time being, I would recommend to run filesystem integrity tool (fsck?}. Check, that you mounted drives are accessible. If not, try to unmount them.

We should try to provide logging mechanism of problematic files. It could help us to understand why NTFS is blocked and emulate the problem.

I have tried to run with suggested patch and cache is used in 80% throughout initial scan.

And how much is it faster with the patch?

I think that the cache can be beneficial slow disks or network drives (which do not cache on OS level). Then I'd 
expect 80% speedup. On a local disk, when OS caches repetitive calls, the speed up is not going to be significant. The 
only hope is by querying the WinNT less often, the 15s delays will not be that often. That is not guaranteed, but 
still, for the benefit of network drives I'd like the filesystem API to lower the amount of normalizeFile calls.

Looking at my actual development hardware and consider the disk activities I see (especially if memory runs low due to a
big platform being run in debugger), I think every call to WinNTFs, which can avoid is worth the effort. 

How about trying the same scenarios with new openjdk 7 builds? I think there may have been changes that could have an
effect, but maybe I am just completely wrong here.

I didn't apply jtulach's patch but I skipped normalization if file in toFile() comes from masterfs. It is already
normalized.
core-main #39aa41b4804d

Good, thanks. Let see if that helps.

Integrated into 'main-golden', will be available in build *200909030951* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main-golden/rev/39aa41b4804d
User: Jiri Skrivanek <jskrivanek@netbeans.org>
Log: #168389 - Do not normalize file in toFile() if comes from masterfs - it is already mormalized.

*** Bug 193770 has been marked as a duplicate of this bug. ***

*** Bug 192657 has been marked as a duplicate of this bug. ***