Debugging

From Buzztrax

Jump to: navigation, search

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

Debug Messages

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

Writing debug messages

As buzztrax 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("buzztrax 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.

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 buzztrax in Level 3 you can start your buzztrax with following arguments:

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

Attention! Following commandline will not produce the expected messages:

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

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

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

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

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:

 ./buzztrax-edit 2>debug.log --gst-debug-no-color --gst-debug="bt-*:4" --command=load --input-file=../share/buzztrax/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.

Compile-time problems

Macro issues

This email teaches a smart trick to track down issues with the preprocessor. It recommends to set CC when running make:

 make CC='gcc -g -save-temps -Wp,-dD ...'

This will produce all macro definitions, expanded in .i files (those files can be made more reaable using GNU indent).

Run-time problems

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 ./buzztrax-edit --gst-debug="*:2,bt-*:3" --g-fatal-warnings

using jhbuild

If you use jhbuild to build and run buzztrax, you can also try to debug it with gdb. Try the follow command line, to get the same result as above:

jhbuild -f ~/projects/buzztrax/build-tools/jhbuild/buzztrax.jhbuildrc run gdb --args ~/buzztrax/jhbuild/install/bin/buzztrax-edit --gst-debug="*:2,bt-*:3" --g-fatal-warnings

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.

Crashers

If the app terminates or hangs - try to remember what you did and rerun under gdb. Then tell us about the backtrace you got. In case the app hangs press Ctrl-C. That gets you back to gdb and lets you print the backtrace.

Better backtraces

Please have debug symbol packages installed.

One idea that helps in gtk/gstreamer apps is to get object names into the backtrace would be to log the (objectname,address) pairs from the library and use something like that to improve the backtrace (needs more work):

 grep "gstobject.c" debug.log | cut -c101- | sed "s#<\(.*\)> \(0x.*\)#s/=\2/=\\<\1\\>/g#" | uniq -u >debug1.log
 sed -fdebug1.log gdb.txt >gdb_fmt.txt

gnome bug buddy

Normally gnome bug buddy would intercept the crasher and allow you to create a report. If this is not what you want, you can disable gnome bug-buddy with this env-var:

 export GNOME_DISABLE_CRASH_DIALOG=1

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:

 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:

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

You can even run a single test under gdb:

 CK_FORK=no BT_CHECKS="test_btsong_io_native_refcounts" /usr/bin/make bt_core.gdb

or

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

(Note that I used full path to make above as I use pretty_make and this would not start gdb interactively.)

G_DEBUG stoppers

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

G_DEBUG="fatal_criticals"
G_DEBUG="fatal_warnings"

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

Ressource usage

Debug GObject reference counting

Some wisdom about when to unref or not (buzztrax specific):

  • 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()

Logging

One can sprinkle this all over the sources:

 GST_DEBUG("object: %p refs: %d)",object,G_OBJECT_REF_COUNT(object);

RefDbg

Get the refdbg tool (for the time being consider the latest version) and install it. To find out about the ref-ct of e.g. BtMachine instances, start the binary as below:

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBRARY_PATH \
 refdbg -c "btnum=8 ; logobjs=0 ; r0=<BtMachine> D:All L:All" ./buzztrax-edit

Then look into refdbg.log.

Hint1: This will only work if you have the glib configured with the --disable-visibility flag which is for example not the default in most linux distributions.--waffel 15:18, 10 Jun 2005 (CEST)

Hint2: Since at least glib2-2.25 one also should configure --disable-Bsymbolic. --[[ensonic 22:28, 11 December 2010 (CET)]]

Another way is to use it in conjunction with gdb:

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBRARY_PATH \
 refdbg -c "btnum=8 ; logobjs=0 ; r0=B:Error" gdb ./buzztrax-edit

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

One issue is a program that segfaults. This would not call the refdbg destructor and thus no refdbg.log would be written. But also here is a way out:

 refdbg -c "btnum=20 ; logobjs=0 ; r0=<BtSourceMachine> D:None L:All" gdb  ./buzztrax-edit
 # now in gdb
 run
 # crash happend
 call refdbg_save_log ()
 quit

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

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBRARY_PATH \
 refdbg -c "btnum=0 ; r0=D:None L:None" ./buzztrax-edit
 cat refdbg.log | egrep -v "(Atk|Gdk|Pango|GtkIMModule|GFile|GLocal|GDummy|Style)" | grep -v "Gtk.*Style" | grep -v "GstPlugin" | grep -v "Gst.*Factory" | grep -v "GstPadTemplate" >refdbg.flt.log

A complete session with the latest refdbg development version might look like this:

 rm refdbg.log*
 refdbg -c "btnum=20 ; logobjs=0 ; r0=<BtPattern> D:Error L:All" gdb ./buzztrax-edit
 refdbg-splitlog.pl
 refdbg-filterlog.pl refdbg.log.FAIL.xxxxxxx

Gdb

The GNU debugger is scriptable. We have one gdb script in the repo that gathers backtraces for particular ref/unref operations. The output is written to a log file. This log file is filtered by a perl script. The perl script reformats the backtraces, truncates them to strip common trailing stack frames and removes certain known ref/unref pairs to ease going through the remaining ones. For example one get from 156 frames for one testcase down to 20.

More resources:

SystemTap

glib/gobject contains a (yet) uninstalled file named gobject.stp inside the gobject folder. In theory a script like below should work. In does not on OpenSuse 11.3 because of bug 656091 and on Ubuntu 10.10 (Maverick).

#!/bin/sh
 
dbglibdir=$HOME/debug/lib
 
stap -v gobject.stp \
-d ../src/lib/core/.libs/libbuzztrax-core.so \
-d ../src/lib/ic/.libs/libbuzztrax-ic.so \
-d ${dbglibdir}/libglib-2.0.so \
-d ${dbglibdir}/libgobject-2.0.so \
-d ${dbglibdir}/libgtk-x11-2.0.so \
-d ./bt_edit \
-c ./bt_edit

Debug memory usage

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 them with both valgrind and MALLOC_CHECK_*!

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 ./buzztrax-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/buzztrax_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 ./buzztrax-edit

There is also a supression file for gtk.

Finally if you have valgrind >= 3.4.x use --track-origins=yes in addition, when trying to find the reasons for uninitialized memory access.

We can also profile memory usage:

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

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

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

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 ./buzztrax-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.

AddressSanitizer (ASan)

http://code.google.com/p/address-sanitizer/wiki/HowToBuild

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 \
  ./buzztrax-edit

Debug multi-threading issues

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

 valgrind --tool=helgrind -v ./buzztrax-edit
 valgrind --tool=drd -v ./buzztrax-edit

Library call stats

Valgrind comes with a tool called lackey that can be used to count call invocations:

 valgrind --tool=lackey --fnname=malloc ./buzztrax-cmd ...

The advantage of lackey over ltrace is that it works across libraries. The disadvantage is its slowness :/

Gtk+

Build yourself a gtk with --enable-debug=yes to e.g. $HOME/debug Then call the application with:

 LD_LIBRARY_PATH=$HOME/debug/lib:$LD_LIBARY_PATH GDK_PIXBUF_MODULE_FILE=/etc/gtk-2.0/gdk-pixbuf.loaders GTK_PATH=/usr/lib/gtk-2.0 ./buzztrax-edit

If you have no /etc/gtk-2.0/gdk-pixbuf.loaders (like I had under ubuntu), run this command:

 sudo gdk-pixbuf-query-loaders > /etc/gtk-2.0/gdk-pixbuf.loaders

There is a nice tool to peek into gtk uis at runtime called Parasite.

GDB Tips

To get the type-name of a gobject:

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

Makefiles

Debug command execution

Makefiles are not easy to debug. Read this article to learn some tricks. In essence add this to the top of the Makefile.am

 OLD_SHELL := @SHELL@
 SHELL = $(warning Building $@$(if $<, (from $<))$(if $?, ($? newer)))$(OLD_SHELL) -vx

Get a list of targets

grep '^[^#[:space:]][^=]*:' Makefile | sort

Another solution:

  # in the directory containing your Makefile:
  make -rpn | sed -n -e '/^$/ { n ; /^[^ ]*:/p }'
 
  # ... or add a touch of color by highlighting the targets in the rules:
  make -rpn | sed -n -e '/^$/ { n ; /^[^ ]*:/p }' | egrep --color '^[^ ]*:'

An interesting patch to spit out a dot graph of the dependencies was proposed in august 2010 on gnu make list. Seems to not yet be included :/.

Support Us

Collaboration

SourceForge Logo
GStreamer Logo
Become a Friend of GNOME
Linux Sound Logo
MediaWiki
Valgrind
GNU Library Public Licence
GNU Free Documentation License 1.2