加载中…
个人资料
微博
  • 博客等级：
  • 博客积分：
  • 博客访问：
  • 关注人气：
  • 获赠金笔：0支
  • 赠出金笔：0支
  • 荣誉徽章：
正文 字体大小：大 中 小

mapreduce作业假死分析

(2016-02-02 05:57:19)
标签：

hadoop

yarncontainer

hive作业假死

mapreduce

 分类： hadoop
 针对昨日凌晨的测试集群作业卡死现象进行了跟踪调查，原因是该作业在运行最后一个子作业时，产生的map: 30、reduce: 32；而现在集群可用内核仅有24个，资源都被map使用时，没有资源可以启动reduce程序对数据进行汇总，导致作业卡死现象发生，集群除资源可用量少外，集群没有发现其他错误信息；执行hivesql语句时hive会进行语法优化，每次进行优化后的语法是不一样的，所以同一条查询语句执行时map和reduce数量会不一样。
        下面是其中一台计算节点的日志，可以看出有8个container在循环执行，其他两台计算节点也是如此。
hive日志
2016-02-01 00:16:37,193 INFO  [Thread-36]: exec.Task (SessionState.java:printInfo(951)) - Hadoop job information for Stage-1: number of mappers: 30; number of reducers: 32

hadoop日志
2016-02-01 00:51:51,218 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 187953 for container-id container_1453269651912_3217_01_000028: 465.6 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:51,229 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 187917 for container-id container_1453269651912_3217_01_000025: 444.1 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:51,241 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 188405 for container-id container_1453269651912_3217_01_000050: 631.0 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:51,252 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 188181 for container-id container_1453269651912_3217_01_000038: 670.0 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:51,264 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 188347 for container-id container_1453269651912_3217_01_000048: 776.2 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:51,275 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 188259 for container-id container_1453269651912_3217_01_000044: 649.0 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:51,287 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 188450 for container-id container_1453269651912_3217_01_000051: 753.1 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:54,299 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 187991 for container-id container_1453269651912_3217_01_000032: 465.3 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:54,310 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 187953 for container-id container_1453269651912_3217_01_000028: 465.6 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used
2016-02-01 00:51:54,322 INFO org.apache.hadoop.yarn.server.nodemanager.containermanager.monitor.ContainersMonitorImpl: Memory usage of ProcessTree 187917 for container-id container_1453269651912_3217_01_000025: 444.1 MB of 3 GB physical memory used; 2.5 GB of 9 GB virtual memory used

        下面是其他大作业计算超过集群资源时，卡死的例子，结果都是被杀死后重跑后才可以
1：Hadoop job information for Stage-1: number of mappers: 22; number of reducers: 24
2016-01-27 22:56:19,095 Stage-1 map = 0%,  reduce = 0%
2016-01-27 22:56:31,628 Stage-1 map = 5%,  reduce = 0%, Cumulative CPU 15.25 sec
2016-01-27 22:56:36,906 Stage-1 map = 10%,  reduce = 0%, Cumulative CPU 33.51 sec
2016-01-27 22:56:39,011 Stage-1 map = 11%,  reduce = 0%, Cumulative CPU 39.82 sec
2016-01-27 22:56:41,083 Stage-1 map = 15%,  reduce = 0%, Cumulative CPU 49.55 sec
2016-01-27 22:56:42,158 Stage-1 map = 20%,  reduce = 0%, Cumulative CPU 59.5 sec
2016-01-27 22:56:45,276 Stage-1 map = 21%,  reduce = 0%, Cumulative CPU 65.56 sec
2016-01-27 22:56:46,327 Stage-1 map = 22%,  reduce = 0%, Cumulative CPU 76.38 sec
2016-01-27 22:56:47,378 Stage-1 map = 23%,  reduce = 0%, Cumulative CPU 84.13 sec
2016-01-27 22:56:50,521 Stage-1 map = 24%,  reduce = 0%, Cumulative CPU 96.4 sec
2016-01-27 22:56:52,629 Stage-1 map = 25%,  reduce = 0%, Cumulative CPU 106.55 sec
2016-01-27 22:56:55,787 Stage-1 map = 26%,  reduce = 0%, Cumulative CPU 127.98 sec
2016-01-27 22:56:56,840 Stage-1 map = 28%,  reduce = 0%, Cumulative CPU 135.97 sec
2016-01-27 22:56:58,943 Stage-1 map = 29%,  reduce = 0%, Cumulative CPU 142.21 sec
2016-01-27 22:56:59,995 Stage-1 map = 30%,  reduce = 0%, Cumulative CPU 148.4 sec
2016-01-27 22:57:01,037 Stage-1 map = 31%,  reduce = 0%, Cumulative CPU 151.62 sec
2016-01-27 22:57:02,083 Stage-1 map = 33%,  reduce = 1%, Cumulative CPU 158.72 sec
2016-01-27 22:57:05,268 Stage-1 map = 36%,  reduce = 1%, Cumulative CPU 175.49 sec
2016-01-27 22:57:08,420 Stage-1 map = 38%,  reduce = 1%, Cumulative CPU 196.36 sec
2016-01-27 22:57:09,467 Stage-1 map = 43%,  reduce = 1%, Cumulative CPU 206.1 sec
2016-01-27 22:57:11,563 Stage-1 map = 44%,  reduce = 1%, Cumulative CPU 212.38 sec
2016-01-27 22:57:12,620 Stage-1 map = 47%,  reduce = 1%, Cumulative CPU 216.78 sec
2016-01-27 22:57:13,667 Stage-1 map = 47%,  reduce = 2%, Cumulative CPU 217.68 sec
2016-01-27 22:57:17,878 Stage-1 map = 48%,  reduce = 2%, Cumulative CPU 232.2 sec
2016-01-27 22:57:21,064 Stage-1 map = 48%,  reduce = 3%, Cumulative CPU 248.29 sec
2016-01-27 22:57:22,129 Stage-1 map = 50%,  reduce = 3%, Cumulative CPU 250.47 sec
2016-01-27 22:57:23,183 Stage-1 map = 51%,  reduce = 3%, Cumulative CPU 277.11 sec
2016-01-27 22:57:24,238 Stage-1 map = 51%,  reduce = 4%, Cumulative CPU 290.18 sec
2016-01-27 22:57:26,330 Stage-1 map = 54%,  reduce = 4%, Cumulative CPU 303.59 sec
2016-01-27 22:57:27,379 Stage-1 map = 55%,  reduce = 4%, Cumulative CPU 310.37 sec
2016-01-27 22:57:29,474 Stage-1 map = 57%,  reduce = 4%, Cumulative CPU 329.29 sec
2016-01-27 22:57:32,616 Stage-1 map = 59%,  reduce = 5%, Cumulative CPU 349.54 sec
2016-01-27 22:57:35,758 Stage-1 map = 63%,  reduce = 5%, Cumulative CPU 369.58 sec
2016-01-27 22:57:37,849 Stage-1 map = 63%,  reduce = 6%, Cumulative CPU 373.84 sec
2016-01-27 22:57:38,892 Stage-1 map = 65%,  reduce = 6%, Cumulative CPU 390.44 sec
2016-01-27 22:57:39,921 Stage-1 map = 68%,  reduce = 6%, Cumulative CPU 394.45 sec
2016-01-27 22:57:42,009 Stage-1 map = 69%,  reduce = 6%, Cumulative CPU 408.31 sec
2016-01-27 22:57:44,102 Stage-1 map = 71%,  reduce = 7%, Cumulative CPU 418.69 sec
2016-01-27 22:57:46,195 Stage-1 map = 73%,  reduce = 7%, Cumulative CPU 424.29 sec
2016-01-27 22:57:48,297 Stage-1 map = 74%,  reduce = 7%, Cumulative CPU 436.89 sec
2016-01-27 22:57:49,343 Stage-1 map = 77%,  reduce = 7%, Cumulative CPU 441.98 sec
2016-01-27 22:57:51,439 Stage-1 map = 77%,  reduce = 8%, Cumulative CPU 444.83 sec
2016-01-27 22:57:52,484 Stage-1 map = 77%,  reduce = 9%, Cumulative CPU 448.48 sec
2016-01-27 22:59:12,674 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 491.55 sec
2016-01-27 23:00:12,911 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 506.41 sec
2016-01-27 23:01:13,035 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 518.6 sec
2016-01-27 23:02:13,110 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 526.3 sec
2016-01-27 23:03:13,177 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 533.45 sec
2016-01-27 23:04:13,196 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 539.68 sec
2016-01-27 23:05:13,199 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 545.76 sec
2016-01-27 23:06:13,211 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 552.55 sec
2016-01-27 23:07:14,215 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 558.5 sec
2016-01-27 23:08:15,172 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 564.72 sec
2016-01-27 23:09:16,133 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 571.42 sec
2016-01-27 23:10:17,087 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 577.91 sec
2016-01-27 23:11:18,036 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 584.09 sec
2016-01-27 23:12:18,968 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 590.1 sec
2016-01-27 23:13:19,896 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 596.24 sec
2016-01-27 23:14:20,826 Stage-1 map = 82%,  reduce = 17%, Cumulative CPU 602.3 sec
2016-01-27 23:14:36,320 Stage-1 map = 82%,  reduce = 0%, Cumulative CPU 435.11 sec
2016-01-27 23:14:41,594 Stage-1 map = 0%,  reduce = 0%
MapReduce Total cumulative CPU time: 7 minutes 15 seconds 110 msec
Ended Job = job_1453269651912_1899 with errors
Error during job, obtaining debugging information...
FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask
MapReduce Jobs Launched:
Stage-Stage-1: Map: 22  Reduce: 24   Cumulative CPU: 435.11 sec   HDFS Read: 0 HDFS Write: 0 FAIL
Total MapReduce CPU Time Spent: 7 minutes 15 seconds 110 msec


2：Hadoop job information for Stage-1: number of mappers: 22; number of reducers: 24
2016-01-27 23:16:22,949 Stage-1 map = 0%,  reduce = 0%
2016-01-27 23:16:33,454 Stage-1 map = 5%,  reduce = 0%, Cumulative CPU 5.7 sec
2016-01-27 23:16:34,534 Stage-1 map = 19%,  reduce = 0%, Cumulative CPU 43.46 sec
2016-01-27 23:16:37,691 Stage-1 map = 20%,  reduce = 0%, Cumulative CPU 57.99 sec
2016-01-27 23:17:59,489 Stage-1 map = 77%,  reduce = 14%, Cumulative CPU 412.35 sec
2016-01-27 23:18:01,575 Stage-1 map = 77%,  reduce = 15%, Cumulative CPU 413.76 sec
2016-01-27 23:18:09,912 Stage-1 map = 77%,  reduce = 16%, Cumulative CPU 417.33 sec
2016-01-27 23:19:10,265 Stage-1 map = 77%,  reduce = 16%, Cumulative CPU 436.23 sec
2016-01-27 23:20:10,506 Stage-1 map = 77%,  reduce = 16%, Cumulative CPU 452.25 sec
2016-01-27 23:21:10,637 Stage-1 map = 77%,  reduce = 16%, Cumulative CPU 464.13 sec
2016-01-27 23:22:10,708 Stage-1 map = 77%,  reduce = 16%, Cumulative CPU 471.3 sec
2016-01-27 23:23:10,774 Stage-1 map = 77%,  reduce = 16%, Cumulative CPU 478.89 sec
2016-01-27 23:23:38,737 Stage-1 map = 77%,  reduce = 14%, Cumulative CPU 468.65 sec
2016-01-27 23:23:39,774 Stage-1 map = 77%,  reduce = 0%, Cumulative CPU 382.49 sec
2016-01-27 23:23:44,030 Stage-1 map = 0%,  reduce = 0%
MapReduce Total cumulative CPU time: 6 minutes 22 seconds 490 msec
Ended Job = job_1453269651912_1915 with errors
Error during job, obtaining debugging information...
FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask

针对上述作业卡死现象，可以通过对集群扩容和语法优化来避免错误的发生，目前集群扩容正在规划中，可以对复杂的sql进行分拆加入临时表来避免计算资源堵塞！

喜欢

0

阅读┊ 收藏 ┊ 喜欢▼ ┊打印┊举报/Report
  

新浪BLOG意见反馈留言板　欢迎批评指正

新浪简介 | About Sina | 广告服务 | 联系我们 | 招聘信息 | 网站律师 | SINA English | 产品答疑

Copyright © 1996 - 2022 SINA Corporation, All Rights Reserved

新浪公司 版权所有