Debugging Problems

Bugs are there for sure, but where...
Here some tips catching them.

General

Make sure your Gambas IDE is uptodate, but be careful that this might introduce other bugs... I'm speaking with experience.
During development of DomotiGa I have been bitten by some bugs in Gambas, all of them are fixed at this moment.

You can also disable certain modules in DomotiGa to pinpoint which one is having problems.

Debug High CPU Load

gdb

To debug high CPU load issues. (where the GUI doesn't respond anymore but program seems to run)
leave the program running open a terminal windows and find out which process ID the running instance has.

$ ps aux|grep gb[xr]3

ron      19485  6.9  1.9  61968 20316 ?        SLl  Jan12 159:53 /usr/local/bin/gbx3 -g -f /home/ron/domotiga/DomotiGa --

Is this case the Process ID is 19485.

Start GNU Debugger and try to get a backtrace.

$ sudo gdb gbx3 <Process ID>

(gdb) bt
#0  0xb7fa5410 in +kernel_vsyscall ()
#1  0xb773c196 in nanosleep () from /lib/tls/i686/cmov/libpthread.so.0
#2  0xb6feac7a in CSerialPort_CallBack (lParam=35) at CSerialPort.c:119
#3  0xb71746d9 in CWatch::read (this=0x8270188, fd=35) at CWatch.cpp:126
#4  0xb7174568 in CWatch::qt_invoke (this=0x8270188, _id=2, _o=0xbfbbc860)
    at CWatch_moc.cpp:90
#5  0xb7aab704 in QObject::activate_signal () from /usr/lib/libqt-mt.so.3
#6  0xb7aac051 in QObject::activate_signal () from /usr/lib/libqt-mt.so.3
#7  0xb7e3bb99 in QSocketNotifier::activated () from /usr/lib/libqt-mt.so.3
#8  0xb7acd766 in QSocketNotifier::event () from /usr/lib/libqt-mt.so.3
#9  0xb7a3fc36 in QApplication::internalNotify () from /usr/lib/libqt-mt.so.3
#10 0xb7a41a5f in QApplication::notify () from /usr/lib/libqt-mt.so.3
#11 0xb714a2ba in [[MyApplication]]::notify (this=0x8116ef8, o=0x81ab178, e=0xbfbbcae0)
    at main.cpp:354
#12 0xb79d028d in QApplication::sendEvent () from /usr/lib/libqt-mt.so.3
#13 0xb7a31b4a in QEventLoop::activateSocketNotifiers () from /usr/lib/libqt-mt.so.3
#14 0xb79e5630 in QEventLoop::processEvents () from /usr/lib/libqt-mt.so.3
#15 0xb7149253 in [[MyEventLoop]]::processEvents (this=0x80884e8, flags=4) at main.cpp:247
#16 0xb7a5af90 in QEventLoop::enterLoop () from /usr/lib/libqt-mt.so.3
#17 0xb7a5ac8e in QEventLoop::exec () from /usr/lib/libqt-mt.so.3
#18 0xb7a417df in QApplication::exec () from /usr/lib/libqt-mt.so.3
#19 0xb714893e in hook_loop () at main.cpp:542
#20 0x0806146e in main (argc=Cannot access memory at address 0xfffffdfc
) at gbx.c:363
(gdb)

Note this is a normal running instance.

valgrind & kcachegrind

A more detailed way to find out where your program has a bottleneck, is to use the valgrind tool to create callgrind information, and load the file it creates into a tool called kcachegrind. It can show you the number of times a call gets called during the run of you program, and displays lots of other useful info.

Install valgrind and kcachegrind if not done already:

$ sudo apt-get install valgrind kcachegrind

You have to recompile your gambas installation without compiler optimizations

$ cd /path/to/gambas/sources
$ make clean
$ make "CFLAGS=-O0 -g" "CXXFLAGS=-O0 -g" 
...
$ sudo make install

Start your program with valgrind

$ cd ~/domotiga/DomotiGa3
$ gbc3 -agpmt
$ valgrind --log-file=/tmp/valgrind.log --tool=callgrind --num-callers=50 gbx3

Then start in another terminal window
$ tail -f /tmp/valgrind.log

Stop program after running your program for a fair amount of time.

You should see something like this...

==29929== Callgrind, a call-graph generating cache profiler
==29929== Copyright (C) 2002-2012, and GNU GPL'd, by Josef Weidendorfer et al.
==29929== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==29929== Command: gbx3
==29929== Parent PID: 6867
==29929== 
==29929== For interactive control, run 'callgrind_control -h'.
==29929== 
==29929== Events    : Ir
==29929== Collected : 2263121265
==29929== 
==29929== I   refs:      2,263,121,265

Then start kcachegrind, if you started it from the project directory it finds and load the generated callgrind.out.xxxx file automatically, otherwise load it via file open menu.
Then sort on number of calls/time to see which code get called the most.
You can then click through the calls, and view the called source code via Source Code tab.

strace

strace is an application to monitor interactions between processes, in this case Gambas, and the Linux kernel. It traces only system calls, signal deliveries, changes of process state etc. but will include the interaction with MySQL and the shell for writing the log files, rrdtool, shell commands, input from sensors.

To get a view of where time is spent, valgrind/kcachegrind is superior but if a process only hangs after several hours (see for example issue #500), valgrind is not really an option because the log file becomes too big.

strace -p <pid> -o /tmp/domotiga.strace -t -s 100

Replace <pid> by the PID of the gbr3 process, let strace run for say a 30 seconds and stop it by pressing Ctrl-C. Have a look at the output file (how large is it) and if you want to share it, does it contain things you do not want to share (all shell commands and log message are present).

A log on itself can show if domotiga is running a infinite loop but in other cases it is not easy to see what is wrong. In this case it is good to compare what you see with a log of the normal behavior.

Debug Signal #11

If DomotiGa/Gambas crashes with a Unix Signal error you can try to get info why/where it had a problem.

You should start the project from within the gdb like so.

$ cd ~/domotiga/DomotiGa3
$ gbc3 -agpmt
$ gdb gbx3

GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying" 
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...
(gdb) run
Starting program: /usr/local/bin/gbx3
[Thread debugging using libthread_db enabled]
[New Thread 0xb7d3c6b0 (LWP 8312)]
Qt: gdb: -nograb added to command-line options.
     Use the -dograb option to enforce grabbing.

Program exited normally.
(gdb) run
Starting program: /usr/local/bin/gbx3
[Thread debugging using libthread_db enabled]
[New Thread 0xb7d976b0 (LWP 8315)]
Qt: gdb: -nograb added to command-line options.
     Use the -dograb option to enforce grabbing.

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb7d976b0 (LWP 8315)]
0x08064dd4 in VARIANT_free (var=0x82304f4) at gbx_variant.h:55
55        OBJECT_UNREF(*((void **)var->value), "VARIANT_free");
(gdb) bt
#0  0x08064dd4 in VARIANT_free (var=0x82304f4) at gbx_variant.h:55
#1  0x080650f5 in collection_free (col=0x80d6f18) at gbx_c_collection.c:56
#2  0x0804e628 in EXEC_call_native (exec=0x806514f <CCOLLECTION_free>,
object=0x80d6f18,
    type=0, param=0x807e908) at gbx_exec.c:843
#3  0x0804ef35 in EXEC_native () at gbx_exec.c:961
#4  0x0804f5d7 in EXEC_spec (special=1, class=0x80794b8,
object=0x82304e8, nparam=0,
    drop=1 '\001') at gbx_exec.c:1233
#5  0x0804f748 in EXEC_special_inheritance (special=1, class=0x80794b8,
object=0x80d6f18,
    nparam=0, drop=1 '\001') at gbx_exec.c:1333
#6  0x08051112 in CLASS_free (object=0x80d6f18) at gbx_class.c:609
#7  0x08062090 in release (class=0x80c8740, ob=0x0) at gbx_object.c:274
#8  0x080621fd in OBJECT_release (class=0x80c8740, ob=0x0) at
gbx_object.c:293
#9  0x0805199a in CLASS_clean_up (silent=0 '\0') at gbx_class.c:246
#10 0x0806112a in main_exit (silent=-25 '\ufffd') at gbx.c:101
#11 0x080617ca in main (argc=Cannot access memory at address 0xffaacce7
) at gbx.c:383
(gdb) 

You can lookup the last valid call before the crash by examining stack frame# 1.
f 1
...

To see the spot in you project where it crashed do this.
(gdb) p DEBUG_get_position(EXEC_current.cp, EXEC_current.fp, EXEC_current.pc)

gdb can call function since recently, EXEC_current is the structure containing
all interpreter registers, and DEBUG_get_position prints the current position
according to their values and the debugging information compiled in the Gambas
object files.

You can also display variable values

l gbx_watch.c:504
print ret
info locals

If you do not have time to (finish) investigating things and want to do that later, type 'gcore' to save the coredump to a file for later inspection:

(gdb) gcore
Saved corefile core.6111

Alternatively, try:

(gdb) generate-core-file
Saved corefile core.2575

Normally writing coredumps for normal users is disabled, you can enable it for the domotiga user using:

$ ulimit -c unlimited

If this fails, see How do I enable core dumps for everybody

Debug Memory Allocation

First install valgrind.

$ sudo apt-get install valgrind

Then run the project with it, it's slow, but maybe the only way to get the debugging info you want.
$ cd ~/domotiga/DomotiGa3
$ gbc3 -agpmt
$ valgrind --tool=memcheck --num-callers=50 --leak-check=full --log-file=/tmp/valgrind.log gbx3 2>&1

Then start in another terminal window
$ tail -f /tmp/valgrind.log

==3806== Memcheck, a memory error detector.
==3806== Copyright (C) 2002-2008, and GNU GPL'd, by Julian Seward et al.
==3806== Using [[LibVEX]] rev 1884, a library for dynamic binary translation.
==3806== Copyright (C) 2004-2008, and GNU GPL'd, by [[OpenWorks]] LLP.
==3806== Using valgrind-3.4.1-Debian, a dynamic binary instrumentation framework.
==3806== Copyright (C) 2000-2008, and GNU GPL'd, by Julian Seward et al.
==3806== For more details, rerun with: -v
==3806==
==3806== Invalid read of size 4
==3806==    at 0x4016A87: (within /lib/ld-2.9.so)
==3806==    by 0x41AC901: (within /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0x400E035: (within /lib/ld-2.9.so)
==3806==    by 0x41ACAC4: +libc_dlopen_mode (in /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0x418423F: +nss_lookup_function (in /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0x418430E: (within /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0x418616C: +nss_services_lookup2 (in /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0x418CE95: getservbyname_r (in /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0x418CBED: getservbyname (in /lib/tls/i686/cmov/libc-2.9.so)
==3806==    by 0xD0BAB85: mysql_server_init (in /usr/lib/libmysqlclient.so.15.0.0)
==3806==    by 0xD0E2E58: mysql_init (in /usr/lib/libmysqlclient.so.15.0.0)
==3806==    by 0x801516E: open_database (main.c:628)
==3806==    by 0x530EFAA: DB_Open (main.c:214)
==3806==    by 0x530FC7B: CCONNECTION_open (CConnection.c:81)
==3806==    by 0x804E80F: EXEC_call_native (gbx_exec.c:843)
==3806==    by 0x804F142: EXEC_native (gbx_exec.c:961)
==3806==    by 0x806BD2F: EXEC_loop (gbx_exec_loop.c:1042)
==3806==    by 0x804F482: EXEC_function_loop (gbx_exec.c:702) 
.....
==3806==
==3806== ERROR SUMMARY: 407 errors from 4 contexts (suppressed: 420 from 6)
==3806== malloc/free: in use at exit: 625,706 bytes in 5,326 blocks.
==3806== malloc/free: 232,165 allocs, 226,839 frees, 43,890,176 bytes allocated.
==3806== For counts of detected errors, rerun with: -v
==3806== Use --track-origins=yes to see where uninitialised values come from
==3806== searching for pointers to 5,326 not-freed blocks.
==3806== checked 1,747,124 bytes.
==3806==
==3806== LEAK SUMMARY:
==3806==    definitely lost: 68,826 bytes in 129 blocks.
==3806==      possibly lost: 10,784 bytes in 300 blocks.
==3806==    still reachable: 546,096 bytes in 4,897 blocks.
==3806==         suppressed: 0 bytes in 0 blocks.
==3806== Rerun with --leak-check=full to see details of leaked memory. 

gdb tricks

break [file_name]:line_number
break [file_name]:func_name

Places break point in the C program. While executing the program the debugger will stop at the break point, and gives you the prompt to debug.
break 10
Breakpoint 1 at 0x804846f: file factorial.c, line 10.

Compile Gambas without gcc optimization

Sometimes the output of gdb is not detailed enough because of gcc compiler optimizations.

Then you need to compile Gambas without those, you can notice a slowdown when running unoptimized code, so recompile when debugging is done.

This is how you recompile the interpreter.

$ cd /path/to/gambas/sources/main/gbx
$ make clean
$ make "CFLAGS=-O0 -g" "CXXFLAGS=-O0 -g" 
...
$ sudo make install

If you come across gdb output with <value optimized out> in it, try to determine the component the code is in and recompile that also without optimization.

For example for gb.net do this.

$ cd /path/to/gambas/sources/gb.net
$ make clean
$ make "CFLAGS=-O0 -g" "CXXFLAGS=-O0 -g" 
...
$ sudo make install

ERROR: #42: System error. Success

$ gdb gbx3
...
(gdb) break THROW
...
(gdb) run
...
... Let your program run until it stops
...
(gdb) bt

Enable Gambas debug output in certain code

Some Gambas source modules have a DEBUG variable.
Uncomment it and recompile the part to enable it.

How to enable debug in ccurl:

gambas/trunk/gb.net.curl/src/CCurl.h

 #include <curl/curl.h>
 #include <curl/easy.h>

 #define DEBUG 1

Debug MySQL queries

You can enable MySQL debug output in Gambas by added the following line to start of you program, for DomotiGa for example in file Main.module like so:

'~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
' connect to the mysql database
'~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Public Function ConnectDatabase() As Boolean

  DB.Debug = True

...

It will output to stdout.

Report gambas bugs

If you think a bug is caused by gambas itself please open a bugreport here, and provide the information asked in the ticket.
http://gambaswiki.org/bugtracker/

Related Resources

    Updated by: rdnzl, Updated over 1 year ago
    Access count: 63369 since 2011-08-25

    Attached Files

    gdb-refcard.pdf (74.8 KB) rdnzl, 12/27/2009 01:31 PM

    Also available in: PDF HTML TXT