Debugging

From Buzztard

Finding errors in complex applications needs help. here we gather tips, tricks and examples.

[edit] Debug Messages

To see whats going on inside your buzztard application you need some debugging support. Here we describe how you can use debugging support in buzztard and how to integrate in into your own code.

[edit] Writing debug messages

As buzztard uses gstreamer, we use their debugging methods. There are several general debug methods you can use:

• GST_LOG (level 5)
• GST_INFO (level 4)
• GST_DEBUG (level 3)
• GST_WARNING (level 2)
• GST_ERROR (level 1)

To generate a debug info use the GST_INFO method. For example to generate a debug info you can write following code:

 GST_INFO("buzztard starts with %d arguments\n",argc);

To generate a debug message use the GST_DEBUG method. For example to generate a debug message you can write following code:

 GST_DEBUG("failed to link the machines\n");

GST_WARNING and GST_ERROR are there to notify about problematic situations or definite errors.

[edit] Seeing the debug messages

Ok. You would like to see the debug messages? It is quite simple. To see all debug messages from gstreamer in Level 2 and from buzztard in Level 3 you can start your buzztard with following arguments:

 ./buzztard-edit --gst-debug="*:2,bt-*:3" song.bt

Attention! Following commandline will not produce the expected messages:

 ./buzztard-edit --gst-debug="*:3,bt-*:2" song.bt

You must use the levels in rising order 1 -> 2 -> 3 -> ...

To debug only buzztard in Level 3 you can start buzztard with following commandline option:

 ./buzztard-edit --gst-debug="bt-*:3" song.btz

[edit] Capturing the debug messages

Debug output can be a lot. And it sometimes wraps lines and so on. In such cases it would be nice to capture it and view it in a editor. Here is how to do it:

 ./buzztard-edit 2>debug.log --gst-debug-no-color --gst-debug="bt-*:4" --command=load --input-file=../share/buzztard/songs/buzz4.xml

I usually filter the output then by

 cat debug.log | sed -e 's/ \+/ /g' | sed -e 's/([ 0-9]*) / /g' | sed -e 's/^\([A-Z]\)[A-Z]*/\1/g' | cut -d' ' -f 1,5-

This removes timestamps, thread number and squeezes log-level.

[edit] Locating problems

[edit] Problems indicated by warnings/errors

During testing you might receive warnings in the console that you would like to trace. The plan is to trap the location with an error log statement and then make that statement fatal. This can be done with the following command:

 gdb --args ./buzztard-edit --gst-debug="*:2,bt-*:3" --g-fatal-warnings

[edit] Short gdb introduction

In gdb start the app with the run command (or the shortcut r). When the app stops due to the error, use the backtrace (bt) command to see from where it comes.

[edit] Problems revealed by unit tests

If the application to test is uninstalled (e.g. a unit-test), this is the trick to get it to work:

 libtool --mode=execute gdb ./bt_edit

If the binary is a unit test you should call it like this:

 env CK_FORK="no" libtool --mode=execute gdb ./bt_edit

Otherwise you wouldn't be able to get a stacktrace from gdb. Finnaly if you want gdb to stop on GLib warnings/criticals this may help:

 env CK_FORK="no" G_DEBUG="fatal_criticals" libtool --mode=execute gdb ./bt_edit

[edit] G_DEBUG stoppers:

If you want to find out whats the problem on a wraning or a fatal error you can use the following G_DEBUG stopper:

G_DEBUG="fatal_criticals"

G_DEBUG="warnings"

G_DEBUG="error"

We have tests that only fail in fork mode. To find out about this we try:

1.) enable core dumps and load those (seems to do work)

 ulimit -c 10000
 make check
 cd tests
 libtool --mode=execute gdb ./bt_edit -c core.xxxxx

2.) try to follow new processes in gdb (we still don't get stack traces)

 set follow-fork-mode child

[edit] Ressource usage

[edit] Debug GObject reference counting

Get the refdbg tool and install it. To find out about the ref-ct of e.g. BtSong instances, start the binary as below:

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBRARY_PATH \
 refdbg -c "btnum=8 r0=<BtSong> D:All L:All" ./buzztard-edit --gst-debug="*:2,bt-*:4"

Then look into refdbg.log.

Hint: This will only work if you have the glib compiled with the --disable-visibility flag which is for exmaple not the default in gentoo or other distributions.--waffel 15:18, 10 Jun 2005 (CEST)

Another way is to use it in conjunction with gdb:

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBRARY_PATH \
 refdbg -c "btnum=8 ; r0=B:Error" gdb --args ./buzztard-edit --gst-debug="*:2,bt-*:4"

In this example it interrupts program execution whenever an ref-couting error has been detected.

TO get a list of remaining object refs (and filter that somewhat):

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBRARY_PATH refdbg -c "btnum=4 r0= D:Error L:None" ./buzztard-edit
 cat refdbg.log | grep -v "Atk" | grep -v "Gdk" | grep -v "Gtk.*Style" | grep -v "GtkIMModule" | grep -v "GstPlugin" | grep -v "Gst.*Factory" | grep -v "GstPadTemplate" | grep -v "Pango" >refdeg.flt.log

Apart its useful to sprinkle this all over the sources:

 GST_DEBUG("object: %p refs: %d)",object,(G_OBJECT(object))->ref_count);

Below some wisdom about when to unref or not:

• when getting a list (e.g. "machine" from setup), do not unref the machines in the list
• when getting a filtered-list from setup, do unref :(

Which actions ref an object?:

• g_object_get()
• g_value_dup_object()
• gtk_tree_model_get(store,&iter,col_id,&obj,-1);

... and which do not?:

• g_signal_connect()
• g_value_get_object()

[edit] Debug memory leaks

One can use some envvar to make GLib and LibC more friendly to mem-leak checkers:

 G_SLICE=always-malloc G_DEBUG=gc-friendly GLIBCPP_FORCE_NEW=1 GLIBCXX_FORCE_NEW=1

Use the with both valgrind and MALLOC_CHECK_!

[edit] Valgrind

On the x86/ppc platforms one can use valgrind to check for memleaks. To do so run an app as below:

 valgrind --tool=memcheck --leak-check=full --leak-resolution=high \
   --trace-children=yes --num-callers=20 -v ./buzztard-edit

This works for uninstalled tests as well:

 valgrind --tool=memcheck --leak-check=full --leak-resolution=high \
   --trace-children=yes --num-callers=20 -v ./.libs/buzztard_cmd

If you have the GStreamer sources available, it might make sense to use the suppression file from there:

 ln -s ~/projects/gstreamer-0.10/gstreamer/common/gst.supp ./
 valgrind --tool=memcheck --leak-check=full --leak-resolution=high \
   --trace-children=yes --num-callers=20 --suppressions=gst.supp -v ./buzztard-edit

There is also a supression file for gtk.

We can also profile memory usage:

 valgrind --tool=massif -v ./buzztard-edit

This generates files named massif.<pid>.ps and massif.<pid>.txt.

And remember - be patient - valgrind takes a while to run ;-).

[edit] LibC

The glibc on linux system provides some help as well. If one sees messages like

*** glibc detected *** free(): invalid pointer: 0x082587f4 ***

the one can rerun the program with an additional environment variable beeing set

 MALLOC_CHECK_=3 gdb --args ./buzztard-cmd

A value of '2' causes glib to call abort after the error, which allows you top get a stacktrace from gdb. A value of '1' just shows the error and a value of 3 does both - showing the info plus aborting. A value of '0' ignores the error.

If this still not helps one can use MALLOC_TRACE: First add a call to mtrace() to start of main(), then recompile and link. Afterwards execute:

MALLOC_TRACE=heap.log ./myprog

This creates the log. Analyze it using

mtrace myprog heap.log

When using this for unittests add CK_FORK=no to make the failing test abort.

[edit] Debug memory usage

For details see Profiling Memory Use in GNOME Software

 valgrind --tool=massif --trace-children=yes --depth=5 \
  --alloc-fn=g_malloc --alloc-fn=g_realloc --alloc-fn=g_try_malloc --alloc-fn=g_malloc0 --alloc-fn=g_mem_chunk_alloc \
  ./buzztard-edit

[edit] Profiling

We recommend to use oprofile or sysprof.

Alternatively get and install qprof. A very simple profiling session looks like this:

 . /usr/local/lib/qprof-0.5/alias.sh
 qprof_start;./buzztard-cmd --help;qprof_stop

[edit] GDB Tips

To get the type-name of a gobject:

print g_type_name(((GTypeClass*)((GTypeInstance*)widget)->g_class)->g_type)