eina: add eina_log_timing.

This commit is contained in:
Cedric BAIL 2013-03-27 21:39:55 +09:00
parent e12dbaeae6
commit 1d5692baa6
8 changed files with 248 additions and 77 deletions

View File

@ -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().

1
NEWS
View File

@ -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.

View File

@ -24,14 +24,6 @@
#include <stdlib.h>
#include <string.h>
#include <stdarg.h>
#ifndef _WIN32
# include <time.h>
# include <sys/time.h>
#else
# define WIN32_LEAN_AND_MEAN
# include <windows.h>
# undef WIN32_LEAN_AND_MEAN
#endif /* _WIN2 */
#include "eina_config.h"
#include "eina_private.h"
@ -46,6 +38,8 @@
# include <Escape.h>
#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",

View File

@ -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 <http://www.gnu.org/licenses/>.
*/
#ifndef EINA_INLINE_PRIVATE_H_
# define EINA_INLINE_PRIVATE_H_
#ifndef _WIN32
# include <time.h>
# include <sys/time.h>
#else
# define WIN32_LEAN_AND_MEAN
# include <windows.h>
# 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

View File

@ -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;
}
}
}

View File

@ -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"
/**

View File

@ -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

View File

@ -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_ */