What steps will reproduce the problem?
This problem happens occasionally when our application is using a
PersevereStore to back a
scrolling dojo grid. The grid loads data 25 rows at a time. When this problem
occurs, we get the
first 25 rows back fine, but the exception occurs in one of the later requests
when we scroll the
grid view.
What is the expected output? What do you see instead?
The expected output is what we usually see: that the later results are returned
without error.
Instead, the call to the server fails and we get the following stack trace in
the log file:
INFO | jvm 1 | 2010/02/09 07:46:08 | Feb 9, 2010 7:46:08 AM
org.persvr.remote.PersevereFilter$DefaultHandler call
INFO | jvm 1 | 2010/02/09 07:46:08 | WARNING:
java.lang.NullPointerException
INFO | jvm 1 | 2010/02/09 07:46:08 | Feb 9, 2010 7:46:08 AM
org.persvr.remote.PersevereFilter$DefaultHandler call
INFO | jvm 1 | 2010/02/09 07:46:08 | WARNING:
INFO | jvm 1 | 2010/02/09 07:46:08 | java.lang.NullPointerException
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableArray.fetchNextPage(PersistableArray.java:449)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableArray.get(PersistableArray.java:521)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptableObject.getProperty(ScriptableObject.java:1645)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptRuntime.getObjectIndex(ScriptRuntime.java:1496)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptRuntime.getObjectIndex(ScriptRuntime.java:1481)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c255._c1(FieldValueCore.js:14)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c255.call(FieldValueCore.js)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.callWithChecks(Method.java:140)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.call(Method.java:94)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.call(Method.java:56)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.optimizer.OptRuntime.call1(OptRuntime.java:66)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c251._c4(authenticate.js:112)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c251.call(authenticate.js)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.ProtectedGlobal$2.callWithChecks(ProtectedGlobal.java:64)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.call(Method.java:94)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.call(Method.java:56)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.optimizer.OptRuntime.callName(OptRuntime.java:97)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c251._c3(authenticate.js:87)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c251.call(authenticate.js)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.ProtectedGlobal$2.callWithChecks(ProtectedGlobal.java:64)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.call(Method.java:94)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.Method.call(Method.java:56)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.security.UserSecurity.getPermissionLevel(UserSecurity.java:36)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableObject.checkSecurity(PersistableObject.java:871)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableObject.get(PersistableObject.java:132)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptableObject.getProperty(ScriptableObject.java:1617)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptRuntime.getObjectProp(ScriptRuntime.java:1437)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptRuntime.getObjectProp(ScriptRuntime.java:1423)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.Interpreter.interpretLoop(Interpreter.java:3027)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.Interpreter.interpret(Interpreter.java:2487)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.InterpretedFunction.call(InterpretedFunction.java:164)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableArray$FilterFunction$1$1.getNext(PersistableArray.jav
a:126)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableArray$FilterFunction$1$1.hasNext(PersistableArray.jav
a:136)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.QueryArray.toArray(QueryArray.java:152)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.PersistableArray$FastSortFunction.call(PersistableArray.java:212
)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.Interpreter.interpretLoop(Interpreter.java:3330)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.Interpreter.interpret(Interpreter.java:2487)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.InterpretedFunction.call(InterpretedFunction.java:164)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.optimizer.OptRuntime.call1(OptRuntime.java:66)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c219._c23(org/persvr/server.js:169)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c219.call(org/persvr/server.js)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.optimizer.OptRuntime.call1(OptRuntime.java:66)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c15._c1(function:2)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c15.call(function)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ContextFactory.doTopCall(ContextFactory.java:398)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.ScriptRuntime.doTopCall(ScriptRuntime.java:3065)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mozilla.javascript.gen.c15.call(function)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.JsonPath.doJsonPath(JsonPath.java:128)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.JsonPath.doJsonPath(JsonPath.java:88)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.data.JsonPath.getTarget(JsonPath.java:79)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.remote.Client$IndividualRequest.requestData(Client.java:245)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.remote.PersevereFilter$DefaultHandler.call(PersevereFilter.java:616)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.persvr.remote.PersevereFilter.doFilter(PersevereFilter.java:357)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.jav
a:1115)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:361)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollecti
on.java:230)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.Server.handle(Server.java:324)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.ja
va:864)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:533)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:207)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:403)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
INFO | jvm 1 | 2010/02/09 07:46:08 | at
org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:522)
What version of the product are you using? On what operating system?
Persevere 1.0
Other information:
Our codebase has custom authentication and access control code, which may be
evident in the
stack trace shown. However, examination of the relevant code in Persevere
leads us to believe
that the problem is in the Persevere code, not in our access control.
fetchNextPage() is a
synchronized method which uses an iterator and then sets it to null. We can't
find the code that
initializes the iterator (at least not inside the synchronized region where it
can be guaranteed to
execute before the iterator is needed). It seems to us that multiple requests
for multiple pages
made to a server under load could cause the synchronized block to execute twice
without any
other code executing in between, which could lead to this problem. As with
most
synchronization issues, this doesn't happen every time, so it is difficult to
reproduce.
Original issue reported on code.google.com by dsta...@gmail.com on 9 Feb 2010 at 7:12
Original issue reported on code.google.com by
dsta...@gmail.com
on 9 Feb 2010 at 7:12