From ba88955be4f7c6909d08d2d7bf88e4c975302b5d Mon Sep 17 00:00:00 2001 From: Ben Vanik Date: Sun, 7 Jun 2015 16:12:54 -0700 Subject: [PATCH] vsnprintf return is dumb. --- src/xenia/apu/audio_system.cc | 2 +- src/xenia/base/logging.cc | 76 ++++++++++------------------ src/xenia/base/logging.h | 15 +++--- src/xenia/kernel/xboxkrnl_strings.cc | 7 ++- 4 files changed, 39 insertions(+), 61 deletions(-) diff --git a/src/xenia/apu/audio_system.cc b/src/xenia/apu/audio_system.cc index ffd2d43c7..ee1f3c875 100644 --- a/src/xenia/apu/audio_system.cc +++ b/src/xenia/apu/audio_system.cc @@ -85,7 +85,7 @@ void av_log_callback(void *avcl, int level, const char *fmt, va_list va) { StringBuffer buff; buff.AppendVarargs(fmt, va); - xe::log_line(__FILE__, __LINE__, 'i', "libav: %s", buff.GetString()); + xe::log_line('i', "libav: %s", buff.GetString()); } X_STATUS AudioSystem::Setup() { diff --git a/src/xenia/base/logging.cc b/src/xenia/base/logging.cc index 920b24427..728ba282a 100644 --- a/src/xenia/base/logging.cc +++ b/src/xenia/base/logging.cc @@ -20,47 +20,31 @@ DEFINE_bool(fast_stdout, false, "Don't lock around stdout/stderr. May introduce weirdness."); DEFINE_bool(flush_stdout, true, "Flush stdout after each log line."); -DEFINE_bool(log_filenames, false, - "Log filenames/line numbers in log statements."); namespace xe { std::mutex log_lock; -void format_log_line(char* buffer, size_t buffer_count, const char* file_path, - const uint32_t line_number, const char level_char, - const char* fmt, va_list args) { - char* buffer_ptr; - if (FLAGS_log_filenames) { - // Strip out just the filename from the path. - const char* filename = strrchr(file_path, xe::path_separator); - if (filename) { - // Slash - skip over it. - filename++; - } else { - // No slash, entire thing is filename. - filename = file_path; - } +thread_local std::vector log_buffer(16 * 1024); - // Format string - add a trailing newline if required. - const char* outfmt = "%c> %.2X %s:%d: "; - buffer_ptr = buffer + snprintf(buffer, buffer_count - 2, outfmt, level_char, - xe::threading::current_thread_id(), filename, - line_number); - } else { - buffer_ptr = buffer; - *(buffer_ptr++) = level_char; - *(buffer_ptr++) = '>'; - *(buffer_ptr++) = ' '; - buffer_ptr += - sprintf(buffer_ptr, "%.4X", xe::threading::current_thread_id()); - *(buffer_ptr++) = ' '; - } +void format_log_line(char* buffer, size_t buffer_capacity, + const char level_char, const char* fmt, va_list args) { + char* buffer_ptr; + buffer_ptr = buffer; + *(buffer_ptr++) = level_char; + *(buffer_ptr++) = '>'; + *(buffer_ptr++) = ' '; + buffer_ptr += sprintf(buffer_ptr, "%.4X", xe::threading::current_thread_id()); + *(buffer_ptr++) = ' '; // Scribble args into the print buffer. - buffer_ptr = buffer_ptr + vsnprintf(buffer_ptr, - buffer_count - (buffer_ptr - buffer) - 2, - fmt, args); + size_t remaining_capacity = buffer_capacity - (buffer_ptr - buffer) - 3; + size_t chars_written = vsnprintf(buffer_ptr, remaining_capacity, fmt, args); + if (chars_written >= remaining_capacity) { + buffer_ptr += remaining_capacity - 1; + } else { + buffer_ptr += chars_written; + } // Add a trailing newline. if (buffer_ptr[-1] != '\n') { @@ -69,25 +53,22 @@ void format_log_line(char* buffer, size_t buffer_count, const char* file_path, } } -thread_local char log_buffer[4 * 1024]; - -void log_line(const char* file_path, const uint32_t line_number, - const char level_char, const char* fmt, ...) { +void log_line(const char level_char, const char* fmt, ...) { // SCOPE_profile_cpu_i("emu", "log_line"); va_list args; va_start(args, fmt); - format_log_line(log_buffer, xe::countof(log_buffer), file_path, line_number, - level_char, fmt, args); + format_log_line(log_buffer.data(), log_buffer.capacity(), level_char, fmt, + args); va_end(args); if (!FLAGS_fast_stdout) { log_lock.lock(); } #if 0 // defined(OutputDebugString) - OutputDebugStringA(log_buffer); + OutputDebugStringA(log_buffer.data()); #else - fprintf(stdout, "%s", log_buffer); + fprintf(stdout, "%s", log_buffer.data()); if (FLAGS_flush_stdout) { fflush(stdout); } @@ -97,22 +78,19 @@ void log_line(const char* file_path, const uint32_t line_number, } } -void handle_fatal(const char* file_path, const uint32_t line_number, - const char* fmt, ...) { - char buffer[2048]; +void handle_fatal(const char* fmt, ...) { va_list args; va_start(args, fmt); - format_log_line(buffer, xe::countof(buffer), file_path, line_number, 'X', fmt, - args); + format_log_line(log_buffer.data(), log_buffer.capacity(), 'X', fmt, args); va_end(args); if (!FLAGS_fast_stdout) { log_lock.lock(); } #if defined(OutputDebugString) - OutputDebugStringA(buffer); + OutputDebugStringA(log_buffer.data()); #else - fprintf(stderr, "%s", buffer); + fprintf(stderr, "%s", log_buffer.data()); fflush(stderr); #endif // OutputDebugString if (!FLAGS_fast_stdout) { @@ -121,7 +99,7 @@ void handle_fatal(const char* file_path, const uint32_t line_number, #if XE_PLATFORM_WIN32 if (!xe::has_console_attached()) { - MessageBoxA(NULL, buffer, "Xenia Error", + MessageBoxA(NULL, log_buffer.data(), "Xenia Error", MB_OK | MB_ICONERROR | MB_APPLMODAL | MB_SETFOREGROUND); } #endif // WIN32 diff --git a/src/xenia/base/logging.h b/src/xenia/base/logging.h index 4bcf518bf..e1a44d7bf 100644 --- a/src/xenia/base/logging.h +++ b/src/xenia/base/logging.h @@ -36,24 +36,21 @@ namespace xe { #else #define XE_LOG_LINE_ATTRIBUTE #endif // XE_COMPILER_GNUC -void log_line(const char* file_path, const uint32_t line_number, - const char level_char, const char* fmt, +void log_line(const char level_char, const char* fmt, ...) XE_LOG_LINE_ATTRIBUTE; #undef XE_LOG_LINE_ATTRIBUTE -void handle_fatal(const char* file_path, const uint32_t line_number, - const char* fmt, ...); +void handle_fatal(const char* fmt, ...); #if XE_OPTION_ENABLE_LOGGING -#define XELOGCORE(level, fmt, ...) \ - xe::log_line(__FILE__, __LINE__, level, fmt, ##__VA_ARGS__) +#define XELOGCORE(level, fmt, ...) xe::log_line(level, fmt, ##__VA_ARGS__) #else #define XELOGCORE(level, fmt, ...) XE_EMPTY_MACRO #endif // ENABLE_LOGGING -#define XEFATAL(fmt, ...) \ - do { \ - xe::handle_fatal(__FILE__, __LINE__, fmt, ##__VA_ARGS__); \ +#define XEFATAL(fmt, ...) \ + do { \ + xe::handle_fatal(fmt, ##__VA_ARGS__); \ } while (false) #if XE_OPTION_LOG_ERROR diff --git a/src/xenia/kernel/xboxkrnl_strings.cc b/src/xenia/kernel/xboxkrnl_strings.cc index 730712af9..208e72bd2 100644 --- a/src/xenia/kernel/xboxkrnl_strings.cc +++ b/src/xenia/kernel/xboxkrnl_strings.cc @@ -647,7 +647,8 @@ int32_t format_core(PPCContext* ppc_context, FormatData& data, ArgList& args, class StackArgList : public ArgList { public: - StackArgList(PPCContext* ppc_context, int32_t index) : ppc_context(ppc_context), index_(index) {} + StackArgList(PPCContext* ppc_context, int32_t index) + : ppc_context(ppc_context), index_(index) {} uint32_t get32() { return (uint32_t)get64(); } @@ -924,17 +925,19 @@ SHIM_CALL _vsnprintf_shim(PPCContext* ppc_context, KernelState* kernel_state) { int32_t count = format_core(ppc_context, data, args, false); if (count < 0) { + // Error. if (buffer_count > 0) { buffer[0] = '\0'; // write a null, just to be safe } } else if (count <= buffer_count) { + // Fit within the buffer. std::memcpy(buffer, data.str().c_str(), count); if (count < buffer_count) { buffer[count] = '\0'; } } else { + // Overflowed buffer. We still return the count we would have written. std::memcpy(buffer, data.str().c_str(), buffer_count); - count = -1; // for return value } SHIM_SET_RETURN_32(count); }