From a1d90f053a0aeabc792abb21a2c2f61e1fd7cab9 Mon Sep 17 00:00:00 2001 From: Billy Laws Date: Fri, 12 Mar 2021 00:11:12 +0530 Subject: [PATCH] Implement Perfetto Tracing This commit implements tracing Skyline using https://perfetto.dev/ for SVCs, IPC, Scheduler and Presentation --- .gitmodules | 4 ++++ app/CMakeLists.txt | 7 ++++++- app/libraries/perfetto | 1 + app/src/main/cpp/emu_jni.cpp | 9 +++++++++ app/src/main/cpp/skyline/common/tracing.cpp | 3 +++ app/src/main/cpp/skyline/common/tracing.h | 19 +++++++++++++++++++ .../cpp/skyline/gpu/presentation_engine.cpp | 8 +++++++- .../cpp/skyline/gpu/presentation_engine.h | 2 ++ app/src/main/cpp/skyline/gpu/texture.cpp | 2 ++ app/src/main/cpp/skyline/kernel/scheduler.cpp | 7 +++++++ app/src/main/cpp/skyline/kernel/svc.cpp | 3 +++ .../main/cpp/skyline/kernel/types/KThread.cpp | 3 +++ app/src/main/cpp/skyline/nce.cpp | 7 ++++++- .../main/cpp/skyline/services/serviceman.cpp | 2 ++ 14 files changed, 74 insertions(+), 3 deletions(-) create mode 160000 app/libraries/perfetto create mode 100644 app/src/main/cpp/skyline/common/tracing.cpp create mode 100644 app/src/main/cpp/skyline/common/tracing.h diff --git a/.gitmodules b/.gitmodules index c10a432e..da113779 100644 --- 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 index 425b786a..21f7d268 100644 --- 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 new file mode 160000 index 00000000..3f02be82 --- /dev/null +++ b/app/libraries/perfetto @@ -0,0 +1 @@ +Subproject commit 3f02be823cef0f54e720c0382ffc4507f48e6e4b diff --git a/app/src/main/cpp/emu_jni.cpp b/app/src/main/cpp/emu_jni.cpp index f15567ab..6a52a10c 100644 --- 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(jvmManager, logger, settings, std::string(appFilesPath), GetTimeZoneName(), std::make_shared(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 new file mode 100644 index 00000000..012cb1b7 --- /dev/null +++ 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 new file mode 100644 index 00000000..9b96172a --- /dev/null +++ b/app/src/main/cpp/skyline/common/tracing.h @@ -0,0 +1,19 @@ +#pragma once + +#include +#include +#include + +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::max() + }; +} \ No newline at end of file diff --git a/app/src/main/cpp/skyline/gpu/presentation_engine.cpp b/app/src/main/cpp/skyline/gpu/presentation_engine.cpp index 65406eeb..184b28dd 100644 --- 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(state, true)), bufferEvent(std::make_shared(state, true)) {} + PresentationEngine::PresentationEngine(const DeviceState &state) : state(state), vsyncEvent(std::make_shared(state, true)), bufferEvent(std::make_shared(state, true)), presentationTrack(static_cast(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((now - frameTimestamp) / 10000); // frametime / 100 is the real ms value, this is to retain the first two decimals Fps = static_cast(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 index a78e1a24..9e1bb7a0 100644 --- 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 #include #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 index 217e1c33..5bbe4e7e 100644 --- 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 #include #include #include @@ -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 index 75d2d62a..41ef946d 100644 --- a/app/src/main/cpp/skyline/kernel/scheduler.cpp +++ b/app/src/main/cpp/skyline/kernel/scheduler.cpp @@ -3,6 +3,7 @@ #include #include +#include #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(*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 &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 index 1d1ea6f9..81197f30 100644 --- a/app/src/main/cpp/skyline/kernel/svc.cpp +++ b/app/src/main/cpp/skyline/kernel/svc.cpp @@ -3,6 +3,7 @@ #include #include +#include #include #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(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 index a500d335..e144c088 100644 --- 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 #include #include +#include #include #include #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 index 12c199cf..51515129 100644 --- a/app/src/main/cpp/skyline/nce.cpp +++ b/app/src/main/cpp/skyline/nce.cpp @@ -4,8 +4,8 @@ #include #include #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 index 3f316e4e..352bc1ae 100644 --- 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 +#include #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(handle)}; state.logger->Verbose("----IPC Start----"); state.logger->Verbose("Handle is 0x{:X}", handle);