From 6f01b8f9d51c80fec3bc28c37784abccd0574740 Mon Sep 17 00:00:00 2001 From: Andrew Williams Date: Fri, 20 Oct 2017 09:21:42 -0700 Subject: [PATCH] Wiki page apps_efl_debugging changed with summary [refactoring developer docs] by Andrew Williams --- pages/develop/apps_efl_debugging.txt | 488 +++++++++++++++++++++++++++ 1 file changed, 488 insertions(+) create mode 100644 pages/develop/apps_efl_debugging.txt diff --git a/pages/develop/apps_efl_debugging.txt b/pages/develop/apps_efl_debugging.txt new file mode 100644 index 000000000..8e29e6920 --- /dev/null +++ b/pages/develop/apps_efl_debugging.txt @@ -0,0 +1,488 @@ +~~Title: Apps debugging~~ +==== EFL application debugging ==== + + +//Please also see [[/contrib/efl-debug|EFL Debugging]] if you want to learn more about debugging our libraries.// + + +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 [[/contrib/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. + + +# Debug log level +EINA_LOG_LEVEL=5 ./my_test_efl + + +The ''EINA_LOG_LEVELS'' variable provide a way to activate logs only for specific modules. + + +# This will set module1 and module2 respectively to log level 5 and 2 +EINA_LOG_LEVELS=module1:5,module2:2 ./my_test_efl + + +---- + +=== 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: + + +#include + +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() + + +Compile with -g flag to have debugging symbols and execute it: + + +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'. + + +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: + + +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 , 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 + + +//elm_obj_box_pack_end// is in frame 6, so called from frame 7 + +Go to frame 7: + + +(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 + + +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: + + +#include + +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() + + +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?__**// + + +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=, eo_obj=, desc=, event_info=) 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 + "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=, + obj=, emission=, source=) at + elm_button.c:191 +#7 0x00007ffff60d0425 in edje_match_callback_exec_check_finals (prop=, ed=, source=, + sig=, source_states=, signal_states=, matches=, ssp=) 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=) at lib/edje/edje_message_queue.c:155 +#14 0x00007ffff696d3e0 in _ecore_job_event_handler (data=, type=, ev=) at lib/ecore/ecore_job.c:113 +#15 0x00007ffff69680a4 in _ecore_call_handler_cb (event=, + type=, data=, func=) 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 + + +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 + + +(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 + + +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. + + +#include + +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() + + +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. + + +... +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) +... + + +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: + + +git clone https://git.enlightenment.org/tools/clouseau.git + + +Here is a simple helloworld to test with Clouseau, it displays a window with some text and one button to exit. + + +#include + +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() + + +To launch it with Clouseau: + + +clousseau ./helloworld + + +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//. + + +win = elm_win_util_standard_add("hello", "Hello"); +... +box = elm_box_add(win); + + +//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. + + +elm_box_pack_end(box, lab); +... +elm_box_pack_end(box, btn); + + +//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. + + +elm_win_resize_object_add(win, box); + + +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. \ No newline at end of file