剑客
关注科技互联网

如何正确地统计函数执行时间

如何正确地统计函数执行时间

1923年,美国福特公司一台大型电机发生故障,来“会诊”的专家一连数月一筹莫展。后来,移居美国的德国科学家斯坦敏茨经过反复摸索比对在电机旁用粉笔画了一道线,并指导工程师们打开电机,将画线的地方的线圈减少16匝后,电机果然恢复正常运转。斯坦敏茨因此开口向福特公司要1万美金的酬劳。有人说:“画一条线值一万美金,这是敲竹杆”。斯坦敏茨听后说道:“粉笔画一条线,1美元。知道在哪里画线,9999美元。”

最近在做性能优化方面的工作,而这其中最重的就是找出性能的瓶颈在哪里——知道了在哪画粉笔线,才能对症下药。

TraceView、Systrace当然是非常好的分析工具,但是profile 的引入必然就导致函数真实执行时间的不准确,我们只能借助这些profile工具分析可能的瓶颈在哪;而且很多时候,工具也是有误差的,甚至误差会超出可以容忍的范围——那就是错误了。想象一下,你用一把最小刻度是1m的尺子去测量1cm长的物体,这样的结果还可靠吗?因此,使用时钟来计量函数的执行时间,这种最原始的方法往往也是最有效的办法;今天要聊的就是我们常用的那几个时钟函数。

在Android里面我们有如下几个时钟函数可以使用:

  1. System.currentTimeMillis()
  2. SystemClock.uptimeMillis()
  3. SystemClock.elapsedRealtime()
  4. SystemClock.currentThreadTimeMillis ()

前面三个函数我就不说了, 官方文档 说的很清楚,无非就是算不算休眠时间的问题;建议好好看一下。

当我看到第四个函数 SystemClock.currentThreadTimeMillis () 的文档的时候,我不由得心里一惊:

Returns milliseconds running in the current thread.

返回当前线程运行的时间?

我们知道,Android里面的线程调度跟一般的操作系统一样,使用的是时间片轮转的方式。线程之间通过抢占CPU时间片来轮流执行达到并发执行的效果。那么问题来了:如果一个线程在执行的时候,CPU被别的线程抢去了,被抢去的这段时间算这个线程的执行时间么?如果我们需要分析的函数里面有IO操作,这种情况几乎是必然的——现代CPU才不会傻傻等待IO完成了,它肯定跑去执行别的CPU任务了。

那么,上面几个计算时间的函数对这种情况分别有什么不同的表现呢?写个demo测一下:

new Thread(new Runnable() {
    @Override
    public void run() {
        long currentTime1 = System.currentTimeMillis();
        long currentThreadTime1 = SystemClock.currentThreadTimeMillis();
        SystemClock.sleep(1000);
        Log.d(TAG, "cost:" + (System.currentTimeMillis() - currentTime1));
        Log.d(TAG, "cost2:" + (SystemClock.currentThreadTimeMillis() - currentThreadTime1));
    }
}).start();

下面是输出结果:

MainActivity: cost:1000

正如文档所述,currentThreadTimeMillis()这个函数返回的是在 当前线程处于running状态的时间。

因此,如果你想统计一个计算密集型函数的执行时间,很有可能被一个IO操作给坑了哦;更一般的情况是,在多线程环境(数百个)下,如果你要统计一个函数的执行时间,很有可能它丫的时间片被抢走了,你统计了线程runnable的时间!!给一张Java线程状态的图:

如何正确地统计函数执行时间

我估计很多人不知道有这么一个函数,因此在你统计执行时间的时候,你选择了对的API吗?

OK,文章说到这里应该就结束了;但是本着刨根问底的态度,这个native的函数到底实现是啥样的呢?

我们找到C++的 实现 ;代码在/framework/base/jni/android_os_SystemClock.cpp :

/*
 * native public static long currentThreadTimeMillis();
 */
static jlong android_os_SystemClock_currentThreadTimeMillis(JNIEnv* env,
        jobject clazz)
{
#if defined(HAVE_POSIX_CLOCKS)
    struct timespec tm;
    clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tm);
    return tm.tv_sec * 1000LL + tm.tv_nsec / 1000000;
#else
    struct timeval tv;
    gettimeofday(&tv, NULL);
    return tv.tv_sec * 1000LL + tv.tv_usec / 1000;
#endif
}

可以看到,这里是用了Linux的API,我们看看这个API的文档: clock_gettime(3): clock/time functions

CLOCK_THREAD_CPUTIME_ID Thread-specific CPU-time clock.

本文完。

所以,你弄清楚了应该使用哪个API测试函数执行时间了吗 ^_^

分享到:更多 ()

评论 抢沙发

  • 昵称 (必填)
  • 邮箱 (必填)
  • 网址