Implement Perfetto Tracing

This commit implements tracing Skyline using https://perfetto.dev/ for SVCs, IPC, Scheduler and Presentation
StigStiggi · Mar 22, 2021 · 6c6e665 · 6c6e665
1 parent 1155394
commit 6c6e665
Show file tree

Hide file tree

Showing 14 changed files with 74 additions and 3 deletions.
diff --git a/.gitmodules b/.gitmodules
@@ -21,3 +21,7 @@
 	path = app/libraries/tzcode
 	url = https://github.com/skyline-emu/tz
 	branch = master
+[submodule "app/libraries/perfetto"]
+	path = app/libraries/perfetto
+	url = https://android.googlesource.com/platform/external/perfetto
+	branch = releases/v12.x
diff --git a/app/CMakeLists.txt b/app/CMakeLists.txt
@@ -32,6 +32,10 @@ include_directories("libraries/frozen/include")
 
 find_package(mbedtls REQUIRED CONFIG)
 
+# Define a static library for Perfetto.
+include_directories(libraries/perfetto/sdk)
+add_library(perfetto STATIC libraries/perfetto/sdk/perfetto.cc)
+
 include_directories(${source_DIR}/skyline)
 
 add_library(skyline SHARED
@@ -41,6 +45,7 @@ add_library(skyline SHARED
         ${source_DIR}/skyline/common/settings.cpp
         ${source_DIR}/skyline/common/signal.cpp
         ${source_DIR}/skyline/common/uuid.cpp
+        ${source_DIR}/skyline/common/tracing.cpp
         ${source_DIR}/skyline/nce/guest.S
         ${source_DIR}/skyline/nce.cpp
         ${source_DIR}/skyline/jvm.cpp
@@ -180,5 +185,5 @@ add_library(skyline SHARED
         ${source_DIR}/skyline/services/prepo/IPrepoService.cpp
         )
 # target_precompile_headers(skyline PRIVATE ${source_DIR}/skyline/common.h) # PCH will currently break Intellisense
-target_link_libraries(skyline vulkan android fmt lz4_static tzcode oboe mbedtls::mbedcrypto)
+target_link_libraries(skyline vulkan android perfetto fmt lz4_static tzcode oboe mbedtls::mbedcrypto)
 target_compile_options(skyline PRIVATE -Wall -Wno-unknown-attributes -Wno-c++20-extensions -Wno-c++17-extensions -Wno-c99-designator -Wno-reorder -Wno-missing-braces -Wno-unused-variable -Wno-unused-private-field)
diff --git a/app/libraries/perfetto b/app/libraries/perfetto
diff --git a/app/src/main/cpp/emu_jni.cpp b/app/src/main/cpp/emu_jni.cpp
@@ -10,6 +10,7 @@
 #include "skyline/common.h"
 #include "skyline/common/signal.h"
 #include "skyline/common/settings.h"
+#include "skyline/common/tracing.h"
 #include "skyline/loader/loader.h"
 #include "skyline/vfs/android_asset_filesystem.h"
 #include "skyline/os.h"
@@ -64,6 +65,12 @@ extern "C" JNIEXPORT void Java_emu_skyline_EmulationActivity_executeApplication(
 
     auto start{std::chrono::steady_clock::now()};
 
+    // Initialize tracing
+    perfetto::TracingInitArgs args;
+    args.backends |= perfetto::kSystemBackend;
+    perfetto::Tracing::Initialize(args);
+    perfetto::TrackEvent::Register();
+
     try {
         auto os{std::make_shared<skyline::kernel::OS>(jvmManager, logger, settings, std::string(appFilesPath), GetTimeZoneName(), std::make_shared<skyline::vfs::AndroidAssetFileSystem>(AAssetManager_fromJava(env, assetManager)))};
         OsWeak = os;
@@ -85,6 +92,8 @@ extern "C" JNIEXPORT void Java_emu_skyline_EmulationActivity_executeApplication(
         logger->Error("An unknown exception has occurred");
     }
 
+    perfetto::TrackEvent::Flush();
+
     InputWeak.reset();
 
     logger->Info("Emulation has ended");

diff --git a/app/src/main/cpp/skyline/common/tracing.cpp b/app/src/main/cpp/skyline/common/tracing.cpp
@@ -0,0 +1,3 @@
+#include "tracing.h"
+
+PERFETTO_TRACK_EVENT_STATIC_STORAGE();
diff --git a/app/src/main/cpp/skyline/common/tracing.h b/app/src/main/cpp/skyline/common/tracing.h
@@ -0,0 +1,19 @@
+#pragma once
+
+#include <limits>
+#include <perfetto.h>
+#include <common.h>
+
+PERFETTO_DEFINE_CATEGORIES(perfetto::Category("sched").SetDescription("Events from the scheduler"),
+                             perfetto::Category("kernel").SetDescription("Events from parts of the kernel"),
+                             perfetto::Category("guest").SetDescription("Events relating to guest code"),
+                             perfetto::Category("gpu").SetDescription("Events from the emulated GPU"));
+
+namespace skyline::tracing {
+    /**
+     * @brief Perfetto track IDs for custom tracks, counting down from U64 max to avoid conflicts
+     */
+    enum class TrackIds : u64 {
+        Presentation = std::numeric_limits<u64>::max()
+    };
+}
diff --git a/app/src/main/cpp/skyline/gpu/presentation_engine.cpp b/app/src/main/cpp/skyline/gpu/presentation_engine.cpp
@@ -9,7 +9,11 @@ extern skyline::u16 Fps;
 extern skyline::u32 FrameTime;
 
 namespace skyline::gpu {
-    PresentationEngine::PresentationEngine(const DeviceState &state) : state(state), vsyncEvent(std::make_shared<kernel::type::KEvent>(state, true)), bufferEvent(std::make_shared<kernel::type::KEvent>(state, true)) {}
+    PresentationEngine::PresentationEngine(const DeviceState &state) : state(state), vsyncEvent(std::make_shared<kernel::type::KEvent>(state, true)), bufferEvent(std::make_shared<kernel::type::KEvent>(state, true)), presentationTrack(static_cast<uint64_t>(tracing::TrackIds::Presentation), perfetto::ProcessTrack::Current()) {
+        auto desc{presentationTrack.Serialize()};
+        desc.set_name("Presentation");
+        perfetto::TrackEvent::SetTrackDescriptor(presentationTrack, desc);
+    }
 
     PresentationEngine::~PresentationEngine() {
         if (window)
@@ -76,6 +80,8 @@ namespace skyline::gpu {
             FrameTime = static_cast<u32>((now - frameTimestamp) / 10000); // frametime / 100 is the real ms value, this is to retain the first two decimals
             Fps = static_cast<u16>(constant::NsInSecond / (now - frameTimestamp));
 
+            TRACE_EVENT_INSTANT("gpu", "Present", presentationTrack, "FrameTimeNs", now - frameTimestamp, "Fps", Fps);
+
             frameTimestamp = now;
         } else {
             frameTimestamp = util::GetTimeNs();

diff --git a/app/src/main/cpp/skyline/gpu/presentation_engine.h b/app/src/main/cpp/skyline/gpu/presentation_engine.h
@@ -3,6 +3,7 @@
 
 #pragma once
 
+#include <common/tracing.h>
 #include <kernel/types/KEvent.h>
 #include "texture.h"
 
@@ -16,6 +17,7 @@ namespace skyline::gpu {
         std::condition_variable windowConditional;
         jobject surface{}; //!< The Surface object backing the ANativeWindow
         u64 frameTimestamp{}; //!< The timestamp of the last frame being shown
+        perfetto::Track presentationTrack; //!< Perfetto track used for presentation events
 
       public:
         texture::Dimensions resolution{};

diff --git a/app/src/main/cpp/skyline/gpu/texture.cpp b/app/src/main/cpp/skyline/gpu/texture.cpp
@@ -1,6 +1,7 @@
 // SPDX-License-Identifier: MPL-2.0
 // Copyright © 2020 Skyline Team and Contributors (https://github.com/skyline-emu/)
 
+#include <common/tracing.h>
 #include <android/native_window.h>
 #include <kernel/types/KProcess.h>
 #include <unistd.h>
@@ -22,6 +23,7 @@ namespace skyline::gpu {
     }
 
     void Texture::SynchronizeHost() {
+        TRACE_EVENT("gpu", "Texture::SynchronizeHost");
         auto pointer{guest->pointer};
         auto size{format.GetSize(dimensions)};
         backing.resize(size);

diff --git a/app/src/main/cpp/skyline/kernel/scheduler.cpp b/app/src/main/cpp/skyline/kernel/scheduler.cpp
@@ -3,6 +3,7 @@
 
 #include <unistd.h>
 #include <common/signal.h>
+#include <common/tracing.h>
 #include "types/KThread.h"
 #include "scheduler.h"
 
@@ -12,6 +13,8 @@ namespace skyline::kernel {
     Scheduler::Scheduler(const DeviceState &state) : state(state) {}
 
     void Scheduler::SignalHandler(int signal, siginfo *info, ucontext *ctx, void **tls) {
+        TRACE_EVENT_END("guest");
+
         if (*tls) {
             const auto &state{*reinterpret_cast<nce::ThreadContext *>(*tls)->state};
             if (signal == PreemptionSignal)
@@ -22,6 +25,7 @@ namespace skyline::kernel {
         } else {
             YieldPending = true;
         }
+        TRACE_EVENT_BEGIN("guest", "Guest");
     }
 
     Scheduler::CoreContext &Scheduler::GetOptimalCoreForThread(const std::shared_ptr<type::KThread> &thread) {
@@ -150,6 +154,7 @@ namespace skyline::kernel {
             return !core->queue.empty() && core->queue.front() == thread;
         }};
 
+        TRACE_EVENT("sched", "WaitSchedule");
         if (loadBalance && thread->affinityMask.count() > 1) {
             std::chrono::milliseconds loadBalanceThreshold{PreemptiveTimeslice * 2}; //!< The amount of time that needs to pass unscheduled for a thread to attempt load balancing
             while (!thread->scheduleCondition.wait_for(lock, loadBalanceThreshold, wakeFunction)) {
@@ -177,6 +182,7 @@ namespace skyline::kernel {
         auto &thread{state.thread};
         auto *core{&cores.at(thread->coreId)};
 
+        TRACE_EVENT("sched", "TimedWaitSchedule");
         std::unique_lock lock(core->mutex);
         if (thread->scheduleCondition.wait_for(lock, timeout, [&]() {
             if (!thread->affinityMask.test(thread->coreId)) [[unlikely]] {
@@ -201,6 +207,7 @@ namespace skyline::kernel {
         auto &core{cores.at(thread->coreId)};
 
         std::unique_lock lock(core.mutex);
+
         if (core.queue.front() == thread) {
             // If this thread is at the front of the thread queue then we need to rotate the thread
             // In the case where this thread was forcefully yielded, we don't need to do this as it's done by the thread which yielded to this thread

diff --git a/app/src/main/cpp/skyline/kernel/svc.cpp b/app/src/main/cpp/skyline/kernel/svc.cpp
@@ -3,6 +3,7 @@
 
 #include <os.h>
 #include <kernel/types/KProcess.h>
+#include <common/tracing.h>
 #include <vfs/npdm.h>
 #include "results.h"
 #include "svc.h"
@@ -286,6 +287,8 @@ namespace skyline::kernel::svc {
         constexpr i64 yieldWithCoreMigration{-1};
         constexpr i64 yieldToAnyThread{-2};
 
+        TRACE_EVENT("kernel", "SleepThread");
+
         i64 in{static_cast<i64>(state.ctx->gpr.x0)};
         if (in > 0) {
             state.logger->Debug("svcSleepThread: Sleeping for {}ns", in);

diff --git a/app/src/main/cpp/skyline/kernel/types/KThread.cpp b/app/src/main/cpp/skyline/kernel/types/KThread.cpp
@@ -4,6 +4,7 @@
 #include <cxxabi.h>
 #include <unistd.h>
 #include <common/signal.h>
+#include <common/tracing.h>
 #include <nce.h>
 #include <os.h>
 #include "KProcess.h"
@@ -82,6 +83,8 @@ namespace skyline::kernel::type {
                 state.scheduler->WaitSchedule();
             }
 
+            TRACE_EVENT_BEGIN("guest", "Guest");
+
             asm volatile(
             "MRS X0, TPIDR_EL0\n\t"
             "MSR TPIDR_EL0, %x0\n\t" // Set TLS to ThreadContext

diff --git a/app/src/main/cpp/skyline/nce.cpp b/app/src/main/cpp/skyline/nce.cpp
@@ -4,8 +4,8 @@
 #include <cxxabi.h>
 #include <unistd.h>
 #include "common/signal.h"
+#include "common/tracing.h"
 #include "os.h"
-#include "gpu.h"
 #include "jvm.h"
 #include "kernel/types/KProcess.h"
 #include "kernel/svc.h"
@@ -15,10 +15,13 @@
 
 namespace skyline::nce {
     void NCE::SvcHandler(u16 svc, ThreadContext *ctx) {
+        TRACE_EVENT_END("guest");
+
         const auto &state{*ctx->state};
         try {
             auto function{kernel::svc::SvcTable[svc]};
             if (function) [[likely]] {
+                TRACE_EVENT("kernel", "SVC");
                 state.logger->Debug("SVC called 0x{:X}", svc);
                 (*function)(state);
             } else [[unlikely]] {
@@ -49,6 +52,8 @@ namespace skyline::nce {
             abi::__cxa_end_catch();
             std::longjmp(state.thread->originalCtx, true);
         }
+
+        TRACE_EVENT_BEGIN("guest", "Guest");
     }
 
     void NCE::SignalHandler(int signal, siginfo *info, ucontext *ctx, void **tls) {

diff --git a/app/src/main/cpp/skyline/services/serviceman.cpp b/app/src/main/cpp/skyline/services/serviceman.cpp
@@ -2,6 +2,7 @@
 // Copyright © 2020 Skyline Team and Contributors (https://github.com/skyline-emu/)
 
 #include <kernel/types/KProcess.h>
+#include <common/tracing.h>
 #include "sm/IUserInterface.h"
 #include "settings/ISettingsServer.h"
 #include "settings/ISystemSettingsServer.h"
@@ -146,6 +147,7 @@ namespace skyline::service {
     }
 
     void ServiceManager::SyncRequestHandler(KHandle handle) {
+        TRACE_EVENT("kernel", "ServiceManager::SyncRequestHandler");
         auto session{state.process->GetHandle<type::KSession>(handle)};
         state.logger->Verbose("----IPC Start----");
         state.logger->Verbose("Handle is 0x{:X}", handle);
Original file line number	Diff line number	Diff line change
		@@ -0,0 +1,3 @@
		#include "tracing.h"

		PERFETTO_TRACK_EVENT_STATIC_STORAGE();