経過時間測定とC言語で呼出元関数名取得

概要

C言語で関数呼出履歴（スタックトレース、バックトレース）を取得する。関数通過ごとにprintfするのはよくやるやり方だけど、性能検証目的では「printf」自体に時間がかかりノイズになる気がする。そこでメモリ上のリングバッファに溜め込み、任意のタイミングでリングバッファの内容を出力する方法を考えた。

ソースコード,github

関数一覧

関数名	概要
int TR_INIT()	出力ファイルのOPEN,RING-BUFの初期化,ELAPS-TIMEの初期化
int TR_PUSH()	トレース情報（関数名、時刻）の取得
int TR_FPRINT()	トレース情報とELAPS-TIMEのファイル出力
int TR_TERM()	出力ファイルのCLOSE
int TR_SETSTART()	ELAPS-TIMEの初期化(起点時間の設定)
int TR_DIFFTIME()	ELAPS-TIMEの時間計算

使用例

void some_function {
	TR_INIT();
	sub1();	
	sub2();	
	sub3();	
	TR_FPRINT();
	TR_TERM();
}

void sub1()
{
	TR_PUSH();
// 関数の処理
}

トレース情報の出力例

---- gCounter=15 gTraceStackMax=10 gTraceFname=
[04]sub511  :Mon Dec 19 01:12:53 2022 ELAPS[0.001373000sec]
[03]sub51   :Mon Dec 19 01:12:53 2022 ELAPS[0.001369000sec]
[02]sub5    :Mon Dec 19 01:12:53 2022 ELAPS[0.001365000sec]
[01]sub411  :Mon Dec 19 01:12:53 2022 ELAPS[0.001297000sec]
[00]sub41   :Mon Dec 19 01:12:53 2022 ELAPS[0.001294000sec]
[09]sub4    :Mon Dec 19 01:12:53 2022 ELAPS[0.001290000sec]
[08]sub311  :Mon Dec 19 01:12:53 2022 ELAPS[0.001222000sec]
[07]sub31   :Mon Dec 19 01:12:53 2022 ELAPS[0.001219000sec]
[06]sub3    :Mon Dec 19 01:12:53 2022 ELAPS[0.001215000sec]
[05]sub211  :Mon Dec 19 01:12:53 2022 ELAPS[0.001152000sec]