关于Android性能打点的探索

背景

在SDK开发迭代过程中需要严格关注SDK的性能问题，因此SDK通常会设计Monitor接口，对主要方法进行性能打点监测，起先用的是System.currentTimeMillis()，然而实操后发现，部分方法的耗时在1ms以内，大约几十微秒的区间，这就hin尴尬了。

所以打算切换到System.nanoTime()，但是问题来了：

System.nanoTime()拿的到底是什么时间，能不能准确测量出方法耗时呢？
System.nanoTime()本身耗时是怎样的呢？其本身会不会影响到方法的性能数据呢？

实验设计

对于问题1，RTFSC总是没错的，以Linux下JDK1.8为例（1.7也是这份代码）

jlong os::javaTimeNanos() {
  if (Linux::supports_monotonic_clock()) {
    struct timespec tp;
    int status = Linux::clock_gettime(CLOCK_MONOTONIC, &tp);
    assert(status == 0, "gettime error");
    jlong result = jlong(tp.tv_sec) * (1000 * 1000 * 1000) + jlong(tp.tv_nsec);
    return result;
  } else {
    timeval time;
    int status = gettimeofday(&time, NULL);
    assert(status != -1, "linux error");
    jlong usecs = jlong(time.tv_sec) * (1000 * 1000) + jlong(time.tv_usec);
    return 1000 * usecs;
  }
}

其中，clock_gettime方法的第一个参数CLOCK_MONOTONIC决定了最终获取的时间类型，CLOCK_MONOTONIC从字面意思来看是单调增加的时间，代码的跟踪结果也显示其代表着距离系统启动那一刻的时间差，本质上是一个差值，由于代码较多，这里不便贴出，有兴趣的同学可以自行研究下。

既然获取的是距离系统启动时刻的时间差，那如果方法在执行的过程中被其它方法中断了呢？通过程序验证，此时System.nanoTime()获取的时间会包含其它方法执行的时间。那么，有没有可能只获得需要测试的方法执行的时间呢？不管测试的方法有没有被中断，也就是说，除了CLOCK_MONOTONIC，有没有其它参数能达成上述目标呢？

当然是有的，只需要传入线程的clock id即可只获取当前需要测试的线程的执行时间，从而排除其它线程的干扰，代码如下（代码是Android项目的jni代码）

Java_myapplication_MainActivity_getThreadUserTime(
        JNIEnv *env,
        jobject /* this */) {

    struct timespec ts;
    clockid_t cid;

    jlong ret = 0;
    if (0 == pthread_getcpuclockid(pthread_self(), &cid)) {
        if (0 == clock_gettime(cid, &ts)) {
            ret = ts.tv_sec*NSEC_PER_SEC + ts.tv_nsec;
        }
    }

    std::string hello = "Hello from C++";
    return ret;
}

实验进行到这里，已经可以回答问题1了：System.nanoTime()拿到的是距离系统启动时刻的时间差，在某些情况下并不能十分准确的测量出方法耗时。

对于问题2，结合上述实验，首先要比较下两种方法即System.nanoTime()与JNI方法的各自耗时，测试手机为Google Pixel2，测试代码如下

for (int j = 0; j < 10; j++) {
            long sum = 0;
            for (int i = 0; i < 10000; i++) {
                long t1 = getThreadUserTime();
                long t2 = getThreadUserTime();
                sum += (t2 - t1);
            }

            long sum2 = 0;
            for (int i = 0; i < 10000; i++) {
                long t1 = System.nanoTime();
                long t2 = System.nanoTime();
                sum2 += (t2 - t1);
            }
            String info = (String) tv.getText();
            tv.setText(info + "\nUserTime  10000次 TotolTime=" + sum + "\n" + "nanoTime 10000次 TotolTime=" + sum2);

测试结果如下（图中时间单位为ns，纳秒）

image1.jpg

从结果可以看出，JNI方法的耗时是System.nanoTime()的三倍左右，这也是可预期的，因为前者获取线程的执行时间是需要计算的，而后者相当于只读取一个数值即可，另一方面System.nanoTime()的执行耗时大约是0.46us。

实验进行到这里，已经可以回答问题2了：

如果需要测试的方法耗时在几十us以上，

方法执行的线程容易被中断，那么建议使用JNI方法

方法执行的线程几乎不会被中断（对于多核手机而言，这种情况将会占据大多数），两种方式都ok

如果需要测试的方法耗时在几us左右，

同样方法执行的线程容易被中断，那么建议使用JNI方法

方法执行的线程几乎不会被中断（对于多核手机而言，这种情况将会占据大多数），那么建议使用System.nanoTime()

总结

当下越来越多的性能分析需要更精确的耗时测量，不能无脑使用System.currentTimeMillis()了。而在切换到System.nanoTime()后，也需要根据应用场景考虑到计时方法本身的限制性了。