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到磁盘。

目前对于 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); 
    } 
  } 
}