issue with the local GAE execution

[ludoch]

See SO entry at http://stackoverflow.com/questions/34620186/failing-to-run-zk-spreadsheet-on-app-engine-managed-vm

[GabiAxel]

Here is an example application to reproduce the problem: https://github.com/GabiAxel/zss-vm

[GabiAxel]

Just noticed the issue title - it happens both locally and in deployment.

A hunch: one difference I noticed between the environments is that GAE uses the datastore for storing the sessions. I configured ZK to use clustered sessions, but maybe something is not right there. Nothing in the logs about that though.

[janbartel]

@ludoch I've verified that the error occurs when using mvn gcloud:run, but not when deploying to a standard jetty 9.2.10 distribution.

I've pursued various avenues of investigation:

• I configured the standard jetty distro to use jdb session persistance - to quickly verify that the session is serializable - and the app works fine
• I configured the standard jetty distro to use a remote gcloud datastore for session persistance (one of the new jetty session managers I've been working on), and again the app works fine

I'm running out of ways to investigate this with the tools I've got. I'd like to try to use the new jetty work that @gregw has been doing in the #140 branch, but it is missing the app-engine services like memcache and datastore. Is there any way that we could get those into that branch so that it would be a complete environment to run the webapp in? That way it could be debugged a little easier.

Failing that, do you have any other suggestions for how to debug this? As the zk spreadsheet stuff is closed-source, its extremely difficult to work with.

For the record, when running locally with mvn gcloud:run, I can always get the webapp to fail with the following errors (note that the name of the css file mutates with every new run):

[INFO] SEVERE: Failed to load media, /view/z_mu10/aQJZ1/1ic/0/ss_aQJZ1_f0_sheet_0.css
[INFO] java.lang.NullPointerException
[INFO] at org.zkoss.zss.ui.Spreadsheet.getMergeMatrixHelper(Spreadsheet.java:2755)
[INFO] at org.zkoss.zss.ui.Spreadsheet.prepareBasicStyleSheet(Spreadsheet.java:4144)
[INFO] at org.zkoss.zss.ui.Spreadsheet.getSheetDefaultRules0(Spreadsheet.java:4603)
[INFO] at org.zkoss.zss.ui.Spreadsheet.getSheetDefaultRules(Spreadsheet.java:4597)
[INFO] at org.zkoss.zss.ui.Spreadsheet.access$6200(Spreadsheet.java:219)
[INFO] at org.zkoss.zss.ui.Spreadsheet$ExtraCtrl.getMedia(Spreadsheet.java:3041)
[INFO] at org.zkoss.zk.au.http.AuDynaMediar.service(AuDynaMediar.java:128)
[INFO] at org.zkoss.zk.au.http.DHtmlUpdateServlet.doGet(DHtmlUpdateServlet.java:459)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:618)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
[INFO] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
[INFO] at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at com.google.apphosting.runtime.jetty9.SaveSessionFilter.doFilter(SaveSessionFilter.java:37)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
[INFO] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
[INFO] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:553)
[INFO] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
[INFO] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
[INFO] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
[INFO] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[INFO] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
[INFO] at com.google.apphosting.vmruntime.jetty9.VmRuntimeWebAppContext.doScope(VmRuntimeWebAppContext.java:299)
[INFO] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[INFO] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
[INFO] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
[INFO] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
[INFO] at org.eclipse.jetty.server.Server.handle(Server.java:497)
[INFO] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
[INFO] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
[INFO] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
[INFO] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
[INFO] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
[INFO] at java.lang.Thread.run(Thread.java:745)

[INFO] SEVERE:
[INFO] java.lang.NullPointerException
[INFO] at org.zkoss.zss.ui.au.in.FetchActiveRangeCommand.process(FetchActiveRangeCommand.java:57)
[INFO] at org.zkoss.zss.ui.Spreadsheet.service(Spreadsheet.java:5876)
[INFO] at org.zkoss.zk.ui.impl.DesktopImpl.service(DesktopImpl.java:710)
[INFO] at org.zkoss.zk.ui.impl.UiEngineImpl.execUpdate(UiEngineImpl.java:1249)
[INFO] at org.zkoss.zk.au.http.DHtmlUpdateServlet.process(DHtmlUpdateServlet.java:611)
[INFO] at org.zkoss.zk.au.http.DHtmlUpdateServlet.doGet(DHtmlUpdateServlet.java:485)
[INFO] at org.zkoss.zk.au.http.DHtmlUpdateServlet.doPost(DHtmlUpdateServlet.java:494)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
[INFO] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
[INFO] at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at com.google.apphosting.runtime.jetty9.SaveSessionFilter.doFilter(SaveSessionFilter.java:37)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
[INFO] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
[INFO] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
[INFO] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:553)
[INFO] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
[INFO] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
[INFO] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
[INFO] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[INFO] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
[INFO] at com.google.apphosting.vmruntime.jetty9.VmRuntimeWebAppContext.doScope(VmRuntimeWebAppContext.java:299)
[INFO] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[INFO] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
[INFO] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
[INFO] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
[INFO] at org.eclipse.jetty.server.Server.handle(Server.java:497)
[INFO] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
[INFO] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
[INFO] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
[INFO] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
[INFO] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
[INFO] at java.lang.Thread.run(Thread.java:745)

[ludoch]

This is why you can try next:
1/ build a jettyhome and jettybase from the branch Greg is working on
2/ make sure quickstart is not used (i.e non annotated servlets) or ask
Greg his workaround
3/ set up these 2 env variables to the correct location of 1/

APP_ENGINE_JETTY_BASE

and

APP_ENGINE_JETTY_HOME

4/ run mvn gcloud:run that will provide stub API services to test against.
The issue might be in this layer (poor session management?) or already
fixed in the lastest branch we are working on.

On Wed, Jan 6, 2016 at 11:36 PM, Jan Bartel notifications@github.com
wrote:

@ludoch https://github.com/ludoch I've verified that the error occurs
when using mvn gcloud:run, but not when deploying to a standard jetty
9.2.10 distribution.

I've pursued various avenues of investigation:

• I configured the standard jetty distro to use jdb session
  persistance - to quickly verify that the session is serializable - and the
  app works fine
• I configured the standard jetty distro to use a remote gcloud
  datastore for session persistance (one of the new jetty session managers
  I've been working on), and again the app works fine

I'm running out of ways to investigate this with the tools I've got. I'd
like to try to use the new jetty work that @gregw
https://github.com/gregw has been doing in the #140
#140
branch, but it is missing the app-engine services like memcache and
datastore. Is there any way that we could get those into that branch so
that it would be a complete environment to run the webapp in? That way it
could be debugged a little easier.

Failing that, do you have any other suggestions for how to debug this? As
the zk spreadsheet stuff is closed-source, its extremely difficult to work
with.

For the record, when running locally with mvn gcloud:run, I can always get
the webapp to fail with the following errors (note that the name of the css
file mutates with every new run):

[INFO] SEVERE: Failed to load media,
/view/z_mu10/aQJZ1/1ic/0/ss_aQJZ1_f0_sheet_0.css
[INFO] java.lang.NullPointerException
[INFO] at
org.zkoss.zss.ui.Spreadsheet.getMergeMatrixHelper(Spreadsheet.java:2755)
[INFO] at
org.zkoss.zss.ui.Spreadsheet.prepareBasicStyleSheet(Spreadsheet.java:4144)
[INFO] at
org.zkoss.zss.ui.Spreadsheet.getSheetDefaultRules0(Spreadsheet.java:4603)
[INFO] at
org.zkoss.zss.ui.Spreadsheet.getSheetDefaultRules(Spreadsheet.java:4597)
[INFO] at org.zkoss.zss.ui.Spreadsheet.access$6200(Spreadsheet.java:219)
[INFO] at
org.zkoss.zss.ui.Spreadsheet$ExtraCtrl.getMedia(Spreadsheet.java:3041)
[INFO] at org.zkoss.zk.au.http.AuDynaMediar.service(AuDynaMediar.java:128)
[INFO] at
org.zkoss.zk.au.http.DHtmlUpdateServlet.doGet(DHtmlUpdateServlet.java:459)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:618)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
[INFO] at
org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
[INFO] at
com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at
com.google.apphosting.runtime.jetty9.SaveSessionFilter.doFilter(SaveSessionFilter.java:37)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at
com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
[INFO] at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
[INFO] at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:553)
[INFO] at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
[INFO] at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
[INFO] at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[INFO] at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
[INFO] at
com.google.apphosting.vmruntime.jetty9.VmRuntimeWebAppContext.doScope(VmRuntimeWebAppContext.java:299)
[INFO] at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[INFO] at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
[INFO] at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
[INFO] at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
[INFO] at org.eclipse.jetty.server.Server.handle(Server.java:497)
[INFO] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
[INFO] at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
[INFO] at
org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
[INFO] at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
[INFO] at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
[INFO] at java.lang.Thread.run(Thread.java:745)

[INFO] SEVERE:
[INFO] java.lang.NullPointerException
[INFO] at
org.zkoss.zss.ui.au.in.FetchActiveRangeCommand.process(FetchActiveRangeCommand.java:57)
[INFO] at org.zkoss.zss.ui.Spreadsheet.service(Spreadsheet.java:5876)
[INFO] at org.zkoss.zk.ui.impl.DesktopImpl.service(DesktopImpl.java:710)
[INFO] at
org.zkoss.zk.ui.impl.UiEngineImpl.execUpdate(UiEngineImpl.java:1249)
[INFO] at
org.zkoss.zk.au.http.DHtmlUpdateServlet.process(DHtmlUpdateServlet.java:611)
[INFO] at
org.zkoss.zk.au.http.DHtmlUpdateServlet.doGet(DHtmlUpdateServlet.java:485)
[INFO] at
org.zkoss.zk.au.http.DHtmlUpdateServlet.doPost(DHtmlUpdateServlet.java:494)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
[INFO] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
[INFO] at
org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
[INFO] at
com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at
com.google.apphosting.runtime.jetty9.SaveSessionFilter.doFilter(SaveSessionFilter.java:37)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at
com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
[INFO] at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
[INFO] at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:553)
[INFO] at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
[INFO] at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
[INFO] at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
[INFO] at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[INFO] at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
[INFO] at
com.google.apphosting.vmruntime.jetty9.VmRuntimeWebAppContext.doScope(VmRuntimeWebAppContext.java:299)
[INFO] at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[INFO] at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
[INFO] at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
[INFO] at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
[INFO] at org.eclipse.jetty.server.Server.handle(Server.java:497)
[INFO] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
[INFO] at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
[INFO] at
org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
[INFO] at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
[INFO] at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
[INFO] at java.lang.Thread.run(Thread.java:745)

—
Reply to this email directly or view it on GitHub
#151 (comment)
.

[janbartel]

@ludoch thanks for that tip. I've now been able to successfully run the gcloud plugin against Greg's new jetty-home and jetty-base from the #140 branch. Some tips documented here to make it work:

1. follow @ludoch's steps from previous post
2. configure the gcloud plugin to pass into the jetty invocation an explicit location for the logs and the exact location of the webapp:

       <jvm_flag>
           <param>-Dcom.google.apphosting.logs=/tmp</param>
           <param>-Droot.webapp=/this/is/my/test-webapp/target/test-webapp</param>
       </jvm_flag>

Using the #140 branch I've been able to produce more and better debug output. It is apparent that:

• there are multiple simultaneous requests in play
• the zss code does a lot of interactions with the session
• the zss code maybe trying to store some kind of request count in the session object, as evidenced by the name of this attribute: org.zkoss.zk.ui.sys.RequestCount

Based on those observations above, I suspect that the architecture of the appengine session manager maybe the cause of the problem: as I mentioned in a prior email exchange, the architecture is such that multiple simultaneous requests do NOT share the same session object, but rather distinct different instances. This is one of the major differences between appengine jetty and the jetty distro. To test this theory, I'll replace the appengine session manager with the standard jetty session managers (I'll try both non-clustered and clustered). I'll post my results shortly.

[janbartel]

I can confirm that replacing the appengine session manager with either the jetty HashSessionManager (non-clustering) or the JDBCSessionManager (clustering) makes the app work.

[gregw]

Is there a particular reason that the GAE session manager does not share session instances within an instance? If not, then we could make the new session manager being developed for memcache/gcloud available in compat - this would fix this issue... unless the multiple requests were spread over multiple instances - in which case there could be problems anyway.

[gregw]

Marked as an enhancement - ie that compat should use a session manager that shares instances withing the same instance. This is supported by the new session manager in jetty-9.4 that can use both gcloud datastore and memecache in a more standard fashion,

[GabiAxel]

I did some more experimentation. I tried using the "vanilla" Jetty runtime with default automatic scaling and got another exception about session timeout. Then I switched to manual scaling and it worked fine. I understand that manual scaling is closer to a non-clustered environment so the session is not clustered across instances and the problem doesn't happen.

I suggest documenting this to make it clearer to new users. I think a matrix showing how each combination (runtime type - compat or vanilla, scaling - automatic or manual, and other possible configurations) behaves in manner of session clustering (or lack of clustering).

Anyway for my case it would be acceptable to use the vanilla runtime, but I much prefer to have session clustering and automatic scaling. Is there a configuration that I could use? Would that be a matter of customising Dockerfile or something more?

[gregw]

@GabiAxel I'm working on an example for #188 that will show how to add a pure gcloud session manager to the jetty9 image. Unfortunately that configuration also has problems as it doesn't use mem-cache to pull session changes between nodes, thus without a sticky load balancer there is a risk of stale sessions. The example has a 1sec stale timeout, but that is a large window for new requests on a different instance to not see changes!

The Jetty-9.4 session manager will allow both shared sessions within an instance and immediate passivation once all requests drain from an instance. However, this could still result in stale sessions if a constant stream of requests is spread over multiple nodes such that the request count never goes to 0.

I guess the approach in GAEv1 and current compat of not sharing sessions and always retrieving from mem cache is an attempt to avoid such stale sessions, but it has the not-share-within-instance problem.

Unfortunately given the poorly defined semantics of the servlet session spec, I'm not sure there is a silver bullet here!