Nanotrace: Add asynchronous trace points

With asynchronous traces you can follow complex tasks.

Change-Id: Ia0fd20f34f3529c59eff5d222c8d87ac5dacd514
Reviewed-by: Tim Jenssen <tim.jenssen@qt.io>

src/libs/nanotrace/nanotracehr.cpp

@@ -4,13 +4,17 @@
 #include "nanotracehr.h"
 
 #include <QCoreApplication>
+#include <QThread>
 
 #include <fstream>
 #include <iomanip>
-#include <iostream>
 #include <limits>
 #include <thread>
 
+#ifdef Q_OS_UNIX
+#  include <pthread.h>
+#endif
+
 namespace NanotraceHR {
 
 namespace {
@@ -18,11 +22,50 @@ namespace {
 template<typename TraceEvent>
 void printEvent(std::ostream &out, const TraceEvent &event, qint64 processId, std::thread::id threadId)
 {
-    out << R"({"ph":"X","name":")" << event.name << R"(","cat":")" << event.category
-        << R"(","ts":")" << static_cast<double>(event.start.time_since_epoch().count()) / 1000
-        << R"(","dur":")" << static_cast<double>(event.duration.count()) / 1000 << R"(","pid":")"
-        << processId << R"(","tid":")" << threadId << R"(","args":)" << event.arguments << "}";
+    out << R"({"ph":")" << event.type << R"(","name":")" << event.name << R"(","cat":")"
+        << event.category << R"(","ts":")"
+        << static_cast<double>(event.time.time_since_epoch().count()) / 1000 << R"(","pid":")"
+        << processId << R"(","tid":")" << threadId << R"(")";
+
+    if (event.type == 'X')
+        out << R"(,"dur":)" << static_cast<double>(event.duration.count()) / 1000;
+
+    if (event.id != 0)
+        out << R"(,"id":)" << event.id;
+
+    if (event.arguments.size())
+        out << R"(,"args":)" << event.arguments;
+
+    out << "}";
 }
+
+void writeMetaEvent(TraceFile<true> *file, std::string_view key, std::string_view value)
+{
+    std::lock_guard lock{file->fileMutex};
+    auto &out = file->out;
+
+    if (out.is_open()) {
+        file->out << R"({"name":")" << key << R"(","ph":"M", "pid":")"
+                  << QCoreApplication::applicationPid() << R"(","tid":")"
+                  << std::this_thread::get_id() << R"(","args":{"name":")" << value << R"("}})"
+                  << ",\n";
+    }
+}
+
+std::string getThreadName()
+{
+    std::array<char, 200> buffer;
+    buffer[0] = 0;
+#ifdef Q_OS_UNIX
+    auto rc = pthread_getname_np(pthread_self(), buffer.data(), buffer.size());
+    if (rc != 0)
+        return {};
+
+#endif
+
+    return buffer.data();
+}
+
 } // namespace
 
 template<typename TraceEvent>
@@ -42,7 +85,6 @@ void flushEvents(const Utils::span<TraceEvent> events,
             printEvent(out, event, processId, threadId);
             out << ",\n";
         }
-        out << std::flush;
     }
 }
 
@@ -57,8 +99,12 @@ void openFile(EnabledTraceFile &file)
 {
     std::lock_guard lock{file.fileMutex};
 
-    if (file.out = std::ofstream{file.filePath, std::ios::trunc}; file.out.good())
+    if (file.out = std::ofstream{file.filePath, std::ios::trunc}; file.out.good()) {
         file.out << std::fixed << std::setprecision(3) << R"({"traceEvents": [)";
+        file.out << R"({"name":"process_name","ph":"M", "pid":)"
+                 << QCoreApplication::applicationPid() << R"(,"args":{"name":"QtCreator"}})"
+                 << ",\n";
+    }
 }
 
 void finalizeFile(EnabledTraceFile &file)
@@ -109,4 +155,45 @@ EnabledEventQueue<StringTraceEvent> &globalEventQueue()
     return s_globalEventQueue;
 }
 
+template<typename TraceEvent>
+EventQueue<TraceEvent, std::true_type>::EventQueue(EnabledTraceFile *file,
+                                                   TraceEventsSpan eventsOne,
+                                                   TraceEventsSpan eventsTwo)
+    : file{file}
+    , eventsOne{eventsOne}
+    , eventsTwo{eventsTwo}
+    , currentEvents{eventsOne}
+{
+    if (auto thread = QThread::currentThread()) {
+        connection = QObject::connect(QCoreApplication::instance(),
+                                      &QCoreApplication::aboutToQuit,
+                                      thread,
+                                      [&] { flush(); });
+        auto name = getThreadName();
+        if (name.size()) {
+            writeMetaEvent(file, "thread_name", name);
+        }
+    }
+}
+
+template<typename TraceEvent>
+EventQueue<TraceEvent, std::true_type>::~EventQueue()
+{
+    flush();
+    if (connection)
+        QObject::disconnect(connection);
+}
+
+template<typename TraceEvent>
+void EventQueue<TraceEvent, std::true_type>::flush()
+{
+    std::lock_guard lock{mutex};
+    if (isEnabled == IsEnabled::Yes && eventsIndex > 0) {
+        flushEvents(currentEvents.subspan(0, eventsIndex), std::this_thread::get_id(), *this);
+        eventsIndex = 0;
+    }
+}
+
+template class NANOTRACE_EXPORT EventQueue<StringViewTraceEvent, std::true_type>;
+template class NANOTRACE_EXPORT EventQueue<StringTraceEvent, std::true_type>;
 } // namespace NanotraceHR

src/libs/nanotrace/nanotracehr.h

@@ -7,7 +7,10 @@
 
 #include <utils/span.h>
 
+#include <QMetaObject>
+
 #include <array>
+#include <atomic>
 #include <chrono>
 #include <fstream>
 #include <future>
@@ -33,15 +36,34 @@ constexpr bool isTracerActive()
 #endif
 }
 
-template<std::size_t size>
-std::string_view toStringView(Utils::span<const char, size> string)
+namespace Literals {
+struct TracerLiteral
 {
-    return {string.data(), string.size()};
-}
+    friend constexpr TracerLiteral operator""_t(const char *text, size_t size);
 
+    constexpr operator std::string_view() const { return text; }
+
+private:
+    constexpr TracerLiteral(std::string_view text)
+        : text{text}
+    {}
+
+    std::string_view text;
+};
+
+constexpr TracerLiteral operator""_t(const char *text, size_t size)
+{
+    return {std::string_view{text, size}};
+}
+} // namespace Literals
+
+using namespace Literals;
 template<typename String>
 struct TraceEvent
 {
+    using StringType = String;
+    using ArgumentType = std::conditional_t<std::is_same_v<String, std::string_view>, TracerLiteral, String>;
+
     TraceEvent() = default;
     TraceEvent(const TraceEvent &) = delete;
     TraceEvent(TraceEvent &&) = delete;
@@ -52,8 +74,10 @@ struct TraceEvent
     String name;
     String category;
     String arguments;
-    TimePoint start;
+    TimePoint time;
     Duration duration;
+    std::size_t id = 0;
+    char type = ' ';
 };
 
 using StringViewTraceEvent = TraceEvent<std::string_view>;
@@ -126,7 +150,10 @@ public:
 
 template<typename TraceEvent, typename Enabled>
 class EventQueue
-{};
+{
+public:
+    using IsActive = std::false_type;
+};
 
 template<typename TraceEvent>
 class EventQueue<TraceEvent, std::true_type>
@@ -134,15 +161,13 @@ class EventQueue<TraceEvent, std::true_type>
     using TraceEventsSpan = Utils::span<TraceEvent>;
 
 public:
-    EventQueue() = default;
+    using IsActive = std::true_type;
 
-    ~EventQueue()
-    {
-        if (isEnabled == IsEnabled::Yes && eventsIndex > 0) {
-            flushEvents(currentEvents.subspan(0, eventsIndex), std::this_thread::get_id(), *this);
-            eventsIndex = 0;
-        }
-    }
+    EventQueue(EnabledTraceFile *file, TraceEventsSpan eventsOne, TraceEventsSpan eventsTwo);
+
+    ~EventQueue();
+
+    void flush();
 
     EventQueue(const EventQueue &) = delete;
     EventQueue(EventQueue &&) = delete;
@@ -154,14 +179,17 @@ public:
     TraceEventsSpan eventsTwo;
     TraceEventsSpan currentEvents;
     std::size_t eventsIndex = 0;
-    IsEnabled isEnabled = IsEnabled::No;
+    IsEnabled isEnabled = IsEnabled::Yes;
+    QMetaObject::Connection connection;
+    std::mutex mutex;
 };
 
+extern template class NANOTRACE_EXPORT EventQueue<StringViewTraceEvent, std::true_type>;
+extern template class NANOTRACE_EXPORT EventQueue<StringTraceEvent, std::true_type>;
+
 template<typename TraceEvent, std::size_t eventCount, typename Enabled>
 class EventQueueData
 {
-    using TraceEvents = std::array<TraceEvent, eventCount>;
-
 public:
     using IsActive = Enabled;
 
@@ -197,7 +225,7 @@ struct EventQueueDataPointer<TraceEvent, eventCount, std::true_type>
     EnabledEventQueue<TraceEvent> createEventQueue() const
     {
         if constexpr (isTracerActive()) {
-            return {&data->file, data->eventsOne, data->eventsTwo, data->eventsOne, 0, IsEnabled::Yes};
+            return {&data->file, data->eventsOne, data->eventsTwo};
         } else {
             return {};
         }
@@ -229,38 +257,63 @@ TraceEvent &getTraceEvent(EnabledEventQueue<TraceEvent> &eventQueue)
     return eventQueue.currentEvents[eventQueue.eventsIndex++];
 }
 
-namespace Literals {
-struct TracerLiteral
+template<bool enabled>
+class Token
 {
-    friend constexpr TracerLiteral operator""_t(const char *text, size_t size);
+public:
+    using IsActive = std::false_type;
 
-    constexpr operator std::string_view() const { return text; }
+    constexpr std::size_t operator*() const { return 0; }
 
-private:
-    constexpr TracerLiteral(std::string_view text)
-        : text{text}
-    {}
+    constexpr explicit operator bool() const { return false; }
 
-    std::string_view text;
+    static constexpr bool isActive() { return false; }
 };
 
-constexpr TracerLiteral operator""_t(const char *text, size_t size)
-{
-    return {std::string_view{text, size}};
-}
-} // namespace Literals
+template<typename TraceEvent, bool enabled>
+class Category;
 
-using namespace Literals;
+template<>
+class Token<true>
+{
+    friend Category<StringViewTraceEvent, true>;
+    friend Category<StringTraceEvent, true>;
+
+    Token(std::size_t id)
+        : m_id{id}
+    {}
+
+public:
+    using IsActive = std::true_type;
+
+    constexpr std::size_t operator*() const { return m_id; }
+
+    constexpr explicit operator bool() const { return m_id; }
+
+    static constexpr bool isActive() { return true; }
+
+private:
+    std::size_t m_id;
+};
 
 template<typename TraceEvent, bool enabled>
 class Category
 {
 public:
     using IsActive = std::false_type;
+    using ArgumentType = typename TraceEvent::ArgumentType;
 
-    Category(TracerLiteral, EventQueue<TraceEvent, std::true_type> &) {}
+    Category(ArgumentType, EventQueue<TraceEvent, std::true_type> &) {}
 
-    Category(TracerLiteral, EventQueue<TraceEvent, std::false_type> &) {}
+    Category(ArgumentType, EventQueue<TraceEvent, std::false_type> &) {}
+
+    Token<false> beginAsynchronous(ArgumentType) { return {}; }
+
+    void tickAsynchronous(Token<false>, ArgumentType) {}
+
+    void endAsynchronous(Token<false>, ArgumentType) {}
+
+    static constexpr bool isActive() { return false; }
 };
 
 template<typename TraceEvent>
@@ -268,8 +321,67 @@ class Category<TraceEvent, true>
 {
 public:
     using IsActive = std::true_type;
-    TracerLiteral name;
-    EnabledEventQueue<TraceEvent> &eventQueue;
+    using ArgumentType = typename TraceEvent::ArgumentType;
+    using StringType = typename TraceEvent::StringType;
+
+    template<typename EventQueue>
+    Category(ArgumentType name, EventQueue &queue)
+        : m_name{std::move(name)}
+        , m_eventQueue{queue}
+    {
+        static_assert(std::is_same_v<typename EventQueue::IsActive, std::true_type>,
+                      "A active category is not possible with an inactive event queue!");
+    }
+
+    Token<true> beginAsynchronous(ArgumentType traceName)
+    {
+        auto id = ++idCounter;
+        auto &traceEvent = getTraceEvent(m_eventQueue);
+        traceEvent.name = std::move(traceName);
+        traceEvent.category = m_name;
+        traceEvent.time = Clock::now();
+        traceEvent.type = 'b';
+        traceEvent.id = id;
+
+        return id;
+    }
+
+    void tickAsynchronous(Token<true> token, ArgumentType traceName)
+    {
+        if (!token)
+            return;
+
+        auto &traceEvent = getTraceEvent(m_eventQueue);
+        traceEvent.name = std::move(traceName);
+        traceEvent.category = m_name;
+        traceEvent.time = Clock::now();
+        traceEvent.type = 'n';
+        traceEvent.id = *token;
+    }
+
+    void endAsynchronous(Token<true> token, ArgumentType traceName)
+    {
+        if (!token)
+            return;
+
+        auto &traceEvent = getTraceEvent(m_eventQueue);
+        traceEvent.name = std::move(traceName);
+        traceEvent.category = m_name;
+        traceEvent.time = Clock::now();
+        traceEvent.type = 'e';
+        traceEvent.id = *token;
+    }
+
+    EnabledEventQueue<TraceEvent> &eventQueue() const { return m_eventQueue; }
+
+    std::string_view name() const { return m_name; }
+
+    static constexpr bool isActive() { return true; }
+
+private:
+    StringType m_name;
+    EnabledEventQueue<TraceEvent> &m_eventQueue;
+    inline static std::atomic<std::size_t> idCounter = 0;
 };
 
 template<bool enabled>
@@ -277,18 +389,15 @@ using StringViewCategory = Category<StringViewTraceEvent, enabled>;
 template<bool enabled>
 using StringCategory = Category<StringTraceEvent, enabled>;
 
-class DisabledCategory
-{
-    using IsActive = std::false_type;
-};
-
 template<typename Category>
 class Tracer
 {
 public:
-    constexpr Tracer(TracerLiteral, Category &, TracerLiteral) {}
+    using ArgumentType = typename Category::ArgumentType;
 
-    constexpr Tracer(TracerLiteral, Category &) {}
+    constexpr Tracer(ArgumentType, Category &, ArgumentType) {}
+
+    constexpr Tracer(ArgumentType, Category &) {}
 
     ~Tracer() {}
 };
@@ -297,22 +406,22 @@ template<>
 class Tracer<StringViewCategory<true>>
 {
 public:
-    constexpr Tracer(TracerLiteral name, StringViewCategory<true> &category, TracerLiteral arguments)
+    Tracer(TracerLiteral name, StringViewCategory<true> &category, TracerLiteral arguments)
         : m_name{name}
         , m_arguments{arguments}
         , m_category{category}
     {
         if constexpr (isTracerActive()) {
-            if (category.eventQueue.isEnabled == IsEnabled::Yes)
+            if (category.eventQueue().isEnabled == IsEnabled::Yes)
                 m_start = Clock::now();
         }
     }
 
-    constexpr Tracer(TracerLiteral name, StringViewCategory<true> &category)
-        : Tracer{name, category, "{}"_t}
+    Tracer(TracerLiteral name, StringViewCategory<true> &category)
+        : Tracer{name, category, ""_t}
     {
         if constexpr (isTracerActive()) {
-            if (category.eventQueue.isEnabled == IsEnabled::Yes)
+            if (category.eventQueue().isEnabled == IsEnabled::Yes)
                 m_start = Clock::now();
         }
     }
@@ -320,14 +429,15 @@ public:
     ~Tracer()
     {
         if constexpr (isTracerActive()) {
-            if (m_category.eventQueue.isEnabled == IsEnabled::Yes) {
+            if (m_category.eventQueue().isEnabled == IsEnabled::Yes) {
                 auto duration = Clock::now() - m_start;
-                auto &traceEvent = getTraceEvent(m_category.eventQueue);
+                auto &traceEvent = getTraceEvent(m_category.eventQueue());
                 traceEvent.name = m_name;
-                traceEvent.category = m_category.name;
+                traceEvent.category = m_category.name();
                 traceEvent.arguments = m_arguments;
-                traceEvent.start = m_start;
+                traceEvent.time = m_start;
                 traceEvent.duration = duration;
+                traceEvent.type = 'X';
             }
         }
     }
@@ -349,16 +459,16 @@ public:
         , m_category{category}
     {
         if constexpr (isTracerActive()) {
-            if (category.eventQueue.isEnabled == IsEnabled::Yes)
+            if (category.eventQueue().isEnabled == IsEnabled::Yes)
                 m_start = Clock::now();
         }
     }
 
     Tracer(std::string name, StringViewCategory<true> &category)
-        : Tracer{std::move(name), category, "{}"}
+        : Tracer{std::move(name), category, ""}
     {
         if constexpr (isTracerActive()) {
-            if (category.eventQueue.isEnabled == IsEnabled::Yes)
+            if (category.eventQueue().isEnabled == IsEnabled::Yes)
                 m_start = Clock::now();
         }
     }
@@ -366,14 +476,15 @@ public:
     ~Tracer()
     {
         if constexpr (isTracerActive()) {
-            if (m_category.eventQueue.isEnabled == IsEnabled::Yes) {
+            if (m_category.eventQueue().isEnabled == IsEnabled::Yes) {
                 auto duration = Clock::now() - m_start;
-                auto &traceEvent = getTraceEvent(m_category.eventQueue);
+                auto &traceEvent = getTraceEvent(m_category.eventQueue());
                 traceEvent.name = std::move(m_name);
-                traceEvent.category = m_category.name;
+                traceEvent.category = m_category.name();
                 traceEvent.arguments = std::move(m_arguments);
-                traceEvent.start = m_start;
+                traceEvent.time = m_start;
                 traceEvent.duration = duration;
+                traceEvent.type = 'X';
             }
         }
     }
@@ -403,7 +514,7 @@ public:
     }
 
     GlobalTracer(std::string name, std::string category)
-        : GlobalTracer{std::move(name), std::move(category), "{}"}
+        : GlobalTracer{std::move(name), std::move(category), ""}
     {}
 
     ~GlobalTracer()
@@ -415,8 +526,9 @@ public:
                 traceEvent.name = std::move(m_name);
                 traceEvent.category = std::move(m_category);
                 traceEvent.arguments = std::move(m_arguments);
-                traceEvent.start = std::move(m_start);
+                traceEvent.time = std::move(m_start);
                 traceEvent.duration = std::move(duration);
+                traceEvent.type = 'X';
             }
         }
     }

src/libs/sqlite/sqlitebasestatement.h

@@ -401,8 +401,8 @@ public:
         const_iterator end() const & { return iterator{m_statement, false}; }
 
     private:
-        NanotraceHR::Tracer<decltype(sqliteHighLevelCategory())> tracer{"range"_t,
-                                                                        sqliteHighLevelCategory()};
+        NanotraceHR::Tracer<std::decay_t<decltype(sqliteHighLevelCategory())>> tracer{
+            "range"_t, sqliteHighLevelCategory()};
         StatementImplementation &m_statement;
     };
 

src/plugins/qmldesigner/CMakeLists.txt

@@ -16,9 +16,13 @@ option(USE_PROJECTSTORAGE "Use ProjectStorage" ${ENV_QDS_USE_PROJECTSTORAGE})
 add_feature_info("ProjectStorage" ${USE_PROJECTSTORAGE} "")
 
 env_with_default("QTC_ENABLE_PROJECT_STORAGE_TRACING" ENV_QTC_ENABLE_PROJECT_STORAGE_TRACING OFF)
-option(ENABLE_PROJECT_STORAGE_TRACING "Enable sqlite tarcing" ${ENV_QTC_ENABLE_PROJECT_STORAGE_TRACING})
+option(ENABLE_PROJECT_STORAGE_TRACING "Enable sqlite tracing" ${ENV_QTC_ENABLE_PROJECT_STORAGE_TRACING})
 add_feature_info("Sqlite tracing" ${ENABLE_PROJECT_STORAGE_TRACING} "")
 
+env_with_default("QTC_ENABLE_IMAGE_CACHE_TRACING" ENV_QTC_ENABLE_IMAGE_CACHE_TRACING OFF)
+option(ENABLE_IMAGE_CACHE_TRACING "Enable image cache tracing" ${ENV_QTC_ENABLE_IMAGE_CACHE_TRACING})
+add_feature_info("Image cache tracing" ${ENABLE_IMAGE_CACHE_TRACING} "")
+
 
 add_qtc_library(QmlDesignerUtils STATIC
   DEPENDS
@@ -93,6 +97,7 @@ extend_qtc_library(QmlDesignerCore
   DEPENDS Nanotrace
   DEFINES
     $<$<BOOL:${ENABLE_PROJECT_STORAGE_TRACING}>:ENABLE_PROJECT_STORAGE_TRACING>
+    $<$<BOOL:${ENABLE_IMAGE_CACHE_TRACING}>:ENABLE_IMAGE_CACHE_TRACING>
 )
 
 extend_qtc_library(QmlDesignerCore

src/plugins/qmldesigner/designercore/imagecache/asynchronousimagecache.cpp

@@ -7,18 +7,39 @@
 #include "imagecachestorage.h"
 #include "timestampprovider.h"
 
+#include <QScopeGuard>
+
 #include <thread>
 
 namespace QmlDesigner {
 
+using namespace NanotraceHR::Literals;
+
+namespace {
+using TraceFile = NanotraceHR::TraceFile<imageCacheTracingIsEnabled()>;
+
+TraceFile traceFile{"qml_designer.json"};
+
+thread_local auto eventQueueData = NanotraceHR::makeEventQueueData<NanotraceHR::StringViewTraceEvent, 10000>(
+    traceFile);
+thread_local NanotraceHR::EventQueue eventQueue = eventQueueData.createEventQueue();
+
+thread_local NanotraceHR::StringViewCategory<imageCacheTracingIsEnabled()> category{"image cache"_t,
+                                                                                    eventQueue};
+} // namespace
+
+NanotraceHR::StringViewCategory<imageCacheTracingIsEnabled()> &imageCacheCategory()
+{
+    return category;
+}
+
 AsynchronousImageCache::AsynchronousImageCache(ImageCacheStorageInterface &storage,
                                                ImageCacheGeneratorInterface &generator,
                                                TimeStampProviderInterface &timeStampProvider)
     : m_storage(storage)
     , m_generator(generator)
     , m_timeStampProvider(timeStampProvider)
-{
-}
+{}
 
 AsynchronousImageCache::~AsynchronousImageCache()
 {
@@ -31,6 +52,7 @@ void AsynchronousImageCache::request(Utils::SmallStringView name,
                                      ImageCache::CaptureImageCallback captureCallback,
                                      ImageCache::AbortCallback abortCallback,
                                      ImageCache::AuxiliaryData auxiliaryData,
+                                     ImageCacheTraceToken traceToken,
                                      ImageCacheStorageInterface &storage,
                                      ImageCacheGeneratorInterface &generator,
                                      TimeStampProviderInterface &timeStampProvider)
@@ -40,6 +62,11 @@ void AsynchronousImageCache::request(Utils::SmallStringView name,
 
     const auto timeStamp = timeStampProvider.timeStamp(name);
     auto requestImageFromStorage = [&](RequestType requestType) {
+        imageCacheCategory().tickAsynchronous(traceToken, "start fetching image from storage"_t);
+
+        QScopeGuard finally{[=] {
+            imageCacheCategory().tickAsynchronous(traceToken, "end fetching image from storage"_t);
+        }};
         switch (requestType) {
         case RequestType::Image:
             return storage.fetchImage(id, timeStamp);
@@ -56,14 +83,19 @@ void AsynchronousImageCache::request(Utils::SmallStringView name,
     const auto entry = requestImageFromStorage(requestType);
 
     if (entry) {
-        if (entry->isNull())
+        if (entry->isNull()) {
             abortCallback(ImageCache::AbortReason::Failed);
-        else
+            imageCacheCategory().endAsynchronous(traceToken,
+                                                 "abort image request because entry in database is null"_t);
+        } else {
             captureCallback(*entry);
+            imageCacheCategory().endAsynchronous(traceToken, "image request delivered from storage"_t);
+        }
     } else {
         auto callback =
             [captureCallback = std::move(captureCallback),
-             requestType](const QImage &image, const QImage &midSizeImage, const QImage &smallImage) {
+             requestType,
+             traceToken](const QImage &image, const QImage &midSizeImage, const QImage &smallImage) {
                 auto selectImage = [](RequestType requestType,
                                       const QImage &image,
                                       const QImage &midSizeImage,
@@ -82,7 +114,12 @@ void AsynchronousImageCache::request(Utils::SmallStringView name,
                     return image;
                 };
                 captureCallback(selectImage(requestType, image, midSizeImage, smallImage));
+                imageCacheCategory().endAsynchronous(traceToken,
+                                                     "image request delivered from generation"_t);
             };
+
+        imageCacheCategory().tickAsynchronous(traceToken, "request image generation"_t);
+
         generator.generateImage(name,
                                 extraId,
                                 timeStamp,
@@ -98,12 +135,15 @@ void AsynchronousImageCache::requestImage(Utils::SmallStringView name,
                                           Utils::SmallStringView extraId,
                                           ImageCache::AuxiliaryData auxiliaryData)
 {
+    auto traceToken = imageCacheCategory().beginAsynchronous(
+        "request image in asynchornous image cache"_t);
     m_taskQueue.addTask(std::move(name),
                         std::move(extraId),
                         std::move(captureCallback),
                         std::move(abortCallback),
                         std::move(auxiliaryData),
-                        RequestType::Image);
+                        RequestType::Image,
+                        traceToken);
 }
 
 void AsynchronousImageCache::requestMidSizeImage(Utils::SmallStringView name,
@@ -112,12 +152,15 @@ void AsynchronousImageCache::requestMidSizeImage(Utils::SmallStringView name,
                                                  Utils::SmallStringView extraId,
                                                  ImageCache::AuxiliaryData auxiliaryData)
 {
+    auto traceToken = imageCacheCategory().beginAsynchronous(
+        "request mid size image in asynchornous image cache"_t);
     m_taskQueue.addTask(std::move(name),
                         std::move(extraId),
                         std::move(captureCallback),
                         std::move(abortCallback),
                         std::move(auxiliaryData),
-                        RequestType::MidSizeImage);
+                        RequestType::MidSizeImage,
+                        traceToken);
 }
 
 void AsynchronousImageCache::requestSmallImage(Utils::SmallStringView name,
@@ -126,12 +169,15 @@ void AsynchronousImageCache::requestSmallImage(Utils::SmallStringView name,
                                                Utils::SmallStringView extraId,
                                                ImageCache::AuxiliaryData auxiliaryData)
 {
+    auto traceToken = imageCacheCategory().beginAsynchronous(
+        "request small size image in asynchornous image cache"_t);
     m_taskQueue.addTask(std::move(name),
                         std::move(extraId),
                         std::move(captureCallback),
                         std::move(abortCallback),
                         std::move(auxiliaryData),
-                        RequestType::SmallImage);
+                        RequestType::SmallImage,
+                        traceToken);
 }
 
 void AsynchronousImageCache::clean()

src/plugins/qmldesigner/designercore/include/asynchronousimagecache.h

@@ -6,6 +6,7 @@
 #include "asynchronousimagecacheinterface.h"
 
 #include <imagecache/taskqueue.h>
+#include <nanotrace/nanotracehr.h>
 
 #include <condition_variable>
 #include <deque>
@@ -21,6 +22,19 @@ class ImageCacheStorageInterface;
 class ImageCacheGeneratorInterface;
 class ImageCacheCollectorInterface;
 
+constexpr bool imageCacheTracingIsEnabled()
+{
+#ifdef ENABLE_IMAGE_CACHE_TRACING
+    return NanotraceHR::isTracerActive();
+#else
+    return false;
+#endif
+}
+
+using ImageCacheTraceToken = NanotraceHR::Token<imageCacheTracingIsEnabled()>;
+
+NanotraceHR::StringViewCategory<imageCacheTracingIsEnabled()> &imageCacheCategory();
+
 class AsynchronousImageCache final : public AsynchronousImageCacheInterface
 {
 public:
@@ -53,18 +67,21 @@ private:
     struct Entry
     {
         Entry() = default;
+
         Entry(Utils::PathString name,
               Utils::SmallString extraId,
               ImageCache::CaptureImageCallback &&captureCallback,
               ImageCache::AbortCallback &&abortCallback,
               ImageCache::AuxiliaryData &&auxiliaryData,
-              RequestType requestType)
+              RequestType requestType,
+              ImageCacheTraceToken traceToken)
             : name{std::move(name)}
             , extraId{std::move(extraId)}
             , captureCallback{std::move(captureCallback)}
             , abortCallback{std::move(abortCallback)}
             , auxiliaryData{std::move(auxiliaryData)}
             , requestType{requestType}
+            , traceToken{traceToken}
         {}
 
         Utils::PathString name;
@@ -73,6 +90,7 @@ private:
         ImageCache::AbortCallback abortCallback;
         ImageCache::AuxiliaryData auxiliaryData;
         RequestType requestType = RequestType::Image;
+        ImageCacheTraceToken traceToken;
     };
 
     static void request(Utils::SmallStringView name,
@@ -81,6 +99,7 @@ private:
                         ImageCache::CaptureImageCallback captureCallback,
                         ImageCache::AbortCallback abortCallback,
                         ImageCache::AuxiliaryData auxiliaryData,
+                        ImageCacheTraceToken traceToken,
                         ImageCacheStorageInterface &storage,
                         ImageCacheGeneratorInterface &generator,
                         TimeStampProviderInterface &timeStampProvider);
@@ -95,6 +114,7 @@ private:
                     std::move(entry.captureCallback),
                     std::move(entry.abortCallback),
                     std::move(entry.auxiliaryData),
+                    entry.traceToken,
                     storage,
                     generator,
                     timeStampProvider);
@@ -107,7 +127,13 @@ private:
 
     struct Clean
     {
-        void operator()(Entry &entry) { entry.abortCallback(ImageCache::AbortReason::Abort); }
+        void operator()(Entry &entry)
+        {
+            using namespace NanotraceHR::Literals;
+
+            entry.abortCallback(ImageCache::AbortReason::Abort);
+            imageCacheCategory().endAsynchronous(entry.traceToken, "aborted for cleanup"_t);
+        }
     };
 
 private: