Bug 206822

Created attachment 114542 [details]
NetBeans log file

In the future, could you avoid making a zip file for log files and attach them as separate plain text attachments...  You will need to change the 'Content Type' since the auto detect feature on bugzilla does not seem to function very well.

Please attach the corresponding GlassFish log in situations like this in the future too (as a separate plain text attachment).

I have been assigned to other high priority tasks within Oracle. Using the limited amount of time I have to convert attachments into a more readable form detracts from the time that I can use to actually diagnose the issue.

I looked through the attached log file.

Is this the message that you are reporting?

INFO [glassfish]: __locations returned from server after 21,382ms. The server is still getting ready

Let me make sure I understand what you are doing in this report...

You

1. have the server started in debug mode
   Is the debugger attached to the server or is the server just running in debug mode?

2. Are you using 'right-click Debug' because the server gets restarted in 'normal mode' otherwise?

Please provide step-by-step instruction on how you produce the issue that you are reporting.

It would be nice to have a detailed description of the server's and the IDE's initial state.

Examples of the server's initial state: number of deployed apps, etc.

Example of the IDE's initial state: number of open projects, types of open projects, etc.

Created attachment 114543 [details]
IDE log covering step 01 and step 02

Created attachment 114544 [details]
server log covering step 01 and step 02

Created attachment 114545 [details]
zip file with shorter logs step 01 and final logs step 02

Sorry about the incomplete information. It was late at night.

The project is a plain JavaEE 6 web project (No CDI) with over 1,000 classes plus 25 jar files. I thought a timeout of 10 seconds is of some concern because it is very short compared with my build time of 1 - 2 minutes, and, for example 10 seconds of solid 100% CPU consumed by the debugger on saving a source file (COS) without involvement of any other work e.g. build script.

I am reporting the timeout which appears to happen in multiple contexts:

INFO [glassfish]: could not get http port value in 10 seconds from the server
java.util.concurrent.TimeoutException
	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:228)
	at java.util.concurrent.FutureTask.get(FutureTask.java:91)
[catch] at org.netbeans.modules.glassfish.common.CommonServerSupport.updateHttpPort(CommonServerSupport.java:861)
	at org.netbeans.modules.glassfish.common.CommonServerSupport.isReady(CommonServerSupport.java:715)
	at org.netbeans.modules.glassfish.common.CommonServerSupport.isReallyRunning(CommonServerSupport.java:661)
	at org.netbeans.modules.glassfish.common.CommonServerSupport$4.run(CommonServerSupport.java:771)
	at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1411)
	at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1991)

1. Yes I am running the server in debug mode exclusively. The debugger is typically
   already attached from the previous debug session before any code changes.
   Then I use again 'right-click Debug' which triggers the whole process in the ant
   project: compile, undeploy, deploy.
2. Please see 1.

Step by tep instructions:

To prepare the situation, I
- undeploy all apps from the server
- shut down the server
- ensure that the IDE has only one open project
- shut down NetBeans

The test sequence:
- Start up NetBeans
- Wait for completion of all scanning:
Line 713
INFO [org.netbeans.modules.parsing.impl.indexing.RepositoryUpdater]: Complete indexing of 7 source roots took: 5922 ms (New or modified files: 0, Deleted files: 0) [Adding listeners took: 1953 ms]
- Start server in debug mode and wait until it is finished
Line 31
[#|2012-01-02T17:31:03.671+1300|INFO|glassfish3.1.1|javax.enterprise.system.core.com.sun.enterprise.v3.services.impl|_ThreadID=19;_ThreadName=Thread-2;|Grizzly Framework 1.9.36 started in: 109ms - bound to [0.0.0.0:8181]|#]
- 'right-click Debug' the application in the projects window

The result in the ide log:

INFO [glassfish]: __locations timed out. 1 of 1
java.util.concurrent.TimeoutException
	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:228)
	at java.util.concurrent.FutureTask.get(FutureTask.java:91)
[catch] at org.netbeans.modules.glassfish.common.CommonServerSupport.isReady(CommonServerSupport.java:698)
	at org.netbeans.modules.glassfish.common.CommonServerSupport.isReallyRunning(CommonServerSupport.java:661)
	at org.netbeans.modules.glassfish.common.CommonServerSupport$4.run(CommonServerSupport.java:771)
	at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1411)
	at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1991)

The IDE output window:

init:
deps-module-jar:
JBakery.init:
Deleting: C:\_dt\app\JBakery\JBakery\build\built-jar.properties
JBakery.deps-jar:
Updating property file: C:\_dt\app\JBakery\JBakery\build\built-jar.properties
JBakery.compile:
JBakery.jar:
PhoneData.init:
Deleting: C:\_dt\app\gt1\jprj\G1\PhoneData\build\built-jar.properties
PhoneData.deps-jar:
Updating property file: C:\_dt\app\gt1\jprj\G1\PhoneData\build\built-jar.properties
PhoneData.compile:
PhoneData.jar:
deps-ear-jar:
deps-jar:
Copying 33 files to C:\_dt\app\gt1\jprj\G1\G1_W\build\web
library-inclusion-in-archive:
library-inclusion-in-manifest:
deleteData:
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\test
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\apple
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\checkbox
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\default
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\themeroller
compressAll:
jar-tests:
compile:
compile-jsps:
debug:
connect-debugger:
Attached JPDA debugger to localhost:9009
In-place deployment at C:\_dt\app\gt1\jprj\G1\G1_W\build\web
debug-display-browser:
Browsing: http://localhost:8080
connect-client-debugger:
BUILD SUCCESSFUL (total time: 2 minutes 17 seconds)

- I copy the IDE and server	log fies at this stage as version 01

- I change one line in a single source file of the web project
- 'right-click Debug' the application in the projects window

IDE output window
init:
deps-module-jar:
JBakery.init:
Deleting: C:\_dt\app\JBakery\JBakery\build\built-jar.properties
JBakery.deps-jar:
Updating property file: C:\_dt\app\JBakery\JBakery\build\built-jar.properties
JBakery.compile:
JBakery.jar:
PhoneData.init:
Deleting: C:\_dt\app\gt1\jprj\G1\PhoneData\build\built-jar.properties
PhoneData.deps-jar:
Updating property file: C:\_dt\app\gt1\jprj\G1\PhoneData\build\built-jar.properties
PhoneData.compile:
PhoneData.jar:
deps-ear-jar:
deps-jar:
Copying 33 files to C:\_dt\app\gt1\jprj\G1\G1_W\build\web
library-inclusion-in-archive:
library-inclusion-in-manifest:
deleteData:
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\test
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\apple
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\checkbox
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\default
Deleting directory C:\_dt\app\gt1\jprj\G1\G1_W\build\web\jslib\tree\themes\themeroller
compressAll:
jar-tests:
compile:
compile-jsps:
debug:
connect-debugger:
Undeploying ...
In-place deployment at C:\_dt\app\gt1\jprj\G1\G1_W\build\web
debug-display-browser:
Browsing: http://localhost:8080
connect-client-debugger:
BUILD SUCCESSFUL (total time: 1 minute 35 seconds)

I copy the IDE and server	log fies at this stage as version 02

The message is informational and is not critical usually.

Here is how it happens...

When the IDE is checking whether the server is running we also update the data about the http port that the is ring used by the server (to help open the browser on the correct port).

To change the port, the server must be restarted.  While some folks will do that start and stop with the IDE actions, others may stop the server change the port configuration and restart it with asadmin.

The org.netbeans.modules.glassfish.common.CommonServerSupport.updateHttpPort method is used to detect those kinds of situation and update IDE data structure automatically.

This exception may be a symptom of something bigger, but I do not know what that is at this point.

You may want to note:

You probably do not need to start the server in Debug mode before you 'right-click Debug'

Thanks for the explanation. I am glad this is not a serious issue at this stage.

If I click debug from the projects window with the app already deployed with the most recend action and no source code changes and the server is already in debug mode, then the app gets undeployed and re-deployed for no abvious reason.

Should I report this as a bug?

(In reply to comment #8)
> Thanks for the explanation. I am glad this is not a serious issue at this
> stage.
> 
> If I click debug from the projects window with the app already deployed with
> the most recend action and no source code changes and the server is already in
> debug mode, then the app gets undeployed and re-deployed for no abvious reason.
> 
> Should I report this as a bug?

No. The IDE is doing the action that you asked it to do.

Note: you may want to try the following workflow.

(assuming the IDE and server are both not running)

start NB

open the project (if it isn't already)

'right-click Debug' the project

  make some code changes

'right-click Run' the project.

  this will use incremental deployment instead of a complete undeploy/redeploy cycle.

The server shouldn't restart and your IDE will not detach from the server VM.

This may help optimize your workflow a little bit.

What I am seeing is different with a standard ant build file and

Project Properties|Libraries|"Build required Projects (Libraries and WAR content)" unchecked.

Still with no source code changes:

init:
deps-module-jar:
deps-ear-jar:
deps-jar:
library-inclusion-in-archive:
library-inclusion-in-manifest:
compile:
compile-jsps:
Undeploying ...
In-place deployment at <my project path>\build\web
run-deploy:
Browsing: http://localhost:8080
run-display-browser:
run:
BUILD SUCCESSFUL (total time: 1 minute 9 seconds)

I think there cold be a potential time saving if the IDE can skip the re-deployment if the project is up to date. Like when I click in the services window at the deployed app "Open in Browser" but I don't always know whether I made source code changes.

What do you think?

(In reply to comment #10)
> What I am seeing is different with a standard ant build file and
> 
> Project Properties|Libraries|"Build required Projects (Libraries and WAR
> content)" unchecked.
> 
> Still with no source code changes:
> 
> init:
> deps-module-jar:
> deps-ear-jar:
> deps-jar:
> library-inclusion-in-archive:
> library-inclusion-in-manifest:
> compile:
> compile-jsps:
> Undeploying ...
> In-place deployment at <my project path>\build\web
> run-deploy:
> Browsing: http://localhost:8080
> run-display-browser:
> run:
> BUILD SUCCESSFUL (total time: 1 minute 9 seconds)
> 
> I think there cold be a potential time saving if the IDE can skip the
> re-deployment if the project is up to date. Like when I click in the services
> window at the deployed app "Open in Browser" but I don't always know whether I
> made source code changes.
> 
> What do you think?

That this suggestion needs to get opened as a new enhancement request...

Provide details in that new issue so it can be understood without having to come back to this issue for 'context'.

Significant parts of org.netbeans.modules.glassfish.common.CommonServerSupport and deployment code will be re-written in Tooling SDK library so we should check it again after this will be done.

I'm assigning this to myself. I'll come back when we'll be done with Tooling SDK.

Please can you test this issue with last 7.3 build again?
We need some update on this because in 7.3 code was changed a lot.

INFO [glassfish]: __locations timed out. 1 of 1

This looks similar to the problem you described in bug# 199099. I missed that this timeout is related to this. Also stack trace is the same - CommonServerSupport.isReady uses __locations call to verify if GlassFish is up and responding.

CommonServerSupport.updateHttpPort method is the same - glassfish admin command, just to retrieve property from server config.
There is 10 seconds timeout and it's still uses original code even in 7.3.

This looks like server did not respond in 10 seconds.

I would like to switch this code to GF Tooling SDK library. Also I would like to come with some way to modify timeout value (together with bug# 19909 changes).

...(together with bug# 199099 changes).

We won't move CommonServerSupport.updateHttpPort() to Tooling SDK in 7.3. 
Skipping the re-deployment if the project is up to date will also be considered as 'next release RFE'.

Targeting this to next release.