Bug 83994

Created attachment 33487 [details]
Debug Scrrenshot 1

Created attachment 33488 [details]
Debug Screenshot 2

Created attachment 33489 [details]
CPU Usage

Created attachment 33490 [details]
Build Details

Check your memory usage. If it is close to maximum heap size increase maximum
heap size -Xmx in netbeans.conf. You can either switch on memory toolbar or use
jconsole. Check also what is your current -Xmx setting.

I installed the latest 09/07 build and the issue is still there.
Looks like, when I install the netbeans it is fine. But when I load the
following projects (just load bpeljbiadapter which loads the rest of them,
because of dependencies). 

It starts to use the maximum CPU. When i debug to find what the threads are
doing it is the same as was reported. My CPU utilization goes upto 95%.

heap size values i run at are 

-J-Xms32m -J-Xmx512m 

Created attachment 33707 [details]
memory usage image

if i turn on the memory tool bar it says that the usage goes upto 56 MB and then
drops (looks like GC). and there is a pattern of saw tooth wave. 

look at the memory usage image attached. 

It is not the problem of mem usage, but of a constant loop in trying to cleanup
something. As can be seen in the stack.

More or less as designed ppl from Java team can comment.

Re 50%: the activity is limited by performance of I/O as it verifies uptodate
state of cached data related to Java sources and classpath entries so it can be
even less. Paralelization of this check is perhaps possible but unlikely at this
moment.

Re "somtime that scanning never completes and get stuck at 99 %". Is it really
reproducible? If so, Radim, how can this be a P3?

After some random tries, looks like disabling the J2SE platform under Java tab,
in the module manager seems to have a positive effect. My CPU is free finally.

kiran, in your setup, is any of the following components on a slower network 
drive by any chance? jdk, project sources, userdir?

jskrivanek described similar problem in issue 72999. Unfortunately we were not
able to reproduce it.

Upgrading to P1 as lot of people are facing this issue and need to be resolved.

According to bug priority guidelines
(http://qa.netbeans.org/bugzilla/bug_priority_guidelines.html) this issue is P2
maximum:
Intermittent crash or deadlock

To evaluate this issue, please attach your messages.log. I guess there must be
some exceptions there.

Can we at least get the output when running with -J-Dperf.refactoring=true option?

What modules have you open - J2SE, Netbeans (standalone / module suite / part of
NB.org CVS tree)? 

Are your sources located on local hard drive?

Anything interesting in messsges.log?

The hint about producing heapdump added by Petr N. to issue #72999 applies to
this one as well. This kind of data can help us to analyze what is going wrong.

There was similar issue 47433. Problem was, that there was 2 urls pointing to
the same jar, but those 2 urls were not equal. The bug was in apisupports class
path provider.

What we definitely need is debug output. Please run the ide with
-J-Dperf.refactoring=true.
Thanks

Looking at JMManager's history, there is one really suspicious commit made by
jglick. See issue 72006.

Checking in java/javacore/src/org/netbeans/modules/javacore/JMManager.java;
/shared/data/ccvs/repository/java/javacore/src/org/netbeans/modules/javacore/JMManager.java,v
 <--  JMManager.java
new revision: 1.118.2.4.2.1; previous revision: 1.118.2.4
done

So if this issue is regression -> it is probably caused by this commit. Jesse,
can you take a look at it?

While it's certainly possible that my patch for issue #72006, which solved an
endless or very long loop with associated massive memory leak, can cause an
endless loop under other conditions, I don't see how that would happen. (I asked
for a patch review from the Java team but didn't get any clear response at the
time.) Whoever maintains javacore is in the best position to understand what it
is doing, when, and why; JMManager is a large, complex class with no unit tests
and not many comments.

This bug report seems to be missing independently verified steps to reproduce
from scratch. (Right?) Without that, it is hard to tell if it is really a
regression, or just a bug triggered by unusual conditions. The thread dumps from
the debugger are somewhat informative but they do not say whether
cleanUpCodebases() and resolveCodebases() are being reinvoked many times or
whether a single invocation never terminates.

Issue #72999 may be unrelated and was anyway unreproducible.

Issue #47433 (observed in 4.0) is disturbing in that an endless loop in javacore
was triggered by a mistake in a project type module, meaning the basic logic for
the scanning is not very robust (and does not apparently report an error when
given a nonnormalized path). However that appeared to involve only
resolveCodebases(), not cleanUpCodebases().

Comment for issue #72006:
Yes, JMManager is damn complex, but it looks like your commit #72006 does not do
exactly the same thing as the previous version of JMManager:

old version:
if (!backup.remove(getRootURI(roots[i]))) {
  existingUnresolved.add(roots[i].getURL().toString());

In this case zero or one uri was removed from backup and then some url is added
to existingUnresolved.

new version:
if (!removeURI(backup, uriBase)) {
  existingUnresolved.add(uriBase);
}

boolean removeURI(...) {
  boolean removed = false; // try to remove >1 if possible, since we don't know
which is right
  if (uris.remove(uriBase)) {
    removed = true;
  }
  if (uris.remove(uriBase + "1.4")) { // NOI18N
    removed = true;
  }
  if (uris.remove(uriBase + "1.5")) { // NOI18N
    removed = true;
  }
  if (removed) {
    return true;
  }
}

In this version up to 3 uris can be removed in this one call. Moreover
kiran_bhumana reported: "After some random tries, looks like disabling the J2SE
platform under Java tab, in the module manager seems to have a positive effect.
My CPU is free finally."
So it looks like it can have something to do with JDKs. JDK 1.4 has different
default source level than JDK 1.5, isn't it?

If anyone is able to reproduce it, we can rollback #72006 and ask him to test
it. If it will be ok, we know, that the problem is in #72006. If not we know,
that the problem is not in #72006.

Indeed removeURI could remove >1 root. Whether that is significant, I don't
know. (Who wrote JMManager, anyway?)

Disabling the Java SE Platform module is likely to have pretty major effects on
anything relating to Java scanning so I am not surprised that "fixes" this bug
(probably breaking something else), but I don't think that tells us very much.

The code was written by Martin Matula I think.

removed the incomplete keyword so that netbeans team can fix the issue for 5.5

This is still INCOMPLETE since as far as I know there are no independently
verified steps to reproduce the problem from scratch. Without that, it is
unlikely that anything will happen.

>>is any of the following components on a slower network 
drive by any chance? jdk, project sources, userdir?

None of them are on the slower network. But this doesn't answer, "looks like
disabling the J2SE platform under Java tab,in the module manager seems to have a
positive effect. My CPU is free finally"

>>What modules have you open - J2SE, Netbeans (standalone / module suite / part
of NB.org CVS tree)? 

Only J2SE and some compApp projects. When i install netbeans, if i remember
correctly, CPU was free, but after i loaded the projects, this starts to happen.
yes all the projects are on the loacal drive. 

Attached lod files with and without the perf option.

Created attachment 34668 [details]
default log

Created attachment 34669 [details]
with perf option

just FYI, to figure if i didn't add the perf parameters wrongly.

In netbeans conf i have an entry,

netbeans_default_options="-J-Dcom.sun.aas.installRoot=\"C:\alaska\Sun\appserver\"
-J-DAM_CONFIG_FILE=\"C:\alaska\Sun\AppServer\addons\amserver\AMConfig.properties\"
-J-Dcom.sun.aas.installRoot=\"C:\alaska\Sun\AppServer\" -J-Xms128m -J-Xmx512m
-J-XX:PermSize=32m -J-XX:MaxPermSize=160m -J-Dnetbeans.logger.console=true -J-ea
 -J-Xdebug -J-Xrunjdwp:transport=dt_socket,address=4999,server=y,suspend=n 

to which i added, -J-Dperf.refactoring=true" so it looks like,

netbeans_default_options="-J-Dcom.sun.aas.installRoot=\"C:\alaska\Sun\appserver\"
-J-DAM_CONFIG_FILE=\"C:\alaska\Sun\AppServer\addons\amserver\AMConfig.properties\"
-J-Dcom.sun.aas.installRoot=\"C:\alaska\Sun\AppServer\" -J-Xms128m -J-Xmx512m
-J-XX:PermSize=32m -J-XX:MaxPermSize=160m -J-Dnetbeans.logger.console=true -J-ea
 -J-Xdebug -J-Xrunjdwp:transport=dt_socket,address=4999,server=y,suspend=n
-J-Dperf.refactoring=true"

Looks like the problem is the endlessly repeating

loading index .../f528aed2244d52dd5d6e8df823ac5e1b5f4964dd6defaultjavacsource
loading index .../fed3795775d09becd00eb0fde5414eaf360ad3bcbdefaultjavacsource 

What does your "defaultjavacsource" project look like? (metadata, contents) If
you shut down the IDE, delete C:\Documents and
Settings\kbhumana\.netbeans\5.5dev\varcache (after making a backup for
diagnosis!), and restart the IDE, does the problem go away? What about if you
close the javac project and then restart the IDE with a clean cache?

I guess you are asking me. Next time pls address by my name if you want
something from me. Its easier. It is hard to see if netbeans developers are
talking amongst themselves or waiting for something from me.
anyway,

"defaultjavacsource" I don't know anything about that. I assume netbeans is
doing something here. I have no project like that.

There is something wrong in you user dir, kiran_bhumana.

First, please shut down the IDE and backup
f528aed2244d52dd5d6e8df823ac5e1b5f4964dd6defaultjavacsource and the
fed3795775d09becd00eb0fde5414eaf360ad3bcbdefaultjavacsource as well. These files
are located in you userdir: var/cache/mdrstorage/org-netbeans-java/0.70.

There are always 3 files with the same name in this folder but with different
extension. So please backup all those six files. Now you can delete them and
restart the IDE. It should work now.

And now, let's analyze the problem. There must be some project, which contains
javac/source on it's classpath. Can you somehow describe us this project, or
send it in private? Thanks

And now is the part of my comment, where developers talk amongst themselves :)

There are 2 index files for one source root? How is that possible?

Removing PERFORMANCE kw - this is simply bug. Nothing to do with performance.

why don't some one log onto my machine and try and do as much to collect all the
information required to debug. I will offer the machine for 30 minutes or so.

Tomasi, Flaskine, .... defaultjavacsource - is it really just coincidence, that
extent name is the same as build properties variable "default.javac.source",
which means source level? What if project properties are just broken and
property name was somehow propagated as source root...

Undefined ${default.javac.source} is the most likely explanation for the strange
MDR cache names. (I don't know what project type would report this string for
SourceLevelQuery...j2seproject does not AFAIK, nor does nbmproject.)
Unfortunately that leaves us with no clue what source root the cache was made
for, since the MDR DB seems to trim all but the last three components, and those
are all bogus in this case. So we are back to looking for steps to reproduce; if
necessary by doing a recursive bisection of the set of open projects to find the
project(s) which triggers the bug.

I can easily prepare modified version of NetBeans, which will print out real classpath root in addition to 
f528aed2244d52dd5d6e8df823ac5e1b5f4964dd6defaultjavacsource

This will help us to find out which project have it.

To jglick: The file name of the MDR repository and classindex file is generated by javacore and has 
nothing to do with MDR, also it is not true that only last three components is used. The algorithm for 
generating the name is more complex. As for undefined ${default.javac.source} - can it be freeform 
project?

According to Bug prirority guidelines the issue is P2. I'm downgrading priority.

"As for undefined ${default.javac.source} - can it be freeform project?" -
perhaps. If the project.xml for some reasons contains

<source-level>${default.javac.source}</source-level>

Note that such a project.xml would be invalid according to schema (only fixed
1.3, 1.4, and 1.5 are supported currently), and anyone editing it to contain
this text in the IDE would see an error to that effect immediately upon saving.
So I don't think it's too likely that this is from a freeform project.

Created attachment 34787 [details]
log file from netbeans with more diagnostica from Tomas

Created attachment 34788 [details]
apache resolver project

Created attachment 34789 [details]
wsdl4j project

Created attachment 34790 [details]
bpel model project

I have attached the log file with the netbeans version of more diagnostics, I
got this version of NB from Tomas.
I also attached projects, that were being pointed in the log file. These projects 
have javac.source=${default.javac.source} entry in the project properties.

Note:
I am not the owner of these projects, i wouldn't know the reasons of why these
projects have such entries. I can probably find out by emailing the relevant folks.

Uf. We finally found it. Thanks to Kiran and especially Tomas Hurka. Thanks guys.

According to logs SourceLevelQuery sometimes returns "${default.javac.source}"
for j2seproject, at least on kiran's machine for wsdl4j project.

Infinite loop itself is caused by Jesse's commit (JMManager 1.118.2.4.2.1). The
commit works fine if SourceLevelQuery returns reasonable result ("1.5","1.4",
"1.something") but it does not remove anything from set of uris if
SourceLeveQuery returns "${default.javac.source}", because there is an uri which
ends with "defaultjavacsource" which is never removed -> and it cause infinite loop.

Shortly speaking, root of the problem is in SourceLevelQuery, which sometimes
returns wrong value. Regression is JMManager, but the commit itself is OK
providing SourceLevelQuery returns "1.something".

I don't think investigation is done yet. Given the latest information, I can
reproduce, but only artificially: you need a j2seproject whose
javac.source=${default.javac.source} (the default I think), but if you start the
IDE then

default.javac.source=1.5

(or similar) is always added to $userdir/build.properties, which is loaded by
the project, so SLQ is fine and no bug occurs. The only way I can find to
reproduce is

1. Make sure the project is closed, and shut down the IDE.

2. Start the IDE.

3. Delete the def of d.j.s from build.properties.

4. Open the project.

I cannot figure out how it could happen that build.properties is left corrupted
at IDE startup time (or that build.properties is not referenced at all). In
other words, yes JMManager should be more robust, and yes the SLQ in j2seproject
should be more robust, but neither of these is the root problem.

The userdir in the attachments is

C:\Documents and Settings\kbhumana\.netbeans\5.5dev

yet private.properties says

user.properties.file=C:\\Documents and
Settings\\kbhumana\\.netbeans\\5.5beta2\\build.properties

i.e. points to a different userdir. Yet private.properties ought to updated with
the correct userdir whenever the project is opened (or the IDE started with the
project open). So all I can guess at is

1. For some reason, private.properties does not get updated in the project open
hook.

2. And, ....\5.5beta2\build.properties for some reason is lacking the usual
definition of default.javac.source, or does not exist at all.

Kiran can you shed any light on these questions? I do not consider this bug
fully fixable until its origin is understood. Although the worst symptoms (e.g.
infinite loop) can be corrected, these projects will still not work correctly in
the IDE if build.properties is not being loaded as expected.

Can you pls be more specific in the question. What exactly do you want me to
tell you?

If you are asking why netbeans is not updating some files, i don't know.

Kiran: I need to know (1) are your projects open when you start the IDE, (2)
what your private.properties for each project says before and after you start
the IDE, (3) what userdir you are using (Help | About), (4) what your
build.properties in that userdir looks like, (5) whether you have an old userdir
in 5.5beta2, (6) what its build.properties looks like, (7) any unusual steps you
might have taken when working on these projects, such as creating while using
one userdir then opening while using another userdir, or accidentally sharing
the nbproject/private/ with colleagues, or any manual edits to any project
metadata files, etc. etc. Basically, we are still looking for some way to
reproduce the problem (without manually breaking metadata files).


Fixing symptoms in trunk:

Checking in test/unit/src/org/netbeans/api/java/queries/SourceLevelQueryTest.java;
/shared/data/ccvs/repository/java/api/test/unit/src/org/netbeans/api/java/queries/SourceLevelQueryTest.java,v
 <--  SourceLevelQueryTest.java
initial revision: 1.1
done
Checking in src/org/netbeans/api/java/queries/SourceLevelQuery.java;
/shared/data/ccvs/repository/java/api/src/org/netbeans/api/java/queries/SourceLevelQuery.java,v
 <--  SourceLevelQuery.java
new revision: 1.6; previous revision: 1.5
done

1) No projcts are not opened. In fact i don't usually work with these projects.
These projects are loaded because the project i work with has a dependency on them.
(2) private.properties has the same value before and after NB is up.
user.properties.file=C:\\Documents and
Settings\\kbhumana\\.netbeans\\5.5beta2\\build.properties, 
(3) and (4) attached userdir. 
(5) and (6) When I used Tomas's Netbeans, i used a new userdir
(7) I didn't create these projects. They have been there in the alaska (Monrovia
CVS) for quite some time. They are shared libraries and many people may have
opened them. I wouldn't know much there. Sorry not of much help with this point.

Created attachment 34844 [details]
userdir zipped up

Does C:\Documents and Settings\kbhumana\.netbeans\5.5beta2\build.properties
exist? What does it contain? I presume at one point you opened these projects
while using this userdir?

I might have, but i don't have that userdir anymore. That makes me ask a
question, why didn't the netbeans update the private properties file with the
current userdir?

OK, so the old userdir is gone. The IDE *will* update your project and correct
its metadata if you ever open it.

OK, so with that I finally have steps to reproduce, which confirm the fix I put
into SourceLevelQuery:

1. Start NB 4.1 (i.e. w/o fix for issue #65631) with fresh userdir testud1.

2. Create new lib j2seproject testlib.

3. Create new app j2seproject testapp.

4. Add dep testapp -> testlib (e.g. use Libraries node).

5. Shut down IDE.

6. Delete testud1.

7. Start current version of IDE with fresh userdir testud2.

8. Open testapp but do not open testlib (uncheck Open Required Projects).

Without patch, Scanning Project Classpaths goes to 99% and stays there, with
100% CPU. With patch, finishes normally.

Jesse thanks for steps to reproduce ...

I vote for fix this into NB 5.5 RC 2. 
Tonda, Jesse, Honza(s) ... what do you think ?

Agreed with Marian. Let's fix in 5.5.

It has to go into RC2.

Created attachment 34871 [details]
Proposed patch for release55

The fix is OK.

Checking in java/api/src/org/netbeans/api/java/queries/SourceLevelQuery.java;
/shared/data/ccvs/repository/java/api/src/org/netbeans/api/java/queries/SourceLevelQuery.java,v
 <--  SourceLevelQuery.java
new revision: 1.3.88.2; previous revision: 1.3.88.1
done

Fix introduced a spurious test regression; corrected in trunk:

Checking in SourceLevelQueryImplTest.java;
/shared/data/ccvs/repository/java/j2seproject/test/unit/src/org/netbeans/modules/java/j2seproject/queries/SourceLevelQueryImplTest.java,v
 <--  SourceLevelQueryImplTest.java
new revision: 1.7; previous revision: 1.6
done