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
index b764eb5..ab005b1 100644 (file)
@@ -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;
@@ -99,32 +111,39 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
   impl.CalculateTextUpdateIndices(paragraphCharacters);
 
   // Check whether the indices for updating the text is valid
-  if(numberOfCharacters > 0u &&
-     (impl.mTextUpdateInfo.mParagraphCharacterIndex > numberOfCharacters ||
-      impl.mTextUpdateInfo.mRequestedNumberOfCharacters > numberOfCharacters))
+  if(impl.mTextUpdateInfo.mParagraphCharacterIndex > numberOfCharacters ||
+     impl.mTextUpdateInfo.mRequestedNumberOfCharacters > numberOfCharacters)
   {
-    std::string currentText;
-    Utf32ToUtf8(impl.mModel->mLogicalModel->mText.Begin(), numberOfCharacters, currentText);
-
-    DALI_LOG_ERROR("Controller::Impl::UpdateModel: mTextUpdateInfo has invalid indices\n");
-    DALI_LOG_ERROR("Number of characters: %d, current text is: %s\n", numberOfCharacters, currentText.c_str());
-
-    // Dump mTextUpdateInfo
-    DALI_LOG_ERROR("Dump mTextUpdateInfo:\n");
-    DALI_LOG_ERROR("     mTextUpdateInfo.mCharacterIndex = %u\n", impl.mTextUpdateInfo.mCharacterIndex);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mNumberOfCharactersToRemove = %u\n", impl.mTextUpdateInfo.mNumberOfCharactersToRemove);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mNumberOfCharactersToAdd = %u\n", impl.mTextUpdateInfo.mNumberOfCharactersToAdd);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mPreviousNumberOfCharacters = %u\n", impl.mTextUpdateInfo.mPreviousNumberOfCharacters);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mParagraphCharacterIndex = %u\n", impl.mTextUpdateInfo.mParagraphCharacterIndex);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mRequestedNumberOfCharacters = %u\n", impl.mTextUpdateInfo.mRequestedNumberOfCharacters);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mStartGlyphIndex = %u\n", impl.mTextUpdateInfo.mStartGlyphIndex);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mStartLineIndex = %u\n", impl.mTextUpdateInfo.mStartLineIndex);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mEstimatedNumberOfLines = %u\n", impl.mTextUpdateInfo.mEstimatedNumberOfLines);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mClearAll = %d\n", impl.mTextUpdateInfo.mClearAll);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mFullRelayoutNeeded = %d\n", impl.mTextUpdateInfo.mFullRelayoutNeeded);
-    DALI_LOG_ERROR("     mTextUpdateInfo.mIsLastCharacterNewParagraph = %d\n", impl.mTextUpdateInfo.mIsLastCharacterNewParagraph);
-
-    return false;
+    if(numberOfCharacters == 0u)
+    {
+      impl.mTextUpdateInfo.Clear();
+      impl.mTextUpdateInfo.mClearAll = true;
+    }
+    else // numberOfCharacters > 0u
+    {
+      std::string currentText;
+      Utf32ToUtf8(impl.mModel->mLogicalModel->mText.Begin(), numberOfCharacters, currentText);
+
+      DALI_LOG_ERROR("Controller::Impl::UpdateModel: mTextUpdateInfo has invalid indices\n");
+      DALI_LOG_ERROR("Number of characters: %d, current text is: %s paragraphCharacters: %d\n", numberOfCharacters, currentText.c_str(), paragraphCharacters);
+
+      // Dump mTextUpdateInfo
+      DALI_LOG_ERROR("Dump mTextUpdateInfo:\n");
+      DALI_LOG_ERROR("     mTextUpdateInfo.mCharacterIndex = %u\n", impl.mTextUpdateInfo.mCharacterIndex);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mNumberOfCharactersToRemove = %u\n", impl.mTextUpdateInfo.mNumberOfCharactersToRemove);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mNumberOfCharactersToAdd = %u\n", impl.mTextUpdateInfo.mNumberOfCharactersToAdd);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mPreviousNumberOfCharacters = %u\n", impl.mTextUpdateInfo.mPreviousNumberOfCharacters);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mParagraphCharacterIndex = %u\n", impl.mTextUpdateInfo.mParagraphCharacterIndex);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mRequestedNumberOfCharacters = %u\n", impl.mTextUpdateInfo.mRequestedNumberOfCharacters);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mStartGlyphIndex = %u\n", impl.mTextUpdateInfo.mStartGlyphIndex);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mStartLineIndex = %u\n", impl.mTextUpdateInfo.mStartLineIndex);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mEstimatedNumberOfLines = %u\n", impl.mTextUpdateInfo.mEstimatedNumberOfLines);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mClearAll = %d\n", impl.mTextUpdateInfo.mClearAll);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mFullRelayoutNeeded = %d\n", impl.mTextUpdateInfo.mFullRelayoutNeeded);
+      DALI_LOG_ERROR("     mTextUpdateInfo.mIsLastCharacterNewParagraph = %d\n", impl.mTextUpdateInfo.mIsLastCharacterNewParagraph);
+
+      return false;
+    }
   }
 
   startIndex = impl.mTextUpdateInfo.mParagraphCharacterIndex;
@@ -259,6 +278,7 @@ bool ControllerImplModelUpdater::Update(Controller::Impl& impl, OperationsMask o
                                          fontDescriptionRuns,
                                          defaultFontDescription,
                                          defaultPointSize,
+                                         impl.GetFontSizeScale(),
                                          startIndex,
                                          requestedNumberOfCharacters,
                                          validFonts);
@@ -319,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;
@@ -342,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))
@@ -362,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()))
@@ -556,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.
@@ -581,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 &&
@@ -600,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());