diff --git a/include/trick/FrameDataRecordGroup.hh b/include/trick/FrameDataRecordGroup.hh index 0bfb6763..45505336 100644 --- a/include/trick/FrameDataRecordGroup.hh +++ b/include/trick/FrameDataRecordGroup.hh @@ -65,9 +65,12 @@ namespace Trick { /** Thread start time */ long long start_time ; - /** Thread total frame scheduled time */ + /** Thread total frame scheduled time in tics*/ long long frame_sched_time ; + /** Thread total frame scheduled time in seconds*/ + double frame_time ; + } ; } ; diff --git a/include/trick/JobData.hh b/include/trick/JobData.hh index 3e6c4e74..c92d1756 100644 --- a/include/trick/JobData.hh +++ b/include/trick/JobData.hh @@ -88,9 +88,12 @@ namespace Trick { /** Clock time when job stopped in frame */ long long rt_stop_time ; /**< trick_io(**) */ - /** Cumulative time used for job in frame (stop - start) */ + /** Cumulative time in tics used for job in frame (stop - start) */ long long frame_time ; /**< trick_io(**) */ + /** Cumulative time in seconds used for job in frame (rt_stop_time - rt_start_time) / time_tic_value */ + double frame_time_seconds; /**< trick_io(s) */ + /** Sim_object_id.id (for job identification in timeline logging) */ double frame_id; /**< trick_io(**) */ diff --git a/include/trick/RealtimeSync.hh b/include/trick/RealtimeSync.hh index de0b2826..c2140b40 100644 --- a/include/trick/RealtimeSync.hh +++ b/include/trick/RealtimeSync.hh @@ -67,9 +67,15 @@ namespace Trick { /** How much time did the current frame take in tics.\n */ long long frame_sched_time ; /**< trick_units(--) */ + /** How much time did the current frame take in seconds for frame logging.\n */ + double frame_time ; /**< trick_units(s) */ + /** The magnitude of the current overrun in tics.\n */ long long frame_overrun_time ; /**< trick_units(--) */ + /** The magnitude of the current overrun in seconds for frame logging.\n */ + double frame_overrun ; /**< trick_units(s) */ + /** This is the start of the frame in wall clock time.\n */ long long last_clock_time ; /**< trick_units(--) */ diff --git a/trick_source/sim_services/FrameLog/FrameDataRecordGroup.cpp b/trick_source/sim_services/FrameLog/FrameDataRecordGroup.cpp index ebcde4e1..af11b6a6 100644 --- a/trick_source/sim_services/FrameLog/FrameDataRecordGroup.cpp +++ b/trick_source/sim_services/FrameLog/FrameDataRecordGroup.cpp @@ -35,6 +35,7 @@ int Trick::FrameDataRecordGroup::frame_log_clear() { std::vector< Trick::JobData *>::iterator it ; for ( it = rec_jobs.begin() ; it != rec_jobs.end() ; it++ ) { (*it)->frame_time = 0 ; + (*it)->frame_time_seconds = 0.0; } return 0 ; @@ -93,6 +94,7 @@ void Trick::FrameDataRecordGroup::start_timer() { */ void Trick::FrameDataRecordGroup::stop_timer() { frame_sched_time = clock_time() - start_time ; + frame_time = frame_sched_time * (1.0/exec_get_time_tic_value()); } void Trick::FrameDataRecordGroup::adjust_time() { diff --git a/trick_source/sim_services/FrameLog/FrameLog.cpp b/trick_source/sim_services/FrameLog/FrameLog.cpp index b380f11b..66715a2b 100644 --- a/trick_source/sim_services/FrameLog/FrameLog.cpp +++ b/trick_source/sim_services/FrameLog/FrameLog.cpp @@ -36,8 +36,8 @@ Trick::FrameLog::FrameLog(Trick::Clock & in_clock) : fp_time_other(NULL), clock(in_clock) { - time_value_attr.type = TRICK_LONG_LONG ; - time_value_attr.size = sizeof(long long) ; + time_value_attr.type = TRICK_DOUBLE; + time_value_attr.size = sizeof(double); time_value_attr.units = strdup("s") ; the_fl = this ; @@ -144,7 +144,7 @@ void Trick::FrameLog::add_recording_vars_for_jobs() { } new_ref->reference = job_name; - new_ref->address = &(all_jobs_vector[ii]->frame_time) ; + new_ref->address = &(all_jobs_vector[ii]->frame_time_seconds) ; new_ref->attr = &time_value_attr ; /** @li use TRK tag in S_define to identify trick jobs */ // trick jobs @@ -184,7 +184,7 @@ void Trick::FrameLog::add_recording_vars_for_jobs() { if ( ii > 0 ) { std::ostringstream group_name ; group_name << "trick_frame_userjobs_C" << ii ; - (*fdrg_it)->add_variable( group_name.str() + ".frame_sched_time") ; + (*fdrg_it)->add_variable( group_name.str() + ".frame_time") ; } } drg_trick->set_job_class("end_of_frame") ; @@ -205,8 +205,8 @@ void Trick::FrameLog::add_recording_vars_for_frame() { char * job_name = NULL ; int ii ; - drg_frame->add_variable(rt_sim_object_name + std::string(".rt_sync.frame_sched_time")) ; - drg_frame->add_variable(rt_sim_object_name + std::string(".rt_sync.frame_overrun_time")) ; + drg_frame->add_variable(rt_sim_object_name + std::string(".rt_sync.frame_time")) ; + drg_frame->add_variable(rt_sim_object_name + std::string(".rt_sync.frame_overrun")) ; /* add the log_userjob frame time we created above to the log_frame group */ for ( ii = 0 ; ii < num_threads ; ii++ ) { @@ -220,7 +220,7 @@ void Trick::FrameLog::add_recording_vars_for_frame() { } trick_jobs.push_back(std::string(job_name)); new_ref->reference = job_name; - new_ref->address = &(drg_users[ii]->write_job->frame_time); + new_ref->address = &(drg_users[ii]->write_job->frame_time_seconds); new_ref->attr = &time_value_attr ; drg_frame->add_variable(new_ref) ; drg_frame->add_rec_job(drg_users[ii]->write_job) ; @@ -231,7 +231,7 @@ void Trick::FrameLog::add_recording_vars_for_frame() { asprintf(&job_name, "JOB_data_record_group.trickjobs.%2.2f(end_of_frame)",drg_trick->jobs[0]->frame_id); trick_jobs.push_back(std::string(job_name)); new_ref->reference = job_name; - new_ref->address = &(drg_trick->write_job->frame_time); + new_ref->address = &(drg_trick->write_job->frame_time_seconds); new_ref->attr = &time_value_attr ; drg_frame->add_variable(new_ref) ; drg_frame->add_rec_job(drg_trick->write_job) ; @@ -360,13 +360,16 @@ int Trick::FrameLog::frame_clock_stop(Trick::JobData * curr_job) { Trick::JobData * target_job = (Trick::JobData *)curr_job->sup_class_data ; int thread, mode; - + double time_scale; + /** @par Detailed Design: */ if ( target_job != NULL ) { if ( target_job->rt_start_time >= 0 ) { /** @li Set current job's stop time and frame time. */ target_job->rt_stop_time = clock.clock_time() ; + time_scale = 1.0 / target_job->time_tic_value; target_job->frame_time += (target_job->rt_stop_time - target_job->rt_start_time); + target_job->frame_time_seconds = target_job->frame_time * time_scale; thread = target_job->thread; mode = exec_get_mode(); @@ -405,6 +408,7 @@ int Trick::FrameLog::frame_clock_stop(Trick::JobData * curr_job) { target_job->rt_stop_time = 0; } else { target_job->frame_time = 0 ; + target_job->frame_time_seconds = 0.0; } } @@ -496,6 +500,8 @@ void Trick::FrameLog::default_data() { allocate_recording_groups() ; add_recording_vars_for_jobs() ; add_recording_vars_for_frame() ; + // reset clock before frame logging + clock.clock_reset(0); } /** @@ -739,14 +745,12 @@ int Trick::FrameLog::create_DP_job_files() { FILE *fpx; unsigned int pages, plots, total_plots, vcells, dot; char *bg_color; - double time_scale; std::string DP_buff; const char *headerx = "\n" \ "\n\n" \ "\n\n" \ "\n"; - time_scale = 1.0 / exec_get_time_tic_value(); DP_buff = DP_dir + "/DP_rt_frame.xml"; if ((fpx = fopen(DP_buff.c_str(), "w")) == NULL) { message_publish(MSG_WARNING, "Could not open DP_rt_frame.xml file for Frame Logging\n") ; @@ -758,16 +762,14 @@ int Trick::FrameLog::create_DP_job_files() { fprintf(fpx, " s \n"); fprintf(fpx, " \n"); fprintf(fpx, " \n sys.exec.out.time\n"); - fprintf(fpx, " %s.rt_sync.frame_overrun_time\n", - time_scale,rt_sim_object_name.c_str()); + fprintf(fpx, " %s.rt_sync.frame_overrun\n", rt_sim_object_name.c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); fprintf(fpx, " \n Frame Scheduled Jobs Time\n"); fprintf(fpx, " s \n"); fprintf(fpx, " \n"); fprintf(fpx, " \n sys.exec.out.time\n"); - fprintf(fpx, " %s.rt_sync.frame_sched_time\n", - time_scale,rt_sim_object_name.c_str()); + fprintf(fpx, " %s.rt_sync.frame_time\n", rt_sim_object_name.c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); fprintf(fpx, " \n"); @@ -796,8 +798,7 @@ int Trick::FrameLog::create_DP_job_files() { fprintf(fpx, " sys.exec.out.time\n"); std::ostringstream group_name ; group_name << "trick_frame_userjobs_C" << (page_count * plots_per_page + ii + 1) ; - fprintf(fpx, " %s.frame_sched_time\n", - time_scale,group_name.str().c_str()); + fprintf(fpx, " %s.frame_time\n", group_name.str().c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); } @@ -809,12 +810,10 @@ int Trick::FrameLog::create_DP_job_files() { fprintf(fpx, " \n sys.exec.out.time\n"); fprintf(fpx, " \n"); fprintf(fpx, " \n"); - fprintf(fpx, " \n %s.rt_sync.frame_overrun_time\n", - time_scale,rt_sim_object_name.c_str()); + fprintf(fpx, " \n %s.rt_sync.frame_overrun\n", rt_sim_object_name.c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); - fprintf(fpx, " \n %s.rt_sync.frame_sched_time\n", - time_scale,rt_sim_object_name.c_str()); + fprintf(fpx, " \n %s.rt_sync.frame_time\n", rt_sim_object_name.c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); fclose(fpx); @@ -861,7 +860,7 @@ int Trick::FrameLog::create_DP_job_files() { fprintf(fpx, " s \n"); fprintf(fpx, " \n"); fprintf(fpx, " \n sys.exec.out.time\n"); - fprintf(fpx, " %s\n", time_scale, (*drb_it)->name.c_str()); + fprintf(fpx, " %s\n", (*drb_it)->name.c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); plots++; @@ -919,7 +918,7 @@ int Trick::FrameLog::create_DP_job_files() { fprintf(fpx, " s \n"); fprintf(fpx, " \n"); fprintf(fpx, " \n sys.exec.out.time\n"); - fprintf(fpx, " %s\n", time_scale, (*job_iterator).c_str()); + fprintf(fpx, " %s\n", (*job_iterator).c_str()); fprintf(fpx, " \n"); fprintf(fpx, " \n"); job_iterator++; diff --git a/trick_source/sim_services/RealtimeSync/RealtimeSync.cpp b/trick_source/sim_services/RealtimeSync/RealtimeSync.cpp index e6b52b84..2b7e0f20 100644 --- a/trick_source/sim_services/RealtimeSync/RealtimeSync.cpp +++ b/trick_source/sim_services/RealtimeSync/RealtimeSync.cpp @@ -286,6 +286,8 @@ int Trick::RealtimeSync::rt_monitor(long long sim_time_tics) { /* calculate the current underrun/overrun */ curr_clock_time = rt_clock->clock_time() ; frame_sched_time = curr_clock_time - last_clock_time ; + frame_time = frame_sched_time * (1.0/tics_per_sec); + /* Set the next frame overrun/underrun reference time to the current time */ last_clock_time = curr_clock_time ; @@ -311,6 +313,8 @@ int Trick::RealtimeSync::rt_monitor(long long sim_time_tics) { frame_overrun_time = curr_clock_time - sim_time_tics ; + frame_overrun = frame_overrun_time * (1.0/tics_per_sec); + /* If the wall clock time is greater than the sim time an overrun occurred. */ if (curr_clock_time > sim_time_tics) { diff --git a/trick_source/sim_services/SimObject/JobData.cpp b/trick_source/sim_services/SimObject/JobData.cpp index 9b91bcc9..a248c414 100644 --- a/trick_source/sim_services/SimObject/JobData.cpp +++ b/trick_source/sim_services/SimObject/JobData.cpp @@ -32,6 +32,7 @@ Trick::JobData::JobData() { next_tics = 0 ; frame_time = 0 ; + frame_time_seconds = 0.0; } Trick::JobData::JobData(int in_thread, int in_id, std::string in_job_class_name , void* in_sup_class_data,