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.
[ BUILD # : 201003140200 ] [ JDK VERSION : 1.6.* ] I have left the IDE running for a while while I was away from the pc, with an active java debugging session. When I returned to the computer, the IDE seemed very slow: I have been able to stop the debugger but netbeans froze completely.
Created attachment 95204 [details] Frozen IDE thread dump
I correct myself: netbeans didn't freeze, but it became _very_ slow. I'm attaching the ide log.
Created attachment 95205 [details] ide log
This does not look like a bug in debugger. thread_dump does not show anything interesting, in messages log we get many messages like: Too much time (2033 ms) spend touching /home/aldo/develop/teko/omc-main/clusters/omc-core/omc-devices/src/com/teko/omc/emulation/ZefeerEmulator.java and: too much time in AWT thread org.netbeans.modules.profiler.actions.SelfSamplerAction$Controller@ac5d1b Since we do not know who initiates the touch (likely Java module, but it's not clear if it's done in AWT thread), I'm moving this to profiler to evaluate the time spent in SelfSamplerAction.
According to thread dump, filesystem refresh is running. To diagnose the problem, we need more information. Please use 'Profile Me Now' <http://wiki.netbeans.org/FitnessViaPartnership> to profile IDE and attach resulting NetBeans Profiler snapshot to the issue. Thanks.
Created attachment 95417 [details] profiler snapshot Taking a profiler snapshot when the ide is so unresponsive is not very easy, but this time I succeeded. I think this is the same problem I had reported previously, so probably the fact that the first time I had been away from the computer for a while is irrelevant. After a minute the ide returned to work normally.
Created attachment 95451 [details] profiler snapshot
An exception report is related to this issue: http://statistics.netbeans.org/analytics/exception.do?id=356042
This is very good snapshot: https://netbeans.org/bugzilla/attachment.cgi?id=95417 97s in org.netbeans.modules.viewmodel.TreeModelNode.refresh() is quite a lot Martine, please note that the number of invocations between org.netbeans.modules.debugger.jpda.ui.models.DebuggingNodeModel.loadFrameDescription() and org.netbeans.api.debugger.Session.lookupFirst() increased significantly. I am not sure how important is that, but there seems to be some kind of loop there.
Thanks for that profiler snapshot.
Created attachment 96694 [details] profiler snapshot 1) set breakpoint on a SelectOneMenu's value change listener 2) began inspecting fields of the ValueChangeEvent 3) debugger became unresponsive 4) started profiler, waited for several minutes 5) took snapshot
Additional profiler snapshots can be found attached to issue 174668.
Created attachment 96765 [details] profiler snapshot Set two breakpoints. Breakpoint hit, expanded "this" and one field of the class being debugged. Debugger became slow immediately, started profiler. Several minutes before all 44 variable values were displayed.
Created attachment 96807 [details] profiler snapshot Similar trace. Started profiler before attaching debugger, four breakpoints set. On first breakpoint, stepped through four lines of code and entered another method, stepped through about a dozen lines of code and inspected a couple of variables; debugger became completely unresponsive (NetBeans at close to 100% CPU, not even "please wait" in debugger's variables pane).
Created attachment 96872 [details] profiler snapshot Started profiler, attached debugger. One breakpoint hit, one variable expanded in variables view. Debugger had not finished displaying variable values after four minutes. Several times during this period, the variables display cleared and began repainting again from the point where an hourglass cursor appears with "Please wait...".
Thank you for the profiler snapshots. They show activity in debugger I/O, in slowness logging (which seems to add to the hung of NetBeans) and also some probably unnecessarily big refreshing of variables. I'm trying to identify if there are some unnecesary refreshes of the Variables view...
Created attachment 96891 [details] profiler snapshot I started the profiler, attached the debugger, selected the Variables tab and then hit a breakpoint. It took a minute to step one line of code the first time, and a minute and a half the second time. The list of variables seemed to get sorted a couple times. For most of the time it was evaluating and then slowly populating each variable.
I am using Netbeans 6.8 and I believe I'm experiencing the same bug. The debugger is so slow that it's unusable, although there are never any exceptions or crashes. While the debugger is churning, the "Continue" and "Step Over" buttons in the NetBeans toolbar rapidly flicker between disabled to an enabled. This happens for me very consistently and has unfortunately forced me to downgrade. Although this bug seems to be covered well, let me know if I can provide any additional information.
I just had my first debugging session with 6.9beta and it's still painfully slow to single-step in the debugger. At times, it takes 1/2 minute before you can get to the next step...mind you, I'm debugging the same program that stepped in 1/2 second in 6.8. One time, I wasn't sure what was going on: the green line indicating the stepped on line was green - i.e. NB indicated that it had already stepped to the new line - but the "play" and "step-over" buttons were still greyed out? Another time things just hangs for a long time with the Variables window showing "Evaluating...." on a bunch of the variable and at the bottom, I see "Checking for external changes..." - see the attached screen shot (the fact that I have the time to take a screen shot while waiting to step between lines should give another indication that things are a tad slow). As per suggestion from the nbusers mailing list, I'm also including a profiling snapshot that was taken during the slowness. Let me know if you need any further data. Environment: 6.9beta on Ubuntu 9.10 with JDK 1.6_20
Created attachment 98207 [details] profiler snapshot for twolfs comment
Created attachment 98208 [details] image of debugger taking time to 'evaluate' variables Image showing "Evaluating..." in Variables window and "Checking External Changes..." in status.
Created attachment 98257 [details] snapshot when debugger was slow see snapshot attached, debugger was very slow, each step took 2-5 seconds
Most of the snapshots reveal that o.n.m.viewmodel.TreeModelNode$MyProperty.getValue() is waiting in AWT thread during painting for data from debugger. This is especially significant in snapshots from gholmer (who is debugging a remote app in GlassFish I believe, which makes this problem more visible). This is wrong and should be fixed, but does not seem to be the main problem because 1) it is not in all reported snapshots, 2) the overall time spent there is not that big (except one or two cases) and 3) the debugger is able to run quickly over the same code - the slowness is occasional, though quite frequent sometimes. Overall it looks like the debugger was doing some refreshes again and again (flickering buttons in toolbar, variables view repeatedly cleared and computed again), reading lots of data from the debugged process, also doing lots of repainting. Sometimes it gets stuck completely (people see "Evaluating..." in variables that does not finish). It seems this was present in 6.8 as well, though in current 6.9 dev builds it is significantly worse.
*** Bug 184250 has been marked as a duplicate of this bug. ***
Steps how to reproduce slow refreshing of variables using AnagramGame sample module: - set breakpoint at line 222 - start debugger - push "New Word" button, debugger stops at the breakpoint - go to Variables view, expand this->aboutMenuItem->Inherited->model - perform Step Over several times, do it fast, do not wait till variables are refreshed - whenever the end of nextTrialActionPerformed() method is reached, continue with debugging and stop again at the breakpoint With growing number of Step Over actions performed, refreshing of variables is slower and the debugger is less responsive. Sometimes it gets stuck completely. During refreshes, make a thread dump. There are usually 3 to 5 "JPDA Debugger" threads running, each of them executing VariablesFormatterFilter.doExpandTest(), implementation of this method requires further evaluation.
*** Bug 184797 has been marked as a duplicate of this bug. ***
One problem is that a lot of nodes (org.netbeans.modules.viewmodel.TreeModelNode) is held in memory and it looks like all these nodes (which might not be visible any more) are still being refreshed. The references point to org.netbeans.swing.outline.TreePathSupport, which caches expanded paths. The paths do not seem to be cleared. When I remove the caching, the node proliferation stops, steps do not take so long, but still there are apparent some repetitive refreshes and not all paths are correctly expanded after each refresh. But it's clear that the caching of nodes makes the biggest evil here.
I've submitted bug #185504 for the memory leak.
In some snapshots there's visible spend time in JPDAClassTypeImpl.isInstanceOf() method. I've done some measurement and it looks like the problem is only the number of invocations, not the time spent in one call. One call takes about 0.1 - 1 ms. The number of invocations can be several thousands during one step when there's a lot of rows in the Variables view and thus spending time for several seconds.
Performance of doExpandTest() was improved in changeset: 169885:201d7fc54237 http://hg.netbeans.org/main/rev/201d7fc54237
Integrated into 'main-golden', will be available in build *201005060200* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress) Changeset: http://hg.netbeans.org/main/rev/ User: Log:
*** Bug 185584 has been marked as a duplicate of this bug. ***
I tried build 201005060200 and the situation is much improved (debugging is usable again!), although stepping over is still a bit sluggish. With the latest build, stepping over a line takes 1 to 1.5 seconds for me. The 'Continue' button in the toolbar visibly flashes between disabled and enabled state two to three times per step. The variables / watches view takes 2-3 seconds after the step is complete to fully refresh. First, all the variables disappear and I see the text "Please wait..." in the variables view. Then, the variables appear, but all values are displayed as "Evaluating...". Then, the values for the variables are populated, in mostly top-to-bottom order.
Thanks for your tests. I've found further problems: 1) Values of all fields of all expanded variables are loaded after each step even if they are not visible in the view. This is there from the beginning, unfortunately, and can also be causing bug #46286. 2) Variable models fire children change event for every node that is asked for a property value. This was done to make the children up-to-date when variable value changes. But when all variables are being refreshed, this is causing too many (repetitive) children refreshes. 3) When watches and evaluator result are included in Variables view (the default setup), refresh fired by watches model and evaluator result model force to refresh the variables again.
Optimizations associated with problem 1) implemented in changesets: 170348:5eb8cd9c5a62 - Further optimization of doExpandTest() for true/false constants. 170349:062cd1b6b07e - Load node's display name and icon lazily. This prevents from unnecessary calls to models. 170350:d0cc4aec2ca5 - Create the property sheet lazily. This speeds up creation of TreeModelNode objects. 170351:8ae9da31f339 - Adaptive property refresh time, prevents from too much time spent in AWT thread if a lot of properties are loaded. 170352:c1bfcf771d6b - Load field values lazily to reduce debugger communication. 170353:83bd3314be5e - Initiate the children expand test in isLeaf() to call it only when it's really needed. 170354:f2cc9ae0a872 - Do caching of variable formatters so that they do not have to be re-loaded every time they are needed. http://hg.netbeans.org/main/rev/5eb8cd9c5a62 http://hg.netbeans.org/main/rev/062cd1b6b07e http://hg.netbeans.org/main/rev/d0cc4aec2ca5 http://hg.netbeans.org/main/rev/8ae9da31f339 http://hg.netbeans.org/main/rev/c1bfcf771d6b http://hg.netbeans.org/main/rev/83bd3314be5e http://hg.netbeans.org/main/rev/f2cc9ae0a872 Too many children refreshes as described in problem 2) still remains there.
Problem 2) is fixed in changeset: 170356:aeefae2f5754 Refresh of children after get value is not necessary any more in variable models. http://hg.netbeans.org/main/rev/aeefae2f5754 Problem 3) is fixed in changeset: 170357:49bc85007f54 http://hg.netbeans.org/main/rev/49bc85007f54 Any node should be refreshed just once per step and only visible variables should be loaded. The performance should be significantly improved. Please verify.
Integrated into 'main-golden', will be available in build *201005100200* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress) Changeset: http://hg.netbeans.org/main/rev/ User: Log:
I just tested build 201005112200 and compared it against build 201005060200. Same machine, same project, same breakpoints, same netbeans.conf. The refreshing of the variable view is much faster now. However every step, without fail, takes 9-10 seconds. Build 201005060200 takes 1-2 seconds per step. The "Step over" button is disabled the whole time and not flickering like before. The 10 seconds per step in the new nighty almost seems like a network timeout (it's very regular). I should mention I have entries such as "blocked_site.com 127.0.0.1" in my /etc/hosts. Also, I have rather nonstandard NetBeans launch options. Here they are netbeans_default_options="-J-client -J-Xverify:none -J-Xss2m -J-Xms256m -J-XX:PermSize=64m -J-XX:MaxPermSize=200m -J-Dapple.laf.useScreenMenuBar=true -J-Dsun.java2d.noddraw=true -J-Dsun.java2d.opengl=true -J-Dsun.java2d.d3d=false -J-Dawt.nativeDoubleBuffering=true -J-Xmx512m -J-XX:+AggressiveOpts -J-XX:+UseConcMarkSweepGC -J-XX:+CMSClassUnloadingEnabled -J-XX:+CMSPermGenSweepingEnabled" I attempted to take a profiler snapshot by launching another instance of NetBeans and attaching the profiler to the 201005112200 instance. I'm probably doing something wrong because it ended up hanging the profiled NetBeans.
It's not necessary to launch another instance of NetBeans just to take a profiler snapshot. Please use the icon in the toolbar. Press it once just before you press the step button and then after the step finishes. Without the profiler dump we can hardly guess what NetBeans do during the 10 seconds. Was CPU being used during that time?
CPU usage shoots up when I initiate a step. Even after the step is done, it remains high for about 20 seconds before dropping down to idle. Taking another step initiates another 30 seconds of high CPU usage. Not sure what you mean about the profiler. I can either "Profile Main Project...", which is the program I'm stepping through, rather than NetBeans. Or, I can "Attach Profiler...", but the profiler won't attach to itself.
Please have a look at http://wiki.netbeans.org/FaqProfileMeNow NetBeans have self-profiling feature in the Memory toolbar.
Created attachment 98884 [details] new snapshot Dev 201005112200 still very slow
Created attachment 98886 [details] Taking one step with build 201005101712. Ok, I made a snapshot of NetBeans taking forever to step over one line. The reason I didn't see the self profile feature is because I had the NetBeans memory toolbar enabled but I had NetBeans resized to a small window. The memory graph was visible, but the other two buttons were not - they showed up after I maximized NetBeans.
Created attachment 98888 [details] NetBeans self-profile snapshot Profiled while debugging Java EE 6 app running under GlassFish on the same machine ("attach debugger"). Stepped through about a dozen lines, each step took about ten seconds.
Created attachment 98889 [details] NetBeans self-profiler dump Similar dump. Stepped through two lines of code; the second took over a minute.
Thank you for the snapshots. Can you please attach also screenshots of the IDE (or at least Variables view) after the long step finishes so that we can see how many watches/variables and of which type do you have opened there? From the profiler dumps it's apparent that the time is mostly spent in variable formatters. Did you add your own variable formatters in the Java Debugger Options? Also, can you try to disable all existing formatters to see if it will speed up stepping? I've made some test with stepping while having expanded local variables with Map variables and it really slows stepping down. But have never had to wait for 10 seconds, it was like 2 or 3 seconds. Egor, in your snapshot there is very active the parsing thread. Is stepping slow even after all parsing is finished?
Martin, it is hard to answer your question. With fresh IDE debugging works fine but after some time it gets slower and slower. After that suddenly external changes scanning starts and everything becomes extremely slow. After that is is almost impossible to say what's happening. One core is 100% busy all the time even when you just stare at the screen. I will attach more snapshots.
Thanks. Can you please test it also with variable formatters all turned off? According to my current observations, formatter expressions are evaluated unnecessarily several times. This certainly consumes CPU. It would be good to know if there are not other problems, which would show up when formatters are disabled. Variable Formatters can be disabled (or modified) in Tools -> Options -> Miscellaneous -> Java Debugger -> Variable Formatters.
Created attachment 98931 [details] Build 201005101712; all formatters turned off; one step in the debugger Turning off all the formatters improved the debugging speed to what it was in build 201005060200. It could probably still stand to be improved a bit (some steps take up to 3 seconds, while others are instant). I took a snapshot of taking a single step; it wasn't a particularly slow step.
I've improved performance with variable formatters in changeset: 170833:f6f58e8e726f http://hg.netbeans.org/main/rev/f6f58e8e726f Maybe it will also slightly improve the performance without formatters.
*** Bug 186152 has been marked as a duplicate of this bug. ***
Closing as fixed, I hope that the performance is acceptable now. Please verify after it gets integrated into some build... Thanks.
Integrated into 'main-golden', will be available in build *201005170932* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress) Changeset: http://hg.netbeans.org/main/rev/ User: Log:
Integrated into 'main-golden', will be available in build *201005182201* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress) Changeset: http://hg.netbeans.org/main/rev/ User: Log:
Created attachment 99208 [details] Video of Neteans 201005182201 stepping over. (Formatters turned off) The debugging in build 201005182201 is usable. I guess the bug can be closed, but the speed is probably still up not to par. I'm running NetBeans on a very powerful machine (i5, 8gb of RAM) and stepping over a relatively simple Java SE program, with all variable formatters turned off. I attached a screencast video so you can judge for yourself whether the speed is acceptable.
Thanks for that. I think that we can not make it better without canceling of the refreshing of all variables when a new step is performed. We want to improve that into the next release, I'll submit an enhancement for that. Till that is improved, it helps to temporarily switch from Variables window to some other, or reduce the size of the Variables window to have visible only the variables/watches you're interested in.
@stiffuser, I just tried the daily and stepped through my SE application. Debugging for me is much faster than it used to be (good job Martin!) Interestingly, stepping for me appears to also be faster than your setup - and I have a 5-year-old 2GB Centrino Duo laptop. I noticed you're using a Mac whereas I use Ubuntu - perhaps some of the lack of speed is attributable to the JDK on the Mac? Just a thought.
It seems very much faster here, I did a lot of complex debugging today.
The video also includes a CPU usage indicator graph. Note that taking steps makes NetBeans max out all four cores. Perhaps there is a Mac-specific issue with debugger speed.
Created attachment 99533 [details] snapshot still slow, especially when step requires opening a new file in the editor. I disabled ExternalChanges checking and do not have any debugger views visible.
Debugger reopens files in the same editor causing versioning and all highlighting to work again and again. This causes some slow down. With "Reuse editor" disabled in Miscellaneous/Java debugger it is much faster (when all required files are opened). Still slow sometimes even inside one file, will try to find the reason.
Created attachment 99538 [details] snapshot Stepping through one file, was pretty fast this time. Anyway in the snapshot I see significant amount of time spent in fs (getBooleanAttributes). And this is even though I was always in the same file. This (if other fs activity present) may lead to significant slowdown.
Created attachment 99541 [details] snapshot This snapshot was generated when I had no files opened in the editor and almost every step required opening of a new file in the editor... Very slow.
see bug 183308. As soon as normalizeFile is using physical fs we can not use findFileObject from AWT. Otherwise we can have AWT hanging any time.
In deb3.nps steps are waiting for Java parser. JavacParser.moveToPhase() takes 3 seconds, parsing for method selection takes another 4 seconds. In another thread there are some more step actions waiting on CompilationControler.toPhase(). When I look at "Parsing & Indexing Loop" thread, I see that the problem is disk IO. Class.forName() takes 8 seconds(!), 6.5 seconds is spent in BufferedReader.readLine(). JavacParser.moveToPhase() takes 11 seconds, because it's reading from disk. If reopening files in the same editor is slow due to highlighting, submit a sepa rate bug for that. Debugger will not change it's functionality just because it's not efficient somewhere... In deb5.nps stepping is waiting for the parser again. These are IO problems tracked in issue #186345. Therefore I'm closing this as fixed again.
BTW: Please assure that some Mercurial commands are not running in the background. When I'm doing "hg fetch", my *whole* system is nearly unusable, all applications are affected, disk is almost inaccessible for them. Mercurial must be implemented very inefficiently.
It's up to you to close it, just want to remind that it is still slow even if one file is opened (in my opinion because of IO operations in AWT). If there is a way not to use findFileObject in AWT - please do that.
I've closed this, because we have issue #186345 for this problem already. I do not think it has sense to have two issues for the same problem. I do not see a snapshot that would show a significant time spent in findFileObject() in AWT. All times are in the range of 1 - 200 ms. Significant time seems to be spent in painting... If you have slow disk access or too many IO operations or whatever that makes FS slow, nothing will assure responsive AWT. Simple class loading can block it. You can not prevent from accessing FS in AWT!