Log last PPU HLE function executed after access violation

Utilities/Thread.cpp

@@ -1408,8 +1408,9 @@ bool handle_access_violation(u32 addr, bool is_writing, x64_context* context)
 			return true;
 		}
 
-		if (cpu->id_type() == 2)
+		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:
@@ -1436,13 +1437,24 @@ bool handle_access_violation(u32 addr, bool is_writing, x64_context* context)
 		}
 		else
 		{
+			if (auto last_func = static_cast<ppu_thread*>(cpu)->current_function)
+			{
+				LOG_FATAL(PPU, "Function aborted: %s", last_func);
+			}
+
 			lv2_obj::sleep(*cpu);
 		}
 	}
 
-	LOG_FATAL(MEMORY, "Access violation %s location 0x%x", is_writing ? "writing" : "reading", addr);
 	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())
 	{
 		thread_ctrl::wait();

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;
 			}
 

rpcs3/Emu/CPU/CPUThread.h

@@ -62,13 +62,13 @@ class cpu_thread
 	}
 
 	// 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));
 	}

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_function_t>([](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;\

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,27 +842,27 @@ 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
 		{
 			state -= cpu_flag::ret;
 			cia = old_cia;
 			gpr[2] = old_rtoc;
 			lr = old_lr;
-			last_function = old_func;
+			current_function = old_func;
 			g_tls_log_prefix = old_fmt;
 		}
 	});

rpcs3/Emu/Cell/PPUThread.h

@@ -180,7 +180,8 @@ class ppu_thread : public cpu_thread
 	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<std::string> ppu_name; // Thread name
 

rpcs3/Emu/Cell/SPUThread.cpp

@@ -1027,32 +1027,32 @@ void spu_thread::cpu_init()
 	ch_tag_upd = 0;
 	ch_tag_mask = 0;
 	mfc_prxy_mask = 0;
-	ch_tag_stat.data.release({});
+	ch_tag_stat.data.raw() = {};
 	ch_stall_mask = 0;
-	ch_stall_stat.data.release({});
-	ch_atomic_stat.data.release({});
+	ch_stall_stat.data.raw() = {};
+	ch_atomic_stat.data.raw() = {};
 
 	ch_in_mbox.clear();
 
-	ch_out_mbox.data.release({});
-	ch_out_intr_mbox.data.release({});
+	ch_out_mbox.data.raw() = {};
+	ch_out_intr_mbox.data.raw() = {};
 
 	snr_config = 0;
 
-	ch_snr1.data.release({});
-	ch_snr2.data.release({});
+	ch_snr1.data.raw() = {};
+	ch_snr2.data.raw() = {};
 
-	ch_event_mask = 0;
-	ch_event_stat = 0;
-	interrupts_enabled = false;
+	ch_event_mask.raw() = 0;
+	ch_event_stat.raw() = 0;
+	interrupts_enabled.raw() = false;
 	raddr = 0;
 
 	ch_dec_start_timestamp = get_timebased_time(); // ???
 	ch_dec_value = 0;
 
-	run_ctrl.release(0);
-	status.release(0);
-	npc.release(0);
+	run_ctrl.raw() = 0;
+	status.raw() = 0;
+	npc.raw() = 0;
 
 	int_ctrl[0].clear();
 	int_ctrl[1].clear();
@@ -1488,6 +1488,7 @@ bool spu_thread::do_dma_check(const spu_mfc_cmd& args)
 				if ((mfc_queue[i].cmd & ~0xc) == MFC_BARRIER_CMD)
 				{
 					mfc_barrier |= -1;
+					mfc_fence |= utils::rol32(1, mfc_queue[i].tag);
 					continue;
 				}
 
@@ -1657,6 +1658,9 @@ void spu_thread::do_mfc(bool wait)
 	// Process enqueued commands
 	std::remove_if(mfc_queue + 0, mfc_queue + mfc_size, [&](spu_mfc_cmd& args)
 	{
+		// Select tag bit in the tag mask or the stall mask
+		const u32 mask = utils::rol32(1, args.tag);
+
 		if ((args.cmd & ~0xc) == MFC_BARRIER_CMD)
 		{
 			if (&args - mfc_queue <= removed)
@@ -1669,12 +1673,10 @@ void spu_thread::do_mfc(bool wait)
 
 			// Block all tags
 			barrier |= -1;
+			fence |= mask;
 			return false;
 		}
 
-		// Select tag bit in the tag mask or the stall mask
-		const u32 mask = utils::rol32(1, args.tag);
-
 		if (barrier & mask)
 		{
 			fence |= mask;
@@ -2092,6 +2094,7 @@ bool spu_thread::process_mfc_cmd()
 		{
 			mfc_queue[mfc_size++] = ch_mfc_cmd;
 			mfc_barrier |= -1;
+			mfc_fence |= utils::rol32(1, ch_mfc_cmd.tag);
 		}
 
 		return true;

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<ppu_thread&>(*thread);
 
-			if (ppu.last_function)
+			if (ppu.current_function)
 			{
-				func = ppu.last_function;
+				func = ppu.current_function;
 			}
 		}
 	}