程序运算性能测量

定量分析是一切优化过程中最重要的过程之一。在性能优化和分析中,我们如何来描述一段代码的执行效率呢?这里,我将这一过程分为2步。

第一步:我们要找到一个客观的、相对稳定的单位,来描述一个程序的运行时间;

第二步:构造合理的、更接近起初情况的测试用例来进行测量。

这样,最终得到的结果,就是对于一段代码执行效率的客观描述。

一、单位确定

首先,我们要确定下来描述单位。通常来说,时间差被广泛地用做描述计算能力的单位。顾名思议,就是在代码前记下一个时间T1,在执行后记下一个时间T2。然后通过计算∆ = T2 - T1即可得到执行的时长。这种方法方便、快捷,而且也较为准确。它被广泛地用于对计算能力的约束上。如,暴力破解某某密码要几小时等等。相信大家都熟悉下面一段话:

“1976年9月,美国数学家阿佩尔和哈肯利用IBM360计算机工作了1200多个小时,终于证明了四色问题是正确的,轰动了世界。从此四色问题变成了四色定理。”

细心的读者一定已经发现,单纯的“1200多个小时”是不能够描述四色问题的验证过程时间的,它往往要跟上一个前提,在IBM360机器,要求有同型号、子型号、同频率、同批次的CPU,才可以得到相同的结果。那么,是否有更加客观的单位可以描述代码的执行能力呢?这个单位一定符合5个条件。

二、测量方法

我们已经确定了用纳秒级的计量单位“CPU时钟周期”。如何才能获得系统当前的CPU时钟周期呢?INTEL® CPU提供了一个64位的寄存器TSC来存储自开机来的周期值。并可通过指令“rdtsc”将其写入edx:eax。所以,我们可以在代码中插入这样的语句。

#define rdtscll_64(val) do {\
unsigned int __a,__d; \
__asm__ __volatile__("rdtsc" : "=a" (__a), "=d" (__d)); \
(val) = (((unsigned long long)__d)<<32) | (__a); \
} while(0);

通过调用rdtscll即可以得到64位的CPU时钟周期数。

三、测量误差

在了解测量方法之后,同样我们要了解到这个测量方法在哪些情况下会产生误差。

从TSC本身来说,最常见的误差便是多核的影响。CPU并不会对多个核的tsc进行同步,所以,我们首先要保证测量过程是在同一个核上进程的。如果被测代码段执行过程中存在进程切换,则测量值一定不会很准。所以如果我们在测量的过程中要保证被测量函数不要进行进程切换。也就是说如果被测函数有异步IO调用,我们则需要将进程绑定在一个核上。

由于cache的存在,导致我们在对访问密集型的代码进行测量的时候,前后2次测量的结果可能相差5-10倍,所以当我们希望获得单次非cache内内存获得开销的时候,我们需要需要取构造一个复杂的case。

时下非常流行的虚拟机技术也会影响测量的结果,因为有些虚拟机自己模拟了这个TSC这样我们拿到的值就是物理机硬件的tsc。因为在对虚拟机进行统计的时候需要关注它是如何获得TSC的。

当然,TSC本身也是有开销的,虽然它很小。大概在20-40个周期。

四、基本操作测量

1. 连续内存写操作

非常简单,只要memset一个大内存就OK了

2. 随机内存写操作

我们需要构造一个大的block_list,每2个相信节点间的距离都要大于 cache大小,且并不相等,前、后关系也不尽相同。同时,我们通过 memset一个和cache相同大小的buff来清空cache。便可以测量出随机内存写操作的开销。

3. 一些基本操作的开销

操作

平均周期数

操作

平均周期数

连续内存访问(4byte)

10

浮点数值运算(+、-、*)

10-12

随机内存访问(4byte)

208

浮点数值运算(/)

14

整数数值运算

7

系统随机

46

三角函数(sin/cos)

135

五、范例:函数耗时分析

测试使用的CPU信息如下:

范例分别用CTscStat和CTimeStat类来测量funcA,funcB和funcC,用usleep来模拟真实函数的耗时。

代码说明:

#include <unistd.h>  
#include <stdlib.h>  
#include <stdio.h>  
#include <string.h>  
#include <errno.h>  
#include <fcntl.h>
#include <sys/time.h>
#include <string>
#include <vector>
#include <stdint.h>

#define rdtscll_64(val) do {\
unsigned int __a,__d; \
__asm__ __volatile__("rdtsc" : "=a" (__a), "=d" (__d)); \
(val) = (((unsigned long long)__d)<<32) | (__a); \
} while(0);

class CTscStat
{
public:
    CTscStat(const std::string& sCallerName)
    : m_sCallerName(sCallerName)
    {
        rdtscll_64(m_start);
        rdtscll_64(m_lastcall);
    }

    ~CTscStat()
    {
        uint64_t end;
        rdtscll_64(end);
        uint64_t totalConsumeTsc = end - m_start;
        printf("TscStat---TOTAL:func=[%s] tsc_cost=[%lu]\n", m_sCallerName.c_str(), totalConsumeTsc);
    }

    void AddCall(const std::string& sCall)
    {
        AddCall(sCall, GetTscSub());
    }

private:
    void AddCall(const std::string& sCallerName, uint64_t consumeTsc)
    {
        printf("TscStat---SubCall:func=[%s] sub_func=[%s] tsc_cost=[%lu]\n",
            m_sCallerName.c_str(), sCallerName.c_str(), consumeTsc);
        rdtscll_64(m_lastcall);
    }

    uint64_t GetTscSub()
    {
        uint64_t now;
        rdtscll_64(now);
        
        return now - m_lastcall;
    }

private:
    struct SCall
    {
        std::string sCallerName;
        uint64_t    consumeTsc;
    };

private:
    std::string         m_sCallerName;  // 统计接口
    std::vector<SCall>  m_vecCall;      // 请求列表

    uint64_t            m_start;        // 开始TSC
    uint64_t            m_lastcall;     // 上次TSC
};

#define TSC_START(sCn) CTscStat oTscS(sCn);
#define TSC_APICALL(API) \
        do { \
            oTscS.AddCall(API); \
        } while(0)

class CTimeStat
{
public:
    CTimeStat(const std::string& sCallerName)
    : m_sCallerName(sCallerName)
    {
        gettimeofday(&m_start, 0);
        gettimeofday(&m_lastcall, 0);
    }

    ~CTimeStat()
    {
        struct timeval end;
        struct timeval subresult;

        gettimeofday(&end, 0);
        timersub(&end, &m_start, &subresult);
        uint32_t dwTotalConsumeTime = subresult.tv_sec * 1000 + subresult.tv_usec / 1000;

        printf("TimeStat---TOTAL:func=[%s] time_cost=[%u]\n", m_sCallerName.c_str(), dwTotalConsumeTime);
    }

    void AddCall(const std::string& sCall)
    {
        AddCall(sCall, GetTimeSub());
    }

private:
    void AddCall(const std::string& sCallerName, uint32_t dwConsumeTime)
    {
        printf("TimeStat---SubCall:func=[%s] sub_func=[%s] time_cost=[%u]\n",
            m_sCallerName.c_str(), sCallerName.c_str(), dwConsumeTime);
        gettimeofday(&m_lastcall, 0);
    }

    uint32_t GetTimeSub()
    {
        struct timeval now;
        struct timeval subresult;
        gettimeofday(&now, 0);

        timersub(&now, &m_lastcall, &subresult);

        return subresult.tv_sec * 1000 + subresult.tv_usec / 1000;
    }

private:
    struct SCall
    {
        std::string sCallerName;
        uint32_t    dwConsumeTime;
    };

private:
    std::string         m_sCallerName;  // 统计接口
    std::vector<SCall>  m_vecCall;      // 请求列表

    struct timeval      m_start;        // 开始时间
    struct timeval      m_lastcall;     // 上次请求时间
};

#define TS_START(sCn) CTimeStat oTimeS(sCn);
#define TS_APICALL(API) \
        do { \
            oTimeS.AddCall(API); \
        } while(0)

void funcA()
{
    usleep(1000); // 1ms
}

void funcB()
{
    usleep(100000); // 100ms
}

void funcC()
{
    sleep(1); // 1s
}

void TestTsc()
{
    TSC_START("TestTsc");
    funcA();
    TSC_APICALL("funcA");
    funcB();
    TSC_APICALL("funcB");
    funcC();
    TSC_APICALL("funcC");
}

void TestTime()
{
    TS_START("TestTsc");
    funcA();
    TS_APICALL("funcA");
    funcB();
    TS_APICALL("funcB");
    funcC();
    TS_APICALL("funcC");
}

int main(int argc, char** argv)  
{ 
    ////////// tsc ///////////
    TestTsc();
    
    ///////// time ///////////
    TestTime();
    
    return 0;
}

结果说明:

[root@rocket linux_programming]# ./module_perform

TscStat---SubCall:func=[TestTsc] sub_func=[funcA] tsc_cost=[6391184]

TscStat---SubCall:func=[TestTsc] sub_func=[funcB] tsc_cost=[362433912]

TscStat---SubCall:func=[TestTsc] sub_func=[funcC] tsc_cost=[3595441050]

TscStat---TOTAL:func=[TestTsc] tsc_cost=[3964662011]

TimeStat---SubCall:func=[TestTsc] sub_func=[funcA] time_cost=[2]

TimeStat---SubCall:func=[TestTsc] sub_func=[funcB] time_cost=[100]

TimeStat---SubCall:func=[TestTsc] sub_func=[funcC] time_cost=[1000]

TimeStat---TOTAL:func=[TestTsc] time_cost=[1104]

可以看到,当sleep 1ms的时候,测试结果与预期有较大差距,这个跟系统的精度有关。

当sleep 1s 和100ms的时候用Tsc测量的结果分别是主频和主频的1/10。

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏友弟技术工作室

工欲善其事,必先利其器之------MAC工具类

前面分享了一篇《工欲善其事,必先利其器之------Ubuntu工具类》,今天分享MAC的工具。 由于我是一个程序员可能,工具偏开发一点。 ? 通用类的工具 ...

37580
来自专栏Linux驱动

31.Linux-wm9876声卡驱动(移植+测试)

本节学习目的 1)分析Linux中的OSS声卡系统 2)移植wm9876声卡 3)使用madplay应用程序播放mp3 1.声音三要素 采样频率 音频采样率是指...

52970
来自专栏北京马哥教育

动画演示9个超有趣的Linux命令

作者 | 佚名 来源 | 51CTO 糖豆贴心提醒,本文阅读时间6分钟,文末有秘密! Linux最强大的一个特征就是它有大量的各种小命令工具,这也可以称做是...

42790
来自专栏AhDung

【C#】让ReSharper灰色显示未使用的非私有成员的关键

1、在Inspection Severity中设置Non-private accessibility为Warning。如图:

15920
来自专栏SAP最佳业务实践

SAP最佳业务实践:MM–组件收费的委外加工(251)-10清帐

4.12 清帐(基于消耗) 提供的组件过帐到了应收,它将抵销对应的应付金额。 完成对委外加工费用的付款。只有当你支付了委外加工费,系统才允许你冲销可抵扣的应付帐...

44460
来自专栏张善友的专栏

流量调整和限流技术

在早期的计算机领域,限流技术(time limiting)被用作控制网络接口收发通信数据的速率。 可以用来优化性能,减少延迟和提高带宽等。 现在在互联网领域,也...

334100
来自专栏逍遥剑客的游戏开发

一个困扰我一个多星期的Nebula3的BUG

18330
来自专栏张戈的专栏

博客集成Hitokoto·一言经典语句功能

Hitokoto·一言是一个挺有意思的项目,官方的自我介绍如下: 一言网(Hitokoto.cn)创立于 2016 年,隶属于萌创 Team,目前网站主要提供一...

359120
来自专栏小白课代表

犀牛Rhino6.1安装教程

19230
来自专栏一个会写诗的程序员的博客

《MongoDB极简教程》第一章 NoSQL简史 & MongoDB安装&环境配置NoSQLNoSQL 简史CAP定理(CAP theorem)BASEMongoDB 特性&优势文档参考安装&环境配置

MongoDB 是一款开源的文档数据库,并且是业内领先的 NoSQL 数据库,用 C++ 编写而成。

12130

扫码关注云+社区

领取腾讯云代金券