From: Eunki, Hong Date: Mon, 19 Feb 2024 13:31:11 +0000 (+0900) Subject: [Tizen] Print image process duration when we trace it X-Git-Tag: accepted/tizen/8.0/unified/20240220.144353^0 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=2cdfb89b8d1d513af65ec3b1bf35bfc60eae5fee;p=platform%2Fcore%2Fuifw%2Fdali-toolkit.git [Tizen] Print image process duration when we trace it Change-Id: Ic9dba03a2f18743ea253ccf9e1234bd1bda78239 Signed-off-by: Eunki, Hong --- diff --git a/dali-toolkit/internal/image-loader/fast-track-loading-task.cpp b/dali-toolkit/internal/image-loader/fast-track-loading-task.cpp index e65ca57..1845ff7 100644 --- a/dali-toolkit/internal/image-loader/fast-track-loading-task.cpp +++ b/dali-toolkit/internal/image-loader/fast-track-loading-task.cpp @@ -27,7 +27,10 @@ #include #ifdef TRACE_ENABLED +#include +#include #include +#include #endif namespace Dali @@ -40,6 +43,16 @@ namespace { DALI_INIT_TRACE_FILTER(gTraceFilter, DALI_TRACE_IMAGE_PERFORMANCE_MARKER, false); +#ifdef TRACE_ENABLED +uint64_t GetNanoseconds() +{ + // 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 + constexpr uint32_t CHROMINANCE_U_INDEX = 1u; constexpr uint32_t CHROMINANCE_V_INDEX = 2u; @@ -146,8 +159,11 @@ bool FastTrackLoadingTask::IsReady() void FastTrackLoadingTask::Load() { #ifdef TRACE_ENABLED + uint64_t mStartTimeNanoSceonds = 0; + uint64_t mEndTimeNanoSceonds = 0; if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mStartTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; oss << "[u:" << mUrl.GetEllipsedUrl() << "]"; // DALI_TRACE_BEGIN(gTraceFilter, "DALI_IMAGE_FAST_TRACK_UPLOADING_TASK"); ///< TODO : Open it if we can control trace log level @@ -219,8 +235,11 @@ void FastTrackLoadingTask::Load() #ifdef TRACE_ENABLED if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mEndTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; + oss << std::fixed << std::setprecision(3); oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; oss << "b:" << pixelBuffers.size() << " "; if(!mPixelData.empty()) { diff --git a/dali-toolkit/internal/image-loader/loading-task.cpp b/dali-toolkit/internal/image-loader/loading-task.cpp index 4471344..5cbd16b 100644 --- a/dali-toolkit/internal/image-loader/loading-task.cpp +++ b/dali-toolkit/internal/image-loader/loading-task.cpp @@ -27,7 +27,10 @@ #include #ifdef TRACE_ENABLED +#include +#include #include +#include #endif namespace Dali @@ -39,7 +42,17 @@ namespace Internal namespace { DALI_INIT_TRACE_FILTER(gTraceFilter, DALI_TRACE_IMAGE_PERFORMANCE_MARKER, false); + +#ifdef TRACE_ENABLED +uint64_t GetNanoseconds() +{ + // 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 +} // namespace LoadingTask::LoadingTask(uint32_t id, Dali::AnimatedImageLoading animatedImageLoading, uint32_t frameIndex, DevelAsyncImageLoader::PreMultiplyOnLoad preMultiplyOnLoad, CallbackBase* callback) : AsyncTask(callback), @@ -159,8 +172,11 @@ LoadingTask::~LoadingTask() void LoadingTask::Process() { #ifdef TRACE_ENABLED + uint64_t mStartTimeNanoSceonds = 0; + uint64_t mEndTimeNanoSceonds = 0; if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mStartTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; oss << "[u:" << (!!(animatedImageLoading) ? animatedImageLoading.GetUrl() : url.GetEllipsedUrl()) << "]"; // DALI_TRACE_BEGIN(gTraceFilter, "DALI_IMAGE_LOADING_TASK"); ///< TODO : Open it if we can control trace log level @@ -183,8 +199,11 @@ void LoadingTask::Process() #ifdef TRACE_ENABLED if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mEndTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; + oss << std::fixed << std::setprecision(3); oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; oss << "m:" << isMaskTask << " "; oss << "i:" << frameIndex << " "; oss << "b:" << pixelBuffers.size() << " "; diff --git a/dali-toolkit/internal/visuals/animated-vector-image/vector-animation-task.cpp b/dali-toolkit/internal/visuals/animated-vector-image/vector-animation-task.cpp index a41dba0..f06effd 100644 --- a/dali-toolkit/internal/visuals/animated-vector-image/vector-animation-task.cpp +++ b/dali-toolkit/internal/visuals/animated-vector-image/vector-animation-task.cpp @@ -31,7 +31,10 @@ #include #ifdef TRACE_ENABLED +#include +#include #include +#include #endif namespace Dali @@ -51,6 +54,16 @@ Debug::Filter* gVectorAnimationLogFilter = Debug::Filter::New(Debug::NoLogging, DALI_INIT_TRACE_FILTER(gTraceFilter, DALI_TRACE_IMAGE_PERFORMANCE_MARKER, false); +#ifdef TRACE_ENABLED +uint64_t GetNanoseconds() +{ + // 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 + } // unnamed namespace VectorAnimationTask::VectorAnimationTask(VisualFactoryCache& factoryCache) @@ -152,8 +165,11 @@ bool VectorAnimationTask::IsAnimating() bool VectorAnimationTask::Load(bool synchronousLoading) { #ifdef TRACE_ENABLED + uint64_t mStartTimeNanoSceonds = 0; + uint64_t mEndTimeNanoSceonds = 0; if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mStartTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; oss << "[u:" << mImageUrl.GetEllipsedUrl() << "]"; // DALI_TRACE_BEGIN(gTraceFilter, "DALI_LOTTIE_LOADING_TASK"); ///< TODO : Open it if we can control trace log level @@ -202,8 +218,12 @@ bool VectorAnimationTask::Load(bool synchronousLoading) #ifdef TRACE_ENABLED if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mEndTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; - oss << "[u:" << mImageUrl.GetEllipsedUrl() << "]"; + oss << std::fixed << std::setprecision(3); + oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; + oss << "u:" << mImageUrl.GetEllipsedUrl() << "]"; // DALI_TRACE_END(gTraceFilter, "DALI_LOTTIE_LOADING_TASK"); ///< TODO : Open it if we can control trace log level DALI_LOG_RELEASE_INFO("END: DALI_LOTTIE_LOADING_TASK %s", oss.str().c_str()); } @@ -232,8 +252,12 @@ bool VectorAnimationTask::Load(bool synchronousLoading) #ifdef TRACE_ENABLED if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mEndTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; - oss << "[u:" << mImageUrl.GetEllipsedUrl() << "]"; + oss << std::fixed << std::setprecision(3); + oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; + oss << "u:" << mImageUrl.GetEllipsedUrl() << "]"; // DALI_TRACE_END(gTraceFilter, "DALI_LOTTIE_LOADING_TASK"); ///< TODO : Open it if we can control trace log level DALI_LOG_RELEASE_INFO("END: DALI_LOTTIE_LOADING_TASK %s", oss.str().c_str()); } @@ -574,7 +598,12 @@ bool VectorAnimationTask::Rasterize() return false; } +#ifdef TRACE_ENABLED + uint64_t mStartTimeNanoSceonds = 0; + uint64_t mEndTimeNanoSceonds = 0; +#endif DALI_TRACE_BEGIN_WITH_MESSAGE_GENERATOR(gTraceFilter, "DALI_LOTTIE_RASTERIZE_TASK", [&](std::ostringstream& oss) { + mStartTimeNanoSceonds = GetNanoseconds(); oss << "[s:" << mWidth << "x" << mHeight << " "; oss << "u:" << mImageUrl.GetEllipsedUrl() << "]"; }); @@ -687,7 +716,11 @@ bool VectorAnimationTask::Rasterize() } DALI_TRACE_END_WITH_MESSAGE_GENERATOR(gTraceFilter, "DALI_LOTTIE_RASTERIZE_TASK", [&](std::ostringstream& oss) { - oss << "[s:" << mWidth << "x" << mHeight << " "; + mEndTimeNanoSceonds = GetNanoseconds(); + oss << std::fixed << std::setprecision(3); + oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; + oss << "s:" << mWidth << "x" << mHeight << " "; oss << "f:" << mCurrentFrame << " "; oss << "l:" << mCurrentLoop << " "; oss << "p:" << mPlayState << " "; diff --git a/dali-toolkit/internal/visuals/svg/svg-task.cpp b/dali-toolkit/internal/visuals/svg/svg-task.cpp index 35c0028..0a4ff89 100644 --- a/dali-toolkit/internal/visuals/svg/svg-task.cpp +++ b/dali-toolkit/internal/visuals/svg/svg-task.cpp @@ -28,7 +28,10 @@ #include #ifdef TRACE_ENABLED +#include +#include #include +#include #endif namespace Dali @@ -40,7 +43,17 @@ namespace Internal namespace { DALI_INIT_TRACE_FILTER(gTraceFilter, DALI_TRACE_IMAGE_PERFORMANCE_MARKER, false); + +#ifdef TRACE_ENABLED +uint64_t GetNanoseconds() +{ + // 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 +} // namespace SvgTask::SvgTask(VectorImageRenderer vectorRenderer, CallbackBase* callback, AsyncTask::PriorityType priorityType) : AsyncTask(callback, priorityType), @@ -86,8 +99,11 @@ void SvgLoadingTask::Process() } #ifdef TRACE_ENABLED + uint64_t mStartTimeNanoSceonds = 0; + uint64_t mEndTimeNanoSceonds = 0; if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mStartTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; oss << "[u:" << mImageUrl.GetEllipsedUrl() << "]"; // DALI_TRACE_BEGIN(gTraceFilter, "DALI_SVG_LOADING_TASK"); ///< TODO : Open it if we can control trace log level @@ -141,8 +157,12 @@ void SvgLoadingTask::Process() #ifdef TRACE_ENABLED if(gTraceFilter && gTraceFilter->IsTraceEnabled()) { + mEndTimeNanoSceonds = GetNanoseconds(); std::ostringstream oss; - oss << "[s:" << mHasSucceeded << " "; + oss << std::fixed << std::setprecision(3); + oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; + oss << "s:" << mHasSucceeded << " "; oss << "u:" << mImageUrl.GetEllipsedUrl() << "]"; // DALI_TRACE_END(gTraceFilter, "DALI_SVG_LOADING_TASK"); ///< TODO : Open it if we can control trace log level DALI_LOG_RELEASE_INFO("END: DALI_SVG_LOADING_TASK %s", oss.str().c_str()); @@ -174,7 +194,12 @@ void SvgRasterizingTask::Process() return; } +#ifdef TRACE_ENABLED + uint64_t mStartTimeNanoSceonds = 0; + uint64_t mEndTimeNanoSceonds = 0; +#endif DALI_TRACE_BEGIN_WITH_MESSAGE_GENERATOR(gTraceFilter, "DALI_SVG_RASTERIZE_TASK", [&](std::ostringstream& oss) { + mStartTimeNanoSceonds = GetNanoseconds(); oss << "[s:" << mWidth << "x" << mHeight << " "; oss << "u:" << mImageUrl.GetEllipsedUrl() << "]"; }); @@ -194,7 +219,11 @@ void SvgRasterizingTask::Process() mHasSucceeded = true; DALI_TRACE_END_WITH_MESSAGE_GENERATOR(gTraceFilter, "DALI_SVG_RASTERIZE_TASK", [&](std::ostringstream& oss) { - oss << "[s:" << mWidth << "x" << mHeight << " "; + mEndTimeNanoSceonds = GetNanoseconds(); + oss << std::fixed << std::setprecision(3); + oss << "["; + oss << "d:" << static_cast(mEndTimeNanoSceonds - mStartTimeNanoSceonds) / 1000000.0f << "ms "; + oss << "s:" << mWidth << "x" << mHeight << " "; oss << "u:" << mImageUrl.GetEllipsedUrl() << "]"; }); }