如何找到Hive提交的SQL相对应的Yarn程序的applicationId

最近的工作是利用hive做数据仓库的etl转换，大致方式是将etl转换逻辑写在一个hsql文件中，脚本当中都是简单的sql语句，不包含判断、循环等存储过程中才有的写法，仅仅支持一些简单的变量替换，比如当前账期等。然后通过一个通用的shell脚本来执行hsql文件。该脚本是主要是调用了hive -f <hsql文件>来执行hsql文件中的sql语句的，当然hive命令会通过--hivevar选项定义变量将当前账期等数值传进去供sql使用。

简单说下环境信息，目前使用的大数据平台版本是hdp 3.1.0.0-78，hive版本是3.1.0，而tez版本是0.9.1。hive 3.x系列的新特性主要包括：

1. 执行引擎不再支持mr，取而代之的是tez或者spark（在hdp平台默认是tez）；

2. 不再支持胖客户端hive cli，被beeline取代（目前通过hive命令执行sql实际还是调用的beeline去连接hiveserver2服务）；

3. 默认建表支持acid语义；

4. 支持llap，即live long and process，相当于内存计算，极大地优化了性能（该特性实际从hive 2.x开始支持）；

言归正传，回到本文的主题，比如hive在运行过程中报错了，我们需要在yarn上找到对应的application的日志以便定位问题，前提是需要知道yarn程序对应的applicationid，但是beeline的输出信息中是没有applicationid的，那么如何找到hive提交的sql相对应的yarn程序的applicationid呢？主要有以下几个步骤：

1. 我们通过shell脚本提交hsql文件时实际是通过beeline向hiveserver2服务提交hsql文件中的sql语句，我们的shell脚本会将beeline的屏幕输出信息同时重定向到日志文件中，这个就是我们的第一个步骤的日志。我们找到这个日志文件，在其中搜索关键字"completed executing command"，可以得到queryid，其中每个sql语句对应1个queryid，因为我们的hsql脚本中有4个sql语句，所以搜索出来的信息如下：

info : completed executing command(queryid=hive_20200502095437_1e9bf52d-e590-4519-a6e1-9e2e4ae91158); time taken: 0.755 seconds
info : completed executing command(queryid=hive_20200502095816_888a7dba-4403-439d-a3a7-f6cdc280c18a); time taken: 52.929 seconds
info : completed executing command(queryid=hive_20200502100121_5752f019-a6e2-463c-b413-a80bbe518a5c); time taken: 52.66 seconds
info : completed executing command(queryid=hive_20200502100428_9d4b8955-b84c-40be-a605-9ce19b4b7773); time taken: 26.463 seconds

2. 找到对应的hiveserver2服务在哪台机器上。由于beeline是通过zookeeper随机连接一个hiveserver2服务，所以从上一步的日志中可以看到连接的是哪台机器上的hiveserver2服务。然后登录到该台主机，通过netstat和ps命令找到对应的hiveserver2进程，从ps命令输出的进程信息对应的命令行中，我们可以找到下面的参数。

-dhive.log.dir=/var/log/hive -dhive.log.file=hiveserver2.log

上面的参数说明了hiveserver2服务对应的日志名称和路径。这样我们就可以找到hiveserver2服务对应的日志，这是我们第二个步骤的日志。从这个日志里通过搜索关键字"callerid=<queryid>"，<queryid>用上一步得到的真实的queryid替换（比如搜索"callerid=hive_20200502095816_888a7dba-4403-439d-a3a7-f6cdc280c18a"）。我们将上面的4个queryid逐一用前述的关键字搜索，得到信息如下：

2020-05-02t10:00:30,440 info [thread-536694]: client.tezclient (:()) - submitting dag to tezsession, sessionname=hive-315802e2-f6e4-499d-a707-4d3057180abd, applicationid=application_1588062934554_53656, dagname=create temporary table ngdwt.rpt_to_etc_...t (stage-1), callercontext={ context=hive, callertype=hive_query_id, callerid=hive_20200502095816_888a7dba-4403-439d-a3a7-f6cdc280c18a }

2020-05-02t10:00:57,229 info [thread-536729]: client.tezclient (:()) - submitting dag to tezsession, sessionname=hive-315802e2-f6e4-499d-a707-4d3057180abd, applicationid=application_1588062934554_53656, dagname=create temporary table ngdwt.rpt_to_etc_...t (stage-4), callercontext={ context=hive, callertype=hive_query_id, callerid=hive_20200502095816_888a7dba-4403-439d-a3a7-f6cdc280c18a }

2020-05-02t10:03:22,043 info [thread-537002]: client.tezclient (:()) - submitting dag to tezsession, sessionname=hive-315802e2-f6e4-499d-a707-4d3057180abd, applicationid=application_1588062934554_53656, dagname=create temporary tabl...ov_in,a.statis_date (stage-1), callercontext={ context=hive, callertype=hive_query_id, callerid=hive_20200502100121_5752f019-a6e2-463c-b413-a80bbe518a5c }

2020-05-02t10:07:39,627 info [thread-537495]: client.tezclient (:()) - submitting dag to tezsession, sessionname=hive-315802e2-f6e4-499d-a707-4d3057180abd, applicationid=application_1588062934554_53656, dagname=insert into ngdwt.rpt_to_etc_rece_d(re...t (stage-1), callercontext={ context=hive, callertype=hive_query_id, callerid=hive_20200502100428_9d4b8955-b84c-40be-a605-9ce19b4b7773 }

可以看到第1个queryid用关键字"callerid=<queryid>"去搜索没有搜到信息，因为对应的第一个sql语句是ddl语句，不会向yarn提交程序（但是仅用"<queryid>"去搜索还是能搜到信息），后面第二个queryid搜索出来有2行，其他queryid只有1行。

可以看到这些queryid(hive命令输出信息)或者callerid(hiveserver2.log日志信息)对应的hive session和yarn application是同一个：
sessionname=hive-315802e2-f6e4-499d-a707-4d3057180abd
applicationid=application_1588062934554_53656

也就是说，同一个hsql文件中的不同sql语句对应的是同一个hive session以及同一个yarn application.

来看下yarn web管理页面中该application的截图。

 

 

可以看到上面页面中的name跟hiveserver2.log中的sessionname一致，application tags跟hiveserver2.log中的callerid（或者hive命令屏幕输出信息中的queryid）一致。

而yarn ui2中的程序信息如下：

  

3. 找到了applicationid就比较好办了，可以通过下面的命令将yarn日志从hdfs下载到本地（待yarn程序执行完毕）
yarn logs -applicationid application_1588062934554_53656 > application_1588062934554_53656.log

然后可以对application_1588062934554_53656.log做进一步的分析。
比如用关键字"container: container_"搜索并去重排序后得到9个container的信息：
container: container_e46_1588062934554_53656_01_000001 on hadoop19_45454_1588385301489
container: container_e46_1588062934554_53656_01_000002 on hadoop31_45454_1588385300882
container: container_e46_1588062934554_53656_01_000003 on hadoop40_45454_1588385301059
container: container_e46_1588062934554_53656_01_000004 on hadoop27_45454_1588385300739
container: container_e46_1588062934554_53656_01_000006 on hadoop36_45454_1588385301268
container: container_e46_1588062934554_53656_01_000007 on hadoop57_45454_1588385301076
container: container_e46_1588062934554_53656_01_000008 on hadoop22_45454_1588385301501
container: container_e46_1588062934554_53656_01_000009 on hadoop31_45454_1588385300882
container: container_e46_1588062934554_53656_01_000010 on hadoop21_45454_1588385301473

上面是该application对用的所有container.

 

或者用关键字"assigning container to task:"搜索得到任务分配信息，其中container_e46_1588062934554_53656_01_000001因为是applicationmaster没有任务分配信息，其他8个container都有任务分配信息，其中container_e46_1588062934554_53656_01_000008和container_e46_1588062934554_53656_01_000009有2条记录，但attempt不同，表示这2个container里的任务之前有失败的，分别进行了2次尝试。为了简洁起见，这里仅列出搜索出来的第一条记录：

2020-05-01 22:00:40,603 [info] [delayedcontainermanager] |rm.yarntaskschedulerservice|: assigning container to task: containerid=container_e46_1588062934554_53656_01_000002, task=attempt_1588062934554_53656_1_00_000000_0, containerhost=hadoop31:45454, containerpriority= 11, containerresources=<memory:12288, vcores:1>, localitymatchtype=racklocal, matchedlocation=/default-rack, honorlocalityflags=false, reusedcontainer=false, delayedcontainers=3

因为现在的hive的执行引擎不再是mr，而是改成了tez，目前我对tez并不太熟悉，只是理解它为mr的升级版，在原来的map/reduce操作上增加了dag，不同job之间的数据传递不必写到hdfs，而是类似数据流的方式，减少了中间环节，提升了效率。对于一个tez程序，类似于mr程序的mrappmaster和yarnchild进程，它会产生dagappmaster和tezchild进程，前者是master负责管理整个程序以及申请资源，后者是slave，负责执行具体的计算任务。