hive：beeline提交SQL报错 return code 2

1.现象

beeline连hive跑任务，报错：

Error: Error while processing statement: FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask (state=08S01,code=2)

 除此以外没有其他详细的错误信息。如果直接到 org.apache.hadoop.hive.ql.exec.mr.MapRedTask 这个类里，是找不出是哪报错的。这条错误信息是 org.apache.hadoop.hive.ql.Executor 类的 getErrorMsgAndDetail 方法抛出的。

 

2.排查

详细源码有兴趣再看，先直接到yarn查看这个任务的详细信息。

 发现这个任务的reduce几乎全挂了。

回头看任务打印的信息，reduce确实是在不断的重试，最后直接飙到100%，但是没有报错。

INFO  : 2021-01-21 13:51:04,196 Stage-1 map = 100%,  reduce = 0%, Cumulative CPU 143608.39 sec
INFO  : 2021-01-21 13:51:46,456 Stage-1 map = 100%,  reduce = 4%, Cumulative CPU 144225.43 sec
INFO  : 2021-01-21 13:51:47,529 Stage-1 map = 100%,  reduce = 5%, Cumulative CPU 144284.17 sec
INFO  : 2021-01-21 13:51:48,581 Stage-1 map = 100%,  reduce = 13%, Cumulative CPU 145581.0 sec
INFO  : 2021-01-21 13:51:49,636 Stage-1 map = 100%,  reduce = 21%, Cumulative CPU 146876.04 sec
INFO  : 2021-01-21 13:51:50,687 Stage-1 map = 100%,  reduce = 31%, Cumulative CPU 148287.36 sec
INFO  : 2021-01-21 13:51:51,753 Stage-1 map = 100%,  reduce = 34%, Cumulative CPU 148734.37 sec
INFO  : 2021-01-21 13:51:52,810 Stage-1 map = 100%,  reduce = 36%, Cumulative CPU 149005.06 sec
INFO  : 2021-01-21 13:52:06,591 Stage-1 map = 100%,  reduce = 37%, Cumulative CPU 149745.38 sec
INFO  : 2021-01-21 13:52:07,663 Stage-1 map = 100%,  reduce = 38%, Cumulative CPU 150181.84 sec
INFO  : 2021-01-21 13:52:10,835 Stage-1 map = 100%,  reduce = 39%, Cumulative CPU 150991.66 sec
INFO  : 2021-01-21 13:52:24,520 Stage-1 map = 100%,  reduce = 40%, Cumulative CPU 151944.43 sec
INFO  : 2021-01-21 13:52:26,618 Stage-1 map = 100%,  reduce = 41%, Cumulative CPU 153001.41 sec
INFO  : 2021-01-21 13:52:28,712 Stage-1 map = 100%,  reduce = 42%, Cumulative CPU 153425.37 sec
INFO  : 2021-01-21 13:52:44,461 Stage-1 map = 100%,  reduce = 43%, Cumulative CPU 155612.28 sec
INFO  : 2021-01-21 13:52:46,553 Stage-1 map = 100%,  reduce = 44%, Cumulative CPU 156468.83 sec
。。。

。。。

。。。
180157.1 sec
INFO  : 2021-01-21 14:10:40,054 Stage-1 map = 100%,  reduce = 20%, Cumulative CPU 178909.9 sec
INFO  : 2021-01-21 14:10:42,156 Stage-1 map = 100%,  reduce = 18%, Cumulative CPU 175819.87 sec
INFO  : 2021-01-21 14:10:44,243 Stage-1 map = 100%,  reduce = 17%, Cumulative CPU 174034.12 sec
INFO  : 2021-01-21 14:10:47,405 Stage-1 map = 100%,  reduce = 16%, Cumulative CPU 173376.69 sec
INFO  : 2021-01-21 14:10:48,456 Stage-1 map = 100%,  reduce = 15%, Cumulative CPU 172579.69 sec
INFO  : 2021-01-21 14:10:53,720 Stage-1 map = 100%,  reduce = 14%, Cumulative CPU 171751.52 sec
INFO  : 2021-01-21 14:10:54,759 Stage-1 map = 100%,  reduce = 13%, Cumulative CPU 170671.51 sec
INFO  : 2021-01-21 14:10:57,952 Stage-1 map = 100%,  reduce = 12%, Cumulative CPU 169015.45 sec
INFO  : 2021-01-21 14:11:04,263 Stage-1 map = 100%,  reduce = 11%, Cumulative CPU 167255.97 sec
INFO  : 2021-01-21 14:11:09,589 Stage-1 map = 100%,  reduce = 10%, Cumulative CPU 165010.97 sec
INFO  : 2021-01-21 14:11:11,697 Stage-1 map = 100%,  reduce = 9%, Cumulative CPU 162740.64 sec
INFO  : 2021-01-21 14:11:22,232 Stage-1 map = 100%,  reduce = 10%, Cumulative CPU 162794.6 sec
INFO  : 2021-01-21 14:11:23,291 Stage-1 map = 100%,  reduce = 11%, Cumulative CPU 162912.56 sec
INFO  : 2021-01-21 14:11:25,399 Stage-1 map = 100%,  reduce = 12%, Cumulative CPU 163204.77 sec
INFO  : 2021-01-21 14:11:26,448 Stage-1 map = 100%,  reduce = 13%, Cumulative CPU 163328.94 sec
INFO  : 2021-01-21 14:11:27,517 Stage-1 map = 100%,  reduce = 14%, Cumulative CPU 163391.05 sec
INFO  : 2021-01-21 14:11:29,649 Stage-1 map = 100%,  reduce = 15%, Cumulative CPU 163620.92 sec
INFO  : 2021-01-21 14:11:30,705 Stage-1 map = 100%,  reduce = 17%, Cumulative CPU 163866.97 sec
INFO  : 2021-01-21 14:11:32,802 Stage-1 map = 100%,  reduce = 18%, Cumulative CPU 164038.57 sec
INFO  : 2021-01-21 14:11:33,877 Stage-1 map = 100%,  reduce = 19%, Cumulative CPU 164206.99 sec
INFO  : 2021-01-21 14:11:37,064 Stage-1 map = 100%,  reduce = 20%, Cumulative CPU 163467.7 sec
INFO  : 2021-01-21 14:11:41,349 Stage-1 map = 100%,  reduce = 21%, Cumulative CPU 163691.52 sec
INFO  : 2021-01-21 14:11:47,689 Stage-1 map = 100%,  reduce = 22%, Cumulative CPU 164062.8 sec
INFO  : 2021-01-21 14:11:52,053 Stage-1 map = 100%,  reduce = 23%, Cumulative CPU 165875.34 sec
INFO  : 2021-01-21 14:11:55,229 Stage-1 map = 100%,  reduce = 24%, Cumulative CPU 168102.94 sec
INFO  : 2021-01-21 14:11:56,277 Stage-1 map = 100%,  reduce = 27%, Cumulative CPU 170153.34 sec
INFO  : 2021-01-21 14:11:57,340 Stage-1 map = 100%,  reduce = 29%, Cumulative CPU 170347.48 sec
INFO  : 2021-01-21 14:11:58,411 Stage-1 map = 100%,  reduce = 30%, Cumulative CPU 170555.28 sec
INFO  : 2021-01-21 14:12:00,508 Stage-1 map = 100%,  reduce = 31%, Cumulative CPU 171063.12 sec
INFO  : 2021-01-21 14:12:01,574 Stage-1 map = 100%,  reduce = 34%, Cumulative CPU 171652.04 sec
INFO  : 2021-01-21 14:12:02,627 Stage-1 map = 100%,  reduce = 35%, Cumulative CPU 174515.25 sec
INFO  : 2021-01-21 14:12:04,725 Stage-1 map = 100%,  reduce = 37%, Cumulative CPU 175999.14 sec
INFO  : 2021-01-21 14:12:05,797 Stage-1 map = 100%,  reduce = 38%, Cumulative CPU 176365.38 sec
INFO  : 2021-01-21 14:12:07,929 Stage-1 map = 100%,  reduce = 39%, Cumulative CPU 176675.09 sec
INFO  : 2021-01-21 14:12:10,055 Stage-1 map = 100%,  reduce = 40%, Cumulative CPU 176969.29 sec
INFO  : 2021-01-21 14:12:11,104 Stage-1 map = 100%,  reduce = 41%, Cumulative CPU 177104.86 sec
INFO  : 2021-01-21 14:12:16,384 Stage-1 map = 100%,  reduce = 42%, Cumulative CPU 177919.42 sec
INFO  : 2021-01-21 14:12:21,705 Stage-1 map = 100%,  reduce = 43%, Cumulative CPU 179549.72 sec
INFO  : 2021-01-21 14:12:37,601 Stage-1 map = 100%,  reduce = 44%, Cumulative CPU 176633.95 sec
INFO  : 2021-01-21 14:12:39,715 Stage-1 map = 100%,  reduce = 43%, Cumulative CPU 176851.47 sec
INFO  : 2021-01-21 14:12:47,026 Stage-1 map = 100%,  reduce = 42%, Cumulative CPU 175622.34 sec
INFO  : 2021-01-21 14:12:58,631 Stage-1 map = 100%,  reduce = 41%, Cumulative CPU 176378.28 sec
INFO  : 2021-01-21 14:12:59,674 Stage-1 map = 100%,  reduce = 42%, Cumulative CPU 176432.13 sec
INFO  : 2021-01-21 14:13:01,807 Stage-1 map = 100%,  reduce = 41%, Cumulative CPU 176927.69 sec
INFO  : 2021-01-21 14:13:18,610 Stage-1 map = 100%,  reduce = 40%, Cumulative CPU 184856.44 sec
INFO  : 2021-01-21 14:13:20,690 Stage-1 map = 100%,  reduce = 100%, Cumulative CPU 148453.75 sec
INFO  : MapReduce Total cumulative CPU time: 1 days 17 hours 14 minutes 13 seconds 750 msec
ERROR : Ended Job = job_1595840492316_5848409 with errors
ERROR : FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask
INFO  : MapReduce Jobs Launched: 
INFO  : Stage-Stage-1: Map: 3053  Reduce: 200   Cumulative CPU: 148453.75 sec   HDFS Read: 142812118788 HDFS Write: 688949370 HDFS EC Read: 0 FAIL
INFO  : Total MapReduce CPU Time Spent: 1 days 17 hours 14 minutes 13 seconds 750 msec
INFO  : Completed executing command(queryId=hive_20210121132753_99b12ea2-6be3-44fc-be14-543cbed110d5); Time taken: 2745.792 seconds
Error: Error while processing statement: FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask (state=08S01,code=2)

查看失败的reduce的报错信息，原因就明了了：

Error: Java heap space

[2021-01-21 14:01:38.269]Container [pid=717259,containerID=container_e05_1595840492316_5848409_01_003253] is running 6373376B beyond the 'PHYSICAL' memory limit. Current usage: 1.5 GB of 1.5 GB physical memory used; 3.1 GB of 3.1 GB virtual memory used. Killing container. Dump of the process-tree for container_e05_1595840492316_5848409_01_003253 : |- PID PPID PGRPID SESSID CMD_NAME USER_MODE_TIME(MILLIS) SYSTEM_TIME(MILLIS) VMEM_USAGE(BYTES) RSSMEM_USAGE(PAGES) FULL_CMD_LINE |- 717370 717259 717259 717259 (java) 57806 1729 3301412864 394479 21-01-21 14:01:38.298]Container exited with a non-zero exit code 143.

Error: GC overhead limit exceeded

所有失败的reduce无非这三种报错。结论都是：内存不够用了。

 

3. 解决

解决办法：提高reduce内存，具体参数视情况而定

set mapreduce.reduce.memory.mb=3000;
set mapreduce.reduce.java.opts=-Djava.net.preferIPv4Stack=true -Xmx2415919104;