You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hive.apache.org by "Sam An (Jira)" <ji...@apache.org> on 2020/05/08 21:33:00 UTC
[jira] [Updated] (HIVE-23425) HS2 disconnect should not affect DDL
operation status
[ 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.site@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.site@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)