1 /******************************************************************************
2 * Copyright (c) 2000-2016 Ericsson Telecom AB
3 * All rights reserved. This program and the accompanying materials
4 * are made available under the terms of the Eclipse Public License v1.0
5 * which accompanies this distribution, and is available at
6 * http://www.eclipse.org/legal/epl-v10.html
12 ******************************************************************************/
14 #include "Profiler.hh"
25 ////////////////////////////////////
26 ////////// TTCN3_Profiler //////////
27 ////////////////////////////////////
29 TTCN3_Profiler ttcn3_prof
;
31 TTCN3_Profiler::TTCN3_Profiler()
32 : stopped(FALSE
), disable_profiler(FALSE
), disable_coverage(FALSE
)
33 , aggregate_data(FALSE
), disable_stats(FALSE
), stats_flags(Profiler_Tools::STATS_ALL
)
35 database_filename
= mcopystr("profiler.db");
36 stats_filename
= mcopystr("profiler.stats");
40 TTCN3_Profiler::~TTCN3_Profiler()
42 if (!profiler_db
.empty() && !TTCN_Runtime::is_undefined() &&
43 (!disable_profiler
|| !disable_coverage
)) {
44 if (aggregate_data
&& (TTCN_Runtime::is_single() || TTCN_Runtime::is_hc())) {
45 // import the data from the previous run
48 if (TTCN_Runtime::is_hc()) {
49 // import the data gathered by the other processes (the import function
50 // waits for them to finish exporting)
51 for (size_t i
= 0; i
< pid_list
.size(); ++i
) {
52 import_data(pid_list
[i
]);
56 if (!disable_stats
&& (TTCN_Runtime::is_single() || TTCN_Runtime::is_hc())) {
60 for (size_t i
= 0; i
< profiler_db
.size(); ++i
) {
61 Free(profiler_db
[i
].filename
);
62 for (size_t j
= 0; j
< profiler_db
[i
].functions
.size(); ++j
) {
63 Free(profiler_db
[i
].functions
[j
].name
);
66 Free(database_filename
);
70 void TTCN3_Profiler::start()
73 set_prev(disable_profiler
? -1 : TTCN3_Stack_Depth::depth(), NULL
, -1);
78 void TTCN3_Profiler::stop()
81 if (NULL
!= prev_file
) {
82 // update the previous line's time
83 timeval elapsed
= Profiler_Tools::subtract_timeval(get_time(), prev_time
);
84 add_line_time(elapsed
, get_element(prev_file
), prev_line
);
85 TTCN3_Stack_Depth::update_stack_elapsed(elapsed
);
91 void TTCN3_Profiler::set_disable_profiler(boolean p_disable_profiler
)
93 disable_profiler
= p_disable_profiler
;
96 void TTCN3_Profiler::set_disable_coverage(boolean p_disable_coverage
)
98 disable_coverage
= p_disable_coverage
;
101 // handles metacharacters in the database or statistics file name
102 static char* finalize_filename(const char* p_filename_skeleton
)
104 size_t len
= strlen(p_filename_skeleton
);
106 char* ret_val
= NULL
;
107 for (size_t i
= 0; i
< len
- 1; ++i
) {
108 if ('%' == p_filename_skeleton
[i
]) {
109 ret_val
= mputstrn(ret_val
, p_filename_skeleton
+ next_idx
, i
- next_idx
);
110 switch (p_filename_skeleton
[i
+ 1]) {
111 case 'e': // %e -> executable name
112 ret_val
= mputstr(ret_val
, TTCN_Logger::get_executable_name());
114 case 'h': // %h -> host name
115 ret_val
= mputstr(ret_val
, TTCN_Runtime::get_host_name());
117 case 'p': // %p -> process ID
118 ret_val
= mputprintf(ret_val
, "%ld", (long)getpid());
120 case 'l': { // %l -> login name
122 struct passwd
*p
= getpwuid(getuid());
124 ret_val
= mputstr(ret_val
, p
->pw_name
);
128 case '%': // %% -> single %
129 ret_val
= mputc(ret_val
, '%');
131 default: // unknown sequence -> leave it as it is
132 ret_val
= mputstrn(ret_val
, p_filename_skeleton
+ i
, 2);
139 if (next_idx
< len
) {
140 ret_val
= mputstr(ret_val
, p_filename_skeleton
+ next_idx
);
145 void TTCN3_Profiler::set_database_filename(const char* p_database_filename
)
147 Free(database_filename
);
148 database_filename
= finalize_filename(p_database_filename
);
151 void TTCN3_Profiler::set_aggregate_data(boolean p_aggregate_data
)
153 aggregate_data
= p_aggregate_data
;
156 void TTCN3_Profiler::set_stats_filename(const char* p_stats_filename
)
158 Free(stats_filename
);
159 stats_filename
= finalize_filename(p_stats_filename
);
162 void TTCN3_Profiler::set_disable_stats(boolean p_disable_stats
)
164 disable_stats
= p_disable_stats
;
167 void TTCN3_Profiler::reset_stats_flags()
172 void TTCN3_Profiler::add_stats_flags(unsigned int p_flags
)
174 stats_flags
|= p_flags
;
177 boolean
TTCN3_Profiler::is_profiler_disabled() const
179 return disable_profiler
;
182 boolean
TTCN3_Profiler::is_running() const
187 void TTCN3_Profiler::add_child_process(pid_t p_pid
)
189 pid_list
.push_back(p_pid
);
192 void TTCN3_Profiler::import_data(pid_t p_pid
/* = 0 */)
194 char* file_name
= NULL
;
196 // this is the main database file (from the previous run), no suffix needed
197 file_name
= database_filename
;
200 // this is the database for one of the PTCs or the MTC,
201 // suffix the file name with the component's PID
202 file_name
= mprintf("%s.%d", database_filename
, p_pid
);
204 // wait for the process to finish
206 waitpid(p_pid
, &status
, 0);
209 Profiler_Tools::import_data(profiler_db
, file_name
, TTCN_warning
);
212 // the process-specific database file is no longer needed
218 void TTCN3_Profiler::export_data()
220 char* file_name
= NULL
;
221 if (TTCN_Runtime::is_single() || TTCN_Runtime::is_hc()) {
222 // this is the main database file, no suffix needed
223 file_name
= database_filename
;
226 // this is the database for one of the PTCs or the MTC,
227 // suffix the file name with the component's PID
228 file_name
= mprintf("%s.%d", database_filename
, (int)getpid());
231 Profiler_Tools::export_data(profiler_db
, file_name
, disable_profiler
,
232 disable_coverage
, TTCN_warning
);
234 if (file_name
!= database_filename
) {
239 void TTCN3_Profiler::print_stats()
241 if (profiler_db
.empty()) {
245 Profiler_Tools::print_stats(profiler_db
, stats_filename
, disable_profiler
,
246 disable_coverage
, stats_flags
, TTCN_warning
);
249 void TTCN3_Profiler::reset()
251 prev_time
.tv_sec
= 0;
252 prev_time
.tv_usec
= 0;
258 timeval
TTCN3_Profiler::get_time()
261 gettimeofday(&tv
, NULL
);
265 void TTCN3_Profiler::enter_function(const char* filename
, int lineno
)
267 if (disable_profiler
&& disable_coverage
) {
271 // Note that the execution time of the last line in a function
272 // is measured by using the stack depth.
273 execute_line(filename
, lineno
);
276 int element
= get_element(filename
);
278 // store function data
279 if (!disable_coverage
) {
280 ++profiler_db
[element
].functions
[get_function(element
, lineno
)].exec_count
;
285 void TTCN3_Profiler::execute_line(const char* filename
, int lineno
)
287 if (disable_profiler
&& disable_coverage
) {
291 if (!disable_profiler
&& TTCN3_Stack_Depth::depth() > prev_stack_len
) {
292 // this line is in a different function than the last one, don't measure anything
293 TTCN3_Stack_Depth::add_stack(prev_stack_len
, prev_file
, filename
, prev_line
, lineno
);
297 if (!disable_profiler
&& NULL
!= prev_file
) {
298 // this line is in the same function as the previous one, measure the time difference
299 timeval elapsed
= Profiler_Tools::subtract_timeval(get_time(), prev_time
);
301 // add the elapsed time to the total time of the previous line
302 add_line_time(elapsed
, get_element(prev_file
), prev_line
);
304 TTCN3_Stack_Depth::update_stack_elapsed(elapsed
);
307 // functions starting at line 0 are: pre_init_module and post_init_module,
308 // don't include them in the database (as they don't appear in the TTCN-3 code),
309 // but include any actual code lines they may contain
310 // also, several instructions could be in the same line, only count the line once
311 if (0 != lineno
&& !disable_coverage
&& (lineno
!= prev_line
|| NULL
== prev_file
||
312 0 != strcmp(prev_file
, filename
))) {
313 int element
= get_element(filename
);
315 // increase line execution count
316 ++profiler_db
[element
].lines
[get_line(element
, lineno
)].exec_count
;
320 // store the current location as previous for the next call
321 set_prev(disable_profiler
? -1 : TTCN3_Stack_Depth::depth(), filename
, lineno
);
324 int TTCN3_Profiler::get_element(const char* filename
)
326 for (size_t i
= 0; i
< profiler_db
.size(); ++i
) {
327 if (0 == strcmp(profiler_db
[i
].filename
, filename
)) {
332 Profiler_Tools::profiler_db_item_t item
;
333 item
.filename
= mcopystr(filename
);
334 profiler_db
.push_back(item
);
335 return profiler_db
.size() - 1;
338 int TTCN3_Profiler::get_function(int element
, int lineno
)
340 return Profiler_Tools::get_function(profiler_db
, element
, lineno
);
343 void TTCN3_Profiler::create_function(int element
, int lineno
, const char* function_name
)
345 Profiler_Tools::create_function(profiler_db
, element
, lineno
, function_name
);
348 int TTCN3_Profiler::get_line(int element
, int lineno
)
350 return Profiler_Tools::get_line(profiler_db
, element
, lineno
);
353 void TTCN3_Profiler::create_line(int element
, int lineno
)
355 Profiler_Tools::create_line(profiler_db
, element
, lineno
);
358 void TTCN3_Profiler::add_line_time(timeval elapsed
, int element
, int lineno
)
363 profiler_db
[element
].lines
[get_line(element
, lineno
)].total_time
= Profiler_Tools::add_timeval(
364 profiler_db
[element
].lines
[get_line(element
, lineno
)].total_time
, elapsed
);
367 void TTCN3_Profiler::add_function_time(timeval elapsed
, int element
, int lineno
)
369 int func
= get_function(element
, lineno
);
373 profiler_db
[element
].functions
[func
].total_time
= Profiler_Tools::add_timeval(
374 profiler_db
[element
].functions
[func
].total_time
, elapsed
);
377 void TTCN3_Profiler::update_last()
379 if (stopped
|| (0 == prev_time
.tv_sec
&& 0 == prev_time
.tv_usec
) || NULL
== prev_file
) {
383 timeval elapsed
= Profiler_Tools::subtract_timeval(get_time(), prev_time
);
385 int element
= get_element(prev_file
);
387 // add the elapsed time to the total time of the previous line
388 add_line_time(elapsed
, element
, prev_line
);
389 TTCN3_Stack_Depth::update_stack_elapsed(elapsed
);
392 prev_time
.tv_sec
= 0;
393 prev_time
.tv_usec
= 0;
396 void TTCN3_Profiler::set_prev(int stack_len
, const char* filename
, int lineno
)
398 prev_file
= filename
;
400 if (!disable_profiler
) {
401 prev_time
= get_time();
402 prev_stack_len
= stack_len
;
406 /////////////////////////////////////
407 ///////// TTCN3_Stack_Depth /////////
408 /////////////////////////////////////
410 int TTCN3_Stack_Depth::current_depth
= -1;
411 Vector
<TTCN3_Stack_Depth::call_stack_timer_item_t
> TTCN3_Stack_Depth::call_stack_timer_db
;
412 boolean
TTCN3_Stack_Depth::net_line_times
= FALSE
;
413 boolean
TTCN3_Stack_Depth::net_func_times
= FALSE
;
415 TTCN3_Stack_Depth::TTCN3_Stack_Depth()
417 if (ttcn3_prof
.is_profiler_disabled()) {
423 TTCN3_Stack_Depth::~TTCN3_Stack_Depth()
425 if (ttcn3_prof
.is_profiler_disabled()) {
428 ttcn3_prof
.update_last();
430 if (0 == current_depth
) {
436 void TTCN3_Stack_Depth::set_net_line_times(boolean p_net_line_times
)
438 net_line_times
= p_net_line_times
;
441 void TTCN3_Stack_Depth::set_net_func_times(boolean p_net_func_times
)
443 net_func_times
= p_net_func_times
;
446 void TTCN3_Stack_Depth::add_stack(int stack_len
, const char* caller_file
, const char* func_file
,
447 int caller_line
, int start_line
)
449 call_stack_timer_item_t item
;
450 item
.stack_len
= stack_len
;
451 item
.caller_file
= caller_file
;
452 item
.func_file
= func_file
;
453 item
.caller_line
= caller_line
;
454 item
.start_line
= start_line
;
455 item
.elapsed
.tv_sec
= 0;
456 item
.elapsed
.tv_usec
= 0;
457 item
.first_call
= true;
458 item
.recursive_call
= false;
460 if (!net_line_times
|| !net_func_times
) {
461 // check if it's a recursive function
462 for (int i
= current_depth
- 1; i
>= 0 ; --i
) {
463 if (call_stack_timer_db
[i
].start_line
== start_line
&&
464 0 == strcmp(call_stack_timer_db
[i
].func_file
, func_file
)) {
465 item
.recursive_call
= true;
467 // check if the caller is new
468 if (call_stack_timer_db
[i
].caller_line
== caller_line
&&
469 ((NULL
== call_stack_timer_db
[i
].caller_file
&& NULL
== caller_file
) ||
470 (NULL
!= call_stack_timer_db
[i
].caller_file
&& NULL
!= caller_file
&&
471 0 == strcmp(call_stack_timer_db
[i
].caller_file
, caller_file
)))) {
472 item
.first_call
= false;
479 call_stack_timer_db
.push_back(item
);
482 void TTCN3_Stack_Depth::remove_stack()
484 // add the time gathered for this stack level to the appropriate line and function
485 // except for functions starting at line 0 (pre_init_module and post_init_module)
486 if (0 != call_stack_timer_db
[current_depth
].start_line
) {
487 timeval elapsed
= call_stack_timer_db
[current_depth
].elapsed
;
488 if (!net_line_times
&& NULL
!= call_stack_timer_db
[current_depth
].caller_file
&&
489 call_stack_timer_db
[current_depth
].first_call
) {
490 // add the elapsed time to the caller line, if it exists
491 // (only add it once for recursive functions, at the first call)
492 ttcn3_prof
.add_line_time(elapsed
,
493 ttcn3_prof
.get_element(call_stack_timer_db
[current_depth
].caller_file
),
494 call_stack_timer_db
[current_depth
].caller_line
);
496 if (!net_func_times
&& !call_stack_timer_db
[current_depth
].recursive_call
) {
497 // add the elapsed time to the called function, if it's not recursive
498 // (in case of net function times this has already been done in update_stack_elapsed)
499 ttcn3_prof
.add_function_time(elapsed
,
500 ttcn3_prof
.get_element(call_stack_timer_db
[current_depth
].func_file
),
501 call_stack_timer_db
[current_depth
].start_line
);
505 ttcn3_prof
.set_prev(call_stack_timer_db
[current_depth
].stack_len
,
506 call_stack_timer_db
[current_depth
].caller_file
,
507 call_stack_timer_db
[current_depth
].caller_line
);
509 call_stack_timer_db
.erase_at(current_depth
);
512 void TTCN3_Stack_Depth::update_stack_elapsed(timeval elapsed
)
514 // if function times are net times, only add the elapsed time to the current function
515 if (net_func_times
) {
516 ttcn3_prof
.add_function_time(elapsed
,
517 ttcn3_prof
.get_element(call_stack_timer_db
[current_depth
].func_file
),
518 call_stack_timer_db
[current_depth
].start_line
);
520 if (!net_line_times
|| !net_func_times
) {
521 // cycle through the stack and add the elapsed time to the entries where
522 // the function/caller pair appears for the first time (marked by 'first_call')
523 for(int i
= 0; i
<= current_depth
; ++i
) {
524 if (call_stack_timer_db
[i
].first_call
) {
525 call_stack_timer_db
[i
].elapsed
= Profiler_Tools::add_timeval(
526 call_stack_timer_db
[i
].elapsed
, elapsed
);