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 221421 - 100% CPU busy for 60 Seconds for a One Line Change
Summary: 100% CPU busy for 60 Seconds for a One Line Change
Status: RESOLVED WONTFIX
Alias: None
Product: javaee
Classification: Unclassified
Component: EJB (show other bugs)
Version: 7.3
Hardware: PC Windows XP
: P1 normal (vote)
Assignee: Martin Fousek
URL:
Keywords: PERFORMANCE
Depends on:
Blocks:
 
Reported: 2012-11-04 05:10 UTC by bht
Modified: 2012-11-06 13:08 UTC (History)
1 user (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
NetBeans snapshot (141.33 KB, application/octet-stream)
2012-11-04 05:10 UTC, bht
Details
logs in zip file (88.93 KB, application/octet-stream)
2012-11-05 08:46 UTC, bht
Details
Task Manager screen shot (61.86 KB, image/gif)
2012-11-05 08:48 UTC, bht
Details
selfsampler snapshot file (616.78 KB, application/octet-stream)
2012-11-05 17:38 UTC, bht
Details
self sampler and logs in zip file (460.73 KB, application/octet-stream)
2012-11-06 09:33 UTC, bht
Details

Note You need to log in before you can comment on or make changes to this bug.
Description bht 2012-11-04 05:10:11 UTC
Created attachment 127071 [details]
NetBeans snapshot

I add a blank line in an EJB, save it and then switch to another tab containing a test class with the aim of testing it.

After switching to the test class, the CPU is 100% busy for more than 60 seconds.

This is reproducible.

In NetBeans 7.1.2, the same process, with the same number and identities of projects open, takes 30 seconds - still extreme.

There are a number of issues regarding slow NT file system access, and I hit them very often.

My suspicion is that this kind of CPU use causes everything to slow down, and that complicates defect analysis.
Comment 1 bht 2012-11-04 05:15:45 UTC
I have to wait the same time to get the the context menu item for testing a single method.
Comment 2 bht 2012-11-04 07:40:50 UTC
If I wait 20s after saving the EJB and then switch to the test class then overall CPU time is reduced significantly may be by 25%. So there is probably a contention problem.

There is only 1 line in the log during this process:

INFO [org.netbeans.modules.parsing.impl.TaskProcessor]: Task: class org.netbeans.modules.java.editor.semantic.SemanticHighlighter ignored cancel for 219 ms.

No scanning is reported in the status bar. I/O Reads count delta before and after in task manager is 6791.
Comment 3 Dusan Balek 2012-11-05 08:10:53 UTC
Could you please attach IDE logfile? Thanks.
Comment 4 Dusan Balek 2012-11-05 08:15:05 UTC
As can be seen from the attached snapshot, most of the time is spent in the UseInjectionInsteadOfInstantionRule computation, however the real problem seems to be an extremely slow WinNTFileSystem. Reassigning to EJB for further evaluation.
Comment 5 bht 2012-11-05 08:46:56 UTC
Created attachment 127115 [details]
logs in zip file

I re-started NetBeans, then waited 15 seconds after CPU was down to 0, then reproduces the issue. Then after a few seconds I made a screenshot of task manager and copied the log files.

In the screen shot you can see the two blocks of 100% CPU, the first being the startup, the second being the test.

During the test (60 seconds) you can see two downward spikes. This is where the I/O counter shows I/O activity. Otherwise during the 100% flat periods the I/O counter does not register any I/O.
Comment 6 bht 2012-11-05 08:48:38 UTC
Created attachment 127116 [details]
Task Manager screen shot
Comment 7 bht 2012-11-05 08:54:29 UTC
This looks like a good opportunity to identify and fix this long-standing NT file system issue or whatever it is. I do not have any issues with this computer with any other programs. I am in control of the computer - I can uninstall or disable programs, I can add debugging parameters, tune memory parameters - whatever you suggest.
Comment 8 Martin Fousek 2012-11-05 13:15:39 UTC
It looks to me that there is not much to do in the JEE area. At least I removed unnecessary call of "SourceUtils.getFile()" which took about 10s in your case but usually is fast: web-main #39ffdf1b649c

I totally agree with DusanB that the problem lies in very slow WinNTFileSystem opetations. For assurance I talked to our performance gurus. It could be also caused by too little of memory which got your Java Virtual Machine and theoretically your processor could be busy by Garbage Collection. In any case you can still try to send us your .npss snapshot. It's saved after profiling into your TEMP directory. It will be called snapshot<some_numbers>.npss so please attach it by during your processor troubles and reopen the issue again. Thanks.
Comment 9 bht 2012-11-05 17:38:36 UTC
Created attachment 127169 [details]
selfsampler snapshot file

I have attached the corresponding .npss snapshot from the temp dir.

If a slow NTFS file system is the root cause, then

1) why does the Windows Task Manager not register any I/O call counts for tens of seconds when the CPU is flat 100% ? Does this mean that all CPU is burnt just while waiting for I/O to occur? This does not make sense to me.

2) why is it that NetBeans 7.3 takes 100% longer than NetBeans 7.1.2

3) what is it in the NTFS file system that is slow and how can I make it faster

Thank you
Comment 10 Quality Engineering 2012-11-06 03:11:41 UTC
Integrated into 'main-golden', will be available in build *201211060001* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main-golden/rev/39ffdf1b649c
User: Martin Fousek <marfous@netbeans.org>
Log: #221421 - 100% CPU busy for 60 Seconds for a One Line Change
Comment 11 bht 2012-11-06 09:33:08 UTC
Created attachment 127198 [details]
self sampler and logs in zip file

With the latest build, 10 seconds off, now 50 seconds. Could we please have more of this?
Comment 12 Martin Fousek 2012-11-06 13:08:44 UTC
(In reply to comment #9)

Thanks for both snapshots.

> 1) why does the Windows Task Manager not register any I/O call counts for tens
> of seconds when the CPU is flat 100% ? Does this mean that all CPU is burnt
> just while waiting for I/O to occur? This does not make sense to me.

Right, but take a look on the last npss you attached. There, if you move mouse cursor over timeline next to "Probes" title you will see when samples were read. For 60s snapshot it should be almost fulfilled line. Empty spaces in your ones means garbage collection which probably takes your processor time. Notice that your GC ran during 60s three times for very long time 5-10s. It indicates that your JVM was quite out of memory.
 
> 2) why is it that NetBeans 7.3 takes 100% longer than NetBeans 7.1.2

Since the real time is spent in the native calls, any small change can lead to more such calls which can increase the processing time. The npss#2 made good example ... java.io.WinNTFileSystem.getLastModifiedTime[native]() took over 3,5s so several such calls can lead to big slowdowns. :/ Of course everytime it's not so slow and the time was spent in many slow native calls.

> 3) what is it in the NTFS file system that is slow and how can I make it faster

I'm afraid that we didn't find any pattern for that so far. You can probably try out disabled ?Antivir?, Anti-spyware or another runtime scanning software (do you really want to try that?) or any other program or environment setup which will cross your mind that could be cause of slowness. This BZ is probably not good place to ask for slow FS, sorry.

One thing which could help a little bit to you environment would be increase of the memory limits. But that is not a cure for the slow filesystem. I'm really sorry, but I don't see anything else what we can do here. I removed piece of useless code which took to you 10s and it commonly takes 10ms to me. In any case if you would detect cause of your I/O slowness please let us know, we would really appreciate that. I'm closing this as wontfix because of reasons mentioned above.