eo: allow valgrind-like tracking of object lifecycle.

Eo pointer indirection is super nice as it avoids you to access
invalid memory, but this extra checks inhibits valgrind's own tracking
of memory lifecycle, usually it would report when the object was
created and when the object is deleted, both as stack traces.

This commits introduces logging of object creation and destruction
under its own eina_log_domain and controlled by EO_LIFECYCLE_DEBUG and
EO_LIFECYCLE_NO_DEBUG envvars. These will only be available if
compiled with EO_DEBUG, thus shouldn't cause any performance hits on
production code.

Running a bogus app with invalid efl_class_name_get() and double
efl_del() will report as below:

```sh
$ export EO_LIFECYCLE_NO_DEBUG=Efl_Loop_Timer,Efl_Promise,Efl_Future
$ export EO_LIFECYCLE_DEBUG=1
$ export EINA_LOG_LEVELS=eo_lifecycle:4
$ /tmp/bogus_app
DBG:eo_lifecycle lib/eo/eo.c:2712 _eo_log_obj_init() will log all object allocation and free
DBG:eo_lifecycle lib/eo/eo.c:2788 _eo_log_obj_init() will NOT log class 'Efl_Future'
DBG:eo_lifecycle lib/eo/eo.c:2788 _eo_log_obj_init() will NOT log class 'Efl_Promise'
DBG:eo_lifecycle lib/eo/eo.c:2788 _eo_log_obj_init() will NOT log class 'Efl_Loop_Timer'
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35a1aa0 obj_id=0x4000000002cf38ef class=0x563fa35a1450 (Efl_Vpath_Core) [0.0004]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35af8d0 obj_id=0x4000000006cf38f0 class=0x563fa35aecf0 (Efl_Loop) [0.0005]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35d61a0 obj_id=0x400000007ecf390e class=0x563fa35d48f0 (Efl_Net_Dialer_Simple) [0.0054]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35d6470 obj_id=0x4000000082cf390f class=0x563fa35d0d60 (Efl_Net_Dialer_Tcp) [0.0055]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35d75b0 obj_id=0x4000000086cf3910 class=0x563fa35d66b0 (Efl_Io_Queue) [0.0056]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35d8f70 obj_id=0x400000008acf3911 class=0x563fa35d7860 (Efl_Io_Copier) [0.0057]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35df980 obj_id=0x40000000a6cf3918 class=0x563fa35d66b0 (Efl_Io_Queue) [0.0058]
DBG:eo_lifecycle lib/eo/eo.c:2665 _eo_log_obj_new() new obj=0x563fa35dfc30 obj_id=0x40000000aacf3919 class=0x563fa35d7860 (Efl_Io_Copier) [0.0058]

will efl_class_name_get() with invalid handle:

ERR:eo lib/eo/eo.c:1013 efl_class_name_get() Class (0x2000000000000029) is an invalid ref.
ERR:eo_lifecycle lib/eo/eo.c:1013 efl_class_name_get() obj_id=0x2000000000000029 was neither created or deleted (EO_LIFECYCLE_NO_DEBUG='Efl_Loop_Timer,Efl_Promise,Efl_Future').
DBG:eo_lifecycle lib/eo/eo.c:2688 _eo_log_obj_free() free obj=0x563fa35df980 obj_id=0x40000000a6cf3918 class=0x563fa35d66b0 (Efl_Io_Queue) [0.0061]
DBG:eo_lifecycle lib/eo/eo.c:2688 _eo_log_obj_free() free obj=0x563fa35dfc30 obj_id=0x40000000aacf3919 class=0x563fa35d7860 (Efl_Io_Copier) [0.0061]
DBG:eo_lifecycle lib/eo/eo.c:2688 _eo_log_obj_free() free obj=0x563fa35d75b0 obj_id=0x4000000086cf3910 class=0x563fa35d66b0 (Efl_Io_Queue) [0.0061]
DBG:eo_lifecycle lib/eo/eo.c:2688 _eo_log_obj_free() free obj=0x563fa35d8f70 obj_id=0x400000008acf3911 class=0x563fa35d7860 (Efl_Io_Copier) [0.0061]
DBG:eo_lifecycle lib/eo/eo.c:2688 _eo_log_obj_free() free obj=0x563fa35d6470 obj_id=0x4000000082cf390f class=0x563fa35d0d60 (Efl_Net_Dialer_Tcp) [0.0063]
DBG:eo_lifecycle lib/eo/eo.c:2688 _eo_log_obj_free() free obj=0x563fa35d61a0 obj_id=0x400000007ecf390e class=0x563fa35d48f0 (Efl_Net_Dialer_Simple) [0.0063]

will double free:

ERR:eo ../src/lib/eo/efl_object.eo.c:78 efl_del() EOID 0x400000007ecf390e is not a valid object. EOID domain=0, current_domain=0, local_domain=0. EOID generation=2cf390e, id=1f, ref=1, super=0. Thread self=main. Available domains [0 1    ]. Maybe it has been deleted or does not belong to your thread?
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del() obj_id=0x400000007ecf390e created obj=0x563fa35d61a0, class=0x563fa35d48f0 (Efl_Net_Dialer_Simple) [0.0054s, 0.0009 ago]:
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc6d0ea: libeo_dbg.so+0x90ea (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc6ca62: _efl_add_internal_start+0x1c2 (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x00563fa15dc95f: bogus_app+0x295f (in /tmp/bogus_app 0x563fa15da000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0ace7291: __libc_start_main+0xf1 (in /usr/lib/libc.so.6 0x7f2c0acc7000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x00563fa15dc48a: _start+0x2a (in /tmp/bogus_app 0x563fa15da000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del() obj_id=0x400000007ecf390e deleted obj=0x563fa35d61a0, class=0x563fa35d48f0 (Efl_Net_Dialer_Simple) [0.0063s, 0.0000 ago]:
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc6d8ba: libeo_dbg.so+0x98ba (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc6d711: libeo_dbg.so+0x9711 (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc6beb8: libeo_dbg.so+0x7eb8 (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc6c06e: _efl_object_call_end+0x4e (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0bc75725: efl_del+0x105 (in src/lib/eo/.libs/libeo_dbg.so 0x7f2c0bc64000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x00563fa15dcd54: lt-efl_net_dialer_simple_example+0x2d54 (in /tmp/bogus_app 0x563fa15da000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x007f2c0ace7291: __libc_start_main+0xf1 (in /usr/lib/libc.so.6 0x7f2c0acc7000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del()    0x00563fa15dc48a: _start+0x2a (in /tmp/bogus_app 0x563fa15da000)
ERR:eo_lifecycle ../src/lib/eo/efl_object.eo.c:78 efl_del() obj_id=0x400000007ecf390e was already deleted 0.0000 seconds ago!
```
This commit is contained in:
Gustavo Sverzut Barbieri 2016-12-02 20:48:37 -02:00
parent fc48161910
commit 227463bdde
5 changed files with 614 additions and 50 deletions

View File

@ -50,6 +50,7 @@ extern "C" {
* @li @ref eo_main_compiling
* @li @ref eo_main_next_steps
* @li @ref eo_main_intro_example
* @li @ref eo_lifecycle_debug
*
* @section eo_main_intro Introduction
*
@ -89,6 +90,66 @@ extern "C" {
* @li @ref Efl_Events
* @li @ref Eo_Composite_Objects
*
* @section eo_lifecycle_debug Debug Object Lifecycle
*
* When dealing with objects it's important to investigate the object
* lifecycle: when it was created, when it was deleted. This is not
* that trivial since objects can have extra references added with
* efl_ref() as well as removed with efl_unref(), efl_parent_set() to
* NULL or efl_del().
*
* To aid development process and debug memory leaks and invalid
* access, we provide eo_debug script helper that will preload
* libeo_dbg.so, run as:
*
* @verbatim
export EO_LIFECYCLE_DEBUG=1
export EINA_LOG_LEVELS=eo_lifecycle:4
eo_debug my_app
* @endverbatim
*
* This will print out all the objects that were created and deleted,
* as well as keep the stack trace that originated those, if a double
* free or user-after-free occurs it will print out the backtrace
* where the object was created and where it was deleted. If only
* errors should be displayed, decrease the log level to 2:
*
* @verbatim
export EO_LIFECYCLE_DEBUG=1
export EINA_LOG_LEVELS=eo_lifecycle:2 # just critical, error and warning
eo_debug my_app
* @endverbatim
*
* Keep in mind that the log will consume memory for all objects and
* that main loop primitives such as timers, jobs, promises and
* futures are all objects, being created in large numbers, thus
* consuming lots of memory.
*
* To address that log pollution and memory consumption, one can
* select just handful classes to be logged using @c
* EO_LIFECYCLE_DEBUG with a list of comma-separated class names. If
* @c EO_LIFECYCLE_DEBUG=1 or @c EO_LIFECYCLE_DEBUG=*, then all
* classes are logged, otherwise just the classes listed will be
* (whitelist).
*
* @verbatim
# Log only 2 classes: Efl_Loop and Efl_Net_Dialer_Tcp
export EO_LIFECYCLE_DEBUG=Efl_Loop,Efl_Net_Dialer_Tcp
export EINA_LOG_LEVELS=eo_lifecycle:4
eo_debug my_app
* @endverbatim
*
* Another approach is to log all but few classes, also known as
* blacklist. This is done with another environment variable @c
* EO_LIFECYCLE_NO_DEBUG=class1,class2.
*
* @verbatim
# Log all but Efl_Future, Efl_Promise and Efl_Loop_Timer
export EO_LIFECYCLE_NO_DEBUG=Efl_Future,Efl_Promise,Efl_Loop_Timer
export EINA_LOG_LEVELS=eo_lifecycle:4
eo_debug my_app
* @endverbatim
*
* @section eo_main_intro_example Introductory Example
*
* @ref Eo_Tutorial

View File

@ -14,6 +14,9 @@
#include "eo_add_fallback.h"
#include "efl_object_override.eo.c"
#ifdef HAVE_EXECINFO_H
#include <execinfo.h>
#endif
#define EO_CLASS_IDS_FIRST 1
#define EFL_OBJECT_OP_IDS_FIRST 1
@ -24,6 +27,27 @@ EAPI unsigned int _efl_object_init_generation = 1;
int _eo_log_dom = -1;
Eina_Thread _efl_object_main_thread;
static inline void _eo_log_obj_init(void);
static inline void _eo_log_obj_shutdown(void);
static inline void _eo_log_obj_new(const _Eo_Object *obj);
static inline void _eo_log_obj_free(const _Eo_Object *obj);
#ifdef EO_DEBUG
static int _eo_log_objs_dom = -1;
static Eina_Bool _eo_log_objs_enabled = EINA_FALSE;
static Eina_Inarray _eo_log_objs_debug;
static Eina_Inarray _eo_log_objs_no_debug;
static double _eo_log_time_start;
#ifdef HAVE_BACKTRACE
static Eina_Array _eo_log_objs;
#endif
#else
static inline void _eo_log_obj_init(void) { }
static inline void _eo_log_obj_shutdown(void) { }
static inline void _eo_log_obj_new(const _Eo_Object *obj EINA_UNUSED) { }
static inline void _eo_log_obj_free(const _Eo_Object *obj EINA_UNUSED) { }
void _eo_log_obj_report(const Eo_Id id EINA_UNUSED, int log_level EINA_UNUSED, const char *func_name EINA_UNUSED, const char *file EINA_UNUSED, int line EINA_UNUSED) { }
#endif
static _Efl_Class **_eo_classes = NULL;
static Eo_Id _eo_classes_last_id = 0;
static Eo_Id _eo_classes_alloc = 0;
@ -346,14 +370,14 @@ efl_super(const Eo *obj, const Efl_Class *cur_klass)
return (Eo *) ((Eo_Id) obj | MASK_SUPER_TAG);
err:
_EO_POINTER_ERR("Class (%p) is an invalid ref.", cur_klass);
_EO_POINTER_ERR(cur_klass, "Class (%p) is an invalid ref.", cur_klass);
return NULL;
err_obj:
_EO_POINTER_ERR("Object (%p) is an invalid ref, class=%p (%s).", obj, cur_klass, efl_class_name_get(cur_klass));
_EO_POINTER_ERR(obj, "Object (%p) is an invalid ref, class=%p (%s).", obj, cur_klass, efl_class_name_get(cur_klass));
return NULL;
#ifdef EO_DEBUG
err_obj_hierarchy:
_EO_POINTER_ERR("Object (%p) class=%p (%s) is not an instance of class=%p (%s).", obj, efl_class_get(obj), efl_class_name_get(obj), cur_klass, efl_class_name_get(cur_klass));
_EO_POINTER_ERR(obj, "Object (%p) class=%p (%s) is not an instance of class=%p (%s).", obj, efl_class_get(obj), efl_class_name_get(obj), cur_klass, efl_class_name_get(cur_klass));
#endif
return NULL;
}
@ -569,7 +593,7 @@ ok_klass:
goto ok_klass_back;
err_klass:
_EO_POINTER_ERR("in %s:%d: func '%s': obj_id=%p is an invalid ref.", file, line, func_name, eo_id);
_EO_POINTER_ERR(eo_id, "in %s:%d: func '%s': obj_id=%p is an invalid ref.", file, line, func_name, eo_id);
return EINA_FALSE;
}
@ -738,7 +762,7 @@ err_funcs:
ERR("Class %s already had its functions set..", klass->desc->name);
return EINA_FALSE;
err_klass:
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id);
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id);
return EINA_FALSE;
}
@ -785,6 +809,8 @@ _efl_add_internal_start(const char *file, int line, const Efl_Class *klass_id, E
obj->header.id = _eo_id_allocate(obj, parent_id);
Eo *eo_id = _eo_obj_id_get(obj);
_eo_log_obj_new(obj);
_eo_condtor_reset(obj);
efl_ref(eo_id);
@ -829,7 +855,7 @@ err_noreg:
return NULL;
err_klass:
_EO_POINTER_ERR("in %s:%d: Class (%p) is an invalid ref.", file, line, klass_id);
_EO_POINTER_ERR(klass_id, "in %s:%d: Class (%p) is an invalid ref.", file, line, klass_id);
err_parent:
return NULL;
}
@ -905,6 +931,42 @@ efl_reuse(const Eo *_obj)
efl_object_override(obj, NULL);
_efl_object_parent_sink_set(obj, EINA_FALSE);
}
void
_eo_free(_Eo_Object *obj)
{
_Efl_Class *klass = (_Efl_Class*) obj->klass;
_eo_log_obj_free(obj);
#ifdef EO_DEBUG
if (obj->datarefcount)
{
ERR("Object %p data still referenced %d time(s).", obj, obj->datarefcount);
}
#endif
if (_obj_is_override(obj))
{
_vtable_func_clean_all(obj->vtable);
eina_freeq_ptr_main_add(obj->vtable, free, 0);
obj->vtable = &klass->vtable;
}
_eo_id_release((Eo_Id) _eo_obj_id_get(obj));
eina_spinlock_take(&klass->objects.trash_lock);
if (klass->objects.trash_count <= 8)
{
eina_trash_push(&klass->objects.trash, obj);
klass->objects.trash_count++;
}
else
{
eina_freeq_ptr_main_add(obj, free, klass->obj_size);
}
eina_spinlock_release(&klass->objects.trash_lock);
}
/*****************************************************************************/
EAPI const Efl_Class *
@ -924,7 +986,7 @@ efl_class_get(const Eo *eo_id)
return klass;
err_klass:
_EO_POINTER_ERR("Class (%p) is an invalid ref.", eo_id);
_EO_POINTER_ERR(eo_id, "Class (%p) is an invalid ref.", eo_id);
err_obj:
return NULL;
}
@ -948,7 +1010,7 @@ efl_class_name_get(const Efl_Class *eo_id)
return klass->desc->name;
err_klass:
_EO_POINTER_ERR("Class (%p) is an invalid ref.", eo_id);
_EO_POINTER_ERR(eo_id, "Class (%p) is an invalid ref.", eo_id);
err_obj:
return NULL;
}
@ -1557,13 +1619,13 @@ efl_isa(const Eo *eo_id, const Efl_Class *klass_id)
return isa;
err_shared_class:
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id);
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id);
err_shared_obj:
eina_lock_release(&(_eo_table_data_shared_data->obj_lock));
return EINA_FALSE;
err_class:
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id);
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id);
err_obj:
return EINA_FALSE;
@ -1974,6 +2036,8 @@ efl_object_init(void)
return EINA_FALSE;
}
_eo_log_obj_init();
eina_magic_string_static_set(EO_EINA_MAGIC, EO_EINA_MAGIC_STR);
eina_magic_string_static_set(EO_FREED_EINA_MAGIC,
EO_FREED_EINA_MAGIC_STR);
@ -2072,6 +2136,8 @@ efl_object_shutdown(void)
_eo_table_data_shared_data = NULL;
}
_eo_log_obj_shutdown();
eina_log_domain_unregister(_eo_log_dom);
_eo_log_dom = -1;
@ -2280,3 +2346,465 @@ efl_callbacks_cmp(const Efl_Callback_Array_Item *a, const Efl_Callback_Array_Ite
else if (a->desc > b->desc) return 1;
else return -1;
}
#ifdef EO_DEBUG
#ifdef HAVE_BACKTRACE
typedef struct _Eo_Log_Obj_Entry {
Eo_Id id;
const _Eo_Object *obj;
const _Efl_Class *klass;
double timestamp;
Eina_Bool is_free;
uint8_t bt_size;
void *bt[];
} Eo_Log_Obj_Entry;
static void
_eo_log_obj_find(const Eo_Id id, const Eo_Log_Obj_Entry **added, const Eo_Log_Obj_Entry **deleted)
{
const Eo_Log_Obj_Entry *entry;
Eina_Array_Iterator it;
unsigned int idx;
*added = NULL;
*deleted = NULL;
EINA_ARRAY_ITER_NEXT(&_eo_log_objs, idx, entry, it)
{
if (EINA_UNLIKELY(id == entry->id))
{
if (entry->is_free)
*deleted = entry;
else
{
*added = entry;
*deleted = NULL; /* forget previous add, if any */
}
}
}
}
/* NOTE: cannot use ecore_time_get()! */
static inline double
_eo_log_time_now(void)
{
#ifdef HAVE_EVIL
return evil_time_get();
#elif defined(__APPLE__) && defined(__MACH__)
static double clk_conv = -1.0;
if (EINA_UNLIKELY(clk_conv < 0))
{
mach_timebase_info_data_t info;
kern_return_t err = mach_timebase_info(&info);
if (err == 0)
clk_conv = 1e-9 * (double)info.numer / (double)info.denom;
else
clk_conv = 1e-9;
}
return clk_conv * mach_absolute_time();
#else
#if defined (HAVE_CLOCK_GETTIME) || defined (EXOTIC_PROVIDE_CLOCK_GETTIME)
struct timespec t;
static int clk_id = -1;
if (EINA_UNLIKELY(clk_id == -2)) goto try_gettimeofday;
if (EINA_UNLIKELY(clk_id == -1))
{
retry_clk_id:
clk_id = CLOCK_MONOTONIC;
if (EINA_UNLIKELY(clock_gettime(clk_id, &t)))
{
WRN("CLOCK_MONOTONIC failed!");
clk_id = CLOCK_REALTIME;
if (EINA_UNLIKELY(clock_gettime(clk_id, &t)))
{
WRN("CLOCK_REALTIME failed!");
clk_id = -2;
goto try_gettimeofday;
}
}
}
else
{
if (EINA_UNLIKELY(clock_gettime(clk_id, &t)))
{
WRN("clk_id=%d previously ok, now failed... retry", clk_id);
goto retry_clk_id;
}
}
return (double)t.tv_sec + (((double)t.tv_nsec) / 1000000000.0);
try_gettimeofday:
#endif
{
struct timeval timev;
gettimeofday(&timev, NULL);
return (double)timev.tv_sec + (((double)timev.tv_usec) / 1000000);
}
#endif
}
static void
_eo_log_obj_entry_show(const Eo_Log_Obj_Entry *entry, int log_level, const char *func_name, const char *file, int line, double now)
{
uint8_t i;
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
"obj_id=%p %s obj=%p, class=%p (%s) [%0.4fs, %0.4f ago]:",
(void *)entry->id,
entry->is_free ? "deleted" : "created",
entry->obj,
entry->klass,
entry->klass->desc->name,
entry->timestamp - _eo_log_time_start, now - entry->timestamp);
for (i = 0; i < entry->bt_size; i++)
{
#ifdef HAVE_DLADDR
Dl_info info;
if (dladdr(entry->bt[i], &info))
{
if (info.dli_sname)
{
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
" %#016" PRIx64 ": %s+%#" PRIx64 " (in %s %#" PRIx64 ")",
(uint64_t)entry->bt[i],
info.dli_sname,
(char *)entry->bt[i] - (char *)info.dli_saddr,
info.dli_fname ? info.dli_fname : "??",
(uint64_t)info.dli_fbase);
continue;
}
else if (info.dli_fname)
{
const char *fname;
#ifdef HAVE_EVIL
fname = strrchr(info.dli_fname, '\\');
#else
fname = strrchr(info.dli_fname, '/');
#endif
if (!fname) fname = info.dli_fname;
else fname++;
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
" %#016" PRIx64 ": %s+%#" PRIx64 " (in %s %#" PRIx64 ")",
(uint64_t)entry->bt[i],
fname,
(char *)entry->bt[i] - (char *)info.dli_fbase,
info.dli_fname,
(uint64_t)info.dli_fbase);
continue;
}
}
#endif
eina_log_print(_eo_log_objs_dom, log_level, func_name, file, line,
" %#016" PRIx64, (uint64_t)entry->bt[i]);
}
}
#endif
inline void
_eo_log_obj_report(const Eo_Id id, int log_level, const char *func_name, const char *file, int line)
{
#ifdef HAVE_BACKTRACE
const Eo_Log_Obj_Entry *added, *deleted;
double now;
if (EINA_LIKELY(!_eo_log_objs_enabled)) return;
_eo_log_obj_find(id, &added, &deleted);
if ((!added) && (!deleted))
{
if ((!_eo_log_objs_debug.len) && (!_eo_log_objs_no_debug.len))
{
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
"obj_id=%p was neither created or deleted.", (void *)id);
}
else if ((_eo_log_objs_debug.len) && (_eo_log_objs_no_debug.len))
{
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
"obj_id=%p was neither created or deleted (EO_LIFECYCLE_DEBUG='%s', EO_LIFECYCLE_NO_DEBUG='%s').",
(void *)id, getenv("EO_LIFECYCLE_DEBUG"), getenv("EO_LIFECYCLE_NO_DEBUG"));
}
else if (_eo_log_objs_debug.len)
{
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
"obj_id=%p was neither created or deleted (EO_LIFECYCLE_DEBUG='%s').",
(void *)id, getenv("EO_LIFECYCLE_DEBUG"));
}
else
{
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
"obj_id=%p was neither created or deleted (EO_LIFECYCLE_NO_DEBUG='%s').",
(void *)id, getenv("EO_LIFECYCLE_NO_DEBUG"));
}
return;
}
now = _eo_log_time_now();
if (added)
_eo_log_obj_entry_show(added, log_level, func_name, file, line, now);
if (deleted)
{
_eo_log_obj_entry_show(deleted, log_level, func_name, file, line, now);
eina_log_print(_eo_log_objs_dom, log_level, file, func_name, line,
"obj_id=%p was already deleted %0.4f seconds ago!",
(void *)id, now - deleted->timestamp);
}
#else
(void)id;
(void)log_level;
(void)func_name;
(void)file;
(void)line;
#endif
}
#ifdef HAVE_BACKTRACE
static Eo_Log_Obj_Entry *
_eo_log_obj_entry_new_and_add(const _Eo_Object *obj, Eina_Bool is_free, uint8_t size, void *const *bt)
{
Eo_Log_Obj_Entry *entry;
entry = malloc(sizeof(Eo_Log_Obj_Entry) + size * sizeof(void *));
if (EINA_UNLIKELY(!entry)) return NULL;
entry->id = (Eo_Id)_eo_obj_id_get(obj);
entry->timestamp = _eo_log_time_now();
entry->obj = obj;
entry->klass = obj->klass;
entry->is_free = is_free;
entry->bt_size = size;
memcpy(entry->bt, bt, size * sizeof(void *));
if (EINA_UNLIKELY(!entry)) return NULL;
if (!eina_array_push(&_eo_log_objs, entry))
{
free(entry);
return NULL;
}
return entry;
}
static inline void
_eo_log_obj_entry_free(Eo_Log_Obj_Entry *entry)
{
free(entry);
}
#endif
static int
_eo_class_name_slice_cmp(const void *pa, const void *pb)
{
const Eina_Slice *a = pa;
const Eina_Slice *b = pb;
if (a->len < b->len) return -1;
if (a->len > b->len) return 1;
return memcmp(a->mem, b->mem, a->len);
}
static Eina_Bool
_eo_log_obj_desired(const _Eo_Object *obj)
{
Eina_Slice cls_name;
if (EINA_LIKELY((_eo_log_objs_debug.len == 0) &&
(_eo_log_objs_no_debug.len == 0)))
return EINA_TRUE;
cls_name.mem = obj->klass->desc->name;
cls_name.len = strlen(cls_name.mem);
if (_eo_log_objs_no_debug.len)
{
if (eina_inarray_search_sorted(&_eo_log_objs_no_debug, &cls_name, _eo_class_name_slice_cmp) >= 0)
return EINA_FALSE;
}
if (!_eo_log_objs_debug.len)
return EINA_TRUE;
if (eina_inarray_search_sorted(&_eo_log_objs_debug, &cls_name, _eo_class_name_slice_cmp) >= 0)
return EINA_TRUE;
return EINA_FALSE;
}
static inline void
_eo_log_obj_new(const _Eo_Object *obj)
{
#ifdef HAVE_BACKTRACE
void *bt[64];
int size;
#endif
if (EINA_LIKELY(!_eo_log_objs_enabled)) return;
if (EINA_LIKELY(!_eo_log_obj_desired(obj))) return;
#ifdef HAVE_BACKTRACE
size = backtrace(bt, sizeof(bt)/sizeof(bt[0]));
if (EINA_UNLIKELY(size < 1)) return;
_eo_log_obj_entry_new_and_add(obj, EINA_FALSE, size, bt);
#endif
EINA_LOG_DOM_DBG(_eo_log_objs_dom,
"new obj=%p obj_id=%p class=%p (%s) [%0.4f]",
obj, _eo_obj_id_get(obj), obj->klass, obj->klass->desc->name,
_eo_log_time_now() - _eo_log_time_start);
}
static inline void
_eo_log_obj_free(const _Eo_Object *obj)
{
#ifdef HAVE_BACKTRACE
void *bt[64];
int size;
#endif
if (EINA_LIKELY(!_eo_log_objs_enabled)) return;
if (EINA_LIKELY(!_eo_log_obj_desired(obj))) return;
#ifdef HAVE_BACKTRACE
size = backtrace(bt, sizeof(bt)/sizeof(bt[0]));
if (EINA_UNLIKELY(size < 1)) return;
_eo_log_obj_entry_new_and_add(obj, EINA_TRUE, size, bt);
#endif
EINA_LOG_DOM_DBG(_eo_log_objs_dom,
"free obj=%p obj_id=%p class=%p (%s) [%0.4f]",
obj, _eo_obj_id_get(obj), obj->klass, obj->klass->desc->name,
_eo_log_time_now() - _eo_log_time_start);
}
static inline void
_eo_log_obj_init(void)
{
const char *s;
_eo_log_objs_dom = eina_log_domain_register("eo_lifecycle", EINA_COLOR_BLUE);
_eo_log_time_start = _eo_log_time_now();
#ifdef HAVE_BACKTRACE
eina_array_step_set(&_eo_log_objs, sizeof(Eina_Array), 4096);
#endif
eina_inarray_step_set(&_eo_log_objs_debug, sizeof(Eina_Inarray), sizeof(Eina_Slice), 0);
eina_inarray_step_set(&_eo_log_objs_no_debug, sizeof(Eina_Inarray), sizeof(Eina_Slice), 0);
s = getenv("EO_LIFECYCLE_DEBUG");
if ((s) && (s[0] != '\0'))
{
_eo_log_objs_enabled = EINA_TRUE;
if ((strcmp(s, "*") == 0) || (strcmp(s, "1") == 0))
{
EINA_LOG_DOM_DBG(_eo_log_objs_dom,
"will log all object allocation and free");
}
else
{
Eina_Slice slice;
const Eina_Slice *itr;
do
{
char *p = strchr(s, ',');
slice.mem = s;
if (p)
{
slice.len = p - s;
s = p + 1;
}
else
{
slice.len = strlen(s);
s = NULL;
}
eina_inarray_push(&_eo_log_objs_debug, &slice);
}
while (s);
eina_inarray_sort(&_eo_log_objs_debug, _eo_class_name_slice_cmp);
EINA_INARRAY_FOREACH(&_eo_log_objs_debug, itr)
{
EINA_LOG_DOM_DBG(_eo_log_objs_dom,
"will log class '" EINA_SLICE_STR_FMT "'",
EINA_SLICE_STR_PRINT(*itr));
}
}
#ifndef HAVE_BACKTRACE
WRN("EO_LIFECYCLE_DEBUG='%s' but your system has no backtrace()!", s);
#endif
}
if (EINA_LIKELY(!_eo_log_objs_enabled)) return;
DBG("logging object allocation and free, use EINA_LOG_LEVELS=eo_lifecycle:4");
s = getenv("EO_LIFECYCLE_NO_DEBUG");
if ((s) && (s[0] != '\0'))
{
if ((strcmp(s, "*") == 0) || (strcmp(s, "1") == 0))
{
EINA_LOG_DOM_ERR(_eo_log_objs_dom,
"expected class names to not log allocation and free, got '%s'", s);
}
else
{
Eina_Slice slice;
const Eina_Slice *itr;
do
{
char *p = strchr(s, ',');
slice.mem = s;
if (p)
{
slice.len = p - s;
s = p + 1;
}
else
{
slice.len = strlen(s);
s = NULL;
}
eina_inarray_push(&_eo_log_objs_no_debug, &slice);
}
while (s);
eina_inarray_sort(&_eo_log_objs_no_debug, _eo_class_name_slice_cmp);
EINA_INARRAY_FOREACH(&_eo_log_objs_no_debug, itr)
{
EINA_LOG_DOM_DBG(_eo_log_objs_dom,
"will NOT log class '" EINA_SLICE_STR_FMT "'",
EINA_SLICE_STR_PRINT(*itr));
}
}
}
}
static inline void
_eo_log_obj_shutdown(void)
{
#ifdef HAVE_BACKTRACE
Eo_Log_Obj_Entry *entry;
Eina_Array_Iterator it;
unsigned int idx;
EINA_ARRAY_ITER_NEXT(&_eo_log_objs, idx, entry, it)
_eo_log_obj_entry_free(entry);
eina_array_flush(&_eo_log_objs);
#endif
eina_inarray_flush(&_eo_log_objs_debug);
eina_inarray_flush(&_eo_log_objs_no_debug);
}
#endif

View File

@ -196,6 +196,9 @@ typedef struct
int line;
} Eo_Xref_Node;
/* provide valgrind-like tracking of object allocationg and deletion */
void _eo_log_obj_report(const Eo_Id id, int log_level, const char *func_name, const char *file, int line);
void _efl_object_parent_sink_set(Eo *obj, Eina_Bool sink);
static inline
@ -270,38 +273,7 @@ _obj_is_override(_Eo_Object *obj)
return (obj->vtable != &obj->klass->vtable);
}
static inline void
_eo_free(_Eo_Object *obj)
{
_Efl_Class *klass = (_Efl_Class*) obj->klass;
#ifdef EO_DEBUG
if (obj->datarefcount)
{
ERR("Object %p data still referenced %d time(s).", obj, obj->datarefcount);
}
#endif
if (_obj_is_override(obj))
{
_vtable_func_clean_all(obj->vtable);
eina_freeq_ptr_main_add(obj->vtable, free, 0);
obj->vtable = &klass->vtable;
}
_eo_id_release((Eo_Id) _eo_obj_id_get(obj));
eina_spinlock_take(&klass->objects.trash_lock);
if (klass->objects.trash_count <= 8)
{
eina_trash_push(&klass->objects.trash, obj);
klass->objects.trash_count++;
}
else
{
eina_freeq_ptr_main_add(obj, free, klass->obj_size);
}
eina_spinlock_release(&klass->objects.trash_lock);
}
void _eo_free(_Eo_Object *obj);
static inline _Eo_Object *
_efl_ref(_Eo_Object *obj)

View File

@ -15,13 +15,14 @@ Eo_Id_Table_Data *_eo_table_data_shared_data = NULL;
//////////////////////////////////////////////////////////////////////////
void
_eo_pointer_error(const char *func_name, const char *file, int line, const char *fmt, ...)
_eo_pointer_error(const Eo *obj_id, const char *func_name, const char *file, int line, const char *fmt, ...)
{
/* NOTE: this function exists to allow easy breakpoint on pointer errors */
va_list args;
va_start(args, fmt);
eina_log_vprint(_eo_log_dom, EINA_LOG_LEVEL_ERR, file, func_name, line, fmt, args);
va_end(args);
_eo_log_obj_report((Eo_Id)obj_id, EINA_LOG_LEVEL_ERR, func_name, file, line);
}
#ifdef HAVE_EO_ID
@ -66,6 +67,7 @@ _eo_obj_pointer_invalid(const Eo_Id obj_id,
(data->tables[2]) ? "2" : " ",
(data->tables[3]) ? "3" : " "
);
_eo_log_obj_report(obj_id, EINA_LOG_LEVEL_ERR, func_name, file, line);
}
#endif
@ -195,6 +197,7 @@ err:
if (EINA_UNLIKELY(!EINA_MAGIC_CHECK(obj, EO_EINA_MAGIC)))
{
eina_magic_fail(obj, obj->__magic, EO_EINA_MAGIC, file, func_name, line);
_eo_log_obj_report(obj_id, EINA_LOG_LEVEL_ERR, func_name, file, line);
return NULL;
}
return (_Eo_Object *) obj_id;

View File

@ -6,10 +6,10 @@
/* Macro used to obtain the object pointer and return if fails. */
void _eo_pointer_error(const char *func_name, const char *file, int line, const char *fmt, ...);
void _eo_pointer_error(const Eo *obj_id, const char *func_name, const char *file, int line, const char *fmt, ...);
#define _EO_POINTER_ERR(fmt, ...) \
_eo_pointer_error(__FUNCTION__, __FILE__, __LINE__, fmt, __VA_ARGS__)
#define _EO_POINTER_ERR(obj_id, fmt, ...) \
_eo_pointer_error(obj_id, __FUNCTION__, __FILE__, __LINE__, fmt, __VA_ARGS__)
#define EO_OBJ_POINTER(obj_id, obj) \
_Eo_Object *obj; \
@ -83,7 +83,7 @@ void _eo_pointer_error(const char *func_name, const char *file, int line, const
do { \
klass = _eo_class_pointer_get(klass_id, __FUNCTION__, __FILE__, __LINE__); \
if (!klass) { \
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id); \
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id); \
return ret; \
} \
} while (0)
@ -93,7 +93,7 @@ void _eo_pointer_error(const char *func_name, const char *file, int line, const
do { \
klass = _eo_class_pointer_get(klass_id, func_name, file, line); \
if (!klass) { \
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id); \
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id); \
return ret; \
} \
} while (0)
@ -103,7 +103,7 @@ void _eo_pointer_error(const char *func_name, const char *file, int line, const
do { \
klass = _eo_class_pointer_get(klass_id, __FUNCTION__, __FILE__, __LINE__); \
if (!klass) { \
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id); \
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id); \
return; \
} \
} while (0)
@ -113,7 +113,7 @@ void _eo_pointer_error(const char *func_name, const char *file, int line, const
do { \
klass = _eo_class_pointer_get(klass_id, func_name, file, line); \
if (!klass) { \
_EO_POINTER_ERR("Class (%p) is an invalid ref.", klass_id); \
_EO_POINTER_ERR(klass_id, "Class (%p) is an invalid ref.", klass_id); \
return; \
} \
} while (0)