You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@phoenix.apache.org by "Kiran Kumar Maturi (JIRA)" <ji...@apache.org> on 2019/05/09 04:47:00 UTC
[jira] [Comment Edited] (PHOENIX-5267) With namespaces enabled
Phoenix client times out with high loads
[ https://issues.apache.org/jira/browse/PHOENIX-5267?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16836071#comment-16836071 ]
Kiran Kumar Maturi edited comment on PHOENIX-5267 at 5/9/19 4:46 AM:
---------------------------------------------------------------------
{code:java}
java.io.IOException: java.net.SocketTimeoutException: callTimeout=1200000, callDuration=1210009: Call to <host>:60020 failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. row 'TEST:TABLE' on table 'hbase:acl' at region=hbase:acl,1556023472786.c6aad76a67d289740bfa5ef7b0fb6e46., hostname=<host>,60020,1556023331491, seqNum=2 at org.apache.hadoop.hbase.security.User.runAsLoginUser(User.java:212) at org.apache.hadoop.hbase.security.access.AccessController.getUserPermissions(AccessController.java:2217) at org.apache.hadoop.hbase.protobuf.generated.AccessControlProtos$AccessControlService$1.getUserPermissions(AccessControlProtos.java:9949) at org.apache.hadoop.hbase.protobuf.generated.AccessControlProtos$AccessControlService.callMethod(AccessControlProtos.java:10107) at org.apache.hadoop.hbase.regionserver.HRegion.execService(HRegion.java:8354) at org.apache.hadoop.hbase.regionserver.RSRpcServices.execServiceOnRegion(RSRpcServices.java:2208) at org.apache.hadoop.hbase.regionserver.RSRpcServices.execService(RSRpcServices.java:2190) at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:35076) at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2399) at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:124) at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:188) at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:168)Caused by: java.net.SocketTimeoutException: callTimeout=1200000, callDuration=1210009: Call to <host>:60020 failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. row 'TEST:TABLE' on table 'hbase:acl' at region=hbase:acl,1556023472786.c6aad76a67d289740bfa5ef7b0fb6e46., hostname=<host>,60020,1556023331491, seqNum=2 at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:171) at org.apache.hadoop.hbase.client.HTable.get(HTable.java:869) at org.apache.hadoop.hbase.client.HTable.get(HTable.java:835) at org.apache.hadoop.hbase.security.access.AccessControlLists.getPermissions(AccessControlLists.java:514) at org.apache.hadoop.hbase.security.access.AccessControlLists.getUserPermissions(AccessControlLists.java:548) at org.apache.hadoop.hbase.security.access.AccessControlLists.getUserTablePermissions(AccessControlLists.java:537) at org.apache.hadoop.hbase.security.access.AccessController$10.run(AccessController.java:2220) at org.apache.hadoop.hbase.security.access.AccessController$10.run(AccessController.java:2217) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAs(Subject.java:422) at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1760) at org.apache.hadoop.security.SecurityUtil.doAsUser(SecurityUtil.java:453) at org.apache.hadoop.security.SecurityUtil.doAsLoginUser(SecurityUtil.java:434) at sun.reflect.GeneratedMethodAccessor51.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.hadoop.hbase.util.Methods.call(Methods.java:39) at org.apache.hadoop.hbase.security.User.runAsLoginUser(User.java:210) ... 11 moreCaused by: java.io.IOException: Call to <host>:60020 failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. at org.apache.hadoop.hbase.ipc.AbstractRpcClient.wrapException(AbstractRpcClient.java:296) at org.apache.hadoop.hbase.ipc.RpcClientImpl.call(RpcClientImpl.java:1295) at org.apache.hadoop.hbase.ipc.AbstractRpcClient.callBlockingMethod(AbstractRpcClient.java:231) at org.apache.hadoop.hbase.ipc.AbstractRpcClient$BlockingRpcChannelImplementation.callBlockingMethod(AbstractRpcClient.java:340) at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$BlockingStub.get(ClientProtos.java:35494) at org.apache.hadoop.hbase.client.HTable$3.call(HTable.java:861) at org.apache.hadoop.hbase.client.HTable$3.call(HTable.java:852) at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:137) ... 28 moreCaused by: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. at org.apache.hadoop.hbase.ipc.Call.checkAndSetTimeout(Call.java:73) at org.apache.hadoop.hbase.ipc.RpcClientImpl.call(RpcClientImpl.java:1269) ... 34 more{code}
on the region server where 'hbase:acl' table is hosted the above exceptions are seen.
For each write request check for permissions by the PhoenixAccessController.requireAccess(). calls
PhoenixAccessController.getUserPermissions() which uses AccessControlClient to get user permissions
org.apache.hadoop.hbase.security.access.AccessControlClient.getUserPermissions()
Which makes a request to hbase:acl thereby hotspotting and requests timeout
was (Author: kiran.maturi):
{code:java}
java.io.IOException: java.net.SocketTimeoutException: callTimeout=1200000, callDuration=1210009: Call to <host>:60020 failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. row 'TEST:TABLE' on table 'hbase:acl' at region=hbase:acl,1556023472786.c6aad76a67d289740bfa5ef7b0fb6e46., hostname=<host>,60020,1556023331491, seqNum=2 at org.apache.hadoop.hbase.security.User.runAsLoginUser(User.java:212) at org.apache.hadoop.hbase.security.access.AccessController.getUserPermissions(AccessController.java:2217) at org.apache.hadoop.hbase.protobuf.generated.AccessControlProtos$AccessControlService$1.getUserPermissions(AccessControlProtos.java:9949) at org.apache.hadoop.hbase.protobuf.generated.AccessControlProtos$AccessControlService.callMethod(AccessControlProtos.java:10107) at org.apache.hadoop.hbase.regionserver.HRegion.execService(HRegion.java:8354) at org.apache.hadoop.hbase.regionserver.RSRpcServices.execServiceOnRegion(RSRpcServices.java:2208) at org.apache.hadoop.hbase.regionserver.RSRpcServices.execService(RSRpcServices.java:2190) at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:35076) at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2399) at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:124) at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:188) at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:168)Caused by: java.net.SocketTimeoutException: callTimeout=1200000, callDuration=1210009: Call to <host>:60020 failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. row 'TEST:TABLE' on table 'hbase:acl' at region=hbase:acl,1556023472786.c6aad76a67d289740bfa5ef7b0fb6e46., hostname=<host>,60020,1556023331491, seqNum=2 at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:171) at org.apache.hadoop.hbase.client.HTable.get(HTable.java:869) at org.apache.hadoop.hbase.client.HTable.get(HTable.java:835) at org.apache.hadoop.hbase.security.access.AccessControlLists.getPermissions(AccessControlLists.java:514) at org.apache.hadoop.hbase.security.access.AccessControlLists.getUserPermissions(AccessControlLists.java:548) at org.apache.hadoop.hbase.security.access.AccessControlLists.getUserTablePermissions(AccessControlLists.java:537) at org.apache.hadoop.hbase.security.access.AccessController$10.run(AccessController.java:2220) at org.apache.hadoop.hbase.security.access.AccessController$10.run(AccessController.java:2217) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAs(Subject.java:422) at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1760) at org.apache.hadoop.security.SecurityUtil.doAsUser(SecurityUtil.java:453) at org.apache.hadoop.security.SecurityUtil.doAsLoginUser(SecurityUtil.java:434) at sun.reflect.GeneratedMethodAccessor51.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.hadoop.hbase.util.Methods.call(Methods.java:39) at org.apache.hadoop.hbase.security.User.runAsLoginUser(User.java:210) ... 11 moreCaused by: java.io.IOException: Call to <host>:60020 failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. at org.apache.hadoop.hbase.ipc.AbstractRpcClient.wrapException(AbstractRpcClient.java:296) at org.apache.hadoop.hbase.ipc.RpcClientImpl.call(RpcClientImpl.java:1295) at org.apache.hadoop.hbase.ipc.AbstractRpcClient.callBlockingMethod(AbstractRpcClient.java:231) at org.apache.hadoop.hbase.ipc.AbstractRpcClient$BlockingRpcChannelImplementation.callBlockingMethod(AbstractRpcClient.java:340) at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$BlockingStub.get(ClientProtos.java:35494) at org.apache.hadoop.hbase.client.HTable$3.call(HTable.java:861) at org.apache.hadoop.hbase.client.HTable$3.call(HTable.java:852) at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:137) ... 28 moreCaused by: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=19, waitTime=91709, operationTimeout=91708 expired. at org.apache.hadoop.hbase.ipc.Call.checkAndSetTimeout(Call.java:73) at org.apache.hadoop.hbase.ipc.RpcClientImpl.call(RpcClientImpl.java:1269) ... 34 more{code}
on the region server where 'hbase:acl' table is hosted the above exceptions are seen.
For each write request check for permissions by the PhoenixAccessController.requireAccess(). calls
PhoenixAccessController.getUserPermissions() which uses AccessControlClient to get user permissions
org.apache.hadoop.hbase.security.access.AccessControlClient.getUserPermissions()
Which makes a request to hbase:acl causing hotspotting and requests timeout
> With namespaces enabled Phoenix client times out with high loads
> ----------------------------------------------------------------
>
> Key: PHOENIX-5267
> URL: https://issues.apache.org/jira/browse/PHOENIX-5267
> Project: Phoenix
> Issue Type: Bug
> Affects Versions: 4.14.1
> Reporter: Kiran Kumar Maturi
> Priority: Major
> Fix For: 4.14.2
>
>
> Steps to reproduce:
> * Enable namespaces for phoenix 4.14.1 and hbase 1.3
> * Run high load using pherf client with 48 threads
> After sometime the client hangs. and gives timeout exception
> {code:java}
> [pool-1-thread-1] WARN org.apache.phoenix.pherf.workload.WriteWorkload -
> java.util.concurrent.ExecutionException: org.apache.phoenix.exception.PhoenixIOException: callTimeout=1200000, callDuration=1238263: Call to <host> failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=857, waitTime=120001, operationTimeout=120000 expired. row '^@TEST^@TABLE' on table 'SYSTEM:CATALOG' at region=SYSTEM:CATALOG,1556024429507.0f80d6de0a002d1421b8fd384e956254., hostname=<host>, seqNum=2
> at java.util.concurrent.FutureTask.report(FutureTask.java:122)
> at java.util.concurrent.FutureTask.get(FutureTask.java:192)
> at org.apache.phoenix.pherf.workload.WriteWorkload.waitForBatches(WriteWorkload.java:239)
> at org.apache.phoenix.pherf.workload.WriteWorkload.exec(WriteWorkload.java:189)
> at org.apache.phoenix.pherf.workload.WriteWorkload.access$100(WriteWorkload.java:56)
> at org.apache.phoenix.pherf.workload.WriteWorkload$1.run(WriteWorkload.java:165)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.phoenix.exception.PhoenixIOException: callTimeout=1200000, callDuration=1238263: Call to <host> failed on local exception: org.apache.hadoop.hbase.ipc.CallTimeoutException: Call id=857, waitTime=120001, operationTimeout=120000 expired. row '^@TEST^@TABLE' on table 'SYSTEM:CATALOG' at region=SYSTEM:CATALOG,1556024429507.0f80d6de0a002d1421b8fd384e956254., hostname=<host>, seqNum=2
> at org.apache.phoenix.util.ServerUtil.parseServerException(ServerUtil.java:144)
> at org.apache.phoenix.query.ConnectionQueryServicesImpl.metaDataCoprocessorExec(ConnectionQueryServicesImpl.java:1379)
> at org.apache.phoenix.query.ConnectionQueryServicesImpl.metaDataCoprocessorExec(ConnectionQueryServicesImpl.java:1343)
> at org.apache.phoenix.query.ConnectionQueryServicesImpl.getTable(ConnectionQueryServicesImpl.java:1560)
> at org.apache.phoenix.schema.MetaDataClient.updateCache(MetaDataClient.java:644)
> at org.apache.phoenix.schema.MetaDataClient.updateCache(MetaDataClient.java:538)
> at org.apache.phoenix.schema.MetaDataClient.updateCache(MetaDataClient.java:530)
> at org.apache.phoenix.schema.MetaDataClient.updateCache(MetaDataClient.java:526)
> at org.apache.phoenix.execute.MutationState.validateAndGetServerTimestamp(MutationState.java:755)
> at org.apache.phoenix.execute.MutationState.validateAll(MutationState.java:743)
> at org.apache.phoenix.execute.MutationState.send(MutationState.java:875)
> at org.apache.phoenix.execute.MutationState.send(MutationState.java:1360)
> at org.apache.phoenix.execute.MutationState.commit(MutationState.java:1183)
> at org.apache.phoenix.jdbc.PhoenixConnection$3.call(PhoenixConnection.java:670)
> at org.apache.phoenix.jdbc.PhoenixConnection$3.call(PhoenixConnection.java:666)
> at org.apache.phoenix.call.CallRunner.run(CallRunner.java:53)
> at org.apache.phoenix.jdbc.PhoenixConnection.commit(PhoenixConnection.java:666)
> at org.apache.phoenix.pherf.workload.WriteWorkload$2.call(WriteWorkload.java:297)
> at org.apache.phoenix.pherf.workload.WriteWorkload$2.call(WriteWorkload.java:256)
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)