Uploaded image for project: 'Hive'
  1. Hive
  2. HIVE-24800

Yarn cluster resource can't be released when close jdbc connection for hiveserver2

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Open
    • Critical
    • Resolution: Unresolved
    • 2.3.6
    • None
    • HiveServer2, JDBC, Spark
    • None

    Description

      When I submit an application job on yarn cluster by Hive on Spark. I found yarn cluster resource which app had apply for can't be released after closing jdbc connection for hiveserver2. I think multi thread operate the same connect would cause this issue, one thread create jdbc connection and start compile Hql, the other thread interrupt the connection when create DAG . I get error info below and alway recurrent this issue, can you help me confirm if it is an issue?xuefuz, How I do if indeed?

      error info:
      2020-12-10T10:24:30,069 INFO [HiveServer2-Handler-Pool: Thread-824055] session.SessionState: Updating thread name to 11bf6a51-9a3b-488b-885e-fc50af485a64 HiveServer2-Handler-Pool: Thread-824055
      2020-12-10T10:24:30,069 INFO [11bf6a51-9a3b-488b-885e-fc50af485a64 HiveServer2-Handler-Pool: Thread-824055] operation.OperationManager: Closing operation: OperationHandle [opType=EXECUTE_STATEMENT, getHandleIdentifier()=df4e1322-c60a-4c28-83e3-c19ae9243404]
      2020-12-10T10:24:30,069 INFO [11bf6a51-9a3b-488b-885e-fc50af485a64 HiveServer2-Handler-Pool: Thread-824055] operation.Operation: The running operation has been successfully interrupted: null
      2020-12-10T10:24:30,070 INFO [11bf6a51-9a3b-488b-885e-fc50af485a64 HiveServer2-Handler-Pool: Thread-824055] session.HiveSessionImpl: Operation log session directory is deleted: /cloud/data/hive/tmp/hadoop/operation_logs/11bf6a51-9a3b-488b-885e-fc50af485a64
      2020-12-10T10:24:30,070 INFO [11bf6a51-9a3b-488b-885e-fc50af485a64 HiveServer2-Handler-Pool: Thread-824055] conf.HiveConf: Using the default value passed in for log id: 11bf6a51-9a3b-488b-885e-fc50af485a64
      2020-12-10T10:24:30,070 INFO [11bf6a51-9a3b-488b-885e-fc50af485a64 HiveServer2-Handler-Pool: Thread-824055] session.SessionState: Resetting thread name to HiveServer2-Handler-Pool: Thread-824055
      2020-12-10T10:24:30,071 WARN [RPC-Handler-7] rpc.RpcDispatcher: [ClientProtocol] Closing RPC channel with 2 outstanding RPCs.
      2020-12-10T10:24:30,070 WARN [HiveServer2-Background-Pool: Thread-824059] spark.SetSparkReducerParallelism: Failed to get spark memory/core info
      java.lang.InterruptedException
      at java.lang.Object.wait(Native Method) ~[?:1.8.0_231]
      at java.lang.Object.wait(Object.java:460) ~[?:1.8.0_231]
      at io.netty.util.concurrent.DefaultPromise.await0(DefaultPromise.java:600) ~[netty-all-4.0.52.Final.jar:4.0.52.Final]
      at io.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:273) ~[netty-all-4.0.52.Final.jar:4.0.52.Final]
      at io.netty.util.concurrent.AbstractFuture.get(AbstractFuture.java:46) ~[netty-all-4.0.52.Final.jar:4.0.52.Final]
      at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.getExecutorCount(RemoteHiveSparkClient.java:156) ~[hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.getExecutorCount(RemoteHiveSparkClient.java:166) ~[hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.getMemoryAndCores(SparkSessionImpl.java:77) ~[hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.optimizer.spark.SetSparkReducerParallelism.getSparkMemoryAndCores(SetSparkReducerParallelism.java:238) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.optimizer.spark.SetSparkReducerParallelism.process(SetSparkReducerParallelism.java:173) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.DefaultRuleDispatcher.dispatch(DefaultRuleDispatcher.java:90) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.DefaultGraphWalker.dispatchAndReturn(DefaultGraphWalker.java:105) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.DefaultGraphWalker.dispatch(DefaultGraphWalker.java:89) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.PreOrderWalker.walk(PreOrderWalker.java:56) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.PreOrderWalker.walk(PreOrderWalker.java:61) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.PreOrderWalker.walk(PreOrderWalker.java:61) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.PreOrderWalker.walk(PreOrderWalker.java:61) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.PreOrderWalker.walk(PreOrderWalker.java:61) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.lib.DefaultGraphWalker.startWalking(DefaultGraphWalker.java:120) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.parse.spark.SparkCompiler.runSetReducerParallelism(SparkCompiler.java:288) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.parse.spark.SparkCompiler.optimizeOperatorPlan(SparkCompiler.java:122) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.parse.TaskCompiler.compile(TaskCompiler.java:140) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.parse.SemanticAnalyzer.analyzeInternal(SemanticAnalyzer.java:11273) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.parse.CalcitePlanner.analyzeInternal(CalcitePlanner.java:286) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.parse.BaseSemanticAnalyzer.analyze(BaseSemanticAnalyzer.java:258) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.Driver.compile(Driver.java:512) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.Driver.compileInternal(Driver.java:1317) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hadoop.hive.ql.Driver.compileAndRespond(Driver.java:1295) [hive-exec-2.3.6.jar:2.3.6]
      at org.apache.hive.service.cli.operation.SQLOperation.prepare(SQLOperation.java:204) [hive-service-2.3.6.jar:2.3.6]
      at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork$1.run(SQLOperation.java:346) [hive-service-2.3.6.jar:2.3.6]
      at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_231]
      at javax.security.auth.Subject.doAs(Subject.java:422) [?:1.8.0_231]
      at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1844) [hadoop-common-2.8.5.jar:?]
      at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork.run(SQLOperation.java:362) [hive-service-2.3.6.jar:2.3.6]
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_231]
      at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_231]
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_231]
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_231]
      at java.lang.Thread.run(Thread.java:748) [?:1.8.0_231]
      ...
      ...
      ...
      2020-12-10T10:24:43,770 INFO [HiveServer2-Background-Pool: Thread-824059] parse.CalcitePlanner: Completed plan generation
      2020-12-10T10:24:43,770 INFO [HiveServer2-Background-Pool: Thread-824059] ql.Driver: Semantic Analysis Completed
      2020-12-10T10:24:43,770 ERROR [HiveServer2-Background-Pool: Thread-824059] ql.Driver: FAILED: command has been interrupted: after analyzing query.
      2020-12-10T10:24:43,774 INFO [HiveServer2-Background-Pool: Thread-824059] ql.Driver: Compiling command(queryId=hadoop_20201210102414_27d30b57-1633-4c8a-b326-852b70bb2c2d) has been interrupted after 28.804 seconds
      2020-12-10T10:24:43,774 ERROR [HiveServer2-Background-Pool: Thread-824059] operation.Operation: Error running hive query:
      org.apache.hive.service.cli.HiveSQLException: Illegal Operation state transition from CLOSED to ERROR
      at org.apache.hive.service.cli.OperationState.validateTransition(OperationState.java:96) ~[hive-service-2.3.6.jar:2.3.6]
      at org.apache.hive.service.cli.OperationState.validateTransition(OperationState.java:102) ~[hive-service-2.3.6.jar:2.3.6]
      at org.apache.hive.service.cli.operation.Operation.setState(Operation.java:164) ~[hive-service-2.3.6.jar:2.3.6]
      at org.apache.hive.service.cli.operation.SQLOperation.prepare(SQLOperation.java:234) ~[hive-service-2.3.6.jar:2.3.6]
      at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork$1.run(SQLOperation.java:346) [hive-service-2.3.6.jar:2.3.6]
      at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_231]
      at javax.security.auth.Subject.doAs(Subject.java:422) [?:1.8.0_231]
      at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1844) [hadoop-common-2.8.5.jar:?]
      at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork.run(SQLOperation.java:362) [hive-service-2.3.6.jar:2.3.6]
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_231]
      at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_231]
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_231]
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_231]
      at java.lang.Thread.run(Thread.java:748) [?:1.8.0_231]

      Attachments

        Activity

          People

            Unassigned Unassigned
            Janvn1989 Wenping Zhan
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: