diff --git a/ChangeLog b/ChangeLog index 680af607c2..0313cdbc9f 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,9 +1,12 @@ +2013-03-27 Cedric Bail + + * Eina: Add eina_log_timing. + 2013-03-27 Jihoon Kim * Add ecore_imf_context_input_panel_variation_set/get API. * Add edje_object_part_text_input_panel_layout_variation_set/get API. - 2013-03-25 Cedric Bail * Eina: add portable eina_file_mkstemp(). diff --git a/NEWS b/NEWS index 31f8b5b8b7..cf5c8fe84e 100644 --- a/NEWS +++ b/NEWS @@ -22,6 +22,7 @@ Additions: - Add eina_log_print_cb_journald() - Add eina_list_shuffle() - Add eina_file_mkstemp() + - Add eina_log_timing() * Add Cserve2 scalecache support * ecore_x: - Add window profile support. diff --git a/src/lib/eina/eina_counter.c b/src/lib/eina/eina_counter.c index 6ca94179c9..63a183de42 100644 --- a/src/lib/eina/eina_counter.c +++ b/src/lib/eina/eina_counter.c @@ -24,14 +24,6 @@ #include #include #include -#ifndef _WIN32 -# include -# include -#else -# define WIN32_LEAN_AND_MEAN -# include -# undef WIN32_LEAN_AND_MEAN -#endif /* _WIN2 */ #include "eina_config.h" #include "eina_private.h" @@ -46,6 +38,8 @@ # include #endif +#include "eina_private.h" + /*============================================================================* * Local * *============================================================================*/ @@ -54,12 +48,6 @@ * @cond LOCAL */ -#ifndef _WIN32 -typedef struct timespec Eina_Nano_Time; -#else -typedef LARGE_INTEGER Eina_Nano_Time; -#endif - typedef struct _Eina_Clock Eina_Clock; struct _Eina_Counter @@ -81,40 +69,12 @@ struct _Eina_Clock Eina_Bool valid; }; -#ifndef _WIN32 -static inline int -_eina_counter_time_get(Eina_Nano_Time *tp) -{ -# if defined(CLOCK_PROCESS_CPUTIME_ID) - return clock_gettime(CLOCK_PROCESS_CPUTIME_ID, tp); -# elif defined(CLOCK_PROF) - return clock_gettime(CLOCK_PROF, tp); -# elif defined(CLOCK_REALTIME) - return clock_gettime(CLOCK_REALTIME, tp); -# else - struct timeval tv; - - if (gettimeofday(&tv, NULL)) - return -1; - - tp->tv_sec = tv.tv_sec; - tp->tv_nsec = tv.tv_usec * 1000L; - - return 0; -# endif -} -#else +#ifdef _WIN32 static const char EINA_ERROR_COUNTER_WINDOWS_STR[] = "Change your OS, you moron !"; static int EINA_ERROR_COUNTER_WINDOWS = 0; -static LARGE_INTEGER _eina_counter_frequency; - -static inline int -_eina_counter_time_get(Eina_Nano_Time *tp) -{ - return QueryPerformanceCounter(tp); -} -#endif /* _WIN2 */ +LARGE_INTEGER _eina_counter_frequency; +#endif static char * _eina_counter_asiprintf(char *base, int *position, const char *format, ...) @@ -265,10 +225,10 @@ eina_counter_start(Eina_Counter *counter) Eina_Nano_Time tp; EINA_SAFETY_ON_NULL_RETURN(counter); - if (_eina_counter_time_get(&tp) != 0) + if (_eina_time_get(&tp) != 0) return; - eina_error_set(0); + eina_error_set(0); clk = calloc(1, sizeof (Eina_Clock)); if (!clk) { @@ -289,7 +249,7 @@ eina_counter_stop(Eina_Counter *counter, int specimen) Eina_Nano_Time tp; EINA_SAFETY_ON_NULL_RETURN(counter); - if (_eina_counter_time_get(&tp) != 0) + if (_eina_time_get(&tp) != 0) return; clk = (Eina_Clock *)counter->clocks; @@ -327,28 +287,9 @@ eina_counter_dump(Eina_Counter *counter) if (clk->valid == EINA_FALSE) continue; -#ifndef _WIN32 - start = clk->start.tv_sec * 1000000000 + clk->start.tv_nsec; - end = clk->end.tv_sec * 1000000000 + clk->end.tv_nsec; - diff = - (clk->end.tv_sec - - clk->start.tv_sec) * 1000000000 + clk->end.tv_nsec - - clk->start.tv_nsec; -#else - start = - (long int)(((long long int)clk->start.QuadPart * - 1000000000ll) / - (long long int)_eina_counter_frequency.QuadPart); - end = - (long int)(((long long int)clk->end.QuadPart * - 1000000000LL) / - (long long int)_eina_counter_frequency.QuadPart); - diff = - (long int)(((long long int)(clk->end.QuadPart - - clk->start.QuadPart) * - 1000000000LL) / - (long long int)_eina_counter_frequency.QuadPart); -#endif /* _WIN2 */ + start = _eina_time_convert(&clk->start); + end = _eina_time_convert(&clk->end); + diff = _eina_time_delta(&clk->start, &clk->end); result = _eina_counter_asiprintf(result, &position, "%i\t%li\t%li\t%li\n", diff --git a/src/lib/eina/eina_inline_private.h b/src/lib/eina/eina_inline_private.h new file mode 100644 index 0000000000..ee0c49bb94 --- /dev/null +++ b/src/lib/eina/eina_inline_private.h @@ -0,0 +1,97 @@ +/* EINA - EFL data type library + * Copyright (C) 2013 Cedric Bail + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; + * if not, see . + */ + +#ifndef EINA_INLINE_PRIVATE_H_ +# define EINA_INLINE_PRIVATE_H_ + +#ifndef _WIN32 +# include +# include +#else +# define WIN32_LEAN_AND_MEAN +# include +# undef WIN32_LEAN_AND_MEAN +#endif /* _WIN2 */ + +#ifndef _WIN32 +typedef struct timespec Eina_Nano_Time; +#else +typedef LARGE_INTEGER Eina_Nano_Time; + +extern LARGE_INTEGER _eina_counter_frequency; +#endif + +static inline int +_eina_time_get(Eina_Nano_Time *tp) +{ +#ifndef _WIN32 +# if defined(CLOCK_PROCESS_CPUTIME_ID) + return clock_gettime(CLOCK_PROCESS_CPUTIME_ID, tp); +# elif defined(CLOCK_PROF) + return clock_gettime(CLOCK_PROF, tp); +# elif defined(CLOCK_REALTIME) + return clock_gettime(CLOCK_REALTIME, tp); +# else + struct timeval tv; + + if (gettimeofday(&tv, NULL)) + return -1; + + tp->tv_sec = tv.tv_sec; + tp->tv_nsec = tv.tv_usec * 1000L; + + return 0; +# endif +#else + return QueryPerformanceCounter(tp); +#endif /* _WIN2 */ +} + +static inline long int +_eina_time_convert(Eina_Nano_Time *tp) +{ + long int r; + +#ifndef _WIN32 + r = tp->tv_sec * 1000000000 + tp->tv_nsec; +#else + r = (long int)(((long long int)tp->QuadPart * 1000000000ll) / + (long long int)_eina_counter_frequency.QuadPart); +#endif + + return r; +} + +static inline long int +_eina_time_delta(Eina_Nano_Time *start, Eina_Nano_Time *end) +{ + long int r; + +#ifndef _WIN32 + r = (end->tv_sec - start->tv_sec) * 1000000000 + + end->tv_nsec - start->tv_nsec; +#else + r = (long int)(((long long int)(end->QuadPart - start->QuadPart) + * 1000000000LL) + / (long long int)_eina_counter_frequency.QuadPart); +#endif + + return r; +} + +#endif diff --git a/src/lib/eina/eina_log.c b/src/lib/eina/eina_log.c index ec2d1ed2a8..90eb93301c 100644 --- a/src/lib/eina/eina_log.c +++ b/src/lib/eina/eina_log.c @@ -54,6 +54,8 @@ #include "eina_safety_checks.h" #include "eina_log.h" +#include "eina_inline_private.h" + /* TODO * + printing logs to stdout or stderr can be implemented * using a queue, useful for multiple threads printing @@ -91,6 +93,14 @@ struct _Eina_Log_Domain_Level_Pending char name[]; }; +typedef struct _Eina_Log_Timing Eina_Log_Timing; +struct _Eina_Log_Timing +{ + const char *phase; + Eina_Nano_Time start; + Eina_Log_State state; +}; + /* * List of levels for domains set by the user before the domains are registered, * updates the domain levels on the first log and clears itself. @@ -104,6 +114,7 @@ static Eina_Bool _disable_color = EINA_FALSE; static Eina_Bool _disable_file = EINA_FALSE; static Eina_Bool _disable_function = EINA_FALSE; static Eina_Bool _abort_on_critical = EINA_FALSE; +static Eina_Bool _disable_timing = EINA_TRUE; static int _abort_level_on_critical = EINA_LOG_LEVEL_CRITICAL; #ifdef EINA_LOG_BACKTRACE @@ -179,6 +190,7 @@ static Eina_Lock _log_mutex; // List of domains registered static Eina_Log_Domain *_log_domains = NULL; +static Eina_Log_Timing *_log_timing = NULL; static unsigned int _log_domains_count = 0; static size_t _log_domains_allocated = 0; @@ -940,7 +952,8 @@ eina_log_domain_str_get(const char *name, const char *color) * constructor acts upon an pre-allocated object. */ static Eina_Log_Domain * -eina_log_domain_new(Eina_Log_Domain *d, const char *name, const char *color) +eina_log_domain_new(Eina_Log_Domain *d, Eina_Log_Timing *t, + const char *name, const char *color) { EINA_SAFETY_ON_NULL_RETURN_VAL(d, NULL); EINA_SAFETY_ON_NULL_RETURN_VAL(name, NULL); @@ -956,6 +969,8 @@ eina_log_domain_new(Eina_Log_Domain *d, const char *name, const char *color) d->name = strdup(name); d->namelen = strlen(name); + t->phase = NULL; + return d; } @@ -1082,7 +1097,7 @@ eina_log_domain_register_unlocked(const char *name, const char *color) if (_log_domains[i].deleted) { // Found a flagged slot, free domain_str and replace slot - eina_log_domain_new(&_log_domains[i], name, color); + eina_log_domain_new(&_log_domains[i], &_log_timing[i], name, color); goto finish_register; } } @@ -1090,6 +1105,7 @@ eina_log_domain_register_unlocked(const char *name, const char *color) if (_log_domains_count >= _log_domains_allocated) { Eina_Log_Domain *tmp; + Eina_Log_Timing *tim; size_t size; if (!_log_domains) @@ -1100,19 +1116,25 @@ eina_log_domain_register_unlocked(const char *name, const char *color) size = _log_domains_allocated + 8; tmp = realloc(_log_domains, sizeof(Eina_Log_Domain) * size); + tim = realloc(_log_timing, sizeof (Eina_Log_Timing) * size); - if (tmp) + if (tmp && tim) { // Success! _log_domains = tmp; + _log_timing = tim; _log_domains_allocated = size; } else - return -1; + { + free(tmp); + free(tim); + return -1; + } } // Use an allocated slot - eina_log_domain_new(&_log_domains[i], name, color); + eina_log_domain_new(&_log_domains[i], &_log_timing[i], name, color); _log_domains_count++; finish_register: @@ -1143,6 +1165,8 @@ finish_register: if (_log_domains[i].level == EINA_LOG_LEVEL_UNKNOWN) _log_domains[i].level = _log_level; + eina_log_timing(i, EINA_LOG_STATE_START, EINA_LOG_STATE_INIT); + return i; } @@ -1198,6 +1222,8 @@ eina_log_domain_unregister_unlocked(int domain) if ((unsigned int)domain >= _log_domains_count) return; + eina_log_timing(domain, EINA_LOG_STATE_STOP, EINA_LOG_STATE_SHUTDOWN); + d = &_log_domains[domain]; eina_log_domain_free(d); d->deleted = 1; @@ -1365,6 +1391,9 @@ eina_log_init(void) _print_cb = eina_log_print_cb_journald; #endif + if (getenv("EINA_LOG_TIMING")) + _disable_timing = EINA_FALSE; + if ((tmp = getenv(EINA_LOG_ENV_FILE_DISABLE)) && (atoi(tmp) == 1)) _disable_file = EINA_TRUE; @@ -1402,6 +1431,10 @@ eina_log_init(void) // Parse pending domains passed through EINA_LOG_LEVELS eina_log_domain_parse_pendings(); + eina_log_timing(EINA_LOG_DOMAIN_GLOBAL, + EINA_LOG_STATE_STOP, + EINA_LOG_STATE_INIT); + #endif return EINA_TRUE; } @@ -1427,6 +1460,10 @@ eina_log_shutdown(void) #ifdef EINA_ENABLE_LOG Eina_Inlist *tmp; + eina_log_timing(EINA_LOG_DOMAIN_GLOBAL, + EINA_LOG_STATE_START, + EINA_LOG_STATE_SHUTDOWN); + while (_log_domains_count--) { if (_log_domains[_log_domains_count].deleted) @@ -1435,7 +1472,8 @@ eina_log_shutdown(void) eina_log_domain_free(&_log_domains[_log_domains_count]); } - free(_log_domains); + free(_log_domains); + free(_log_timing); _log_domains = NULL; _log_domains_count = 0; @@ -2118,3 +2156,60 @@ eina_log_console_color_set(FILE *fp, const char *color) (void)color; #endif } + +EAPI void +eina_log_timing(int domain, + Eina_Log_State state, + const char *phase) +{ + Eina_Log_Domain *d; + Eina_Log_Timing *t; + + if (_disable_timing) return ; + + d = _log_domains + domain; + t = _log_timing + domain; +#ifdef EINA_SAFETY_CHECKS + if (EINA_UNLIKELY(d->deleted)) + { + fprintf(stderr, + "ERR: eina_log_print() domain %d is deleted\n", + domain); + return; + } +#endif + + if (t->phase == EINA_LOG_STATE_INIT && + phase == EINA_LOG_STATE_SHUTDOWN) + return ; + + if (state == EINA_LOG_STATE_START && + t->phase && + strcmp(t->phase, phase)) // Different phase + { + fprintf(stderr, "%s vs %s\n", t->phase, phase); + eina_log_timing(domain, EINA_LOG_STATE_STOP, t->phase); + } + + switch (state) + { + case EINA_LOG_STATE_START: + { + _eina_time_get(&t->start); + t->phase = phase; + break; + } + case EINA_LOG_STATE_STOP: + { + Eina_Nano_Time end; + long int r; + + _eina_time_get(&end); + r = _eina_time_delta(&t->start, &end); + EINA_LOG_DOM_INFO(domain, "%s timing: %li", t->phase, r); + + t->phase = NULL; + break; + } + } +} diff --git a/src/lib/eina/eina_log.h b/src/lib/eina/eina_log.h index f3980bffc8..40bc3fb0c8 100644 --- a/src/lib/eina/eina_log.h +++ b/src/lib/eina/eina_log.h @@ -464,6 +464,12 @@ typedef void (*Eina_Log_Print_Cb)(const Eina_Log_Domain *d, const char *file, const char *fnc, int line, const char *fmt, void *data, va_list args); +typedef enum _Eina_Log_State +{ + EINA_LOG_STATE_START, + EINA_LOG_STATE_STOP +} Eina_Log_State; + /* * Customization */ @@ -935,6 +941,26 @@ EAPI void eina_log_print_cb_journald(const Eina_Log_Domain *d, EAPI void eina_log_console_color_set(FILE *fp, const char *color) EINA_ARG_NONNULL(1, 2); +#define EINA_LOG_STATE_INIT "init" +#define EINA_LOG_STATE_SHUTDOWN "shutdown" + +/** + * @brief Start or stop the timing of a phase. + * + * @param d The domain. + * @param state State indicating if we are starting or stopping a phase. + * @param phase The name of the phase to be used in the log. + * + * @note One domain can be in only one phase at a time. + * @note If you change the name of the phase, it is assumed that + * the previous phase has stopped. + * @note The phase name should be available for all the life of the timing. + * @since 1.8 + */ +EAPI void eina_log_timing(int domain, + Eina_Log_State state, + const char *phase) EINA_ARG_NONNULL(1, 3); + #include "eina_inline_log.x" /** diff --git a/src/lib/eina/eina_main.c b/src/lib/eina/eina_main.c index f70a85f3a0..fa6ece893c 100644 --- a/src/lib/eina/eina_main.c +++ b/src/lib/eina/eina_main.c @@ -310,6 +310,8 @@ eina_init(void) eina_cpu_count_internal(); + eina_log_timing(_eina_log_dom, EINA_LOG_STATE_STOP, EINA_LOG_STATE_INIT); + _eina_main_count = 1; return 1; } @@ -325,6 +327,10 @@ eina_shutdown(void) _eina_main_count--; if (EINA_UNLIKELY(_eina_main_count == 0)) { + eina_log_timing(_eina_log_dom, + EINA_LOG_STATE_START, + EINA_LOG_STATE_SHUTDOWN); + _eina_shutdown_from_desc(_eina_desc_setup + _eina_desc_setup_len); #ifdef EINA_HAVE_DEBUG_THREADS diff --git a/src/lib/eina/eina_private.h b/src/lib/eina/eina_private.h index 255959b120..c51d35fae9 100644 --- a/src/lib/eina/eina_private.h +++ b/src/lib/eina/eina_private.h @@ -146,5 +146,7 @@ void eina_cpu_count_internal(void); void eina_file_mmap_faulty(void *addr, long page_size); +#include "eina_inline_private.h" + #endif /* EINA_PRIVATE_H_ */