你的位置:首页 > 数据库

[数据库]Hive中使用Python实现Transform时遇到Broken pipe错误排查


Hive中有一表,列分隔符为冒号(:),有一列utime是Timestamp格式,需要转成Weekday存到新表。

利用Python写一个Pipeline的Transform,weekday.py的代码也很简单:
import sys
import datetime
for line in sys.stdin:
 line=line.strip()
 uid,mid,rating,utime=line.split(':')
 weekday=datetime.datetime.fromtimestamp(float(utime)).isoweekday()
 print '\t'.join([uid,mid,rating,str(weekday)])
 
HQL的查询也很简单:
select 
transform(uid,mid,rating,utime) 
using 'python weekday.py' as (uid,mid,rating,weekday) 
from rating
 
Stage-1结束后就报错!
 
排查过程:
1. Hive给出的日志,没有什么意义。Hive日志:
 INFO exec.Task: 2015-07-07 16:34:57,938 Stage-1 map = 0%,  reduce = 0%
INFO exec.Task: 2015-07-07 16:35:30,262 Stage-1 map = 100%,  reduce = 0%
ERROR exec.Task: Ended Job = job_1431587697935_0210 with errors
ERROR operation.Operation: Error running hive query:
org.apache.hive.service.cli.HiveSQLException: Error while processing statement: FAILED: Execution Error, return code 20001 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask. An error occurred while reading or writing to your custom script. It may have crashed with an error. 
 at org.apache.hive.service.cli.operation.Operation.toSQLException(Operation.java:315)
 at org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:156)
 at org.apache.hive.service.cli.operation.SQLOperation.access$100(SQLOperation.java:71)
 at org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:206)
 at java.security.AccessController.doPrivileged(Native Method)
 at javax.security.auth.Subject.doAs(Subject.java:415)
 at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1628)
 at org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:218)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
 at java.util.concurrent.FutureTask.run(FutureTask.java:262)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
 at java.lang.Thread.run(Thread.java:745)
 
 2. 不死心呀!开启Hive日志的Debug,再看看日志。
   因为我一直使用的是Beeline连接Hive,得到的日志跟1.一样,没有收获。后来我想想,要不用Hive CLI看一下,会不会有收获。终于得到点有意义的日志了:
Task with the most failures(4): 
-----
Task ID:
  task_1431587697935_0210_m_000000
-----
Diagnostic Messages for this Task:
Error: java.lang.RuntimeException: org.apache.hadoop.hive.ql.metadata.HiveException: Hive Runtime Error while processing row {"uid":11,"mid":2791,"rating":4,"utime":"978903186"}
at org.apache.hadoop.hive.ql.exec.mr.ExecMapper.map(ExecMapper.java:172)
at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:54)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:450)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:343)
at org.apache.hadoop.mapred.YarnChild$2.run(YarnChild.java:163)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:415)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1628)
at org.apache.hadoop.mapred.YarnChild.main(YarnChild.java:158)
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: Hive Runtime Error while processing row {"uid":11,"mid":2791,"rating":4,"utime":"978903186"}
at org.apache.hadoop.hive.ql.exec.MapOperator.process(MapOperator.java:518)
at org.apache.hadoop.hive.ql.exec.mr.ExecMapper.map(ExecMapper.java:163)
... 8 more
Caused by: org.apache.hadoop.hive.ql.metadata.HiveException: [Error 20001]: An error occurred while reading or writing to your custom script. It may have crashed with an error.
at org.apache.hadoop.hive.ql.exec.ScriptOperator.process(ScriptOperator.java:456)
at org.apache.hadoop.hive.ql.exec.Operator.forward(Operator.java:837)
at org.apache.hadoop.hive.ql.exec.SelectOperator.process(SelectOperator.java:88)
at org.apache.hadoop.hive.ql.exec.Operator.forward(Operator.java:837)
at org.apache.hadoop.hive.ql.exec.TableScanOperator.process(TableScanOperator.java:97)
at org.apache.hadoop.hive.ql.exec.MapOperator$MapOpCtx.forward(MapOperator.java:162)
at org.apache.hadoop.hive.ql.exec.MapOperator.process(MapOperator.java:508)

Caused by: java.io.IOException: Broken pipe
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:345)
at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.write(BufferedOutputStream.java:126)
at java.io.DataOutputStream.write(DataOutputStream.java:107)
at org.apache.hadoop.hive.ql.exec.TextRecordWriter.write(TextRecordWriter.java:53)
at org.apache.hadoop.hive.ql.exec.ScriptOperator.process(ScriptOperator.java:425)


3. 根据上步提示的那行可疑的数据,我怀疑有Bad Data,处理时出错。我单独将报错的行放到另一个表中去处理,又完全没有问题。好吧,继续。
 
4. 断续之前我需要搞清楚: java.io.IOException: Broken pipe是什么?
    写入端出现的时候,另一端却休息或退出了,因此造成没有及时取走管道中的数据,从而系统异常退出。在这里就是:当Streaming正在获取input数据,好给weekday.py处理的过程中,weekday.py异常终止了。等Streaming准备好数据回来后,却找不到weekday.py来接收数据,于是Broken pipe了。
 
5. 搞明白Broken pipe并给前面的错误信息,断定问题应该出在weekday.py上。接下来,既然是MapReduce出错,那就需要去看Yarn的Stderr.
     通过ResouceManager查看对应Application的Logs中的stderr,发现:
     Traceback (most recent call last):
     File "weekday_mapper.py", line 5, in <module>
    uid,mid,rating,utime=line.split(':')
    ValueError: need more than 1 value to unpack
 
6. 从Python的错误来看,推测有数据行的分隔符(:)有异常,导致split之后不能返回4个值(uid,mid,rating,utime)。用各种方法检查数据格式,一切正常。只好,处理脚本加上异常处理。
加上异常处理之后不报错了,但是Select输出0行数据
import sys
import datetime
for line in sys.stdin:
 try:
  line=line.strip()
  uid,mid,rating,utime=line.split(':')
  weekday=datetime.datetime.fromtimestamp(float(utime)).isoweekday()
  print '\t'.join([uid,mid,rating,str(weekday)])
 except Exception, ex:
  pass
 
7. 问题锁定到:脚本处理数据有问题。尝试直接从HDFS上直接抓取表的数据文件,再用脚本处理,是正常的。
hdfs dfs -cat /user/hive/warehouse/test.db/t/000000_0|python /tmp/weekday_mapper.py
最后,怀疑transform的输出格式是不是与定义表的格式不一样,查阅官方说明:

By default, columns will be transformed to STRING and delimited by TAB before feeding to the user script。

于是,将脚本中的 uid,mid,rating,utime=line.split(':')改成 uid,mid,rating,utime=line.split('\t')。再试一次,成功!

 

总结

  1. 排查这个问题,花了2天左右时间,不应该。写这个总结时,其实我的内心是崩溃的,心中有一万只小鹿。。。。

  2. 基础知识很重要,要在自己内心成体系,才能够用信手拈来。路漫漫兮!

  3. 有时凭借经验的“猜”,会很有帮助,有时却会“聪明反被聪明误"。所以要重视日志,并以之为操作重现的依据。





去浙江旅游最佳时间浙江旅游线路报价浙江旅游攻略大全浙江旅游路线推荐浙江自驾游攻略清远金子山杜鹃花好看吗?金子山杜鹃花盛花期? 金子山杜鹃花最佳观赏期?连山金子山杜鹃花什么时候最好看? 金子山杜鹃花开了吗?连山金子山杜鹃花什么时候开放? 清明小长假 不出津城也能游世界 2015春节森波拉酒店住宿免费泡温泉吗?森波拉温泉春节篝火晚会有什么表演? 过年到锦里沟品土家民俗 2015春节佛冈森波拉春节有什么活动?森波拉奇妙世界春节活动介绍? 2015天适樱花悠乐园花期多长?从化天适樱花悠乐园什么时间最好看? 花都香草世界有导游证免费吗?广州花都香草世界门票优惠政策? 花都香草世界门票团购多少钱?广州花都香草世界团体票怎么买? 花都香草世界网上订票?广州花都香草世界优惠票多少钱? 八里湖湿地 鸟儿栖息的纯净乐园 去香港买ipad怎么过关比较好? 哪里可以办香港购物打折卡VIP CARD? 八达通在哪里可以充值? 元旦节澳门哪里好玩?有什么活动? AQ12EA3R9BAJME Datasheet AQ12EA3R9BAJME Datasheet SQCA5A241FAJWE Datasheet SQCA5A241FAJWE Datasheet 08055C681KAT4A Datasheet 08055C681KAT4A Datasheet 阳泉市去香港旅游 阳泉市去香港旅游 阳泉市去香港旅游 运城香港旅游 运城香港旅游 运城香港旅游 舟山去香港游 舟山去香港游 舟山去香港游