If I make a request to my app, and (I assume) AppEngine decides it needs
to start up a new servlet instance for me, then warming up the server
can take about 5000ms. Is this normal?
For example, the first two items in my log for a request will be:
09-08 12:57AM 30.917 [standard notification of incoming request]
09-08 12:57AM 35.344
com.google.appengine.repackaged.com.google.common.base.FinalizableReferenceQueue$SystemLoader
loadFinalizer: Not allowed to access system class loader.
Note the five second difference between the two timestamps. This all
happens before my app has even started running any code. As this only
happens the first time, it's not really a problem, but does cause nasty
red warning banners in my logs.
Possibly related, the first time I do a database request in one of these
new servers, I'm getting the following scary backtrace. Everything
*works* --- it's just a warning. Can I safely ignore it or is this a
symptom of something wrong with my code?
09-08 12:57AM 35.361
com.google.appengine.repackaged.com.google.common.base.FinalizableReferenceQueue
<init>: Failed to start reference finalizer thread. Reference cleanup
will only occur when new references are created.
java.lang.reflect.InvocationTargetException
at
com.google.appengine.runtime.Request.process-5d48060cebaffe54(Request.java)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Method.java:40)
at
com.google.appengine.repackaged.com.google.common.base.FinalizableReferenceQueue.<init>(FinalizableReferenceQueue.java:124)
at
com.google.appengine.repackaged.com.google.common.labs.misc.InterningPools$WeakInterningPool.<clinit>(InterningPools.java:104)
at
com.google.appengine.repackaged.com.google.common.labs.misc.InterningPools.newWeakInterningPool(InterningPools.java:48)
at
com.google.appengine.repackaged.com.google.io.protocol.ProtocolSupport.<clinit>(ProtocolSupport.java:55)
at
com.google.apphosting.api.DatastorePb$GetRequest.freeze(DatastorePb.java:7233)
at
com.google.apphosting.api.DatastorePb$GetRequest$1.<init>(DatastorePb.java:7177)
at
com.google.apphosting.api.DatastorePb$GetRequest.<clinit>(DatastorePb.java:7174)
at
com.google.appengine.api.datastore.DatastoreServiceImpl.get(DatastoreServiceImpl.java:90)
at
com.google.appengine.api.datastore.DatastoreServiceImpl.get(DatastoreServiceImpl.java:69)
at
com.google.appengine.api.datastore.DatastoreServiceImpl.get(DatastoreServiceImpl.java:57)
at
com.cowlark.stellation2.server.db.GAEPersistenceInterface.atomicallyModify(GAEPersistenceInterface.java:130)
at
com.cowlark.stellation2.server.db.GAEPersistenceInterface.lock(GAEPersistenceInterface.java:160)
at com.cowlark.stellation2.server.db.ServerDB.lock(ServerDB.java:110)
at
com.cowlark.stellation2.server.RPCServiceImpl.ping(RPCServiceImpl.java:81)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Method.java:40)
at
com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:527)
at
com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:166)
at
com.google.gwt.user.server.rpc.RemoteServiceServlet.doPost(RemoteServiceServlet.java:86)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:713)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:806)
at
org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
at
com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
at
com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:237)
at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:313)
at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:830)
at
com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
at
com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:139)
at
com.google.apphosting.runtime.JavaRuntime.handleRequest(JavaRuntime.java:235)
at
com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:4950)
at
com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:4948)
at
com.google.net.rpc.impl.BlockingApplicationHandler.handleRequest(BlockingApplicationHandler.java:24)
at com.google.net.rpc.impl.RpcUtil.runRpcInApplication(RpcUtil.java:359)
at com.google.net.rpc.impl.Server$2.run(Server.java:823)
at
com.google.tracing.LocalTraceSpanRunnable.run(LocalTraceSpanRunnable.java:56)
at
com.google.tracing.LocalTraceSpanBuilder.internalContinueSpan(LocalTraceSpanBuilder.java:516)
at com.google.net.rpc.impl.Server.startRpc(Server.java:778)
at com.google.net.rpc.impl.Server.processRequest(Server.java:351)
at
com.google.net.rpc.impl.ServerConnection.messageReceived(ServerConnection.java:437)
at
com.google.net.rpc.impl.RpcConnection.parseMessages(RpcConnection.java:319)
at
com.google.net.rpc.impl.RpcConnection.dataReceived(RpcConnection.java:290)
at com.google.net.async.Connection.handleReadEvent(Connection.java:428)
at
com.google.net.async.EventDispatcher.processNetworkEvents(EventDispatcher.java:762)
at
com.google.net.async.EventDispatcher.internalLoop(EventDispatcher.java:207)
at com.google.net.async.EventDispatcher.loop(EventDispatcher.java:101)
at
com.google.net.rpc.RpcService.runUntilServerShutdown(RpcService.java:251)
at
com.google.apphosting.runtime.JavaRuntime$RpcRunnable.run(JavaRuntime.java:392)
at java.lang.Thread.run(Unknown Source)
Caused by: java.security.AccessControlException: access denied
(java.lang.RuntimePermission modifyThreadGroup)
at java.security.AccessControlContext.checkPermission(Unknown Source)
at java.security.AccessController.checkPermission(Unknown Source)
at java.lang.SecurityManager.checkPermission(Unknown Source)
at java.lang.ThreadGroup.checkAccess(Unknown Source)
at java.lang.Thread.init(Unknown Source)
at java.lang.Thread.<init>(Unknown Source)
at
com.google.appengine.repackaged.com.google.common.base.internal.Finalizer.<init>(Finalizer.java:96)
at
com.google.appengine.repackaged.com.google.common.base.internal.Finalizer.startFinalizer(Finalizer.java:82)
... 66 more
--
┌─── ｄｇ＠ｃｏｗｌａｒｋ．ｃｏｍ ───── http://www.cowlark.com ─────
│
│ "They laughed at Newton. They laughed at Einstein. Of course, they
│ also laughed at Bozo the Clown." --- Carl Sagan
--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups
"Google App Engine for Java" group.
To post to this group, send email to [email protected]
To unsubscribe from this group, send email to
[email protected]
For more options, visit this group at
http://groups.google.com/group/google-appengine-java?hl=en
-~----------~----~----~----~------~----~------~--~---
