"Page Map Locked By Thread" Error?

[bobcusick]

Anyone seen this one? I'm not sure what it means...

Code: Select all

org.mozilla.javascript.WrappedException: Wrapped org.apache.wicket.WicketRuntimeException: After 1 minute the Pagemap null is still locked by: Thread[http-80-3,5,main], giving up trying to get the page for path: 4 (onShow#1174)
       at com.servoy.j2db.scripting.ScriptVariableScope.put(Unknown Source)
       at org.mozilla.javascript.ScriptableObject.putProperty(ScriptableObject.java:1768)
       at org.mozilla.javascript.ScriptRuntime.setObjectProp(ScriptRuntime.java:1531)
       at org.mozilla.javascript.ScriptRuntime.setObjectProp(ScriptRuntime.java:1519)
       at org.mozilla.javascript.Interpreter.interpretLoop(Interpreter.java:3355)
       at script.onShow(onShow:1174)
       at org.mozilla.javascript.Interpreter.interpret(Interpreter.java:2680)
       at org.mozilla.javascript.InterpretedFunction.call(InterpretedFunction.java:166)
       at org.mozilla.javascript.ContextFactory.doTopCall(ContextFactory.java:387)
       at org.mozilla.javascript.ScriptRuntime.doTopCall(ScriptRuntime.java:3134)
       at org.mozilla.javascript.InterpretedFunction.call(InterpretedFunction.java:165)
       at com.servoy.j2db.scripting.ScriptEngine.executeFunction(Unknown Source)
       at com.servoy.j2db.FormController.executeFunction(Unknown Source)
       at com.servoy.j2db.FormController.executeFormMethod(Unknown Source)
       at com.servoy.j2db.FormController.executeOnShowMethod(Unknown Source)
       at com.servoy.j2db.FormController.access$1500(Unknown Source)
       at com.servoy.j2db.FormController$3.run(Unknown Source)
       at com.servoy.j2db.server.headlessclient.WebClient.executeEvents(Unknown Source)
       at com.servoy.j2db.server.headlessclient.WebClient.executeEvents(Unknown Source)
       at com.servoy.j2db.server.headlessclient.WebClient.onBeginRequest(Unknown Source)
       at com.servoy.j2db.server.headlessclient.WebClientsApplication$7.onBeginRequest(Unknown Source)
       at org.apache.wicket.RequestCycle.prepare(RequestCycle.java:1242)
       at org.apache.wicket.RequestCycle.step(RequestCycle.java:1306)
       at org.apache.wicket.RequestCycle.steps(RequestCycle.java:1438)
       at org.apache.wicket.RequestCycle.request(RequestCycle.java:546)
       at org.apache.wicket.protocol.http.WicketFilter.doGet(WicketFilter.java:486)
       at com.servoy.j2db.server.servlets.Zm.doGet(Unknown Source)
       at org.apache.wicket.protocol.http.WicketServlet.doGet(WicketServlet.java:138)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
       at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
       at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
       at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
       at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
       at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:554)
       at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
       at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
       at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
       at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
       at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
       at java.lang.Thread.run(Thread.java:636)
    Caused by: org.apache.wicket.WicketRuntimeException: After 1 minute the Pagemap null is still locked by: Thread[http-80-3,5,main], giving up trying to get the page for path: 4
       at org.apache.wicket.session.pagemap.LeastRecentlyAccessedEvictionStrategy.evict(LeastRecentlyAccessedEvictionStrategy.java:61)
       at org.apache.wicket.AccessStackPageMap.put(AccessStackPageMap.java:310)
       at org.apache.wicket.Session.requestDetached(Session.java:1462)
       at org.apache.wicket.RequestCycle.detach(RequestCycle.java:1178)
       at org.apache.wicket.RequestCycle.steps(RequestCycle.java:1464)

[jcompagner]

somehow something is very busy doing stuff (loading a form or something) but the other is waiting for that to happen, and it will wait 1 minute until it times out with that exception.
Please to try figure out why the first request takes so long.

What version are you seeing this?

[sbutler]

I'm getting this too. On a server Servoy version 5.2.13 -build 1025.
I also see there was a support case here, but never any resolution: https://support.servoy.com/browse/SVY-2162

Any suggestions?

[jcompagner]

what are you doing that makes one request so slow that it takes more the 1 minute to complete?

[sbutler]

I don't know, and there isn't any information in the error or log to tell me exactly why it happens.

[jcompagner]

but the stacktrace says a lot
if you get this:

After 1 minute the Pagemap null is still locked by: Thread[http-80-3,5,main],

then the stacktrace you see next is of the thread that is busy so Thread[http-80-3,5,main] so we can see what that thread is really doing.

[sbutler]

Yes, but what am I supposed to do with that? I would like to know what code is running in that thread that is blocking it. Is that detail in a log somewhere? How can I see exactly what that thread is doing?

[jcompagner]

yes that is what you see, you see which thread is really doing stuff (for more then a minute), blocking all other incoming request

[sbutler]

Getting a thread ID doesn't help me much. Lets look at Bob's example in the first post.

Code: Select all

After 1 minute the Pagemap null is still locked by: Thread[http-80-3,5,main], giving up trying to get the page for path: 4 (onShow#1174)

So that's saying that its attempting to run the onShow method, but its blocked because another thread, Thread[http-80-3,5,main], is blocking it (because its taking more than 1 minute). So my question is, what is Thread[http-80-3,5,main] doing?

[jcompagner]

thats what i explain to say
The stack trace you get after the exception that says that as a title is the stack dump of the "http-80-3,5,main"

so

org.mozilla.javascript.WrappedException: Wrapped org.apache.wicket.WicketRuntimeException: After 1 minute the Pagemap null is still locked by: Thread[http-80-3,5,main], giving up trying to get the page for path: 4 (onShow#1174)
at com.servoy.j2db.scripting.ScriptVariableScope.put(Unknown Source)
at org.mozilla.javascript.ScriptableObject.putProperty(ScriptableObject.java:1768)
at org.mozilla.javascript.ScriptRuntime.setObjectProp(ScriptRuntime.java:1531)
at org.mozilla.javascript.ScriptRuntime.setObjectProp(ScriptRuntime.java:1519)
at org.mozilla.javascript.Interpreter.interpretLoop(Interpreter.java:3355)
at script.onShow(onShow:1174)

that means that thread http-80-3,5,main that is blocking the thread that wants to get the lock is doing the onshow...
It is currently setting a scope variable..

[Yeroc]

This looks suspiciously similar to an issue we reported (https://support.servoy.com/browse/SVY-4922) where we sometimes see form variable updates taking a very long time resulting in page lock timeout errors with very similar stack traces...