www-content/pages/debugging/apps_efl_debugging.txt

488 lines
19 KiB
Plaintext

~~Title: Apps debugging~~
==== EFL application debugging ====
<note important>
//Please also see [[/docs-efl-debug]]. This should probably be merged with this page.//
</note>
This tutorial's goal is to help you debug your EFL applications with several use cases that you can reproduce. It gives you approaches to know if the bug comes from your application or from the EFL libraries.
Then, if you are sure the bug does not come from your application, you can [[/debugging/report_bugs|report a bug]].
In this tutorial we'll cover log levels and tracing the sources of bugs:
- [[apps_efl_debugging#Log level]]
- [[apps_efl_debugging#Wrong function on an object]]
- [[apps_efl_debugging#Segfault in callback function]]
- [[apps_efl_debugging#Memory leak]]
- [[apps_efl_debugging#Clouseau]]
Before debugging, make sure your debug symbols are enabled. If not, go to the [[/docs-efl-start#Enable_debug_symbols_Optional|Enable debug symbols]] section.
You can also have a look at the [[https://phab.enlightenment.org/w/coding_convention/|EFL coding convention]] if you modify code and want to send patches.
=== Log level ===
The Eina log module provides log level traces, there are 5 debugging levels with their respective macros:
^Level ^Macro ^
|Critical |EINA_LOG_LEVEL_CRITICAL() |
|Error |EINA_LOG_ERR() |
|Warning |EINA_LOG_WARN() |
|Info |EINA_LOG_INFO() |
|Debug |EINA_LOG_DBG() |
Global log level can be set with the ''EINA_LOG_LEVEL'' environment variable.
<code bash>
# Debug log level
EINA_LOG_LEVEL=5 ./my_test_efl
</code>
The ''EINA_LOG_LEVELS'' variable provide a way to activate logs only for specific modules.
<code bash>
# This will set module1 and module2 respectively to log level 5 and 2
EINA_LOG_LEVELS=module1:5,module2:2 ./my_test_efl
</code>
----
=== Wrong function on an object ===
The code below creates 3 Elementary objects: win, box and btn. It displays a window with an //OK// button that closes the window when it is clicked. Here, the //elm_box_pack_end()// function is called on a wrong object (win) which generates an error:
<code c hello.c>
#include <Elementary.h>
static void
on_done(void *data, Evas_Object *obj, void *event_info)
{
// quit the mainloop (elm_run function will return)
elm_exit();
}
EAPI_MAIN int
elm_main(int argc, char **argv)
{
Evas_Object *win, *box, *btn;
// new window
win = elm_win_util_standard_add("hello", "Hello");
// add a box object
box = elm_box_add(win);
// add object as a resize object for the window (controls window minimum
// size as well as gets resized if window is resized)
elm_win_resize_object_add(win, box);
evas_object_show(box);
// add a button
btn = elm_button_add(win);
// set default text of button to "OK"
elm_object_text_set(btn, "OK");
// pack the button at the end of the box
/****ERROR****/
elm_box_pack_end(win, btn); //win instead of box
evas_object_show(btn);
// call on_done when button is clicked
evas_object_smart_callback_add(win, "clicked", on_done, NULL);
//show the window
evas_object_show(win);
// run the mainloop and process events and callbacks
elm_run();
return 0;
}
ELM_MAIN()
</code>
Compile with -g flag to have debugging symbols and execute it:
<code bash>
gcc -Wall -O1 -march=native -g -ggdb3 -o hello hello.c `pkg-config --cflags --libs elementary`
./hello
ERR<13670>:eo lib/eo/eo.c:780 _eo_api_op_id_get() in elm_box.eo.c:48: unable to resolve regular api func 'elm_obj_box_pack_end' 0x7f1128f50faf in class 'Elm_Win'.
</code>
Here, the error log says that the ''elm_obj_box_pack_end'' is not in the api of Elm_win, and so, that this error is coming from your application and not from EFL. Guessing you have a more complicated application, this trace is not enough to find in your code where is the problem. Fortunately, EFL provide a macro to provide backtraces: //EINA_LOG_ABORT//.
In fact, a message generated by CRI macro can automatically call abort() once some given level message is printed. This is controlled by environment variable //EINA_LOG_ABORT// and the level to be considered critical with //EINA_LOG_ABORT_LEVEL//. This means the program will stop at the first error met with these two variables.
Get a backtrace with the following command:
<code gdb>
EINA_LOG_ABORT_LEVEL=4 EINA_LOG_ABORT=1 gdb hello
(gdb) run
Starting program: /home/efl/test/hello
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7fffea2da700 (LWP 13679)]
ERR<13675>:eo lib/eo/eo.c:780 _eo_api_op_id_get() in elm_box.eo.c:48: unable
to resolve regular api func 'elm_obj_box_pack_end' 0x7ffff7991faf in class
'Elm_Win'.
Program received signal SIGABRT, Aborted.
0x00007ffff6c76cc9 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 0x00007ffff6c76cc9 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1 0x00007ffff6c7a0d8 in __GI_abort () at abort.c:89
#2 0x00007ffff6387919 in eina_log_print_unlocked (args=0x7fffffffdac8, fmt=0x7ffff561c970 "in %s:%d: unable to resolve %s api func '%s' %p in class '%s'.", line=780, fnc=0x7ffff561d330 <__FUNCTION__.12409> "_eo_api_op_id_get", file=0x7ffff561c48c "lib/eo/eo.c", level=EINA_LOG_LEVEL_ERR, domain=25) at lib/eina/eina_log.c:1274
#3 eina_log_print (domain=25, level=level@entry=EINA_LOG_LEVEL_ERR, file=file@entry=0x7ffff561c48c "lib/eo/eo.c", fnc=fnc@entry=0x7ffff561d330 <__FUNCTION__.12409> "_eo_api_op_id_get", line=line@entry=780, fmt=fmt@entry=0x7ffff561c970 "in %s:%d: unable to resolve %s api func '%s' %p in class '%s'.") at lib/eina/eina_log.c:2079
#4 0x00007ffff56122c5 in _eo_api_op_id_get (api_func=api_func@entry=0x7ffff7991faf <elm_obj_box_pack_end>, is_main_loop=is_main_loop@entry=1 '\001', file=file@entry=0x7ffff7af39cc "elm_box.eo.c", line=line@entry=48) at lib/eo/eo.c:778
#5 0x00007ffff7991fe3 in elm_obj_box_pack_end (subobj=subobj@entry=0x80000007e0000040) at elm_box.eo.c:48
#6 0x00007ffff79940cf in elm_box_pack_end (obj=obj@entry=0x80000003a000001e, subobj=subobj@entry=0x80000007e0000040) at elm_box.eo.c:223
#7 0x0000000000400b69 in elm_main (argc=argc@entry=1, argv=argv@entry=0x7fffffffddb8) at hello.c:34
#8 0x0000000000400bcd in main (argc=1, argv=0x7fffffffddb8) at hello.c:47
</code>
//elm_obj_box_pack_end// is in frame 6, so called from frame 7
Go to frame 7:
<code gdb>
(gdb) fr 7
#7 0x0000000000400b69 in elm_main (argc=argc@entry=1, argv=argv@entry=0x7fffffffddb8) at hello.c:34
34 elm_box_pack_end(win, btn); //win instead of box
</code>
You finally see that win is used as a parameter of //elm_box_pack_end// instead of box, at line 34 of hello.c.
----
=== Segfault in callback function ===
Let's make a segfault in a callback function:
<code c helloworld.c>
#include <Elementary.h>
static void
on_done(void *data, Evas_Object *obj, void *event_info)
{
int *pi = (int *)0; // pointer on 0x0!!!
/**SEGFAULT**/
int i = *pi; // segfault accessing 0x0 address
// quit the mainloop (elm_run function will return)
elm_exit();
}
EAPI_MAIN int
elm_main(int argc, char **argv)
{
Evas_Object *win, *box, *btn;
// new window
win = elm_win_util_standard_add("hello", "Hello");
// add a box object
box = elm_box_add(win);
// add object as a resize object for the window
elm_win_resize_object_add(win, box);
evas_object_show(box);
// add a button
btn = elm_button_add(win);
// set default text of button to "SEG"
elm_object_text_set(btn, "SEG");
// pack the button at the end of the box
elm_box_pack_end(box, btn);
evas_object_show(btn);
// call on_done when button is clicked
evas_object_smart_callback_add(btn, "clicked", on_done, NULL);
//show the window
evas_object_show(win);
// run the mainloop and process events and callbacks
elm_run();
return 0;
}
ELM_MAIN()
</code>
This program segfaults when the seg button is clicked that is to say that the program segfaults in the callback function:
//**__How to get that with GDB?__**//
<code gdb>
gdb helloworld
(gdb) run
(gdb)bt
#0 0x0000000000400c7f in on_done (data=0x0, obj=0x8000000800000041, event_info=0x0) at helloworld.c:6
#1 0x00007ffff6c1cb84 in _eo_evas_smart_cb (data=<optimized out>, eo_obj=<optimized out>, desc=<optimized out>, event_info=<optimized out>) at
lib/evas/canvas/evas_object_smart.c:65
#2 0x00007ffff5e43d22 in _eo_base_event_callback_call (obj_id=0x8000000800000041, pd=0x92b4f0, desc=0x94e320, event_info=0x0) at
lib/eo/eo_base_class.c:716
#3 0x00007ffff5e42a97 in eo_event_callback_call (desc=desc@entry=0x94e320,
event_info=event_info@entry=0x0) at lib/eo/eo_base.eo.c:94
#4 0x00007ffff6c1ebad in evas_object_smart_callback_call (eo_obj=eo_obj@entry=0x8000000800000041, event=event@entry=0x7ffff7af0bdf
<SIG_CLICKED> "clicked", event_info=event_info@entry=0x0) at lib/evas/canvas/evas_object_smart.c:791
#5 0x00007ffff7994b8c in _activate (obj=0x8000000800000041) at elm_button.c:69
#6 0x00007ffff7994bc2 in _on_clicked_signal (data=<optimized out>,
obj=<optimized out>, emission=<optimized out>, source=<optimized out>) at
elm_button.c:191
#7 0x00007ffff60d0425 in edje_match_callback_exec_check_finals (prop=<optimized out>, ed=<optimized out>, source=<optimized out>,
sig=<optimized out>, source_states=<optimized out>, signal_states=<optimized out>, matches=<optimized out>, ssp=<optimized
out>) at lib/edje/edje_match.c:556
#8 edje_match_callback_exec (ssp=0x0, ssp@entry=0x946520, matches=0x8000000800000041, sig=0x0, sig@entry=0x92c06c "elm,action,click",
source=0x0, source@entry=0x914f60 "elm", ed=0x7ffff5e471b7, ed@entry=0x92ba70, prop=94 '^', prop@entry=0 '\000') at
lib/edje/edje_match.c:712
#9 0x00007ffff60d673d in _edje_emit_cb (prop=0 '\000', data=0x0, src=0x914f60
"elm", sig=0x92c06c "elm,action,click", ed=0x92ba70) at lib/edje/edje_program.c:1392
#10 _edje_emit_handle (ed=0x92ba70, sig=0x92c06c "elm,action,click", src=0x914f60 "elm", sdata=0x0, prop=0 '\000') at lib/edje/edje_program.c:1345
#11 0x00007ffff60d1296 in _edje_message_process (em=0x669cf0) at lib/edje/edje_message_queue.c:651
#12 0x00007ffff60d178c in _edje_message_queue_process () at lib/edje/edje_message_queue.c:754
#13 0x00007ffff60d18ec in _edje_job (data=<optimized out>) at lib/edje/edje_message_queue.c:155
#14 0x00007ffff696d3e0 in _ecore_job_event_handler (data=<optimized out>, type=<optimized out>, ev=<optimized out>) at lib/ecore/ecore_job.c:113
#15 0x00007ffff69680a4 in _ecore_call_handler_cb (event=<optimized out>,
type=<optimized out>, data=<optimized out>, func=<optimized out>) at lib/ecore/ecore_private.h:386
#16 _ecore_event_call () at lib/ecore/ecore_events.c:565
#17 0x00007ffff696f711 in _ecore_main_loop_iterate_internal (once_only=once_only@entry=0) at lib/ecore/ecore_main.c:1927
#18 0x00007ffff696f81e in ecore_main_loop_begin () at lib/ecore/ecore_main.c:983
#19 0x00007ffff7a4559f in elm_run () at elm_main.c:1097
#20 0x0000000000400d79 in elm_main (argc=1, argv=0x7fffffffe398) at helloworld.c:39
#21 0x0000000000400dc2 in main (argc=1, argv=0x7fffffffe398) at helloworld.c:42
</code>
The program failed in the callback function, meaning the problem comes from your application, even if the callback is called from Evas.
Let's go a bit more deeply:
- Go to frame 0, the callback function
- Print pi pointer
- Print what it points to
<code bash>
(gdb) fr 0
#0 0x0000000000400c86 in on_done (data=0x0, obj=0x8000000800000041, event_info=0x0) at helloworld.c:6
6 int i=*pi;
(gdb) p pi
$1 (int *) 0x0
(gdb) p *pi
Cannot access memory at address 0x0
</code>
In this easy example, the problem is quite clear, address 0x0 cannot be accessed! Eventually, even if the callback functions are called from Evas and so generate lots of traces, it is quite simple to know where the bug is coming from.
----
=== Memory leak ===
Valgrind is composed of several tools especially memcheck which checks:
- Read/write access
- Memory leaks
- Non-initialized variables
In this example, an Eina array is created in a callback function but it is never freed. This generates a memory leak.
<code c hello_valgrind.c>
#include <Elementary.h>
static void
on_done(void *data, Evas_Object *obj, void *event_info)
{
Eina_Array *array;
unsigned int i;
eina_init();
array = eina_array_new(100);
eina_array_step_set(array, sizeof(*array), 20);
for (i = 0; i < 20; i++) eina_array_push(array, strdup("hello"));
/****To free array****/
//while (eina_array_count(array))
//free(eina_array_pop(array));
//eina_array_free(array);
//eina_shutdown();
// quit the mainloop (elm_run function will return)
elm_exit();
}
EAPI_MAIN int
elm_main(int argc, char **argv)
{
Evas_Object *win, *box, *btn;
// new window
win = elm_win_util_standard_add("hello", "Hello");
// add a box object
box = elm_box_add(win);
// add object as a resize object for the window (controls window minimum
// size as well as gets resized if window is resized)
elm_win_resize_object_add(win, box);
evas_object_show(box);
// add a button
btn = elm_button_add(win);
// set default text of button to "SEG"
elm_object_text_set(btn, "SEG");
// pack the button at the end of the box
elm_box_pack_end(box, btn);
evas_object_show(btn);
// call on_done when button is clicked
evas_object_smart_callback_add(btn, "clicked", on_done, NULL);
//show the window
evas_object_show(win);
// run the mainloop and process events and callbacks
elm_run();
return 0;
}
ELM_MAIN()
</code>
There can be other traces in the HEAD SUMMARY but here we are just interested in the memory leak due to your application, so you may have to ignore things not relevant to your code.
<code bash>
...
valgrind --leak-check=full --track-origins=yes ./hello
...
==22370== 312 (32 direct, 280 indirect) bytes in 1 blocks are definitely lost
in loss record 349 of 417
==22370== at 0x4C28C20: malloc (vg_replace_malloc.c:296)
==22370== by 0x55A585D: eina_array_new (eina_array.c:279)
==22370== by 0x400E4C: on_done (hello.c:7)
==22370== by 0x5CD1B83: _eo_evas_smart_cb (evas_object_smart.c:65)
==22370== by 0x6BCFD21: _eo_base_event_callback_call (eo_base_class.c:716)
==22370== by 0x6BCEA96: eo_event_callback_call (in
/usr/local/lib/libeo.so.1.14.99)
==22370== by 0x5CD3BAC: evas_object_smart_callback_call
(evas_object_smart.c:791)
==22370== by 0x4F34B8B: _activate (elm_button.c:69)
==22370== by 0x4F34BC1: _on_clicked_signal (elm_button.c:191)
==22370== by 0x6970424: edje_match_callback_exec_check_finals
(edje_match.c:556)
==22370== by 0x6970424: edje_match_callback_exec (edje_match.c:712)
==22370== by 0x697673C: _edje_emit_cb (edje_program.c:1392)
==22370== by 0x697673C: _edje_emit_handle (edje_program.c:1345)
==22370== by 0x6971295: _edje_message_process (edje_message_queue.c:651)
...
</code>
All the memory accesses pass through Valgrind, so it shows you a backtrace when an allocation is made and not freed.
As in the backtrace, an allocation took place in the //eina_array_new function//. This function itself is called from //on_done// function on hello.c file. You can go up, but remember that a callback function is called from Evas, so there is a big chance that the allocation is made in your callback function.
----
=== Clouseau ===
Clouseau is the EFL UI Inspection tool. It makes it easy to query UI components and structure. Moreover it supports remote debugging and works with GDB. In fact, Clouseau can also give information about different widgets with their properties.
You can get Clouseau from git:
<code bash>
git clone http://git.enlightenment.org/tools/clouseau.git
</code>
Here is a simple helloworld to test with Clouseau, it displays a window with some text and one button to exit.
<code c hello_clouseau.c>
#include <Elementary.h>
static void
on_done(void *data, Evas_Object *obj, void *event_info)
{
// quit the mainloop (elm_run function will return)
elm_exit();
}
EAPI_MAIN int
elm_main(int argc, char **argv)
{
Evas_Object *win, *box, *lab, *btn;
// new window - new background
win = elm_win_util_standard_add("hello", "Hello");
// when the user clicks "close" on a window there is a request to delete
evas_object_smart_callback_add(win, "delete,request", on_done, NULL);
// add a box object - default is vertical. a box holds children in a row,
// either horizontally or vertically. nothing more.
box = elm_box_add(win);
// make the box horizontal
elm_box_horizontal_set(box, EINA_TRUE);
// add object as a resize object for the window (controls window minimum
// size as well as gets resized if window is resized)
elm_win_resize_object_add(win, box);
evas_object_show(box);
// add a label widget, set the text and put it in the pad frame
lab = elm_label_add(win);
// set default text of the label
elm_object_text_set(lab, "Hello out there world!");
// pack the label at the end of the box
elm_box_pack_end(box, lab);
evas_object_show(lab);
// add an ok button
btn = elm_button_add(win);
// set default text of button to "OK"
elm_object_text_set(btn, "OK");
// pack the button at the end of the box
elm_box_pack_end(box, btn);
evas_object_show(btn);
// call on_done when button is clicked
evas_object_smart_callback_add(btn, "clicked", on_done, NULL);
// now we are done, show the window
evas_object_show(win);
// run the mainloop and process events and callbacks
elm_run();
return 0;
}
ELM_MAIN()
</code>
To launch it with Clouseau:
<code bash>
clousseau ./helloworld
</code>
Here below is a screenshot of Clouseau and the helloworld application:
{{:clouseau.png?direct|Clouseau}}
- Yellow : Helloworld application
- Red : the composition of Helloworld application
- Blue : The characteristic of Elm and Evas_object
Let's see now what Clouseau shows and how it relates to the code:
The application is composed of 3 main widgets : //Elm_win//, //Elm_bg//, //Elm_box//.
<code c>
win = elm_win_util_standard_add("hello", "Hello");
...
box = elm_box_add(win);
</code>
//elm_win_util_standard_add// function creates the window which is the root widget often used in an application. It also puts a standard background (//Elm_bg//). Then, //elm_box_add// function creates a box widget.
<code c>
elm_box_pack_end(box, lab);
...
elm_box_pack_end(box, btn);
</code>
//elm_box_pack_end// add lab and btn widgets at the end of the pack list. So the lab and btn widgets appear as inside the box widget.
Otherwise, the blue section shows a certain number of characteristics of the object and widget: position, size, color, ... of course some of these characteristics are dynamic and can be updated with the reload button of Clouseau.
<code c>
elm_win_resize_object_add(win, box);
</code>
This function controls the size of the window such as it takes the minimum place. You can see in the blue section that the minimum and maximum size are equal as a consequence of this function call.
//**__Show objects__**//
As you can see on the picture below, click on setting in yellow and deselect //Only show Elementary widgets// in red.
{{:settings_clouseau.png?direct|Clouseau settings}}
In the result below, you see that all the objects are visible and you see that widgets are just gathered specific objects.
{{:clouseau_object.png?direct|Clouseau Objects}}
For example in yellow, it is the Elm_box which is an Evas_box composed of an Evas_rectangle, an Elm_Label and an Elm_Button.
A Button widget is an Edje_Object which is composed of 4 Evas_rectangle, one Evas_image and 2 Evas_text.