From: Bowon Ryu Date: Thu, 3 Aug 2023 05:50:05 +0000 (+0900) Subject: Add trace log to check performance of text update X-Git-Tag: dali_2.2.39~4^2 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;ds=sidebyside;h=59e4ac91653eb44d4d6f88d49bafab0166c3853b;p=platform%2Fcore%2Fuifw%2Fdali-toolkit.git Add trace log to check performance of text update Change-Id: I054f862085208b58f9a5137abccc8f9a1465513c Signed-off-by: Bowon Ryu --- 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 --- 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(epoch); + + return static_cast(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& 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(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()); diff --git a/dali-toolkit/internal/text/shaper.cpp b/dali-toolkit/internal/text/shaper.cpp index 9d9fc1b..5fbabd4 100644 --- a/dali-toolkit/internal/text/shaper.cpp +++ b/dali-toolkit/internal/text/shaper.cpp @@ -19,7 +19,11 @@ #include // EXTERNAL INCLUDES +#include +#include #include +#include +#include namespace Dali { @@ -27,12 +31,26 @@ namespace Toolkit { namespace Text { +DALI_INIT_TRACE_FILTER(gTraceFilter, DALI_TRACE_TEXT_PERFORMANCE_MARKER, false); + CharacterIndex min(CharacterIndex index0, CharacterIndex index1) { return (index0 < index1) ? index0 : index1; } +#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(epoch); + + return static_cast(duration.count()); +} +#endif + void ShapeText(const Vector& text, const Vector& lineBreakInfo, const Vector& scripts, @@ -51,6 +69,15 @@ void ShapeText(const Vector& text, return; } + DALI_TRACE_SCOPE(gTraceFilter, "DALI_TEXT_SHAPE_TEXT"); + +#if defined(TRACE_ENABLED) + uint32_t sumPre = 0, sumShape = 0, sumPost = 0; + + uint32_t logThreshold = TextAbstraction::FontClient::GetPerformanceLogThresholdTime(); + bool logEnabled = TextAbstraction::FontClient::IsPerformanceLogEnabled(); +#endif + #ifdef DEBUG_ENABLED const Length numberOfFontRuns = fonts.Count(); const Length numberOfScriptRuns = scripts.Count(); @@ -132,6 +159,16 @@ void ShapeText(const Vector& text, const CharacterIndex lastCharacter = startCharacterIndex + numberOfCharacters; for(previousIndex = startCharacterIndex; previousIndex < lastCharacter;) { +#if defined(TRACE_ENABLED) + uint32_t timeStamps[4]; + uint32_t timeStampIndex = 0; + + if(logEnabled) + { + timeStamps[timeStampIndex++] = GetMilliSeconds(); + } +#endif + // Get the font id and the script. const FontRun& fontRun = *fontRunIt; const ScriptRun& scriptRun = *scriptRunIt; @@ -164,12 +201,26 @@ void ShapeText(const Vector& text, } } +#if defined(TRACE_ENABLED) + if(logEnabled) + { + timeStamps[timeStampIndex++] = GetMilliSeconds(); + } +#endif + // Shape the text for the current chunk. const Length numberOfGlyphs = shaping.Shape(textBuffer + previousIndex, (currentIndex - previousIndex), // The number of characters to shape. currentFontId, currentScript); +#if defined(TRACE_ENABLED) + if(logEnabled) + { + timeStamps[timeStampIndex++] = GetMilliSeconds(); + } +#endif + // Retrieve the glyphs and the glyph to character conversion map. Vector tmpGlyphs; Vector tmpGlyphToCharacterMap; @@ -224,6 +275,16 @@ void ShapeText(const Vector& text, // Update the previous index. previousIndex = currentIndex; + +#if defined(TRACE_ENABLED) + if(logEnabled) + { + timeStamps[timeStampIndex++] = GetMilliSeconds(); + sumPre += timeStamps[1] - timeStamps[0]; + sumShape += timeStamps[2] - timeStamps[1]; + sumPost += timeStamps[3] - timeStamps[2]; + } +#endif } // Update indices. @@ -252,6 +313,16 @@ void ShapeText(const Vector& text, // Resize the vectors to set the right number of items. glyphs.Resize(totalNumberOfGlyphs); glyphToCharacterMap.Resize(totalNumberOfGlyphs); + +#if defined(TRACE_ENABLED) + if(logEnabled) + { + if(sumPre + sumShape + sumPost > logThreshold) + { + DALI_LOG_DEBUG_INFO("DALI_TEXT_SHAPE_TEXT updated:%u/%u, pre:%u ms, shape:%u ms, post:%u ms\n", numberOfNewGlyphs, totalNumberOfGlyphs, sumPre, sumShape, sumPost); + } + } +#endif } } // namespace Text