dali/internal/render/common/performance-monitor.cpp

   1 //
   2 // Copyright (c) 2014 Samsung Electronics Co., Ltd.
   3 //
   4 // Licensed under the Flora License, Version 1.0 (the License);
   5 // you may not use this file except in compliance with the License.
   6 // You may obtain a copy of the License at
   7 //
   8 //     http://floralicense.org/license/
   9 //
  10 // Unless required by applicable law or agreed to in writing, software
  11 // distributed under the License is distributed on an AS IS BASIS,
  12 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13 // See the License for the specific language governing permissions and
  14 // limitations under the License.
  15 //
  16
  17 // CLASS HEADER
  18 #include <dali/internal/render/common/performance-monitor.h>
  19
  20 // EXTERNAL INCLUDES
  21 #include <string>
  22 #include <time.h>
  23 #include <climits>
  24
  25 // INTERNAL INCLUDES
  26 #include <dali/public-api/common/dali-common.h>
  27 #include <dali/integration-api/debug.h>
  28 #include <dali/integration-api/platform-abstraction.h>
  29
  30
  31 #if defined(PRINT_TIMERS) || defined(PRINT_COUNTERS) || defined(PRINT_DRAW_CALLS) || defined(PRINT_MATH_COUNTERS)
  32
  33 namespace Dali
  34 {
  35
  36 namespace Internal
  37 {
  38
  39 namespace
  40 {
  41 PerformanceMonitor *mInstance = NULL;
  42 const float epsilon = 0.9f; // smooth average = (average * epsilon) + (current * epsilon)
  43
  44 const unsigned int MICROSECONDS_PER_SECOND = 1000000;
  45 const unsigned int NANOSECS_TO_MICROSECS = 1000;      ///< 1000 nanoseconds = 1 microsecond
  46
  47 /*
  48  * Structure similar to timespec which holds the seconds and millisecond values.
  49  */
  50 struct TimeInfo
  51 {
  52   unsigned int seconds;
  53   unsigned int microSeconds;
  54 };
  55
  56 /*
  57  * Returns the time difference in seconds (as a float)
  58  */
  59 float Diff(const TimeInfo& start, const TimeInfo& end)
  60 {
  61   int diff = end.microSeconds - start.microSeconds;
  62   if (diff < 0)
  63   {
  64     diff += MICROSECONDS_PER_SECOND;
  65   }
  66   return (float) diff / MICROSECONDS_PER_SECOND;
  67 }
  68
  69 } // unnamed namespace
  70
  71 /*
  72  * Base performance metric class, needs overloading
  73  */
  74 class PerformanceMetric
  75 {
  76
  77 public:
  78
  79   enum MetricType
  80   {
  81     TIMER,           ///< timer
  82     FPS_TIMER,       ///< timer that outputs in frames per second
  83     COUNTER,         ///< counter that is set once per frame using SET macro
  84     INC_COUNTER,     ///< incremental counter which is set multiple times per frame (e.g. to count number of draw calls).
  85     DATA_COUNTER,    ///< used to measure changes in data, e.g. amount of texture data uploaded
  86   };
  87
  88   PerformanceMetric(MetricType type):mType(type) {}
  89
  90   virtual void SetFloat(float value) {}
  91   virtual void SetInt(unsigned int value) {}
  92   virtual void IncreaseBy(unsigned int value) {}
  93   virtual void Tick() {}
  94   virtual void Reset() {};
  95   virtual void Log() = 0;
  96
  97   bool mEnabled;                ///< whether the metric is enabled
  98   MetricType mType;             ///< type of metric
  99   std::string mName;            ///< name
 100   unsigned int mMetricId;       ///< unique id
 101 };
 102
 103 /*
 104  * Timer metric, used to measure elapsed time each frame (e.g. for frame rate)
 105  */
 106 class TimerMetric : public PerformanceMetric
 107 {
 108 public:
 109
 110   TimerMetric()
 111   : PerformanceMetric( TIMER ),
 112     mAvg( 0.0 ),
 113     mTotal( 0.0 ),
 114     mCount( 0.0f )
 115   {
 116     Reset();
 117   }
 118
 119   void Reset()
 120   {
 121     mMin = 10.0;  // default min to 10 seconds
 122     mMax = 0.0;
 123   }
 124
 125   void Log()
 126   {
 127     LogMessage( Integration::Log::DebugInfo, "%s min: %.06f, max: %.06f, total %.06f, average: %.06f, count: %.0f, mean: %f\n", mName.c_str(), mMin, mMax, mTotal, mAvg, mCount, mTotal/mCount );
 128   }
 129
 130   float mMin;
 131   float mMax;
 132   float mAvg;
 133   float mTotal;
 134   float mCount;
 135   TimeInfo mTime;
 136 };
 137
 138 /*
 139  * Timer metric, used to measure elapsed time each frame (e.g. for frame rate)
 140  */
 141 class FPSTimerMetric : public TimerMetric
 142 {
 143 public:
 144
 145   void Log()
 146   {
 147     LogMessage( Integration::Log::DebugInfo, "%s average: %04f\n", mName.c_str(), 1.0f/mAvg );
 148   }
 149
 150 };
 151
 152 /*
 153  * Counter class, used to measure things like the number of nodes drawn
 154  */
 155 class CounterMetric : public PerformanceMetric
 156 {
 157 public:
 158
 159   CounterMetric():PerformanceMetric(COUNTER) { Reset();}
 160
 161   void Reset()
 162   {
 163     mMin = UINT_MAX;
 164     mMax = 0;
 165     mAvg = mLast;
 166   }
 167   /*
 168    * Used for values set one per-frame, e.g. number of messages
 169    */
 170   void SetInt(unsigned int value)
 171   {
 172     mLast = value;
 173
 174     if (mMin > value)
 175     {
 176       mMin = value;
 177     }
 178     if (mMax < value)
 179     {
 180       mMax = value;
 181     }
 182
 183     if (mAvg == 0)
 184     {
 185       mAvg = value;
 186     }
 187     else
 188     {
 189       mAvg =  ((float)mAvg * epsilon) + ((float)value * (1.0f - epsilon));
 190     }
 191   }
 192   void Log()
 193   {
 194     LogMessage(Integration::Log::DebugInfo, "%s  min: %04d, max: %04d, average: %04d\n",mName.c_str(),mMin,mMax,mAvg);
 195   }
 196
 197   unsigned int mMin;
 198   unsigned int mMax;
 199   unsigned int mAvg;
 200   unsigned int mLast;
 201
 202 };
 203
 204 /*
 205  * Incremental Counter class, used to measure things like the number of nodes drawn
 206  */
 207 class IncCounterMetric : public PerformanceMetric
 208 {
 209 public:
 210   IncCounterMetric():PerformanceMetric(INC_COUNTER){ Reset();}
 211
 212   virtual void Reset()
 213   {
 214     mMin = UINT_MAX;
 215     mMax = 0;
 216     mAvg = mCurrent;
 217     mCurrent = 0;
 218   }
 219   /*
 220    * Used for values that are set multiple times a frame, e.g. number of draw calls
 221    */
 222   void IncreaseBy(unsigned int value)
 223   {
 224     mCurrent += value;
 225   }
 226   virtual void Tick()
 227   {
 228     if (mMin > mCurrent)
 229     {
 230       mMin = mCurrent;
 231     }
 232     if (mMax < mCurrent)
 233     {
 234       mMax = mCurrent;
 235     }
 236
 237     if (mAvg == 0)
 238     {
 239       mAvg = mCurrent;
 240     }
 241     else
 242     {
 243       mAvg =  ((float)mAvg * epsilon) + ((float)mCurrent * (1.0f - epsilon));
 244     }
 245
 246     mCurrent = 0;
 247   }
 248
 249   virtual void Log()
 250   {
 251     LogMessage(Integration::Log::DebugInfo, "%s  min: %04d, max: %04d, average: %04d\n",mName.c_str(),mMin,mMax,mAvg);
 252   }
 253
 254   unsigned int mMin;
 255   unsigned int mMax;
 256   unsigned int mAvg;
 257   unsigned int mCurrent;
 258
 259 };
 260
 261 /*
 262  * Data Counter class
 263  * used to measure things like the number of texture bytes uploaded
 264  */
 265 class DataCountMetric : public IncCounterMetric
 266 {
 267 public:
 268
 269   DataCountMetric():mTotal(0) {}
 270
 271   virtual void Tick()
 272   {
 273     if (mMax < mCurrent)
 274     {
 275       mMax = mCurrent;
 276     }
 277
 278     mTotal += mCurrent;
 279
 280     mCurrent = 0;
 281   }
 282
 283   virtual void Log()
 284   {
 285     unsigned int shift = 0;
 286     std::string label("bytes");
 287
 288     if (mMax>>20)
 289     {
 290       shift = 20;
 291       label = "MegaBytes";
 292     }
 293     else if (mMax>>10)
 294     {
 295       shift = 10;
 296       label = "KiloBytes";
 297     }
 298
 299     LogMessage(Integration::Log::DebugInfo, "%s  max: %01d %s, total: %01d MegaBytes since start-up \n",
 300                mName.c_str(),
 301                mMax>>shift,
 302                label.c_str(),
 303                mTotal>>20);
 304   }
 305   unsigned int mTotal;
 306 };
 307
 308 /*
 309  * small structure used in MetricTable
 310  */
 311 struct MetricInfo
 312 {
 313   std::string mName;
 314   int mId;
 315   PerformanceMetric::MetricType type;
 316 };
 317
 318 /*
 319  * table to map a metric id, to a string / metric type
 320  */
 321 const MetricInfo MetricTable[] = {
 322   {  "NODE_COUNT            ",   PerformanceMonitor::NODE_COUNT,            PerformanceMetric::COUNTER },
 323   {  "NODES_DRAWN           ",   PerformanceMonitor::NODES_DRAWN,           PerformanceMetric::COUNTER },
 324   {  "MESSAGE_COUNT         ",   PerformanceMonitor::MESSAGE_COUNT,         PerformanceMetric::COUNTER },
 325   {  "NODES_ADDED           ",   PerformanceMonitor::NODES_ADDED,           PerformanceMetric::INC_COUNTER },
 326   {  "NODES_REMOVED         ",   PerformanceMonitor::NODES_REMOVED,         PerformanceMetric::INC_COUNTER },
 327   {  "ANIMATORS_APPLIED     ",   PerformanceMonitor::ANIMATORS_APPLIED,     PerformanceMetric::INC_COUNTER },
 328   {  "CONSTRAINTS_APPLIED   ",   PerformanceMonitor::CONSTRAINTS_APPLIED,   PerformanceMetric::INC_COUNTER },
 329   {  "CONSTRAINTS_SKIPPED   ",   PerformanceMonitor::CONSTRAINTS_SKIPPED,   PerformanceMetric::INC_COUNTER },
 330   {  "TEXTURE_STATE_CHANGES ",   PerformanceMonitor::TEXTURE_STATE_CHANGES, PerformanceMetric::INC_COUNTER },
 331   {  "SHADER_STATE_CHANGES  ",   PerformanceMonitor::SHADER_STATE_CHANGES,  PerformanceMetric::INC_COUNTER },
 332   {  "BLEND_MODE_CHANGES    ",   PerformanceMonitor::BLEND_MODE_CHANGES,    PerformanceMetric::INC_COUNTER },
 333   {  "INDICIES              ",   PerformanceMonitor::INDICIE_COUNT,         PerformanceMetric::INC_COUNTER },
 334   {  "GL_DRAW_CALLS         ",   PerformanceMonitor::GL_DRAW_CALLS,         PerformanceMetric::INC_COUNTER },
 335   {  "GL_DRAW_ELEMENTS      ",   PerformanceMonitor::GL_DRAW_ELEMENTS,      PerformanceMetric::INC_COUNTER },
 336   {  "GL_DRAW_ARRAYS        ",   PerformanceMonitor::GL_DRAW_ARRAYS,        PerformanceMetric::INC_COUNTER },
 337   {  "TEXTURE_LOADS         ",   PerformanceMonitor::TEXTURE_LOADS,         PerformanceMetric::INC_COUNTER },
 338   {  "TEXTURE_DATA_UPLOADED ",   PerformanceMonitor::TEXTURE_DATA_UPLOADED, PerformanceMetric::DATA_COUNTER },
 339   {  "VERTEX_BUFFERS_BUILT  ",   PerformanceMonitor::VERTEX_BUFFERS_BUILT,  PerformanceMetric::INC_COUNTER },
 340   {  "QUATERNION_TO_MATRIX  ",   PerformanceMonitor::QUATERNION_TO_MATRIX,  PerformanceMetric::INC_COUNTER },
 341   {  "MATRIX_MULTIPLYS      ",   PerformanceMonitor::MATRIX_MULTIPLYS,      PerformanceMetric::INC_COUNTER },
 342   {  "FLOAT_POINT_MULTIPLY  ",   PerformanceMonitor::FLOAT_POINT_MULTIPLY,  PerformanceMetric::INC_COUNTER },
 343   {  "UPDATE                ",   PerformanceMonitor::UPDATE,                PerformanceMetric::TIMER },
 344   {  "RESET_PROPERTIES      ",   PerformanceMonitor::RESET_PROPERTIES,      PerformanceMetric::TIMER },
 345   {  "PROCESS_MESSAGES      ",   PerformanceMonitor::PROCESS_MESSAGES,      PerformanceMetric::TIMER },
 346   {  "ANIMATE_NODES         ",   PerformanceMonitor::ANIMATE_NODES,         PerformanceMetric::TIMER },
 347   {  "APPLY_CONSTRAINTS     ",   PerformanceMonitor::APPLY_CONSTRAINTS,     PerformanceMetric::TIMER },
 348   {  "UPDATE_AND_SORT_NODES ",   PerformanceMonitor::UPDATE_NODES,          PerformanceMetric::TIMER },
 349   {  "PREPARE_RENDERABLES   ",   PerformanceMonitor::PREPARE_RENDERABLES,   PerformanceMetric::TIMER },
 350   {  "PROCESS_RENDER_TASKS  ",   PerformanceMonitor::PROCESS_RENDER_TASKS,  PerformanceMetric::TIMER },
 351   {  "DRAW_NODES            ",   PerformanceMonitor::DRAW_NODES,            PerformanceMetric::TIMER },
 352   {  "FRAME_RATE            ",   PerformanceMonitor::FRAME_RATE,            PerformanceMetric::FPS_TIMER }
 353 };
 354
 355 namespace
 356 {
 357 const unsigned int NUM_METRICS = sizeof(MetricTable)/sizeof(MetricInfo);
 358 } // unnamed namespace
 359
 360 void PerformanceMonitor::Init( Integration::PlatformAbstraction& platform )
 361 {
 362    if( NULL == mInstance )
 363    {
 364      mInstance = new PerformanceMonitor( platform );
 365    }
 366 }
 367
 368 PerformanceMonitor::PerformanceMonitor( Integration::PlatformAbstraction& platform )
 369 : mPlatform( platform ),
 370   mStartSeconds( 0 ),
 371   mSeconds( 0 )
 372 {
 373 }
 374
 375 PerformanceMonitor* PerformanceMonitor::Get()
 376 {
 377   DALI_ASSERT_ALWAYS( NULL != mInstance );
 378   return mInstance;
 379 }
 380
 381 PerformanceMetric *PerformanceMonitor::Add(Metric metricId)
 382 {
 383   PerformanceMetric *metric = NULL;
 384   const MetricInfo &info = GetMetricInfo(metricId);
 385
 386   switch (info.type)
 387   {
 388     case PerformanceMetric::FPS_TIMER   : metric = new FPSTimerMetric();   break;
 389     case PerformanceMetric::TIMER       : metric = new TimerMetric();      break;
 390     case PerformanceMetric::COUNTER     : metric = new CounterMetric();    break;
 391     case PerformanceMetric::INC_COUNTER : metric = new IncCounterMetric(); break;
 392     case PerformanceMetric::DATA_COUNTER: metric = new DataCountMetric();  break;
 393     default : DALI_ASSERT_ALWAYS( 0 && "PerformanceMetric enumeration out of bounds");
 394   }
 395
 396   metric->mMetricId = metricId;
 397   metric->mType = info.type;
 398   metric->mName = info.mName;
 399   metric->mEnabled = true;
 400   mMetrics[metricId] = metric;
 401
 402   return metric;
 403 }
 404
 405 PerformanceMetric *PerformanceMonitor::GetMetric(Metric metricId)
 406 {
 407   mLookupTypeType::const_iterator item=mMetrics.find(metricId);
 408   if (item!=mMetrics.end())
 409   {
 410     return ((*item).second);
 411   }
 412   // metric not found, so add it
 413   return Add(metricId);
 414 }
 415
 416 void PerformanceMonitor::Set(Metric metricId, float value)
 417 {
 418   PerformanceMetric *metric = GetMetric(metricId);
 419
 420   metric->SetFloat(value);
 421 }
 422
 423 void PerformanceMonitor::Set(Metric metricId, unsigned int value)
 424 {
 425   PerformanceMetric *metric = GetMetric(metricId);
 426
 427   metric->SetInt(value);
 428 }
 429
 430 void PerformanceMonitor::Increase(Metric metricId,unsigned int value)
 431 {
 432   PerformanceMetric *metric = GetMetric(metricId);
 433
 434   metric->IncreaseBy(value);
 435 }
 436
 437 void PerformanceMonitor::StartTimer(Metric metricId)
 438 {
 439   TimerMetric *timer = static_cast<TimerMetric *>(GetMetric(metricId));
 440
 441   TimeInfo& timeInfo = timer->mTime;
 442   mPlatform.GetTimeMicroseconds(timeInfo.seconds, timeInfo.microSeconds);
 443 }
 444
 445 void PerformanceMonitor::EndTimer(Metric metricId)
 446 {
 447   TimerMetric *timer = static_cast<TimerMetric *>(GetMetric(metricId));
 448   TimeInfo endTime;
 449
 450   mPlatform.GetTimeMicroseconds(endTime.seconds, endTime.microSeconds);
 451
 452   // frame time in seconds
 453   float elapsedTime = Diff(timer->mTime, endTime);
 454
 455   if (elapsedTime < timer->mMin)
 456   {
 457     timer->mMin = elapsedTime;
 458   }
 459   if (elapsedTime > timer->mMax)
 460   {
 461     timer->mMax = elapsedTime;
 462   }
 463
 464   timer->mTotal += elapsedTime;
 465
 466   timer->mCount += 1.0f;
 467
 468   timer->mAvg = (elapsedTime * (1.0f - epsilon)) + (timer->mAvg * epsilon);
 469 }
 470
 471 const MetricInfo &PerformanceMonitor::GetMetricInfo(Metric metricId)
 472 {
 473   for (unsigned int i = 0; i < NUM_METRICS; i++)
 474   {
 475     if (MetricTable[i].mId == metricId)
 476     {
 477       return MetricTable[i];
 478     }
 479   }
 480   DALI_ASSERT_ALWAYS(0 && "metricId not found");
 481   return MetricTable[0];
 482 }
 483
 484 void PerformanceMonitor::FrameTick()
 485 {
 486   unsigned int currentTimeSeconds;
 487   unsigned int currentTimeMicroSeconds;
 488   mLookupTypeType::const_iterator item;
 489
 490   mPlatform.GetTimeMicroseconds(currentTimeSeconds, currentTimeMicroSeconds);
 491
 492   // incremental counters need to know when a frame has been done
 493   // to store min/max/average values
 494
 495   for (item = mMetrics.begin(); item!=mMetrics.end(); item++)
 496   {
 497     PerformanceMetric *metric=(*item).second;
 498     metric->Tick();
 499   }
 500
 501   // only display info every other second
 502   if ( 0 == mSeconds )
 503   {
 504     // This is the first tick
 505     mStartSeconds = currentTimeSeconds;
 506   }
 507   else if ( currentTimeSeconds < (mSeconds + DEBUG_FREQUENCY))
 508   {
 509     return;
 510   }
 511
 512   mSeconds = currentTimeSeconds;
 513
 514   LogMessage(Integration::Log::DebugInfo, "--------------------------- %d\n", mSeconds - mStartSeconds);
 515   for (item = mMetrics.begin(); item!=mMetrics.end(); item++)
 516   {
 517     PerformanceMetric *metric=(*item).second;
 518     if (metric->mEnabled)
 519     {
 520       metric->Log();
 521       metric->Reset();
 522     }
 523   }
 524 }
 525
 526 } // namespace Internal
 527
 528 } // namespace Dali
 529
 530
 531 #endif