导航：首页 > 服务器 >

AIX下C/C++函数性能统计实现方法--改进版

发表于：2024-11-26 作者：千家信息网编辑

千家信息网最后更新 2024年11月26日，上一篇实现，是统计了每一次函数调用的层次关系和耗时。如果在函数调用比较多的情况下，更关心的是减少输出，只需要总计的耗时即可。另外如果是后台程序，输出到文件会更好。因此，对程序做了改进。当设置TRACE

千家信息网最后更新 2024年11月26日AIX下C/C++函数性能统计实现方法--改进版

上一篇实现，是统计了每一次函数调用的层次关系和耗时。如果在函数调用比较多的情况下，更关心的是减少输出，只需要总计的耗时即可。另外如果是后台程序，输出到文件会更好。

因此，对程序做了改进。当设置TRACELOG环境变量，则输出到这个环境变量指定的文件中。如果设置了DETAILF，则会输出调用层次关系和每一次的耗时，否则只输出总计时间。

tr.cpp改进后的程序如下。

#include <iostream>

#include <fstream>

#include <vector>

#include <map>

#include <string>

#include <sys/time.h>

using std::vector;

using std::map;

using std::string;

using std::clog;

using std::endl;

using std::ofstream;

using std::ostream;

extern "C" void print_trace(const char * const procname);

struct Stat

{

int lvl;

string name;

long stm;

long etm;

long oitv;

Stat(int l, const string& s, long st) : lvl(l), name(s), stm(st), etm(0), oitv(0) {}

};

struct Sum

{

int cnt;

long itv;

Sum() : cnt(0), itv(0) {}

Sum operator+=(long i)

{

++cnt;

itv+=i;

return *this;

}

};

namespace

{

vector<Stat> tracev;

map<string, Sum> itvm;

int clvl = 0;

bool detailf = (getenv("DETAILF")!=NULL);

}

extern "C" void

__func_trace_enter(const char * const proc_name,

const char * const file_name,

const int line_no,

void ** const id)

{

// printf("{ %s (%s:%d) %p %s\n", proc_name, file_name, line_no, id[0], (char*)*id);

struct timeval nowtm;

gettimeofday(&nowtm, NULL);

++clvl;

tracev.push_back(Stat(clvl, string(proc_name)+"() : "+file_name, nowtm.tv_sec * 1000000 + nowtm.tv_usec));

}

extern "C" void

__func_trace_exit(const char * const proc_name,

const char * const file_name,

const int line_no,

void ** const id)

{

// printf("} %s (%s:%d) %p %s\n", proc_name, file_name, line_no, id[0], (char*)*id);

struct timeval nowtm;

int itv;

gettimeofday(&nowtm, NULL);

auto iter = tracev.end() - 1;

while (iter->etm != 0)

--iter;

iter->etm = nowtm.tv_sec * 1000000 + nowtm.tv_usec;

itv = iter->etm - iter->stm - iter->oitv;

itvm[proc_name]+=itv;

for (auto s = tracev.begin(); s!=iter; ++s)

{

if (s->etm == 0)

s->oitv += itv;

}

--clvl;

if (!detailf)

tracev.erase(iter, tracev.end());

if (clvl == 0)

{

print_trace(proc_name);

tracev.clear();

itvm.clear();

}

extern "C" void print_trace(const char * const procname)

{

time_t t;

char buf[30];

ofstream logf(getenv("TRACELOG"), std::ios::app);

ostream &log = logf ? logf : clog;

if (detailf)

{

log<<"Detail of "<< procname <<"() :\n";

for (auto s = tracev.begin(); s!=tracev.end(); ++s)

{

log << s->lvl << "\t";

t=s->stm/1000000;

strftime(buf, sizeof(buf), "%Y%m%d%H%M%S", localtime(&t));

log << buf << "." << s->stm % 1000000 << "\t";

t=s->etm/1000000;

strftime(buf, sizeof(buf), "%Y%m%d%H%M%S", localtime(&t));

log << buf << "." << s->etm % 1000000 << "\t";

log << s->etm-s->stm << "\t" << s->oitv << "\t" << s->etm-s->stm-s->oitv << "\t";

log << string(s->lvl-1, ' ') << s->name << "\n";

}

log<<"Total of "<< procname <<"() :\n";

for (auto s = itvm.begin(); s!=itvm.end(); ++s)

{

log << s->first << "()\t count "<< (s->second).cnt << "\ttime " << (s->second).itv << "\n";

}

log<<endl;

}

设置DETAILF后，运行后输出结果如下。

Detail of main() :
1 20170801152000.103879 20170801152000.104034 155 58 97 main() : tt.c
2 20170801152000.103954 20170801152000.103997 43 3 40 f1() : tt.c
3 20170801152000.103958 20170801152000.103961 3 0 3 f2() : tt.c
2 20170801152000.104017 20170801152000.104032 15 3 12 f1() : tt.c
3 20170801152000.104021 20170801152000.104024 3 0 3 f2() : tt.c
Total of main() :
f1() count 2 time 0.000052 s
f2() count 2 time 0.000006 s
main() count 1 time 0.000097 s

很赞哦！