75128


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

[code]

    #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();
    }
    
[/code]

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

[code]

    call a
    call b
    call c
    return c
    call c
    return c
    return b
    return a
    
[/code]

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

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

[code]

    //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;
        }
    }
    
[/code]

実行結果は以下です。

[code]

    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
    
[/code]

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

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

[code]

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

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

[code]

    g++ -fPIC -finstrument-functions main.cpp -o main 
    
[/code]

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

追記

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

[code]

    #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
    }
    
[/code]

makefile

[code]

    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
    
[/code]

実行結果

[code]

    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
    
[/code]

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


CC BY-SA 4.0
2021-04-05T08:34:28.650
75094
2021-04-07T04:12:02.557
2021-04-07T04:12:02.557
18637
18637
question
debugging
実行ログを自動生成するツール


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

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

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

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

[gcc](/questions/tagged/gcc "'gcc' のタグが付いた質問を表示") には `-finstrument-functions`
という[コンパイルオプション](https://gcc.gnu.org/onlinedocs/gcc-9.3.0/gcc/Instrumentation-
Options.html) があって、これを指定すると

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

とあります。

んで、ログを取る関数の中のログを取っても邪魔なだけだったりしますし、先に述べたようにログを取ること自体がまずい箇所もあるので、そういう箇所は
`-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` ではできなかった) という実測結果があります。  
# 注意：コメント内リンク先の記事では自動変数へのポインタを返却して使っている大バグがあります！

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

[code]

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

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


CC BY-SA 4.0
2021-04-07T01:43:29.703
75128
2021-04-07T01:43:29.703
8589
75094
answer