nx2: measure the TSC on AMD, no rethrows for rejected shaders, debug hooks off the hot path

- AMD CPUs have no CPUID leaf 0x15, so the TSC frequency stayed 0 and
  every guest CNTPCT read went through QueryPerformanceCounter (~10% of
  the game's main core in title 1). Measure it like Intel CPUs without
  a crystal frequency.
- A rejected native shader was rethrown (two C++ throws) every time it
  was bound; return false instead (~1-2% of the GPU thread).
- The semaphore watch, pushbuffer entry hashing, first-write trace and
  per-macro debug logs ran on every command word or macro call; they
  now cost a flag check unless their environment variable is set
  (~4% of the GPU thread). Also starts the macro engine's profile zone.

6 files changed, 54 insertions, 13 deletions

diff --git a/src/common/cpu_features.cpp b/src/common/cpu_features.cpp
index 8ccb6847f7..52fd003c44 100644
--- a/src/common/cpu_features.cpp
+++ b/src/common/cpu_features.cpp
@@ -225,6 +225,13 @@ const CPUCaps g_cpu_caps = [] {
         }
     }
 
+    // AMD CPUs have no leaf 0x15 (Zen 4 stops at 0x10): measure their invariant TSC too, or every
+    // guest clock read (CNTPCT, which games read thousands of times a frame) goes through the
+    // host's much slower QueryPerformanceCounter.
+    if (caps.invariant_tsc && caps.tsc_frequency == 0) {
+        caps.tsc_frequency = X64::EstimateRDTSCFrequency();
+    }
+
     if (max_std_fn >= 0x16) {
         __cpuid(cpu_id, 0x16);
         caps.base_frequency = cpu_id[0];
diff --git a/src/video_core/dma_pusher.cpp b/src/video_core/dma_pusher.cpp
index a1d9ef3f91..3cc5afe967 100644
--- a/src/video_core/dma_pusher.cpp
+++ b/src/video_core/dma_pusher.cpp
@@ -299,19 +299,26 @@ void DmaPusher::SetState(const CommandHeader& command_header) {
 
 // EDEN_NX2_SEM_WATCH=<gpu address>: log every method whose argument is the low word of an
 // address in the 16 bytes there (finds the engine and method that release a semaphore).
+static const u32 g_semaphore_watch = [] {
+    const char* value = std::getenv("EDEN_NX2_SEM_WATCH");
+    return value ? static_cast<u32>(std::strtoull(value, nullptr, 16)) : 0U;
+}();
+
+// EDEN_NX2_PB_CHECK also keeps the last parsed entries, for DumpCurrentEntry.
+static const bool g_record_parsed_entries = std::getenv("EDEN_NX2_PB_CHECK") != nullptr;
+
 void DmaPusher::WatchArgument(u32 method, u32 argument) const {
-    static const u32 watch = [] {
-        const char* value = std::getenv("EDEN_NX2_SEM_WATCH");
-        return value ? static_cast<u32>(std::strtoull(value, nullptr, 16)) : 0U;
-    }();
-    if (watch != 0 && (argument & ~0xfU) == watch) {
+    const u32 watch = g_semaphore_watch;
+    if ((argument & ~0xfU) == watch) {
         LOG_INFO(HW_GPU, "Semaphore watch: channel {} subchannel {} method {:#x} argument {:#x}",
                  channel_state.bind_id, dma_state.subchannel, method, argument);
     }
 }
 
 void DmaPusher::CallMethod(u32 argument) {
-    WatchArgument(dma_state.method, argument);
+    if (g_semaphore_watch != 0) [[unlikely]] {
+        WatchArgument(dma_state.method, argument);
+    }
     if (dma_state.method < non_puller_methods) {
         puller.CallPullerMethod(*this, Engines::Puller::MethodCall{
             dma_state.method,
@@ -336,8 +343,10 @@ void DmaPusher::CallMethod(u32 argument) {
 }
 
 void DmaPusher::CallMultiMethod(const u32* base_start, u32 num_methods) {
-    for (u32 i = 0; i < num_methods; ++i) {
-        WatchArgument(dma_state.method + (dma_state.non_incrementing ? 0 : i), base_start[i]);
+    if (g_semaphore_watch != 0) [[unlikely]] {
+        for (u32 i = 0; i < num_methods; ++i) {
+            WatchArgument(dma_state.method + (dma_state.non_incrementing ? 0 : i), base_start[i]);
+        }
     }
     if (dma_state.method < non_puller_methods) {
         puller.CallMultiMethod(*this, dma_state.method, dma_state.subchannel, base_start, num_methods, dma_state.method_count);
@@ -382,6 +391,9 @@ void DmaPusher::CheckSubmitHash(const CommandListHeader& header, u64 submit_hash
 
 void DmaPusher::RecordParsedEntry(const CommandListHeader& header,
                                   std::span<const CommandHeader> commands) {
+    if (!g_record_parsed_entries) {
+        return;
+    }
     u64 hash = 0xcbf29ce484222325ULL;
     for (const CommandHeader& command : commands) {
         hash = (hash ^ command.argument) * 0x100000001b3ULL;
diff --git a/src/video_core/engines/maxwell_3d.cpp b/src/video_core/engines/maxwell_3d.cpp
index 7884d8009c..60efef9b8e 100644
--- a/src/video_core/engines/maxwell_3d.cpp
+++ b/src/video_core/engines/maxwell_3d.cpp
@@ -393,10 +393,11 @@ void Maxwell3D::CallMacroMethod(Core::System& system, u32 method, const std::vec
 }
 
 // EDEN_NX2_3D_METHODS: log the first write to each 3D register (finds methods Eden doesn't model).
+static const bool g_trace_first_method_writes = std::getenv("EDEN_NX2_3D_METHODS") != nullptr;
+
 void Maxwell3D::TraceFirstMethodWrite(u32 method, u32 argument) {
-    static const bool trace = std::getenv("EDEN_NX2_3D_METHODS") != nullptr;
     static std::array<bool, Regs::NUM_REGS> seen{};
-    if (trace && method < seen.size() && !seen[method]) {
+    if (method < seen.size() && !seen[method]) {
         seen[method] = true;
         LOG_INFO(HW_GPU, "3D method first write: {:#x} (byte {:#x}) = {:#x}", method, method * 4, argument);
     }
@@ -419,7 +420,9 @@ void Maxwell3D::CallMethod(Core::System& system, u32 method, u32 method_argument
         ProcessMacro(system, method, &method_argument, 1, is_last_call);
         return;
     }
-    TraceFirstMethodWrite(method, method_argument);
+    if (g_trace_first_method_writes) [[unlikely]] {
+        TraceFirstMethodWrite(method, method_argument);
+    }
 
     ASSERT(method < Regs::NUM_REGS && "Invalid Maxwell3D register, increase the size of the Regs structure");
     const u32 argument = ProcessShadowRam(method, method_argument);
diff --git a/src/video_core/macro.cpp b/src/video_core/macro.cpp
index d3ba353ca0..c74cd6087a 100644
--- a/src/video_core/macro.cpp
+++ b/src/video_core/macro.cpp
@@ -36,6 +36,7 @@
 #include "common/bit_field.h"
 #include "common/logging.h"
 #include "video_core/engines/maxwell_3d.h"
+#include "video_core/nx2_profile.h"
 
 namespace Tegra {
 
@@ -1343,6 +1344,7 @@ static void Dump(u64 hash, std::span<const u32> code, bool decompiled = false) {
 
 void MacroEngine::Execute(Core::System& system, Engines::Maxwell3D& maxwell3d, u32 method,
                           std::span<const u32> parameters) {
+    VideoCommon::Nx2Profile::Scope profile_scope{VideoCommon::Nx2Profile::Zone::Macro};
     if (native_turing) {
         maxwell3d.RefreshParameters();
         const auto context = reinterpret_cast<std::uintptr_t>(this);
@@ -1352,8 +1354,11 @@ void MacroEngine::Execute(Core::System& system, Engines::Maxwell3D& maxwell3d, u
             std::ofstream dump("native-graphics-mme-" + std::to_string(context) + ".bin", std::ios::binary);
             dump.write(reinterpret_cast<const char*>(native_code.data()), sizeof(native_code));
         }
-        LOG_DEBUG(HW_GPU, "Native MME context={:#x}", context);
-        LOG_DEBUG(HW_GPU, "Native MME start={:#x}, parameters={}, data={:08x}", method, parameters.size(), fmt::join(parameters, ","));
+        // EDEN_NX2_MME_LOG: log every macro call (runs ~750,000 times a second in title 1).
+        if (static const bool log_calls = std::getenv("EDEN_NX2_MME_LOG") != nullptr; log_calls) {
+            LOG_DEBUG(HW_GPU, "Native MME context={:#x}", context);
+            LOG_DEBUG(HW_GPU, "Native MME start={:#x}, parameters={}, data={:08x}", method, parameters.size(), fmt::join(parameters, ","));
+        }
         // Reused between calls (a macro never calls another: methods >= 0xe00 are refused below).
         auto& fifo = native_fifo;
         fifo.assign(parameters.begin(), parameters.end());
diff --git a/src/video_core/shader_cache.cpp b/src/video_core/shader_cache.cpp
index da5417be02..73a2bf6646 100644
--- a/src/video_core/shader_cache.cpp
+++ b/src/video_core/shader_cache.cpp
@@ -79,6 +79,13 @@ bool ShaderCache::RefreshStages(std::array<u64, 6>& unique_hashes) try {
             return false;
         }
         const ShaderInfo* shader_info{TryGet(*cpu_shader_addr)};
+        if (!shader_info && native && IsRejected(*cpu_shader_addr)) {
+            // A rejected program fails the same way every time it is bound: skip its draws
+            // without rethrowing (two C++ throws each time cost ~1-2% of the GPU thread).
+            maxwell3d->GetNativeMacroEngine().native_execution_failed = true;
+            last_shaders_valid = false;
+            return false;
+        }
         if (!shader_info) {
             const u32 start_address{native ? 0 : shader_config.offset};
             try {
@@ -165,6 +172,11 @@ void ShaderCache::RethrowIfRejected(VAddr addr) {
     }
 }
 
+bool ShaderCache::IsRejected(VAddr addr) {
+    std::scoped_lock lock{rejected_mutex};
+    return rejected_native.contains(addr);
+}
+
 void ShaderCache::RememberRejection(VAddr addr) {
     std::scoped_lock lock{rejected_mutex};
     rejected_native.emplace(addr, std::current_exception());
diff --git a/src/video_core/shader_cache.h b/src/video_core/shader_cache.h
index eac2c5ba75..9ffb7bb44d 100644
--- a/src/video_core/shader_cache.h
+++ b/src/video_core/shader_cache.h
@@ -146,6 +146,8 @@ private:
 
     /// Rethrows the error a native program at this address was rejected with, if any.
     void RethrowIfRejected(VAddr addr);
+    /// Whether a native program at this address was rejected.
+    bool IsRejected(VAddr addr);
     /// Remembers the exception being handled as this address's rejection.
     void RememberRejection(VAddr addr);