Merge branch 'master' into virtual_g27

rpcs3/Emu/Cell/Modules/cellAudio.cpp

@@ -301,7 +301,7 @@ void audio_ringbuffer::commit_data(f32* buf, u32 sample_cnt)
 	if (g_recording_mode != recording_mode::stopped)
 	{
 		utils::video_provider& provider = g_fxo->get<utils::video_provider>();
-		provider.present_samples(reinterpret_cast<u8*>(buf), sample_cnt, cfg.audio_channels);
+		provider.present_samples(reinterpret_cast<const u8*>(buf), sample_cnt, cfg.audio_channels);
 	}
 
 	// Downmix if necessary

rpcs3/Emu/Cell/Modules/cellSysutil.cpp

@@ -580,8 +580,6 @@ error_code cellSysutilCheckCallback(ppu_thread& ppu)
 
 	auto& cbm = g_fxo->get<sysutil_cb_manager>();
 
-	bool read = false;
-
 	for (auto&& func : cbm.registered.pop_all())
 	{
 		if (func.call_active && !*func.call_active)
@@ -589,7 +587,11 @@ error_code cellSysutilCheckCallback(ppu_thread& ppu)
 			continue;
 		}
 
-		read = true;
+		// Increase read counter before we call the callback.
+		// We use this counter to check if the game reacts to a command during game termination and calls sys_process_exit.
+		// We would not realize that the game reacted in time and terminate it prematurely if we increased
+		// the counter after we called the callback and the callback did some time-consuming work.
+		cbm.read_counter++;
 
 		if (s32 res = func.func(ppu))
 		{
@@ -603,11 +605,6 @@ error_code cellSysutilCheckCallback(ppu_thread& ppu)
 		}
 	}
 
-	if (read)
-	{
-		cbm.read_counter++;
-	}
-
 	return CELL_OK;
 }
 

rpcs3/Emu/Cell/lv2/sys_rsxaudio.cpp

@@ -1858,7 +1858,7 @@ u32 rsxaudio_backend_thread::write_data_callback(u32 bytes, void* buf)
 		if (g_recording_mode != recording_mode::stopped)
 		{
 			utils::video_provider& provider = g_fxo->get<utils::video_provider>();
-			provider.present_samples(reinterpret_cast<u8*>(callback_tmp_buf.data()), sample_cnt / cb_cfg.input_ch_cnt, cb_cfg.input_ch_cnt);
+			provider.present_samples(reinterpret_cast<const u8*>(callback_tmp_buf.data()), sample_cnt / cb_cfg.input_ch_cnt, cb_cfg.input_ch_cnt);
 		}
 
 		// Downmix if necessary

rpcs3/Emu/RSX/Overlays/HomeMenu/overlay_home_menu_main_menu.cpp

@@ -138,7 +138,7 @@ namespace rsx
 				rsx_log.notice("User selected exit game in home menu");
 				Emu.CallFromMainThread([]
 				{
-					Emu.GracefulShutdown(false, true);
+					Emu.GracefulShutdown(true, true);
 				});
 				return page_navigation::stay;
 			});

rpcs3/Emu/RSX/VK/VKRenderTargets.h

@@ -683,4 +683,3 @@ namespace vk
 		void trim(vk::command_buffer& cmd, rsx::problem_severity memory_pressure);
 	};
 }
-//h

rpcs3/Emu/System.cpp

@@ -2920,8 +2920,20 @@ void Emulator::GracefulShutdown(bool allow_autoexit, bool async_op, bool savesta
 
 	const u64 read_counter = get_sysutil_cb_manager_read_count();
 
-	if (old_state == system_state::frozen || savestate || !sysutil_send_system_cmd(0x0101 /* CELL_SYSUTIL_REQUEST_EXITGAME */, 0))
+	const bool force_termination = old_state == system_state::frozen || savestate;
+
+	if (!force_termination)
 	{
+		sys_log.notice("Requesting game to exit...");
+	}
+
+	if (force_termination || !sysutil_send_system_cmd(0x0101 /* CELL_SYSUTIL_REQUEST_EXITGAME */, 0))
+	{
+		if (!force_termination)
+		{
+			sys_log.warning("The game ignored the exit request. Forcing termination...");
+		}
+
 		// The callback has been rudely ignored, we have no other option but to force termination
 		Kill(allow_autoexit && !savestate, savestate);
 
@@ -2936,15 +2948,20 @@ void Emulator::GracefulShutdown(bool allow_autoexit, bool async_op, bool savesta
 		return;
 	}
 
+	sys_log.notice("The game was requested to exit. Waiting for its reaction...");
+
 	auto perform_kill = [read_counter, allow_autoexit, this, info = GetEmulationIdentifier()]()
 	{
 		bool read_sysutil_signal = false;
 
-		u32 i = 100;
+		// If EXITGAME signal is not read, force kill after a couple of seconds.
+		constexpr int loop_timeout_ms = 50;
+		int kill_timeout_ms = 2000;
+		int elapsed_ms = 0;
 
-		qt_events_aware_op(50, [&]()
+		qt_events_aware_op(loop_timeout_ms, [&]()
 		{
-			if (i >= 140)
+			if (elapsed_ms >= kill_timeout_ms)
 			{
 				return true;
 			}
@@ -2955,9 +2972,11 @@ void Emulator::GracefulShutdown(bool allow_autoexit, bool async_op, bool savesta
 				Resume();
 			}, nullptr, true, read_counter);
 
+			// Check if the EXITGAME signal was read. We allow the game to terminate itself if that's the case.
 			if (!read_sysutil_signal && read_counter != get_sysutil_cb_manager_read_count())
 			{
-				i -= 100; // Grant 5 seconds (if signal is not read force kill after two second)
+				sys_log.notice("The game received the exit request. Waiting for it to terminate itself...");
+				kill_timeout_ms += 5000; // Grant a couple more seconds
 				read_sysutil_signal = true;
 			}
 
@@ -2967,13 +2986,14 @@ void Emulator::GracefulShutdown(bool allow_autoexit, bool async_op, bool savesta
 			}
 
 			// Process events
-			i++;
+			elapsed_ms += loop_timeout_ms;
 			return false;
 		});
 
-		// An inevitable attempt to terminate the *current* emulation course will be issued after 7s
+		// An inevitable attempt to terminate the *current* emulation course will be issued after the timeout was reached.
-		CallFromMainThread([allow_autoexit, this]()
+		CallFromMainThread([this, allow_autoexit, elapsed_ms, read_sysutil_signal]()
 		{
+			sys_log.error("The game did not react to the exit request in time. Terminating manually... (read_sysutil_signal=%d, elapsed_ms=%d)", read_sysutil_signal, elapsed_ms);
 			Kill(allow_autoexit);
 		}, info);
 	};

rpcs3/headless_application.cpp

@@ -12,6 +12,8 @@
 
 #include <clocale>
 
+LOG_CHANNEL(sys_log, "SYS");
+
 [[noreturn]] void report_fatal_error(std::string_view text, bool is_html = false, bool include_help_text = true);
 
 // For now, a trivial constructor/destructor. May add command line usage later.
@@ -56,6 +58,7 @@ void headless_application::InitializeCallbacks()
 				on_exit();
 			}
 
+			sys_log.notice("Quitting headless application");
 			quit();
 			return true;
 		}

rpcs3/main.cpp

@@ -1,6 +1,11 @@
+#include "stdafx.h"
 #include "rpcs3.h"
 
+LOG_CHANNEL(sys_log, "SYS");
+
 int main(int argc, char** argv)
 {
-	return run_rpcs3(argc, argv);
+	const int exit_code = run_rpcs3(argc, argv);
+	sys_log.notice("RPCS3 terminated with exit code %d", exit_code);
+	return exit_code;
 }

rpcs3/rpcs3.cpp

@@ -303,7 +303,7 @@ struct fatal_error_listener final : logs::listener
 public:
 	~fatal_error_listener() override = default;
 
-	void log(u64 /*stamp*/, const logs::message& msg, const std::string& prefix, const std::string& text) override
+	void log(u64 /*stamp*/, const logs::message& msg, std::string_view prefix, std::string_view text) override
 	{
 		if (msg == logs::level::fatal || (msg == logs::level::always && m_log_always))
 		{
@@ -1192,7 +1192,7 @@ int run_rpcs3(int argc, char** argv)
 	}
 	else if (const QStringList args = parser.positionalArguments(); (!args.isEmpty() || !emu_argv.empty()) && !is_updating && !parser.isSet(arg_installfw) && !parser.isSet(arg_installpkg))
 	{
-		const std::string spath = (args.isEmpty() ? emu_argv[0] : ::at32(args, 0).toStdString());
+		std::string spath = (args.isEmpty() ? emu_argv[0] : ::at32(args, 0).toStdString());
 
 		if (spath.starts_with(Emulator::vfs_boot_prefix))
 		{
@@ -1275,8 +1275,13 @@ int run_rpcs3(int argc, char** argv)
 			}
 		}
 
+		if (!spath.starts_with("%RPCS3_"))
+		{
+			spath = QFileInfo(::at32(args, 0)).absoluteFilePath().toStdString();
+		}
+
 		// Postpone startup to main event loop
-		Emu.CallFromMainThread([path = spath.starts_with("%RPCS3_") ? spath : QFileInfo(::at32(args, 0)).absoluteFilePath().toStdString(), rpcs3_argv = std::move(rpcs3_argv), config_path = std::move(config_path)]() mutable
+		Emu.CallFromMainThread([path = std::move(spath), rpcs3_argv = std::move(rpcs3_argv), config_path = std::move(config_path)]() mutable
 		{
 			Emu.argv = std::move(rpcs3_argv);
 			Emu.SetForceBoot(true);

rpcs3/rpcs3qt/gui_application.cpp

@@ -593,6 +593,8 @@ void gui_application::InitializeCallbacks()
 				// Close main window in order to save its window state
 				m_main_window->close();
 			}
+
+			gui_log.notice("Quitting gui application");
 			quit();
 			return true;
 		}

rpcs3/rpcs3qt/log_frame.cpp

@@ -50,7 +50,7 @@ struct gui_listener : logs::listener
 	{
 	}
 
-	void log(u64 stamp, const logs::message& msg, const std::string& prefix, const std::string& text) override
+	void log(u64 stamp, const logs::message& msg, std::string_view prefix, std::string_view text) override
 	{
 		Q_UNUSED(stamp)
 

rpcs3/tests/test_fmt.cpp

@@ -5,7 +5,7 @@ using namespace std::literals::string_literals;
 
 namespace fmt
 {
-	TEST(StrUtil, test_trim)
+	TEST(StrUtil, Trim)
 	{
 		EXPECT_EQ(""s, fmt::trim("", ""));
 		EXPECT_EQ(""s, fmt::trim("", " "));
@@ -25,7 +25,7 @@ namespace fmt
 		EXPECT_EQ("b"s, fmt::trim("    aba    ", " a"));
 	}
 
-	TEST(StrUtil, test_trim_front)
+	TEST(StrUtil, TrimFront)
 	{
 		EXPECT_EQ(""s, fmt::trim_front("", ""));
 		EXPECT_EQ(""s, fmt::trim_front("", " "));
@@ -45,7 +45,7 @@ namespace fmt
 		EXPECT_EQ("ba    "s, fmt::trim_front("    aba    ", " a"));
 	}
 
-	TEST(StrUtil, test_trim_back)
+	TEST(StrUtil, TrimBack)
 	{
 		std::string str;
 		fmt::trim_back(str, "");
@@ -112,7 +112,7 @@ namespace fmt
 		EXPECT_EQ("    ab"s, str);
 	}
 
-	TEST(StrUtil, test_to_upper_to_lower)
+	TEST(StrUtil, ToUpperToLower)
 	{
 		const std::string lowercase = "abcdefghijklmnopqrstuvwxyzäüöß0123456789 .,-<#+";
 		const std::string uppercase = "ABCDEFGHIJKLMNOPQRSTUVWXYZäüöß0123456789 .,-<#+";
@@ -128,7 +128,7 @@ namespace fmt
 		EXPECT_EQ(uppercase, to_upper_res);
 	}
 
-	TEST(StrUtil, test_truncate)
+	TEST(StrUtil, Truncate)
 	{
 		const std::string str = "abcdefghijklmnopqrstuvwxyzäüöß0123456789 .,-<#+";
 
@@ -145,7 +145,7 @@ namespace fmt
 		EXPECT_EQ(str, fmt::truncate(str, str.size() + 1));
 	}
 
-	TEST(StrUtil, test_replace_all)
+	TEST(StrUtil, ReplaceAll)
 	{
 		EXPECT_EQ(""s, fmt::replace_all("", "", ""));
 		EXPECT_EQ(""s, fmt::replace_all("", "", " "));
@@ -191,7 +191,7 @@ namespace fmt
 		EXPECT_EQ("drow drow drow"s, fmt::replace_all("word word word", "word", "drow", -1));
 	}
 
-	TEST(StrUtil, test_split)
+	TEST(StrUtil, Split)
 	{
 		using vec = std::vector<std::string>;
 
@@ -340,7 +340,7 @@ namespace fmt
 		EXPECT_EQ(vec({"This", "is", "test!"}), fmt::split(" This is a test! ", {"a", " ", "b"}, true));
 	}
 
-	TEST(StrUtil, test_merge)
+	TEST(StrUtil, Merge)
 	{
 		using vec = std::vector<std::string>;
 		using lst = std::initializer_list<std::vector<std::string>>;
@@ -413,7 +413,7 @@ namespace fmt
 		EXPECT_EQ("a *-* 1 *-* b *-* 2"s, fmt::merge(lst{vec{"a", "1"}, vec{"b", "2"}}, " *-* "));
 	}
 
-	TEST(StrUtil, test_get_file_extension)
+	TEST(StrUtil, GetFileExtension)
 	{
 		EXPECT_EQ(""s, get_file_extension(""));
 		EXPECT_EQ(""s, get_file_extension("."));
@@ -435,4 +435,28 @@ namespace fmt
 		EXPECT_EQ(""s, get_file_extension("my_file/asd"));
 		EXPECT_EQ("txt"s, get_file_extension("my_file/asd.txt"));
 	}
+
+	TEST(StrUtil, StrcpyTrunc)
+	{
+		char dst[13];
+		std::memset(dst, 'A', sizeof(dst));
+		strcpy_trunc(dst, "");
+		EXPECT_TRUE(std::all_of(dst, dst + sizeof(dst), [](char c){ return c == '\0'; }));
+
+		std::memset(dst, 'A', sizeof(dst));
+		strcpy_trunc(dst, "Hello");
+		EXPECT_EQ('\0', dst[5]);
+		EXPECT_EQ(std::string(dst), "Hello");
+		EXPECT_TRUE(std::all_of(dst + 5, dst + sizeof(dst), [](char c){ return c == '\0'; }));
+
+		std::memset(dst, 'A', sizeof(dst));
+		strcpy_trunc(dst, "Hello World!");
+		EXPECT_EQ('\0', dst[12]);
+		EXPECT_EQ(std::string(dst), "Hello World!");
+
+		std::memset(dst, 'A', sizeof(dst));
+		strcpy_trunc(dst, "Hello World! Here I am!");
+		EXPECT_EQ('\0', dst[12]);
+		EXPECT_EQ(std::string(dst), "Hello World!");
+	}
 }

rpcs3/util/logs.cpp

@@ -118,7 +118,7 @@ namespace logs
 
 		~file_listener() override = default;
 
-		void log(u64 stamp, const message& msg, const std::string& prefix, const std::string& text) override;
+		void log(u64 stamp, const message& msg, std::string_view prefix, std::string_view text) override;
 
 		void sync() override
 		{
@@ -138,7 +138,7 @@ namespace logs
 		~root_listener() override = default;
 
 		// Encode level, current thread name, channel name and write log message
-		void log(u64, const message&, const std::string&, const std::string&) override
+		void log(u64, const message&, std::string_view, std::string_view) override
 		{
 			// Do nothing
 		}
@@ -251,7 +251,7 @@ namespace logs
 	{
 		std::lock_guard lock(g_mutex);
 
-		auto found = get_logger()->channels.equal_range(ch_name);
+		const auto found = get_logger()->channels.equal_range(ch_name);
 
 		if (found.first != found.second)
 		{
@@ -771,7 +771,7 @@ logs::file_listener::file_listener(const std::string& path, u64 max_size)
 	file_writer::log("\xEF\xBB\xBF", 3);
 }
 
-void logs::file_listener::log(u64 stamp, const logs::message& msg, const std::string& prefix, const std::string& _text)
+void logs::file_listener::log(u64 stamp, const logs::message& msg, std::string_view prefix, std::string_view _text)
 {
 	/*constinit thread_local*/ std::string text;
 	text.reserve(50000);

rpcs3/util/logs.hpp

@@ -79,7 +79,7 @@ namespace logs
 		virtual ~listener();
 
 		// Process log message
-		virtual void log(u64 stamp, const message& msg, const std::string& prefix, const std::string& text) = 0;
+		virtual void log(u64 stamp, const message& msg, std::string_view prefix, std::string_view text) = 0;
 
 		// Flush contents (file writer)
 		virtual void sync();

rpcs3/util/video_provider.cpp

@@ -162,7 +162,7 @@ namespace utils
 		}
 	}
 
-	void video_provider::present_samples(u8* buf, u32 sample_count, u16 channels)
+	void video_provider::present_samples(const u8* buf, u32 sample_count, u16 channels)
 	{
 		if (!buf || !sample_count || !channels || !m_active)
 		{

rpcs3/util/video_provider.h

@@ -23,7 +23,7 @@ namespace utils
 		bool can_consume_frame();
 		void present_frame(std::vector<u8>& data, u32 pitch, u32 width, u32 height, bool is_bgra);
 
-		void present_samples(u8* buf, u32 sample_count, u16 channels);
+		void present_samples(const u8* buf, u32 sample_count, u16 channels);
 
 	private:
 		recording_mode check_mode();