[
https://issues.apache.org/jira/browse/HIVE-23425?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sam An updated HIVE-23425:
--------------------------
Description:
I observe in a cluster that HS2 connection to HMS was timed out.
{code:java}
// code placeholder
{code}
2020-05-07 19:28:46,718 WARN
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: MetaStoreClient lost connection.
Attempting to reconnect (1 of 1) after 1s. dropTable
org.apache.thrift.transport.TTransportException:
java.net.SocketTimeoutException: Read timed out at
org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:129)
~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:374)
~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:451)
~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:433)
~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:37)
~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714]
2020-05-07 19:28:47,718 INFO
org.apache.hadoop.hive.metastore.RetryingMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: RetryingMetaStoreClient trying
reconnect as
hive/ascend-px-ha2.ascend-p.a8du-8mgv.cloudera.s...@ascend-p.a8du-8mgv.cloudera.site
(auth:KERBEROS)
2020-05-07 19:28:47,719 INFO
org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: Closed a connection to metastore,
current connections: 29
2020-05-07 19:28:47,719 INFO
org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: Trying to connect to metastore
with URI thrift://ascend-px-master4.ascend-p.a8du-8mgv.cloudera.site:9083
2020-05-07 19:28:47,719 INFO
org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: HMSC::open(): Could not find
delegation token. Creating KERBEROS-based thrift connection.
2020-05-07 19:28:47,724 INFO
org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: Opened a connection to metastore,
current connections: 30
2020-05-07 19:28:47,725 INFO
org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
[HiveServer2-Background-Pool: Thread-21790]: Connected to metastore.
2020-05-07 19:28:47,730 INFO
org.apache.hadoop.hive.ql.hooks.HiveProtoLoggingHook:
[HiveServer2-Background-Pool: Thread-21790]: Received post-hook notification
for: hive_20200507192346_a1a0bad2-ca4f-4cd0-a0e7-22415c7050f0
2020-05-07 19:28:47,731 INFO
org.apache.hive.service.cli.operation.OperationManager:
[d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
Thread-19285]: Adding operation: OperationHandle [opType=EXECUTE_STATEMENT,
getHandleIdentifier()=db40b2c8-d291-4f34-9809-24b6300ee45c]
2020-05-07 19:28:47,731 INFO org.apache.hadoop.hive.common.LogUtils:
[d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
Thread-19285]: Thread context registration is done.
2020-05-07 19:28:47,731 INFO org.apache.hive.service.cli.operation.Operation:
[d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
Thread-19285]: [opType=EXECUTE_STATEMENT,
queryId=hive_20200507192847_08dbb746-b38f-405c-a92c-f6d2dd02b6f8,
startTime=1588879727730, sessionId=d900945d-9eb5-4b63-8ce9-c1166bc2474a,
createTime=1588879461427, userName=hive, ipAddress=10.28.140.56]
2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.Driver:
[d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
Thread-19285]: Compiling
command(queryId=hive_20200507192847_08dbb746-b38f-405c-a92c-f6d2dd02b6f8): repl
dump `*` from 1501982 with ('hive.repl.dump.metadata.only'='true',
'hive.repl.dump.include.acid.tables'='true')
2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.Driver:
[HiveServer2-Background-Pool: Thread-21790]: Completed executing
command(queryId=hive_20200507192346_a1a0bad2-ca4f-4cd0-a0e7-22415c7050f0); Time
taken: 301.177 seconds
2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.Driver:
[HiveServer2-Background-Pool: Thread-21790]: OK
2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.lockmgr.DbTxnManager:
[HiveServer2-Background-Pool: Thread-21790]: Stopped heartbeat for query:
hive_20200507192346_a1a0bad2-ca4f-4cd0-a0e7-22415c7050f0
2020-05-07 19:28:47,738 INFO org.apache.hadoop.hive.common.LogUtils:
[HiveServer2-Background-Pool: Thread-21790]: Unregistered logging context.
However, on HMS, the drop table operation has not been completed till 5 minutes
later.
was:I observe in a cluster that HS2 connection to HMS was timed out.
> HS2 disconnect should not affect DDL operation status
> -----------------------------------------------------
>
> Key: HIVE-23425
> URL: https://issues.apache.org/jira/browse/HIVE-23425
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
> Reporter: Sam An
> Assignee: Sam An
> Priority: Minor
>
> I observe in a cluster that HS2 connection to HMS was timed out.
> {code:java}
> // code placeholder
> {code}
> 2020-05-07 19:28:46,718 WARN
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: MetaStoreClient lost connection.
> Attempting to reconnect (1 of 1) after 1s. dropTable
> org.apache.thrift.transport.TTransportException:
> java.net.SocketTimeoutException: Read timed out at
> org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:129)
> ~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
> org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
> ~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
> org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:374)
> ~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
> org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:451)
> ~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
> org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:433)
> ~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714] at
> org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:37)
> ~[hive-exec-3.1.3000.7.1.0.0-714.jar:3.1.3000.7.1.0.0-714]
> 2020-05-07 19:28:47,718 INFO
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: RetryingMetaStoreClient trying
> reconnect as
> hive/ascend-px-ha2.ascend-p.a8du-8mgv.cloudera.s...@ascend-p.a8du-8mgv.cloudera.site
> (auth:KERBEROS)
> 2020-05-07 19:28:47,719 INFO
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: Closed a connection to
> metastore, current connections: 29
> 2020-05-07 19:28:47,719 INFO
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: Trying to connect to metastore
> with URI thrift://ascend-px-master4.ascend-p.a8du-8mgv.cloudera.site:9083
> 2020-05-07 19:28:47,719 INFO
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: HMSC::open(): Could not find
> delegation token. Creating KERBEROS-based thrift connection.
> 2020-05-07 19:28:47,724 INFO
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: Opened a connection to
> metastore, current connections: 30
> 2020-05-07 19:28:47,725 INFO
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient:
> [HiveServer2-Background-Pool: Thread-21790]: Connected to metastore.
> 2020-05-07 19:28:47,730 INFO
> org.apache.hadoop.hive.ql.hooks.HiveProtoLoggingHook:
> [HiveServer2-Background-Pool: Thread-21790]: Received post-hook notification
> for: hive_20200507192346_a1a0bad2-ca4f-4cd0-a0e7-22415c7050f0
> 2020-05-07 19:28:47,731 INFO
> org.apache.hive.service.cli.operation.OperationManager:
> [d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
> Thread-19285]: Adding operation: OperationHandle [opType=EXECUTE_STATEMENT,
> getHandleIdentifier()=db40b2c8-d291-4f34-9809-24b6300ee45c]
> 2020-05-07 19:28:47,731 INFO org.apache.hadoop.hive.common.LogUtils:
> [d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
> Thread-19285]: Thread context registration is done.
> 2020-05-07 19:28:47,731 INFO org.apache.hive.service.cli.operation.Operation:
> [d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
> Thread-19285]: [opType=EXECUTE_STATEMENT,
> queryId=hive_20200507192847_08dbb746-b38f-405c-a92c-f6d2dd02b6f8,
> startTime=1588879727730, sessionId=d900945d-9eb5-4b63-8ce9-c1166bc2474a,
> createTime=1588879461427, userName=hive, ipAddress=10.28.140.56]
> 2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.Driver:
> [d900945d-9eb5-4b63-8ce9-c1166bc2474a HiveServer2-HttpHandler-Pool:
> Thread-19285]: Compiling
> command(queryId=hive_20200507192847_08dbb746-b38f-405c-a92c-f6d2dd02b6f8):
> repl dump `*` from 1501982 with ('hive.repl.dump.metadata.only'='true',
> 'hive.repl.dump.include.acid.tables'='true')
> 2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.Driver:
> [HiveServer2-Background-Pool: Thread-21790]: Completed executing
> command(queryId=hive_20200507192346_a1a0bad2-ca4f-4cd0-a0e7-22415c7050f0);
> Time taken: 301.177 seconds
> 2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.Driver:
> [HiveServer2-Background-Pool: Thread-21790]: OK
> 2020-05-07 19:28:47,732 INFO org.apache.hadoop.hive.ql.lockmgr.DbTxnManager:
> [HiveServer2-Background-Pool: Thread-21790]: Stopped heartbeat for query:
> hive_20200507192346_a1a0bad2-ca4f-4cd0-a0e7-22415c7050f0
> 2020-05-07 19:28:47,738 INFO org.apache.hadoop.hive.common.LogUtils:
> [HiveServer2-Background-Pool: Thread-21790]: Unregistered logging context.
> However, on HMS, the drop table operation has not been completed till 5
> minutes later.
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
