While deploy job is running, certain things in Eclipse go into a weird state

[chanseokoh]

This is a very weird bug.

It is a bit tricky to reproduce. You need to somehow make a deploy take a long time. (I have a GCP project where it takes several minutes to deploy any app.)

1. Deploy an app that will take a long time.
2. While the job is running (in my case, the job is stuck at 30%), create a Maven Helloworld project. Notice that the project created doesn't have a warning marker (which should be there normally):

Now, while the job from 1 is running, if you run the project from 2 locally, the server will come up, but it's not functional. Some error messages from the dev_appserver:

WARNING: EXCEPTION 
java.lang.ClassNotFoundException: mavenproj.HelloAppEngine
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381)

SEVERE: [1489635710024000] javax.servlet.ServletContext log: unavailable
javax.servlet.UnavailableException: mavenproj.HelloAppEngine

WARNING: Failed startup of context com.google.appengine.tools.development.DevAppEngineWebAppContext@17c386de{/,/home/chanseok/runtime-gcloud-eclipse/.metadata/.plugins/org.eclipse.wst.server.core/tmp0/mavenproj}
java.lang.NullPointerException
	at java.lang.Class.isAssignableFrom(Native Method)

Also, while the job from 1 is running, if you deploy the project from 2, it will fail at the staging step:

Beginning interaction for module default...
0% Scanning for jsp files.
0% Compiling jsp files.
Mar 15, 2017 11:42:15 PM org.apache.jasper.JspC processFile
INFO: Built File: /index.jsp
/tmp/1489635734977-0/org/apache/jsp/index_jsp.java:6: error: package mavenproj does not exist
import mavenproj.HelloInfo;
                ^
/tmp/1489635734977-0/org/apache/jsp/index_jsp.java:6: error: package mavenproj does not exist
import mavenproj.HelloInfo;
                ^
/tmp/1489635734977-0/org/apache/jsp/index_jsp.java:56: error: cannot find symbol
      out.print( HelloInfo.getInfo() );
                 ^
  symbol:   variable HelloInfo
  location: class index_jsp
2 errors
Unable to stage app: Failed to compile the generated JSP java files.
Please see the logs [/tmp/appcfg6470123138935393703.log] for further information.

If the job from 1 is finally complete, the project 2 will eventually show a warning marker:

I can always reproduce this up to this point.

At this point, I also observed other weird things. For example, I tried to stop the dev_appserver I ran before, but the server was stuck at the "Stopping, Synchronized" state for several minutes. It eventually went down, but when I try to re-launch the dev_appserver, it immediately fails with a NullPointerException:

An internal error occurred during: "Starting App Engine Standard at localhost".

java.lang.NullPointerException
	at com.google.cloud.tools.eclipse.appengine.localserver.server.LocalAppEngineServerLaunchConfigurationDelegate.getLaunch(LocalAppEngineServerLaunchConfigurationDelegate.java:124)
	at org.eclipse.debug.internal.core.LaunchConfiguration.launch(LaunchConfiguration.java:812)
	at org.eclipse.debug.internal.core.LaunchConfiguration.launch(LaunchConfiguration.java:739)
	at org.eclipse.debug.internal.core.LaunchConfiguration.launch(LaunchConfiguration.java:731)
	at org.eclipse.wst.server.core.internal.Server.startImpl2(Server.java:3556)
	at org.eclipse.wst.server.core.internal.Server.startImpl(Server.java:3492)
	at org.eclipse.wst.server.core.internal.Server$StartJob.run(Server.java:367)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)

Also, deploying the project from 2 again still fails for some time, but somewhat differently: it passed the staging, but pre-compiling fails on the server side:

Beginning interaction for module default...
0% Scanning for jsp files.
0% Compiling jsp files.
Mar 16, 2017 12:04:51 AM org.apache.jasper.JspC processFile
INFO: Built File: /index.jsp
Success.
Temporary staging for module default directory left in /home/chanseok/runtime-gcloud-eclipse/.metadata/.plugins/com.google.cloud.tools.eclipse.appengine.deploy/tmp/1489637090214/staging
You are about to deploy the following services:
 - chanseok-playground-new/default/20170316t000453 (from [/home/chanseok/runtime-gcloud-eclipse/.metadata/.plugins/com.google.cloud.tools.eclipse.appengine.deploy/tmp/1489637090214/staging/app.yaml])
     Deploying to URL: [https://chanseok-playground-new.appspot.com]

Beginning deployment of service [default]...
File upload done.
Updating service [default]...
...........failed.
ERROR: (gcloud.app.deploy) Error Response: [13] Error precompiling app during deployment.

[chanseokoh]

It is a bit tricky to reproduce. You need to somehow make a deploy take a long time.

It's actually easy to reproduce. All you have to do is to make StandardDeployJob.deployProject() to take artificially a long time:

  private IStatus deployProject(Path credentialFile, IPath stagingDirectory, IProgressMonitor monitor) {
    while (!monitor.isCanceled()) try {
      Thread.sleep(1000);
    } catch (Exception e) {}

    RecordProcessError deployExitListener = new RecordProcessError();
        ...
    return deployExitListener.getExitStatus();
  }

[chanseokoh]

My suspicion is that the deploy job holds a lock or something, and it interferes with something workspace-wide.

[briandealwis]

That NPE looks like a bug:

An internal error occurred during: "Starting App Engine Standard at localhost".

java.lang.NullPointerException
	at com.google.cloud.tools.eclipse.appengine.localserver.server.LocalAppEngineServerLaunchConfigurationDelegate.getLaunch(LocalAppEngineServerLaunchConfigurationDelegate.java:124)
	at org.eclipse.debug.internal.core.LaunchConfiguration.launch(LaunchConfiguration.java:812)
	at org.eclipse.debug.internal.core.LaunchConfiguration.launch(LaunchConfiguration.java:739)
	at org.eclipse.debug.internal.core.LaunchConfiguration.launch(LaunchConfiguration.java:731)
	at org.eclipse.wst.server.core.internal.Server.startImpl2(Server.java:3556)
	at org.eclipse.wst.server.core.internal.Server.startImpl(Server.java:3492)
	at org.eclipse.wst.server.core.internal.Server$StartJob.run(Server.java:367)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)

Here's LocalAppEngineServerLaunchConfigurationDelegate.java around line 124: looks like a launch may not have a launch configuration:

    for (ILaunch launch : getLaunchManager().getLaunches()) {
      if (launch.isTerminated()
          || launch.getLaunchConfiguration().getType() != configuration.getType()) {  // line 124
        continue;
      }

[briandealwis]

What if you don't use JSPs? Is it possible Jasper is sharing space somehow?

[chanseokoh]

In fact, I can reproduce these using only the non-Maven helloworld projects, which don't have any JSP (although of course it may not guarantee Jasper is not kicked in.)

[briandealwis]

I wonder if you could use dtrace (like opensnoop) to see if they are somehow stomping on each others toes.

[chanseokoh]

It's surprising that this happens whenever any WorkspaceJob is running. I can reproduce these with the code below, which just runs a WorkspaceJob that doesn't terminate while doing nothing:

public class StandardDeployCommandHandler extends AbstractHandler {

  @Override
  public Object execute(ExecutionEvent event) throws ExecutionException {
    new WorkspaceJob("My Awesome Workspace Job") {
      @Override
      public IStatus runInWorkspace(IProgressMonitor monitor) throws CoreException {
        while (!monitor.isCanceled()) try {
          Thread.sleep(1000);
        } catch (Exception e) {}
        return Status.OK_STATUS;
      }
    }.schedule();
    return null;
  }

Not sure if it's the deploy job, the project creation, or both that need to be fixed.