- Moved rtclock from Compiler/runtime to c_runtime

  - Started using the rt clock to do time measurements in simulations


git-svn-id: https://openmodelica.org/svn/OpenModelica/trunk@7679 f25d12d1-65f4-0310-ae8a-bbce733d8d8e

Compiler/FrontEnd/Ceval.mo

@@ -4395,6 +4395,7 @@ algorithm
       Option<Interactive.InteractiveSymbolTable> st;
       Msg msg;
       Env.Cache cache;
+      String str;
     case (cache,env,{xe,ye},impl,st,msg)
       equation
         (cache,Values.ARRAY(xv,{3}),_) = ceval(cache,env, xe, impl, st,NONE(), msg);
@@ -4404,7 +4405,8 @@ algorithm
         (cache,res,st);
     case (_,_,_,_,_,MSG())
       equation
-        Print.printErrorBuf("#- Error, could not evaulate cross. Ceval.cevalBuiltinCross failed.\n");
+        str = "cross" +& ExpressionDump.printExpStr(DAE.TUPLE(inExpExpLst));
+        Error.addMessage(Error.FAILED_TO_EVALUATE_EXPRESSION, {str});
       then
         fail();
   end matchcontinue;

Compiler/FrontEnd/ValuesUtil.mo

@@ -1693,7 +1693,7 @@ algorithm
         makeArray({Values.INTEGER(iz1),Values.INTEGER(iz2),Values.INTEGER(iz3)});
     case (_,_)
       equation
-        Debug.fprintln("failtrace", "- ValuesUtil.crossProduct failed");
+        Error.addMessage(Error.INTERNAL_ERROR, {"ValuesUtil.crossProduct failed"});
       then
         fail();
   end matchcontinue;

Compiler/Util/Error.mo

@@ -271,6 +271,7 @@ public constant ErrorID CONSISTENT_UNITS=518;
 public constant ErrorID INCOMPLETE_UNITS=519;
 public constant ErrorID INCOMPATIBLE_TYPES_FUNC=520;
 public constant ErrorID ASSIGN_RHS_ELABORATION=521;
+public constant ErrorID FAILED_TO_EVALUATE_EXPRESSION = 522;
 
 public constant ErrorID INDEX_REDUCTION_NOTIFICATION=1000;
 public constant ErrorID SELECTED_STATE_DUE_TO_START_NOTIFICATION = 1001;
@@ -687,6 +688,7 @@ protected constant list<tuple<Integer, MessageType, Severity, String>> errorTabl
           (META_DEAD_CODE,TRANSLATION(),NOTIFICATION(),"Dead code elimination: %s."),
           (META_UNUSED_DECL,TRANSLATION(),NOTIFICATION(),"Unused local variable: %s."),
           (META_UNUSED_AS_BINDING,TRANSLATION(),NOTIFICATION(),"Removing unused as-binding: %s."),
+          (FAILED_TO_EVALUATE_EXPRESSION,TRANSLATION(),ERROR(),"Could not evaluate expression: %s"),
 
           (COMPILER_WARNING,TRANSLATION(),WARNING(),"%s")
           };

Compiler/runtime/Makefile.common

@@ -19,7 +19,7 @@ endif
 RML_COMPAT=$(top_builddir)/c_runtime/rml_compatibility.h
 
 SRC	= RTOpts_rml.c Print_rml.c System_rml.c Settings_rml.c \
-  SimulationResults_rml.c IOStreamExt_rml.c rtclock.c Database.c Socket_rml.c
+  SimulationResults_rml.c IOStreamExt_rml.c Database.c Socket_rml.c
 
 CPPSRC  = unitparser.cpp UnitParserExt_rml.cpp ptolemyio_rml.cpp \
   BackendDAEEXT_rml.cpp ErrorMessage.cpp Error_rml.cpp OptManager_rml.cpp \
@@ -28,7 +28,7 @@ CPPSRC  = unitparser.cpp UnitParserExt_rml.cpp ptolemyio_rml.cpp \
 OBJ     = $(SRC:.c=.o) $(CPPSRC:.cpp=.o) $(CPPSRC:.cc=.o)
 
 OMC_OBJ = Error_omc.o Print_omc.o RTOpts_omc.o System_omc.o Settings_omc.o \
-  IOStreamExt_omc.o ErrorMessage.o systemimplmisc.o rtclock.o \
+  IOStreamExt_omc.o ErrorMessage.o systemimplmisc.o \
   UnitParserExt_omc.o unitparser.o BackendDAEEXT_omc.o Socket_omc.o \
   Dynload_omc.o OptManager_omc.o SimulationResults_omc.o ptolemyio_omc.o $(OMCCORBASRC)
 

c_runtime/Makefile.common

@@ -15,7 +15,7 @@ ddasrt.o  dlinpk.o  enorm.o   hybrd1.o  nelmead.o  qform.o   r1updt.o \
 biglag.o  ddassl.o  dogleg.o  fdjac1.o  hybrj.o   newuoa.o   qrfac.o   trsapp.o \
 daux.o    dlamch.o  dpmpar.o  hybrd.o   lsame.o   newuob.o   r1mpyq.o  update.o division.o\
 java_interface.o meta_modelica.o meta_modelica_builtin.o meta_modelica_real.o \
-meta_modelica_string_lit.o ModelicaUtilities.o $(EXTRA_OBJS)
+meta_modelica_string_lit.o rtclock.o ModelicaUtilities.o $(EXTRA_OBJS)
 
 SIMOBJS = $(FOBJS) simulation_runtime.o simulation_init.o simulation_input.o simulation_events.o linearize.o \
 solver_dasrt.o solver_main.o simulation_result_plt.o simulation_result_csv.o simulation_result_bin.o simulation_result_mat.o simulation_delay.o tables.o options.o dgesv_aux.o $(EXTRA_SIMOBJS)
@@ -50,6 +50,7 @@ read_write.h \
 real_array.h \
 ringbuffer.h \
 rml_compatibility.h \
+rtclock.h \
 sendData/sendData.h \
 simulation_delay.h \
 simulation_events.h \

c_runtime/meta_modelica_builtin_boxptr.h

@@ -25,25 +25,25 @@ boxptr_binOp(boxptr_intMul,mmc_mk_icon,mmc_unbox_integer,*)
 boxptr_binOp(boxptr_intDiv,mmc_mk_icon,mmc_unbox_integer,/)
 boxptr_unOp(boxptr_intAbs,mmc_mk_icon,mmc_unbox_integer,labs)
 boxptr_unOp(boxptr_intNeg,mmc_mk_icon,mmc_unbox_integer,-)
-boxptr_binOp(boxptr_intLt,mmc_mk_icon,mmc_unbox_integer,<)
-boxptr_binOp(boxptr_intLe,mmc_mk_icon,mmc_unbox_integer,<=)
-boxptr_binOp(boxptr_intEq,mmc_mk_icon,mmc_unbox_integer,==)
-boxptr_binOp(boxptr_intNe,mmc_mk_icon,mmc_unbox_integer,!=)
-boxptr_binOp(boxptr_intGe,mmc_mk_icon,mmc_unbox_integer,>)
-boxptr_binOp(boxptr_intGt,mmc_mk_icon,mmc_unbox_integer,>=)
+boxptr_binOp(boxptr_intLt,mmc_mk_bcon,mmc_unbox_integer,<)
+boxptr_binOp(boxptr_intLe,mmc_mk_bcon,mmc_unbox_integer,<=)
+boxptr_binOp(boxptr_intEq,mmc_mk_bcon,mmc_unbox_integer,==)
+boxptr_binOp(boxptr_intNe,mmc_mk_bcon,mmc_unbox_integer,!=)
+boxptr_binOp(boxptr_intGe,mmc_mk_bcon,mmc_unbox_integer,>=)
+boxptr_binOp(boxptr_intGt,mmc_mk_bcon,mmc_unbox_integer,>)
 boxptr_unOp(boxptr_intReal,mmc_mk_rcon,mmc_unbox_integer,(modelica_real))
 boxptr_binOp(boxptr_realAdd,mmc_mk_rcon,mmc_unbox_real,+)
 boxptr_binOp(boxptr_realSub,mmc_mk_rcon,mmc_unbox_real,-)
 boxptr_binOp(boxptr_realMul,mmc_mk_rcon,mmc_unbox_real,*)
 boxptr_binOp(boxptr_realDiv,mmc_mk_rcon,mmc_unbox_real,/)
 boxptr_unOp(boxptr_realAbs,mmc_mk_rcon,mmc_unbox_real,fabs)
 boxptr_unOp(boxptr_realNeg,mmc_mk_rcon,mmc_unbox_real,-)
-boxptr_binOp(boxptr_realLt,mmc_mk_rcon,mmc_unbox_real,<)
-boxptr_binOp(boxptr_realLe,mmc_mk_rcon,mmc_unbox_real,<=)
-boxptr_binOp(boxptr_realEq,mmc_mk_rcon,mmc_unbox_real,==)
-boxptr_binOp(boxptr_realNe,mmc_mk_rcon,mmc_unbox_real,!=)
-boxptr_binOp(boxptr_realGe,mmc_mk_rcon,mmc_unbox_real,>)
-boxptr_binOp(boxptr_realGt,mmc_mk_rcon,mmc_unbox_real,>=)
+boxptr_binOp(boxptr_realLt,mmc_mk_bcon,mmc_unbox_real,<)
+boxptr_binOp(boxptr_realLe,mmc_mk_bcon,mmc_unbox_real,<=)
+boxptr_binOp(boxptr_realEq,mmc_mk_bcon,mmc_unbox_real,==)
+boxptr_binOp(boxptr_realNe,mmc_mk_bcon,mmc_unbox_real,!=)
+boxptr_binOp(boxptr_realGe,mmc_mk_bcon,mmc_unbox_real,>=)
+boxptr_binOp(boxptr_realGt,mmc_mk_bcon,mmc_unbox_real,>)
 boxptr_unOp(boxptr_realInt,mmc_mk_icon,mmc_unbox_real,(modelica_integer))
 
 #undef boxptr_unOp

Compiler/runtime/rtclock.c → c_runtime/rtclock.c

@@ -35,6 +35,7 @@
 #include <windows.h>
 
 LARGE_INTEGER performance_frequency;
+LARGE_INTEGER acc_tp[NUM_RT_CLOCKS];
 LARGE_INTEGER tick_tp[NUM_RT_CLOCKS];
 
 void rt_tick(int ix) {
@@ -55,11 +56,30 @@ double rt_tock(int ix) {
   return d1 / d2;
 }
 
+void rt_clear(int ix)
+{
+  acc_tp[ix] = 0;
+}
+
+void rt_accumulate(int ix) {
+  LARGE_INTEGER tock_tp;
+  QueryPerformanceCounter(&tock_tp);
+  acc_tp[ix] += tock_tp - tick_tp[ix];
+}
+
+double rt_total(int ix) {
+  double d1,d2;
+  d1 = (double)(acc_tp[ix].QuadPart);
+  d2 = (double) performance_frequency.QuadPart;
+  return d1 / d2;
+}
+
 #elif defined(__APPLE_CC__)
 
 #include <mach/mach_time.h>
 #include <time.h>
 
+uint64_t acc_tp[NUM_RT_CLOCKS];
 uint64_t tick_tp[NUM_RT_CLOCKS];
 
 void rt_tick(int ix) {
@@ -76,10 +96,29 @@ double rt_tock(int ix) {
   return elapsednano * 1e-9;
 }
 
+void rt_clear(int ix)
+{
+  acc_tp[ix] = 0;
+}
+
+void rt_accumulate(int ix) {
+  uint64_t tock_tp = mach_absolute_time();
+  acc_tp[ix] += tock_tp - tick_tp[ix];
+}
+
+double rt_total(int ix) {
+  static mach_timebase_info_data_t info = {0,0};
+  if (info.denom == 0)
+    mach_timebase_info(&info);
+  uint64_t elapsednano = acc_tp[ix] * (info.numer / info.denom);
+  return elapsednano * 1e-9;
+}
+
 #else
 
 #include <time.h>
 
+struct timespec acc_tp[NUM_RT_CLOCKS];
 struct timespec tick_tp[NUM_RT_CLOCKS];
 
 void rt_tick(int ix) {
@@ -92,4 +131,25 @@ double rt_tock(int ix) {
   return (tock_tp.tv_sec - tick_tp[ix].tv_sec) + (tock_tp.tv_nsec - tick_tp[ix].tv_nsec)*1e-9;
 }
 
+void rt_clear(int ix)
+{
+  acc_tp[ix].tv_sec = 0;
+  acc_tp[ix].tv_nsec = 0;
+}
+
+void rt_accumulate(int ix) {
+  struct timespec tock_tp = {0,0};
+  clock_gettime(CLOCK_MONOTONIC, &tock_tp);
+  acc_tp[ix].tv_sec  += tock_tp.tv_sec -tick_tp[ix].tv_sec;
+  acc_tp[ix].tv_nsec += tock_tp.tv_nsec-tick_tp[ix].tv_nsec;
+  if (acc_tp[ix].tv_nsec > 1e9) {
+    acc_tp[ix].tv_sec++;
+    acc_tp[ix].tv_nsec -= 1e9;
+  }
+}
+
+double rt_total(int ix) {
+  return acc_tp[ix].tv_sec + (acc_tp[ix].tv_nsec*1e-9);
+}
+
 #endif

Compiler/runtime/rtclock.h → c_runtime/rtclock.h

@@ -31,11 +31,32 @@
 #ifndef __RTCLOCK__H
 #define __RTCLOCK__H
 
+#ifdef __cplusplus
+extern "C" {
+#endif
+
 #define NUM_RT_CLOCKS 17
 #define NUM_USER_RT_CLOCKS 16
 #define RT_CLOCK_SPECIAL_STOPWATCH 16 /* The 17th clock */
 
+#define SIM_TIMER_TOTAL   0
+#define SIM_TIMER_INIT    1
+#define SIM_TIMER_STEP    2
+#define SIM_TIMER_OUTPUT  3
+#define SIM_TIMER_EVENT   4
+
 void rt_tick(int ix);
+/* tick() ... tock() -> returns the number of seconds since the tick */
 double rt_tock(int ix);
 
+/*clear() ... tick() ... accumulate() ... tick() ... accumulate()
+ * returns the total number of seconds accumulated between the tick() and accumulate() calls */
+void rt_clear(int ix);
+void rt_accumulate(int ix);
+double rt_total(int ix);
+
+#ifdef __cplusplus
+}
+#endif
+
 #endif

c_runtime/simulation_result_csv.cpp

@@ -46,12 +46,13 @@
 #include "simulation_runtime.h"
 #include <sstream>
 #include <time.h>
-
+#include "rtclock.h"
 
 void simulation_result_csv::emit()
 {
   const char* format = "%.16g,";
   storeExtrapolationData();
+  rt_tick(SIM_TIMER_OUTPUT);
   fprintf(fout, format, globalData->timeValue);
   for (int i = 0; i < globalData->nStates; i++)
      fprintf(fout, format, globalData->states[i]);
@@ -64,6 +65,7 @@ void simulation_result_csv::emit()
   for (int i = 0; i < globalData->boolVariables.nAlgebraic; i++)
     fprintf(fout, format, globalData->boolVariables.algebraics[i]);
   fprintf(fout, "\n");
+  rt_accumulate(SIM_TIMER_OUTPUT);
 }
 
 simulation_result_csv::simulation_result_csv(const char* filename, long numpoints) : simulation_result(filename,numpoints)
@@ -92,5 +94,7 @@ simulation_result_csv::simulation_result_csv(const char* filename, long numpoint
 
 simulation_result_csv::~simulation_result_csv()
 {
+  rt_tick(SIM_TIMER_OUTPUT);
   fclose(fout);
+  rt_accumulate(SIM_TIMER_OUTPUT);
 }

c_runtime/simulation_result_plt.cpp

@@ -47,6 +47,7 @@
 #include <sstream>
 #include <time.h>
 #include "../Compiler/runtime/config.h"
+#include "rtclock.h"
 
 #ifdef CONFIG_WITH_SENDDATA
 #include "sendData/sendData.h"
@@ -55,11 +56,10 @@
 void simulation_result_plt::emit()
 {
   storeExtrapolationData();
+  rt_tick(SIM_TIMER_OUTPUT);
   if (actualPoints < maxPoints) {
     if(!isInteractiveSimulation())add_result(simulationResultData,&actualPoints); //used for non-interactive simulation
-    return;
-  }
-  else {
+  } else {
     maxPoints = 1.4*maxPoints + (maxPoints-actualPoints) + 2000;
     // cerr << "realloc simulationResultData to a size of " << maxPoints * dataSize * sizeof(double) << endl;
     simulationResultData = (double*)realloc(simulationResultData, maxPoints * dataSize * sizeof(double));
@@ -69,6 +69,7 @@ void simulation_result_plt::emit()
     }
     add_result(simulationResultData,&actualPoints);
   }
+  rt_accumulate(SIM_TIMER_OUTPUT);
 }
 
  /*
@@ -221,6 +222,7 @@ simulation_result_plt::~simulation_result_plt()
   if(Static::enabled())
     closeSendData();
 #endif
+  rt_tick(SIM_TIMER_OUTPUT);
 
   FILE* f = fopen(filename, "w");
   if (!f)
@@ -230,9 +232,6 @@ simulation_result_plt::~simulation_result_plt()
     throw SimulationResultFileOpenException();
   }
 
-  clock_t  t0, t1;
-  t0 = clock();
-
   // Rather ugly numbers than unneccessary rounding.
   //f.precision(std::numeric_limits<double>::digits10 + 1);
   fprintf(f, "#Ptolemy Plot file, generated by OpenModelica\n");
@@ -295,6 +294,5 @@ simulation_result_plt::~simulation_result_plt()
     throw SimulationResultFileCloseException();
   }
 
-  t1 = clock();
-  // printf ("\telapsed wall clock time for printing simulation results: %g\n", ((double) (t1 - t0))/CLOCKS_PER_SEC);
+  rt_accumulate(SIM_TIMER_OUTPUT);
 }

c_runtime/simulation_runtime.cpp

@@ -52,6 +52,7 @@
 #include "simulation_result_plt.h"
 #include "simulation_result_csv.h"
 #include "simulation_result_mat.h"
+#include "rtclock.h"
 
 using namespace std;
 
@@ -262,8 +263,12 @@ int startNonInteractiveSimulation(int argc, char**argv){
   initSample(start,stop);
   initDelay(start);
 
-  if (measure_time_flag)
-    measure_start_time = clock();
+  if (measure_time_flag) {
+    rt_tick(SIM_TIMER_TOTAL);
+    rt_clear(SIM_TIMER_OUTPUT);
+    rt_clear(SIM_TIMER_EVENT);
+    rt_clear(SIM_TIMER_INIT);
+  }
 
   if(create_linearmodel){
     if (lintime == NULL ) {
@@ -285,8 +290,12 @@ int startNonInteractiveSimulation(int argc, char**argv){
 
   deinitDelay();
 
-  if (measure_time_flag)
-     cout << "Time to calculate simulation: "<< (clock()-measure_start_time)/CLOCKS_PER_SEC <<" sec." << endl;
+  if (measure_time_flag) {
+    cout << "Time to calculate initial values: "<< rt_total(SIM_TIMER_INIT) <<" sec." << endl;
+    cout << "Total time to do event handling: "<< rt_total(SIM_TIMER_EVENT) <<" sec." << endl;
+    cout << "Total time to produce the output file: "<< rt_total(SIM_TIMER_OUTPUT) <<" sec." << endl;
+    cout << "Total time to calculate simulation: "<< rt_tock(SIM_TIMER_TOTAL) <<" sec." << endl;
+  }
   deInitializeDataStruc(globalData,ALL);
 
   return retVal;