大数据集群开启 kerberos 认证后 Hive 作业执行失败

大数据
本文是大数据问题排查系列 的 kerberos问题排查子序列博文之一,讲述大数据集群开启 kerberos 安全认证后,hive作业执行失败的根本原因,解决方法与背后的原理和机制。 以下是正文。

[[421858]]

本文转载自微信公众号「明哥的IT随笔」,作者IT明哥。转载本文请联系明哥的IT随笔公众号。

1 前言

大家好,我是明哥!

本文是大数据问题排查系列 的 kerberos问题排查子序列博文之一,讲述大数据集群开启 kerberos 安全认证后,hive作业执行失败的根本原因,解决方法与背后的原理和机制。 以下是正文。

2 问题现象

大数据集群开启 kerberos 安全认证后,HIVE ON SPARK 作业执行失败。通过客户端 beeline 提交作业,报错 spark client 创建失败,其报错信息是:

  1. Failed to create spark client for spark session xxx: java.util.concurrent.TimeoutException: client xxx timedout waiting for connection from the remote spark driver 

或者是:

  1. Failed to create spark client for spark session xxx: java.lang.RuntimeException: spark-submit 

客户端 beeline 的报错信息截图如下图所示:

error-msg-beeline1

error-msg-beeline2

3 问题分析

按照问题排查的常规思路,我们首先查看 hiveserver2 的日志,能发现核心报错信息 “Error while waiting for Remote Spark Driver to connect back to HiveServer2”,hiveserver2 的完整相关日志如下所示:

  1. 2021-09-02 11:01:29,496 ERROR org.apache.hive.spark.client.SparkClientImpl: [HiveServer2-Background-Pool: Thread-135]: Error while waiting for Remote Spark Driver to connect back to HiveServer2. 
  2. java.util.concurrent.ExecutionException: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  3.     at io.netty.util.concurrent.AbstractFuture.get(AbstractFuture.java:41) ~[netty-common-4.1.17.Final.jar:4.1.17.Final] 
  4.     at org.apache.hive.spark.client.SparkClientImpl.<init>(SparkClientImpl.java:103) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  5.     at org.apache.hive.spark.client.SparkClientFactory.createClient(SparkClientFactory.java:90) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  6.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.createRemoteClient(RemoteHiveSparkClient.java:104) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  7.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.<init>(RemoteHiveSparkClient.java:100) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  8.     at org.apache.hadoop.hive.ql.exec.spark.HiveSparkClientFactory.createHiveSparkClient(HiveSparkClientFactory.java:77) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  9.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:131) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  10.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionManagerImpl.getSession(SparkSessionManagerImpl.java:132) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  11.     at org.apache.hadoop.hive.ql.exec.spark.SparkUtilities.getSparkSession(SparkUtilities.java:131) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  12.     at org.apache.hadoop.hive.ql.exec.spark.SparkTask.execute(SparkTask.java:122) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  13.     at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:199) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  14.     at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:97) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  15.     at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:2200) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  16.     at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1843) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  17.     at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1563) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  18.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1339) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  19.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1334) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  20.     at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:256) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  21.     at org.apache.hive.service.cli.operation.SQLOperation.access$600(SQLOperation.java:92) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  22.     at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork$1.run(SQLOperation.java:345) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  23.     at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_201] 
  24.     at javax.security.auth.Subject.doAs(Subject.java:422) [?:1.8.0_201] 
  25.     at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1875) [hadoop-common-3.0.0-cdh6.3.2.jar:?] 
  26.     at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork.run(SQLOperation.java:357) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  27.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_201] 
  28.     at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_201] 
  29.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_201] 
  30.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_201] 
  31.     at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201] 
  32. Caused by: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  33.     at org.apache.hive.spark.client.SparkClientImpl$2.run(SparkClientImpl.java:495) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  34.     ... 1 more 
  35. 2021-09-02 11:01:29,505 ERROR org.apache.hadoop.hive.ql.exec.spark.SparkTask: [HiveServer2-Background-Pool: Thread-135]: Failed to execute Spark task "Stage-1" 
  36. org.apache.hadoop.hive.ql.metadata.HiveException: Failed to create Spark client for Spark session f43a158c-168a-4117-8993-8f1780913715_0: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  37.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.getHiveException(SparkSessionImpl.java:286) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  38.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:135) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  39.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionManagerImpl.getSession(SparkSessionManagerImpl.java:132) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  40.     at org.apache.hadoop.hive.ql.exec.spark.SparkUtilities.getSparkSession(SparkUtilities.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  41.     at org.apache.hadoop.hive.ql.exec.spark.SparkTask.execute(SparkTask.java:122) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  42.     at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:199) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  43.     at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:97) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  44.     at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:2200) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  45.     at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1843) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  46.     at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1563) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  47.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1339) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  48.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1334) [hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  49.     at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:256) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  50.     at org.apache.hive.service.cli.operation.SQLOperation.access$600(SQLOperation.java:92) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  51.     at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork$1.run(SQLOperation.java:345) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  52.     at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_201] 
  53.     at javax.security.auth.Subject.doAs(Subject.java:422) [?:1.8.0_201] 
  54.     at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1875) [hadoop-common-3.0.0-cdh6.3.2.jar:?] 
  55.     at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork.run(SQLOperation.java:357) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  56.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_201] 
  57.     at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_201] 
  58.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_201] 
  59.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_201] 
  60.     at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201] 
  61. Caused by: java.lang.RuntimeException: Error while waiting for Remote Spark Driver to connect back to HiveServer2. 
  62.     at org.apache.hive.spark.client.SparkClientImpl.<init>(SparkClientImpl.java:124) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  63.     at org.apache.hive.spark.client.SparkClientFactory.createClient(SparkClientFactory.java:90) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  64.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.createRemoteClient(RemoteHiveSparkClient.java:104) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  65.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.<init>(RemoteHiveSparkClient.java:100) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  66.     at org.apache.hadoop.hive.ql.exec.spark.HiveSparkClientFactory.createHiveSparkClient(HiveSparkClientFactory.java:77) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  67.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  68.     ... 22 more 
  69. Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  70.     at io.netty.util.concurrent.AbstractFuture.get(AbstractFuture.java:41) ~[netty-common-4.1.17.Final.jar:4.1.17.Final] 
  71.     at org.apache.hive.spark.client.SparkClientImpl.<init>(SparkClientImpl.java:103) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  72.     at org.apache.hive.spark.client.SparkClientFactory.createClient(SparkClientFactory.java:90) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  73.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.createRemoteClient(RemoteHiveSparkClient.java:104) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  74.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.<init>(RemoteHiveSparkClient.java:100) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  75.     at org.apache.hadoop.hive.ql.exec.spark.HiveSparkClientFactory.createHiveSparkClient(HiveSparkClientFactory.java:77) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  76.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  77.     ... 22 more 
  78. Caused by: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  79.     at org.apache.hive.spark.client.SparkClientImpl$2.run(SparkClientImpl.java:495) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  80.     ... 1 more 
  81. 2021-09-02 11:01:29,506 ERROR org.apache.hadoop.hive.ql.Driver: [HiveServer2-Background-Pool: Thread-135]: FAILED: Execution Error, return code 30041 from org.apache.hadoop.hive.ql.exec.spark.SparkTask. Failed to create Spark client for Spark session f43a158c-168a-4117-8993-8f1780913715_0: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  82. 2021-09-02 11:01:29,507 INFO  org.apache.hadoop.hive.ql.Driver: [HiveServer2-Background-Pool: Thread-135]: Completed executing command(queryId=hive_20210902110125_ca2ab819-fb9c-4540-8690-2a1ed303186d); Time taken: 3.722 seconds 
  83. 2021-09-02 11:01:29,526 ERROR org.apache.hive.service.cli.operation.Operation: [HiveServer2-Background-Pool: Thread-135]: Error running hive query:  
  84. org.apache.hive.service.cli.HiveSQLException: Error while processing statement: FAILED: Execution Error, return code 30041 from org.apache.hadoop.hive.ql.exec.spark.SparkTask. Failed to create Spark client for Spark session f43a158c-168a-4117-8993-8f1780913715_0: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  85.     at org.apache.hive.service.cli.operation.Operation.toSQLException(Operation.java:329) ~[hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  86.     at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:258) ~[hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  87.     at org.apache.hive.service.cli.operation.SQLOperation.access$600(SQLOperation.java:92) ~[hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  88.     at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork$1.run(SQLOperation.java:345) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  89.     at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_201] 
  90.     at javax.security.auth.Subject.doAs(Subject.java:422) [?:1.8.0_201] 
  91.     at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1875) [hadoop-common-3.0.0-cdh6.3.2.jar:?] 
  92.     at org.apache.hive.service.cli.operation.SQLOperation$BackgroundWork.run(SQLOperation.java:357) [hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  93.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_201] 
  94.     at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_201] 
  95.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_201] 
  96.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_201] 
  97.     at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201] 
  98. Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: Failed to create Spark client for Spark session f43a158c-168a-4117-8993-8f1780913715_0: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  99.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.getHiveException(SparkSessionImpl.java:286) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  100.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:135) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  101.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionManagerImpl.getSession(SparkSessionManagerImpl.java:132) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  102.     at org.apache.hadoop.hive.ql.exec.spark.SparkUtilities.getSparkSession(SparkUtilities.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  103.     at org.apache.hadoop.hive.ql.exec.spark.SparkTask.execute(SparkTask.java:122) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  104.     at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:199) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  105.     at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:97) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  106.     at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:2200) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  107.     at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1843) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  108.     at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1563) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  109.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1339) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  110.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1334) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  111.     at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:256) ~[hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  112.     ... 11 more 
  113. Caused by: java.lang.RuntimeException: Error while waiting for Remote Spark Driver to connect back to HiveServer2. 
  114.     at org.apache.hive.spark.client.SparkClientImpl.<init>(SparkClientImpl.java:124) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  115.     at org.apache.hive.spark.client.SparkClientFactory.createClient(SparkClientFactory.java:90) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  116.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.createRemoteClient(RemoteHiveSparkClient.java:104) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  117.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.<init>(RemoteHiveSparkClient.java:100) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  118.     at org.apache.hadoop.hive.ql.exec.spark.HiveSparkClientFactory.createHiveSparkClient(HiveSparkClientFactory.java:77) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  119.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  120.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionManagerImpl.getSession(SparkSessionManagerImpl.java:132) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  121.     at org.apache.hadoop.hive.ql.exec.spark.SparkUtilities.getSparkSession(SparkUtilities.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  122.     at org.apache.hadoop.hive.ql.exec.spark.SparkTask.execute(SparkTask.java:122) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  123.     at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:199) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  124.     at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:97) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  125.     at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:2200) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  126.     at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1843) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  127.     at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1563) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  128.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1339) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  129.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1334) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  130.     at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:256) ~[hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  131.     ... 11 more 
  132. Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  133.     at io.netty.util.concurrent.AbstractFuture.get(AbstractFuture.java:41) ~[netty-common-4.1.17.Final.jar:4.1.17.Final] 
  134.     at org.apache.hive.spark.client.SparkClientImpl.<init>(SparkClientImpl.java:103) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  135.     at org.apache.hive.spark.client.SparkClientFactory.createClient(SparkClientFactory.java:90) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  136.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.createRemoteClient(RemoteHiveSparkClient.java:104) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  137.     at org.apache.hadoop.hive.ql.exec.spark.RemoteHiveSparkClient.<init>(RemoteHiveSparkClient.java:100) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  138.     at org.apache.hadoop.hive.ql.exec.spark.HiveSparkClientFactory.createHiveSparkClient(HiveSparkClientFactory.java:77) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  139.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionImpl.open(SparkSessionImpl.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  140.     at org.apache.hadoop.hive.ql.exec.spark.session.SparkSessionManagerImpl.getSession(SparkSessionManagerImpl.java:132) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  141.     at org.apache.hadoop.hive.ql.exec.spark.SparkUtilities.getSparkSession(SparkUtilities.java:131) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  142.     at org.apache.hadoop.hive.ql.exec.spark.SparkTask.execute(SparkTask.java:122) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  143.     at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:199) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  144.     at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:97) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  145.     at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:2200) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  146.     at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1843) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  147.     at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1563) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  148.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1339) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  149.     at org.apache.hadoop.hive.ql.Driver.run(Driver.java:1334) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  150.     at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:256) ~[hive-service-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  151.     ... 11 more 
  152. Caused by: java.lang.RuntimeException: spark-submit process failed with exit code 1 and error ? 
  153.     at org.apache.hive.spark.client.SparkClientImpl$2.run(SparkClientImpl.java:495) ~[hive-exec-2.1.1-cdh6.3.2.jar:2.1.1-cdh6.3.2] 
  154.     ... 1 more 
  155. 2021-09-02 11:01:29,552 INFO  org.apache.hadoop.hive.conf.HiveConf: [HiveServer2-Handler-Pool: Thread-128]: Using the default value passed in for log id: f43a158c-168a-4117-8993-8f1780913715 

但是因为 “Error while waiting for Remote Spark Driver to connect back to HiveServer2” 造成 “Failed to create spark client for spark session xxx:” 的根本原因,相对难发现,因为在hiveserver2的日志,hive on spark 作业的日志 (通过yarn logs -applicationId xx 查看),甚至yarn的日志中,都找不到明显的相关信息;

4 问题原因

进一步排查问题,需要 在理解作业的底层执行机制的基础上, 大胆猜想,小心求证。

HIVE 作业的执行机制如下:

  • 终端业务用户比如 xyz 提交给 HIVESERVER2 的 SQL作业,经过 HIVESERVER2 的解析编译和优化后,一般会生成 MR/TEZ/SPARK 任务(之所以说一般,是因为有的 SQL 是直接在HIVESERVER2中执行的,不会生成分布式的 MR/TEZ/SPARK 任务),这些 MR/TEZ/SPARK 任务最终访问底层的基础设施 HDFS 和 YARN 时,一样要经过 kerberos 安全认证;
  • 当启用了 HIVE 的代理机制时(hive.server.enable.doAs=true),业务终端用户如 xyz 提交的 HIVE SQL 作业底层的 MR/TEZ/SPARK 任务访问 HDFS/YARN 时,HDFS/YARN 验证的是业务终端用户 xyz 的身份 (后续 HDFS/YARN 的权限校验,校验的也是 xyz 用户的权限);
  • 当没有启用 HIVE 的代理机制时(hive.server.enable.doAs=false),业务终端用户提交的 HIVE SQL 作业底层的 MR/TEZ/SPARK 任务访问 HDFS/YARN 时,需要验证的是 hiveserver2 服务对应的用户,即 hive 的身份 (后续 HDFS/YARN 的权限校验,校验的也是 hive 用户的权限);

至此问题就比较清晰了:

  • 在上述集群环境中,cdh 集群管理员开启了 kerberos 安全认证,即集群中 hdfs/yarn/hive/spark/kafka 等服务的使用,都需要经过kerberso 安全认证;
  • 当 hiveserver2 执行业务用户提交的 sql 作业时,由于业务用户配置了使用 spark 执行引擎,所以 hiveserver2 需要首先为业务用户用户创建 spark 集群;
  • 在上述集群环境中,cdh 集群管理员开启了 hive.server.enable.doAs=true,所以 hiveserver2 创建 spark集群时,spark 集群的 driver 向 yarn 申请资源时,yarn 校验的是 xyz 的身份;
  • 由于 hiveserver2 没有提供一致机制将业务用户 xyz的 principal 和对应的 keytab 透传到 yarn, 所以 yarn 对 xyz 的用户认证失败,没有相应其资源请求,从而 spark driver 因获取不到 yarn资源无法成功启动,自然也就不会回连到spark driver的客户端即hiveserver2,所以才有相关报错:"Failed to create spark client for spark session xxx“,“Error while waiting for Remote Spark Driver to connect back to HiveServer2”等。

事实上,细心的小伙伴,能在 hiveserver2 的日志中,查看到 securityManager 验证用户身份的相关日志:

同样的,细心的小伙伴,能在 hiveserver2 的日志中,查看到 hive 启动 spark on yarn 集群的相关日志:

  1. 2021-09-02 14:19:10,067 INFO  org.apache.hive.spark.client.SparkClientImpl: [HiveServer2-Background-Pool: Thread-110]: Running client driver with argv: kinit hive/uf30-1@CDH.COM -k -t hive.keytab; /opt/cloudera/parcels/CDH-6.3.2-1 
  2. .cdh6.3.2.p0.1605554/lib/spark/bin/spark-submit --executor-cores 4 --executor-memory 6442450944b --proxy-user dap --jars /opt/cloudera/parcels/CDH-6.3.2-1.cdh6.3.2.p0.1605554/jars/hive-kryo-registrator-2.1.1-cdh6.3.2.jar --propert 
  3. ies-file /tmp/spark-submit.7174671910364719325.properties --class org.apache.hive.spark.client.RemoteDriver /opt/cloudera/parcels/CDH-6.3.2-1.cdh6.3.2.p0.1605554/jars/hive-exec-2.1.1-cdh6.3.2.jar --remote-host uf30-1 --remote-port 
  4.  39677 --remote-driver-conf hive.spark.client.future.timeout=60000 --remote-driver-conf hive.spark.client.connect.timeout=1000 --remote-driver-conf hive.spark.client.server.connect.timeout=90000 --remote-driver-conf hive.spark.cli 
  5. ent.channel.log.level=null --remote-driver-conf hive.spark.client.rpc.max.size=52428800 --remote-driver-conf hive.spark.client.rpc.threads=8 --remote-driver-conf hive.spark.client.secret.bits=256 --remote-driver-conf hive.spark.cl 
  6. ient.rpc.server.address=null --remote-driver-conf hive.spark.client.rpc.server.port=null 

5 问题解决

知道了问题的根本原因,问题的解决也就顺理成章了。 有两个解决办法:

  • 关闭集群的 kerberos 安全认证,此时向 yarn 申请资源时,yarn 不再需要验证用户的身份,hive sql 作业不管再底层用什么身份执行,都不会有用户身份认证问题;(当然,用户权限问题是另一回事);
  • 保留集群的 kerberos 安全认证,但关闭 hive的代理功能,即hive.server2.enable.doAs=false:此时 hive 可以使用各种认证方式(hive.server2.authentication= none/ldap/kerberos), 各个业务用户正常提交 HIVE SQL 作业给 HIVESERVER2 并可配置使用 MR/TEZ/SPARK 任一执行引擎,HIVESERVER2 经解析编译优化生成 MR/TEZ/SPARK任务后,会以 hive 用户身份跟 yarn/hdfs 进行交互和身份认证,由于集群已经配好了 HIVE 用户的相关配置(其实底层是在 hive-site.xml 中配置好了 hive 这个用户的 principal 和对应的keytab文件,所以 hive 用户跟 hdfs/yarn的交互和认证都没有问题),所以此时 hivesql 作业可以提交执行。

6 知识总结

 

  • hive 可以配置使用各种认证方式 (hive.server2.authentication= none/ldap/kerberos);
  • hive 可以配置使用各种执行引擎 (hive.execution.engine= mr/tez/spark);
  • hive 有代理功能,可以开启也可以关闭:hive.server2.enable.doAs=false/TRUE,"Setting this property to true will have HiveServer2 execute Hive operations as the user making the calls to it." (一些安全插件如 SENTRY/RANGER 要求关闭该功能);
  • 终端业务用户比如 xyz 提交给 HIVESERVER2 的 SQL作业,经过 HIVESERVER2 的解析编译和优化后,一般会生成 MR/TEZ/SPARK 任务(之所以说一般,是因为有的 SQL 是直接在HIVESERVER2中执行的,不会生成分布式的 MR/TEZ/SPARK 任务),这些 MR/TEZ/SPARK 任务最终访问底层的基础设施 HDFS 和 YARN 时,一样要经过这些基础设施 hdfs/yarn的 安全认证;
  • 当启用了 HIVE 的代理机制时(hive.server.enable.doAs=true),业务终端用户如 xyz 提交的 HIVE SQL 作业底层的 MR/TEZ/SPARK 任务访问 HDFS/YARN 时,HDFS/YARN 验证的是业务终端用户 xyz 的身份 (后续 HDFS/YARN 的权限校验,校验的也是 xyz 用户的权限);
  • 当没有启用 HIVE 的代理机制时(hive.server.enable.doAs=false),业务终端用户提交的 HIVE SQL 作业底层的 MR/TEZ/SPARK 任务访问 HDFS/YARN 时,需要验证的是 hiveserver2 服务对应的用户,即 hive 的身份 (后续 HDFS/YARN 的权限校验,校验的也是 hive 用户的权限);
  • 当我们说启用大数据集群的 kerberos 安全认证,一般是整个集群层面的各个服务,都启用 kerberos 安全认证:因为当底层的基础设施 hdfs/yarn 启用 kerberos 安全认证后,任何和 hdfs/yarn 交互的组件,都需要经过 kerberos 安全认证;
  • 发行版的大数据集群如 CDH 一般都已经配好了 HIVE 用户的相关 kerberos 安全配置,其实底层是在 hive-site.xml 中配置好了 hive 这个用户的 principal 和对应的keytab文件,所以 hive 用户跟 hdfs/yarn的交互和认证都没有问题;

 

责任编辑:武晓燕 来源: 明哥的IT随笔
相关推荐

2021-09-03 18:36:50

大数据

2013-07-30 11:23:34

SAP开启大数据城市之

2014-01-22 15:27:13

大数据

2014-05-09 17:26:54

数据化CRMCRM

2017-08-02 14:31:58

大数据集群数据存储

2017-01-11 16:57:51

大数据大数据集群监控

2016-01-20 12:07:49

阿里云云栖大会大数据

2012-11-08 10:09:57

大数据HIVE

2016-10-12 18:58:15

大数据PIGHive

2013-05-31 10:22:12

2010-05-11 17:50:51

Kerberos认证协

2016-05-11 15:02:31

大数据

2020-12-01 09:37:00

点链大数据中心

2021-04-15 21:56:14

大数据技术数据分析

2023-05-06 07:20:27

HiveDDL管理表

2015-04-24 11:20:15

Hadoop大数据架构大数据

2023-05-08 00:08:51

Hive机制场景

2023-05-06 07:15:59

Hive内置函数工具

2014-05-28 13:50:17

微软

2017-12-20 15:25:51

数据分析大数据企业
点赞
收藏

51CTO技术栈公众号