kern: optimize logging for release kernel strings (saves printf space in .text)

This commit is contained in:
Michael Scire 2021-09-17 16:44:57 -07:00
parent d2664c60a3
commit 62fe20693e
4 changed files with 53 additions and 8 deletions

View file

@ -28,6 +28,8 @@ namespace ams::kern {
static NOINLINE void Printf(const char *format, ...) __attribute__((format(printf, 1, 2))); static NOINLINE void Printf(const char *format, ...) __attribute__((format(printf, 1, 2)));
static NOINLINE void VPrintf(const char *format, ::std::va_list vl); static NOINLINE void VPrintf(const char *format, ::std::va_list vl);
static NOINLINE void LogException(const char *str);
static NOINLINE Result PrintUserString(ams::kern::svc::KUserPointer<const char *> user_str, size_t len); static NOINLINE Result PrintUserString(ams::kern::svc::KUserPointer<const char *> user_str, size_t len);
/* Functionality for preserving across sleep. */ /* Functionality for preserving across sleep. */
@ -49,6 +51,8 @@ namespace ams::kern {
#endif #endif
#define MESOSPHERE_EXCEPTION_LOG(str) ::ams::kern::KDebugLog::LogException(str)
#define MESOSPHERE_RELEASE_LOG(fmt, ...) ::ams::kern::KDebugLog::Printf((fmt), ## __VA_ARGS__) #define MESOSPHERE_RELEASE_LOG(fmt, ...) ::ams::kern::KDebugLog::Printf((fmt), ## __VA_ARGS__)
#define MESOSPHERE_RELEASE_VLOG(fmt, vl) ::ams::kern::KDebugLog::VPrintf((fmt), (vl)) #define MESOSPHERE_RELEASE_VLOG(fmt, vl) ::ams::kern::KDebugLog::VPrintf((fmt), (vl))

View file

@ -308,7 +308,7 @@ namespace ams::kern::arch::arm64 {
{ {
if (ec != EsrEc_SoftwareStepEl0) { if (ec != EsrEc_SoftwareStepEl0) {
/* If the exception wasn't single-step, print details. */ /* If the exception wasn't single-step, print details. */
MESOSPHERE_RELEASE_LOG("Exception occurred. %016lx\n", GetCurrentProcess().GetProgramId()); MESOSPHERE_EXCEPTION_LOG("Exception occurred. ");
{ {
/* Print the current thread's registers. */ /* Print the current thread's registers. */
@ -327,7 +327,7 @@ namespace ams::kern::arch::arm64 {
#else #else
{ {
/* Print that an exception occurred. */ /* Print that an exception occurred. */
MESOSPHERE_RELEASE_LOG("Exception occurred. %016lx\n", GetCurrentProcess().GetProgramId()); MESOSPHERE_EXCEPTION_LOG("Exception occurred. ");
{ {
/* Print the current thread's registers. */ /* Print the current thread's registers. */
@ -496,7 +496,7 @@ namespace ams::kern::arch::arm64 {
} }
/* Print that an exception occurred. */ /* Print that an exception occurred. */
MESOSPHERE_RELEASE_LOG("Exception occurred. %016lx\n", GetCurrentProcess().GetProgramId()); MESOSPHERE_EXCEPTION_LOG("Exception occurred. ");
/* Exit the current process. */ /* Exit the current process. */
GetCurrentProcess().Exit(); GetCurrentProcess().Exit();

View file

@ -20,15 +20,15 @@ namespace ams::kern {
namespace { namespace {
KSpinLock g_debug_log_lock; constinit KSpinLock g_debug_log_lock;
bool g_initialized_impl; constinit bool g_initialized_impl;
/* NOTE: Nintendo's print buffer is size 0x100. */ /* NOTE: Nintendo's print buffer is size 0x100. */
char g_print_buffer[0x400]; constinit char g_print_buffer[0x400];
void PutString(const char *str) { void PutString(const char *str) {
/* Only print if the implementation is initialized. */ /* Only print if the implementation is initialized. */
if (!g_initialized_impl) { if (AMS_UNLIKELY(!g_initialized_impl)) {
return; return;
} }
@ -73,6 +73,20 @@ namespace ams::kern {
#endif #endif
ALWAYS_INLINE void FormatU64(char * const dst, u64 value) {
/* Adjust, so that we can print the value backwards. */
char *cur = dst + 2 * sizeof(value);
/* Format the value in (as %016lx) */
while (cur > dst) {
/* Extract the digit. */
const auto digit = value & 0xF;
value >>= 4;
*(--cur) = (digit <= 9) ? ('0' + digit) : ('a' + digit - 10);
}
}
} }
void KDebugLog::Initialize() { void KDebugLog::Initialize() {
@ -109,6 +123,33 @@ namespace ams::kern {
::ams::util::TVSNPrintf(dst, dst_size, format, vl); ::ams::util::TVSNPrintf(dst, dst_size, format, vl);
} }
void KDebugLog::LogException(const char *str) {
if (KTargetSystem::IsDebugLoggingEnabled()) {
/* Get the current program ID. */
/* NOTE: Nintendo does this after printing the string, */
/* but it seems wise to avoid holding the lock/disabling interrupts */
/* for longer than is strictly necessary. */
char suffix[18];
if (const auto *cur_process = GetCurrentProcessPointer(); AMS_LIKELY(cur_process != nullptr)) {
FormatU64(suffix, cur_process->GetProgramId());
suffix[16] = '\n';
suffix[17] = '\x00';
} else {
suffix[0] = '\n';
suffix[1] = '\x00';
}
KScopedInterruptDisable di;
KScopedSpinLock lk(g_debug_log_lock);
/* Log the string. */
PutString(str);
/* Log the program id (and newline) suffix. */
PutString(suffix);
}
}
Result KDebugLog::PrintUserString(ams::kern::svc::KUserPointer<const char *> user_str, size_t len) { Result KDebugLog::PrintUserString(ams::kern::svc::KUserPointer<const char *> user_str, size_t len) {
/* If printing is enabled, print the user string. */ /* If printing is enabled, print the user string. */
#if defined(MESOSPHERE_ENABLE_DEBUG_PRINT) #if defined(MESOSPHERE_ENABLE_DEBUG_PRINT)

View file

@ -60,7 +60,7 @@ namespace ams::kern::svc {
} }
/* Print that break was called. */ /* Print that break was called. */
MESOSPHERE_RELEASE_LOG("Break() called. %016lx\n", GetCurrentProcess().GetProgramId()); MESOSPHERE_EXCEPTION_LOG("Break() called. ");
/* Try to enter JIT debug state. */ /* Try to enter JIT debug state. */
if (GetCurrentProcess().EnterJitDebug(ams::svc::DebugEvent_Exception, ams::svc::DebugException_UserBreak, KDebug::GetProgramCounter(GetCurrentThread()), break_reason, address, size)) { if (GetCurrentProcess().EnterJitDebug(ams::svc::DebugEvent_Exception, ams::svc::DebugException_UserBreak, KDebug::GetProgramCounter(GetCurrentThread()), break_reason, address, size)) {