- update LOG_STATS

git-svn-id: https://openmodelica.org/svn/OpenModelica/trunk@15074 f25d12d1-65f4-0310-ae8a-bbce733d8d8e
OpenModelica · Feb 6, 2013 · d4118b9 · d4118b9
1 parent 9b7d846
commit d4118b9
Show file tree

Hide file tree

Showing 3 changed files with 81 additions and 52 deletions.
diff --git a/SimulationRuntime/c/simulation/solver/model_help.c b/SimulationRuntime/c/simulation/solver/model_help.c
@@ -1,8 +1,8 @@
 /*
  * This file is part of OpenModelica.
  *
- * Copyright (c) 1998-2010, Linköpings University,
- * Department of Computer and Information Science,
+ * Copyright (c) 1998-2010, Linköpings University, 
+ * Department of Computer and Information Science, 
  * SE-58183 Linköping, Sweden.
  *
  * All rights reserved.
@@ -14,7 +14,7 @@
  *
  * The OpenModelica software and the Open Source Modelica
  * Consortium (OSMC) Public License (OSMC-PL) are obtained
- * from Linköpings University, either from the above address,
+ * from Linköpings University, either from the above address, 
  * from the URL: http://www.ida.liu.se/projects/OpenModelica
  * and in the OpenModelica distribution.
  *
@@ -588,14 +588,14 @@ void initializeDataStruc(DATA *data)
     tmpSimData.timeValue = 0;
     /* buffer for all variable values */
     tmpSimData.realVars = (modelica_real*)calloc(data->modelData.nVariablesReal, sizeof(modelica_real));
-    ASSERT(tmpSimData.realVars,"out of memory");
+    ASSERT(tmpSimData.realVars, "out of memory");
     tmpSimData.integerVars = (modelica_integer*)calloc(data->modelData.nVariablesInteger, sizeof(modelica_integer));
-    ASSERT(tmpSimData.integerVars,"out of memory");
+    ASSERT(tmpSimData.integerVars, "out of memory");
     tmpSimData.booleanVars = (modelica_boolean*)calloc(data->modelData.nVariablesBoolean, sizeof(modelica_boolean));
-    ASSERT(tmpSimData.booleanVars,"out of memory");
+    ASSERT(tmpSimData.booleanVars, "out of memory");
     tmpSimData.stringVars = (modelica_string*)calloc(data->modelData.nVariablesString, sizeof(modelica_string));
-    ASSERT(tmpSimData.stringVars,"out of memory");
-    appendRingData(data->simulationData,&tmpSimData);
+    ASSERT(tmpSimData.stringVars, "out of memory");
+    appendRingData(data->simulationData, &tmpSimData);
   }
   data->localData = (SIMULATION_DATA**) calloc(SIZERINGBUFFER, sizeof(SIMULATION_DATA*));
   rotateRingBuffer(data->simulationData, 0, (void**) data->localData);
@@ -670,7 +670,7 @@ void initializeDataStruc(DATA *data)
   data->simulationInfo.extObjs = NULL;
   data->simulationInfo.extObjs = (void**) calloc(data->modelData.nExtObjs, sizeof(void*));
 
-  ASSERT(data->simulationInfo.extObjs,"error allocating external objects");
+  ASSERT(data->simulationInfo.extObjs, "error allocating external objects");
 
   /* initial build calls terminal, initial */
   data->simulationInfo.terminal = 0;
@@ -829,7 +829,7 @@ modelica_boolean LessZC(double a, double b, modelica_boolean direction)
 {
   modelica_boolean retVal;
   double eps = (direction)? tolZC*fabs(b)+tolZC : tolZC*fabs(a)+tolZC;
-  /*INFO4(LOG_EVENTS, "Relation LESS:  %.20e < %.20e = %c (%c)",a, b, (a < b)?'t':'f' , direction?'t':'f');*/
+  /*INFO4(LOG_EVENTS, "Relation LESS:  %.20e < %.20e = %c (%c)", a, b, (a < b)?'t':'f' , direction?'t':'f');*/
   retVal = (direction)? (a < b + eps):(a + eps < b);
   /*INFO1(LOG_EVENTS, "Result := %c", retVal?'t':'f');*/
   return retVal;
@@ -844,7 +844,7 @@ modelica_boolean GreaterZC(double a, double b, modelica_boolean direction)
 {
   modelica_boolean retVal;
   double eps = (direction)? tolZC*fabs(a)+tolZC : tolZC*fabs(b)+tolZC;
-  /*INFO4(LOG_EVENTS, "Relation GREATER:  %.20e > %.20e = %c (%c)",a, b, (a > b)?'t':'f' , direction?'t':'f');*/
+  /*INFO4(LOG_EVENTS, "Relation GREATER:  %.20e > %.20e = %c (%c)", a, b, (a > b)?'t':'f' , direction?'t':'f');*/
   retVal = (direction)? (a + eps > b ):(a  > b + eps);
   /*INFO1(LOG_EVENTS, "Result := %c", retVal?'t':'f');*/
   return retVal;
@@ -911,9 +911,10 @@ modelica_integer _event_integer(modelica_real x, modelica_integer index, DATA *d
 modelica_real _event_floor(modelica_real x, modelica_integer index, DATA *data)
 {
   modelica_real value;
-  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous){
+  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous)
     value = data->simulationInfo.mathEventsValuePre[index];
-  } else{
+  else
+  {
     data->simulationInfo.mathEventsValuePre[index] = x;
     value = data->simulationInfo.mathEventsValuePre[index];
   }
@@ -932,9 +933,10 @@ modelica_real _event_floor(modelica_real x, modelica_integer index, DATA *data)
 modelica_real _event_ceil(modelica_real x, modelica_integer index, DATA *data)
 {
   modelica_real value;
-  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous){
+  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous)
     value = data->simulationInfo.mathEventsValuePre[index];
-  } else{
+  else
+  {
     data->simulationInfo.mathEventsValuePre[index] = x;
     value = data->simulationInfo.mathEventsValuePre[index];
   }
@@ -952,18 +954,21 @@ modelica_real _event_ceil(modelica_real x, modelica_integer index, DATA *data)
  */
 modelica_integer _event_div_integer(modelica_integer x1, modelica_integer x2, modelica_integer index, DATA *data)
 {
-  modelica_integer value1,value2;
-  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous){
+  modelica_integer value1, value2;
+  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous)
+  {
     value1 = (modelica_integer)data->simulationInfo.mathEventsValuePre[index];
     value2 = (modelica_integer)data->simulationInfo.mathEventsValuePre[index+1];
-  } else{
+  }
+  else
+  {
     data->simulationInfo.mathEventsValuePre[index] = (modelica_real)x1;
     data->simulationInfo.mathEventsValuePre[index+1] = (modelica_real)x2;
     value1 = (modelica_integer)data->simulationInfo.mathEventsValuePre[index];
     value2 = (modelica_integer)data->simulationInfo.mathEventsValuePre[index+1];
   }
-  ASSERT1(value2 != 0,"event_div_integer failt at time %f because x2 is zero!",data->localData[0]->timeValue);
-  return ldiv(value1,value2).quot;
+  ASSERT1(value2 != 0, "event_div_integer failt at time %f because x2 is zero!", data->localData[0]->timeValue);
+  return ldiv(value1, value2).quot;
 }
 
 /*! \fn _event_div_real
@@ -977,11 +982,14 @@ modelica_integer _event_div_integer(modelica_integer x1, modelica_integer x2, mo
  */
 modelica_real _event_div_real(modelica_real x1, modelica_real x2, modelica_integer index, DATA *data)
 {
-  modelica_real value1,value2;
-  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous){
+  modelica_real value1, value2;
+  if(data->simulationInfo.discreteCall == 0 || data->simulationInfo.solveContinuous)
+  {
     value1 = data->simulationInfo.mathEventsValuePre[index];
     value2 = data->simulationInfo.mathEventsValuePre[index+1];
-  } else{
+  }
+  else
+  {
     data->simulationInfo.mathEventsValuePre[index] = x1;
     data->simulationInfo.mathEventsValuePre[index+1] = x2;
     value1 = data->simulationInfo.mathEventsValuePre[index];
@@ -992,7 +1000,7 @@ modelica_real _event_div_real(modelica_real x1, modelica_real x2, modelica_integ
     modelica_real rtmp = value1/value2;
     modelica_integer tmp = (modelica_integer)(rtmp);
     return (modelica_real)tmp;
-  };
+  }
 #else
   return trunc(value1/value2);
 #endif

diff --git a/SimulationRuntime/c/simulation/solver/solver_main.c b/SimulationRuntime/c/simulation/solver/solver_main.c
@@ -138,10 +138,12 @@ int solver_main(DATA* data, const char* init_initMethod,
   solverInfo.didEventStep = 0;
   solverInfo.stateEvents = 0;
   solverInfo.sampleEvents = 0;
+  /* not used
   solverInfo.stepNo = 0;
   solverInfo.callsODE = 0;
   solverInfo.callsDAE = 0;
-
+  */
+
   copyStartValuestoInitValues(data);
   /* read input vars */
   input_function(data);
@@ -278,7 +280,6 @@ int solver_main(DATA* data, const char* init_initMethod,
    */
   while(solverInfo.currentTime < simInfo->stopTime)
   {
-    INDENT(LOG_SOLVER);
     if(measure_time_flag)
     {
       for(i = 0; i < data->modelData.modelDataXml.nFunctions + data->modelData.modelDataXml.nProfileBlocks; i++)
@@ -447,7 +448,6 @@ int solver_main(DATA* data, const char* init_initMethod,
       }
       break;
     }
-    RELEASE(LOG_SOLVER);
   } /* end while solver */
 
 
@@ -467,33 +467,52 @@ int solver_main(DATA* data, const char* init_initMethod,
     writeOutputVars(strdup(outputVariablesAtEnd), data);
   }
 
-  /* save dassl stats before print */
-
   if(DEBUG_STREAM(LOG_STATS))
   {
-    if(flag == 3)
+    rt_accumulate(SIM_TIMER_TOTAL);
+
+    INFO(LOG_STATS, "### STATISTICS ###");
+
+    INFO(LOG_STATS, "timer");
+    INDENT(LOG_STATS);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] pre-initialization", rt_accumulated(SIM_TIMER_PREINIT), rt_accumulated(SIM_TIMER_PREINIT)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] initialization", rt_accumulated(SIM_TIMER_INIT), rt_accumulated(SIM_TIMER_INIT)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] steps", rt_accumulated(SIM_TIMER_STEP), rt_accumulated(SIM_TIMER_STEP)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] creating output-file", rt_accumulated(SIM_TIMER_OUTPUT), rt_accumulated(SIM_TIMER_OUTPUT)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] event-handling", rt_accumulated(SIM_TIMER_EVENT), rt_accumulated(SIM_TIMER_EVENT)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] overhead", rt_accumulated(SIM_TIMER_OVERHEAD), rt_accumulated(SIM_TIMER_OVERHEAD)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    INFO2(LOG_STATS, "%12gs [%5.1f%%] simulation", rt_accumulated(SIM_TIMER_TOTAL), rt_accumulated(SIM_TIMER_TOTAL)/rt_accumulated(SIM_TIMER_TOTAL)*100.0);
+    RELEASE(LOG_STATS);
+
+    INFO(LOG_STATS, "events");
+    INDENT(LOG_STATS);
+    INFO1(LOG_STATS, "%5ld state events", solverInfo.stateEvents);
+    INFO1(LOG_STATS, "%5ld sample events", solverInfo.sampleEvents);
+    RELEASE(LOG_STATS);
+
+    INFO(LOG_STATS, "solver");
+    INDENT(LOG_STATS);
+    if(flag == 3) /* dassl */
     {
+      /* save dassl stats before print */
       for(ui = 0; ui < numStatistics; ui++)
         ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[ui] += ((DASSL_DATA*)solverInfo.solverData)->dasslStatisticsTmp[ui];
+
+      INFO1(LOG_STATS, "%5d steps taken", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[0]);
+      INFO1(LOG_STATS, "%5d calls of functionODE", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[1]);
+      INFO1(LOG_STATS, "%5d evaluations of jacobian", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[2]);
+      INFO1(LOG_STATS, "%5d error test failures", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[3]);
+      INFO1(LOG_STATS, "%5d convergence test failures", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[4]);
     }
-    rt_accumulate(SIM_TIMER_TOTAL);
-
-    INFO(LOG_STATS, "##### Statistics #####");
-    INFO1(LOG_STATS, "simulation time: %g", rt_accumulated(SIM_TIMER_TOTAL));
-    INFO1(LOG_STATS, "Events: %d", solverInfo.stateEvents + solverInfo.sampleEvents);
-    INFO1(LOG_STATS, "State Events: %d", solverInfo.stateEvents);
-    INFO1(LOG_STATS, "Sample Events: %d", solverInfo.sampleEvents);
-    if(flag == 3)
+    else
     {
-      INFO(LOG_STATS, "##### Solver Statistics #####");
-      INFO1(LOG_STATS, "The number of steps taken: %d", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[0]);
-      INFO1(LOG_STATS, "The number of calls to functionODE: %d", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[1]);
-      INFO1(LOG_STATS, "The evaluations of Jacobian: %d", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[2]);
-      INFO1(LOG_STATS, "The number of error test failures: %d", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[3]);
-      INFO1(LOG_STATS, "The number of convergence test failures: %d", ((DASSL_DATA*)solverInfo.solverData)->dasslStatistics[4]);
+      INFO(LOG_STATS, "sorry - no solver statistics available. [not yet implemented]");
     }
+    RELEASE(LOG_STATS);
+
+    INFO(LOG_STATS, "### END STATISTICS ###");
+
     rt_tick(SIM_TIMER_TOTAL);
-
   }
 
   /* deintialize solver related workspace */
@@ -614,8 +633,8 @@ int radauIIA_step(DATA* data, SOLVER_INFO* solverInfo)
 }
 #endif
 
-/** function checkTermination
- *  author: wbraun
+/*! \fn checkTermination
+ *  \author wbraun
  *
  *  function checks if the model should really terminated.
  */

diff --git a/SimulationRuntime/c/simulation/solver/solver_main.h b/SimulationRuntime/c/simulation/solver/solver_main.h
@@ -60,11 +60,13 @@ typedef struct SOLVER_INFO
   modelica_boolean didEventStep;
 
   /* stats */
-  unsigned int stateEvents;
-  unsigned int sampleEvents;
-  unsigned int stepNo;
-  unsigned int callsODE;
-  unsigned int callsDAE;
+  unsigned long stateEvents;
+  unsigned long sampleEvents;
+  /* not used
+  unsigned long stepNo;
+  unsigned long callsODE;
+  unsigned long callsDAE;
+  */
 
   void* solverData;
 }SOLVER_INFO;