Another question: does enabling tracing ( https://phoenix.apache.org/tracing.html) on phoenix help monitor following properties used by PQS?
avatica.connectioncache.concurrency avatica.connectioncache.initialcapacity avatica.connectioncache.maxcapacity avatica.connectioncache.expiryduration avatica.connectioncache.expiryunit avatica.statementcache.concurrency avatica.statementcache.initialcapacity avatica.statementcache.maxcapacity avatica.statementcache.expiryduration avatica.statementcache.expiryunit On Thu, Jan 5, 2017 at 10:04 AM, Tulasi Paradarami < [email protected]> wrote: > Yes, I mean 4.7.0. > Since PQS restart, we are seeing the error raised during fetch instead of > closeStatement. > > Here is the latest trace: > > TRACE server.AvaticaJsonHandler: request: {"connectionId": > "0359595b-509a-41e2-9348-d3f8fcec65df", "request": "fetch", > "fetchMaxRowCount": 2000, "offset": 100, "statementId": 181894} > TRACE jdbc.JdbcMeta: fetching 0359595b-509a-41e2-9348-d3f8fcec65df::181894 > offset:100 fetchMaxRowCount:2000 > TRACE server.AvaticaJsonHandler: response: Response: {"response":"error"," > exceptions":["java.lang.ArrayIndexOutOfBoundsException > \n"],"errorMessage":"ArrayIndexOutOfBoundsException: (null exception > message)","errorCode":-1,"sqlState":"00000","severity":" > UNKNOWN","rpcMetadata":{"response":"rpcMetadata"," > serverAddress":"pqs_hostname:8765"}}, Status:500 > DEBUG server.Server: RESPONSE / 500 handled=true > > > I also noticed that as the number concurrent connections on the server > increases, we are hitting this exception more frequently. > Note that, we are using default values for following parameters. > > *Configurations relating to the server statement cache.* > *Property* *Description* *Default* > avatica.statementcache.concurrency Statement cache concurrency level. > Default is 100. 100 > avatica.statementcache.initialcapacity Statement cache initial capacity. > Default is 1000. 1000 > avatica.statementcache.maxcapacity Statement cache maximum capacity. > Approaching this point, the cache will start to evict least recently used > statement objects. Default is 10000. 10000 > avatica.statementcache.expiryduration Statement cache expiration > duration. Any statements older than this value will be discarded. Default > is 5 minutes. 5 > avatica.statementcache.expiryunit Statement cache expiration unit. Unit > modifier applied to the value provided in avatica.statementcache.expiryunit. > Default is minutes. MINUTES > > > On Thu, Jan 5, 2017 at 9:44 AM, Josh Elser <[email protected]> wrote: > >> Interesting! I haven't come across this one myself. >> >> By Phoenix 4.7, am I to assume you mean 4.7.0? Phoenix version strings >> are 3 "digits", not 2. >> >> My first guess would be that it might be a race condition around the >> closeStatement call (either from multiple callers) or the automatic-closing >> logic inside of PQS itself (by default, PQS will close statements that >> haven't been used for 10mins, IIRC). >> >> Any more information on the context in which you see this would be very >> helpful. >> >> Tulasi Paradarami wrote: >> >>> We noticed that PQS started raising ArrayIndexOutOfBoundsException in >>> our production cluster. This exception is raised sporadically and goes >>> away when PQS is restarted. Does anyone know what might be causing this >>> exception? Are there any configuration (PQS and/or Avatica) parameters >>> that we can modify to prevent it from recurring? >>> >>> CDH 5.7.2 >>> HBase: 1.2.0 >>> Phoenix: 4.7 >>> >>> Here is an error stack for "closeStatement" request: >>> >>> {"level":"TRACE","message":" server.AvaticaJsonHandler: response: >>> Response: >>> {"response":"error","exceptions":["java.lang.ArrayIndexOutOf >>> BoundsException: >>> -1 >>> at java.util.ArrayList.fastRemove(ArrayList.java:528) >>> at java.util.ArrayList.remove(ArrayList.java:511) >>> at org.apache.phoenix.jdbc.PhoenixResultSet.close(PhoenixResult >>> Set.java:165) >>> at >>> org.apache.calcite.avatica.jdbc.JdbcMeta.closeStatement(Jdbc >>> Meta.java:559) >>> at >>> org.apache.calcite.avatica.remote.LocalService.apply(LocalSe >>> rvice.java:256) >>> at >>> org.apache.calcite.avatica.remote.Service$CloseStatementRequ >>> est.accept(Service.java:1529) >>> at >>> org.apache.calcite.avatica.remote.Service$CloseStatementRequ >>> est.accept(Service.java:1511) >>> at >>> org.apache.calcite.avatica.remote.AbstractHandler.apply(Abst >>> ractHandler.java:102) >>> at org.apache.calcite.avatica.remote.JsonHandler.apply(JsonHand >>> ler.java:43) >>> at >>> org.apache.calcite.avatica.server.AvaticaJsonHandler.handle( >>> AvaticaJsonHandler.java:73) >>> at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerL >>> ist.java:52) >>> at >>> org.eclipse.jetty.server.handler.HandlerWrapper.handle(Handl >>> erWrapper.java:97) >>> at org.eclipse.jetty.server.Server.handle(Server.java:497) >>> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) >>> at >>> org.eclipse.jetty.server.HttpConnection.onFillable(HttpConne >>> ction.java:245) >>> at org.eclipse.jetty.io >>> <http://org.eclipse.jetty.io>.AbstractConnection$2.run(Abstr >>> actConnection.java:540) >>> at >>> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(Queued >>> ThreadPool.java:635) >>> at >>> org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedT >>> hreadPool.java:555) >>> at java.lang.Thread.run(Thread.java:745) >>> "],"errorMessage":"ArrayIndexOutOfBoundsException: >>> -1","errorCode":-1,"sqlState":"00000","severity":"UNKNOWN"," >>> rpcMetadata":{"response":"rpcMetadata","serverAddress":"pqs_ >>> hostname:8765"}}, >>> Status:500"} >>> >>> >
