Merge pull request #818 from nasa/786-clock-stuff

Add C call to clock_tics_per_sec and also log init job elapsed time

.gitignore

@@ -26,3 +26,4 @@ aclocal.m4
 autom4te.cache
 trick_test
 gmon.out
+*init_log.csv*

include/trick/Executive.hh

@@ -7,6 +7,7 @@
 #define EXECUTIVE_HH
 
 #include <iostream>
+#include <fstream>
 #include <string>
 #include <map>
 #include <vector>
@@ -42,7 +43,6 @@ namespace Trick {
      */
 
     class Executive : public Trick::Scheduler {
-
         protected:
             /** Attempts to attach a debugger in the event a signal shuts down the simulation.\n */
             bool attach_debugger;            /**< trick_units(--) */
@@ -155,6 +155,10 @@ namespace Trick {
             /** Next scheduled jobs call time.\n */
             long long job_call_time_tics;   /**< trick_units(--) */
 
+            /** stream to record elapsed time of default_data, 
+                input_processor, and initialization queues \n */
+            std::ofstream init_log_stream; /**< trick_units(--) */
+
             /** Queue to hold default data jobs.\n */
             Trick::ScheduledJobQueue default_data_queue ;     /**< trick_io(**) */
 
@@ -1265,6 +1269,12 @@ namespace Trick {
             */
             virtual int exec_terminate(const char *file_name, const char *error);
             
+            /* deleted functions  */
+      private:
+            /* SWIG doesn't like the Executive assignment operator because of ofstream init_log_stream */
+            Executive& operator=(const Executive&); /* = delete; '= delete' is not compatible with SWIG 2.0.
+                                                                  stick to 'private' for now */
+
     } ;
 
 }

include/trick/clock_proto.h

@@ -13,6 +13,7 @@ int clock_spin(long long ref) ;
 int clock_set_reference(long long ref) ;
 double clock_get_rt_clock_ratio(void) ;
 int clock_set_rt_clock_ratio(double in_rt_clock_ratio) ;
+unsigned long long clock_tics_per_sec(void) ;
 
 #ifdef __cplusplus
 }

share/trick/sim_objects/default_trick_sys.sm

@@ -130,8 +130,6 @@ class SysSimObject : public Trick::SimObject {
 
         SysSimObject() {
 
-            {TRK} P0 ("default_data") sched.process_sim_args() ;
-
             {TRK} ("default_data") sched.get_freeze_job(name + ".sched") ;
 
             {TRK} P65534 ("initialization") exec_collect_init() ;

trick_sims/.gitignore

@@ -5,6 +5,7 @@ S_run_summary
 send_hs
 varserver_log
 log_*
+*init_log.csv*
 chkpnt_*
 MONTE_RUN_*
 .S_library*

trick_source/sim_services/Clock/clock_c_intf.cpp

@@ -32,3 +32,6 @@ extern "C" int clock_set_rt_clock_ratio(double in_clock_ratio) {
     return the_clock->set_rt_clock_ratio(in_clock_ratio) ;
 }
 
+extern "C" unsigned long long clock_tics_per_sec(void) {
+	return the_clock->clock_tics_per_sec;
+}

trick_source/sim_services/CommandLineArguments/CommandLineArguments.cpp

@@ -31,6 +31,9 @@ Trick::CommandLineArguments::CommandLineArguments() {
 
     output_dir = std::string(".") ;
     default_dir = std::string(".") ;
+
+    argc = 0;
+    argv = NULL;
 }
 
 int Trick::CommandLineArguments::get_argc() {

trick_source/sim_services/Executive/Executive_call_default_data.cpp

@@ -4,6 +4,7 @@
 
 #include "trick/Executive.hh"
 #include "trick/ExecutiveException.hh"
+#include "trick/clock_proto.h"
 
 /**
 @details
@@ -24,7 +25,12 @@ int Trick::Executive::call_default_data() {
     /* Call the default data jobs. */
     default_data_queue.reset_curr_index() ;
     while ( (curr_job = default_data_queue.get_next_job()) != NULL ) {
+        long long start = clock_wall_time();
         ret = curr_job->call() ;
+        long long end = clock_wall_time();
+        if(init_log_stream.is_open()) {
+          init_log_stream << "default_data," << curr_job->name << ',' << (double)(end-start)/clock_tics_per_sec() << '\n';
+        }
         if ( ret != 0 ) {
             throw Trick::ExecutiveException(ret , curr_job->name.c_str() , 0 , "default_data job did not return 0") ;
         }

trick_source/sim_services/Executive/Executive_call_initialization.cpp

@@ -1,9 +1,9 @@
 
 #include <iostream>
 #include <sys/resource.h>
-
 #include "trick/Executive.hh"
 #include "trick/ExecutiveException.hh"
+#include "trick/clock_proto.h"
 
 /**
 @details
@@ -22,7 +22,12 @@ int Trick::Executive::call_initialization() {
     /* Call the initialization jobs. */
     initialization_queue.reset_curr_index() ;
     while ( (curr_job = initialization_queue.get_next_job()) != NULL ) {
+        long long start = clock_wall_time();
         ret = curr_job->call() ;
+        long long end = clock_wall_time();
+        if(init_log_stream.is_open()) {
+            init_log_stream << "init," << curr_job->name << ',' << (double)(end-start)/clock_tics_per_sec() << '\n';
+        }
         if ( ret != 0 ) {
             throw Trick::ExecutiveException(ret , curr_job->name.c_str() , 0 , "initialization job did not return 0") ;
         }

trick_source/sim_services/Executive/Executive_call_input_processor.cpp

@@ -4,6 +4,7 @@
 
 #include "trick/Executive.hh"
 #include "trick/ExecutiveException.hh"
+#include "trick/clock_proto.h"
 
 /**
 @details
@@ -25,7 +26,12 @@ int Trick::Executive::call_input_processor() {
        So we test for the restart_called flag and break out of the loop if we restart_called is set. */
     input_processor_queue.reset_curr_index() ;
     while ( !restart_called and (curr_job = input_processor_queue.get_next_job()) != NULL ) {
+        long long start = clock_wall_time();
         ret = curr_job->call() ;
+        long long end = clock_wall_time();
+        if(init_log_stream.is_open()) {
+          init_log_stream << "input_processor," << curr_job->name << ',' << (double)(end-start)/clock_tics_per_sec() << '\n';
+        }
         if ( ret != 0 ) {
             throw Trick::ExecutiveException(ret , curr_job->name.c_str() , 0 , "input_processor job did not return 0") ;
         }

trick_source/sim_services/Executive/Executive_init.cpp

@@ -2,7 +2,6 @@
 #include <iostream>
 #include <stdlib.h>
 #include <sys/resource.h>
-
 #include "trick/Executive.hh"
 #include "trick/ExecutiveException.hh"
 #include "trick/exec_proto.h"
@@ -25,6 +24,7 @@ int Trick::Executive::init() {
 
     double cpu_time ;
 
+
     try {
 
         mode = Initialization ;
@@ -34,8 +34,10 @@ int Trick::Executive::init() {
         getrusage(RUSAGE_SELF, &cpu_usage_buf);
         cpu_start =   ((double) cpu_usage_buf.ru_utime.tv_sec) + ((double) cpu_usage_buf.ru_utime.tv_usec / 1000000.0);
         
-        call_default_data() ;
+        /* command line args */
+        process_sim_args();
 
+        call_default_data() ;
         call_input_processor() ;
 
         // If we are starting from a checkpoint, restart_called will be true.  Skip init routines in this case.
@@ -43,6 +45,8 @@ int Trick::Executive::init() {
             call_initialization() ;
         }
 
+        init_log_stream.close();
+
         /* Set the initial values for the scheduler times. */
         next_frame_check_tics = software_frame_tics + time_tics ;
         job_call_time_tics = next_frame_check_tics ;

trick_source/sim_services/Executive/Executive_process_sim_args.cpp

@@ -25,6 +25,7 @@
       simulation and exit.
    -# If the argument is "help" print out a help message about the possible command line
       arguments and exit.
+   -# If the argument is "sie" then disable init_log which records data on some job queues.
 */
 int Trick::Executive::process_sim_args() {
 
@@ -53,7 +54,7 @@ int Trick::Executive::process_sim_args() {
             "     trick_version       Print which version of Trick is being used\n"
             "                         to the screen.\n" ) ;
 
-    /* If there are arguments to main... */
+    bool open_stream = true;
     if (argc > 1) {
 
         if (!strcmp(argv[1], "trick_version")) {
@@ -64,9 +65,17 @@ int Trick::Executive::process_sim_args() {
                    !strcmp(argv[1], "-h")     || !strcmp(argv[1], "help") ) {
             /* Try and help the user */
             exit(0);
+        } else if (!strcmp(argv[1], "sie")) {
+            /* do not create init_log.csv if we are generating sie */
+            open_stream = false;
         }
     }
 
+    /* create a log if we are not generating an sie file (usually during trick-CP) */
+    if(open_stream) {
+        init_log_stream.open((std::string(command_line_args_get_output_dir()) + std::string("/_init_log.csv")).c_str(), std::ofstream::out);
+        init_log_stream << "class,job,duration (s)\n";
+    }
+
     return(0) ;
 }
-

trick_source/sim_services/Executive/test/Executive_test.cpp

@@ -14,6 +14,8 @@
 #include "trick/SimObject.hh"
 #include "trick/MemoryManager.hh"
 #include "trick/memorymanager_c_intf.h"
+#include "trick/CommandLineArguments.hh"
+#include "trick/GetTimeOfDayClock.hh"
 
 void sig_hand(int sig) ;
 void ctrl_c_hand(int sig) ;
@@ -225,10 +227,12 @@ class ExecutiveTest : public ::testing::Test {
         Trick::MessagePublisher mpublisher ;
         Trick::MessageCout mcout ;
         Trick::MemoryManager mm ;
+        Trick::CommandLineArguments cla ;
+        Trick::GetTimeOfDayClock gtodc ;
         //Trick::RequirementScribe req;
 
 
-        ExecutiveTest() {}
+        ExecutiveTest() {gtodc.set_global_clock();}
         ~ExecutiveTest() {}
         virtual void SetUp() ;
         virtual void TearDown() {}

trick_source/trick_utils/unicode/.gitignore

@@ -0,0 +1 @@
+*unicode_utils_test*