Merge pull request #20157 from hrydgard/log-optimization

Logging optimization

Common/Log.h

@@ -78,12 +78,33 @@ enum class LogLevel : int {
 	LVERBOSE = VERBOSE_LEVEL,
 };
 
-void GenericLog(LogLevel level, Log type, const char *file, int line, const char *fmt, ...)
+struct LogChannel {
+#if defined(_DEBUG)
+	LogLevel level = LogLevel::LDEBUG;
+#else
+	LogLevel level = LogLevel::LDEBUG;
+#endif
+	bool enabled = true;
+
+	bool IsEnabled(LogLevel level) const {
+		if (level > this->level || !this->enabled)
+			return false;
+		return true;
+	}
+};
+
+extern bool *g_bLogEnabledSetting;
+extern LogChannel g_log[(size_t)Log::NUMBER_OF_LOGS];
+
+inline bool GenericLogEnabled(Log type, LogLevel level) {
+	return g_log[(int)type].IsEnabled(level) && (*g_bLogEnabledSetting);
+}
+
+void GenericLog(Log type, LogLevel level, const char *file, int line, const char *fmt, ...)
 #ifdef __GNUC__
 		__attribute__((format(printf, 5, 6)))
 #endif
 		;
-bool GenericLogEnabled(LogLevel level, Log type);
 
 // If you want to see verbose logs, change this to VERBOSE_LEVEL.
 
@@ -91,9 +112,9 @@ bool GenericLogEnabled(LogLevel level, Log type);
 
 // Let the compiler optimize this out.
 // TODO: Compute a dynamic max level as well that can be checked here.
-#define GENERIC_LOG(t, v, ...) { \
+#define GENERIC_LOG(t, v, ...) \
-	if ((int)v <= MAX_LOGLEVEL) \
+	if ((int)v <= MAX_LOGLEVEL && GenericLogEnabled(t, v)) { \
-		GenericLog(v, t, __FILE__, __LINE__, __VA_ARGS__); \
+		GenericLog(t, v, __FILE__, __LINE__, __VA_ARGS__); \
 	}
 
 #define ERROR_LOG(t,...)   do { GENERIC_LOG(t, LogLevel::LERROR,   __VA_ARGS__) } while (false)

Common/Log/LogManager.cpp

@@ -41,11 +41,13 @@
 #include "Common/Data/Format/IniFile.h"
 #include "Common/StringUtils.h"
 
+LogChannel g_log[(size_t)Log::NUMBER_OF_LOGS];
 LogManager g_logManager;
 
 const char *hleCurrentThreadName = nullptr;
 
-bool *g_bLogEnabledSetting = nullptr;
+bool g_bDummySetting = true;
+bool *g_bLogEnabledSetting = &g_bDummySetting;
 
 static const char level_to_char[8] = "-NEWIDV";
 
@@ -59,19 +61,13 @@ static const char level_to_char[8] = "-NEWIDV";
 void AndroidLog(const LogMessage &message);
 #endif
 
-void GenericLog(LogLevel level, Log type, const char *file, int line, const char* fmt, ...) {
+void GenericLog(Log type, LogLevel level, const char *file, int line, const char* fmt, ...) {
-	if (g_bLogEnabledSetting && !(*g_bLogEnabledSetting))
-		return;
 	va_list args;
 	va_start(args, fmt);
 	g_logManager.LogLine(level, type, file, line, fmt, args);
 	va_end(args);
 }
 
-bool GenericLogEnabled(LogLevel level, Log type) {
-	return (*g_bLogEnabledSetting) && g_logManager.IsEnabled(level, type);
-}
-
 // NOTE: Needs to be kept in sync with the Log enum.
 static const char * const g_logTypeNames[] = {
 	"SYSTEM",
@@ -127,11 +123,11 @@ void LogManager::Init(bool *enabledSetting, bool headless) {
 	initialized_ = true;
 
 	_dbg_assert_(ARRAY_SIZE(g_logTypeNames) == (size_t)Log::NUMBER_OF_LOGS);
-	_dbg_assert_(ARRAY_SIZE(g_logTypeNames) == ARRAY_SIZE(log_));
+	_dbg_assert_(ARRAY_SIZE(g_logTypeNames) == ARRAY_SIZE(g_log));
 
-	for (size_t i = 0; i < ARRAY_SIZE(log_); i++) {
+	for (size_t i = 0; i < ARRAY_SIZE(g_log); i++) {
-		log_[i].enabled = true;
+		g_log[i].enabled = true;
-		log_[i].level = LogLevel::LINFO;
+		g_log[i].level = LogLevel::LINFO;
 	}
 }
 
@@ -151,12 +147,12 @@ void LogManager::Shutdown() {
 	ringLog_.Clear();
 	initialized_ = false;
 
-	for (size_t i = 0; i < ARRAY_SIZE(log_); i++) {
+	for (size_t i = 0; i < ARRAY_SIZE(g_log); i++) {
-		log_[i].enabled = true;
+		g_log[i].enabled = true;
 #if defined(_DEBUG)
-		log_[i].level = LogLevel::LDEBUG;
+		g_log[i].level = LogLevel::LDEBUG;
 #else
-		log_[i].level = LogLevel::LINFO;
+		g_log[i].level = LogLevel::LINFO;
 #endif
 	}
 }
@@ -217,8 +213,8 @@ void LogManager::ChangeFileLog(const Path &filename) {
 
 void LogManager::SaveConfig(Section *section) {
 	for (int i = 0; i < (int)Log::NUMBER_OF_LOGS; i++) {
-		section->Set((std::string(g_logTypeNames[i]) + "Enabled"), log_[i].enabled);
+		section->Set((std::string(g_logTypeNames[i]) + "Enabled"), g_log[i].enabled);
-		section->Set((std::string(g_logTypeNames[i]) + "Level"), (int)log_[i].level);
+		section->Set((std::string(g_logTypeNames[i]) + "Level"), (int)g_log[i].level);
 	}
 }
 
@@ -228,8 +224,8 @@ void LogManager::LoadConfig(const Section *section, bool debugDefaults) {
 		int level = 0;
 		section->Get((std::string(g_logTypeNames[i]) + "Enabled"), &enabled, true);
 		section->Get((std::string(g_logTypeNames[i]) + "Level"), &level, (int)(debugDefaults ? LogLevel::LDEBUG : LogLevel::LERROR));
-		log_[i].enabled = enabled;
+		g_log[i].enabled = enabled;
-		log_[i].level = (LogLevel)level;
+		g_log[i].level = (LogLevel)level;
 	}
 }
 
@@ -243,9 +239,11 @@ void LogManager::SetOutputsEnabled(LogOutput outputs) {
 void LogManager::LogLine(LogLevel level, Log type, const char *file, int line, const char *format, va_list args) {
 	char msgBuf[1024];
 
-	const LogChannel &log = log_[(size_t)type];
+	const LogChannel &log = g_log[(size_t)type];
-	if (level > log.level || !log.enabled || outputs_ == (LogOutput)0)
+	if (level > log.level || !log.enabled || outputs_ == (LogOutput)0) {
+		// If we get here, it should have been caught earlier.
 		return;
+	}
 
 	LogMessage message;
 	message.level = level;

Common/Log/LogManager.h

@@ -73,19 +73,11 @@ private:
 	int count_ = 0;
 };
 
-struct LogChannel {
-#if defined(_DEBUG)
-	LogLevel level = LogLevel::LDEBUG;
-#else
-	LogLevel level = LogLevel::LDEBUG;
-#endif
-	bool enabled = true;
-};
-
 class Section;
 class ConsoleListener;
 
 typedef void (*LogCallback)(const LogMessage &message, void *userdata);
+extern bool *g_bLogEnabledSetting;
 
 class LogManager {
 public:
@@ -111,33 +103,26 @@ public:
 	void LogLine(LogLevel level, Log type,
 				 const char *file, int line, const char *fmt, va_list args);
 
-	bool IsEnabled(LogLevel level, Log type) const {
-		const LogChannel &log = log_[(size_t)type];
-		if (level > log.level || !log.enabled)
-			return false;
-		return true;
-	}
-
 	LogChannel *GetLogChannel(Log type) {
-		return &log_[(size_t)type];
+		return &g_log[(size_t)type];
 	}
 
 	void SetLogLevel(Log type, LogLevel level) {
-		log_[(size_t)type].level = level;
+		g_log[(size_t)type].level = level;
 	}
 
 	void SetAllLogLevels(LogLevel level) {
 		for (int i = 0; i < (int)Log::NUMBER_OF_LOGS; ++i) {
-			log_[i].level = level;
+			g_log[i].level = level;
 		}
 	}
 
 	void SetEnabled(Log type, bool enable) {
-		log_[(size_t)type].enabled = enable;
+		g_log[(size_t)type].enabled = enable;
 	}
 
 	LogLevel GetLogLevel(Log type) {
-		return log_[(size_t)type].level;
+		return g_log[(size_t)type].level;
 	}
 
 #if PPSSPP_PLATFORM(WINDOWS)
@@ -172,7 +157,6 @@ private:
 
 	bool initialized_ = false;
 
-	LogChannel log_[(size_t)Log::NUMBER_OF_LOGS];
 #if PPSSPP_PLATFORM(WINDOWS)
 	ConsoleListener *consoleLog_ = nullptr;
 #endif

Core/Dialog/SavedataParam.cpp

@@ -1267,7 +1267,7 @@ bool SavedataParam::GetList(SceUtilitySavedataParam *param)
 		// Save num of folder found
 		param->idList->resultCount = (u32)validDir.size();
 		// Log out the listing.
-		if (GenericLogEnabled(LogLevel::LINFO, Log::sceUtility)) {
+		if (GenericLogEnabled(Log::sceUtility, LogLevel::LINFO)) {
 			INFO_LOG(Log::sceUtility, "LIST (searchstring=%s): %d files (max: %d)", searchString.c_str(), param->idList->resultCount, maxFileCount);
 			for (int i = 0; i < validDir.size(); i++) {
 				INFO_LOG(Log::sceUtility, "%s: mode %08x, ctime: %s, atime: %s, mtime: %s",
@@ -1387,7 +1387,7 @@ int SavedataParam::GetFilesList(SceUtilitySavedataParam *param, u32 requestAddr)
 		entry->name[15] = '\0';
 	}
 
-	if (GenericLogEnabled(LogLevel::LINFO, Log::sceUtility)) {
+	if (GenericLogEnabled(Log::sceUtility, LogLevel::LINFO)) {
 		INFO_LOG(Log::sceUtility, "FILES: %d files listed (+ %d system, %d secure)", fileList->resultNumNormalEntries, fileList->resultNumSystemEntries, fileList->resultNumSecureEntries);
 		if (fileList->normalEntries.IsValid()) {
 			for (int i = 0; i < (int)fileList->resultNumNormalEntries; i++) {

Core/HLE/HLE.cpp

@@ -1057,13 +1057,13 @@ void hleDoLogInternal(Log t, LogLevel level, u64 res, const char *file, int line
 	const char *kernelFlag = (funcFlags & HLE_KERNEL_SYSCALL) ? "K " : "";
 	if (retmask != 'v') {
 		if (errStr) {
-			GenericLog(level, t, file, line, fmt, kernelFlag, errStr, funcName, formatted_args, formatted_reason);
+			GenericLog(t, level, file, line, fmt, kernelFlag, errStr, funcName, formatted_args, formatted_reason);
 		} else {
-			GenericLog(level, t, file, line, fmt, kernelFlag, res, funcName, formatted_args, formatted_reason);
+			GenericLog(t, level, file, line, fmt, kernelFlag, res, funcName, formatted_args, formatted_reason);
 		}
 	} else {
 		// Skipping the res argument for this format string.
-		GenericLog(level, t, file, line, fmt, kernelFlag, funcName, formatted_args, formatted_reason);
+		GenericLog(t, level, file, line, fmt, kernelFlag, funcName, formatted_args, formatted_reason);
 	}
 
 	if (reportTag) {

Core/HLE/HLE.h

@@ -181,7 +181,7 @@ __attribute__((format(printf, 7, 8)))
 #endif
 NO_INLINE
 T hleDoLog(Log t, LogLevel level, T res, const char *file, int line, const char *reportTag, const char *reasonFmt, ...) {
-	if (!GenericLogEnabled(level, t)) {
+	if (!GenericLogEnabled(t, level)) {
 		if (leave) {
 			hleLeave();
 		}
@@ -221,7 +221,7 @@ template <bool leave, bool convert_code, typename T>
 [[nodiscard]]
 NO_INLINE
 T hleDoLog(Log t, LogLevel level, T res, const char *file, int line, const char *reportTag) {
-	if (((int)level > MAX_LOGLEVEL || !GenericLogEnabled(level, t)) && !reportTag) {
+	if (((int)level > MAX_LOGLEVEL || !GenericLogEnabled(t, level)) && !reportTag) {
 		if (leave) {
 			hleLeave();
 		}