phoenix-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Tulasi Paradarami <tulasi.krishn...@gmail.com>
Subject Re: ArrayIndexOutOfBoundsException in PQS
Date Thu, 05 Jan 2017 19:46:47 GMT
Unfortunately, there's no error stack other than:
ArrayIndexOutOfBoundsException: (null exception message)

I've set org.apache.calcite.avatica=TRACE

jdbc.jdbcMeta has following messages:

17/01/05 18:47:49 TRACE server.AvaticaJsonHandler: request:
{"connectionId": "68b4686a-c51e-4e82-b9df-a55eeb6188d4", "request":
"closeStatement", "statementId": 15251}
17/01/05 18:47:49 TRACE jdbc.JdbcMeta: closing statement
68b4686a-c51e-4e82-b9df-a55eeb6188d4::15251
17/01/05 18:47:49 DEBUG jdbc.JdbcMeta: Expiring statement 15251 because
EXPLICIT

EXPLICIT implies statement has been closed and not evicted?

On Thu, Jan 5, 2017 at 11:03 AM, Josh Elser <josh.elser@gmail.com> wrote:

> No, PQS itself is not instrumented with the HTrace library, only (parts
> of?) the thick Phoenix JDBC inside of PQS.
>
> There is some support for metrics that I built into Avatica, but, sadly,
> I've not had the time to spend to focus on how we expose those downstream
> in Phoenix. That would be the "easiest" way to monitor it, but I think it'd
> require modifying Phoenix and re-building it (which is likely not something
> you want to do).
>
> You can try setting org.apache.calcite.avatica.jdbc.JdbcMeta=DEBUG in the
> $PHOENIX_HOME/bin/log4j.properties file. That will print some messages
> when a statement or connection is automatically evicted from the respective
> cache.
>
> Finally, no stack trace on the ErrorResponse you showed for fetch()?
>
> Tulasi Paradarami wrote:
>
>> 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
>> <tulasi.krishna.p@gmail.com <mailto:tulasi.krishna.p@gmail.com>> 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.ArrayIndexOutOf
>> BoundsException\n"],"errorMessage":"ArrayIndexOutOfBoundsException:
>>     (null exception
>>     message)","errorCode":-1,"sqlState":"00000","severity":"UNKN
>> OWN","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 <josh.elser@gmail.com
>>     <mailto:josh.elser@gmail.com>> 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>
>>             <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"}
>>
>>
>>
>>

Mime
View raw message