基于方法耗时统计等场景实现的耗时统计小工具

说到方法耗时统计、性能调试等，开发中经常都会去做，但我们在做这个事情的过程中，似乎很多人都用的很暴力的一种方式去做。哪里需要统计耗时，就直接使用时间戳变量，在最后计算结果，比如下面这样：

private static void work() {
        long time1 = System.currentTimeMillis();
        workA();
        long time2 = System.currentTimeMillis();
        workB();
        long time3 = System.currentTimeMillis();
        workC();
        long time4 = System.currentTimeMillis();
        workEnd();
        long time5 = System.currentTimeMillis();

        long aRunTime = time2 - time1;
        long bRunTime = time3 - time2;
        long cRunTime = time4 - time3;
        long totalRunTime = time5 - time1;
        
        // 统计A、B、C分别耗时和总耗时
        System.out.println("aRunTime:" + aRunTime + " bRunTime:" + bRunTime + " cRunTime:" + cRunTime + " totalRunTime:" + totalRunTime);
    }

有没有点似曾相识？这种做法我们同事都经常干，哈哈哈，简单的写两句图省事，但是往往不省事~唉。

在一个方法内我们可以写几个局部变量统计，多个方法我们写几个成员变量统计，不在一个类，页面跳转之类的又怎么办呢？写几个全局静态变量来统计么？

我个人是不太喜欢这样的写法，感觉会越写越乱，而且变得很麻烦、复杂，也不好控制和查看，所以最后写个简单方便的小工具。

使用效果图如下：

解释一波

• 第一行包含标签，表示开始。
• 最后一行统计总耗时，以及添加记录的次数，表示结束。
• 中间部分就是具体的每次记录。举例：1492 ms message: 执行A。
  • 1492 ms（毫秒）是相对于前一条记录的耗时。
  • “message: 执行A” 中的 “执行A” 是任意添加的消息内容。
  • 任务A执行耗时1492毫秒，任务B执行耗时0毫秒（耗时太少，毫秒单位统计不出来）。
  • 任意两个记录间的耗时可以相加，得到间隔的耗时，比如：从开始到任务C的耗时 = 1492 + 2004 = 3496ms。

代码实现

import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.ConcurrentHashMap;

/**
 * 一个实用程序类，用来帮助记录在方法调用中的耗时。
 * 用法如下:
 *
 * <pre>
 *     TimingRecorder.addRecord(label, "work");
 *     // ... do some work A ...
 *     TimingRecorder.addRecord(label, "work A");
 *     // ... do some work B ...
 *     TimingRecorder.addRecord(label, "work B");
 *     // ... do some work C ...
 *     TimingRecorder.addRecord(label, "work C");
 *     TimingRecorder.logTime(label);
 * </pre>
 *
 * <p>logTime调用会后输出示例如下:</p>
 *
 * <pre>
 *     标签: label <开始>
 *        0 ms  message: 开始
 *     1501 ms  message: 执行A
 *      302 ms  message: 执行B
 *     2002 ms  message: 执行完成~
 *     <结束>   总耗时: 3805 ms   记录次数: 4 次
 * </pre>
 *
 * @author LiuFeng
 * @date 2020-10-21
 */
public class TimingRecorder {
    private static String TAG = "TimingRecorder";

    // 是否调用打印
    private static boolean isToLog = true;

    // 单个标签可以添加记录的最大数量
    private static final int RECORD_MAX_NUM = 1000;

    // 记录储存容器
    private static final ConcurrentHashMap<String, List<RecordTime>> recordMap = new ConcurrentHashMap<>();

    /**
     * 添加记录
     *
     * @param label   记录的标签
     * @param message 记录的日志内容。
     */
    public static void addRecord(String label, String message) {
        // 时间记录
        RecordTime recordTime = new RecordTime();
        // Android系统可以使用SystemClock.elapsedRealtime()
        // 代替System.nanoTime() / 1000_000，作用相同，这里是考虑到Java里使用
        recordTime.time = System.nanoTime() / 1000_000;
        recordTime.message = message;

        // 处理存入记录
        handleRecordTimes(label, recordTime);
    }

    /**
     * 处理记录数据集合（数据过多时将释放）
     *
     * @param label
     * @param recordTime
     */
    private static synchronized void handleRecordTimes(String label, RecordTime recordTime) {
        // 取出记录
        List<RecordTime> recordTimes = getRecordTimes(label);

        // 超过记录容量时，调用打印释放，目的避免有未打印记录占用过多内存
        if (recordTimes.size() >= RECORD_MAX_NUM) {
            String desc = label + ": Add too many records! will invoke logTime.";
            println(desc);

            // 保留第一条，是为了释放打印后，新的记录中能计算到从第一条开始的耗时
            RecordTime firstRecordTime = recordTimes.get(0);

            // 执行打印记录，并清除标签
            logTime(label, desc);

            // 存入第一条数据到新容器
            recordTimes = getRecordTimes(label);
            recordTimes.add(firstRecordTime);
        }

        // 存入新记录
        recordTimes.add(recordTime);
    }

    /**
     * 获取标签对应容器
     *
     * @param label
     * @return
     */
    private static List<RecordTime> getRecordTimes(String label) {
        List<RecordTime> recordTimes = recordMap.get(label);

        // 创建容器
        if (recordTimes == null) {
            recordTimes = new ArrayList<>();
            List<RecordTime> tempRecords = recordMap.putIfAbsent(label, recordTimes);
            if (tempRecords != null) {
                recordTimes = tempRecords;
            }
        }
        return recordTimes;
    }

    /**
     * 打印记录时间
     *
     * @param label 记录的标签
     * @return
     */
    public static String logTime(String label) {
        return logTime(label, null);
    }

    /**
     * 打印记录时间
     *
     * @param label 记录的标签
     * @param msg   追加的日志内容。
     * @return
     */
    public static String logTime(String label, String msg) {
        List<RecordTime> recordTimes;

        // 加锁保证添加数据和移除数据操作安全
        synchronized (TimingRecorder.class) {
            // 取出记录，清除标记
            recordTimes = recordMap.remove(label);
        }

        // 在记录容量内，追加一条表示结束的记录
        if (recordTimes != null && recordTimes.size() < RECORD_MAX_NUM) {
            RecordTime recordTime = new RecordTime();
            recordTime.time = System.nanoTime() / 1000_000;
            recordTime.message = msg != null ? msg : "log time end.";
            recordTimes.add(recordTime);
        }

        // 解析记录
        String record = parseRecord(label, recordTimes);

        // 打印
        if (isToLog) {
            println(record);
        }

        return record;
    }

    /**
     * 解析记录数据
     *
     * @param label
     * @param recordTimes
     * @return
     */
    private static String parseRecord(String label, List<RecordTime> recordTimes) {
        // 组装数据
        StringBuilder buffer = new StringBuilder();
        buffer.append("\n标签: ").append(label);

        // 无记录处理
        if (recordTimes == null || recordTimes.isEmpty()) {
            buffer.append(" <没有记录>");
            return buffer.toString();
        }

        buffer.append(" <开始>\n");

        int size = recordTimes.size();

        // 第一次记录时间
        long firstTime = recordTimes.get(0).time;

        // 最后一次记录时间
        long lastTime = recordTimes.get(size - 1).time;

        // 总耗时
        long totalTime = lastTime - firstTime;

        // 计算耗时的前一个时间
        long prevTime = firstTime;

        // 取总耗时位数长度，记作最大的位长，用于空格缩进
        int maxDigitLength = String.valueOf(totalTime).length();

        // 取出数据计算差值并拼接
        for (int i = 0; i < size; i++) {
            RecordTime record = recordTimes.get(i);
            long spaceTime = record.time - prevTime;
            prevTime = record.time;

            // 当前耗时位长
            int currentDigitLength = String.valueOf(spaceTime).length();

            // 缩进空格字符（目的是对齐易看）
            String indentSpaceStr = getSpaceStr(maxDigitLength - currentDigitLength);

            // 拼接
            buffer.append(indentSpaceStr);
            buffer.append(spaceTime).append(" ms");
            buffer.append("  message: ").append(record.message);
            buffer.append("\n");
        }

        buffer.append("<结束>");
        buffer.append("   总耗时: ").append(totalTime).append(" ms");
        buffer.append("   记录次数: ").append(size).append(" 次");


        return buffer.toString();
    }

    /**
     * 记录时间的model
     */
    private static class RecordTime {
        long time;
        String message;
    }

    /**
     * 生成指定数量空格字符串
     *
     * @param spaces
     * @return
     */
    private static String getSpaceStr(int spaces) {
        String number = String.valueOf(spaces <= 0 ? "" : spaces);
        return String.format("%" + number + "s", "");
    }

    /**
     * 调用日志打印
     *
     * @param msg
     */
    private static void println(String msg) {
        // Java里用System.out，Android最好是用Log
        System.out.println(msg);
        //Log.println(Log.INFO, TAG, msg);
    }
}

使用方式

// 执行任务前，调用addRecord，添加记录
TimingRecorder.addRecord("label", "work start");

// ... do some work A ...
TimingRecorder.addRecord("label", "work A");

// ... do some work B ...
TimingRecorder.addRecord("label", "work B");

// ... do some work C ...
TimingRecorder.addRecord("label", "work C");

// 执行结束，调用logTime，打印时间统计
TimingRecorder.logTime("label", "work end");

达到的目的？

1. 简单、易用，不用手动写时间戳再计算吧。
2. 可以统计很多方法函数的耗时，想统计几个写几个。
3. 以标签作为区别不同统计耗时的唯一键，好理解，可跨不同方法、不同类添加记录。
4. 一个统计记录在一条日志里，美观好看，不用到处查找其他记录。

注意事项

1. isToLog控制日志打印开关，正式环境不需要打印就置false关掉。
2. logTime()方法返回统计记录的字符串，可以拿到数据丢到本地文件等。
3. 单个标签可以添加记录的最大数量是1000条，但不是说超过就不能用了，为了减少占内存，会先打印清空释放，和后续的统计数据可以串起来的。
4. 代码里记录时间用的System.nanoTime() / 1000_000，所以如果需要更精确的时间，比如微秒，就除以1000。
5. 调用日志打印：Java里用System.out，Android最好是用Log。

最后

看起来简单的一个小工具，其实考虑的东西还是有不少的，里面也有没考虑到的问题，大家可以根据自己需求修改完善。