From 1df232d9691aef7caac110a7517597e79f082382 Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Tue, 1 Apr 2014 10:09:29 +0800 Subject: [PATCH 1/7] ferite_script.c: Fix off-by-one error in line number counter --- src/ferite_script.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/ferite_script.c b/src/ferite_script.c index 36ed0ab..fa195ff 100644 --- a/src/ferite_script.c +++ b/src/ferite_script.c @@ -61,7 +61,7 @@ FeriteScript *ferite_new_script() ptr->include_list = ferite_create_stack( NULL, FE_COMPILER_INTERNAL_STACK_SIZE ); ptr->current_op_file = NULL; - ptr->current_op_line = 0; + ptr->current_op_line = 1; ptr->error_state = 0; ptr->keep_execution = 0; From b013cb5f3a2daa118b1a2aaef744d115952d7dec Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Mon, 24 Feb 2014 11:33:09 +0800 Subject: [PATCH 2/7] Ferite profiling RUn configure with --enable-profile, then $ ferite --fe-profile=out.json Feed out.json to fprof[1] to produce the html reports. Profile metrics are saved into the given file at atexit(3) [1] https://github.com/cention-nazri/fprof --- configure.ac.stub | 13 + docs/profile.txt | 42 ++ include/ferite.h | 9 + include/ferite/Makefile.am | 1 + include/ferite/fglobals.h | 3 + include/ferite/fprofile.h | 18 + include/ferite/fstructs.h | 48 ++ src/Makefile.am | 3 +- src/ferite.c | 23 + src/ferite_execute.c | 119 +++++ src/ferite_globals.c | 5 + src/ferite_obj.c | 28 +- src/ferite_profile.c | 946 +++++++++++++++++++++++++++++++++++++ src/ferite_script.c | 3 + test/Makefile.am | 2 +- test/main.c | 7 + 16 files changed, 1266 insertions(+), 4 deletions(-) create mode 100644 docs/profile.txt create mode 100644 include/ferite/fprofile.h create mode 100644 src/ferite_profile.c diff --git a/configure.ac.stub b/configure.ac.stub index 40a8c20..2bc8b6b 100644 --- a/configure.ac.stub +++ b/configure.ac.stub @@ -130,6 +130,19 @@ AC_ARG_ENABLE( autoload-core, AC_SUBST(debugdefs) +profile_defs="" +AC_MSG_CHECKING( for profiling support ) +AC_ARG_ENABLE( profile, + [ --enable-profile enable line and function profiling within ferite [default=no]], + echo "yes"; profile_defs="-DFERITE_PROFILE"; + echo "**************************************************"; + echo "* PROFILE SUPPORT ENABLED *"; + echo "**************************************************"; + AC_DEFINE([FERITE_PROFILE], 1, [Whether we are compiling ferite with profiling support mode]) + , + echo "no"; ) +AC_SUBST(profile_defs) + AC_CHECK_LIB(xml2, xmlParseDocument, [gotxml=yes], [gotxml=no; diff --git a/docs/profile.txt b/docs/profile.txt new file mode 100644 index 0000000..dbe26bf --- /dev/null +++ b/docs/profile.txt @@ -0,0 +1,42 @@ +Introduction +------------ + + "Let there be profilers" + - unknown + +Currently ferite support for profiling is enabled/disabled at compile time for +the obvious performance overheads associated with keeping the profiling data +during runtime. The configure switch for this is "--enable-profile" + +Enabling profiling support +-------------------------- + + $ ./configure --enable-profile + +Profiling a ferite script +------------------------- + +A ferite script to be profiled must be free of errors and exceptions otherwise +the profiling data will be unavailable or incorrect. + + $ ferite --fe-profile=foo.json foo.fe + +The above will run and profile the script foo.fe. The profiling data is saved +in foo.json. The fprof[1] tool can be used to generate an html report from the +profiling data and open the result in a browser (see fprof -h): + + $ fprof foo.json + +[1] https://github.com/cention-nazri/fprof + +Caveats +------- + +1. Tested only on linux. +2. Does not support profiling in multithreaded environment. +3. When run under mod_ferite, with FeriteCache on, the ferite script that is + loaded from the cache will have wrong line number information for its + !__start__ function. Reason: !__start__() function is not cached and + ferite_do_function_start() does a ferite_lexer_jump() for cached functions + which voids ferite_scanner_lineno because YY_LESS_LINENO is defined to do + nothing (maybe). diff --git a/include/ferite.h b/include/ferite.h index 6e9c136..f195436 100644 --- a/include/ferite.h +++ b/include/ferite.h @@ -81,6 +81,12 @@ FERITE_API int ferite_get_parameters( FeriteVariable **list, int num_args, ... ) FERITE_API int ferite_get_parameter_count( FeriteVariable **list ); FERITE_API void *ferite_get_parameter( FeriteVariable **list, int num ); FERITE_API int ferite_get_required_parameter_list_size( FeriteScript *script, FeriteFunction *function ); + +#ifdef FERITE_PROFILE +FERITE_API void ferite_profile_toggle( int state ); +FERITE_API void ferite_profile_save(const pid_t pid); +FERITE_API void ferite_profile_set_filename_format(const char *filename); +#endif /* macros to cover internal functions */ #define fe_new_lng( name, val ) ferite_create_number_long_variable( script, name, val, FE_ALLOC ) @@ -197,6 +203,9 @@ FERITE_API int ferite_get_required_parameter_list_size( FeriteScript *script, Fe #include #include #include +#ifdef FERITE_PROFILE +#include +#endif #include /* As this is the native class 'Obj' we need the macros here for compilation!*/ diff --git a/include/ferite/Makefile.am b/include/ferite/Makefile.am index 9277f4b..1989073 100644 --- a/include/ferite/Makefile.am +++ b/include/ferite/Makefile.am @@ -8,6 +8,7 @@ feincludes_DATA = \ fopcode.h \ fops.h \ fparser.h \ + fprofile.h \ freq.h \ fstack.h \ fstructs.h \ diff --git a/include/ferite/fglobals.h b/include/ferite/fglobals.h index 01a53d0..a503cd2 100644 --- a/include/ferite/fglobals.h +++ b/include/ferite/fglobals.h @@ -41,6 +41,9 @@ FERITE_API int ferite_hide_mem_use; FERITE_API int ferite_use_mm_with_pcre; FERITE_API int ferite_is_strict; FERITE_API int ferite_show_partial_implementation; +#ifdef FERITE_PROFILE +FERITE_API int ferite_profile_enabled; +#endif FERITE_API FeriteVariable *ferite_ARGV; FERITE_API void (*ferite_memory_init)(void); diff --git a/include/ferite/fprofile.h b/include/ferite/fprofile.h new file mode 100644 index 0000000..d5ecfc5 --- /dev/null +++ b/include/ferite/fprofile.h @@ -0,0 +1,18 @@ +#ifndef __FERITE_PROFILE_H__ +#define __FERITE_PROFILE_H__ + +#ifdef FERITE_PROFILE +#include + +extern int ferite_profile_enabled; + +struct timespec ferite_profile_function_begin(FeriteScript *script, void *container, FeriteFunction *function, FeriteProfileFunction **fpf); +struct timespec ferite_profile_function_end(FeriteScript *script, FeriteProfileFunction *fpf, int end_line, struct timespec *begin_ts); +struct timespec ferite_profile_line_begin(FeriteScript *script, const char *filename, const size_t line); +void ferite_profile_line_end(FeriteScript *script, const char *filename, const size_t line, struct timespec *begin_ts); +FeriteProfileFunction *ferite_profile_get_function_profile(FeriteScript *script, void *container, FeriteFunction *function); +void ferite_profile_set_caller(FeriteScript *script, void *container, FeriteFunction *function); +void ferite_profile_add_caller(FeriteProfileFunction *callee, FeriteProfileFunction *caller, int caller_line, struct timespec duration); + +#endif /* FERITE_PROFILE */ +#endif /* __FERITE_PROFILE_H__ */ diff --git a/include/ferite/fstructs.h b/include/ferite/fstructs.h index 563ff03..dfbe456 100644 --- a/include/ferite/fstructs.h +++ b/include/ferite/fstructs.h @@ -70,6 +70,12 @@ typedef struct _ferite_compile_record FeriteCompileRecord; typedef struct _ferite_bk_req FeriteBkRequest; typedef struct _ferite_variable_accessors FeriteVariableAccessors; typedef struct _ferite_variable_subtype FeriteVariableSubType; +#ifdef FERITE_PROFILE +typedef struct _ferite_profile_function_caller FeriteProfileFunctionCaller; +typedef struct _ferite_profile_function FeriteProfileFunction; +typedef struct _ferite_profile_line_entry FeriteProfileLineEntry; +typedef struct _ferite_profile_entry FeriteProfileEntry; +#endif typedef void (*FeriteVariableGetAccessor)(FeriteScript*,FeriteVariable*); typedef void (*FeriteVariableSetAccessor)(FeriteScript*,FeriteVariable*,FeriteVariable*); @@ -429,6 +435,9 @@ struct _ferite_script FeriteAMT *globals; FeriteAMT *types; +#ifdef FERITE_PROFILE + FeriteProfileFunction *caller; +#endif }; struct _ferite_script_attached_data @@ -518,4 +527,43 @@ struct _ferite_compile_record /* Used in the compiler */ int want_container_finish; }; +#ifdef FERITE_PROFILE +struct _ferite_profile_function_caller { + FeriteProfileFunction *caller; + int caller_line; + size_t frequency; + struct timespec total_duration; +}; + +struct _ferite_profile_function { + char *filename; + char *container; /* namespace or class fqn */ + char *name; + int is_native; + size_t ncalls; + int start_line; + int end_line; + int calling_line; + struct timespec exclusive_duration; + struct timespec inclusive_duration; + FeriteHash *callers; +}; + +struct _ferite_profile_line_entry { + unsigned int ncalls; + struct timespec total_duration; + FeriteHash *functions; /* not null means this line has one or more function definitions */ +}; + +struct _ferite_profile_entry { + char *filename; + int is_file; + unsigned int filename_len; + size_t line_count; + FeriteProfileLineEntry *lines; /* 1-based indexing */ + + FeriteProfileEntry *next; // next in hash table +}; +#endif /* FERITE_PROFILE */ + #endif /* __FERITE_STRUCTS_H__ */ diff --git a/src/Makefile.am b/src/Makefile.am index 01c8649..1dd3a8c 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -12,7 +12,7 @@ LDFLAGS = -L${prefix}/lib -lm INCLUDES = -I$(top_srcdir) -I$(top_srcdir)/libs/aphex/include -I$(top_srcdir)/libs/triton/include -I${top_srcdir}/include -I${prefix}/include -I$(includedir) -I${top_srcdir}/include/ferite/ @pcre_cflags@ -DEFS = @debugdefs@ @thread_defs@ @gc_defs@ +DEFS = @debugdefs@ @thread_defs@ @gc_defs@ @profile_defs@ lib_LTLIBRARIES = libferite.la @@ -31,6 +31,7 @@ ferite_gc_generation.c \ ferite_execute.c \ ferite_scanner.c \ ferite_globals.c \ + ferite_profile.c \ ferite_script.c \ ferite_parser.c \ ferite_opcode.c \ diff --git a/src/ferite.c b/src/ferite.c index 6df1b89..de0240d 100644 --- a/src/ferite.c +++ b/src/ferite.c @@ -60,6 +60,7 @@ int ferite_pow_lookup[32]; * --fe-use-classic - this will tell ferite to use malloc/free rather than the jedi memory manager * --fe-debug - tell ferite to dump debug out to stdout, warning: this will produce a lot of output, ferite also has to be compiled with debugging support. * --fe-show-mem-use - tell ferite to dump to stdout a set of memory statistics, this is useful for detecting leaks + * --fe-profile=<file.json> - enable and save profiling data to <file.json>. Date and time formatting specifications as understood by strftime(3) is supported for <file.json>. Requires compile time switch -DFERITE_PROFILE * * This function can be called multiple times without fear - it will only set things up * if they are needed. @@ -70,6 +71,9 @@ int ferite_init( int argc, char **argv ) { int i = 0; int wantDebugBanner = FE_TRUE; +#ifdef FERITE_PROFILE + char *profile_filename_pattern = NULL; +#endif FE_ENTER_FUNCTION; @@ -148,6 +152,17 @@ int ferite_init( int argc, char **argv ) wantDebugBanner = FE_FALSE; if( strcmp( argv[i], "--fe-show-partial-implementation") == 0 ) ferite_show_partial_implementation = FE_TRUE; + if( strncmp( argv[i], "--fe-profile", 12) == 0) { +#ifdef FERITE_PROFILE + if (strlen(argv[i]) <= strlen("--fe-profile=")) { + fprintf( stderr, "--fe-profile needs argument: --fe-profile=filename\n"); + exit(1); + } + profile_filename_pattern = argv[i] + 13; +#else + fprintf( stderr, "Warning: profiling was not enabled at compile time.\n" ); +#endif + } } } @@ -194,6 +209,13 @@ int ferite_init( int argc, char **argv ) FE_LEAVE_FUNCTION( ferite_is_initialised ); } +#ifdef FERITE_PROFILE + if (profile_filename_pattern != NULL) { + ferite_profile_set_filename_format(profile_filename_pattern); + ferite_profile_toggle(FE_TRUE); + } +#endif + ferite_init_compiler(); ferite_init_regex(); ferite_set_script_argv( 0, NULL ); @@ -384,6 +406,7 @@ void ferite_show_help() printf( " --fe-use-classic \t Run w/ alternate MM mode. (enables allocation tracking; will cause slow downs)\n" ); printf( " --fe-use-std-gc \t Run w/ simple GC mode. (will cause slow downs)\n" ); printf( " --fe-show-mem-use\t Report memory use at script end.\n" ); + printf( " --fe-profile=\t Enable and save profiling data to (may include strftime(3) formatters).\n" ); printf( " --fe-use-mm-with-pcre\t Use PCRE [Regular Expression Engine] with ferite's MM\n" ); printf( "\n MM = Memory Manager\n" ); FE_LEAVE_FUNCTION( NOWT ); diff --git a/src/ferite_execute.c b/src/ferite_execute.c index 35f7962..cf0925a 100644 --- a/src/ferite_execute.c +++ b/src/ferite_execute.c @@ -84,6 +84,9 @@ int ferite_script_execute( FeriteScript *script ) FeriteNamespaceBucket *nsb = NULL; FeriteFunction *func = NULL; FeriteVariable *err = NULL, *errstr = NULL, *erno = NULL, *rval = NULL; +#ifdef FERITE_PROFILE + FeriteProfileFunction *callee; +#endif FE_ENTER_FUNCTION; @@ -95,8 +98,22 @@ int ferite_script_execute( FeriteScript *script ) if( nsb != NULL ) { +#ifdef FERITE_PROFILE + struct timespec begin_ts = {0, 0}; +#endif func = nsb->data; + +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + begin_ts = ferite_profile_function_begin(script, script->mainns, func, &callee); + } +#endif rval = ferite_script_function_execute( script, script->mainns, NULL, func, NULL ); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + (void) ferite_profile_function_end(script, callee, script->current_op_line, &begin_ts); + } +#endif #ifdef THREAD_SAFE ferite_thread_group_wait( script, script->thread_group ); @@ -175,6 +192,9 @@ FE_NATIVE_FUNCTION( ferite_script_function_execute ) exec.block_depth = 0; exec.parent = script->gc_stack; script->gc_stack = &exec; +#ifdef FERITE_PROFILE + script->caller = NULL; +#endif /*}}}*/ /*{{{ Copy parameter values over to the local variable stack */ @@ -344,6 +364,17 @@ INLINE_OP( ferite_exec_funcall ) int i, j, _arg_count; char *method_name = NULL; void *function_container = NULL; +#ifdef FERITE_PROFILE + struct timespec duration; + struct timespec begin_ts = {0, 0}; + FeriteProfileFunction *caller = NULL; + FeriteProfileFunction *callee = NULL; + int caller_line = -1; + + if (ferite_profile_enabled) { + caller_line = script->current_op_line; + } +#endif /*{{{ Create Parameter List */ FUD(("CREATING PARAMETER LIST.\n")); @@ -366,6 +397,11 @@ INLINE_OP( ferite_exec_funcall ) // FUNCALL FeriteFunction *f = ferite_object_get_function( script, current_recipient, "invoke" ); FUD(( "%s>>> Deliver: Pre: %p\n", ferite_stroflen(' ', (ferite_execute_call_depth*2)), context->new_yield_block )); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + ferite_profile_set_caller(script, container, function); + } +#endif rval = ferite_call_function( script, current_recipient, context->new_yield_block, f, param_list ); FUD(( "%s<<< Deliver: Post: %p\n", ferite_stroflen(' ', (ferite_execute_call_depth*2)),context->new_yield_block )); } @@ -617,6 +653,13 @@ INLINE_OP( ferite_exec_funcall ) if( trgt_function_call != NULL ) { // FUNCALL LOCK_VARIABLE(trgt_function_call); /* lock the method */ + +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + caller = ferite_profile_get_function_profile(script, container, function); + begin_ts = ferite_profile_function_begin(script, function_container, trgt_function_call, &callee); + } +#endif if( trgt_function_call->type == FNC_IS_EXTRL ) { if( trgt_function_call->fncPtr != NULL ) { EXTERNAL_ENTER( trgt_function_call ); @@ -638,6 +681,13 @@ INLINE_OP( ferite_exec_funcall ) { rval = ferite_script_function_execute( script, function_container, context->new_yield_block, trgt_function_call, param_list ); } +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + duration = ferite_profile_function_end(script, callee, script->current_op_line, &begin_ts); + callee = ferite_profile_get_function_profile(script, container, trgt_function_call); + ferite_profile_add_caller(callee, caller, caller_line, duration); + } +#endif UNLOCK_VARIABLE(trgt_function_call); /* unlock the method */ if( script->error_state != FE_ERROR_THROWN ) { script->current_op_file = function->bytecode->filename; /* we do this because the other function might cause it to change */ @@ -658,6 +708,11 @@ INLINE_OP( ferite_exec_funcall ) ferite_error( script, 0, "%s is not a class, bad luck, try again :)\n", ferite_variable_id_to_str(script,vartwo->type) ); break; } +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + ferite_profile_set_caller(script, container, function); + } +#endif rval = (void *)ferite_new_object( script, VAC(vartwo), param_list ); if( script->error_state != FE_ERROR_THROWN ) { script->current_op_file = function->bytecode->filename; /* we do this because the other function might cause it to change */ @@ -738,6 +793,11 @@ INLINE_OP( ferite_exec_pushattr ) FUD(( "%s>>> attribute_missing: Pre: %s: %p\n", ferite_stroflen(' ', (ferite_execute_call_depth*2)), var_name, context->new_yield_block )); str = ferite_str_new( script, var_name, strlen( var_name ), FE_CHARSET_DEFAULT ); pml = ferite_create_parameter_list_from_data( script, "s", str ); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + ferite_profile_set_caller(script, container, function); + } +#endif varone = ferite_call_function( script, VAP(vartwo), context->new_yield_block, trgt_function_call, pml ); ferite_delete_parameter_list( script, pml ); ferite_str_destroy( script, str ); @@ -801,6 +861,11 @@ INLINE_OP( ferite_exec_pushattr ) { str = ferite_str_new( script, var_name, strlen( var_name ), FE_CHARSET_DEFAULT ); pml = ferite_create_parameter_list_from_data( script, "s", str ); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + ferite_profile_set_caller(script, container, function); + } +#endif varone = ferite_call_function( script, VAP(vartwo), context->new_yield_block, trgt_function_call, pml ); ferite_delete_parameter_list( script, pml ); ferite_str_destroy( script, str ); @@ -849,6 +914,11 @@ INLINE_OP( ferite_exec_pushattr ) FUD(( "%s>>> attribute_missing: Pre: %s: %p\n", ferite_stroflen(' ', (ferite_execute_call_depth*2)), var_name, context->new_yield_block )); str = ferite_str_new( script, var_name, strlen( var_name ), FE_CHARSET_DEFAULT ); pml = ferite_create_parameter_list_from_data( script, "s", str ); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + ferite_profile_set_caller(script, container, function); + } +#endif varone = ferite_call_function( script, VAP(vartwo), context->new_yield_block, trgt_function_call, pml ); ferite_delete_parameter_list( script, pml ); ferite_str_destroy( script, str ); @@ -1377,6 +1447,12 @@ FeriteVariable *ferite_script_real_function_execute( FeriteScript *script, void FeriteVariable *return_val = NULL; FeriteOpcodeContext *context, stack_context; int error_op_location = 0, error_array[ERROR_UPPER_BOUND + 1]; +#ifdef FERITE_PROFILE + // NOTE: In this function we profile only line duration + struct timespec begin_ts = {0, 0}; + char profile_filename[PATH_MAX]; + int profile_current_line = -1; +#endif /*}}}*/ FE_ENTER_FUNCTION; @@ -1391,6 +1467,11 @@ FeriteVariable *ferite_script_real_function_execute( FeriteScript *script, void context->current_op_loc++; script->current_op_file = function->bytecode->filename; +#ifdef FERITE_PROFILE + /* Make a copy because by the end of execution script->current_op_file + * might not be pointing to the same file */ + strcpy(profile_filename, script->current_op_file); +#endif FUD(("EXECUTION STARTING\n")); while( context->keep_function_running && script->keep_execution ) @@ -1400,6 +1481,15 @@ FeriteVariable *ferite_script_real_function_execute( FeriteScript *script, void script->current_op_line = current_op->line; exec->block_depth = current_op->block_depth; +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + if (profile_current_line != current_op->line) { + profile_current_line = current_op->line; + begin_ts = ferite_profile_line_begin(script, profile_filename, profile_current_line); + } + } +#endif + if( ferite_opcode_table[current_op->OP_TYPE].op != NULL ) return_val = CALL_INLINE_OP((ferite_opcode_table[current_op->OP_TYPE].op)); else @@ -1471,6 +1561,14 @@ FeriteVariable *ferite_script_real_function_execute( FeriteScript *script, void } } +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + if ((current_op != NULL && profile_current_line != current_op->line) || + !context->keep_function_running || !script->keep_execution) { + ferite_profile_line_end(script, profile_filename, profile_current_line, &begin_ts); + } + } +#endif if( !context->keep_function_running || !script->keep_execution ) break; @@ -1629,6 +1727,12 @@ FeriteVariable *ferite_call_function( FeriteScript *script, void *container, Fer FeriteFunction *function = NULL; FeriteVariable **plist = NULL; int script_exec_state = 0; +#ifdef FERITE_PROFILE + struct timespec begin_ts = {0, 0}; + struct timespec duration; + FeriteProfileFunction *callee = NULL; + FeriteProfileFunction *caller = NULL; +#endif FE_ENTER_FUNCTION; @@ -1649,6 +1753,12 @@ FeriteVariable *ferite_call_function( FeriteScript *script, void *container, Fer if( ferite_check_params( script, plist, function ) == 1 ) { LOCK_VARIABLE( function ); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + caller = script->caller; + begin_ts = ferite_profile_function_begin(script, container, function, &callee); + } +#endif if( function->type == FNC_IS_EXTRL ) { /* This is used to hook up the execute record */ @@ -1665,6 +1775,15 @@ FeriteVariable *ferite_call_function( FeriteScript *script, void *container, Fer if( script->error_state == FE_ERROR_THROWN ) retval = ferite_create_void_variable( script, "error...", FE_STATIC ); } +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + duration = ferite_profile_function_end(script, callee, script->current_op_line, &begin_ts); + if (caller != NULL) { + ferite_profile_add_caller(callee, caller, caller->calling_line, duration); + script->caller = NULL; + } + } +#endif UNLOCK_VARIABLE( function ); break; } diff --git a/src/ferite_globals.c b/src/ferite_globals.c index 4207bf5..9f44536 100644 --- a/src/ferite_globals.c +++ b/src/ferite_globals.c @@ -58,6 +58,11 @@ int ferite_is_strict = 0; int ferite_show_partial_implementation = 0; +#ifdef FERITE_PROFILE +int ferite_enable_profiling = 0; +char *ferite_profile_filename_pattern = NULL; +#endif + /*! Generic function for memory management. Hides the actually memory manager */ void (*ferite_memory_init)(void); /*! Generic function for memory management. Hides the actually memory manager */ diff --git a/src/ferite_obj.c b/src/ferite_obj.c index 8aef4ab..c5dccfa 100644 --- a/src/ferite_obj.c +++ b/src/ferite_obj.c @@ -472,6 +472,12 @@ FeriteVariable *ferite_new_object( FeriteScript *script, FeriteClass *nclass, Fe FeriteVariable *ptr = NULL, *rval = NULL; FeriteFunction *func = NULL; FeriteVariable **params = NULL; +#ifdef FERITE_PROFILE + struct timespec begin_ts = {0, 0}; + struct timespec duration; + FeriteProfileFunction *callee = NULL; + FeriteProfileFunction *caller = NULL; +#endif FE_ENTER_FUNCTION; if(nclass != NULL) @@ -501,7 +507,15 @@ FeriteVariable *ferite_new_object( FeriteScript *script, FeriteClass *nclass, Fe func = ferite_find_constructor( script, VAO(ptr), params ); if( func != NULL ) { FUD(("OPS: Calling constructor in class %s\n", nclass->name )); - + +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + /* Make a copy of the caller because func might reset it */ + caller = script->caller; + begin_ts = ferite_profile_function_begin(script, NULL, func, &callee); + } +#endif + if( func->type == FNC_IS_EXTRL ) { EXTERNAL_ENTER(func); rval = (func->fncPtr)( script, VAO(ptr), NULL, func, params ); @@ -509,6 +523,16 @@ FeriteVariable *ferite_new_object( FeriteScript *script, FeriteClass *nclass, Fe } else rval = ferite_script_function_execute( script, VAO(ptr), NULL, func, params ); + +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + duration = ferite_profile_function_end(script, callee, script->current_op_line, &begin_ts); + if (caller != NULL) { + ferite_profile_add_caller(callee, caller, caller->calling_line, duration); + script->caller = NULL; + } + } +#endif if( rval == NULL || (rval != NULL && F_VAR_TYPE(rval) == F_VAR_OBJ && VAO(rval) == NULL) ) { @@ -539,4 +563,4 @@ FeriteVariable *ferite_new_object( FeriteScript *script, FeriteClass *nclass, Fe FE_LEAVE_FUNCTION( ptr ); } /*}}}*/ -/** @end */ \ No newline at end of file +/** @end */ diff --git a/src/ferite_profile.c b/src/ferite_profile.c new file mode 100644 index 0000000..5f9e8d7 --- /dev/null +++ b/src/ferite_profile.c @@ -0,0 +1,946 @@ +#ifdef FERITE_PROFILE +#ifdef HAVE_CONFIG_HEADER +#include "../config.h" +#endif +#include +#include "ferite.h" +#include "aphex.h" +#include +#include + +AphexMutex *ferite_profile_mutex = NULL; +#define INIT_PROFILE_LOCK() if (ferite_profile_mutex == NULL) \ + ferite_profile_mutex = aphex_mutex_recursive_create() +#define LOCK_PROFILE() aphex_mutex_lock(ferite_profile_mutex) +#define UNLOCK_PROFILE() aphex_mutex_unlock(ferite_profile_mutex) + +#define DIE(reason) do { fprintf(stderr, "%s:%d: %s\n", __FILE__, __LINE__, reason); exit(1); } while(0) +#define ONE_BILLION 1000000000L +#define ONE_MILLION 1000000L +#define TIMESPEC_TO_MILLISECONDS(ts) \ + (((long double)((ts).tv_sec) * ONE_BILLION + (ts).tv_nsec) / ONE_MILLION) +#define calculate_average_in_milliseconds(ts, freq) \ + (((long)((ts).tv_sec) * ONE_BILLION \ + + (ts).tv_nsec) / (long double)(freq) / ONE_MILLION) + +/* We don't expect many functions to be defined on the same line */ +#define FE_FUNCTIONS_HASH_SIZE 3 + +#define FE_CALLER_HASH_SIZE 256 +#define FERITE_PROFILE_NHASH 8192 +#define FERITE_PROFILE_STACK_SIZE 5 +static char *FILENAME_EVAL = "eval()"; +int ferite_profile_enabled = FE_FALSE; +static char profile_output[PATH_MAX] = { 0 }; +static FeriteProfileEntry *profile_entries[FERITE_PROFILE_NHASH] = { NULL }; +static struct timespec profile_start_ts = { 0, 0 }; + +//#define FERITE_FAKE_CLOCK +#ifdef FERITE_FAKE_CLOCK +# define CLOCK_GETTIME(p) fake_clock_gettime(p) +static int fake_clock_gettime(struct timespec *ts) +{ + static int fake_clock_counter = 0; + ts->tv_sec = fake_clock_counter; + ts->tv_nsec = 0; + fake_clock_counter++; + return 0; +} +#else +# define CLOCK_TYPE CLOCK_THREAD_CPUTIME_ID +# define CLOCK_GETTIME(p) clock_gettime(CLOCK_TYPE, p) +#endif + +static size_t hash(const char *key, size_t limit) +{ + unsigned int hash = 0; + while (*key) { + hash = *key + 31 * hash; + key++; + } + return hash % limit; +} + +static int number_width(unsigned int num) +{ + unsigned int width = 0; + + do { + width += 1; + num /= 10; + } while (num > 0); + + return width; +} + +static int get_line_count(const char *filename, size_t *count) +{ + FILE *f = fopen(filename, "r"); + int ch; + int got_ch = 0; + int lines = 0; + + if (f == NULL) { + perror(filename); + return 1; + } + + while (EOF != (ch=fgetc(f))) { + got_ch = 1; + if (ch=='\n') + lines++; + } + if (lines == 0 && got_ch) { + /* File with no line terminators */ + lines = 1; + } + *count = lines; + + if (fclose(f) == EOF) { + perror(filename); + } + return 0; +} + +static int file_exists(const char *filename) +{ + struct stat st; + const int r = stat(filename, &st); + if (r == 0) + return 1; + if (errno == ENOENT) + return 0; + + fprintf(stderr, "Error stat'ing file %s\n", filename); + perror(filename); + return 0; +} + +static int profile_line_entry_init_for_eval(FeriteProfileEntry * const pe) +{ + pe->is_file = 0; + pe->lines = fcalloc_ngc(sizeof(FeriteProfileLineEntry), + 3 /* 1-based indexing + 1 line + 1 EOF line */ + ); + pe->line_count = 2; /* line 1 + EOF line */ + + return 0; +} + +static int profile_line_entry_init_for_file(FeriteProfileEntry * const pe) +{ + size_t line_count; + + if (get_line_count(pe->filename, &line_count) != 0) { + fprintf(stderr, "Error getting line count for %s", pe->filename); + return 1; + } + + pe->is_file = 1; + pe->lines = fcalloc_ngc(sizeof(FeriteProfileLineEntry), + line_count + + 1 /* 1-based indexing, for unused lines[0] */ + + 1 /* Count in EOF too */ + ); + pe->line_count = line_count + 1 /* EOF */; + + return 0; +} + +static int profile_line_entry_init_for_unknown(FeriteProfileEntry * const pe) +{ + size_t line_count = 1; + + pe->is_file = 0; + pe->lines = fcalloc_ngc(sizeof(FeriteProfileLineEntry), + line_count + + 1 /* 1-based indexing, for unused lines[0] */ + + 1 /* Count in EOF too */ + ); + pe->line_count = line_count + 1 /* EOF */; + + return 0; +} + +static int profile_line_entry_init(FeriteProfileEntry *pe) +{ + if (file_exists(pe->filename)) { + return profile_line_entry_init_for_file(pe); + } + + if (pe->filename == FILENAME_EVAL) { + return profile_line_entry_init_for_eval(pe); + } + + return profile_line_entry_init_for_unknown(pe); +} + +static FeriteProfileEntry *profile_init(const char *filename) +{ + FeriteProfileEntry *pe; + + pe = fmalloc_ngc(sizeof(FeriteProfileEntry)); + if (strncmp(filename, "eval()", 6) == 0) { + pe->filename = FILENAME_EVAL; + } else { + pe->filename = ferite_strdup((char *)filename, __FILE__, __LINE__); + } + if (profile_line_entry_init(pe)) { + return NULL; + } + + pe->next = NULL; + + return pe; +} + +static int is_profile_for(const char *filename, const FeriteProfileEntry *pe) +{ + return strcmp(pe->filename, filename) == 0; +} + +static FeriteProfileEntry *find_in_linked_list(const char *filename, FeriteProfileEntry *pe) +{ + while (pe) { + if (is_profile_for(filename, pe)) + return pe; + pe = pe->next; + } + return NULL; +} + +static FeriteProfileEntry *get_profile_entry_in_hash(const char *filename) +{ + unsigned int idx = hash(basename((char *)filename), FERITE_PROFILE_NHASH); + + return find_in_linked_list(filename, profile_entries[idx]); +} + +static FeriteProfileEntry *get_or_create_profile_entry_in_hash(const char *filename) +{ + FeriteProfileEntry *p = NULL; + unsigned int idx = hash(basename((char *)filename), FERITE_PROFILE_NHASH); + FeriteProfileEntry *pe = profile_entries[idx]; + + if (pe) { + p = find_in_linked_list(filename, pe); + if (p) + return p; + } + + p = profile_init(filename); + p->next = profile_entries[idx]; + profile_entries[idx] = p; + + return p; +} + +void save_profile(void) { + ferite_profile_save(0); +} + +void ferite_profile_toggle(const int state) +{ + static int atexit_registered = 0; + INIT_PROFILE_LOCK(); + +#ifdef FERITE_FAKE_CLOCK + fprintf(stderr, "Note: ferite profiling is using fake clock\n"); +#endif + + LOCK_PROFILE(); + + ferite_profile_enabled = state; + if (ferite_profile_enabled) { + if (profile_start_ts.tv_sec == 0 && profile_start_ts.tv_sec == 0) { +#ifdef FERITE_FAKE_CLOCK + CLOCK_GETTIME(&profile_start_ts); +#else + clock_gettime(CLOCK_REALTIME, &profile_start_ts); +#endif + } + if (! atexit_registered) { + atexit_registered = 1; + atexit(save_profile); + } + } else { + profile_start_ts.tv_sec = 0; + profile_start_ts.tv_nsec = 0; + } + + UNLOCK_PROFILE(); +} + +static struct timespec timespec_diff(const struct timespec *old, struct timespec *new) +{ + struct timespec d; + if (new->tv_nsec < old->tv_nsec) { + new->tv_sec -= 1; + new->tv_nsec += ONE_BILLION; + } + d.tv_nsec = new->tv_nsec - old->tv_nsec; + d.tv_sec = new->tv_sec - old->tv_sec; + return d; +} + +static void timespec_add(struct timespec *t, const struct timespec delta) +{ + t->tv_nsec += delta.tv_nsec; + if (t->tv_nsec >= ONE_BILLION) { + t->tv_nsec %= ONE_BILLION; + t->tv_sec += 1; + } + t->tv_sec += delta.tv_sec; +} + +static void grow_pe_line_count(FeriteProfileEntry *pe, int line) +{ + size_t add = line - pe->line_count; + + pe->lines = frealloc_ngc(pe->lines, sizeof(FeriteProfileLineEntry) * (pe->line_count + add + 1)); + if (pe->lines == NULL) { + fprintf(stderr, "OOM reallocating profile lines record\n"); + UNLOCK_PROFILE(); + exit(1); + } + memset(pe->lines + pe->line_count + 1, 0, sizeof(FeriteProfileLineEntry) * add); + pe->line_count += add; +} + +static FeriteProfileLineEntry *get_line_entry(FeriteProfileEntry *pe, const size_t line) +{ + FeriteProfileLineEntry *le; + + if (!pe->is_file && line > pe->line_count ) + grow_pe_line_count(pe, line); + + + FE_ASSERT(line <= pe->line_count); + + le = &pe->lines[line]; + return le; +} + +static char *get_container_fqn(void *container, FeriteFunction *function) +{ + if (strncmp(function->name, "!__start__", 10) == 0) { + return "[main]"; + } + + if (strncmp(function->name, "!closure:", 9) == 0) { + fprintf(stderr, "FIXME: we shouldn't reach here"); + exit(1); + } + + if (function->klass != NULL) { + if (strncmp(function->klass->name, "!closure:", 9) == 0) { + return fstrdup(function->klass->name); + } + return ferite_generate_class_fqn(NULL, function->klass); + } + + if (container != NULL) { + FeriteNamespace *ns = (FeriteNamespace*) container; + if (ns->name != NULL && strncmp(ns->name, "!closure:", 9) == 0) { + fprintf(stderr, "FIXME: we shouldn't reach here"); + exit(1); + } + return ferite_generate_namespace_fqn(NULL, (FeriteNamespace*)container); + } + + return "[container unknown]"; +} + +static void get_filename_and_start_line(FeriteScript *script, FeriteFunction *f, char **filename, int *start_line) +{ + if (f->native_information != NULL) { + *filename = ferite_strdup(f->native_information->file, __FILE__, __LINE__); + *start_line = f->native_information->line; + } else if (f->bytecode != NULL) { + *filename = ferite_strdup(f->bytecode->filename, __FILE__, __LINE__); + *start_line = f->bytecode->list[0]->line; + /* Assume that the function definition is just before its first instruction. + * TODO: teach the parser to include the function location + * (line number where it is defined) */ + *start_line -= 1; + } else { + // Both filename and bytecode are null - assume builtin obj methods + if (f->klass != NULL) { + int len = strlen(f->name); + *filename = ferite_generate_class_fqn(NULL, f->klass); + *filename = frealloc_ngc(*filename, len + 2 ); + strcat(*filename, "."); + strcat(*filename, f->name); + } else { + FE_ASSERT(0 /* We shouldn't reach here */); + } + *start_line = 1; + } + + if (strncmp(*filename, "eval()", 6) == 0 || strncmp(*filename, "entry:eval()", 12) == 0) { + ffree_ngc(*filename) + *filename = FILENAME_EVAL; + *start_line = f->bytecode->list[0]->line; + } +} + +FeriteProfileFunction *ferite_profile_get_function_profile(FeriteScript *script, void *container, FeriteFunction *function) +{ + FeriteProfileEntry *pe; + FeriteProfileLineEntry *le; + FeriteProfileFunction *fpf = NULL; + char *filename = NULL; + int start_line = -1; + + LOCK_PROFILE(); + + get_filename_and_start_line(script, function, &filename, &start_line); + + pe = get_or_create_profile_entry_in_hash(filename); + FE_ASSERT(pe != NULL); + + le = get_line_entry(pe, start_line); + + if (le->functions == NULL) { + le->functions = ferite_create_hash(NULL, FE_FUNCTIONS_HASH_SIZE); + } else { + fpf = ferite_hash_get(NULL, le->functions, function->name); + } + + if (fpf == NULL) { + fpf = fcalloc_ngc(sizeof(FeriteProfileFunction), 1); + fpf->filename = (char *)filename; + fpf->start_line = start_line; + fpf->is_native = function->native_information != NULL; + fpf->container = get_container_fqn(container, function); + fpf->name = fstrdup(function->name); + ferite_hash_add(NULL, le->functions, fpf->name, fpf); + } + + UNLOCK_PROFILE(); + + return fpf; +} + +void ferite_profile_set_caller(FeriteScript *script, void *container, FeriteFunction *function) +{ + FE_ASSERT(script->caller == NULL); + script->caller = ferite_profile_get_function_profile(script, container, function); + script->caller->calling_line = script->current_op_line; +} + +struct timespec ferite_profile_function_begin(FeriteScript *script, void *container, FeriteFunction *function, FeriteProfileFunction **fpf) +{ + struct timespec begin_ts; + + CLOCK_GETTIME(&begin_ts); + + LOCK_PROFILE(); + + *fpf = ferite_profile_get_function_profile(script, container, function); + (*fpf)->ncalls++; + + UNLOCK_PROFILE(); + + return begin_ts; +} + +struct timespec ferite_profile_function_end(FeriteScript *script, FeriteProfileFunction *fpf, int end_line, struct timespec *begin_ts) +{ + struct timespec end_ts, duration; + + CLOCK_GETTIME(&end_ts); + + LOCK_PROFILE(); + + // TODO handle two functions defined on the same line + if (fpf->end_line < end_line) { + fpf->end_line = end_line; + } + + duration = timespec_diff(begin_ts, &end_ts); + timespec_add(&fpf->inclusive_duration, duration); + + UNLOCK_PROFILE(); + + return duration; +} + +struct timespec ferite_profile_line_begin(FeriteScript *script, const char *filename, const size_t line) +{ + FeriteProfileEntry *pe; + FeriteProfileLineEntry *le; + struct timespec begin_ts = {0,0}; + + CLOCK_GETTIME(&begin_ts); + + LOCK_PROFILE(); + + pe = get_or_create_profile_entry_in_hash(filename); + if (pe == NULL) { + fprintf(stderr, + "Error creating profile entry for file %s\n", filename); + UNLOCK_PROFILE(); + return begin_ts; + } + + le = get_line_entry(pe, line); + if (le == NULL) { + UNLOCK_PROFILE(); + return begin_ts; + } + + le->ncalls++; + + UNLOCK_PROFILE(); + + return begin_ts; +} + +void ferite_profile_line_end(FeriteScript *script, const char *filename, const size_t line, struct timespec *begin_ts) +{ + FeriteProfileEntry *pe; + FeriteProfileLineEntry *le; + struct timespec end_ts, duration; + + // TODO either get rid of these getpid()s or use them at least once + // to verify locking works as intended + static pid_t pid = 0; + if (pid == 0) { + pid = getpid(); + } + pid_t other_pid = getpid(); + if (pid != other_pid) { + fprintf(stderr, "pid %d, other pid = %d\n", pid, other_pid); + } + + CLOCK_GETTIME(&end_ts); + + LOCK_PROFILE(); + + pe = get_profile_entry_in_hash(filename); + if (pe == NULL) { + fprintf(stderr, "FIXME No hash for file %s ???\n", filename); + UNLOCK_PROFILE(); + return; + } + if (pe->line_count < line) { + if (pe->is_file) { + fprintf(stderr, + "Error: Line number %lu exceeds the one we " + "counted initially (%lu) for file %s", + line, pe->line_count, filename); + UNLOCK_PROFILE(); + exit(1); + } else { + grow_pe_line_count(pe, line); + } + } + + le = &pe->lines[line]; + + duration = timespec_diff(begin_ts, &end_ts); + timespec_add(&le->total_duration, duration); + + UNLOCK_PROFILE(); +} + +static void get_caller_key(FeriteProfileFunction *caller, int caller_line, FeriteProfileFunction *callee, char *buf, size_t size) +{ + int nprinted; + + nprinted = snprintf(buf, size, "%s:%d:%s:%d,%s:%d:%s", + caller->filename, caller->start_line, caller->name, + caller_line, + callee->filename, callee->start_line, callee->name); + if (nprinted >= size) { + fprintf(stderr, "FIXME: ferite profile: get_caller_key(): failed " + "assumption: bufsize %lu is to small\n", size); + exit(1); + } +} + +void ferite_profile_add_caller(FeriteProfileFunction *callee, FeriteProfileFunction *caller, int caller_line, struct timespec duration_ts) +{ + FeriteProfileFunctionCaller *fpfc; + char caller_key[PATH_MAX*3]; + + LOCK_PROFILE(); + + if (callee->callers == NULL) { + callee->callers = ferite_create_hash(NULL, FE_CALLER_HASH_SIZE); + } + + get_caller_key(caller, caller_line, callee, caller_key, PATH_MAX*2); + fpfc = ferite_hash_get(NULL, callee->callers, caller_key); + if (fpfc == NULL) { + fpfc = fcalloc_ngc(sizeof(FeriteProfileFunctionCaller), 1); + fpfc->caller = caller; + fpfc->caller_line = caller_line; + ferite_hash_add(NULL, callee->callers, caller_key, fpfc); + } + + fpfc->frequency += 1; + timespec_add(&fpfc->total_duration, duration_ts); + timespec_add(&caller->exclusive_duration, duration_ts); + + UNLOCK_PROFILE(); +} + +static int append_pid(char *buf, pid_t pid) +{ + unsigned int len; + unsigned int pid_width; + char pid_str[10]; + + pid_width = number_width(pid); + if (pid_width > 8) { + fprintf(stderr, "FIXME: pid too large? %d (%s:%d)\n", + pid, __FILE__, __LINE__); + return 0; + } + snprintf(pid_str, 10, ".%d", pid); + + len = strlen(buf) + pid_width + 1; + if (len > PATH_MAX - 1) { + fprintf(stderr, + "Error: profile output '%s.{pid} exceeds PATH_MAX\n", + profile_output); + return 0; + } + strncat(buf, pid_str, 10); + return 1; +} + +static int format_profile_filename(char *format, char *buf, pid_t pid) +{ + struct tm now; + time_t t; + + (void)time(&t); + (void)localtime_r(&t, &now); + + if (strftime(buf, PATH_MAX, format, &now) == 0) { + fprintf(stderr, "Error: profile output pattern '%s' results in " + "empty filename\n", profile_output); + return 0; + } + + if (pid != 0 && append_pid(buf, pid) == 0) + return 0; + + return 1; +} + +static void json_comma(FILE *f) +{ + fprintf(f, ","); +} + +static void json_key(FILE *f, char *key) +{ + fprintf(f, "\"%s\":", key); +} + +static void json_array_open(FILE *f, char *key) +{ + if (key != NULL) + json_key(f, key); + fprintf(f, "["); +} + +static void json_array_close(FILE *f) +{ + fprintf(f, "]"); +} + +static void json_dict_open(FILE *f, char *key) +{ + if (key != NULL) + json_key(f, key); + fprintf(f, "{"); +} + +static void json_dict_close(FILE *f) +{ + fprintf(f, "}"); +} + +static void json_string(FILE *f, char *key, char *value) +{ + fprintf(f, "\"%s\":\"%s\"", key, value); +} + +static void json_positive_number(FILE *f, char *key, size_t value) +{ + fprintf(f, "\"%s\":%lu", key, value); +} + +static void json_bool(FILE *f, char *key, int value) +{ + fprintf(f, "\"%s\":%s", key, value ? "true":"false"); +} + +static void json_null(FILE *f, char *key) +{ + if (key) { + fprintf(f, "\"%s\":", key); + } + fprintf(f, "null"); +} + +static void json_timespec(FILE *f, char *key, struct timespec value) +{ + json_dict_open(f, key); + json_positive_number(f, "sec", value.tv_sec); + json_comma(f); + json_positive_number(f, "nsec", value.tv_nsec); + json_dict_close(f); +} + +static void write_json_name_and_namespace(FILE *f, FeriteProfileFunction *function) +{ + json_string(f, "name", function->name); + json_comma(f); + if (function->container != NULL) { + json_string(f, "namespace", function->container); + } else { + json_null(f, "namespace"); + } +} + +static void write_json_one_function_caller(FILE *f, FeriteProfileFunctionCaller *fpfc) +{ + char *realname; + FeriteProfileFunction *caller = fpfc->caller; + + json_dict_open(f, NULL); + write_json_name_and_namespace(f, caller); + json_comma(f); + if (file_exists(caller->filename)) { + realname = realpath(caller->filename, NULL); + json_string(f, "file", realname); + free(realname); + } else { + json_string(f, "file", caller->filename); + } + json_comma(f); json_positive_number(f, "at", fpfc->caller_line); + json_comma(f); json_positive_number(f, "frequency", fpfc->frequency); + json_comma(f); json_timespec(f, "total_duration", fpfc->total_duration); + json_dict_close(f); +} + +static void write_json_callers(FILE *f, FeriteHash *callersHash) +{ + FeriteHashBucket *fhb; + FeriteIterator iter; + iter.curbucket = NULL; + iter.curindex = 0; + int has_previous_entry = 0; + + if (callersHash == NULL) { + json_null(f, "callers"); + return; + } + + json_array_open(f, "callers"); + while ((fhb = ferite_hash_walk(NULL, callersHash, &iter)) != NULL) { + FeriteProfileFunctionCaller *fpfc = fhb->data; + if (has_previous_entry) { + json_comma(f); + } + write_json_one_function_caller(f, fpfc); + has_previous_entry = 1; + } + json_array_close(f); +} + +#define ZERO_TIME(ts) ((ts)->tv_sec == 0 && (ts)->tv_nsec == 0) +static void write_json_one_function_callee(FILE *f, FeriteProfileFunction *callee) { + struct timespec *inclusive; + + json_dict_open(f, NULL); + json_string(f, "name", callee->name); + json_comma(f); json_positive_number(f, "start_line", callee->start_line); + json_comma(f); + if (callee->container != NULL) { + json_string(f, "namespace", callee->container); + } else { + json_null(f, "namespace"); + } + json_comma(f); json_positive_number(f, "hits", callee->ncalls); + json_comma(f); json_bool(f, "is_native", callee->is_native); + + inclusive = &callee->inclusive_duration; + if (ZERO_TIME(inclusive) && !ZERO_TIME(&callee->exclusive_duration)) { + /* We have eclusive duration but zero inclusive duration. This + * may happen if this function is called from a native function + * so we have no record of the total time it spent doing its + * stuff (inclusive time). We know that it calls some other + * function because its exclusive_duration is not zero. So set + * its inclusive_duration to be equal to its exclusive_duration + */ + inclusive = &callee->exclusive_duration; + } + + json_comma(f); json_timespec(f, "inclusive_duration", *inclusive); + json_comma(f); json_timespec(f, "exclusive_duration", callee->exclusive_duration); + json_comma(f); + + write_json_callers(f, callee->callers); + + json_dict_close(f); +} + +static void write_json_functions(FILE *f, FeriteHash *hash) +{ + FeriteHashBucket *fhb; + int has_previous_entry = 0; + FeriteIterator iter; + iter.curbucket = NULL; + iter.curindex = 0; + + if (hash == NULL) { + json_null(f, "functions"); + return; + } + + json_array_open(f, "functions"); + while ((fhb = ferite_hash_walk(NULL, hash, &iter)) != NULL) { + FeriteProfileFunction *callee = fhb->data; + if (has_previous_entry) { + json_comma(f); + } + write_json_one_function_callee(f, callee); + has_previous_entry = 1; + } + + json_array_close(f); +} + +static void write_line_profile(FILE *f, FeriteProfileLineEntry *le) +{ + if (le->ncalls == 0 && le->functions == NULL) { + json_null(f, NULL); + return; + + } + + json_dict_open(f, NULL); + json_positive_number(f, "hits", le->ncalls); + json_comma(f); json_timespec(f, "total_duration", le->total_duration); + json_comma(f); + + write_json_functions(f, le->functions); + json_dict_close(f); +} + +static void write_json_profile_line_entries_for_one_file(FILE *f, FeriteProfileEntry *pe) +{ + FeriteProfileLineEntry *le; + char path[PATH_MAX]; + size_t line_no; + char *filename = pe->filename; + #define LINE_METRIC_SZ 128 + int has_previous_entry = 0; + + if (realpath(pe->filename, path) != NULL) + filename = path; + else { + if (ENOENT != errno) { + perror(pe->filename); + + } + } + + json_array_open(f, filename); + + for (line_no = 1; line_no <= pe->line_count; line_no++) { + le = &pe->lines[line_no]; + if (has_previous_entry) { + json_comma(f); + } + write_line_profile(f, le); + has_previous_entry = 1; + } + + json_array_close(f); +} + +static void save_json_profile(const pid_t pid) +{ + int i; + FILE *f; + char filename[PATH_MAX]; + int has_previous_entry = 0; + struct timespec total_duration; + struct timespec profile_end_ts; + + LOCK_PROFILE(); + +#ifdef FERITE_FAKE_CLOCK + CLOCK_GETTIME(&profile_end_ts); +#else + clock_gettime(CLOCK_REALTIME, &profile_end_ts); +#endif + total_duration = timespec_diff(&profile_start_ts, &profile_end_ts); + + if (format_profile_filename(profile_output, filename, pid) == 0) { + UNLOCK_PROFILE(); + return; + } + + f = fopen(filename, "w"); + if (f == NULL) { + perror(filename); + UNLOCK_PROFILE(); + return; + } + + json_dict_open(f, NULL); + json_timespec(f, "start", profile_start_ts); + json_comma(f); json_timespec(f, "stop", profile_end_ts); + json_comma(f); json_timespec(f, "duration", total_duration); + json_comma(f); json_dict_open(f, "files"); + + for (i = 0; i < FERITE_PROFILE_NHASH; i++) { + FeriteProfileEntry *pe = profile_entries[i]; + while (pe) { + if (has_previous_entry) { + json_comma(f); + } + write_json_profile_line_entries_for_one_file(f, pe); + has_previous_entry = 1; + pe = pe->next; + } + } + + json_dict_close(f); + json_dict_close(f); + + UNLOCK_PROFILE(); + + if (fclose(f) == EOF) + perror(filename); + +} + +void ferite_profile_save(const pid_t pid) +{ + save_json_profile(pid); +} + +void ferite_profile_set_filename_format(const char *filename) +{ + LOCK_PROFILE(); + + if (strncmp(profile_output, filename, PATH_MAX) == 0) { + UNLOCK_PROFILE(); + return; + } + strncpy(profile_output, filename, PATH_MAX); + profile_output[PATH_MAX-1] = '\0'; + + UNLOCK_PROFILE(); +} +#endif diff --git a/src/ferite_script.c b/src/ferite_script.c index fa195ff..67b3c70 100644 --- a/src/ferite_script.c +++ b/src/ferite_script.c @@ -53,6 +53,9 @@ FeriteScript *ferite_new_script() FE_ENTER_FUNCTION; ptr = fmalloc_ngc( sizeof( FeriteScript ) ); +#ifdef FERITE_PROFILE + ptr->caller = NULL; +#endif ptr->filename = NULL; ptr->scripttext = NULL; diff --git a/test/Makefile.am b/test/Makefile.am index cfa0c35..9980683 100644 --- a/test/Makefile.am +++ b/test/Makefile.am @@ -16,6 +16,6 @@ INCLUDES = -I. -I$(top_srcdir) -I$(top_srcdir)/src -I.. \ -I$(top_srcdir)/libs/aphex/include -I$(top_srcdir)/include \ -I$(includedir) -I$(prefix)/include -DEFS=@thread_defs@ @gc_defs@ +DEFS=@thread_defs@ @gc_defs@ @profile_defs@ LDADD = $(top_builddir)/src/libferite.la -L$(libdir) -L$(prefix)/lib @gc_libs@ diff --git a/test/main.c b/test/main.c index 3f397a9..6e93350 100644 --- a/test/main.c +++ b/test/main.c @@ -118,6 +118,13 @@ void print_version() printf( "%s %s [built: %s %s] [%s]\n", PACKAGE, VERSION, __DATE__, __TIME__, PLATFORM ); printf( " Base Cross Platform Library Path: %s\n", XPLAT_LIBRARY_DIR ); printf( " Base Native Library Path: %s\n", NATIVE_LIBRARY_DIR ); + printf( " Profiling: %s\n", +#ifdef FERITE_PROFILE + "enabled" +#else + "disabled" +#endif + ); } void print_copyright() From 628daae3d7e66c6a131beb81efe19a3744049998 Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Mon, 7 Apr 2014 10:52:21 +0800 Subject: [PATCH 3/7] Add line field in FeriteFunction native_information->line holds the same information, there were no equivalent information for non-native functions. Eventually these two locations should be consolidated as one - the next commit after this one will do it. --- include/ferite/fstructs.h | 1 + src/ferite_compile.c | 1 + src/ferite_profile.c | 6 +----- 3 files changed, 3 insertions(+), 5 deletions(-) diff --git a/include/ferite/fstructs.h b/include/ferite/fstructs.h index dfbe456..4cdc069 100644 --- a/include/ferite/fstructs.h +++ b/include/ferite/fstructs.h @@ -274,6 +274,7 @@ struct _ferite_function /* Encapsulate a native and script function */ FeriteVariable *(*fncPtr)( FeriteScript*,void*,FeriteObject*,FeriteFunction*,FeriteVariable**); /* If it is native, it's function pointer */ FeriteFunctionNative *native_information; /* The native infomation about the function */ + int line; /* For non-native function, the line it was declared on */ void *odata; /* If we happen to have any native data */ int arg_count; /* The number of arguments in the signature */ char is_static; /* If the function is a static class method */ diff --git a/src/ferite_compile.c b/src/ferite_compile.c index e053130..1654ae3 100644 --- a/src/ferite_compile.c +++ b/src/ferite_compile.c @@ -937,6 +937,7 @@ void ferite_do_function_header( char *name, int is_static, int is_native, int is } new_function = ferite_create_internal_function( CURRENT_SCRIPT, real_function_name ); + new_function->line = ferite_scanner_lineno; new_function->bytecode->filename = fstrdup( (ferite_scanner_file == NULL ? "" : ferite_scanner_file) ); new_function->is_static = is_static; new_function->state = FE_ITEM_IS_PUBLIC; diff --git a/src/ferite_profile.c b/src/ferite_profile.c index 5f9e8d7..74af50b 100644 --- a/src/ferite_profile.c +++ b/src/ferite_profile.c @@ -358,11 +358,7 @@ static void get_filename_and_start_line(FeriteScript *script, FeriteFunction *f, *start_line = f->native_information->line; } else if (f->bytecode != NULL) { *filename = ferite_strdup(f->bytecode->filename, __FILE__, __LINE__); - *start_line = f->bytecode->list[0]->line; - /* Assume that the function definition is just before its first instruction. - * TODO: teach the parser to include the function location - * (line number where it is defined) */ - *start_line -= 1; + *start_line = f->line; } else { // Both filename and bytecode are null - assume builtin obj methods if (f->klass != NULL) { From efaa9df665098e7ea65482839989367b389e75d3 Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Mon, 7 Apr 2014 11:41:00 +0800 Subject: [PATCH 4/7] Consolidate line field information for native and non-native functions --- builder/builder_main.c | 4 ++-- include/ferite/fcompile.h | 2 +- include/ferite/fstructs.h | 3 +-- src/ferite_compile.c | 2 +- src/ferite_execute.c | 2 +- src/ferite_function.c | 2 +- src/ferite_profile.c | 2 +- 7 files changed, 8 insertions(+), 9 deletions(-) diff --git a/builder/builder_main.c b/builder/builder_main.c index 003d62f..3767439 100644 --- a/builder/builder_main.c +++ b/builder/builder_main.c @@ -528,7 +528,7 @@ void builder_process_closed_function( FeriteScript *script, FeriteFunction *fnc, if( (buf = strrchr( native_info->file, '/' )) != NULL ) buf++; - fprintf( target, "#line %d \"%s\"\n", native_info->line, + fprintf( target, "#line %d \"%s\"\n", fnc->line, ferite_replace_string( (buf != NULL ? buf : native_info->file), "\\", "\\\\" ) ); fprintf( target, "%s\n }\n FE_RETURN_VOID;\n self = NULL;\n}\n\n", native_info->code ); ferite_stack_pop( FE_NoScript, current_module->name_stack ); @@ -649,7 +649,7 @@ void builder_process_open_function( FeriteScript *script, FeriteFunction *fnc, c if( (buf = strrchr( native_info->file, '/' )) != NULL ) buf++; - fprintf( target, "#line %d \"%s\"\n", native_info->line, + fprintf( target, "#line %d \"%s\"\n", fnc->line, ferite_replace_string( (buf != NULL ? buf : native_info->file), "\\", "\\\\" ) ); fprintf( target, "%s\n }\n FE_RETURN_VOID;\n self = NULL;\n", native_info->code ); if( fnc->klass != NULL && !fnc->is_static ) diff --git a/include/ferite/fcompile.h b/include/ferite/fcompile.h index 3765b3f..1730a4b 100644 --- a/include/ferite/fcompile.h +++ b/include/ferite/fcompile.h @@ -195,7 +195,7 @@ FeriteOp *ferite_do_get_current_op(); exec.variable_list = NULL; \ exec.stack = NULL; \ exec.parent = script->gc_stack; \ - exec.line = (FUNCTION->native_information ? FUNCTION->native_information->line : 0); \ + exec.line = FUNCTION->line; \ script->gc_stack = &exec #define EXTERNAL_EXIT() \ diff --git a/include/ferite/fstructs.h b/include/ferite/fstructs.h index 4cdc069..e08dc62 100644 --- a/include/ferite/fstructs.h +++ b/include/ferite/fstructs.h @@ -264,7 +264,6 @@ struct _ferite_function_native_information /* Stores the native code info for bu { char *code; /* The code in the block */ char *file; /* The file it was declared in */ - int line; /* The line it was declared on */ }; struct _ferite_function /* Encapsulate a native and script function */ @@ -274,7 +273,7 @@ struct _ferite_function /* Encapsulate a native and script function */ FeriteVariable *(*fncPtr)( FeriteScript*,void*,FeriteObject*,FeriteFunction*,FeriteVariable**); /* If it is native, it's function pointer */ FeriteFunctionNative *native_information; /* The native infomation about the function */ - int line; /* For non-native function, the line it was declared on */ + int line; /* The line it was declared on */ void *odata; /* If we happen to have any native data */ int arg_count; /* The number of arguments in the signature */ char is_static; /* If the function is a static class method */ diff --git a/src/ferite_compile.c b/src/ferite_compile.c index 1654ae3..b7a3179 100644 --- a/src/ferite_compile.c +++ b/src/ferite_compile.c @@ -1104,7 +1104,7 @@ void ferite_do_function_native_block( char *code, char *file, int line ) ptr = fmalloc_ngc( sizeof(FeriteFunctionNative) ); ptr->code = NULL; ptr->file = fstrdup( file ); - ptr->line = line; + CURRENT_FUNCTION->line = line; CURRENT_FUNCTION->native_information = ptr; if( ferite_keep_native_function_data == 1 ) diff --git a/src/ferite_execute.c b/src/ferite_execute.c index cf0925a..c9fde7c 100644 --- a/src/ferite_execute.c +++ b/src/ferite_execute.c @@ -667,7 +667,7 @@ INLINE_OP( ferite_exec_funcall ) FE_ENTER_NAMED_FUNCTION( trgt_function_call->name ); if( trgt_function_call->native_information != NULL ) { script->current_op_file = trgt_function_call->native_information->file; - script->current_op_line = trgt_function_call->native_information->line; + script->current_op_line = trgt_function_call->line; } rval = (trgt_function_call->fncPtr)( script, function_container, context->new_yield_block, trgt_function_call, param_list ); FE_LEAVE_NAMED_FUNCTION( trgt_function_call->name ); diff --git a/src/ferite_function.c b/src/ferite_function.c index 958bd67..bceb208 100644 --- a/src/ferite_function.c +++ b/src/ferite_function.c @@ -536,6 +536,7 @@ FeriteFunction *ferite_function_dup( FeriteScript *script, FeriteFunction *funct else ptr->name = NULL; + ptr->line = function->line; ptr->type = function->type; ptr->is_static = function->is_static; ptr->arg_count = function->arg_count; @@ -567,7 +568,6 @@ FeriteFunction *ferite_function_dup( FeriteScript *script, FeriteFunction *funct ptr->native_information = fmalloc(sizeof(FeriteFunctionNative)); ptr->native_information->code = fstrdup(function->native_information->code); ptr->native_information->file = fstrdup(function->native_information->file); - ptr->native_information->line = function->native_information->line; } else ptr->native_information = NULL; diff --git a/src/ferite_profile.c b/src/ferite_profile.c index 74af50b..c2053f3 100644 --- a/src/ferite_profile.c +++ b/src/ferite_profile.c @@ -355,7 +355,7 @@ static void get_filename_and_start_line(FeriteScript *script, FeriteFunction *f, { if (f->native_information != NULL) { *filename = ferite_strdup(f->native_information->file, __FILE__, __LINE__); - *start_line = f->native_information->line; + *start_line = f->line; } else if (f->bytecode != NULL) { *filename = ferite_strdup(f->bytecode->filename, __FILE__, __LINE__); *start_line = f->line; From 4db0c44a548102d1f53ec59aefb44ded129c3697 Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Wed, 23 Apr 2014 15:51:38 +0800 Subject: [PATCH 5/7] Expand "%i" in profile filename pattern to process id --- include/ferite.h | 2 +- src/ferite.c | 2 +- src/ferite_profile.c | 92 +++++++++++++++++++++++++++++--------------- 3 files changed, 62 insertions(+), 34 deletions(-) diff --git a/include/ferite.h b/include/ferite.h index f195436..95f3e9f 100644 --- a/include/ferite.h +++ b/include/ferite.h @@ -84,7 +84,7 @@ FERITE_API int ferite_get_required_parameter_list_size( FeriteScript *script, Fe #ifdef FERITE_PROFILE FERITE_API void ferite_profile_toggle( int state ); -FERITE_API void ferite_profile_save(const pid_t pid); +FERITE_API void ferite_profile_save(); FERITE_API void ferite_profile_set_filename_format(const char *filename); #endif diff --git a/src/ferite.c b/src/ferite.c index de0240d..b06999b 100644 --- a/src/ferite.c +++ b/src/ferite.c @@ -406,7 +406,7 @@ void ferite_show_help() printf( " --fe-use-classic \t Run w/ alternate MM mode. (enables allocation tracking; will cause slow downs)\n" ); printf( " --fe-use-std-gc \t Run w/ simple GC mode. (will cause slow downs)\n" ); printf( " --fe-show-mem-use\t Report memory use at script end.\n" ); - printf( " --fe-profile=\t Enable and save profiling data to (may include strftime(3) formatters).\n" ); + printf( " --fe-profile=\t Enable and save profiling data to (may include strftime(3) formatters, and additionally %%i for the process id).\n" ); printf( " --fe-use-mm-with-pcre\t Use PCRE [Regular Expression Engine] with ferite's MM\n" ); printf( "\n MM = Memory Manager\n" ); FE_LEAVE_FUNCTION( NOWT ); diff --git a/src/ferite_profile.c b/src/ferite_profile.c index c2053f3..336fba2 100644 --- a/src/ferite_profile.c +++ b/src/ferite_profile.c @@ -236,7 +236,7 @@ static FeriteProfileEntry *get_or_create_profile_entry_in_hash(const char *filen } void save_profile(void) { - ferite_profile_save(0); + ferite_profile_save(); } void ferite_profile_toggle(const int state) @@ -583,48 +583,76 @@ void ferite_profile_add_caller(FeriteProfileFunction *callee, FeriteProfileFunct UNLOCK_PROFILE(); } -static int append_pid(char *buf, pid_t pid) -{ - unsigned int len; - unsigned int pid_width; - char pid_str[10]; - - pid_width = number_width(pid); - if (pid_width > 8) { - fprintf(stderr, "FIXME: pid too large? %d (%s:%d)\n", - pid, __FILE__, __LINE__); - return 0; - } - snprintf(pid_str, 10, ".%d", pid); - - len = strlen(buf) + pid_width + 1; - if (len > PATH_MAX - 1) { - fprintf(stderr, - "Error: profile output '%s.{pid} exceeds PATH_MAX\n", - profile_output); - return 0; +static int maybe_expand_pid(char *buf, size_t size) +{ + char *p = buf; + char len = strlen(buf); + pid_t pid = getpid(); + + while (*p && p-buf < size) { + if (*p == '%' && *(p+1) == '%') { + p++; + } else if (*p == '%' && *(p+1) == 'i') { + size_t w = number_width(pid); + + if (w > 2) { + int add = w - 2; /*%p*/ + if (len + add < PATH_MAX) { + char *j; + char save = *(p+2); + /* Shift chars to the right to make + * space for the pid */ + for (j = buf+len; j > p+1; j--) { + *(j+add) = *j; + *j = 'x'; + } + snprintf(p, (buf+len+w)-p, "%d", pid); + *(p+w) = save; + len += add; + } else { + printf("Not enough buffer space to include process id\n"); + return 0; + } + } else if (w < 2) { + char *j; + /* It must be 1 */ + FE_ASSERT(w == 1); + *p = pid + '0'; + /* Shift chars left by 1 */ + for (j = p + 1; j <= buf + len; j++) { + *j = *(j+1); + } + len--; + } else { /* w == 2 */ + char save = *(p+2); + snprintf(p, (buf+len+1)-p, "%d", pid); + *(p+2) = save; + } + } + p++; } - strncat(buf, pid_str, 10); - return 1; + return len; } -static int format_profile_filename(char *format, char *buf, pid_t pid) + +static int format_profile_filename(char *format, char *buf) { struct tm now; time_t t; + char fmt[PATH_MAX]; + + strncpy(fmt, format, PATH_MAX); + (void)maybe_expand_pid(fmt, PATH_MAX); (void)time(&t); (void)localtime_r(&t, &now); - if (strftime(buf, PATH_MAX, format, &now) == 0) { + if (strftime(buf, PATH_MAX, fmt, &now) == 0) { fprintf(stderr, "Error: profile output pattern '%s' results in " "empty filename\n", profile_output); return 0; } - if (pid != 0 && append_pid(buf, pid) == 0) - return 0; - return 1; } @@ -863,7 +891,7 @@ static void write_json_profile_line_entries_for_one_file(FILE *f, FeriteProfileE json_array_close(f); } -static void save_json_profile(const pid_t pid) +static void save_json_profile() { int i; FILE *f; @@ -881,7 +909,7 @@ static void save_json_profile(const pid_t pid) #endif total_duration = timespec_diff(&profile_start_ts, &profile_end_ts); - if (format_profile_filename(profile_output, filename, pid) == 0) { + if (format_profile_filename(profile_output, filename) == 0) { UNLOCK_PROFILE(); return; } @@ -921,9 +949,9 @@ static void save_json_profile(const pid_t pid) } -void ferite_profile_save(const pid_t pid) +void ferite_profile_save() { - save_json_profile(pid); + save_json_profile(); } void ferite_profile_set_filename_format(const char *filename) From 6d1e850ab7342d37fc91790dee6afe4d39800a37 Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Fri, 25 Apr 2014 11:54:55 +0800 Subject: [PATCH 6/7] Avoid possible segfault when saving profiling data Saving profiling data atexit(3) may cause a segfault due to ferite_deinit() being called before ferite_profile_save() - the memory allocated for the profiling metrics may have been freed by the garbage collector. Provide an api for saving the profiling data at exit for use by clients such as mod_ferite. --- include/ferite.h | 1 + src/ferite_profile.c | 27 +++++++++++++++++---------- test/main.c | 6 ++++++ 3 files changed, 24 insertions(+), 10 deletions(-) diff --git a/include/ferite.h b/include/ferite.h index 95f3e9f..c4624a6 100644 --- a/include/ferite.h +++ b/include/ferite.h @@ -84,6 +84,7 @@ FERITE_API int ferite_get_required_parameter_list_size( FeriteScript *script, Fe #ifdef FERITE_PROFILE FERITE_API void ferite_profile_toggle( int state ); +FERITE_API void ferite_profile_set_save_at_exit(); FERITE_API void ferite_profile_save(); FERITE_API void ferite_profile_set_filename_format(const char *filename); #endif diff --git a/src/ferite_profile.c b/src/ferite_profile.c index 336fba2..6f0e4c6 100644 --- a/src/ferite_profile.c +++ b/src/ferite_profile.c @@ -34,6 +34,7 @@ int ferite_profile_enabled = FE_FALSE; static char profile_output[PATH_MAX] = { 0 }; static FeriteProfileEntry *profile_entries[FERITE_PROFILE_NHASH] = { NULL }; static struct timespec profile_start_ts = { 0, 0 }; +static int atexit_registered = 0; //#define FERITE_FAKE_CLOCK #ifdef FERITE_FAKE_CLOCK @@ -235,13 +236,8 @@ static FeriteProfileEntry *get_or_create_profile_entry_in_hash(const char *filen return p; } -void save_profile(void) { - ferite_profile_save(); -} - void ferite_profile_toggle(const int state) { - static int atexit_registered = 0; INIT_PROFILE_LOCK(); #ifdef FERITE_FAKE_CLOCK @@ -259,10 +255,6 @@ void ferite_profile_toggle(const int state) clock_gettime(CLOCK_REALTIME, &profile_start_ts); #endif } - if (! atexit_registered) { - atexit_registered = 1; - atexit(save_profile); - } } else { profile_start_ts.tv_sec = 0; profile_start_ts.tv_nsec = 0; @@ -949,9 +941,24 @@ static void save_json_profile() } +void save_profile(void) { + save_json_profile(); +} + +void ferite_profile_set_save_at_exit() +{ + if (! atexit_registered) { + atexit_registered = 1; + atexit(save_profile); + } +} + void ferite_profile_save() { - save_json_profile(); + if (atexit_registered) { + fprintf(stderr, "Warning: save atexit was set but ferite_profile_save() is called.\n"); + } + save_json_profile(); } void ferite_profile_set_filename_format(const char *filename) diff --git a/test/main.c b/test/main.c index 6e93350..6f1ec20 100644 --- a/test/main.c +++ b/test/main.c @@ -522,6 +522,12 @@ int main( int argc, char **argv ) /* delete the script */ ferite_script_delete( script ); +#ifdef FERITE_PROFILE + if (ferite_profile_enabled) { + ferite_profile_save(); + } +#endif + /* deinitialise the engien */ ferite_deinit(); aphex_free( opt.scriptname ); From 76265c827f4399aeefed25297cbf9aa42572b7d4 Mon Sep 17 00:00:00 2001 From: Nazri Ramliy Date: Thu, 24 Jul 2014 15:11:19 +0800 Subject: [PATCH 7/7] Add -DFERITE_PROFILE into ferite-config's --cflags --- ferite-config.in | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ferite-config.in b/ferite-config.in index 422c412..0e76ddd 100644 --- a/ferite-config.in +++ b/ferite-config.in @@ -42,7 +42,7 @@ while test $# -gt 0; do if test @includedir@ != /usr/include ; then includes=-I@includedir@ fi - echo $includes @debugdefs@ @thread_defs@ @gc_defs@ + echo $includes @debugdefs@ @thread_defs@ @gc_defs@ @profile_defs@ ;; --libs) libdirs=-L@libdir@