hadoop日志简单分析

hadoop日志简单分析

一、概述
本文基于0.19.1分析得出，有一些是alibaba hadoop优化的部分。本文不涉及jobtracker及nodename元数据的部分,本文主要讲述一个任务在计算阶段大致产生的一些日志，及日志的一些问题。
二、日志简单介绍
当所有的守护进程都起来后（为了简单起见，我们用的是伪分布模式，是由一个机器搭建的），大致的目录结构如下：
[python] 
[dragon.caol@hd19-vm1 logs]$ tree 
. 
|-- hadoop-dragon.caol-datanode-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-datanode-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-jobtracker-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-jobtracker-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-namenode-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-namenode-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-secondarynamenode-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-secondarynamenode-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-tasktracker-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-tasktracker-hd19-vm1.yunti.yh.aliyun.com.out 
|-- history 
`-- userlogs 
    `-- toBeDeleted 
 
3 directories, 10 files 
此时注意点，
其中的log配置是由配置文件log4j.properties配置的，但是其中的一些配置项则由 shell命令启动时确定的。
如：
[python] 
307 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.log.dir=$HADOOP_LOG_DIR" 
308 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.log.file=$HADOOP_LOGFILE" 
309 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.home.dir=$HADOOP_HOME" 
310 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.id.str=$HADOOP_IDENT_STRING" 
311 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.root.logger=${HADOOP_ROOT_LOGGER:-INFO,console}" 
312 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.root.logger.appender=${HADOOP_ROOT_LOGGER_APPENDER:-console}" 
313 HADOOP_OPTS="$HADOOP_OPTS -Dhadoop.root.logger.level=${HADOOP_ROOT_LOGGER_LEVEL:-info}" 
启动后 jobtracker的jvm参数为：
[python] 
5537 JobTracker -Xmx1000m -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote -Xdebug -Xrunjdwp:transport=dt_socket,address=1314,server=y,suspend=n -Dhadoop.log.dir=/home/dragon.caol/hadoop-0.19.1-dc/bin/../logs -Dhadoop.log.file=hadoop-dragon.caol-jobtracker-hd19-vm1.yunti.yh.aliyun.com.log -Dhadoop.home.dir=/home/dragon.caol/hadoop-0.19.1-dc/bin/.. -Dhadoop.id.str=dragon.caol -Dhadoop.root.logger=INFO,RFA -Dhadoop.root.logger.appender=RFA -Dhadoop.root.logger.level=info -Djava.library.path=/home/dragon.caol/hadoop-0.19.1-dc/bin/../lib/native/Linux-amd64-64 
用此些配置共同来拼装log4j的配置。
当执行一个简单的任务后，logs目录的日志结构大致如下所示：
[python] 
[dragon.caol@hd19-vm1 logs]$ tree 
. 
|-- hadoop-dragon.caol-datanode-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-datanode-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-jobtracker-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-jobtracker-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-namenode-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-namenode-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-secondarynamenode-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-secondarynamenode-hd19-vm1.yunti.yh.aliyun.com.out 
|-- hadoop-dragon.caol-tasktracker-hd19-vm1.yunti.yh.aliyun.com.log 
|-- hadoop-dragon.caol-tasktracker-hd19-vm1.yunti.yh.aliyun.com.out 
|-- history 
|   |-- h1_1348474254849_job_201209241610_0001_conf.xml 
|   `-- h1_1348474254849_job_201209241610_0001_dragon.caol_word+count 
|-- history.idx 
|-- job_201209241610_0001_conf.xml 
`-- userlogs 
    |-- job_201209241610_0001 
    |   |-- attempt_201209241610_0001_m_000000_0 
    |   |   |-- log.index 
    |   |   |-- stderr 
    |   |   |-- stdout 
    |   |   `-- syslog 
    |   |-- attempt_201209241610_0001_m_000001_0 
    |   |   |-- log.index 
    |   |   |-- stderr 
    |   |   |-- stdout 
    |   |   `-- syslog 
    |   |-- attempt_201209241610_0001_m_000002_0 
    |   |   |-- log.index 
    |   |   |-- stderr 
    |   |   |-- stdout 
    |   |   `-- syslog 
    |   `-- attempt_201209241610_0001_r_000000_0 
    |       |-- log.index 
    |       |-- stderr 
    |       |-- stdout 
    |       `-- syslog 
    `-- toBeDeleted 
 
8 directories, 30 files 
我们看出在 history、userlogs有子文件了，且多出了 history.idx、job_201209241610_0001_conf.xml文件。此些文件其实是框架在不同的时期产生的。有的是索引文件，基本是为了供页面查询的。在一段时间后会删除。
二、用户日志userlogs
我们主要关注的是userlogs文件，由于里面存的大部分是客户的代码产生的，如果客户在代码中写入了system.out则日志会出现在相应的attempt_YYYYMMDDHHMM_000x_(r/m)_000000_x/stdout文件中，err则会出现在***/stderr中。如果是log4j的，则会出现
相应syslog中。
为什么日志被定位了，System.err/out的日志其实是shell脚本调用java的时候，把标准输入流与标准输出流改成了文件。对于log4j则是采取先前说的log4j.properties与TaskRunner确定的，log4j采取的是hadoop自己实现的org.apache.hadoop.mapred.TaskLogAppender。TaskLogAppender在这里做了一个限制的事情，如果mapred.userlog.limit.kb配置大于0，则采取了tail -c的模式，也就是 采取FIFO，出去直接丢弃，当task结束的时候，队列的日志全部flush到磁盘。www.2cto.com

目前对于 System.out/err没有限制，我则采取限制方案，代码如下： 基本思路是 用 LimitOutputSteam 重新装饰 System.out/err 采取计数来限制大小，如果超过则抛出异常，这样样户端会感知。其实不建议使用system.out/err来打印日志的。
[java] 
import java.io.FilterOutputStream; 
import java.io.IOException; 
import java.io.OutputStream; 
 
/**
 * limit writing data. if writing data size has reached limit,system writes log
 * message and throws IOException
 * 
 * @author dragon.caol
 * @date 2012-09-21
 * 
 */ 
public class LimitOutputSteam extends FilterOutputStream { 
  private long remaining; 
  private String msg; 
  private boolean limit = Boolean.FALSE; 
  private boolean isRestriction = Boolean.FALSE; 
 
  public LimitOutputSteam(OutputStream out, long maxSize) { 
    super(out); 
    if (maxSize > 0) { 
      this.isRestriction = Boolean.TRUE; 
      this.remaining = maxSize; 
      this.msg = "\nException:Written to stdout or stderr cann't exceed " 
          + ((float) maxSize / 1024) + "kb. \n"; 
    } 
  } 
 
  public void write(int b) throws IOException { 
    if (isRestriction) { 
      if (!limit) { 
        if (remaining-- > 0) { 
          super.write(b); 
        } else { 
          for (int i = 0; i < msg.length(); i++) { 
            super.write(msg.getBytes()[i]); 
          } 
          this.limit = Boolean.TRUE; 
          throw new LimitOutputSteamException(msg); 
        } 
      } 
    } else { 
      super.write(b); 
    } 
  } 
}