This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.

Bug 65135 - Excessive calls to File.isDirectory() cause performance problems
Summary: Excessive calls to File.isDirectory() cause performance problems
Alias: None
Product: platform
Classification: Unclassified
Component: -- Other -- (show other bugs)
Version: 5.x
Hardware: All All
: P3 blocker with 1 vote (vote)
Assignee: Pavel Flaska
Depends on: 65700 65714 66361 169852 171330
  Show dependency tree
Reported: 2005-09-26 16:30 UTC by _ tboudreau
Modified: 2016-09-19 06:18 UTC (History)
10 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:

Patch to eliminate most frequent calls to isDirectory() (7.06 KB, application/x-gzip)
2005-09-26 16:32 UTC, _ tboudreau
jvmti agent (32.98 KB, text/plain)
2005-10-07 14:54 UTC, _ rkubacki
premain class for JVMTI aganet (2.69 KB, text/plain)
2005-10-07 14:55 UTC, _ rkubacki
File.isDirectory() invocations (13.78 KB, text/plain)
2008-02-19 15:58 UTC, Pavel Flaska
Samples of important call-stacks (31.02 KB, text/plain)
2008-02-19 16:36 UTC, Pavel Flaska
Startup log (1.10 MB, application/x-bzip)
2009-08-04 21:50 UTC, _ tboudreau
Logging w/ stack traces of expensive I/O calls after expanding one project (107.44 KB, application/x-bzip)
2009-08-04 22:16 UTC, _ tboudreau
Code used for logging (51.10 KB, application/octet-stream)
2009-08-04 22:19 UTC, _ tboudreau
Log of I/O triggered by simply pressing Enter in the editor, w/ stack traces (17.83 KB, application/x-bzip)
2009-08-04 22:37 UTC, _ tboudreau
Log for adding JFrame to main() (95.54 KB, application/x-bzip)
2009-08-04 22:53 UTC, _ tboudreau
Log file for new project and adding code, filtered for only I/O in event thread (140.63 KB, application/x-bzip)
2009-08-04 23:06 UTC, _ tboudreau
JMH test mentioned at 2016-09-14 13:58:34 UTC (4.87 KB, application/x-zip-compressed)
2016-09-14 14:00 UTC, NukemBy
JMH test for various file access API's (4.10 KB, application/x-zip-compressed)
2016-09-19 06:11 UTC, NukemBy

Note You need to log in before you can comment on or make changes to this bug.
Description _ tboudreau 2005-09-26 16:30:49 UTC
Synopsis:  A user recently complained about very bad performance when working with a project on an 
encrypted disk.  I duplicated the problem somewhat by creating a project on a USB drive.  In particular, 
the call file.isDirectory() involves IO, and, at least on Windows, can be a serious bottleneck.  Patching to log calls to this method showed two things:

1.  It is indeed slower
2.  It is called *all* the time in NetBeans

This could definitely account for some of the performance problems that user was experiencing - just 
typing a character in the editor causes this method to be called multiple times against the currently 
open file for each character typed;  many operations cause it to be called against all jars on the 

To get a real sense of the effect on performance of calls to this method being slow, try inserting a 
sleep() into a patched version of and use NetBeans with that.

I will attach an experimental patch to seriously reduce calls to this method - in particular to eliminate 
them from the critical path of typing in the editor.  The patch does some things that may be 
questionable in practice, like assuming files ending in ".class"/".jar"/".java"/etc. are never directories, 
manually constructing URLs/URIs, etc.  It does work on Windows and Macintosh - I have been running 
successfully with it for a few days.

Subjectively, the effect seems profound:  The "stuttering" feeling of typing in the editor is gone - the 
delay between clicking a line and the caret/highlight appearing there is below the threshold of 
perception;  the same for typing characters in the ediitor.  It *feels* faster in a way that's hard to put a 
finger on - many things (switching editor tabs, typing, menus) seem smoother.

An unscientific stopwatch timing of startup time on my mac, with loaded J2SE projects and disk cache 
primed showed startup time to be significantly improved (30 seconds w/o patch, 21 seconds with), but 
that seems too large a difference to be believed - probably it has more to do with my disk cache.

It sounds too good to be true, so I suspect I must be seeing what I want to see here.  Or who knows, 
maybe it really is a "silver bullet".  It would be interesting to see real scientific measurement of the 
performance differences running with the attached patch and not.


Some numbers:

227:C:\Program Files\Java\jdk1.6.0\jre\lib\rt.jar
134:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\dnsns.jar
129:C:\Program Files\Java\jdk1.6.0\
128:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\sunpkcs11.jar
128:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\localedata.jar
128:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\sunjce_provider.jar
111:C:\Program Files\Java\jdk1.6.0\jre\lib\jsse.jar
110:C:\Program Files\Java\jdk1.6.0\jre\lib\jce.jar
110:C:\Program Files\Java\jdk1.6.0\jre\lib\charsets.jar
48:C:\Program Files\Java\jdk1.6.0\jre\lib\i18n.jar
48:C:\Program Files\Java\jdk1.6.0\jre\lib\sunrsasign.jar

440:C:\Program Files\Java\jdk1.6.0\jre\lib\rt.jar
294:C:\Program Files\Java\jdk1.6.0\
242:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\dnsns.jar
225:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\sunpkcs11.jar
225:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\localedata.jar
225:C:\Program Files\Java\jdk1.6.0\jre\lib\ext\sunjce_provider.jar
186:C:\Program Files\Java\jdk1.6.0\jre\lib\jce.jar
186:C:\Program Files\Java\jdk1.6.0\jre\lib\charsets.jar
186:C:\Program Files\Java\jdk1.6.0\jre\lib\jsse.jar
Comment 1 _ tboudreau 2005-09-26 16:32:03 UTC
Created attachment 25189 [details]
Patch to eliminate most frequent calls to isDirectory()
Comment 2 Jan Chalupa 2005-09-27 08:56:59 UTC
This needs to be analzyed. Perf guys, please take a look at it. Feel free to
re-assign if appropriate.
Comment 3 _ rkubacki 2005-09-29 12:49:38 UTC
I am looking at your patch.

You are suggesting an API addition (I have no problem with this). The heuristic
with names is perhaps acceptable though not quite safe. Manual building of URL
is more controversial: is your patch OK wrt to non 7-bit ASCII chars? Even
localized version "Documents and Settings" can contain them. Do you really think
new URL(String) is faster than other constructors?

java/api/src/org/netbeans/spi/java/classpath/support/ -
does your patch really helps here? When this code is called.

Your normalized cache is leaking (only put()s no remove()).

re startup time improvement - I did not check yet.
Comment 4 _ tboudreau 2005-09-30 01:15:15 UTC
> I am looking at your patch.
> You are suggesting an API addition (I have no problem with this). The heuristic
> with names is perhaps acceptable though not quite safe. Manual building of URL
> is more controversial: is your patch OK wrt to non 7-bit ASCII chars? Even
> localized version "Documents and Settings" can contain them. Do you really think
> new URL(String) is faster than other constructors?

The only thing the patch tries to do is eliminate as many calls to File.isDirectory() as possible and still 
have NetBeans run - it's quick and dirty code.  None of it is pretty or necessarily correct or necessarily 
what we should do in production.  If it shows the avenues we should explore, it serves its purpose.

Re non 7-bit ASCII - I have no idea, it would have to be tested - as for new URL(String), same thing - I 
did think about the cost of the required try/catch.  The only thing I'm trying to do is show that taking I/
O out of these code paths can make a significant difference in performance.  Probably we should find 
the changes that make the most significant differences and concentrate on how to do those in a correct 
and safe way.

I'd be curious if the URL/URI caching/manual construction stuff makes a difference in JarClassLoader.  
There will be some places where it's safe to do this sort of thing and some places it won't be.
Comment 5 _ rkubacki 2005-09-30 10:49:55 UTC
OK, we know the File.isDirectory can be a problem and have a patch showing that
there are possible improvements. This patch probably needs to be refined.

Re try/catch block: should have negligible impact if there are no exception. re
URL constructors - almost all versions boils down to the same one that parses
URL so IMO there is no big difference

re JarClassLoader: how big win can we get in constructor that is called 229
during startup? I guess we could get more if we speed up creating of URL that is
returned from getResource

OK I will built it and submit to our testing machines.
Comment 6 _ tboudreau 2005-10-01 01:16:51 UTC
I'll be curious to see the results.

One place I notice a definite difference is plain old typing in the editor:  The
time between typing a character and it appearing (usually imperceptible but with
the occasional hiccup) seems shorter - below the threshold of perception.  Same
for moving the caret between lines with the mouse.  Maybe it is my imagination.

Do we have tests for that?

Also, do we run tests with jdk and/or project on an NFS mount?
Comment 7 _ rkubacki 2005-10-07 14:54:26 UTC
Created attachment 25671 [details]
jvmti agent
Comment 8 _ rkubacki 2005-10-07 14:55:00 UTC
Created attachment 25672 [details]
premain class for JVMTI aganet
Comment 9 _ rkubacki 2005-10-07 14:58:01 UTC
attached are sources of JVMTI agent that tracks who calls particular method
(grouped by given number of stack elements). This is modified demo from JDK

During start roughly half of calls goes through FileUtils.normalizeFile. We
already know this I am going to file few other IZ records for possible improvements.

Next step is to add reseting of counter so we can track this during typing.
Comment 10 _ rkubacki 2005-11-16 13:00:09 UTC
Lowering to P3 as we fixed some of these calls.

Definitely we are going to continue. Probably most of the fixes will be done
during next release. This should include improving in Java parsing (convert FO
of platform CP elements to files) for example.
Comment 11 Jesse Glick 2007-07-06 21:36:13 UTC
The patch to in particular looks dangerous. Perhaps we can use an LRU cache of some kind to try to reduce
the number of calls to File.isDirectory rather than eliminating them.
Comment 12 Jaroslav Tulach 2008-02-11 09:48:47 UTC
Pavel, looks like Radim also played with tracking agents. Anyway I believe your solution with java.lang.instrument is 
more portable. Maybe you can modify it to track also isDirectory...

Anyway, as you help Radek with his MasterFS changes, you are probably the right one to take care and close this bug.
Comment 13 Pavel Flaska 2008-02-11 10:19:23 UTC
Yes. I'll modify my agent.
Comment 14 Pavel Flaska 2008-02-16 14:05:44 UTC
I've tried to reproduce the original scenario. Unfortunately, I didn't find the patched to use the same
measuring method, so I cannot be sure that my data use the same measuring method. I will do the measurements  for the
older versions to have comparable data. (and will attach my agent for further measurements.)

From the initial measurements, it seems the number of isDirectory() method calls was reduced. I expect this is related
to recent Filesystems changes and, maybe, java infrastructure changes.

42 : /usr/java/jdk1.6.0_04/jre/lib/rt.jar
60 : /usr/java/jdk1.6.0_04/jre/lib/ext/dnsns.jar
100: /tmp/JavaApplication1/src/javaapplication1/
32 : /usr/java/jdk1.6.0_04/
60 :/usr/java/jdk1.6.0_04/jre/lib/ext/sunpkcs11.jar
61 : /usr/java/jdk1.6.0_04/jre/lib/ext/localedata.jar
Comment 15 Pavel Flaska 2008-02-19 15:58:25 UTC
Created attachment 56868 [details]
File.isDirectory() invocations
Comment 16 Pavel Flaska 2008-02-19 16:03:24 UTC
I measured the new values and dive into the problem. Seems that this issue is no longer valid, I tried the specified
use-case and it seems it works correctly, see file above.

On the other hand, we can still do some improvements here, but not sure about the gain.

Bear in mind that testing has to be done with disabled assertions!
Comment 17 Pavel Flaska 2008-02-19 16:36:56 UTC
Created attachment 56873 [details]
Samples of important call-stacks
Comment 18 Pavel Flaska 2008-02-19 16:37:48 UTC
Comment 19 Petr Nejedly 2008-02-19 17:31:42 UTC
For the record, I particularly don't like the accesses from the JarClassLoader. We tried to avoid accessing the jars (in
any way) during the startup, but the JarClassLoader ctor still needs to touch the disk, it seems, even when we're not
really opening the jars at that time.

And of course the IFL looks scary. I didn't even know it has so many clients, but every client access is multiplied by
the number of clusters!
Comment 20 _ tboudreau 2008-02-19 18:37:30 UTC
Pavle:  This problem appears only to cause serious performance on Windows (probably the implementation of file access in the JDK);  if you are going to mark 
this as fixed, did you test it there?
Comment 21 Pavel Flaska 2008-02-20 08:54:27 UTC
Yes, I run on Windows too. NetBeans are a bit slower, but I do not see huge problems.

I did some raw measuring of File.isDirectory() on both, Ubuntu and XP platforms, see: Of course, we carry on all excessive I/O operations.

I closed the issue because the number of original reported File.isDirectory() invocations was reduced significantly (of
course, many other improvements can be done.) Feel free to reopen. At least,, suspicious calls described by nenik should
be investigated.
Comment 22 _ tboudreau 2008-02-20 23:14:33 UTC
Well, probably the true test of this would be if you can work with a reasonably sized project on a USB drive without hangs...
Comment 23 Pavel Flaska 2008-02-22 08:27:24 UTC
Maybe. -- Because we still do not have reliable data from I/O measuring (and still we don't know how to get them) we
agreed with Jarda that we will focus on reducing I/O operations and we believe this will lead to the faster startup.
Comment 24 _ tboudreau 2009-07-25 09:17:51 UTC
c.f. issue 168389, probably some of the suggestions here are still worth looking at;  while startup File I/O has been
reduced, runtime performance still appears to be an issue issue 168389 looks like a duplicate of this;  issue 169166 and
issue 169160 both are related.

It also might be worth looking at how the JDK actually implements these methods - in many cases, on Windows, there are
multiple APIs to do the same thing (for example, listening for file changes - there are three Win32 APIs for it, and
which you use depends on the version of windows).  If the JDK is using the lowest common denominator, it might be
possible for the problem to be improved at the source.
Comment 25 _ tboudreau 2009-08-04 21:17:19 UTC
This issue is far from fixed.  In particular, I frequently still encounter multi-minute freezes of the AWT event thread,
and the thread dump is always in File.isDirectory(), File.isFile() or File.getCanonicalFile().

I did what I originally did - instrumenting to record calls to isDirectory(), isFile() and
getCanonicalFile() (also a frequent bottleneck in thread dumps when NetBeans is frozen - see below). 

"AWT-EventQueue-1" prio=6 tid=0x07a1c400 nid=0xa2c runnable [0x08a5e000]
   java.lang.Thread.State: RUNNABLE
        at Method)
        at org.openide.filesystems.FileUtil.normalizeFileOnWindows(
        at org.openide.filesystems.FileUtil.normalizeFile(
        at org.netbeans.modules.masterfs.filebasedfs.FileBasedURLMapper.getFileObjects(FileBasedURLM
        at org.netbeans.modules.masterfs.MasterURLMapper.getFileObjects(
        at org.openide.filesystems.URLMapper.findFileObject(
        at org.netbeans.modules.parsing.impl.indexing.RepositoryUpdater.getOwningSourceRoot(Reposito

(what this is doing running in the event queue, I have no idea)

Below is a list of the above named expensive I/O calls from NetBeans startup through 7 percent of 30 projects opened
(the added logging code is rather non-optimal), running on a real-world userdir with a number of NetBeans src module
projects open, a module suite and its modules, one web application, two j2se projects and one web application open, and
a number of files open in the editor.  I will attach a log file with actual stack traces for these.

This is startup through editors initialized, project scanning completed, opening projects 7% complete:

1253 H:\work\nbsrc2
1253 H:\work\nbsrc2
562  H:\work\PatchFile\src\java\io\
562  H:\work\PatchFile\src\java\io\
180  C:\Documents and Settings\Administrator\My Documents\NetBeansProjects\AbbreviationsTutor
180  C:\Documents and Settings\Administrator\My Documents\NetBeansProjects\AbbreviationsTutor
177  H:\work\nbsrc2\applemenu
177  H:\work\nbsrc2\applemenu
172  C:\
172  C:\
167  H:\work\nbsrc2\nbbuild\netbeans\ide11
167  H:\work\nbsrc2\nbbuild\netbeans\ide11
154  H:\work\nbsrc2\project.ant
154  H:\work\nbsrc2\project.ant
148  H:\work\nbsrc2\mobility.project\src\org\netbeans\modules\mobility\project\ui\wizard\imports\
148  H:\work\nbsrc2\mobility.project\src\org\netbeans\modules\mobility\project\ui\wizard\imports\
148  H:\work\nbsrc2\mobility.project\src\org\netbeans\modules\mobility\project\ui\wizard\imports\
146  H:\work\nbsrc2\java.platform\src\org\netbeans\modules\java\platform\ui\
146  H:\work\nbsrc2\java.platform\src\org\netbeans\modules\java\platform\ui\
133  H:\work\PatchFile
133  H:\work\PatchFile
132  H:\work\nbsrc2\java.platform
132  H:\work\nbsrc2\java.platform
131  H:\work\nbsrc2\mobility.project
131  H:\work\nbsrc2\mobility.project
130  H:\work\PatchFile\src\java
130  H:\work\PatchFile\src\java
126  H:\work\PatchFile\src
126  H:\work\PatchFile\src
122  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\dnsns.jar
122  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\dnsns.jar
119  H:\work\nbsrc2\java.j2seplatform
119  H:\work\nbsrc2\java.j2seplatform
118  C:\Program Files\Java\jdk1.7.0
118  C:\Program Files\Java\jdk1.7.0
117  H:\work\nbsrc2\mobility.cldcplatform
117  H:\work\nbsrc2\j2me.cdc.platform
117  H:\work\nbsrc2\mobility.cldcplatform
117  H:\work\nbsrc2\j2me.cdc.platform
115  H:\work\nbsrc2\nbbuild
115  H:\work\nbsrc2\nbbuild
112  H:\work\nbsrc2\javacard.project
112  H:\work\nbsrc2\javacard.project
110  H:\work\nbsrc2\contrib\jemmysupport
110  H:\work\nbsrc2\contrib\jemmysupport
107  H:\work\nbsrc2\nbbuild\netbeans\enterprise5
107  H:\work\nbsrc2\nbbuild\netbeans\enterprise5
104  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunjce_provider.jar
104  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunjce_provider.jar
103  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunmscapi.jar
103  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\localedata.jar
103  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunmscapi.jar
103  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\localedata.jar
102  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunpkcs11.jar
102  H:\work\nbsrc2\jemmy
102  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunpkcs11.jar
102  H:\work\nbsrc2\jemmy
102  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunpkcs11.jar
100  C:\Documents and Settings\Administrator\My Documents\NetBeansProjects\WebApplication15
100  C:\Documents and Settings\Administrator\My Documents\NetBeansProjects\WebApplication15

I'll attach some logs for runtime behavior, turning off logging until full initializing, when working in the editor.  

Given that these calls cause the editor to freeze, just moving the work out of the startup sequence doesn't really
address this issue at all - it just delays the expensive calls until they will have even more impact on runtime performance.
Comment 26 _ tboudreau 2009-08-04 21:50:13 UTC
Created attachment 85785 [details]
Startup log
Comment 27 _ tboudreau 2009-08-04 22:15:10 UTC
I modified my patch to be able to be turned on and off with a system property, and installed a module to add an action
to set that property to true.  The following is the number of expensive I/O calls after doing the following steps:
 - Start Netbeans on an existing userdir with a module suite application open, three J2SE projects open (one of them
using an instance of JDK 5) and one web application open
 - Go to File > Start Logging to enable logging
 - Expand one non-nbsrc NetBeans module project
 - Change window focus to another window and do not give focus back to NetBeans until logging stops

I'll attach the full log file.  Note that all of this I/O was happening when NetBeans should be *idle*:

6057 C:\Program Files\Java\jdk1.5.0_06
2621 C:\Program Files\Java\jdk1.7.0
279  C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\dnsns.jar
275  C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\localedata.jar
272  C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\sunpkcs11.jar
256  C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\sunjce_provider.jar
240  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\dnsns.jar
239  C:\Program Files\Java\jdk1.5.0_06\jre\classes
236  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\localedata.jar
235  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunjce_provider.jar
235  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunmscapi.jar
235  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunpkcs11.jar
219  C:\Documents and Settings\Administrator\
219  C:\Program Files\Java\jdk1.7.0\jre\classes
140  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\meta-index
136  C:\Program Files\Java\jdk1.5.0_06\jre\lib\rt.jar
132  C:\Program Files\Java\jdk1.5.0_06\jre\lib\jsse.jar
132  C:\Program Files\Java\jdk1.5.0_06\jre\lib\i18n.jar
132  C:\Program Files\Java\jdk1.5.0_06\jre\lib\sunrsasign.jar
131  C:\Program Files\Java\jdk1.5.0_06\jre\lib\jce.jar
131  C:\Program Files\Java\jdk1.5.0_06\jre\lib\charsets.jar
121  C:\Program Files\Java\jdk1.7.0\jre\lib\sunrsasign.jar
110  C:\Program Files\Java\jdk1.7.0\jre\lib\resources.jar
106  C:\Program Files\Java\jdk1.7.0\jre\lib\rt.jar
106  C:\Program Files\Java\jdk1.7.0\jre\lib\charsets.jar
106  C:\Program Files\Java\jdk1.7.0\jre\lib\jsse.jar
106  C:\Program Files\Java\jdk1.7.0\jre\lib\jce.jar
98   H:\work\TaxSheet\nbproject
89   H:\work\PatchFile\dist\PatchFile.jar
Comment 28 _ tboudreau 2009-08-04 22:16:31 UTC
Created attachment 85786 [details]
Logging w/ stack traces of expensive I/O calls after expanding one project
Comment 29 _ tboudreau 2009-08-04 22:19:14 UTC
Created attachment 85787 [details]
Code used for logging
Comment 30 _ tboudreau 2009-08-04 22:21:42 UTC
The attached zip file includes the projects used to generate these logs.
PatchFile just contains a patched version of w/ non-blocking logging code (logging is enabled by setting
the system property "file.log" to "true")
PatchFileTester adds an action to the file menu that toggles the system property.

Note the logging code is very slow, due to use of CopyOnWriteArrayList and ConcurrentHashMap to avoid potential locking
issues (although the periodic logging code probably does forcibly serialize some operations).
Comment 31 _ tboudreau 2009-08-04 22:36:45 UTC
A very simple case:  Close all projects except one small J2SEProject with one Main class and one text file;  before
shutting down, open Main.  Shut down IDE.

Restart IDE.  Wait 10 minutes to ensure all startup activities are finished.  Position cursor at the opening { of the
main(String[]) method.  Do not remove focus from IDE window, to avoid fs refresh activity.  Wait again to ensure any I/O
that triggered by moving the caret is done.  Now, simply press Enter.

The next attachment contains the full log of all files touched (includes files from projects that were closed before the

The following files had > 10 expensive I/O operations performed on them, simply by pressing Enter in the editor.  See
next attached log for all files touched, with stack traces:

175  H:\work\ThingSorter\src\thingsorter\
74   H:\work\ThingSorter\src
60   H:\work\ThingSorter\src\thingsorter
44   H:\ud\var\cache\index\s1002\java\14
35   H:\ud\var\cache\index\s1002\java\14\
27   H:\ud\var\cache\index\s1002\
26   C:\Program Files\Java\jdk1.7.0\jre\classes
23   H:\ud\var\cache\index\s1002\java\14\classes
22   C:\Program Files\Java\jdk1.7.0\jre\lib\sunrsasign.jar
16   H:\
15   H:\ud\var\cache\index\s1002\java
14   H:\work\ThingSorter\src\thingsorter\nbproject\project.xml
14   H:\work\ThingSorter\src\thingsorter\grails-app
14   H:\work\ThingSorter\src\thingsorter\pom.xml
12   H:\netbeans\ide11\jsstubs\
11   H:\ud\var\cache\index\s1002
11   H:\work\ThingSorter\build\classes
Comment 32 _ tboudreau 2009-08-04 22:37:23 UTC
Created attachment 85788 [details]
Log of I/O triggered by simply pressing Enter in the editor, w/ stack traces
Comment 33 _ tboudreau 2009-08-04 22:52:28 UTC
The next log shows the expensive I/O calls triggered by the following:
 - In the same Main class, invoke the start logging action, then add the lines
        JFrame jf = new JFrame();
        jf.setLayout (new BorderLayout());
using code completion where appropriate.

1606 H:\work\ThingSorter\src\thingsorter\
484  H:\work\ThingSorter\src
366  C:\Program Files\Java\jdk1.7.0\
267  H:\ud\var\cache\index\s1002
205  H:\ud\var\cache\index\s1002\TaskListIndexer\1\1
193  H:\ud\var\cache\index\s1002\java\14
167  H:\work\ThingSorter\src\thingsorter
160  C:\Program Files\Java\jdk1.7.0\jre\classes
144  C:\Program Files\Java\jdk1.7.0\jre\lib\sunrsasign.jar
139  H:\ud\var\cache\index\s1002\TaskListIndexer\1
128  H:\ud\var\cache\index\s1002\java
124  C:\Program Files\Java\jdk1.7.0
122  C:\Program Files\Java\jdk1.7.0\jre\lib\rt.jar
121  H:\ud\var\cache\index\s1002\org-netbeans-modules-jumpto-file-FileIndexer\1
112  C:\
111  H:\ud\var\cache\index\s22\java\14\classes
111  H:\ud\var\cache\index\s1002\org-netbeans-modules-jumpto-file-FileIndexer
110  H:\ud\var\cache\index\s1002\TaskListIndexer
80   H:\ud\var\cache\index\s22\java\14
77   C:\Program Files\Java\jdk1.7.0\jre\lib\ext\dnsns.jar
72   C:\Program Files
71   C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunjce_provider.jar
71   C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunmscapi.jar
71   C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunpkcs11.jar
71   C:\Program Files\Java\jdk1.7.0\jre\lib\ext\localedata.jar
70   C:\Program Files\Java\jdk1.7.0\jre\lib\resources.jar
65   C:\Program Files\Java
62   H:\ud\var\cache\index\s22\java
58   C:\Program Files\Java\jdk1.7.0\jre\lib\charsets.jar
58   C:\Program Files\Java\jdk1.7.0\jre\lib\jsse.jar
58   C:\Program Files\Java\jdk1.7.0\jre\lib\jce.jar
56   H:\ud\var\cache\index\s45\java\14\classes
56   H:\ud\var\cache\index\s19\java\14\classes
56   H:\ud\var\cache\index\s21\java\14\classes
56   H:\ud\var\cache\index\s44\java\14\classes
56   H:\ud\var\cache\index\s14\java\14\classes
56   H:\ud\var\cache\index\s1000\java\14\classes
55   H:\ud\var\cache\index\s31\java\14\classes
55   H:\ud\var\cache\index\s17\java\14\classes
55   H:\ud\var\cache\index\s25\java\14\classes
55   H:\ud\var\cache\index\s28\java\14\classes
52   H:\ud\var\cache\index\s18\java\14\classes
52   H:\ud\var\cache\index\s42\java\14\classes
50   H:\ud\var\cache\index\s22
45   H:\ud\var\cache\index\s22\java\14\classes\java\awt
44   C:\Program Files\Java\jdk1.7.0\jre
43   C:\Program Files\Java\jdk1.7.0\nbproject\project.xml
42   H:\work\ThingSorter\src\thingsorter\nbproject\project.xml
42   H:\work\ThingSorter\src\thingsorter\pom.xml
42   H:\work\ThingSorter\src\thingsorter\grails-app
40   H:\ud\var\cache\index\s1002\java\14\
40   H:\ud\var
40   H:\ud
34   C:\Program Files\Java\jdk1.7.0\grails-app
34   C:\Program Files\Java\jdk1.7.0\pom.xml
30   H:\ud\var\cache
28   H:\
26   C:\Program Files\nbproject\project.xml
24   C:\Program Files\Java\nbproject\project.xml
24   H:\ud\config\Preferences\org\netbeans
24   H:\ud\var\cache\index\s45\java\14
24   H:\ud\config\Preferences\org\netbeans\modules
24   H:\ud\var\cache\index\s21\java\14
24   H:\ud\var\cache\index\s19\java\14
23   H:\ud\var\cache\index\s18\java\14
23   H:\ud\var\cache\index\s1000\java\14
23   H:\ud\var\cache\index\s17\java\14
23   H:\ud\var\cache\index\s42\java\14
23   H:\ud\var\cache\index\s44\java\14
23   C:\Program Files\Java\jdk1.7.0\jre\lib
23   H:\ud\var\cache\index\s25\java\14
22   H:\ud\var\cache\index\s14\java\14
22   H:\ud\var\cache\index\s1002\java\14\classes
21   C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\dnsns.jar
21   H:\ud\var\cache\index\s28\java\14
20   C:\Program Files\grails-app
20   H:\ud\var\cache\index\s31\java\14
20   C:\Program Files\pom.xml
19   C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\sunpkcs11.jar
19   H:\work\ThingSorter
19   C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\localedata.jar
19   C:\Program Files\Java\jdk1.7.0\lib\dt.jar
19   C:\Program Files\Java\jdk1.5.0_06\jre\lib\ext\sunjce_provider.jar
19   H:\netbeans\platform10\lib\boot.jar
19   H:\work\ThingSorter\build\classes
19   C:\Program Files\Java\jdk1.5.0_06\jre\classes
18   C:\Program Files\Java\jdk1.7.0\jre\lib\ext\meta-index
18   C:\Program Files\Java\grails-app
18   C:\Program Files\Java\pom.xml
18   C:\Program Files\Java\jdk1.7.0\lib\tools.jar
17   H:\netbeans\platform10\lib\org-openide-util.jar
17   H:\netbeans\platform10\lib\org-openide-modules.jar
17   H:\work\PatchFile\dist\PatchFile.jar
14   H:\ud\var\cache\index\s22\java\14\classes\java
14   H:\ud\var\cache\index\s1000\java\14\classes\java
12   C:\Program Files\Java\jdk1.7.0\jre\pom.xml
12   C:\Program Files\Java\jdk1.5.0_06\jre\lib\rt.jar
12   C:\Program Files\Java\jdk1.7.0\jre\grails-app
12   C:\Program Files\Java\jdk1.7.0\jre\nbproject\project.xml
12   H:\ud\var\cache\index\s1000\java\14\classes\java\awt
11   H:\ud\config\Preferences\org\netbeans\modules\
11   H:\ud\var\cache\index\s1002\java\14\classes\thingsorter\Main$X.sig
11   H:\work\ThingSorter\src\java
11   H:\ud\var\cache\index\s1002\java\14\classes\thingsorter\Main.sig
Comment 34 _ tboudreau 2009-08-04 22:53:12 UTC
Created attachment 85789 [details]
Log for adding JFrame to main()
Comment 35 _ tboudreau 2009-08-04 23:05:39 UTC
In the following case, I initiated logging, then
 - Created a new project
 - Using code completion and Override Methods and the Implement All Abstract Methods and Fix Imports hint where
appropriate, I created the code below.

In this case, I modified the filtering in the patched to only log expensive I/O if it were performed in the
event thread.  Simply typing this code in the editor resulted in a total of 32345 expensive blocking I/O calls performed
in the event thread.  And bear in mind this is a simple J2SE project with no dependencies using the default JDK.  There
were three J2SE projects open - ThingSorter (a project that simply sorts the logging output I've been pasting in below),
the project for patching, and the project I created while logging was enabled.

public class Main {
   public static void main(String[] args) {
        JFrame jf = new JFrame() {
            protected JRootPane createRootPane() {
                return super.createRootPane();
            public void repaint(long time, int x, int y, int width, int height) {
                super.repaint(time, x, y, width, height);
            public void setGlassPane(Component glassPane) {
        jf.setLayout (new BorderLayout());
        JButton jb = new JButton("Hello");
        jf.add (jb, BorderLayout.CENTER);
    private static final class AL implements ActionListener {
        public void actionPerformed(ActionEvent e) {
            System.out.println("Hello world");

4206 H:\work\JavaApplication9\src\javaapplication9\
3684 H:\
1790 H:\work\JavaApplication9\src
1367 H:\netbeans\ide11\jsstubs\
960  H:\ud\var\cache\index\s1010
726  H:\work\ThingSorter\src
720  H:\work\ThingSorter\test
715  H:\work\PatchFile\src
713  H:\work\PatchFile\test
697  H:\ud\var\cache\index\s1010\TaskListIndexer\1\1
666  H:\ud\var\cache\index\s1010\java\14
666  H:\work\JavaApplication9
519  H:\ud\var\cache\index\s1010\org-netbeans-modules-jumpto-file-FileIndexer\1
436  H:\ud\var\cache\index\s1010\TaskListIndexer\1
414  H:\ud\var\cache\index\s1010\java
358  C:\Program Files\Java\jdk1.7.0\jre\classes
354  H:\ud\var\cache\index\s1010\org-netbeans-modules-jumpto-file-FileIndexer
354  H:\ud\var\cache\index\s1010\TaskListIndexer
348  H:\work
319  C:\Program Files\Java\jdk1.7.0\jre\lib\sunrsasign.jar
282  H:\work\JavaApplication9\build
279  H:\work\JavaApplication9\test
251  C:\Program Files\Java\jdk1.7.0\
237  H:\work\JavaApplication9\src\javaapplication9
232  H:\work\JavaApplication9\dist
231  C:\Program Files\Java\jdk1.7.0\jre\lib\rt.jar
175  H:\ud\var\cache\index\s1010\
173  H:\ud\var\cache\index\s1010\java\14\
149  H:\ud\var\cache\index\s22\java\14\classes
141  H:\work\JavaApplication9\nbproject\project.xml
139  C:\Program Files\Java
137  C:\Program Files\Java\jdk1.7.0
128  C:\
123  C:\Program Files
123  H:\work\JavaApplication9\nbproject
114  H:\work\JavaApplication9\build\generated-sources
113  H:\work\JavaApplication9\nbproject\private\
112  H:\ud\var\cache\index\s22\java\14
110  H:\work\JavaApplication9\nbproject\
109  H:\work\JavaApplication9\build\classes
109  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\dnsns.jar
102  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\localedata.jar
101  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunjce_provider.jar
101  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunmscapi.jar
101  C:\Program Files\Java\jdk1.7.0\jre\lib\ext\sunpkcs11.jar
100  C:\Program Files\Java\jdk1.7.0\jre\lib\resources.jar
Comment 36 _ tboudreau 2009-08-04 23:06:27 UTC
Created attachment 85790 [details]
Log file for new project and adding code, filtered for only I/O in event thread
Comment 37 _ tboudreau 2009-09-08 19:49:30 UTC
Some info I got from Jeff Richter, formerly of Microsoft, re Win32 file API calls.  Probably the most relevant detail is that any call to File.isDirectory() will 
cause the OS to put the calling thread to sleep for some amount of time.

 - Is GetAttributesEx the optimal call to be using in modern versions of Windows?
[JR] Yes.

   - Is there any internal synchronization that could be serializing such calls, making contention the source of the bottleneck?
[JR] Absolutely. When you call GetAttributesEx, your thread calls into the kernel, the I/O request is queued to the device driver and your thread is put to 
sleep. The driver then handles the request (along with other queued requests) and wakes your thread up so it can return. Depending on the various 
outstanding I/O requests that are queued, they can't all happen at once especially if the disk head has to move.

 - At worst, is there any way to ensure that metadata about files which are frequently stat'd are retained in the OS filesystem cache?
[JR] No as there could be hundreds of thousands of files and keeping all this data would hurt other parts of the system too much.

 - Any other thoughts on strategies to work around this issue?
[JR] I've never heard of anything like you describe and I have been in this are for 20 years or so now. I can't really believe that GetAttributesEx is actually the 
problem at all. I would think that something else is happening.

We're encountering this problem on fast, local drives - primarily NTFS
- so I'm not talking about remote filesystems or USB drives or anything like that here.  While we are working to cut down the amount of I/O performed, 
app- or VM-level attribute-caching is not an option because we need an accurate representation of the filesystem state.

Windows has Event Tracing for Windows (ETW).
This mechanism records/logs events that are happening in the system including I/O events.
You can then filter these events down to see just the ones for a single process using tools like xperf.exe.
I don't know if it offers as much details as you're looking for.
Comment 38 NukemBy 2016-09-14 13:58:34 UTC
I'd like to resurrect that ancient issues becase

a) self-profiler shows that 3sec out 11sec (or 30%) during initial load of the project goes to WinNTFileSystem.getBooleanAttributes()
b) i have a solution for that problem

Short answer ...

switch to proper java.nio API and never call any of File.isFolder(), File.getCanonicalFile(), File.getAbsoluteFile().

Long answer ...

1) It appears that native WinNTFileSystem.getBooleanAttributes() is a very resource-consuming operation. It is called once from File.isFolder() and many times from File.getCanonicalFile() and File.getAbsoluteFile() - it means that these calls should be avoided as much as possible.

Typical problemous code looks like following: `dir.listFile()` -> exclude non-files via `file.isDirectory()`.
Below is method using such implementation and which is the bottleneck for many operations:


    final class FileObjectKeeper implements FileChangeListener {

        final synchronized FileObjectKeeper getKeeper(Collection<? super File> arr) {
            if (keeper == null) {
                keeper = new FileObjectKeeper(this);
                List<File> ch = keeper.init(-1, null, false);

         public List<File> init(long previous, FileObjectFactory factory, boolean expected) {
             List<File> arr = new ArrayList<File>();
             long ts = root.getProvidedExtensions().refreshRecursively(file, previous, arr);
             try {
                 for (File f : arr) {
                     if (f.isDirectory()) {

It appears that java.nio provides one of the methods to list files absolutely without need for file.isDirecory(). The same functionality can be rewritten with java.nio like following:

    List<Path> list = Files.find(dir, 1, (path, attrs) 
            -> !attrs.isDirectory()).collect(Collectors.toList());

    Note: file `attrs` provided by find() can be cached for later use to avoid need to call methods like
    file.isFolder(), file.length() and other later. 

    Look here for more details

Files.find() appears to be 10 times quicker than `dir.listFile()`->`file.isDirectory(), BUT wrong API appears to be 4 times slower. 

Here are the results of JMH test (sources will be attached below). The test lists 'files-only' in Netbeans source directory with 50 iterations per 'operation' : 

Benchmark                  Mode  Cnt  Score    Error  Units
MyBenchmark.dir_listFiles  avgt    5  0.437 ?  0.064   s/op
MyBenchmark.path_find      avgt    5  0.046 ?  0.001   s/op
MyBenchmark.path_walkTree  avgt    5  1.702 ?  0.047   s/op

2) It appears that across sources of NetBeans there are places where usage of File.isFolder|getCanonicalFile|getAbsoluteFile() can be avoided by

- caching the 'canonical' path, isFolder flag, if its going to be used later multiple times
- not calling these methods one after another in the same method

Some examples of such cases can be found here: ('flag' isNormalized can be made as a cacheble property of FileObject).
Comment 39 NukemBy 2016-09-14 14:00:25 UTC
Created attachment 162048 [details]
JMH test mentioned at 2016-09-14 13:58:34 UTC
Comment 40 NukemBy 2016-09-15 16:01:00 UTC
Below is one more code sample where unneeded call to file IO is invoked - in this case it is enough to check for binaryFile.isFile() - it will return false if file do not exist, preceding 'binaryFile.exists()' just have no sense here, but fill cause invocation of expensive "WinNTFileSystem.getBooleanAttributes[native] ()"

public class RepositoryForBinaryQueryImpl extends AbstractMavenForBinaryQueryImpl {

    private List<Coordinates> getJarMetadataCoordinatesIntern(File binaryFile) {        
        if (binaryFile == null || !binaryFile.exists() || !binaryFile.isFile()) {
            return null;

    public static List<Coordinates> getJarMetadataCoordinates(File binaryFile) {
        if (binaryFile == null || !binaryFile.exists() || !binaryFile.isFile()) {
            return null;
Comment 41 NukemBy 2016-09-19 06:11:38 UTC
Created attachment 162106 [details]
JMH test for various file access API's
Comment 42 NukemBy 2016-09-19 06:18:40 UTC
I've created JMH test to check if some APIs from java.nio can be used to replace old file API in terms of performances. Results are not encouraging - below are the numbers for verifying of pre-collected lists of file paths in Netbeans install dir, Win7 x64 & Java 8 u102.  

    Running over --- 4399 --- paths

    Benchmark                         Mode  Cnt   Score    Error  Units
    FileAccess.file_new               avgt    5   0.001 ?  0.001   s/op
    FileAccess.file_exists            avgt    5   0.233 ?  0.002   s/op
    FileAccess.file_isFile            avgt    5   0.231 ?  0.001   s/op
    FileAccess.file_getAbsoluteFile   avgt    5  ? 10??            s/op
    FileAccess.file_getAbsolutePath   avgt    5  ? 10??            s/op
    FileAccess.file_getCanonicalFile  avgt    5   0.572 ?  0.012   s/op
    FileAccess.file_getCanonicalPath  avgt    5   0.575 ?  0.004   s/op
    FileAccess.path_toFile            avgt    5   0.001 ?  0.001   s/op
    FileAccess.paths_get              avgt    5   0.008 ?  0.001   s/op
    FileAccess.paths_exists           avgt    5   0.383 ?  0.003   s/op
    FileAccess.paths_exists_real      avgt    5   0.383 ?  0.003   s/op
    FileAccess.paths_toAbsolutePath   avgt    5  ? 10??            s/op
    FileAccess.paths_toRealPath       avgt    5   1.895 ?  0.027   s/op
    FileAccess.paths_toRealPath_nf    avgt    5   2.027 ?  0.014   s/op