草庐IT

Hadoop运维记录系列(六)

Slaytanic 2023-03-28 原文
这两天有业务部门反馈,总有hive跑某天的log失败。看了一下log,虽然各种报错不一样,但基本都是OOM,追了一下午,终于追出来原因了,特此记录一下。


这个问题很诡异,map阶段oom,按说map的时候一个map对应一个数据块,最大也就占用128M内存,怎么会溢出呢,通常都应该是reduce溢出才对。先看看各个hadoop节点的tasktracker报的错误log。

节点一

2013-05-08 20:59:06,467 FATAL org.apache.hadoop.mapred.Child: Error running child : java.lang.OutOfMemoryError: Java heap space

at java.nio.HeapByteBuffer.<init>(HeapByteBuffer.java:39)

at java.nio.ByteBuffer.allocate(ByteBuffer.java:312)

at sun.nio.cs.StreamDecoder.<init>(StreamDecoder.java:231)

at sun.nio.cs.StreamDecoder.<init>(StreamDecoder.java:211)

at sun.nio.cs.StreamDecoder.forInputStreamReader(StreamDecoder.java:50)

at java.io.InputStreamReader.<init>(InputStreamReader.java:57)

at org.apache.hadoop.util.Shell.runCommand(Shell.java:211)

at org.apache.hadoop.util.Shell.run(Shell.java:182)

at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:375)

at org.apache.hadoop.util.Shell.execCommand(Shell.java:461)

at org.apache.hadoop.util.Shell.execCommand(Shell.java:444)

at org.apache.hadoop.fs.FileUtil.execCommand(FileUtil.java:710)

at org.apache.hadoop.fs.RawLocalFileSystem$RawLocalFileStatus.loadPermissionInfo(RawLocalFileSystem.java:443)

at org.apache.hadoop.fs.RawLocalFileSystem$RawLocalFileStatus.getOwner(RawLocalFileSystem.java:426)

at org.apache.hadoop.mapred.TaskLog.obtainLogDirOwner(TaskLog.java:267)

at org.apache.hadoop.mapred.TaskLogsTruncater.truncateLogs(TaskLogsTruncater.java:124)

at org.apache.hadoop.mapred.Child$4.run(Child.java:260)

at java.security.AccessController.doPrivileged(Native Method)

at javax.security.auth.Subject.doAs(Subject.java:396)

at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1121)

at org.apache.hadoop.mapred.Child.main(Child.java:249)


节点二

2013-05-08 20:56:37,012 INFO org.apache.hadoop.mapred.Task: Communication exception: java.lang.OutOfMemoryError: Java heap space

at java.io.BufferedReader.<init>(BufferedReader.java:80)

at java.io.BufferedReader.<init>(BufferedReader.java:91)

at org.apache.hadoop.util.ProcfsBasedProcessTree.constructProcessInfo(ProcfsBasedProcessTree.java:396)

at org.apache.hadoop.util.ProcfsBasedProcessTree.getProcessTree(ProcfsBasedProcessTree.java:151)

at org.apache.hadoop.util.LinuxResourceCalculatorPlugin.getProcResourceValues(LinuxResourceCalculatorPlugin.java:401)

at org.apache.hadoop.mapred.Task.updateResourceCounters(Task.java:808)

at org.apache.hadoop.mapred.Task.updateCounters(Task.java:830)

at org.apache.hadoop.mapred.Task.access$600(Task.java:66)

at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:666)

at java.lang.Thread.run(Thread.java:662)


节点三

2013-05-08 21:02:26,489 FATAL org.apache.hadoop.mapred.Child: Error running child : java.lang.OutOfMemoryError: Java heap space

at com.sun.org.apache.xerces.internal.xni.XMLString.toString(XMLString.java:185)

at com.sun.org.apache.xerces.internal.parsers.AbstractDOMParser.characters(AbstractDOMParser.java:1185)

at com.sun.org.apache.xerces.internal.xinclude.XIncludeHandler.characters(XIncludeHandler.java:1085)

at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:464)

at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:808)

at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:737)

at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:119)

at com.sun.org.apache.xerces.internal.parsers.DOMParser.parse(DOMParser.java:232)

at com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderImpl.parse(DocumentBuilderImpl.java:284)

at javax.xml.parsers.DocumentBuilder.parse(DocumentBuilder.java:180)

at org.apache.hadoop.conf.Configuration.loadResource(Configuration.java:1168)

at org.apache.hadoop.conf.Configuration.loadResources(Configuration.java:1119)

at org.apache.hadoop.conf.Configuration.getProps(Configuration.java:1063)

at org.apache.hadoop.conf.Configuration.get(Configuration.java:416)

at org.apache.hadoop.conf.Configuration.getLong(Configuration.java:521)

at org.apache.hadoop.io.nativeio.NativeIO.ensureInitialized(NativeIO.java:120)

at org.apache.hadoop.io.nativeio.NativeIO.getOwner(NativeIO.java:103)

at org.apache.hadoop.io.SecureIOUtils.openForRead(SecureIOUtils.java:116)

at org.apache.hadoop.mapred.TaskLog.getAllLogsFileDetails(TaskLog.java:191)

at org.apache.hadoop.mapred.TaskLogsTruncater.getAllLogsFileDetails(TaskLogsTruncater.java:342)

at org.apache.hadoop.mapred.TaskLogsTruncater.truncateLogs(TaskLogsTruncater.java:134)

at org.apache.hadoop.mapred.Child$4.run(Child.java:260)

at java.security.AccessController.doPrivileged(Native Method)

at javax.security.auth.Subject.doAs(Subject.java:396)

at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1121)

at org.apache.hadoop.mapred.Child.main(Child.java:249)


每个节点报错信息还都不一样,这就很让人头疼,不过下面这个log倒是殊途同归,所有节点最后都报了个无关紧要的文件错误。

2013-05-08 20:58:47,568 ERROR org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException as:hadoop cause:org.apache.hadoop.io.SecureIOUtils$AlreadyExistsException: EEXIST: File exists

2013-05-08 20:58:47,569 WARN org.apache.hadoop.mapred.Child: Error running child

org.apache.hadoop.io.SecureIOUtils$AlreadyExistsException: EEXIST: File exists

at org.apache.hadoop.io.SecureIOUtils.createForWrite(SecureIOUtils.java:167)

at org.apache.hadoop.mapred.TaskLog.writeToIndexFile(TaskLog.java:312)

at org.apache.hadoop.mapred.TaskLog.syncLogs(TaskLog.java:385)

at org.apache.hadoop.mapred.Child$4.run(Child.java:257)

at java.security.AccessController.doPrivileged(Native Method)

at javax.security.auth.Subject.doAs(Subject.java:396)

at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1121)

at org.apache.hadoop.mapred.Child.main(Child.java:249)

Caused by: EEXIST: File exists

at org.apache.hadoop.io.nativeio.NativeIO.open(Native Method)

at org.apache.hadoop.io.SecureIOUtils.createForWrite(SecureIOUtils.java:161)

... 7 more


最后这个log的确是殊途同归的,因为每个map在OOM之后,tasktracker会尝试重新启动map并重新创建相同的TaskLog的文件句柄,但因为是异常终止的,之前的TaskLog的文件句柄已经被创建,但是OOM了,这个句柄没有正常关闭,所以会报写失败的异常。源码如下


/** * Open the specified File for write access, ensuring that it does not exist. * @param f the file that we want to create * @param permissions we want to have on the file (if security is enabled) * * @throws AlreadyExistsException if the file already exists * @throws IOException if any other error occurred */ public static FileOutputStream createForWrite(File f, int permissions) throws IOException { if (skipSecurity) { return insecureCreateForWrite(f, permissions); } else { // Use the native wrapper around open(2) try { FileDescriptor fd = NativeIO.open(f.getAbsolutePath(), NativeIO.O_WRONLY | NativeIO.O_CREAT | NativeIO.O_EXCL, permissions); return new FileOutputStream(fd); } catch (NativeIOException nioe) { if (nioe.getErrno() == Errno.EEXIST) { throw new AlreadyExistsException(nioe); } throw nioe; } } }




De这个bug有点难度,按说map阶段是不容易溢出的,map阶段溢出最有可能发生的应该是在sort和spill阶段,也就是io.sort.mb参数所控制的环形内存所做的快速排序上,但是这个内存已经设置为600M足够大了,mapred.map.child.java.opts也设置了1.5G,也够了。然后由于每个节点的溢出错误都不一样,但是主要有一个共同点,是节点一、二heap和buffer读写问题。


回去再看他的HiveQL,很简单,做了一个uid的count distinct,然后做了几个字段的group by就没了。看来问题可能主要还是出在这个uid上面,他这个hql是特定选的4月某一天。然后尝试选3月的某天,没问题,选5月的某天也没问题,5月日志肯定比4月要大。这样就排除掉了日志大小的问题,一天才100G日志而已,比这个大的有的是。肯定不是因为日志太大引发的map阶段oom。


继续排除,然后高潮来了,选这一天的前一天,也没问题,选后一天,也没问题。看来问题就出在这一天的日志上面了。选了一下distinct length(uid),发现有一条uid有71个字节,正常的应该都是32字节。然后剔除uid长度为71的uid,也就是加上where length(uid) != 71做跟报错HQL相同的group by立马正常了,然后尝试原报错HQL,仍然报错,看来就是他了。


单独写个select * from xxx where length(uid) = 71的HQL抽出这条uid,发现里面含有特殊字符,就是这条uid捣的鬼了。可能是nginx在日志接收过程中发生了TCP错误,然后数据清洗没有洗掉。由于含有特殊字符,Hadoop在做本地map的时候,数据流含有可能是EOF或者NOP之类的东西,导致无法用BufferedReader读取和用StreamDecoder解释,跟做本地任务执行时继承到map.local.dir里的job.xml指定的InputFormat对不上,说白了也就是无法正常执行,然后就溢出了。


这个问题太操蛋了,但是也可能很常见,日志清洗总不能100%保证正确。就一行特殊字符的log,坑了我一下午。这个日志一天一百多G,总不能拿肉眼看,awk跑正则更没戏,总得想点变通的办法。Hive出的问题,最后还是用Hive把问题揪出来了。搞hadoop集群运维不能光搞hadoop的运行进程稳定,还得了解hadoop原理,还得了解业务。还好接手集群运维之前我是写map/reduce的,还算有一点点编程的基础,了解一些业务,比较容易分析一些bug。但是还是不得不吐槽,特殊字符真是个大坑。回头得要求他们把清洗程序加点过滤条件。


上亿行里面就一行bad log,典型的一颗老鼠屎污染了一片海。


另外,51cto的新版编辑器里面的引用标签好像不好使,我把log放在引用里面了,似乎没起什么美化的作用,盼修正。


有关Hadoop运维记录系列(六)的更多相关文章

  1. python - 如何使用 Ruby 或 Python 创建一系列高音调和低音调的蜂鸣声? - 2

    关闭。这个问题是opinion-based.它目前不接受答案。想要改进这个问题?更新问题,以便editingthispost可以用事实和引用来回答它.关闭4年前。Improvethisquestion我想在固定时间创建一系列低音和高音调的哔哔声。例如:在150毫秒时发出高音调的蜂鸣声在151毫秒时发出低音调的蜂鸣声200毫秒时发出低音调的蜂鸣声250毫秒的高音调蜂鸣声有没有办法在Ruby或Python中做到这一点?我真的不在乎输出编码是什么(.wav、.mp3、.ogg等等),但我确实想创建一个输出文件。

  2. ruby-on-rails - 使用一系列等级计算字母等级 - 2

    这里是Ruby新手。完成一些练习后碰壁了。练习:计算一系列成绩的字母等级创建一个方法get_grade来接受测试分数数组。数组中的每个分数应介于0和100之间,其中100是最大分数。计算平均分并将字母等级作为字符串返回,即“A”、“B”、“C”、“D”、“E”或“F”。我一直返回错误:avg.rb:1:syntaxerror,unexpectedtLBRACK,expecting')'defget_grade([100,90,80])^avg.rb:1:syntaxerror,unexpected')',expecting$end这是我目前所拥有的。我想坚持使用下面的方法或.join,

  3. ruby - Sinatra:运行 rspec 测试时记录噪音 - 2

    Sinatra新手;我正在运行一些rspec测试,但在日志中收到了一堆不需要的噪音。如何消除日志中过多的噪音?我仔细检查了环境是否设置为:test,这意味着记录器级别应设置为WARN而不是DEBUG。spec_helper:require"./app"require"sinatra"require"rspec"require"rack/test"require"database_cleaner"require"factory_girl"set:environment,:testFactoryGirl.definition_file_paths=%w{./factories./test/

  4. ruby-on-rails - Rails 5 Active Record 记录无效错误 - 2

    我有两个Rails模型,即Invoice和Invoice_details。一个Invoice_details属于Invoice,一个Invoice有多个Invoice_details。我无法使用accepts_nested_attributes_forinInvoice通过Invoice模型保存Invoice_details。我收到以下错误:(0.2ms)BEGIN(0.2ms)ROLLBACKCompleted422UnprocessableEntityin25ms(ActiveRecord:4.0ms)ActiveRecord::RecordInvalid(Validationfa

  5. 【鸿蒙应用开发系列】- 获取系统设备信息以及版本API兼容调用方式 - 2

    在应用开发中,有时候我们需要获取系统的设备信息,用于数据上报和行为分析。那在鸿蒙系统中,我们应该怎么去获取设备的系统信息呢,比如说获取手机的系统版本号、手机的制造商、手机型号等数据。1、获取方式这里分为两种情况,一种是设备信息的获取,一种是系统信息的获取。1.1、获取设备信息获取设备信息,鸿蒙的SDK包为我们提供了DeviceInfo类,通过该类的一些静态方法,可以获取设备信息,DeviceInfo类的包路径为:ohos.system.DeviceInfo.具体的方法如下:ModifierandTypeMethodDescriptionstatic StringgetAbiList​()Obt

  6. 阿里云RDS——产品系列概述 - 2

    基础版云数据库RDS的产品系列包括基础版、高可用版、集群版、三节点企业版,本文介绍基础版实例的相关信息。RDS基础版实例也称为单机版实例,只有单个数据库节点,计算与存储分离,性价比超高。说明RDS基础版实例只有一个数据库节点,没有备节点作为热备份,因此当该节点意外宕机或者执行重启实例、变更配置、版本升级等任务时,会出现较长时间的不可用。如果业务对数据库的可用性要求较高,不建议使用基础版实例,可选择其他系列(如高可用版),部分基础版实例也支持升级为高可用版。基础版与高可用版的对比拓扑图如下所示。优势 性能由于不提供备节点,主节点不会因为实时的数据库复制而产生额外的性能开销,因此基础版的性能相对于

  7. hadoop安装之保姆级教程(二)之YARN的配置 - 2

    1.1.1 YARN的介绍 为克服Hadoop1.0中HDFS和MapReduce存在的各种问题⽽提出的,针对Hadoop1.0中的MapReduce在扩展性和多框架⽀持⽅⾯的不⾜,提出了全新的资源管理框架YARN. ApacheYARN(YetanotherResourceNegotiator的缩写)是Hadoop集群的资源管理系统,负责为计算程序提供服务器计算资源,相当于⼀个分布式的操作系统平台,⽽MapReduce等计算程序则相当于运⾏于操作系统之上的应⽤程序。 YARN被引⼊Hadoop2,最初是为了改善MapReduce的实现,但是因为具有⾜够的通⽤性,同样可以⽀持其他的分布式计算模

  8. ruby-on-rails - 事件记录 : Select max of limit - 2

    我正在尝试将以下SQL查询转换为ActiveRecord,它正在融化我的大脑。deletefromtablewhereid有什么想法吗?我想做的是限制表中的行数。所以,我想删除少于最近10个条目的所有内容。编辑:通过结合以下几个答案找到了解决方案。Temperature.where('id这给我留下了最新的10个条目。 最佳答案 从您的SQL来看,您似乎想要从表中删除前10条记录。我相信到目前为止的大多数答案都会如此。这里有两个额外的选择:基于MurifoX的版本:Table.where(:id=>Table.order(:id).

  9. Ruby 守护进程导致 ActiveRecord 记录器 IOError - 2

    我目前正在用Ruby编写一个项目,它使用ActiveRecordgem进行数据库交互,我正在尝试使用ActiveRecord::Base.logger记录所有数据库事件具有以下代码的属性ActiveRecord::Base.logger=Logger.new(File.open('logs/database.log','a'))这适用于迁移等(出于某种原因似乎需要启用日志记录,因为它在禁用时会出现NilClass错误)但是当我尝试运行包含调用ActiveRecord对象的线程守护程序的项目时脚本失败并出现以下错误/System/Library/Frameworks/Ruby.frame

  10. ruby-on-rails - 在 Rails 中更高效地查找或创建多条记录 - 2

    我有一个应用需要发送用户事件邀请。当用户邀请friend(用户)参加事件时,如果尚不存在将用户连接到该事件的新记录,则会创建该记录。我的模型由用户、事件和events_user组成。classEventdefinvite(user_id,*args)user_id.eachdo|u|e=EventsUser.find_or_create_by_event_id_and_user_id(self.id,u)e.save!endendend用法Event.first.invite([1,2,3])我不认为以上是完成我的任务的最有效方法。我设想了一种方法,例如Model.find_or_cr

随机推荐