Add trace log to check performance of text update

[platform/core/uifw/dali-toolkit.git] / dali-toolkit / internal / text / controller / text-controller-impl-model-updater.cpp

diff --git a/dali-toolkit/internal/text/controller/text-controller-impl-model-updater.cpp b/dali-toolkit/internal/text/controller/text-controller-impl-model-updater.cpp
index 01e9157..ab005b1 100644 (file)
--- a/dali-toolkit/internal/text/controller/text-controller-impl-model-updater.cpp
+++ b/dali-toolkit/internal/text/controller/text-controller-impl-model-updater.cpp
@@ -43,6 +43,18 @@ Debug::Filter* gLogFilter = Debug::Filter::New(Debug::NoLogging, true, "LOG_TEXT
 
 DALI_INIT_TRACE_FILTER(gTraceFilter, DALI_TRACE_TEXT_PERFORMANCE_MARKER, false);
 
+#if defined(TRACE_ENABLED)
+uint32_t GetMilliSeconds()
+{
+  // Get the time of a monotonic clock since its epoch.
+  auto epoch = std::chrono::steady_clock::now().time_since_epoch();
+
+  auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(epoch);
+
+  return static_cast<uint32_t>(duration.count());
+}
+#endif
+
 // The relative luminance of a color is defined as (L = 0.2126 * R + 0.7152 * G + 0.0722 * B)
 // based on W3C Recommendations (https://www.w3.org/TR/WCAG20/)
 constexpr float         BRIGHTNESS_THRESHOLD = 0.179f;
@@ -327,6 +339,20 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
   newParagraphGlyphs.Reserve(numberOfParagraphs);
 
   const Length currentNumberOfGlyphs = glyphs.Count();
+
+#if defined(TRACE_ENABLED)
+  uint32_t logThreshold = TextAbstraction::FontClient::GetPerformanceLogThresholdTime();
+  bool     logEnabled   = TextAbstraction::FontClient::IsPerformanceLogEnabled();
+
+  uint32_t timeStamps[6];
+  uint32_t timeStampIndex = 0;
+
+  if(logEnabled)
+  {
+    timeStamps[timeStampIndex++] = GetMilliSeconds();
+  }
+#endif
+
   if(Controller::NO_OPERATION != (Controller::SHAPE_TEXT & operations))
   {
     const Vector<Character>& textToShape = textMirrored ? mirroredUtf32Characters : utf32Characters;
@@ -350,6 +376,13 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
     updated = true;
   }
 
+#if defined(TRACE_ENABLED)
+  if(logEnabled)
+  {
+    timeStamps[timeStampIndex++] = GetMilliSeconds();
+  }
+#endif
+
   const Length numberOfGlyphs = static_cast<Length>(glyphs.Count()) - currentNumberOfGlyphs;
 
   if(Controller::NO_OPERATION != (Controller::GET_GLYPH_METRICS & operations))
@@ -370,6 +403,13 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
     updated = true;
   }
 
+#if defined(TRACE_ENABLED)
+  if(logEnabled)
+  {
+    timeStamps[timeStampIndex++] = GetMilliSeconds();
+  }
+#endif
+
   if((nullptr != impl.mEventData) &&
      impl.mEventData->mPreEditFlag &&
      (0u != impl.mModel->mVisualModel->mCharactersToGlyph.Count()))
@@ -564,6 +604,13 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
     updated = true;
   }
 
+#if defined(TRACE_ENABLED)
+  if(logEnabled)
+  {
+    timeStamps[timeStampIndex++] = GetMilliSeconds();
+  }
+#endif
+
   if(Controller::NO_OPERATION != (Controller::COLOR & operations))
   {
     // Set the color runs in glyphs.
@@ -589,6 +636,13 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
     updated = true;
   }
 
+#if defined(TRACE_ENABLED)
+  if(logEnabled)
+  {
+    timeStamps[timeStampIndex++] = GetMilliSeconds();
+  }
+#endif
+
   if((Controller::NO_OPERATION != (Controller::SHAPE_TEXT & operations)) &&
      !((nullptr != impl.mEventData) &&
        impl.mEventData->mPreEditFlag &&
@@ -608,6 +662,26 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
     updated = true;
   }
 
+#if defined(TRACE_ENABLED)
+  if(logEnabled)
+  {
+    timeStamps[timeStampIndex++] = GetMilliSeconds();
+    uint32_t timeShape   = timeStamps[1] - timeStamps[0];
+    uint32_t timeGlyph   = timeStamps[2] - timeStamps[1];
+    uint32_t timePreedit = timeStamps[3] - timeStamps[2];
+    uint32_t timeColor   = timeStamps[4] - timeStamps[3];
+    uint32_t timeCopy    = timeStamps[5] - timeStamps[4];
+
+    if(timeStamps[5] - timeStamps[0] > logThreshold)
+    {
+      std::string currentText;
+      Utf32ToUtf8(impl.mModel->mLogicalModel->mText.Begin(), numberOfCharacters, currentText);
+      DALI_LOG_DEBUG_INFO("DALI_TEXT_MODEL_UPDATE shape:%u ms, glyph:%u ms, preedit:%u ms, color:%u ms, copy:%u ms\n", timeShape, timeGlyph, timePreedit, timeColor, timeCopy);
+      DALI_LOG_DEBUG_INFO("DALI_TEXT_MODEL_UPDATE chars:%d, text:%s\n", numberOfCharacters, currentText.c_str());
+    }
+  }
+#endif
+
   // The estimated number of lines. Used to avoid reallocations when layouting.
   impl.mTextUpdateInfo.mEstimatedNumberOfLines = std::max(impl.mModel->mVisualModel->mLines.Count(), impl.mModel->mLogicalModel->mParagraphInfo.Count());