Лог запуска функций при помощи GCC

Давайте представим, что вы делаете устройство, которое должно работать годами, но почему-то процесс вылетает через некоторое время без сообщения причин.
Ситуация довольно распространенная в мире встраиваемых систем. И если при программировании для микроконтроллеров такая ситуация решается при помощи сторожевого таймера (watchdog), то тут такой подход не подойдет. Ведь система не зависла, просто планировщик завершил один процесс.
Есть выход подобный сторожевому таймеру — супервизор. Вы создаете отдельное ПО, которое будет следить за тем, выполняется ли ваша программа и если нет, сигнализировать/перезапускать/выключаться и так далее.
Но это все не решает корня проблемы. Почему вылетает ПО?
Само по себе оно этого не сделает. На то есть причины. Самая обыденная — указатель, который пытается получить доступ к чужой памяти. Но как это отследить?
В принципе ответ напрашивается сам. Необходимо вести лог запуска функций. Самый простой вариант для этого — разметистить в начале и конце функции, которые пишут в лог имя функции и время. Но это рутинно и очень долго.
К счастью в GCC есть метод сделать это практически автоматически. Для этого можно использовать конструктор и деструктор функции.
Для этого ваш компилятор должен быть собран с флагом

-finstrument-functions

В большинстве дистрибутивов Linux компилятор поставляется с этим флагом.

Давайте рассмотрим на примере как реализовать логирование запуска функций при помощи GCC.
Создайте файл main.c

#include <stdio.h>
 
void foo() {
    printf("foo\n");
}
 
int main() {
    foo(); 
    return 0;
}

Самый обычный hello world.
Теперь нужно оприделить функции логирования.
Писать лог будем в файл.
trace.c:

#include 
#include 
 
static FILE *fp_trace;
 
void __attribute__ ((constructor)) trace_begin(void)
{
    fp_trace = fopen("trace.out", "w");
}
 
void __attribute__ ((destructor)) trace_end(void)
{
    if(fp_trace != NULL) 
    {
        fclose(fp_trace);
    }
}
 
void __cyg_profile_func_enter(void *func,  void *caller)
{
    if(fp_trace != NULL) 
    {
        fprintf(fp_trace, "e %p %p %lu\n", func, caller, time(NULL) );
    }
}
 
void __cyg_profile_func_exit(void *func, void *caller)
{
    if(fp_trace != NULL)
    {
        fprintf(fp_trace, "x %p %p %lu\n", func, caller, time(NULL));
    }
}

Две последние функции выполняются при входе/выходе из каждой вашей функции и записывают в файл адрес функции, откуда она вызвана и время. Также при помощи символов e и x метится вход это или выход.

Компилируем.

$ gcc -finstrument-functions -g -c -o main.o main.c
$ gcc -c -o trace.o trace.c
$ gcc main.o trace.o -o main

После запуска main вы увидите в текущем каталоге файл trace.out следующего содержания.

e 0x4006f8 0x7f604e869fe0 1420879817
e 0x4006c6 0x40071c 1420879817
x 0x4006c6 0x40071c 1420879817
x 0x4006f8 0x7f604e869fe0 1420879817

Это уже необходимые нам данные. Но формат конечно оставляет желать лучшего. И тут есть два пути хардкорный — смотреть в map файле что и откуда вызвано или же воспользоваться утилитой addr2line.
Забугорные товарищи же вообще предлагают такой скрипт:

#!/bin/sh
if test ! -f "$1"
then
 echo "Error: executable $1 does not exist."
 exit 1
fi
if test ! -f "$2"
then
 echo "Error: trace log $2 does not exist."
 exit 1
fi
EXECUTABLE="$1"
TRACELOG="$2"
while read LINETYPE FADDR CADDR CTIME; do
 FNAME="$(addr2line -f -e ${EXECUTABLE} ${FADDR}|head -1)"
 CDATE="$(date -Iseconds -d @${CTIME})"
 if test "${LINETYPE}" = "e"
 then
 CNAME="$(addr2line -f -e ${EXECUTABLE} ${CADDR}|head -1)"
 CLINE="$(addr2line -s -e ${EXECUTABLE} ${CADDR})"
 echo "Enter ${FNAME} at ${CDATE}, called from ${CNAME} (${CLINE})"
 fi
 if test "${LINETYPE}" = "x"
 then
 echo "Exit  ${FNAME} at ${CDATE}"
 fi
done < "${TRACELOG}"

Получаем уже человекочитабельный результат.

$ ./readtracelog.sh main trace.out 
Enter main at 2015-01-10T10:50:17+0200, called from ?? (??:0)
Enter foo at 2015-01-10T10:50:17+0200, called from main (hello.c:9)
Exit  foo at 2015-01-10T10:50:17+0200
Exit  main at 2015-01-10T10:50:17+0200

Вот и все. Надюсь поможет.