LINUX.ORG.RU

Трассировка вызова функций - Call Нunter

 , , трассировка,


0

1

Разбирал тут хлам и нашёл у себя пару поделок для трассировки вызова функций, я уже не помню что я именно хотел, вроде хотел отладить что-то замудрёное и не понимал кто кого вызывает поэтому понавтыкал трассировку, но да ладно может кому пригодится. Суть есть короткие макросы которые вставляются в конец и начало функций, и всё. При работе программы будет показано кто кого вызывает. Реализаций две, чуть разные и чуть по разному показывают. Есть ограничение на количество вызовов, в первой реализации запись вызовов явно ограничена и при превышении будет неточность так как вызовы записываются все, во второй чуть получше, там подход к фреймам вызовов и они лишь должны уместится в размер фрейма, но нет полной трассировки как в первом случае. Ну компромисс, либо так, либо сяк. По сути, это ненужный тупак, но в своё время мне помогло. Каталог в котором валялись сорцы я в своё время назвал пафосно и по детски call hunter типа охотник за вызовами или позвоните Хантеру хехехех :D Ой лол, ладно. Пусть как есть так и будет, чё уж там :D Ну, ну и всё.

Первый вариант

#include <stdio.h>
#include <string.h>
#include <stdlib.h>
#define IDXMAX 1062

#define RS static struct { int ok; char * file; char *  func;}HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__= {.file = __FILE__, .func = (char*)&__func__,.ok=1};\
hunter_record_start((void *)&HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__);\

#define RE { HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__.ok = 0; hunter_record_end(); };\

unsigned long long idx = 0;
struct hunter_call
{
     int    ok;
     char * file;
     char * func;
};

struct hunter_record_data
{
    struct hunter_call * call;
    unsigned long long parent;
};

struct hunter_record_data  record[IDXMAX];

unsigned long long curent=0;

void hunter_print()
{
    for (int i = 0; i < idx; ++i)
    {
        unsigned long long prev = record[i].parent;
        unsigned long long prev_index = 0;
        while(record[prev].call != record[0].call)
        {
            prev = record[prev].parent;
            prev_index++;
        }
        while(prev_index--)
        {
            printf("│   ");
        }
        if(i==0)
        {
            printf("┣━━━━━━ frame ━━━━━━━>\n");
            printf("%s:%s() \n",record[i].call->file,record[i].call->func);
        }else{
            printf("└─> %s:%s() \n",record[i].call->file,record[i].call->func);
        }
     }
     unsigned long long prev = record[curent].parent;
     unsigned long long prev_index = 0;
     while(record[prev].call != record[0].call)
     {
         prev = record[prev].parent;
         prev_index++;

     }
     prev_index++;
     while(prev_index--)
     {
        printf("│   ");
     }
     printf("┗━> backtrace from ━━━> %s:%s() \n",record[curent].call->file,record[curent].call->func);
}

int overflow = 0;
unsigned long long overflow_count=0;
void hunter_record_start(void * data)
{
    struct hunter_call * hunter = (struct hunter_call*)data;
    if(idx == IDXMAX-1)
    {
      printf("============ stack is full, please set '#define IDXMAX %lld' for more data ===========\n",++overflow_count+IDXMAX);
      overflow=1;
      return;

    }else{
        record[idx].call = hunter;
        record[idx].parent = curent;
        curent = idx;
        idx++;
    }
}

void hunter_record_end()
{
  if(overflow)
  {
      return;
  }
  if(record[curent].call->ok != 0)
  {
      printf("\n In file -> %s in funtion -> %s() not set 'RE' \n\n",record[curent].call->file,record[curent].call->func);
      exit(1);
  }
  curent = record[curent].parent;
}
/*
#undef  RS
#define RS

#undef RE
#define RE
*/
void function_5() {RS   hunter_print(); RE}
void function_4() {RS   int x= 10; while(x--) function_5();  RE}
void function_3() {RS   function_4();  function_4(); function_4();  RE}
void function_1() {RS   function_3();   RE}
void function_2() {RS   function_1();  function_1(); function_1();  RE}
int main()
{
   RS
   for (int i = 0; i < 2; ++i)
   {
       function_2();
   }
   RE
}

Выхлоп будет такой.

...
│   └─> cc.c:function_1() 
│   │   └─> cc.c:function_3() 
│   │   │   └─> cc.c:function_4() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   └─> cc.c:function_4() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   └─> cc.c:function_4() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   └─> cc.c:function_5() 
│   │   │   │   │   ┗━> backtrace from ━━━> cc.c:function_5()

Вторая реализация

#include <stdio.h>
#include <string.h>
#include <stdlib.h>
#include <time.h>
#include <unistd.h>

#if defined( _WIN32)  || defined( _WIN64 )  || defined( __CYGWIN__ )
#include <windows.h>
#endif
enum
{
  RED     = 31,
  GREEN   = 32,
  YELLOW  = 33,
  BLUE    = 34,
  PURPULE = 35,
  AQUA    = 36,
  DEFAULT = 39,
};

//-----------------------------------------------------------------------------
static void colorset(int color)
{
#if defined( __unix__  )
    if(isatty(fileno(stderr)) && isatty(fileno(stdout)))
    {
        printf("\x1B[%dm",color);
    }
#elif defined( _WIN32)  || defined( _WIN64 )  || defined( __CYGWIN__ )
    HANDLE handle_1 = (HANDLE) _get_osfhandle(fileno(stdout));
    DWORD mode_1;
    HANDLE handle_2 = (HANDLE) _get_osfhandle(fileno(stderr));
    DWORD mode_2;
    if(GetConsoleMode(handle_1,&mode_1) && GetConsoleMode(handle_2,&mode_2))
    {
       printf("\x1B[%dm",color);
    }
#endif
}

#define IDXMAX 127

#define RS \
struct hunter_call\
{\
     int    ok;\
     char * file;\
     char * func;\
     struct hunter_call * parent;\
     struct hunter_call * children;\
     time_t time_s;\
     time_t time_e;\
     unsigned long calls;\
};\
static struct hunter_call HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__= {.calls=0,.file = __FILE__, .func = (char*)&__func__,.ok=1,.parent=NULL,.children=NULL,.time_e=0,.time_s=0};\
hunter_record_start((void *)&HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__);\
HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__.time_s = clock();\

#define RE  HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__.time_e =clock();  HUNTER_RECORD_TOKEN##__FILE__##__LINE__##__func__.ok = 0; hunter_record_end(); \


unsigned long long idx = 0;
struct hunter_call
{
     int    ok;
     char * file;
     char * func;
     struct hunter_call * parent;
     struct hunter_call * children;
     time_t time_s;
     time_t time_e;
     unsigned long calls;
};

struct hunter_call * record = NULL;
struct hunter_call * curent = NULL;

void hunter_print( )
{
    setbuf(stdout,NULL);
    curent->time_e = clock();

    struct hunter_call * buff = record;
    while(buff != NULL)
    {
        if(buff == record)
        {
            colorset(AQUA);
            printf("┣━━━━━━ frame ━━━━━━━> \n");
            colorset(DEFAULT);
            printf("%s:%s()",buff->file,buff->func);
            colorset(GREEN);
            printf(" time %f sec (calls %ld)\n", difftime(curent->time_e,buff->time_s)/CLOCKS_PER_SEC,buff->calls);
            colorset(DEFAULT);
        }else{
            printf("└─> %s:%s()",buff->file,buff->func);
            colorset(GREEN);
            printf(" time %f sec (calls %ld)", difftime(curent->time_e,buff->time_s)/CLOCKS_PER_SEC,buff->calls);
            colorset(DEFAULT);
            if(buff == curent)
            {
                printf(" ──>\n");
            }else{
                printf("\n");
            };
        }
        if(buff == curent) {break;}
        buff = buff->children;
    }
    colorset(YELLOW);
    printf("┗━> backtrace from ━━━> %s:%s() \n",curent->file,curent->func);
    colorset(DEFAULT);
}

int overflow = 0;
unsigned long long overflow_count=0;
void hunter_record_start(void * data)
{
    colorset(DEFAULT);
    struct hunter_call * hunter = (struct hunter_call*)data;
    if(curent == NULL)
    {
        curent = hunter;
        hunter->parent   = NULL;
        curent = hunter;
        record = curent;
        hunter->calls++;
    }else if(curent != hunter){
        curent->children = hunter;
        hunter->parent   = curent;
        curent = hunter;
        hunter->calls++;
    }
}

void hunter_record_end()
{
    colorset(DEFAULT);
    if(curent->ok != 0)
    {
        printf("\n In file -> %s in funtion -> %s() not set 'RE' \n\n",curent->file,curent->func);
        exit(1);
    }
    curent = curent->parent;
}
#define HP hunter_print();
/*
#undef  RS
#define RS

#undef RE
#define RE

#undef HP
#define HP
*/
void function_x() {RS  int x=1000000; while(x--){};  HP  RE}
void function_5() {RS  function_x();  HP   RE}
void function_4() {RS  function_5();   function_5(); function_5();  HP RE}
void function_3() {RS  function_4();  HP  RE}
void function_1() {RS  function_3(); HP RE}
void function_2() {RS  function_1();  function_1(); function_1(); HP RE}
void function_6() {RS  function_4();  function_2(); HP RE}
int main()
{
   RS
   for (int i = 0; i < 2; ++i)
   {
     function_6();
   }
   RE
}

Выхлоп

┣━━━━━━ frame ━━━━━━━> 
cc-list.c:main() time 0.006517 sec (calls 1)
└─> cc-list.c:function_6() time 0.006508 sec (calls 1)
└─> cc-list.c:function_4() time 0.006503 sec (calls 1)
└─> cc-list.c:function_5() time 0.006499 sec (calls 1)
└─> cc-list.c:function_x() time 0.006495 sec (calls 1) ──>
┗━> backtrace from ━━━> cc-list.c:function_x() 
┣━━━━━━ frame ━━━━━━━> 
cc-list.c:main() time 0.006615 sec (calls 1)
└─> cc-list.c:function_6() time 0.006606 sec (calls 1)
└─> cc-list.c:function_4() time 0.006601 sec (calls 1)
└─> cc-list.c:function_5() time 0.006597 sec (calls 1) ──>
┗━> backtrace from ━━━> cc-list.c:function_5() 
┣━━━━━━ frame ━━━━━━━> 
cc-list.c:main() time 0.009705 sec (calls 1)
└─> cc-list.c:function_6() time 0.009696 sec (calls 1)
└─> cc-list.c:function_4() time 0.009691 sec (calls 1)
└─> cc-list.c:function_5() time 0.002997 sec (calls 2)
└─> cc-list.c:function_x() time 0.002995 sec (calls 2) ──>
┗━> backtrace from ━━━> cc-list.c:function_x() 
┣━━━━━━ frame ━━━━━━━> 
cc-list.c:main() time 0.009788 sec (calls 1)
└─> cc-list.c:function_6() time 0.009779 sec (calls 1)
└─> cc-list.c:function_4() time 0.009774 sec (calls 1)
└─> cc-list.c:function_5() time 0.003080 sec (calls 2) ──>
┗━> backtrace from ━━━> cc-list.c:function_5() 
┣━━━━━━ frame ━━━━━━━> 
cc-list.c:main() time 0.012853 sec (calls 1)
└─> cc-list.c:function_6() time 0.012844 sec (calls 1)
└─> cc-list.c:function_4() time 0.012839 sec (calls 1)
└─> cc-list.c:function_5() time 0.002990 sec (calls 3)
└─> cc-list.c:function_x() time 0.002986 sec (calls 3) ──>
┗━> backtrace from ━━━> cc-list.c:function_x() 
┣━━━━━━ frame ━━━━━━━> 
cc-list.c:main() time 0.012935 sec (calls 1)
└─> cc-list.c:function_6() time 0.012926 sec (calls 1)
└─> cc-list.c:function_4() time 0.012921 sec (calls 1)
└─> cc-list.c:function_5() time 0.003072 sec (calls 3) ──>
┗━> backtrace from ━━━> cc-list.c:function_5() 

...

Валяется уже давно, я не уверен что оно вообще доделано.
Мне даже свой код читать лень :D.
Но раз лежит мёртвым грузом, то можно и выложить. Вдруг, кому нечто подобное надо. Выкладываю как есть, лишь проверил что оно компилируется и работает.
Но нужно допиливать, только вот мне уже это ненужно. По крайней мере сейчас.
Вроде всё. Досвиданья.

Ответ на: комментарий от ox55ff

Если чуток переделать можно использовать только 1 макрос на входе функции и всё. Второй это лично моя излишняя явность. Ведь вход в функцию одновременно означает выход из другой, если таковая имелась.

Насколько же всё таки c++ программисты белые со своим RAII.

Наверное, но есть gdb и прочие штуки, которые покажут, что, куда, как и зачем. Тут просто шляпа ситуативная, для каких-то уж совсем частных случаев.

LINUX-ORG-RU ★★★★★
() автор топика

Для трассировки без изменения исходников есть uftrace.

Для трассировки с явной расстановкой «зондов» есть супербыстрый lttng, который можно оставлять включенным в проде, не боясь что он что-то замедлит, по крайней мере пока не будет включена запись (и даже в этом случае основная нагрузка и I/O лягут на вспомогательный процесс, а не на рабочее приложение).

annulen ★★★★★
()
Ответ на: комментарий от ox55ff

Если в функции два return, то нужно будет перед каждым макрос вставлять?

У сишников нет деструкторов, поэтому вместо двух return пишут goto в конец)

annulen ★★★★★
()

Суть есть короткие макросы которые вставляются в конец и начало функций, и всё.

Зачем вставлять костыли и марать код? Компиль ведь умеет вставлять хелперы самостоятельно -finstrument-functions и смежные.

kvpfs_2
()
Последнее исправление: kvpfs_2 (всего исправлений: 1)
18 апреля 2024 г.