From 537d3f25487e025cb197fed15ebc64e74c7cf9a9 Mon Sep 17 00:00:00 2001 From: Eladash Date: Tue, 9 Jul 2019 20:44:07 +0300 Subject: [PATCH] Log last function on debug pause or exception, dump cpu_thread state on access violation --- Utilities/Thread.cpp | 7 +++++++ rpcs3/Emu/CPU/CPUThread.cpp | 2 +- rpcs3/Emu/CPU/CPUThread.h | 4 ++-- rpcs3/Emu/Cell/PPUFunction.h | 7 ++++--- rpcs3/Emu/Cell/PPUThread.cpp | 28 +++++++++++++++++++--------- rpcs3/Emu/Cell/PPUThread.h | 3 ++- rpcs3/Emu/System.cpp | 4 ++-- 7 files changed, 37 insertions(+), 18 deletions(-) diff --git a/Utilities/Thread.cpp b/Utilities/Thread.cpp index 9797915077..912507b7d5 100644 --- a/Utilities/Thread.cpp +++ b/Utilities/Thread.cpp @@ -1410,6 +1410,7 @@ bool handle_access_violation(u32 addr, bool is_writing, x64_context* context) if (cpu->id_type() != 1) { + LOG_NOTICE(GENERAL, "\n%s", cpu->dump()); LOG_FATAL(MEMORY, "Access violation %s location 0x%x", is_writing ? "writing" : "reading", addr); // TODO: @@ -1446,6 +1447,12 @@ bool handle_access_violation(u32 addr, bool is_writing, x64_context* context) } Emu.Pause(); + + if (cpu) + { + LOG_NOTICE(GENERAL, "\n%s", cpu->dump()); + } + LOG_FATAL(MEMORY, "Access violation %s location 0x%x", is_writing ? "writing" : "reading", addr); while (Emu.IsPaused()) diff --git a/rpcs3/Emu/CPU/CPUThread.cpp b/rpcs3/Emu/CPU/CPUThread.cpp index 28bf53a323..898acfdfed 100644 --- a/rpcs3/Emu/CPU/CPUThread.cpp +++ b/rpcs3/Emu/CPU/CPUThread.cpp @@ -153,9 +153,9 @@ void cpu_thread::operator()() } catch (const std::exception& e) { + Emu.Pause(); LOG_FATAL(GENERAL, "%s thrown: %s", typeid(e).name(), e.what()); LOG_NOTICE(GENERAL, "\n%s", dump()); - Emu.Pause(); break; } diff --git a/rpcs3/Emu/CPU/CPUThread.h b/rpcs3/Emu/CPU/CPUThread.h index a1f3af46e9..7bc69f9ac9 100644 --- a/rpcs3/Emu/CPU/CPUThread.h +++ b/rpcs3/Emu/CPU/CPUThread.h @@ -62,13 +62,13 @@ public: } // Test stopped state - bool is_stopped() + bool is_stopped() const { return !!(state & (cpu_flag::stop + cpu_flag::exit + cpu_flag::jit_return + cpu_flag::dbg_global_stop)); } // Test paused state - bool is_paused() + bool is_paused() const { return !!(state & (cpu_flag::suspend + cpu_flag::dbg_global_pause + cpu_flag::dbg_pause)); } diff --git a/rpcs3/Emu/Cell/PPUFunction.h b/rpcs3/Emu/Cell/PPUFunction.h index 0e476af4bc..d8cacce8e9 100644 --- a/rpcs3/Emu/Cell/PPUFunction.h +++ b/rpcs3/Emu/Cell/PPUFunction.h @@ -6,10 +6,11 @@ using ppu_function_t = bool(*)(ppu_thread&); // BIND_FUNC macro "converts" any appropriate HLE function to ppu_function_t, binding it to PPU thread context. #define BIND_FUNC(func, ...) (static_cast([](ppu_thread& ppu) -> bool {\ - const auto old_f = ppu.last_function;\ - ppu.last_function = #func;\ + const auto old_f = ppu.current_function;\ + if (!old_f) ppu.last_function = #func;\ + ppu.current_function = #func;\ ppu_func_detail::do_call(ppu, func);\ - ppu.last_function = old_f;\ + ppu.current_function = old_f;\ ppu.cia += 4;\ __VA_ARGS__;\ return false;\ diff --git a/rpcs3/Emu/Cell/PPUThread.cpp b/rpcs3/Emu/Cell/PPUThread.cpp index 6e1d19e376..384664a2b0 100644 --- a/rpcs3/Emu/Cell/PPUThread.cpp +++ b/rpcs3/Emu/Cell/PPUThread.cpp @@ -448,14 +448,24 @@ std::string ppu_thread::dump() const fmt::append(ret, "Joiner: %s\n", join_status(joiner.load())); fmt::append(ret, "Commands: %u\n", cmd_queue.size()); - const auto _func = last_function; + const char* _func = current_function; if (_func) { - ret += "Last function: "; + ret += "Current function: "; ret += _func; ret += '\n'; } + else if (is_paused()) + { + if (const auto last_func = last_function) + { + _func = last_func; + ret += "Last function: "; + ret += _func; + ret += '\n'; + } + } if (const auto _time = start_time) { @@ -814,13 +824,13 @@ void ppu_thread::fast_call(u32 addr, u32 rtoc) const auto old_cia = cia; const auto old_rtoc = gpr[2]; const auto old_lr = lr; - const auto old_func = last_function; + const auto old_func = current_function; const auto old_fmt = g_tls_log_prefix; cia = addr; gpr[2] = rtoc; lr = ppu_function_manager::addr + 8; // HLE stop address - last_function = nullptr; + current_function = nullptr; g_tls_log_prefix = [] { @@ -832,19 +842,19 @@ void ppu_thread::fast_call(u32 addr, u32 rtoc) { if (std::uncaught_exceptions()) { - if (last_function) + if (current_function) { if (start_time) { - LOG_WARNING(PPU, "'%s' aborted (%fs)", last_function, (get_system_time() - start_time) / 1000000.); + LOG_WARNING(PPU, "'%s' aborted (%fs)", current_function, (get_system_time() - start_time) / 1000000.); } else { - LOG_WARNING(PPU, "'%s' aborted", last_function); + LOG_WARNING(PPU, "'%s' aborted", current_function); } } - last_function = old_func; + current_function = old_func; } else { @@ -852,7 +862,7 @@ void ppu_thread::fast_call(u32 addr, u32 rtoc) cia = old_cia; gpr[2] = old_rtoc; lr = old_lr; - last_function = old_func; + current_function = old_func; g_tls_log_prefix = old_fmt; } }); diff --git a/rpcs3/Emu/Cell/PPUThread.h b/rpcs3/Emu/Cell/PPUThread.h index e4f4fb9184..d96998d7a9 100644 --- a/rpcs3/Emu/Cell/PPUThread.h +++ b/rpcs3/Emu/Cell/PPUThread.h @@ -180,7 +180,8 @@ public: cmd64 cmd_get(u32 index) { return cmd_queue[cmd_queue.peek() + index].load(); } u64 start_time{0}; // Sleep start timepoint - const char* last_function{}; // Last function name for diagnosis, optimized for speed. + const char* current_function{}; // Current function name for diagnosis, optimized for speed. + const char* last_function{}; // Sticky copy of current_function, is not cleared on function return lf_value ppu_name; // Thread name diff --git a/rpcs3/Emu/System.cpp b/rpcs3/Emu/System.cpp index 723ca8ea1c..29e86d1628 100644 --- a/rpcs3/Emu/System.cpp +++ b/rpcs3/Emu/System.cpp @@ -1744,9 +1744,9 @@ s32 error_code::error_report(const fmt_type_info* sup, u64 arg, const fmt_type_i { auto& ppu = static_cast(*thread); - if (ppu.last_function) + if (ppu.current_function) { - func = ppu.last_function; + func = ppu.current_function; } } }