Created attachment 16650 [details]
DeploymentException

There are some weird smells in the code. For example, if the user
cancels deployment, method _start() in ServerInstance returns false
(ServerInstance:446). Then startTarget() also returns false.

Then TargetServer.startTargets() returns false (TargetServer:389).

Then Deployment.deploy() gets false (Deployment:84) and then it throws
an exception (Deployment:91).

So, this nasty looking exception may be a consequence of the user
cancelling the dialog.

Or another smell is the threading code in ServerInstance.start().
Regardless of whether _start() succeeds, it always returns false ?!?
(ServerInstance:339).

I have never canceled the dialog. I started execution or debugging of
the project and waited.

I can reproduce the ex when I debug, stop server and then run the
project. Thanks for the scanario!
I am looking into it.

> There are some weird smells in the code. For example, if the user
> cancels deployment, method _start() in ServerInstance returns false
> (ServerInstance:446). Then startTarget() also returns false.
> 
This is actually how it is supposed to behave!

> Then TargetServer.startTargets() returns false (TargetServer:389).

Perhaps the message should be different if the user stopped the
server, otherwise it is ok.

> 
> Then Deployment.deploy() gets false (Deployment:84) and then it throws
> an exception (Deployment:91).
> 
> So, this nasty looking exception may be a consequence of the user
> cancelling the dialog.
> 
> Or another smell is the threading code in ServerInstance.start().
> Regardless of whether _start() succeeds, it always returns false ?!?
> (ServerInstance:339).
> 

This code looks suspicious but it is not called here. 
The TS.startTargets calls SI.start(UI) - with parameter.

The problem is not reproducible 100%, it seems rather random.

My debug prints show that the problem spot is in checking the server
status after the plugin says the server has been started,
ServerInstance:441. The problem is that SI is caching the value of
isRunning!!! so it is sure to return false (and FAIL) if is checked
the value in the last 2000ms.
I tried removing the check for isRunning at 441 in SI and after that I
cannot reproduce the bug.

Nam has added this check in ver. 1.15 as part of IN=19137 which says:

> This will be done quietly without dialog for confirmation at this time.
> The implementation will rely on j2eeserver ModuleInstall.close() to
detect IDE exit.
> 
> This check in also fix:
> - infinite loop during silent start server in case of S1AS plugin.
> - clean up duplicate and unused entries in Bundle.properties
> - fix ServerStatusBar not to use invokeLater unecessarily
> 

I will let him comment on whether the check is really needed.
If it is I will add a new method 
private boolean checkRunning () which will no use the cached value.

The caching of state is for UI responsiveness reason. 
If the cache value is wrong for that 2 secs, I still don't see how it
can contribute to the scenario in either cases.  

Case 1: server stopped and cached value is running, the failure would
be later during deployment.  

Case 2: server is running and cached value says stopped,
SS.startDeploymentManager will be called.  Here if the plugin normally
just fire completed event and the cached state is in sync again.  If
plugin fire an error event then we got the problem.  But I think Libor
test case more likely fall into case 1 or the following plugin theory.

From the stack, I think that the possible reason is that the (tomcat
or as8) ProgressObject did not notify the StartProgressHandler.  I
remember there was a race condition where the plugin PO fire the
completed event too early even before the handler attached.  Could
this be the case?

I don't know how to explain Pavel observation about removing cached
value make the problem go away.  But if this really solve the problem,
I think that to have a private "realtime" method checkRunning to use
only for deployment is fine.

To explain better what I mean: it is the case 2. The server is stopped
and the cached value of isRunning is false. ServerInstance calls
StartServer.startDeploymentManager() and as soon as the server starts
and norifies the ServerInstance the ServerInstance will check the
isRunning() again -- I guess to make sure(?). If this happnes within
2000 ms of the last check the isRunning() will return false. If the
ServerInstance would ask StartServer at this point (e.g. if the 2000
ms time out expired, or just ignore the chache value) it would return
true, as it should be.

(ServerInstance, line 416.. with my comments started with //PB)

    private synchronized boolean _start(DeployProgressUI ui) {
        if (isRunning())
            return true;
 //PB: this.isRunning == false (the cache)
        DeployProgressUI.CancelHandler ch = getCancelHandler();
        ui.addCancelHandler(ch);
        
        try {
            StartServer ss = getStartServer();
            String errorMessage = checkStartDM(ss);
            if (errorMessage != null) {
                handleStartServerError(ui, errorMessage);
                return false;
            }
            
            ProgressObject po = ss.startDeploymentManager();
            
            ui.setProgressObject(po);
            po.addProgressListener(new StartProgressHandler());
            
            // wait until done or cancelled
            boolean done = sleep();
            if (! done) {
               
ui.addMessage(NbBundle.getMessage(ServerInstance.class,
"MSG_StartServerTimeout", url));
                return false;

//PB: done == true, ie. StartServer notified Server Instance 
//PB: that it has started succesfully

            } else if (! isRunning()) {
               ui.addMessage(NbBundle.getMessage(ServerInstance.class,
"MSG_StartedServerFailedPing", url));
                return false;
//PB: ^^ this is where it fails (IMO), the server was just 
//PB: started but the cache says it is not running!
//PB: when it failed it was here...

Well 2 secs is about the time required for an empty tomcat to start. 
Anyway, for bullet proof functionality, we can change the
StartProgressHandler.handleProgressEvent code to also remember the
ending state (FAILED or COMPLETED) so that we don't have to check
isRunning again.

Nam kindly offered to take this issue. Tx.

Depending on implementation of pinging the server
(StartServer.isRunning) sometimes it is not the best mechanism to
determine when starting server is successful.  Sometime
StartServer.isRunning just return false when
StartServer.startDeploymentManager already generate COMPLETED event.  

The integrated fix for this issue has the following improvements to
ServerInstance:

- Plainly rely on the plugin ProgressObject event COMPLETED to decide
when a start/debug/stop is done successfully.
- Precautious check for ProgressObject event COMPLETED even before
start waiting. (Sometimes plugin fire event COMPLETED event too fast
before listener attached.  Maybe this is not what happen to
start/stop/debug, but it happens in implementation of incremental deploy).
- Parameterize ServerInstance.isRunning and add isReallyRunning which
alway call StartServer.isRunning without relying on cahed value.
- Cleanup ServerInstance: eliminate unecessary methods that get in the
way of optimization.  Rearrange and streamline atomic calls:
_start/_stop/_debug.  All external calls now go through multiplexor
method SI.startTarget(Target target, DeployProgressUI ui, boolean
debugMode)
- Make sure event handlers are detached in finally blocks.

The fix consists of the following changes:

src/org/netbeans/modules/j2ee/deployment/impl/Bundle.properties;
new revision: 1.21; previous revision: 1.20
src/org/netbeans/modules/j2ee/deployment/impl/ServerInstance.java;
new revision: 1.27; previous revision: 1.26
src/org/netbeans/modules/j2ee/deployment/impl/ui/ServerStatusBar.java;
new revision: 1.10; previous revision: 1.9