Merge pull request #2878 from FernandoS27/icmp

shader_ir: Implement ICMP

src/core/core.cpp

@@ -160,10 +160,6 @@ struct System::Impl {
 
         LOG_DEBUG(Core, "Initialized OK");
 
-        // Reset counters and set time origin to current frame
-        GetAndResetPerfStats();
-        perf_stats.BeginSystemFrame();
-
         return ResultStatus::Success;
     }
 
@@ -206,6 +202,16 @@ struct System::Impl {
         main_process->Run(load_parameters->main_thread_priority,
                           load_parameters->main_thread_stack_size);
 
+        u64 title_id{0};
+        if (app_loader->ReadProgramId(title_id) != Loader::ResultStatus::Success) {
+            LOG_ERROR(Core, "Failed to find title id for ROM (Error {})",
+                      static_cast<u32>(load_result));
+        }
+        perf_stats = std::make_unique<PerfStats>(title_id);
+        // Reset counters and set time origin to current frame
+        GetAndResetPerfStats();
+        perf_stats->BeginSystemFrame();
+
         status = ResultStatus::Success;
         return status;
     }
@@ -219,6 +225,8 @@ struct System::Impl {
                                     perf_results.game_fps);
         telemetry_session->AddField(Telemetry::FieldType::Performance, "Shutdown_Frametime",
                                     perf_results.frametime * 1000.0);
+        telemetry_session->AddField(Telemetry::FieldType::Performance, "Mean_Frametime_MS",
+                                    perf_stats->GetMeanFrametime());
 
         is_powered_on = false;
 
@@ -229,6 +237,7 @@ struct System::Impl {
         service_manager.reset();
         cheat_engine.reset();
         telemetry_session.reset();
+        perf_stats.reset();
         gpu_core.reset();
 
         // Close all CPU/threading state
@@ -286,7 +295,7 @@ struct System::Impl {
     }
 
     PerfStatsResults GetAndResetPerfStats() {
-        return perf_stats.GetAndResetStats(core_timing.GetGlobalTimeUs());
+        return perf_stats->GetAndResetStats(core_timing.GetGlobalTimeUs());
     }
 
     Timing::CoreTiming core_timing;
@@ -327,7 +336,7 @@ struct System::Impl {
     ResultStatus status = ResultStatus::Success;
     std::string status_details = "";
 
-    Core::PerfStats perf_stats;
+    std::unique_ptr<Core::PerfStats> perf_stats;
     Core::FrameLimiter frame_limiter;
 };
 
@@ -480,11 +489,11 @@ const Timing::CoreTiming& System::CoreTiming() const {
 }
 
 Core::PerfStats& System::GetPerfStats() {
-    return impl->perf_stats;
+    return *impl->perf_stats;
 }
 
 const Core::PerfStats& System::GetPerfStats() const {
-    return impl->perf_stats;
+    return *impl->perf_stats;
 }
 
 Core::FrameLimiter& System::FrameLimiter() {

src/core/perf_stats.cpp

@@ -4,8 +4,14 @@
 
 #include <algorithm>
 #include <chrono>
+#include <iterator>
 #include <mutex>
+#include <numeric>
+#include <sstream>
 #include <thread>
+#include <fmt/chrono.h>
+#include <fmt/format.h>
+#include "common/file_util.h"
 #include "common/math_util.h"
 #include "core/perf_stats.h"
 #include "core/settings.h"
@@ -15,8 +21,31 @@ using DoubleSecs = std::chrono::duration<double, std::chrono::seconds::period>;
 using std::chrono::duration_cast;
 using std::chrono::microseconds;
 
+// Purposefully ignore the first five frames, as there's a significant amount of overhead in
+// booting that we shouldn't account for
+constexpr std::size_t IgnoreFrames = 5;
+
 namespace Core {
 
+PerfStats::PerfStats(u64 title_id) : title_id(title_id) {}
+
+PerfStats::~PerfStats() {
+    if (!Settings::values.record_frame_times || title_id == 0) {
+        return;
+    }
+
+    const std::time_t t = std::time(nullptr);
+    std::ostringstream stream;
+    std::copy(perf_history.begin() + IgnoreFrames, perf_history.begin() + current_index,
+              std::ostream_iterator<double>(stream, "\n"));
+    const std::string& path = FileUtil::GetUserPath(FileUtil::UserPath::LogDir);
+    // %F Date format expanded is "%Y-%m-%d"
+    const std::string filename =
+        fmt::format("{}/{:%F-%H-%M}_{:016X}.csv", path, *std::localtime(&t), title_id);
+    FileUtil::IOFile file(filename, "w");
+    file.WriteString(stream.str());
+}
+
 void PerfStats::BeginSystemFrame() {
     std::lock_guard lock{object_mutex};
 
@@ -27,7 +56,12 @@ void PerfStats::EndSystemFrame() {
     std::lock_guard lock{object_mutex};
 
     auto frame_end = Clock::now();
-    accumulated_frametime += frame_end - frame_begin;
+    const auto frame_time = frame_end - frame_begin;
+    if (current_index < perf_history.size()) {
+        perf_history[current_index++] =
+            std::chrono::duration<double, std::milli>(frame_time).count();
+    }
+    accumulated_frametime += frame_time;
     system_frames += 1;
 
     previous_frame_length = frame_end - previous_frame_end;
@@ -40,6 +74,17 @@ void PerfStats::EndGameFrame() {
     game_frames += 1;
 }
 
+double PerfStats::GetMeanFrametime() {
+    std::lock_guard lock{object_mutex};
+
+    if (current_index <= IgnoreFrames) {
+        return 0;
+    }
+    const double sum = std::accumulate(perf_history.begin() + IgnoreFrames,
+                                       perf_history.begin() + current_index, 0);
+    return sum / (current_index - IgnoreFrames);
+}
+
 PerfStatsResults PerfStats::GetAndResetStats(microseconds current_system_time_us) {
     std::lock_guard lock{object_mutex};
 

src/core/perf_stats.h

@@ -4,7 +4,9 @@
 
 #pragma once
 
+#include <array>
 #include <chrono>
+#include <cstddef>
 #include <mutex>
 #include "common/common_types.h"
 
@@ -27,6 +29,10 @@ struct PerfStatsResults {
  */
 class PerfStats {
 public:
+    explicit PerfStats(u64 title_id);
+
+    ~PerfStats();
+
     using Clock = std::chrono::high_resolution_clock;
 
     void BeginSystemFrame();
@@ -35,6 +41,11 @@ public:
 
     PerfStatsResults GetAndResetStats(std::chrono::microseconds current_system_time_us);
 
+    /**
+     * Returns the Arthimetic Mean of all frametime values stored in the performance history.
+     */
+    double GetMeanFrametime();
+
     /**
      * Gets the ratio between walltime and the emulated time of the previous system frame. This is
      * useful for scaling inputs or outputs moving between the two time domains.
@@ -42,7 +53,15 @@ public:
     double GetLastFrameTimeScale();
 
 private:
-    std::mutex object_mutex;
+    std::mutex object_mutex{};
+
+    /// Title ID for the game that is running. 0 if there is no game running yet
+    u64 title_id{0};
+    /// Current index for writing to the perf_history array
+    std::size_t current_index{0};
+    /// Stores an hour of historical frametime data useful for processing and tracking performance
+    /// regressions with code changes.
+    std::array<double, 216000> perf_history = {};
 
     /// Point when the cumulative counters were reset
     Clock::time_point reset_point = Clock::now();

src/core/settings.h

@@ -409,6 +409,7 @@ struct Values {
     float volume;
 
     // Debugging
+    bool record_frame_times;
     bool use_gdbstub;
     u16 gdbstub_port;
     std::string program_args;

src/video_core/engines/shader_bytecode.h

@@ -949,6 +949,11 @@ union Instruction {
         BitField<49, 3, PredCondition> cond;
     } isetp;
 
+    union {
+        BitField<48, 1, u64> is_signed;
+        BitField<49, 3, PredCondition> cond;
+    } icmp;
+
     union {
         BitField<0, 3, u64> pred0;
         BitField<3, 3, u64> pred3;
@@ -1645,6 +1650,10 @@ public:
         SEL_C,
         SEL_R,
         SEL_IMM,
+        ICMP_RC,
+        ICMP_R,
+        ICMP_CR,
+        ICMP_IMM,
         MUFU,  // Multi-Function Operator
         RRO_C, // Range Reduction Operator
         RRO_R,
@@ -1910,6 +1919,10 @@ private:
             INST("0100110010100---", Id::SEL_C, Type::ArithmeticInteger, "SEL_C"),
             INST("0101110010100---", Id::SEL_R, Type::ArithmeticInteger, "SEL_R"),
             INST("0011100-10100---", Id::SEL_IMM, Type::ArithmeticInteger, "SEL_IMM"),
+            INST("010100110100----", Id::ICMP_RC, Type::ArithmeticInteger, "ICMP_RC"),
+            INST("010110110100----", Id::ICMP_R, Type::ArithmeticInteger, "ICMP_R"),
+            INST("010010110100----", Id::ICMP_CR, Type::ArithmeticInteger, "ICMP_CR"),
+            INST("0011011-0100----", Id::ICMP_IMM, Type::ArithmeticInteger, "ICMP_IMM"),
             INST("0101101111011---", Id::LEA_R2, Type::ArithmeticInteger, "LEA_R2"),
             INST("0101101111010---", Id::LEA_R1, Type::ArithmeticInteger, "LEA_R1"),
             INST("001101101101----", Id::LEA_IMM, Type::ArithmeticInteger, "LEA_IMM"),

src/video_core/shader/decode/arithmetic_integer.cpp

@@ -138,6 +138,35 @@ u32 ShaderIR::DecodeArithmeticInteger(NodeBlock& bb, u32 pc) {
         SetRegister(bb, instr.gpr0, value);
         break;
     }
+    case OpCode::Id::ICMP_CR:
+    case OpCode::Id::ICMP_R:
+    case OpCode::Id::ICMP_RC:
+    case OpCode::Id::ICMP_IMM: {
+        const Node zero = Immediate(0);
+
+        const auto [op_b, test] = [&]() -> std::pair<Node, Node> {
+            switch (opcode->get().GetId()) {
+            case OpCode::Id::ICMP_CR:
+                return {GetConstBuffer(instr.cbuf34.index, instr.cbuf34.offset),
+                        GetRegister(instr.gpr39)};
+            case OpCode::Id::ICMP_R:
+                return {GetRegister(instr.gpr20), GetRegister(instr.gpr39)};
+            case OpCode::Id::ICMP_RC:
+                return {GetRegister(instr.gpr39),
+                        GetConstBuffer(instr.cbuf34.index, instr.cbuf34.offset)};
+            case OpCode::Id::ICMP_IMM:
+                return {Immediate(instr.alu.GetSignedImm20_20()), GetRegister(instr.gpr39)};
+            default:
+                UNREACHABLE();
+                return {zero, zero};
+            }
+        }();
+        const Node op_a = GetRegister(instr.gpr8);
+        const Node comparison =
+            GetPredicateComparisonInteger(instr.icmp.cond, instr.icmp.is_signed != 0, test, zero);
+        SetRegister(bb, instr.gpr0, Operation(OperationCode::Select, comparison, op_a, op_b));
+        break;
+    }
     case OpCode::Id::LOP_C:
     case OpCode::Id::LOP_R:
     case OpCode::Id::LOP_IMM: {

src/yuzu/configuration/config.cpp

@@ -466,6 +466,9 @@ void Config::ReadDataStorageValues() {
 void Config::ReadDebuggingValues() {
     qt_config->beginGroup(QStringLiteral("Debugging"));
 
+    // Intentionally not using the QT default setting as this is intended to be changed in the ini
+    Settings::values.record_frame_times =
+        qt_config->value(QStringLiteral("record_frame_times"), false).toBool();
     Settings::values.use_gdbstub = ReadSetting(QStringLiteral("use_gdbstub"), false).toBool();
     Settings::values.gdbstub_port = ReadSetting(QStringLiteral("gdbstub_port"), 24689).toInt();
     Settings::values.program_args =
@@ -879,6 +882,8 @@ void Config::SaveDataStorageValues() {
 void Config::SaveDebuggingValues() {
     qt_config->beginGroup(QStringLiteral("Debugging"));
 
+    // Intentionally not using the QT default setting as this is intended to be changed in the ini
+    qt_config->setValue(QStringLiteral("record_frame_times"), Settings::values.record_frame_times);
     WriteSetting(QStringLiteral("use_gdbstub"), Settings::values.use_gdbstub, false);
     WriteSetting(QStringLiteral("gdbstub_port"), Settings::values.gdbstub_port, 24689);
     WriteSetting(QStringLiteral("program_args"),

src/yuzu/main.cpp

@@ -54,6 +54,7 @@ static FileSys::VirtualFile VfsDirectoryCreateFileWrapper(const FileSys::Virtual
 #include <QProgressDialog>
 #include <QShortcut>
 #include <QStatusBar>
+#include <QSysInfo>
 #include <QtConcurrent/QtConcurrent>
 
 #include <fmt/format.h>
@@ -66,6 +67,9 @@ static FileSys::VirtualFile VfsDirectoryCreateFileWrapper(const FileSys::Virtual
 #include "common/microprofile.h"
 #include "common/scm_rev.h"
 #include "common/scope_exit.h"
+#ifdef ARCHITECTURE_x86_64
+#include "common/x64/cpu_detect.h"
+#endif
 #include "common/telemetry.h"
 #include "core/core.h"
 #include "core/crypto/key_manager.h"
@@ -205,6 +209,10 @@ GMainWindow::GMainWindow()
 
     LOG_INFO(Frontend, "yuzu Version: {} | {}-{}", Common::g_build_fullname, Common::g_scm_branch,
              Common::g_scm_desc);
+#ifdef ARCHITECTURE_x86_64
+    LOG_INFO(Frontend, "Host CPU: {}", Common::GetCPUCaps().cpu_string);
+#endif
+    LOG_INFO(Frontend, "Host OS: {}", QSysInfo::prettyProductName().toStdString());
     UpdateWindowTitle();
 
     show();

src/yuzu_cmd/config.cpp

@@ -374,6 +374,8 @@ void Config::ReadValues() {
     Settings::values.use_dev_keys = sdl2_config->GetBoolean("Miscellaneous", "use_dev_keys", false);
 
     // Debugging
+    Settings::values.record_frame_times =
+        sdl2_config->GetBoolean("Debugging", "record_frame_times", false);
     Settings::values.use_gdbstub = sdl2_config->GetBoolean("Debugging", "use_gdbstub", false);
     Settings::values.gdbstub_port =
         static_cast<u16>(sdl2_config->GetInteger("Debugging", "gdbstub_port", 24689));

src/yuzu_cmd/default_ini.h

@@ -213,6 +213,8 @@ region_value =
 log_filter = *:Trace
 
 [Debugging]
+# Record frame time data, can be found in the log directory. Boolean value
+record_frame_times =
 # Port for listening to GDB connections.
 use_gdbstub=false
 gdbstub_port=24689