一个java的Profile工具

Posted 2020-08-08 生若秋叶

场景：我们在系统运行中，需要监控某个代码段的运行时间，我们完全可以使用currentTimeMillis来做，但是做起来比较麻烦，尤其是需要阶段监控的时候，那么这个工具就出现啦~~~

先说下想要实现的功能：1.能够对代码段进行运行时间的监控，比如代码行a->代码行b的运行时间。2.能够监控代码行嵌套的运行时间监控，比如a->b->c->d中a->d和b->c的运行时间监控（类似括号一样，形成配对的方式）。3.能够在运行范围内的jvm一些指标的监控，比如内存使用量等。

/**
 * 性能相关的调试工具,支持,线程正式场景,做运行时间的profile,运行性能监控(不建议线上使用,因为需要开启监控线程)
 * 该工具不会抛出任何异常
 * @author Administrator
 * @version $Id: ProfileUtils.java, v 0.1 2016年9月5日 下午11:02:45 Administrator Exp $
 */
public class Profiler {

    /** debug模式 */
    //    private static volatile boolean                    debug               = false;

    private final static String                        LOG_TEMPLATE        = "[messag=%s][startTime=%s][endTime=%s][durationTime=%sms][processors=%s][memUse=%s]";
    private final static String                        SIMPLE_LOG_TEMPLATE = "[durationTime=%sms][message=%s]";
    private final static SimpleDateFormat              DATE_FORMAT         = new SimpleDateFormat(
        "yyyy/MM/dd HH:mm:ss");

    /** profile日志,建议运行中别做修改,否则有些配置会导致残留线程 */
    private static ThreadLocal<ProfileConfig>          configHolder        = new ThreadLocal<ProfileConfig>() {
                                                                               protected ProfileConfig initialValue() {
                                                                                   return new ProfileConfig(
                                                                                       false, false,
                                                                                       0);
                                                                               };
                                                                           };

    /** 开始monitor的时间 */
    private static ThreadLocal<Stack<MonitorResource>> resStackHolder      = new ThreadLocal<Stack<MonitorResource>>() {
                                                                               protected java.util.Stack<MonitorResource> initialValue() {
                                                                                   return new Stack<MonitorResource>();
                                                                               };
                                                                           };

    /** 监控线程 */
    private static ThreadLocal<MonitorThread>          monitorThreadHolder = new ThreadLocal<MonitorThread>();

    /**
     * 开始monitor
     */
    public static void enter(Object msgObj) {
        try {
            Stack<MonitorResource> monitorResStack = resStackHolder.get();
            monitorResStack.push(new MonitorResource(msgObj, System.currentTimeMillis()));
            ProfileConfig config = configHolder.get();
            //开启监控线程
            if (config.isUseMonitorThread()) {
                if (monitorThreadHolder.get() != null) {
                    killThread();
                }
                MonitorThread monitorThread = new MonitorThread(getCurrentMonitorRes(), config);
                monitorThreadHolder.set(monitorThread);
                monitorThread.start();
            }
        } catch (Throwable e) {
            //            if (debug) {
            //                e.printStackTrace();
            //            }
            return;
        }
    }

    /**
     * 结束monitor
     * @return
     */
    public static MonitorResource release() {
        try {
            Stack<MonitorResource> monitorResStack = resStackHolder.get();
            MonitorResource monitorResource = getCurrentMonitorRes();
            monitorResource.setEndTime(System.currentTimeMillis());
            ProfileConfig config = configHolder.get();
            //监控线程关闭
            if (config.isUseMonitorThread()) {
                killThread();
            }
            return monitorResStack.pop();
        } catch (Throwable e) {
            //            if (debug) {
            //                e.printStackTrace();
            //            }
            return new MonitorResource(e.getMessage(), 0);
        }
    }

    /**
     * 使用新的messageObj替换原来的
     * @param messageObj
     * @return
     */
    public static MonitorResource release(Object messageObj) {
        MonitorResource monitorResource = release();
        monitorResource.setMessageObj(messageObj);
        return monitorResource;
    }

    /**
     * 结束monitor并且打印日志
     * @param logger
     * @return
     */
    public static MonitorResource releaseAndLog(Logger logger, Object messageObj) {
        MonitorResource resource = release(messageObj);
        LoggerUtils.info(logger, resource);
        return resource;
    }

    /**
     * 结束monitor并且打印日志
     * @param logger
     * @return
     */
    public static MonitorResource releaseAndLog(Logger logger) {
        MonitorResource resource = release();
        LoggerUtils.info(logger, resource);
        return resource;
    }

    /**
     * 设置profile配置
     * @param config
     */
    public static void setProfileConfig(ProfileConfig config) {
        configHolder.set(config);
    }

    /**
     * Setter method for property <tt>debug</tt>.
     * 
     * @param debug value to be assigned to property debug
     */
    //    public static void setDebug(boolean debug) {
    //        Profiler.debug = debug;
    //    }

    /**
     * 移除监控线程
     */
    private static void killThread() {
        try {
            MonitorThread futureTask = monitorThreadHolder.get();
            monitorThreadHolder.remove();
            futureTask.interrupt();
        } catch (Throwable e) {
            // ignore
            //            if (debug) {
            //                e.printStackTrace();
            //            }
        }
    }

    /**
     * 获取当前的monitorRes
     * @return
     */
    public static MonitorResource getCurrentMonitorRes() {
        try {
            Stack<MonitorResource> resStack = resStackHolder.get();
            return resStack.get(resStack.size() - 1);
        } catch (Exception e) {
            //            if (debug) {
            //                e.printStackTrace();
            //            }
            return new MonitorResource(e.getMessage(), 0);
        }
    }

    /**
     * 资源使用情况，比如cpu最大使用量等。
     * @author Administrator
     * @version $Id: Profile.java, v 0.1 2016年9月5日 下午11:38:39 Administrator Exp $
     */
    public static class MonitorResource {

        /** 当前资源的标志 */
        private Object     messageObj    = null;

        private long       startTime     = 0;

        private long       endTime       = 0;

        private int        processorNums = 0;

        private List<Long> memUse        = Lists.newArrayList();

        /**
         * @param messageObj
         * @param startTime
         */
        public MonitorResource(Object messageObj, long startTime) {
            super();
            this.messageObj = messageObj;
            this.startTime = startTime;
        }

        /**
         * Setter method for property <tt>messageObj</tt>.
         * 
         * @param messageObj value to be assigned to property messageObj
         */
        public void setMessageObj(Object messageObj) {
            this.messageObj = messageObj;
        }

        public String getMemUse() {
            StringBuilder stringBuilder = new StringBuilder();
            for (int i = 0; i < memUse.size(); i++) {
                stringBuilder.append(memUse.get(i) / 1024L + "K");
                if (i != memUse.size() - 1) {
                    stringBuilder.append(",");
                }
            }
            return stringBuilder.toString();
        }

        /**
         * 获取整个profile堆栈
         * @return
         */
        public Stack<MonitorResource> getMonitorResStack() {
            return resStackHolder.get();
        }

        /** 
         * @see java.lang.Object#toString()
         */
        @Override
        public String toString() {
            return configHolder.get().isUseSimpleLogTemplate()
                ? (String.format(SIMPLE_LOG_TEMPLATE, endTime - startTime, messageObj))
                : (String.format(LOG_TEMPLATE, messageObj, DATE_FORMAT.format(new Date(startTime)),
                    DATE_FORMAT.format(new Date(endTime)), endTime - startTime, processorNums,
                    getMemUse()));
        }

        /**
         * 获取运行时间
         * @return
         */
        public long getDurTime() {
            return endTime - startTime;
        }

        public void putMemUse(long l) {
            memUse.add(l);
        }

        /**
         * Setter method for property <tt>endTime</tt>.
         * 
         * @param endTime value to be assigned to property endTime
         */
        public void setEndTime(long endTime) {
            this.endTime = endTime;
        }

        /**
         * Getter method for property <tt>messageObj</tt>.
         * 
         * @return property value of messageObj
         */
        public Object getMessageObj() {
            return messageObj;
        }

        /**
         * Setter method for property <tt>processorNums</tt>.
         * 
         * @param processorNums value to be assigned to property processorNums
         */
        public void setProcessorNums(int processorNums) {
            this.processorNums = processorNums;
        }

    }

    public static class ProfileConfig {
        private boolean useSimpleLogTemplate  = false;
        private boolean useMonitorThread      = false;
        private int     monitorCollectDurTime = 500;

        /**
         * @param useSimpleLogTemplate
         * @param useMonitorThread
         * @param monitorCollectDurTime
         */
        public ProfileConfig(boolean useSimpleLogTemplate, boolean useMonitorThread,
                             int monitorCollectDurTime) {
            super();
            this.useSimpleLogTemplate = useSimpleLogTemplate;
            this.useMonitorThread = useMonitorThread;
            this.monitorCollectDurTime = monitorCollectDurTime;
        }

        /**
         * Getter method for property <tt>useSimpleLogTemplate</tt>.
         * 
         * @return property value of useSimpleLogTemplate
         */
        public boolean isUseSimpleLogTemplate() {
            return useSimpleLogTemplate;
        }

        /**
         * Setter method for property <tt>useSimpleLogTemplate</tt>.
         * 
         * @param useSimpleLogTemplate value to be assigned to property useSimpleLogTemplate
         */
        public void setUseSimpleLogTemplate(boolean useSimpleLogTemplate) {
            this.useSimpleLogTemplate = useSimpleLogTemplate;
        }

        /**
         * Getter method for property <tt>useMonitorThread</tt>.
         * 
         * @return property value of useMonitorThread
         */
        public boolean isUseMonitorThread() {
            return useMonitorThread;
        }

        /**
         * Setter method for property <tt>useMonitorThread</tt>.
         * 
         * @param useMonitorThread value to be assigned to property useMonitorThread
         */
        public void setUseMonitorThread(boolean useMonitorThread) {
            this.useMonitorThread = useMonitorThread;
        }

        /**
         * Getter method for property <tt>monitorCollectDurTime</tt>.
         * 
         * @return property value of monitorCollectDurTime
         */
        public int getMonitorCollectDurTime() {
            return monitorCollectDurTime;
        }

        /**
         * Setter method for property <tt>monitorCollectDurTime</tt>.
         * 
         * @param monitorCollectDurTime value to be assigned to property monitorCollectDurTime
         */
        public void setMonitorCollectDurTime(int monitorCollectDurTime) {
            this.monitorCollectDurTime = monitorCollectDurTime;
        }

    }

    private static class MonitorThread extends Thread {

        private static final AtomicLong threadCount = new AtomicLong();

        private MonitorResource         monitorResource;

        private final ProfileConfig     config;

        /**
         * 
         */
        public MonitorThread(MonitorResource resource, ProfileConfig config) {
            monitorResource = resource;
            setName("monitor-thread-" + threadCount.getAndIncrement());
            setDaemon(true);
            this.config = config;
        }

        /** 
         * @see java.lang.Thread#run()
         */
        @Override
        public void run() {
            monitorResource.setProcessorNums(Runtime.getRuntime().availableProcessors());
            while (true) {
                monitorResource.putMemUse(
                    Runtime.getRuntime().maxMemory() - Runtime.getRuntime().freeMemory());

                try {
                    Thread.sleep(config.getMonitorCollectDurTime());
                } catch (InterruptedException e) {
                    //                    if (debug) {
                    //                        e.printStackTrace();
                    //                    }
                    return;
                }
            }
        }
    }
}

 可以看到，我们有个监控资源的概念，每个阶段都对应一个监控资源，比如a->d和b->c都对应了一个监控资源。从实现上，每次进入监控的时候，会生成一个监控资源，并且记录当前时间，并且把该监控资源压栈。同时，还会启动一个监控线程，将jvm的状态不断写入该监控资源中，所以针对a->d和b->c都生成了自己的监控线程，并且吧jvm状态写入自己的监控资源中。  当release的时候，会kill掉监控线程，并且把监控资源出栈。

根据上面的设计可以看到，该工具的使用需要注意下面的问题：

1.如果不启用监控线程，那么可以用于线上的场景。

2.如果启用了监控线程，那么只适合debug分析的场景，因为如果是线上，当监控的代码块并发量大起来的时候，会以1:1的比例创建监控线程，这个时候会有风险。

3.启用监控线程的场景比较适合于，并发量较小（创建的监控线程少），但是执行时间长的场景。这个时候可以对代码块进行执行分析。