diff --git a/src/android/app/src/main/java/org/citra/citra_emu/fragments/EmulationFragment.kt b/src/android/app/src/main/java/org/citra/citra_emu/fragments/EmulationFragment.kt index e1f653a09..027c73b28 100644 --- a/src/android/app/src/main/java/org/citra/citra_emu/fragments/EmulationFragment.kt +++ b/src/android/app/src/main/java/org/citra/citra_emu/fragments/EmulationFragment.kt @@ -1178,8 +1178,12 @@ class EmulationFragment : Fragment(), SurfaceHolder.Callback, Choreographer.Fram if (EmulationMenuSettings.showPerformanceOverlay) { val SYSTEM_FPS = 0 val FPS = 1 - val FRAMETIME = 2 - val SPEED = 3 + val SPEED = 2 + val FRAMETIME = 3 + val TIME_SVC = 4 + val TIME_IPC = 5 + val TIME_GPU = 6 + val TIME_REM = 7 perfStatsUpdater = Runnable { val sb = StringBuilder() val perfStats = NativeLibrary.getPerfStats() @@ -1193,8 +1197,12 @@ class EmulationFragment : Fragment(), SurfaceHolder.Callback, Choreographer.Fram if (sb.isNotEmpty()) sb.append(dividerString) sb.append( String.format( - "Frametime:\u00A0%.1fms", - (perfStats[FRAMETIME] * 1000.0f).toFloat() + "Frame:\u00A0%.1fms (GPU:\u00A0%.1fms IPC:\u00A0%.1fms SVC:\u00A0%.1fms Rem:\u00A0%.1fms)", + (perfStats[FRAMETIME] * 1000.0f).toFloat(), + (perfStats[TIME_GPU] * 1000.0f).toFloat(), + (perfStats[TIME_IPC] * 1000.0f).toFloat(), + (perfStats[TIME_SVC] * 1000.0f).toFloat(), + (perfStats[TIME_REM] * 1000.0f).toFloat(), ) ) } diff --git a/src/android/app/src/main/jni/native.cpp b/src/android/app/src/main/jni/native.cpp index 7bc1844c9..ac018bea6 100644 --- a/src/android/app/src/main/jni/native.cpp +++ b/src/android/app/src/main/jni/native.cpp @@ -644,16 +644,18 @@ void Java_org_citra_citra_1emu_NativeLibrary_reloadSettings([[maybe_unused]] JNI jdoubleArray Java_org_citra_citra_1emu_NativeLibrary_getPerfStats(JNIEnv* env, [[maybe_unused]] jobject obj) { auto& core = Core::System::GetInstance(); - jdoubleArray j_stats = env->NewDoubleArray(4); + jdoubleArray j_stats = env->NewDoubleArray(8); if (core.IsPoweredOn()) { auto results = core.GetAndResetPerfStats(); // Converting the structure into an array makes it easier to pass it to the frontend - double stats[4] = {results.system_fps, results.game_fps, results.frametime, - results.emulation_speed}; + double stats[8] = {results.system_fps, results.game_fps, + results.emulation_speed, results.time_vblank_interval, + results.time_hle_svc, results.time_hle_ipc, + results.time_gpu, results.time_remaining}; - env->SetDoubleArrayRegion(j_stats, 0, 4, stats); + env->SetDoubleArrayRegion(j_stats, 0, 8, stats); } return j_stats; diff --git a/src/citra_qt/citra_qt.cpp b/src/citra_qt/citra_qt.cpp index 00c12d9ce..e1c7968a8 100644 --- a/src/citra_qt/citra_qt.cpp +++ b/src/citra_qt/citra_qt.cpp @@ -3233,7 +3233,18 @@ void GMainWindow::UpdateStatusBar() { .arg(Settings::GetFrameLimit())); } game_fps_label->setText(tr("App: %1 FPS").arg(results.game_fps, 0, 'f', 0)); - emu_frametime_label->setText(tr("Frame: %1 ms").arg(results.frametime * 1000.0, 0, 'f', 2)); + if (UISettings::values.show_advanced_frametime_info) { + emu_frametime_label->setText( + tr("Frame: %1 ms (GPU: %2 ms, IPC: %3 ms, SVC: %4 ms, Rem: %5 ms)") + .arg(results.time_vblank_interval * 1000.0, 2, 'f', 2) + .arg(results.time_gpu * 1000.0, 2, 'f', 2) + .arg(results.time_hle_ipc * 1000.0, 2, 'f', 2) + .arg(results.time_hle_svc * 1000.0, 2, 'f', 2) + .arg(results.time_remaining * 1000.0, 2, 'f', 2)); + } else { + emu_frametime_label->setText( + tr("Frame: %1 ms").arg(results.time_vblank_interval * 1000.0, 2, 'f', 2)); + } if (show_artic_label) { artic_traffic_label->setVisible(true); diff --git a/src/citra_qt/configuration/config.cpp b/src/citra_qt/configuration/config.cpp index 426600bdc..5abdc4a72 100644 --- a/src/citra_qt/configuration/config.cpp +++ b/src/citra_qt/configuration/config.cpp @@ -812,6 +812,7 @@ void QtConfig::ReadUIValues() { ReadBasicSetting(UISettings::values.display_titlebar); ReadBasicSetting(UISettings::values.show_filter_bar); ReadBasicSetting(UISettings::values.show_status_bar); + ReadBasicSetting(UISettings::values.show_advanced_frametime_info); ReadBasicSetting(UISettings::values.confirm_before_closing); ReadBasicSetting(UISettings::values.save_state_warning); ReadBasicSetting(UISettings::values.first_start); @@ -1322,6 +1323,7 @@ void QtConfig::SaveUIValues() { WriteBasicSetting(UISettings::values.display_titlebar); WriteBasicSetting(UISettings::values.show_filter_bar); WriteBasicSetting(UISettings::values.show_status_bar); + WriteBasicSetting(UISettings::values.show_advanced_frametime_info); WriteBasicSetting(UISettings::values.confirm_before_closing); WriteBasicSetting(UISettings::values.save_state_warning); WriteBasicSetting(UISettings::values.first_start); diff --git a/src/citra_qt/configuration/configure_ui.cpp b/src/citra_qt/configuration/configure_ui.cpp index 8fa4effc8..dae93b995 100644 --- a/src/citra_qt/configuration/configure_ui.cpp +++ b/src/citra_qt/configuration/configure_ui.cpp @@ -60,6 +60,8 @@ void ConfigureUi::SetConfiguration() { ui->toggle_hide_no_icon->setChecked(UISettings::values.game_list_hide_no_icon.GetValue()); ui->toggle_single_line_mode->setChecked( UISettings::values.game_list_single_line_mode.GetValue()); + ui->show_advanced_frametime_info->setChecked( + UISettings::values.show_advanced_frametime_info.GetValue()); } void ConfigureUi::ApplyConfiguration() { @@ -73,6 +75,7 @@ void ConfigureUi::ApplyConfiguration() { static_cast(ui->row_2_text_combobox->currentIndex() - 1); UISettings::values.game_list_hide_no_icon = ui->toggle_hide_no_icon->isChecked(); UISettings::values.game_list_single_line_mode = ui->toggle_single_line_mode->isChecked(); + UISettings::values.show_advanced_frametime_info = ui->show_advanced_frametime_info->isChecked(); } void ConfigureUi::OnLanguageChanged(int index) { diff --git a/src/citra_qt/configuration/configure_ui.ui b/src/citra_qt/configuration/configure_ui.ui index 4ea6f4607..f522a910e 100644 --- a/src/citra_qt/configuration/configure_ui.ui +++ b/src/citra_qt/configuration/configure_ui.ui @@ -208,6 +208,26 @@ + + + Status Bar + + + + + + + + Show Advanced Frame Time Info + + + + + + + + + Qt::Vertical diff --git a/src/citra_qt/uisettings.h b/src/citra_qt/uisettings.h index 392954cf8..393e20dd4 100644 --- a/src/citra_qt/uisettings.h +++ b/src/citra_qt/uisettings.h @@ -75,6 +75,7 @@ struct Values { Settings::Setting display_titlebar{true, "displayTitleBars"}; Settings::Setting show_filter_bar{true, "showFilterBar"}; Settings::Setting show_status_bar{true, "showStatusBar"}; + Settings::Setting show_advanced_frametime_info{false, "show_advanced_frametime_info"}; Settings::Setting confirm_before_closing{true, "confirmClose"}; Settings::Setting save_state_warning{true, "saveStateWarning"}; diff --git a/src/core/hle/kernel/svc.cpp b/src/core/hle/kernel/svc.cpp index e4ba9d888..cbdc3fd61 100644 --- a/src/core/hle/kernel/svc.cpp +++ b/src/core/hle/kernel/svc.cpp @@ -657,7 +657,18 @@ Result SVC::SendSyncRequest(Handle handle) { kernel.GetIPCRecorder().RegisterRequest(session, thread); } - return session->SendSyncRequest(thread); + const bool is_hle = + session->parent->server != nullptr && session->parent->server->hle_handler != nullptr; + + if (is_hle) { + system.perf_stats->BeginIPCProcessing(); + } + const auto res = session->SendSyncRequest(thread); + if (is_hle) { + system.perf_stats->EndIPCProcessing(); + } + + return res; } Result SVC::OpenProcess(Handle* out_handle, u32 process_id) { @@ -2364,6 +2375,7 @@ MICROPROFILE_DEFINE(Kernel_SVC, "Kernel", "SVC", MP_RGB(70, 200, 70)); void SVC::CallSVC(u32 immediate) { MICROPROFILE_SCOPE(Kernel_SVC); + system.perf_stats->BeginSVCProcessing(); // Lock the kernel mutex when we enter the kernel HLE. std::scoped_lock lock{kernel.GetHLELock()}; @@ -2380,6 +2392,7 @@ void SVC::CallSVC(u32 immediate) { LOG_ERROR(Kernel_SVC, "unimplemented SVC function {:02X} {}(..)", info->id, info->name); } } + system.perf_stats->EndSVCProcessing(); } SVC::SVC(Core::System& system) : system(system), kernel(system.Kernel()), memory(system.Memory()) {} diff --git a/src/core/hle/service/gsp/gsp_gpu.cpp b/src/core/hle/service/gsp/gsp_gpu.cpp index 35157cd08..72dce9804 100644 --- a/src/core/hle/service/gsp/gsp_gpu.cpp +++ b/src/core/hle/service/gsp/gsp_gpu.cpp @@ -439,7 +439,9 @@ void GSP_GPU::TriggerCmdReqQueue(Kernel::HLERequestContext& ctx) { gpu.Debugger().GXCommandProcessed(command); // Decode and execute command + system.perf_stats->BeginGPUProcessing(); gpu.Execute(command); + system.perf_stats->EndGPUProcessing(); if (command.stop) { command_buffer->should_stop.Assign(1); diff --git a/src/core/perf_stats.cpp b/src/core/perf_stats.cpp index d65ac2a24..1a14b620d 100644 --- a/src/core/perf_stats.cpp +++ b/src/core/perf_stats.cpp @@ -48,6 +48,30 @@ PerfStats::~PerfStats() { file.WriteString(stream.str()); } +void PerfStats::BeginSVCProcessing() { + start_svc_time = Clock::now(); +} + +void PerfStats::EndSVCProcessing() { + accumulated_svc_time += (Clock::now() - start_svc_time); +} + +void PerfStats::BeginIPCProcessing() { + start_ipc_time = Clock::now(); +} + +void PerfStats::EndIPCProcessing() { + accumulated_ipc_time += (Clock::now() - start_ipc_time); +} + +void PerfStats::BeginGPUProcessing() { + start_gpu_time = Clock::now(); +} + +void PerfStats::EndGPUProcessing() { + accumulated_gpu_time += (Clock::now() - start_gpu_time); +} + void PerfStats::BeginSystemFrame() { std::scoped_lock lock{object_mutex}; @@ -102,8 +126,28 @@ PerfStats::Results PerfStats::GetAndResetStats(microseconds current_system_time_ last_stats.system_fps = static_cast(system_frames) / interval; last_stats.game_fps = static_cast(game_frames) / interval; - last_stats.frametime = duration_cast(accumulated_frametime).count() / - static_cast(system_frames); + last_stats.time_vblank_interval = + system_frames ? (duration_cast(accumulated_frametime).count() / + static_cast(system_frames)) + : 0; + last_stats.time_hle_svc = + system_frames + ? (duration_cast(accumulated_svc_time - accumulated_ipc_time).count() / + static_cast(system_frames)) + : 0; + last_stats.time_hle_ipc = + system_frames + ? (duration_cast(accumulated_ipc_time - accumulated_gpu_time).count() / + static_cast(system_frames)) + : 0; + last_stats.time_gpu = system_frames ? (duration_cast(accumulated_gpu_time).count() / + static_cast(system_frames)) + : 0; + last_stats.time_remaining = + system_frames + ? (duration_cast(accumulated_frametime - accumulated_svc_time).count() / + static_cast(system_frames)) + : 0; last_stats.emulation_speed = system_us_per_second.count() / 1'000'000.0; last_stats.artic_transmitted = static_cast(artic_transmitted) / interval; last_stats.artic_events.raw = artic_events.raw | prev_artic_event.raw; @@ -113,6 +157,12 @@ PerfStats::Results PerfStats::GetAndResetStats(microseconds current_system_time_ reset_point_system_us = current_system_time_us; accumulated_frametime = Clock::duration::zero(); system_frames = 0; + accumulated_svc_time = Clock::duration::zero(); + svc_processing_times = 0; + accumulated_ipc_time = Clock::duration::zero(); + ipc_processing_times = 0; + accumulated_gpu_time = Clock::duration::zero(); + gpu_processing_times = 0; game_frames = 0; artic_transmitted = 0; prev_artic_event.raw &= artic_events.raw; diff --git a/src/core/perf_stats.h b/src/core/perf_stats.h index 8c4917783..93c7603ae 100644 --- a/src/core/perf_stats.h +++ b/src/core/perf_stats.h @@ -1,4 +1,4 @@ -// Copyright 2017 Citra Emulator Project +// Copyright Citra Emulator Project / Azahar Emulator Project // Licensed under GPLv2 or any later version // Refer to the license.txt file included. @@ -54,8 +54,16 @@ public: double system_fps; /// Game FPS (GSP frame submissions) in Hz double game_fps; - /// Walltime per system frame, in seconds, excluding any waits - double frametime; + /// Walltime in seconds, between guest vblank events + double time_vblank_interval; + // Walltime in seconds of the vblank interval spent in SVC processing, excluding GPU and IPC + double time_hle_svc; + // Walltime in seconds of the vblank interval spent in IPC processing, excluding GPU + double time_hle_ipc; + // Walltime in seconds of the vblank interval spent in GPU command processing + double time_gpu; + // Walltime in seconds of teh vblank interval spent in other operations + double time_remaining; /// Ratio of walltime / emulated time elapsed double emulation_speed; /// Artic base bytes per second @@ -64,6 +72,12 @@ public: PerfArticEvents artic_events{}; }; + void BeginSVCProcessing(); + void EndSVCProcessing(); + void BeginIPCProcessing(); + void EndIPCProcessing(); + void BeginGPUProcessing(); + void EndGPUProcessing(); void BeginSystemFrame(); void EndSystemFrame(); void EndGameFrame(); @@ -140,6 +154,21 @@ private: /// Visible duration for the frame prior to previous_frame_length Clock::duration previous_previous_frame_length = Clock::duration::zero(); + Clock::time_point start_svc_time = reset_point; + + Clock::duration accumulated_svc_time = Clock::duration::zero(); + u32 svc_processing_times = 0; + + Clock::time_point start_ipc_time = reset_point; + + Clock::duration accumulated_ipc_time = Clock::duration::zero(); + u32 ipc_processing_times = 0; + + Clock::time_point start_gpu_time = reset_point; + + Clock::duration accumulated_gpu_time = Clock::duration::zero(); + u32 gpu_processing_times = 0; + /// Last recorded performance statistics. Results last_stats; };