Java Maven deployment fails on flexible environment most of the time.

392 views
Skip to first unread message

Mehmet D. Akın

unread,
Jan 31, 2017, 12:07:14 PM1/31/17
to Google App Engine
I have a simple springboot Java application to deploy on appengine flexible environment, when I try to deploy it with:

mvn -e appengine:deploy

It fails with this error, (but rarely it deploys successfully) Unfortunately none of the error messages or exceptions are helpful. I am using  appengine-maven-plugin:1.1.0-beta to deploy.

Any idea how to get more information about the reason?

[INFO] GCLOUD: ERROR: (gcloud.app.deploy) Error Response: [9] 
[INFO] GCLOUD: Application startup error:
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.2 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.1 ms]
[INFO] GCLOUD:    [Eden: 16.0M(16.0M)->0.0B(17.0M) Survivors: 4096.0K->3072.0K Heap: 90.5M(410.0M)->88.0M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.13 sys=0.01, real=0.13 secs] 
[INFO] GCLOUD: I|16:46:34.098|Lexicon Generated.                                                                                  | TurkishMorphology$Builder#addTextDictionaryResources
[INFO] GCLOUD: 2017-01-31T16:46:34.215+0000: [GC pause (G1 Evacuation Pause) (young), 0.0975918 secs]
[INFO] GCLOUD:    [Parallel Time: 96.8 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  12017.7]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  3.0]
[INFO] GCLOUD:       [Update RS (ms):  42.2]
[INFO] GCLOUD:          [Processed Buffers:  93]
[INFO] GCLOUD:       [Scan RS (ms):  5.6]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.0]
[INFO] GCLOUD:       [Object Copy (ms):  46.1]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  96.8]
[INFO] GCLOUD:       [GC Worker End (ms):  12114.6]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.0 ms]
[INFO] GCLOUD:    [Other: 0.7 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.2 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.1 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.1 ms]
[INFO] GCLOUD:    [Eden: 17.0M(17.0M)->0.0B(17.0M) Survivors: 3072.0K->3072.0K Heap: 105.0M(410.0M)->96.0M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.09 sys=0.01, real=0.10 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:34.491+0000: [GC pause (G1 Evacuation Pause) (young), 0.0273624 secs]
[INFO] GCLOUD:    [Parallel Time: 26.8 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  12294.2]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  2.0]
[INFO] GCLOUD:       [Update RS (ms):  3.1]
[INFO] GCLOUD:          [Processed Buffers:  9]
[INFO] GCLOUD:       [Scan RS (ms):  8.9]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.1]
[INFO] GCLOUD:       [Object Copy (ms):  12.7]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  26.8]
[INFO] GCLOUD:       [GC Worker End (ms):  12321.0]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.0 ms]
[INFO] GCLOUD:    [Other: 0.5 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.1 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.0 ms]
[INFO] GCLOUD:    [Eden: 17.0M(17.0M)->0.0B(18.0M) Survivors: 3072.0K->2048.0K Heap: 113.0M(410.0M)->98.0M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.03 sys=0.00, real=0.02 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:34.656+0000: [GC pause (G1 Evacuation Pause) (young), 0.0126255 secs]
[INFO] GCLOUD:    [Parallel Time: 12.2 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  12458.6]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  1.9]
[INFO] GCLOUD:       [Update RS (ms):  3.1]
[INFO] GCLOUD:          [Processed Buffers:  11]
[INFO] GCLOUD:       [Scan RS (ms):  0.0]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.0]
[INFO] GCLOUD:       [Object Copy (ms):  7.2]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  12.2]
[INFO] GCLOUD:       [GC Worker End (ms):  12470.8]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.0 ms]
[INFO] GCLOUD:    [Other: 0.4 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.0 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.0 ms]
[INFO] GCLOUD:    [Eden: 18.0M(18.0M)->0.0B(28.0M) Survivors: 2048.0K->3072.0K Heap: 116.0M(410.0M)->98.5M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.01 sys=0.00, real=0.01 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:34.840+0000: [GC pause (G1 Evacuation Pause) (young), 0.0156458 secs]
[INFO] GCLOUD:    [Parallel Time: 15.1 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  12642.7]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  1.9]
[INFO] GCLOUD:       [Update RS (ms):  0.6]
[INFO] GCLOUD:          [Processed Buffers:  4]
[INFO] GCLOUD:       [Scan RS (ms):  0.0]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.0]
[INFO] GCLOUD:       [Object Copy (ms):  12.6]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  15.1]
[INFO] GCLOUD:       [GC Worker End (ms):  12657.8]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.0 ms]
[INFO] GCLOUD:    [Other: 0.5 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.0 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.0 ms]
[INFO] GCLOUD:    [Eden: 28.0M(28.0M)->0.0B(64.0M) Survivors: 3072.0K->3072.0K Heap: 126.5M(410.0M)->100.5M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.01 sys=0.00, real=0.02 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:35.211+0000: [GC pause (G1 Evacuation Pause) (young), 0.0376476 secs]
[INFO] GCLOUD:    [Parallel Time: 37.2 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  13013.9]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  1.8]
[INFO] GCLOUD:       [Update RS (ms):  3.8]
[INFO] GCLOUD:          [Processed Buffers:  13]
[INFO] GCLOUD:       [Scan RS (ms):  0.0]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.0]
[INFO] GCLOUD:       [Object Copy (ms):  31.4]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  37.1]
[INFO] GCLOUD:       [GC Worker End (ms):  13051.0]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.0 ms]
[INFO] GCLOUD:    [Other: 0.4 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.0 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.1 ms]
[INFO] GCLOUD:    [Eden: 64.0M(64.0M)->0.0B(82.0M) Survivors: 3072.0K->7168.0K Heap: 164.5M(410.0M)->104.0M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.04 sys=0.01, real=0.03 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:35.723+0000: [GC pause (G1 Evacuation Pause) (young), 0.0260400 secs]
[INFO] GCLOUD:    [Parallel Time: 25.5 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  13525.7]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  1.8]
[INFO] GCLOUD:       [Update RS (ms):  0.7]
[INFO] GCLOUD:          [Processed Buffers:  4]
[INFO] GCLOUD:       [Scan RS (ms):  0.1]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.0]
[INFO] GCLOUD:       [Object Copy (ms):  22.9]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  25.5]
[INFO] GCLOUD:       [GC Worker End (ms):  13551.2]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.1 ms]
[INFO] GCLOUD:    [Other: 0.4 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.0 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.1 ms]
[INFO] GCLOUD:    [Eden: 82.0M(82.0M)->0.0B(129.0M) Survivors: 7168.0K->10.0M Heap: 186.0M(410.0M)->108.4M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.03 sys=0.00, real=0.02 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:36.299+0000: [GC pause (G1 Evacuation Pause) (young), 0.1042257 secs]
[INFO] GCLOUD:    [Parallel Time: 103.6 ms, GC Workers: 1]
[INFO] GCLOUD:       [GC Worker Start (ms):  14101.8]
[INFO] GCLOUD:       [Ext Root Scanning (ms):  1.8]
[INFO] GCLOUD:       [Update RS (ms):  7.5]
[INFO] GCLOUD:          [Processed Buffers:  12]
[INFO] GCLOUD:       [Scan RS (ms):  0.1]
[INFO] GCLOUD:       [Code Root Scanning (ms):  0.0]
[INFO] GCLOUD:       [Object Copy (ms):  90.2]
[INFO] GCLOUD:       [Termination (ms):  0.0]
[INFO] GCLOUD:          [Termination Attempts:  1]
[INFO] GCLOUD:       [GC Worker Other (ms):  0.0]
[INFO] GCLOUD:       [GC Worker Total (ms):  99.7]
[INFO] GCLOUD:       [GC Worker End (ms):  14201.6]
[INFO] GCLOUD:    [Code Root Fixup: 0.0 ms]
[INFO] GCLOUD:    [Code Root Purge: 0.0 ms]
[INFO] GCLOUD:    [Clear CT: 0.1 ms]
[INFO] GCLOUD:    [Other: 0.5 ms]
[INFO] GCLOUD:       [Choose CSet: 0.0 ms]
[INFO] GCLOUD:       [Ref Proc: 0.1 ms]
[INFO] GCLOUD:       [Ref Enq: 0.0 ms]
[INFO] GCLOUD:       [Redirty Cards: 0.0 ms]
[INFO] GCLOUD:       [Humongous Register: 0.0 ms]
[INFO] GCLOUD:       [Humongous Reclaim: 0.0 ms]
[INFO] GCLOUD:       [Free CSet: 0.1 ms]
[INFO] GCLOUD:    [Eden: 129.0M(129.0M)->0.0B(117.0M) Survivors: 10.0M->16.0M Heap: 237.4M(410.0M)->116.1M(410.0M)]
[INFO] GCLOUD:  [Times: user=0.08 sys=0.00, real=0.11 secs] 
[INFO] GCLOUD: 2017-01-31T16:46:36.870+0000: [GC pause (G1 Evacuation Pause) (young)
[INFO] GCLOUD: 
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 05:24 min
[INFO] Finished at: 2017-01-31T17:48:57+01:00
[INFO] Final Memory: 21M/972M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal com.google.cloud.tools:appengine-maven-plugin:1.1.0-beta:deploy (default-cli) on project website: Execution default-cli of goal com.google.cloud.tools:appengine-maven-plugin:1.1.0-beta:deploy failed: Non zero exit: 1 -> [Help 1]
org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal com.google.cloud.tools:appengine-maven-plugin:1.1.0-beta:deploy (default-cli) on project website: Execution default-cli of goal com.google.cloud.tools:appengine-maven-plugin:1.1.0-beta:deploy failed: Non zero exit: 1
at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:212)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:307)
at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:193)
at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:106)
at org.apache.maven.cli.MavenCli.execute(MavenCli.java:863)
at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288)
at org.apache.maven.cli.MavenCli.main(MavenCli.java:199)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)
Caused by: org.apache.maven.plugin.PluginExecutionException: Execution default-cli of goal com.google.cloud.tools:appengine-maven-plugin:1.1.0-beta:deploy failed: Non zero exit: 1
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:145)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:207)
... 20 more
Caused by: com.google.cloud.tools.appengine.api.AppEngineException: Non zero exit: 1
at com.google.cloud.tools.appengine.cloudsdk.process.NonZeroExceptionExitListener.onExit(NonZeroExceptionExitListener.java:30)
at com.google.cloud.tools.appengine.cloudsdk.internal.process.DefaultProcessRunner.syncRun(DefaultProcessRunner.java:183)
at com.google.cloud.tools.appengine.cloudsdk.internal.process.DefaultProcessRunner.run(DefaultProcessRunner.java:128)
at com.google.cloud.tools.appengine.cloudsdk.CloudSdk.runGcloudCommand(CloudSdk.java:153)
at com.google.cloud.tools.appengine.cloudsdk.CloudSdk.runAppCommand(CloudSdk.java:108)
at com.google.cloud.tools.appengine.cloudsdk.CloudSdkAppEngineDeployment.deploy(CloudSdkAppEngineDeployment.java:68)
at com.google.cloud.tools.maven.DeployMojo.execute(DeployMojo.java:101)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
... 21 more
[ERROR] 
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:

Message has been deleted

Jordan (Cloud Platform Support)

unread,
Feb 2, 2017, 4:45:35 PM2/2/17
to Google App Engine
I am seeing existing issues [1][2][3] filed for this in the app-maven-plugin Github repository. 

I suggest you review these existing issues to see if they match your configuration and runtime and follow up there. If not it is recommended you open a new issue directly to the engineers working on the Maven plugin in that same Github repository (as Google Groups is meant for general product discussions). 

Reply all
Reply to author
Forward
0 new messages