1

例えばC++ですが以下のコードを実行すると

#include<iostream>

void a();
void b();
void c();

void a()
{
    std::cout<<"call a"<<std::endl;
    b();
    std::cout<<"return a"<<std::endl;
}
void b()
{
    std::cout<<"call b"<<std::endl;
    c();
    c();
    std::cout<<"return b"<<std::endl;
}
void c()
{
    std::cout<<"call c"<<std::endl;
    std::cout<<"return c"<<std::endl;
}

int main()
{
    a();
}

実行結果は以下のようになりますが

call a
call b
call c
return c
call c
return c
return b
return a

このような関数呼び出しのログを自動生成するツールはないでしょうか?
言語はなんでも構いません。

追記
@metropolis さんのページを参考に以下のようなコードを追加しました。

//main.cpp
#define _GNU_SOURCE
#include<iostream>

void a();
void b();
void c();

int i=0;

void a()
{
    b();
}

void b()
{
    c();
    c();
}

void c()
{
    ++i;
}

int main()
{
    a();
    std::cout<<i<<std::endl;
}


// simpletrace.cpp
#define _GNU_SOURCE
#include <dlfcn.h>
#include <iostream>

extern "C" {
    void __cyg_profile_func_enter(void* func_address, void* call_site);
    void __cyg_profile_func_exit(void* func_address, void* call_site);
}

// dladdrを用いて関数アドレスから関数シンボルへ変換
const char* addr2name(void* address) {
    Dl_info dli;
    if (0 != dladdr(address, &dli)) {
        std::cout<<"success dladdr"<<std::endl;
        return dli.dli_sname;
    }
    else
    {
        std::cout<<"failed dladdr"<<std::endl;
    }
    return 0;
}

void __cyg_profile_func_enter(void* func_address, void* call_site) {
    const char* func_name = addr2name(func_address); 
    if (func_name) {
        std::cout << "simple tracer: enter - " << func_name << std::endl;
    }
    else
    {
        std::cout << "simple tracer: enter - " << "some_func" << std::endl;
    }
}

void __cyg_profile_func_exit(void* func_address, void* call_site) {
    const char* func_name = addr2name(func_address); 
    if (func_name) {
        std::cout << "simple tracer: exit  - " << func_name << std::endl;
    }
    else
    {
        std::cout << "simple tracer: exit - " << "some_func" << std::endl;
    }
}

実行結果は以下です。

success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: exit - some_func
success dladdr
simple tracer: exit - some_func
success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: exit - some_func
success dladdr
simple tracer: enter - some_func
success dladdr
simple tracer: exit - some_func
success dladdr
simple tracer: exit - some_func
success dladdr
simple tracer: exit - some_func
2
success dladdr
simple tracer: exit - some_func

関数名が取れていないのですがどうすれば関数名が取れるでしょうか

追記
@774RRさんのコメントを受けて
試験環境はcygwin64でコンパイルリンクは以下です。

all:
    g++ -fPIC -shared simpletrace.cpp -o libsimpletrace.so
    g++ -fPIC -finstrument-functions main.cpp libsimpletrace.so -o main 
    ./main.exe

確かに参考ページと違うことをやっていたので書くべきでした。
参考ページの

g++ -fPIC -finstrument-functions main.cpp -o main 

はリンクが通らなかったのでlibsimpletrace.soをくっつけました。

追記

関数のアドレスを表示するようにしてrubyで簡単な変換かけるようにしてみました。

#convert.rb

open(ARGV[0]).readlines.each{|f|
    s=f.scan(/[0-9a-f]{8}/)
    if(s.size>=1)
    then
        printf f.chomp+" "
        print `grep #{s[0]} main.map | grep -v .text`
    else
        print f
    end
}

makefile

all:
    g++ -fPIC -shared simpletrace.cpp -o libsimpletrace.so
    g++ -fPIC -finstrument-functions main.cpp libsimpletrace.so -o main -Xlinker -Map=main.map
    ./main.exe > log.txt
    ruby convert.rb log.txt

実行結果

success dladdr
simple tracer: enter - 0x100401293 success dladdr
simple tracer: enter - 0x1004011f9 success dladdr
simple tracer: exit  - 0x1004011f9 success dladdr
simple tracer: exit  - 0x100401293 success dladdr
simple tracer: enter - 0x100401167                 0x0000000100401167                main
success dladdr
simple tracer: enter - 0x100401080                 0x0000000100401080                a()
success dladdr
simple tracer: enter - 0x1004010e4                 0x00000001004010e4                b()
success dladdr
simple tracer: enter - 0x100401123                 0x0000000100401123                c()
success dladdr
simple tracer: exit  - 0x100401123                 0x0000000100401123                c()
success dladdr
simple tracer: enter - 0x100401123                 0x0000000100401123                c()
success dladdr
simple tracer: exit  - 0x100401123                 0x0000000100401123                c()
success dladdr
simple tracer: exit  - 0x1004010e4                 0x00000001004010e4                b()
success dladdr
simple tracer: exit  - 0x100401080                 0x0000000100401080                a()
2
success dladdr
simple tracer: exit  - 0x100401167                 0x0000000100401167                main

やりたかったことはほぼ実現できることがわかりました。
ありがとうございました。

4
  • 動作環境や使用条件が提示されない方が、考える範囲が広すぎて助言・回答が難しくなるのでは? あるいは何をやりたいのか/何に困っているのか/どういう物が望ましいのか、と言ったことを追記されるのも良いと思われます。
    – kunif
    2021年4月5日 11:33
  • 2
    参考:GCCのコンパイルオプションで関数トレーサ
    – user39889
    2021年4月5日 11:54
  • 1
    hppa2.0w-hp-hpux11.11-gcc-9.2.0 では関数名が出せましたが cygwin x64 では関数名が出せませんでした。あとあなたのところで具体的にどうコンパイル・リンクしたのか手順が載っていないので shared-library に正しくなっているかどうか不明です。やはり試験環境をきっちり掲載するのは大事なようです。
    – 774RR
    2021年4月6日 7:43
  • 全般的にはAspect-oriented programmingというのがあるらしいですね。こちらC++の記事 Logging/monitoring all function calls... とVC++2015でのライブラリ PrakaramJoshi/Interceptor C#での記事 How do I intercept a method call in C#? と商業製品 PostSharp[Framework] と使用例? ...Using C# and PostSharp
    – kunif
    2021年4月7日 0:20

1 件の回答 1

1

コメントならびに元発言の編集結果から回答の形でまとめておきます

まずそのようなログを取ってどう活用するのか(活用できるのか)がかなり疑問です。

  • ログが大規模になって分析に困難がある
  • ログを取得することで動作速度が変わる可能性が高くリアルタイム用途には向かなそう
  • 排他制御部などでログを取る関数を呼ぶとデッドロックしたりしてうまくないかもしれない
  • イベントハンドラなど「ライブラリ・システムによって呼ばれる」関数は、呼ばれたことはわかっても「どこから」呼ばれたかは(呼び出し元は自作プログラムの外なので)わからないであろう
  • 関数のインライン展開結果に対してどこまでログが信頼できるか・役立つか、わからない
  • 自作だけどデバッグ済み下請け関数などのログは不要なことが多い
  • 他人作でデバッグ済みだけどライブラリ関数が呼ばれるログが欲しいこともある
  • ASLR 有効時には分析に注意

というのはまず指摘しておいて

には -finstrument-functions というコンパイルオプション があって、これを指定すると

  • 関数入口で void __cyg_profile_func_enter(void *this_fn, void *call_site) が呼ばれる
  • 関数出口で void __cyg_profile_func_exit(void *this_fn, void *call_site) が呼ばれる
  • 1個目の引数はシンボルテーブル上の関数入口アドレスに一致する
  • ので、これらの関数をプログラマが自作すると呼出しログなり実行時間なりが取れる

とあります。

んで、ログを取る関数の中のログを取っても邪魔なだけだったりしますし、先に述べたようにログを取ること自体がまずい箇所もあるので、そういう箇所は -finstrument-functions-exclude-file-finstrument-functions-exclude-function-list 等で除外する必要があります。が、これらを使うには事前の調査を行ったうえでの列挙が必要だったりするので、全体像がよくわからないうちはログを出力する関数などを -finstrument-functions コンパイルオプションなしでコンパイルした別 DLL / so に追い出すなどすると便利かもしれません。というあたりの前提条件を全略したうえでの解説記事がコメント中に張られていますね。

で、実行環境によっては、実行中に dladdr() 関数呼び出しで関数へのポインタ値から関数名を知ることができる (hppa2.0w-hp-hpux11.11-gcc-9.4.0 ではできた) のですが、実行環境によってはできない (3.1.7(0.340/5/3) 2020-08-22 17:48 x86_64 Cygwin ではできなかった) という実測結果があります。
# 注意:コメント内リンク先の記事では自動変数へのポインタを返却して使っている大バグがあります!

は今の時点で dladdr() の実装が不完全のようなので、ログ取得後にアドレス→シンボルに変換するツールをかませれば良さそうです。変換テーブルが必要ですのでリンクの際にマップファイルを生成するとよいでしょう。

g++ -fPIC -finstrument-functions main.cpp libsimpletrace.so -o main -Xlinker -Map=main.map

としておくとリンクマップなるものが作成され、関数名と関数アドレスの対比表などもこのマップファイルの中に含まれます。簡単な変換ソフトを自作してアドレス→シンボル変換してやるとよいでしょう。

この質問に回答するには、ログインする必要があります。

求めていた回答ではありませんか? のタグが付いた他の質問を参照する。