频繁fullgc竟然是这样造成的？

最新推荐文章于 2024-05-02 16:03:08 发布

背书包的老男孩

最新推荐文章于 2024-05-02 16:03:08 发布

阅读量1.3k

点赞数 1

分类专栏：工作杂谈文章标签： jvm java 算法 Powered by 金山文档

本文链接：https://blog.csdn.net/weixin_42459814/article/details/128880659

版权

工作杂谈专栏收录该内容

8 篇文章 0 订阅

订阅专栏

问题描述

排查线上服务监控，发现某个应用服务最近fullGC频繁，jvm监控如图

问题分析

fullGC问题，首先排查jvm内存配置是否足够，查看应用启动jvm参数,

jvm参数配置内存3G，足够，查看内存使用率

从上面两个图可以发现，堆内存虽然有波动，但是总体是在上升的，达到70%（-XX:CMSInitiatingOccupancyFraction=70参数控制，CMS老年代回收器回收阈值）的时候，直线下降，触发了fullGC，老年代内存被回收

以上可以得出结论，应用在运行中存在某些对象没有在新生代回收，走到了老年代，时间久了一直堆积，达到老年代的瓶颈，触发fullGC才回收

继续排查，内存中是有什么对象，为什么没有在新生代回收，跑到了老年代？

光凭代码合猜没办法得出结论，应用并没有什么耗时长的请求（长期hold对象，多次ygc后跑到老年代），也没有什么地方会分配大对象（大对象可能会直接分配到老年代）

通过jvm命令，查找内存中到底有什么对象

jmap -histo:live 335273 | head -n30 查找内存中存活的排名前30的对象

查询结果并没有发现什么异常，内存中最大的对象为char[] 和byte[] 但是也才43M，根本达不到应用的内存瓶颈

再次查询当前内存中的所有对象占用的内存

jmap -histo 335273 | head -n30

对比上图发现区别，其他对象差别不大，但是char[]相差900多M，其中的差异表明内存中存在900多M的待回收的char[]对象（不可达），此时问题基本可以确认是因为内存中大量的cha[]，没有在新生代被回收，跑到老年代

对象找到了，但是并没有解决问题，为什么大量的char[]会在内存中没回收？是从哪里引入的？内容是什么？

dump内存分析

#线上慎用此命令，dump内存期间服务不可用，会引起线上异常

jmap -dump:format=b,file=/tmp/baseuser.bin 335273

上图可以明确就是char[]的问题，进一步查看存的是什么内容

查看源码，看下是哪里报错，报错源是因为，请求上下文解析出错，此时问题基本明了，因为这个报错太多，每次都打印一行日志，一条记录就是一个char[]，这也解释了为什么内存中会有很多日志上报的对象

接着查询为什么会有此报错，根据错误堆栈，找到具体报错的

报错是因为com.oppo.lang.StringUtils高版本，去掉了isEmpty方法，但是RequestContext还是用的旧版本（在高版本的RequestContext已经不依赖com.oppo.lang）

原因分析，为什么日志打印多了，会引起fullGC?

日志打印会通过基础技术的api，上报到PaaS平台，查看日志上报相关代码

@Override
    public void append(LogEvent logEvent) {
        try {
            ThrowableProxy throwableProxy = logEvent.getThrownProxy();
            String traceId = logEvent.getContextData().getValue("traceId");
            if(StringUtils.isBlank(traceId)){
                traceId = "";
            }
            if(null == throwableProxy){
                //将日志封装成一个LogData对象，进入队列
                QueueUtil.getInstance().offer(new LogData(logEvent.getMessage().getFormattedMessage(), logEvent.getThreadName(), logEvent.getLevel().name(),
                        logEvent.getTimeMillis(), logEvent.getLoggerName() , traceId));
            }else{//错误调用栈
                StringBuilder sb = new StringBuilder(logEvent.getMessage().getFormattedMessage());
                sb.append("\n");
                sb = dealErrorContent(throwableProxy, sb);
                ThrowableProxy throwable = throwableProxy.getCauseProxy();
                while(null != throwable){
                    sb.append("Caused by: ");
                    dealErrorContent(throwable, sb);
                    throwable = throwable.getCauseProxy();
                }
                QueueUtil.getInstance().offer(new LogData(sb.toString(), logEvent.getThreadName(), logEvent.getLevel().name(),
                        logEvent.getTimeMillis(), logEvent.getLoggerName() , traceId));
            }
        } catch (Exception e) {
            System.err.println("log4j2 httpAppender error!" + e.toString());
        }
 
    }
 
 private void pushTask() {
        //定时push 数据
        Thread t = new Thread(new Runnable() {
            @Override
            public void run() {
                sleep();
                List<LogData> arr = new ArrayList<>();
                while (true) {
                    try {
                        //从队列中取出数据
                        LogData logData = poll();
                        if (null == logData && arr.size() > 0) {
                            try {
                                uploadAndRetry(arr, 0);
                            } finally {
                                arr.clear();
                            }
                        } else if(null != logData){
                            //将数据放入数组，达到200个，上传
                            arr.add(logData);
                            if (arr.size() >= BATCH_SUBMIT_COUNT) {
                                try {
                                    uploadAndRetry(arr, 0);
                                } finally {
                                    arr.clear();
                                }
                            }else{
                                continue;
                            }
                        }
                        //线程sleep2秒
                        sleep();
                    } catch (Exception e) {
                        try {
                            System.err.println(new Date() + "logger-appender pushTask error!" + e.toString());
                        } catch (Exception e1) {
                        }
                        sleep();
                    }
                }
            }
        });
        t.setName("upload-log");
        t.setDaemon(true);
        t.start();
    }

日志上报流程：

1、log4j异步appender到 HttpAppender的appender方法

2、将日志数据封装成一个LogData对象，放到QueueUtil中的一个阻塞队列quene中

3、QueueUtil中起一个线程，从queue中取出来，放入一个临时列表，达到200个时，调用http接口，上报到PaaS，线程sleep2秒

4、上报线程再次执行，重复第三步

上面过程存在一个问题：

由于对象首先放到队列中，队列大小2000，每次上报（一次200条）后会sleep2秒，最快得(2000/200)*2= 20秒才可能会上报，从而变成可回收的对象，实际时间肯定大于20秒，每次上报的耗时，上报异常还会重试的耗时

在这20多秒内：

发生Minor GC（回收Eden区内存）时，由于此时对象处于队列中不可被回收，被分配到survivor区，（Eden区和survivor区的比例默认是8:1:1）

当请求量太大，日志太多时，Minor GC更加频繁，达到了20次/30秒，日志对象，大部分会进入survivor区

虚拟机并不是永远的要等到对象年龄达到阈值后才能晋升到老年代，当Survivor中相同年龄（比如N）的所有对象的大小总和大于Survivor的一半的时候，那些年龄大于等于N所有对象将会直接提前进入老年代。

基于上面准则，当随着survivor区越来越大，对象会进入老年代。