AlexBR

Попробую написать утилитку, которая бы отслеживала путь выполнения программы, не так подробно как ltrace, но все же существенно более быстро.

А так же попробую воспользоваться функциями.

1 Напишу функцию, которая аналогична indent, но с собственным алгоритмом формирования смещения:

function local_depth() {
    ind = ""
    for (i=depth[tid()];i>=0;i--){
        ind = sprintf("%s|", ind)
    }
    ind = ind . ">"
    return ind
}

Результат выполения функции - это строка отступа для текущего потока с учетом глубины вложенности. Т.е сведения о глубине хранятся в массиве depth с ключем tid(), т.е идентификатором текущего потока. Результат примерно выглядит так |||> или |||||||>

2 Непосредственно сами функции формирования информации о текущем местонахождении:

function out_info(func_name, vars_list, fid) {
    dbg = get_debug_info()
    if (dbg != "") {
        dbg = " >>>".dbg
    }
    printf("%s(%10d) uid(%5d):%s%s[%d](%s) %s%s\n", func_name, tid(), uid(), local_depth(), ppfunc(), fid, execname(), vars_list, dbg)
}

function out_info_return(func_name, vars_list, fid) {
    printf("%s(%10d) uid(%5d):|%s%s[%d](%s) ret +----> %s\n", func_name, tid(), uid(), local_depth(), ppfunc(), fid, execname(), vars_list)
}

Функции используют механизмы форматирования printf. И выводит стандартный, ранее рассматриваемый набор функций: tid, uid, ppfunc. Как раз здесь вызывается функция создания отступа, рассмотренна ранее local_depth.

Входные параметры функций:

  1. имя которое будет выведено вначале и при анализе может понадобится для фильтрации,
  2. список переменных локальных
  3. идентификатор, присвоенный функции программы(не проба), при входе в нее.

Идентификатор - это число одинаковое для входа функции и выхода из нее. Т.к. вход и выход могут быть не сразу друг за другом, по идентификатору можно будет определить когда был произведен вход. Даже если функция вызывалась рекурсивно.

3 Функция погружения и выхода из подпрограммы:

function work_depth_push(){
    #fn = sprintf("%s", ppfunc())
    foreach (val in skip){
        if(is_current_function(skip[val])==0) return 0
    }
    s_tid = tid()
    if (!@defined( depth[s_tid])) {
        depth[s_tid] = 0
    }
    cnt = counter++
    names[s_tid, depth[s_tid]++] = cnt
    return cnt
}

function work_depth_pop(){
    foreach (val in skip){
        if(is_current_function(skip[val])==0) return 0
    }
    s_tid = tid()
    if (!@defined( depth[s_tid])) {
        depth[s_tid] = 0
    }
    cnt = 0
    if (depth[s_tid] > 0 ) {
        cnt = names[s_tid, depth[s_tid]-1]
        delete names[s_tid, --depth[s_tid]]
    }
    return cnt
}

Первая функция производит манипуляции, необходимые для учета и отображения при вызове в ослеживаемой программе любой функции, вторая делает манипуляции, чтоб очистить, то что насоздавала первая функция. Функции возвращают тот уникальный идентификатор, который описывался ранее, для учета входа и выхода из функции.

В начале этих двух функций вызывается is_current_function, которая проверяет, является ли текущее место тем которое нужно игнорировать. Список игнорирования - это skip.

Сведения о погруженных функциях и идентификаторе сохранются в массив names[tid, number].

4 Сами probes, которые говорят куда наша программка должна встроиться:

probe process("*").function("*").call {
    fid = work_depth_push()
    if (fid==0) next
    vrs = sprintf("%s", $$vars)
    ap_name = sprintf("%7s", execname())
    out_info(ap_name, vrs, fid)
}

probe process("*").function("*").return {
    fid = work_depth_pop()
    if (fid==0) next
    vrs = sprintf("%s", $$return)
    ap_name = sprintf("%7s", execname())
    out_info_return(ap_name, vrs, fid)
}

Мы прикрепляемся ко всем процессам, ко всем вызовам функций, а так же к результату возвращаемому функциями - это методы .call и .reurn. В самих в начале для проверки и подготовки данных вызываются work_depth_push и work_depth_pop. Если идентификатор не создан, т.е fid=0, то методом next, мы пропускаем probe. Получаем возвращаемое значение $$return или список локальных переменных $$vars и передаем их ранее рассмотренным функциям формирования вывода.

В массив skip в probe begin заносятся имена функций, которые не будут попадать в общий вывод программы:

    skip[0] = "ap_get_scoreboard_process"
    skip[1] = "ap_get_scoreboard_worker_from_indexes"

Пример запуска:

С параметром --ldd и -w, чтоб отладочная информация подтягивалась из библиотек и игнорировались предпреждения:

[systemtap]# stap fstrace.stp --ldd -w -c "./tst"
Function tracer
Waiting for even or Ctrl+C
    tst(     35561) uid(    0):||>_start[1](tst)
    tst(     35561) uid(    0):|||>__libc_csu_init[2](tst)
    tst(     35561) uid(    0):||||>_init[3](tst)
    tst(     35561) uid(    0):||||>_init[3](tst) ret +---->
    tst(     35561) uid(    0):||||>frame_dummy[4](tst)
    tst(     35561) uid(    0):|||||>register_tm_clones[5](tst)
    tst(     35561) uid(    0):|||||>register_tm_clones[5](tst) ret +---->
    tst(     35561) uid(    0):||||>frame_dummy[4](tst) ret +---->
    tst(     35561) uid(    0):|||>__libc_csu_init[2](tst) ret +---->
    tst(     35561) uid(    0):|||>main[6](tst) test=[...] data=0x0
    tst(     35561) uid(    0):||||>memory_fill[7](tst) src=0x7ffdc4a90b00 dest=0x1904010 len=0x400 buff=[...]
    tst(     35561) uid(    0):||||>memory_fill[7](tst) ret +---->
    tst(     35561) uid(    0):|||>main[6](tst) ret +----> return=0x0
    tst(     35561) uid(    0):|||>__do_global_dtors_aux[8](tst)
    tst(     35561) uid(    0):||||>deregister_tm_clones[9](tst)
    tst(     35561) uid(    0):||||>deregister_tm_clones[9](tst) ret +---->
    tst(     35561) uid(    0):|||>__do_global_dtors_aux[8](tst) ret +---->
    tst(     35561) uid(    0):|||>_fini[10](tst)
    tst(     35561) uid(    0):|||>_fini[10](tst) ret +---->

И второй пример, над той же программкой из стати, но с дополнительным параметром ext=on:

[systemtap]# stap fstrace.stp ext=on --ldd -w -c "./tst"
Function tracer
Waiting for even or Ctrl+C
    tst(     35798) uid(    0):||>_start[1](tst)  >>>0x400540
    tst(     35798) uid(    0):|||>__libc_csu_init[2](tst)  >>>0x400730
    tst(     35798) uid(    0):||||>_init[3](tst)  >>>0x4004a8
    tst(     35798) uid(    0):||||>_init[3](tst) ret +---->
    tst(     35798) uid(    0):||||>frame_dummy[4](tst)  >>>0x400600
    tst(     35798) uid(    0):|||||>register_tm_clones[5](tst)  >>>0x4005a0
    tst(     35798) uid(    0):|||||>register_tm_clones[5](tst) ret +---->
    tst(     35798) uid(    0):||||>frame_dummy[4](tst) ret +---->
    tst(     35798) uid(    0):|||>__libc_csu_init[2](tst) ret +---->
    tst(     35798) uid(    0):|||>main[6](tst) test=[...] data=0x0 >>>/check/systemtap/1.c:12
    tst(     35798) uid(    0):||||>memory_fill[7](tst) src=0x7ffe9b5ade40 dest=0x7ba010 len=0x400 buff=[...] >>>/check/systemtap/1.c:6
    tst(     35798) uid(    0):||||>memory_fill[7](tst) ret +---->
    tst(     35798) uid(    0):|||>main[6](tst) ret +----> return=0x0
    tst(     35798) uid(    0):|||>__do_global_dtors_aux[8](tst)  >>>0x4005e0
    tst(     35798) uid(    0):||||>deregister_tm_clones[9](tst)  >>>0x400570
    tst(     35798) uid(    0):||||>deregister_tm_clones[9](tst) ret +---->
    tst(     35798) uid(    0):|||>__do_global_dtors_aux[8](tst) ret +---->
    tst(     35798) uid(    0):|||>_fini[10](tst)  >>>0x4007a4
    tst(     35798) uid(    0):|||>_fini[10](tst) ret +---->

В выводе появилась отладочная информация: >>>/check/systemtap/1.c:6

Полный текс скрипта можно скачаь здесь.