Backtrace of a glib app stops at g_logv

[pcph]

Greetings everyone, here is a rather long-winded explanation of the problem I am experiencing. I am using GNU gdb 6.3, glib 2.6.3 and gcc 3.4.1.

This problem has to do with, I believe, either gdb or the glib logging functions. Sometimes my application crashes with weird/random errors, but the backtrace (in a core dump) I get when this happens is not helpful at all. Here is a sample backtrace:

(gdb) bt
#0 0xffffe410 in ?? ()
#1 0xb3c5134c in ?? ()
#2 0x00000006 in ?? ()
#3 0x00001526 in ?? ()
#4 0xb739db41 in raise () from /lib/libc.so.6
#5 0xb739f299 in abort () from /lib/libc.so.6
#6 0x0805f272 in jukeui_log_handler (log_domain=0xb779fc7e "GThread", log_level=6,
message=0xa2df6a0 "file gthread-posix.c: line 160 (): error 'Device or resource busy' during 'pthread_mutex_destroy ((pthread_mutex_t *) mutex)'", user_data=0x0) at ./src/jukemain.c:89
#7 0xb77f7dd2 in g_logv () from /usr/lib/libglib-2.0.so.0
#8 0xb779f644 in ?? () from /usr/lib/libgthread-2.0.so.0
(gdb) quit

jukeui_log_handler is a function I set as the default log handler using g_log_set_default_handler. The actual message that is being logged (about a mutex being busy) has no relevance as I get various core dumps with different messages.

Looking at the code of g_logv, it calls the default log handler (my function) then, if the log entry has the FATAL flag set, it calls abort. In order to get a more complete backtrace, I added a call to abort in my log function so I can see in the backtrace the message that was being logged. For simplicity, we can remove entry #6 in the above backtrace as that is what I would get when I remove the abort in my code.

Now, when googling for this problem, I have seen a number of backtraces that go beyond g_logv, the next entry being g_log, then whatever functions the program was in. The fact that glib is compiled with debugging information or not doesn't seem to make a difference, as I have seen backtraces with both.

If I happen to run my program in gdb and break on g_log, I get a meaningful, complete backtrace. I noticed that g_log calls va_start then calls g_logv. As soon as I break on g_logv, everything before that is lost and I get a backtrace with 2 entries: g_logv and then either ?? or __PRETTY_FUNCTION__ (I believe I see __PRETTY_FUNCTION__ when debugging but not in cores, but don't quote me on that).

So, does anyone have an idea on how I could trace beyond g_logv?

P.S. If you want to reproduce this core on your machine, either enable core dumps or break on g_logv in gdb and try calling g_malloc(10000000000000) (any huge number that is higher than your memory). That will log a message and abort.

[pcph]

Well, I managed to find the cause for this. My version of glib was compiled with the -fomit-frame-pointer compiler flag, and this seems to cause the problem I was having. When I recompile glib without -fomit-frame-pointer, I get complete stack traces (regardless of presence of -g). My guess is that variable arguments require both stack registers, EBP and ESP, at least on my machine.

I've read some posts about the usage of the -fomit-frame-pointer, and the general opinion seems to be that it's a good optimization, but do not use it if you want to debug and have meaningful stack traces. Had I known this earlier...