Print some timing statistics when the sim exits

Saved the timestamps on the default gettimeofday clock as close to
the beginning of the simulation, after initialization is finished and
at the end of shutdown.  Printed out the elapsed time as well as
the number of overruns counted by RealtimeSync.

refs #183

Conflicts:
	trick_source/sim_services/RealtimeSync/src/RealtimeSync.cpp
This commit is contained in:
Alex Lin 2016-02-17 16:27:37 -06:00
parent e714aecdb8
commit 347e102f40
3 changed files with 60 additions and 18 deletions

View File

@ -555,11 +555,13 @@ class RTSyncSimObject : public Trick::SimObject {
Trick::RealtimeSync rt_sync ;
RTSyncSimObject() : rt_sync(&gtod_clock, &itimer) {
{TRK} P0 ("default_data") rt_sync.get_sim_start_time() ;
{TRK} P65535 ("initialization") rt_sync.rt_clock->calc_sim_time_ratio(exec_get_time_tic_value()) ;
{TRK} P65535 ("initialization") trick_ret = rt_sync.initialize() ;
{TRK} P65535 ("initialization") rt_sync.start_realtime(exec_get_software_frame() , exec_get_time_tics()) ;
{TRK} P65535 ("initialization") rt_sync.get_sim_end_init_time() ;
{TRK} P65535 ("restart") rt_sync.restart(exec_get_time_tics()) ;
#ifndef TRICK_NO_DMTCP
@ -573,6 +575,7 @@ class RTSyncSimObject : public Trick::SimObject {
// rt_monitor should be last end_of_frame jobs in sim
{TRK} P65535 ("end_of_frame") rt_sync.rt_monitor(exec_get_time_tics()) ;
{TRK} P65535 ("shutdown") rt_sync.get_sim_end_time() ;
// the rt_sync shutdown jobs should be last in sim
{TRK} P65535 ("shutdown") rt_sync.shutdown() ;
}

View File

@ -95,6 +95,15 @@ namespace Trick {
/** Maximum overrun condition exceeded. Shutdown after leaving freeze.\n */
bool freeze_shutdown; /**< trick_units(--) */
/** The clock time when the sim started. Used for total actual time calculation.\n */
long long sim_start_time ; /**< trick_units(--) */
/** The clock time when initialization ended. Used for total actual time calculation.\n */
long long sim_end_init_time ; /**< trick_units(--) */
/** The clock time when the sim ended. Used for total actual time calculation.\n */
long long sim_end_time ; /**< trick_units(--) */
/**
@brief This is the constructor of the RealtimeSync class. It starts the RealtimeSync as
disabled and sets the maximum overrun parameters to basically infinity.
@ -156,6 +165,24 @@ namespace Trick {
*/
int set_rt_clock_ratio(double in_clock_ratio) ;
/**
@brief Starts the actual elapsed timer used on the default clock
@return always 0
*/
virtual void get_sim_start_time() ;
/**
@brief Ends the actual elapsed timer for initalization
@return always 0
*/
virtual void get_sim_end_init_time() ;
/**
@brief Ends the actual elapsed timer at shutdown.
@return always 0
*/
virtual void get_sim_end_time() ;
/**
@brief Initializes the clock and sleep timer hardware.
Called as an initialization job in the S_define file.

View File

@ -42,6 +42,10 @@ Trick::RealtimeSync::RealtimeSync( Trick::Clock * in_clock , Trick::Timer * in_t
align_sim_to_wall_clock = false ;
align_tic_mult = 1.0 ;
sim_start_time = 0 ;
sim_end_init_time = 0 ;
sim_end_time = 0 ;
the_rts = this ;
}
@ -105,6 +109,18 @@ int Trick::RealtimeSync::set_rt_clock_ratio(double in_clock_ratio) {
return 0 ;
}
void Trick::RealtimeSync::get_sim_start_time() {
sim_start_time = default_clock->wall_clock_time() ;
}
void Trick::RealtimeSync::get_sim_end_init_time() {
sim_end_init_time = default_clock->wall_clock_time() ;
}
void Trick::RealtimeSync::get_sim_end_time() {
sim_end_time = default_clock->wall_clock_time() ;
}
/**
@details
-# If real-time synchronization has been enabled:
@ -452,6 +468,7 @@ int Trick::RealtimeSync::unfreeze(long long sim_time_tics, double software_frame
-# If real-time is active:
-# Stop the real-time clock hardware
-# Stop the sleep timer hardware
-# Print the overrun count
*/
int Trick::RealtimeSync::shutdown() {
@ -461,28 +478,23 @@ int Trick::RealtimeSync::shutdown() {
/* If a sleep timer has been defined, stop the timer */
sleep_timer->shutdown() ;
#if 0
if (clock_time == 0.0) {
sim_to_actual = 0.0;
} else {
sim_to_actual = (sim_elapsed_time / clock_time);
}
//TODO: move to Clock class shutdown job
if (software_frame < 1.0e36) {
/* There were any overruns during the sim & in rt mode. Calculate and print out overrun percentage */
if (time_tics != 0) {
overrun_percentage = total_overrun / (get_sim_time() / software_frame);
} else {
overrun_percentage = 0.0;
std::stringstream os ;
double actual_time = (sim_end_time - sim_start_time) / (double)default_clock->clock_tics_per_sec ;
os << "\n" <<
" REALTIME SHUTDOWN STATS:\n" ;
if ( active ) {
os << " REALTIME TOTAL OVERRUNS: " << std::setw(12) << frame_overrun_cnt << "\n" ;
}
*message_publisher() << " TOTAL OVERRUNS: " << setw(12) << total_overrun << "\n" <<
"PERCENTAGE REALTIME OVERRUNS: " << setw(12) << (overrun_percentage * 100.0) << "%\n" ;
}
#endif
if ( sim_end_init_time != 0 ) {
double init_time = (sim_end_init_time - sim_start_time) / (double)default_clock->clock_tics_per_sec ;
os << " ACTUAL INIT TIME: " ;
os << std::fixed << std::setw(12) << std::setprecision(3) << init_time << "\n" ;
}
os << " ACTUAL ELAPSED TIME: " ;
os << std::fixed << std::setw(12) << std::setprecision(3) << actual_time << "\n" ;
message_publish(MSG_NORMAL,os.str().c_str()) ;
return(0) ;
}