hadoop从调整GC到关键Counter计算原理分析

 hadoop集群中发现使用Parallel Scavenge+Parallel Old收集器组合进行垃圾收集（这也是server端jvm默认的GC方式）时CPU占用可能会非常高，偶尔会出现爆满的状态，考虑可能是由于当时程序在执行GC导致的，而且很可能是由于并行GC导致的，我们根据服务器启动的Java进程查看一下当前使用的是哪种GC方式：

 

$ jinfo -flag "GC方式" jvm进程id

 

最终可以看出使用的是-XX:+UseParallelOldGC，打开此开关参数后，使用Parallel Scavenge+Parallel Old收集器组合进行垃圾收集。

 

串行垃圾回收器在jvm Client模式下是默认启动的，参数 -XX:+UseSerialGC 可以设置垃圾回收策略为串行。

 

模拟线上同样的两个MR任务，比较其执行CPU时间和GC时间：

 

-XX:+UseParallelOldGC

 

-XX:+UseSerialGC

 

经过分析之后，可以发现GC花费的时间有一定的增长，由453s提高了大概3倍左右，到达1321s；而CPU时间则有大幅度下降，说明的确降低了CPU的时间。

 

为了确保实验结果的正确性，再进行第二次的测试：

 

-XX:+UseParallelOldGC

 

-XX:+UseSerialGC

 

通过对比仍然可以看出，CPU时间减少200s左右，GC时间增加大概260s。通过简单分析可以看出，对于hadoop的每个任务的JVM，更像是client应用程序而非server端的应用，因为每个Task分配的资源CPU: 1 core, 2G memory是相对固定的。

 

Counter的计算逻辑

 

那么这两个Counter（CPU时间的计算以及GC时间的计算）是如何得出来的？

（参考文章：http://www.cnblogs.com/ggjucheng/archive/2013/05/08/3065220.html）

 

这两个Counter都在hadoop-mapreduce-client包下面的hadoop-mapreduce-client-core模块下，其中的resources包含了所有需要的资源，每个分组都是以不同的.properties文件命名的。CPU和GC消耗时间都在TaskCounter.properties文件中，可以看出这个文件的Counter都属于分组Map-Reduce Framework，在工程中它们存在于具体的枚举中：org.apache.hadoop.mapreduce.TaskCounter，

GC_TIME_MILLIS,
CPU_MILLISECONDS

  

 

hadoop如何衡量mapreduce任务的计算量，肯定不能按照任务的运行时间来计算，这是由于Map和Reduce的不均匀性，任务可能卡在单个Map或者Reduce端（由于分片和Partition的不均匀性导致）。

 

CPU，内存等资源的计算

 

可以确定，hadoop使用的是CPU时间，CPU_MILLISECONDS就是任务运行耗费的CPU时间。原来在hadoop运行期间，task会从/proc/<pid>/stat读取对应进程的用户CPU时间和内核CPU时间，其总和就是最后的CPU时间。

 

关于proc文件的具体信息说明，可以查看这篇blog:

http://blog.csdn.net/zjl_1026_2001/article/details/2294067

 

我们关联到具体的源码位置，可以查看下面这个方法：

org.apache.hadoop.mapred.Task void updateResourceCounters()
方法说明：Update resource information counters

 

其中使用了org.apache.hadoop.yarn.util.ResourceCalculatorProcessTree来获得进程使用的相关资源，其中包括了CPU资源，物理内存以及虚拟内存资源等等。在hadoop2.2.0版本中包括了两种子类型，分别是基于Windows和Linux监测进程资源的，这里只分析基于Linux计算资源的子类：

org.apache.hadoop.yarn.util.ProcfsBasedProcessTree

  

由于CPU时间都是以jiffies为单位的，因此ProcessTree中首先计算了jiffies：

• 执行Shell命令:  getconf CLK_TCK，返回jiffiPerseconds=100
• jiffies的计算公式为：JIFFY_LENGTH_IN_MILLIS = jiffiesPerSecond != -1 ? Math.round(1000D / jiffiesPerSecond) : -1; 

而内存占用则摘自上述blog中：

"Map-Reduce Framework:Physical memory (bytes) snapshot" 每个task会从/proc/<pid>/stat读取对应进程的内存快照，这个是进程的当前物理内存使用大小。

"Map-Reduce Framework:Virtual memory (bytes) snapshot" 每个task会从/proc/<pid>/stat读取对应进程的虚拟内存快照，这个是进程的当前虚拟内存使用大小。
 
"Map-Reduce Framework:Total committed heap usage (bytes)" 每个task的jvm调用Runtime.getRuntime().totalMemory()获取jvm的当前堆大小。

  

物理内存和虚拟内存是从/proc/pid/stat中拿到的，Total committed heap usage (bytes)是直接调用JDK中的方法Runtime.getRuntime().totalMemory()方法拿到，这个值是这个JVM能拿到的最大内存。

 

GC时间的计算 

 

GC时间是肯定不能从系统中得出，这只能寄希望于Java虚拟机。Hadoop中是使用JMX来拿到GC的总时间的，这部分代码可以参考类org.apache.hadoop.mapred.Task类中子类GCTimeUpdater中的构造器以及getElapseGC()方法：

 

public GcTimeUpdater() {
      this.gcBeans = ManagementFactory.getGarbageCollectorMXBeans();
      getElapsedGc(); // Initialize 'lastGcMillis' with the current time spent.
    }

    /**
     * @return the number of milliseconds that the gc has used for CPU
     * since the last time this method was called.
     */
    protected long getElapsedGc() {
      long thisGcMillis = 0;
      for (GarbageCollectorMXBean gcBean : gcBeans) {
        thisGcMillis += gcBean.getCollectionTime();
      }

      long delta = thisGcMillis - lastGcMillis;
      this.lastGcMillis = thisGcMillis;
      return delta;
    }

 

JMX，Java Management eXtension，即Java管理扩展，为管理和监测资源提供了一个通过架构，设计模式，API和服务，JMX可以管理和监测的资源包括应用程序、设备、服务和Java虚拟机。

JMX的应用包括但不仅限于以下几种：

• 管理应用程序的配置；
• 统计并展现应用程序的行为；
• 当资源的状态发生变化时发出通知；

比如JDK自带的工具JConsole就是第二种应用的方式：

 

通过其中的GarbageCollectorMBean中的方法就可以监测到具体的收集次数以及收集时间。

 

上述的分析仅仅是关于单个TaskAttempt的counter，这些Counter也需要定时地向Application Master汇报（通过RPC方式以及org.apache.hadoop.mapred.TaskUmbilicalProtocol协议）。

 

任务的Counter刷新也是有一定的间隔的，默认时间间隔（貌似不能修改的）：

/** The number of milliseconds between progress reports. */
  public static final int PROGRESS_INTERVAL = 3000;

 

在任务执行过程中会进行不断地刷新操作，任务整体完成后，也会进行最后一次的状态提交，所以我们可以在任务完成后能够查看到所有map/reduce任务成功attemp的Counter指标数据。