JVM源码分析之不要被GC日志的表面现象迷惑

简书 占小狼
转载请注明原创出处,谢谢!

数组动态扩容导致频繁FGC

关于数组动态扩容导致频繁GC的问题,笨神又写了一篇文章分析,当时因为没有仔细看,导致还有一些疑惑,于是把垃圾回收算法的实现重新看了一遍,不过每次看都会有不小的收获,所以源码不是读一遍就可以了,隔三差五的回头看看,说不定有些不懂的地方,在下一次的时候就豁朗了。

关于数组动态扩容导致频繁FGC,有兴趣的同学可以按下面的步骤动手实践一下,Java代码如下:

// jdk1.7  -Xmx500M -Xms500M -Xmn200M -XX:+UseConcMarkSweepGC
// -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=90
public class CrossReference {
       
    private static int unit = 20 * 1024;

    public static void main(String[] args) throws Exception{
        Thread.sleep(5000);
        System.out.println("allocate start************");
        allocate();
        Thread.sleep(1000);
        System.out.println("allocate end************");
        System.in.read();
    }

    private static void allocate() throws Exception{
        int size = 1024 * 1024 * 400; // 400M
        int len = size / unit;
        List<BigObject> list = new ArrayList<>();

        for(int i = 1; i <= len; i++){
            BigObject bigObject = new BigObject();
            list.add(bigObject);
            Thread.sleep(1);
            System.out.println(i);
        }
    }

    private static class BigObject{
        private byte[] foo;
        BigObject(){
            foo = new byte[unit];
        }
    }
}

通过jstat -gcutil <pid> 1000命令,可以展示堆内存的使用情况和GC触发情况。

1、JVM参数中没有-XX:+CMSScavengeBeforeRemark,jstat 结果如下:

图中每个分代的数值代表内存使用率,可以看出发生FGC的时候,并没有触发YGC,所以老年代的对象一直回收不了,因为老年代进行GC时,会把新生代的对象作为GC root,在本场景中,新生代的对象不回收,老年代的对象也无法回收,而且老年代的内存使用率已经超过设置的阈值90%,所以会不断的进行FGC。

2、JVM参数中添加-XX:+CMSScavengeBeforeRemark,结果如下:

从上面的数据可以发现,发生FGC时,确实也触发了YGC,但是这次YGC并没有回收对象,导致了又不断的FGC,通过查看GC日志,可以发现也是在不断的打印GC信息,而且每次打印的数据(GC前的内存使用量和GC后的内存使用量)都是一样的。

现象描述如下:
allocate() 方法执行完成后
1.频繁CMS GC,但是old区仍然占用大,基本未回收空间
2.添加-XX:+CMSScavengeBeforeRemark参数,remark之前的一次ygc也未回收空间,old区情况同1
3.在Jprofiler中手动Run Full GC,young区,old区都被正常回收
4.若Arraylist初始化容量为它需要add的数量,则不存在上述现象

问题如下:
1.allocate() 方法执行完成后,堆中存在young-》old, old-》young的循环引用吗
2.添加-XX:+CMSScavengeBeforeRemark参数,为何仍然有问题,方法执行完后在Jprofiler中查看存活对象Arraylist已经没有,但是BigObject,byte[]仍然存在,占用约400M内存
3.手动Run Full GC为何就能正常回收?

为了解答这个问题,就得从Hotspot的实现源码入手,看看GC动作到底是什么样的过程,我们不妨可以假设一下,确实触发了YGC动作,然后记录了GC信息,但是因为某些原因并没有真正的执行YGC过程。

YGC实现过程

新生代内存分配失败触发YGC

如果是因为新生代内存分配失败触发YGC时,JVM内部对应会生成一个VM_GenCollectForAllocation对象,提交到一个执行队列中,最终会由VM Thread执行它的doit()方法,可以看一下doit方法

void VM_GenCollectForAllocation::doit() {
  SvcGCMarker sgcm(SvcGCMarker::MINOR);

  GenCollectedHeap* gch = GenCollectedHeap::heap();
  GCCauseSetter gccs(gch, _gc_cause);
  _res = gch->satisfy_failed_allocation(_size, _tlab);
  assert(gch->is_in_reserved_or_null(_res), "result not in heap");

  if (_res == NULL && GC_locker::is_active_and_needs_gc()) {
    set_gc_locked();
  }
}

这里需要关注的是satisfy_failed_allocation()方法,定义在GenCollectedHeap


HeapWord* GenCollectedHeap::satisfy_failed_allocation(size_t size, bool is_tlab) {
  return collector_policy()->satisfy_failed_allocation(size, is_tlab);
}

由垃圾回收策略决定执行satisfy_failed_allocation方法,实现如下


HeapWord* GenCollectorPolicy::satisfy_failed_allocation(size_t size,
                                                        bool   is_tlab) {
  GenCollectedHeap *gch = GenCollectedHeap::heap();
  GCCauseSetter x(gch, GCCause::_allocation_failure);
  HeapWord* result = NULL;

  assert(size != 0, "Precondition violated");
  if (GC_locker::is_active_and_needs_gc()) {
    // GC locker is active; instead of a collection we will attempt
    // to expand the heap, if there's room for expansion.
    if (!gch->is_maximal_no_gc()) {
      result = expand_heap_and_allocate(size, is_tlab);
    }
    return result;   // could be null if we are out of space
  } else if (!gch->incremental_collection_will_fail(false /* don't consult_young */)) {
    // Do an incremental collection.
    gch->do_collection(false            /* full */,
                       false            /* clear_all_soft_refs */,
                       size             /* size */,
                       is_tlab          /* is_tlab */,
                       number_of_generations() - 1 /* max_level */);
  } else {
    if (Verbose && PrintGCDetails) {
      gclog_or_tty->print(" :: Trying full because partial may fail :: ");
    }
    // Try a full collection; see delta for bug id 6266275
    // for the original code and why this has been simplified
    // with from-space allocation criteria modified and
    // such allocation moved out of the safepoint path.
    gch->do_collection(true             /* full */,
                       false            /* clear_all_soft_refs */,
                       size             /* size */,
                       is_tlab          /* is_tlab */,
                       number_of_generations() - 1 /* max_level */);
  }

  ...

1、如果GC_locker正在起作用,说明有线程正在通过JNI操作临界内存,那么就放弃GC动作,因为JNI操作完之后会可能会触发一次GC
2、如果上一次YGC是失败的,至于为什么上一次是失败的,可能是因为老年代没有足够的空间容纳新生代的对象,那么就不执行本次的YGC,直接进行FGC

不管是YGC还是FGC,都是通过执行GenCollectedHeap::do_collection()方法实现的,在该方法中会记录执行GC的日志,实现如下:

bool complete = full && (max_level == (n_gens()-1));
const char* gc_cause_prefix = complete ? "Full GC" : "GC";
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
GCTraceTime t(GCCauseString(gc_cause_prefix, gc_cause()), PrintGCDetails, false, NULL);

其中GCTraceTime实现中,会打印GC日志信息,而且这个时刻并未开始GC动作。

CTraceTime::GCTraceTime(const char* title, bool doit, bool print_cr, GCTimer* timer) :
    _title(title), _doit(doit), _print_cr(print_cr), _timer(timer) {
  if (_doit || _timer != NULL) {
    _start_counter = os::elapsed_counter();
  }

  if (_timer != NULL) {
    assert(SafepointSynchronize::is_at_safepoint(), "Tracing currently only supported at safepoints");
    assert(Thread::current()->is_VM_thread(), "Tracing currently only supported from the VM thread");

    _timer->register_gc_phase_start(title, _start_counter);
  }

  if (_doit) {
    gclog_or_tty->date_stamp(PrintGCDateStamps);
    gclog_or_tty->stamp(PrintGCTimeStamps);
    gclog_or_tty->print("[%s", title);
    gclog_or_tty->flush();
  }
}

执行YGC的真正逻辑在parNewGeneration::collect()方法中,在方法中有这么一个判断逻辑:

  // If the next generation is too full to accommodate worst-case promotion
  // from this generation, pass on collection; let the next generation
  // do it.
  if (!collection_attempt_is_safe()) {
    gch->set_incremental_collection_failed();  // slight lie, in that we did not even attempt one
    return;
  }

如果不满足collection_attempt_is_safe(),就直接返回,说明本次YGC是不安全的,不会真正执行本次的垃圾回收,那什么情况算是不安全的呢?collection_attempt_is_safe()实现如下:

bool DefNewGeneration::collection_attempt_is_safe() {
  if (!to()->is_empty()) {
    if (Verbose && PrintGCDetails) {
      gclog_or_tty->print(" :: to is not empty :: ");
    }
    return false;
  }
  if (_next_gen == NULL) {
    GenCollectedHeap* gch = GenCollectedHeap::heap();
    _next_gen = gch->next_gen(this);
    assert(_next_gen != NULL,
           "This must be the youngest gen, and not the only gen");
  }
  return _next_gen->promotion_attempt_is_safe(used());
}

1、to空间不为空
2、没有下一个内存代,即没有老年代
3、其中情况1和2几乎不会发生,主要还是看这种情况,主要看老年代是否有足够的空间来容纳新生代的对象,老年代的promotion_attempt_is_safe()的实现如下:

bool ConcurrentMarkSweepGeneration::promotion_attempt_is_safe(size_t max_promotion_in_bytes) const {
  size_t available = max_available();
  size_t av_promo  = (size_t)gc_stats()->avg_promoted()->padded_average();
  bool   res = (available >= av_promo) || (available >= max_promotion_in_bytes);
  if (Verbose && PrintGCDetails) {
    gclog_or_tty->print_cr(
      "CMS: promo attempt is%s safe: available("SIZE_FORMAT") %s av_promo("SIZE_FORMAT"),"
      "max_promo("SIZE_FORMAT")",
      res? "":" not", available, res? ">=":"<",
      av_promo, max_promotion_in_bytes);
  }
  return res;
}

如果老年代中的可用空间大于gc_stats统计的新生代每次平均晋升的对象大小,或者可以容纳目前新生代所有的对象,表明可以执行正常的YGC动作,如果都不满足,就直接放弃本次YGC。

由FGC触发的YGC

在JVM参数中添加-XX:+CMSScavengeBeforeRemark,执行FGC之前会触发一次YGC,这个参数的好处是如果YGC比较有效果的话是能有效降低remark的时间长度,可以简单理解为如果大部分新生代的对象被回收了,那么GC root变少了,从而提高了remark的效率。

因为CMS是多线程执行的,主要的执行入口定义在ConcurrentMarkSweepThread::run()方法,ConcurrentMarkSweepThread相当于继承了Java中的Thread的一个类,在run方法执行实现具体逻辑,下面是CMS执行过程的简要分析。

1、run方法中调用CMSCollector::collect_in_background方法,在该方法中,会根据当前CMS的执行状态,初始化对应的 VM_CMS_Operation,本文是分析CMSScavengeBeforeRemark,该变量所用到的逻辑中对用的状态为 VM_CMS_Final_Remark,该状态是CMS中再次标记阶段。

2、初始化 VM_CMS_Final_Remark,并提交到VM Thread的执行队列中,等待被执行,最终由VM Thread执行它的doit方法,这方式和执行YGC时类似

3、在VM_CMS_Final_Remark::doit()方法中调用_collector->do_CMS_operation();,最终调用CMSCollector::checkpointRootsFinal()方法,其中和CMSScavengeBeforeRemark相关的代码实现如下:

if (CMSScavengeBeforeRemark) {
      GenCollectedHeap* gch = GenCollectedHeap::heap();
      // Temporarily set flag to false, GCH->do_collection will
      // expect it to be false and set to true
      FlagSetting fl(gch->_is_gc_active, false);
      NOT_PRODUCT(GCTraceTime t("Scavenge-Before-Remark",
        PrintGCDetails && Verbose, true, _gc_timer_cm);)
      int level = _cmsGen->level() - 1;
      if (level >= 0) {
        gch->do_collection(true,        // full (i.e. force, see below)
                           false,       // !clear_all_soft_refs
                           0,           // size
                           false,       // is_tlab
                           level        // max_level
                          );
      }
    }

这里又回到了GenCollectedHeap::do_collection()方法,具体过程和新生代内存分配失败触发YGC的情况一样。

另外手动执行Run Full GC和执行jmap -histo:live <pid> 命令,可以强制虚拟机执行垃圾回收。

参考资料:

假笨说-关于数组动态扩容导致频繁GC的问题,我还有话说

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 159,015评论 4 362
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,262评论 1 292
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 108,727评论 0 243
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,986评论 0 205
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,363评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,610评论 1 219
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,871评论 2 312
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,582评论 0 198
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,297评论 1 242
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,551评论 2 246
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,053评论 1 260
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,385评论 2 253
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,035评论 3 236
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,079评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,841评论 0 195
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,648评论 2 274
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,550评论 2 270

推荐阅读更多精彩内容