From ba4263d859819c4ef92f05559799e01b5112325a Mon Sep 17 00:00:00 2001 From: XorTroll Date: Sun, 13 Dec 2020 19:59:09 +0100 Subject: [PATCH] Improve logging implementation and other minor details --- .../stratosphere/diag/diag_log_observer.hpp | 2 +- .../diag_detail_default_log_observer.cpp | 2 +- .../source/diag/detail/diag_detail_log.cpp | 95 +++++++++++++++++-- .../lm/detail/lm_detail_log_observer.cpp | 12 +-- .../libstratosphere/source/lm/lm_api.cpp | 8 +- .../vapours/util/util_format_string.hpp | 5 + .../source/util/util_format_string.cpp | 11 +++ .../lm/source/impl/lm_log_server_proxy.cpp | 5 +- .../lm/source/impl/lm_sd_card_logging.cpp | 2 +- stratosphere/lm/source/lm_log_service.cpp | 7 +- stratosphere/lm/source/lm_log_service.hpp | 10 +- stratosphere/lm/source/lm_main.cpp | 2 +- 12 files changed, 137 insertions(+), 24 deletions(-) diff --git a/libraries/libstratosphere/include/stratosphere/diag/diag_log_observer.hpp b/libraries/libstratosphere/include/stratosphere/diag/diag_log_observer.hpp index fdf72610e..a07216cb1 100644 --- a/libraries/libstratosphere/include/stratosphere/diag/diag_log_observer.hpp +++ b/libraries/libstratosphere/include/stratosphere/diag/diag_log_observer.hpp @@ -19,7 +19,7 @@ namespace ams::diag { struct LogObserverHolder { - using LogFunction = void (*)(const LogMetaData&, const LogBody&, void*); + using LogFunction = void (*)(const LogMetaData &log_metadata, const LogBody &log_body, void *user_data); LogFunction log_function; LogObserverHolder *next; diff --git a/libraries/libstratosphere/source/diag/detail/diag_detail_default_log_observer.cpp b/libraries/libstratosphere/source/diag/detail/diag_detail_default_log_observer.cpp index 2fb23b177..0ac208556 100644 --- a/libraries/libstratosphere/source/diag/detail/diag_detail_default_log_observer.cpp +++ b/libraries/libstratosphere/source/diag/detail/diag_detail_default_log_observer.cpp @@ -21,7 +21,7 @@ namespace ams::diag::detail { os::SdkMutex g_log_observer_lock; - const char *g_log_severity_color_table[LogSeverity_Count] = { + constexpr const char *g_log_severity_color_table[LogSeverity_Count] = { "\x1B[90m", /* Dark gray for Trace. */ "", /* No special color for Info. */ "\x1B[33m", /* Yellow for Warn. */ diff --git a/libraries/libstratosphere/source/diag/detail/diag_detail_log.cpp b/libraries/libstratosphere/source/diag/detail/diag_detail_log.cpp index 02f04d1f8..b82065b66 100644 --- a/libraries/libstratosphere/source/diag/detail/diag_detail_log.cpp +++ b/libraries/libstratosphere/source/diag/detail/diag_detail_log.cpp @@ -17,20 +17,103 @@ namespace ams::diag::detail { + namespace { + + struct LogPrintData { + char *print_str_start; + char *print_str_end; + char *print_str_cur; + /* void *d; */ + const LogMetaData &log_metadata; + bool is_head; + char buffer[40]; + }; + + void PutCharacters(void *user_data, const char *chars, int chars_len) { + auto print_data = reinterpret_cast(user_data); + if (chars_len > 0) { + while (true) { + if (print_data->print_str_cur >= print_data->print_str_end) { + break; + } + + auto copy_len = std::min(static_cast(chars_len), static_cast(print_data->print_str_end - print_data->print_str_cur)); + std::memcpy(print_data->print_str_cur, chars, copy_len); + chars_len -= copy_len; + chars += copy_len; + print_data->print_str_cur += copy_len; + if (chars_len == 0) { + return; + } + } + if (!print_data->log_metadata.use_default_locale_charset) { + const auto cur_print_str_len = static_cast(print_data->print_str_cur - print_data->print_str_start); + auto actual_print_str_len = GetValidSizeAsUtf8String(print_data->print_str_start, cur_print_str_len); + if (actual_print_str_len < cur_print_str_len) { + auto print_str_cur_end = print_data->print_str_start + actual_print_str_len; + *print_str_cur_end = '\0'; + + const LogBody log_body = { + .log_text = print_data->print_str_start, + .log_text_length = actual_print_str_len, + .log_is_head = print_data->is_head, + .log_is_tail = false, + }; + CallAllLogObserver(print_data->log_metadata, log_body); + auto move_len = cur_print_str_len - actual_print_str_len; + std::memmove(print_data->print_str_start, print_str_cur_end, move_len); + print_data->print_str_cur = print_data->print_str_start + move_len; + print_data->is_head = false; + AMS_ASSERT(print_data->print_str_cur < print_data->print_str_end); + } + } + *print_data->print_str_cur = '\0'; + + const LogBody log_body = { + .log_text = print_data->print_str_start, + .log_text_length = static_cast(print_data->print_str_cur - print_data->print_str_start), + .log_is_head = print_data->is_head, + .log_is_tail = false, + }; + CallAllLogObserver(print_data->log_metadata, log_body); + print_data->print_str_cur = print_data->print_str_start; + print_data->is_head = false; + AMS_ASSERT(print_data->print_str_cur < print_data->print_str_end); + } + } + + } + void DefaultLogObserver(const LogMetaData &log_metadata, const LogBody &log_body, void *user_data); LogObserverHolder g_default_log_observer = { DefaultLogObserver, nullptr, true, nullptr }; LogObserverHolder *g_log_observer_list_head = std::addressof(g_default_log_observer); void LogImpl(const LogMetaData &log_metadata, const char *fmt, ...) { - std::va_list v; - va_start(v, fmt); - VLogImpl(log_metadata, fmt, v); - va_end(v); + std::va_list vl; + va_start(vl, fmt); + VLogImpl(log_metadata, fmt, vl); + va_end(vl); } - void VLogImpl(const LogMetaData &log_metadata, const char *fmt, std::va_list va_args) { - /* TODO */ + void VLogImpl(const LogMetaData &log_metadata, const char *fmt, std::va_list vl) { + LogPrintData print_data = { + .print_str_start = print_data.buffer, + .print_str_end = static_cast(print_data.buffer) + sizeof(print_data.buffer), + .print_str_cur = print_data.buffer, + .log_metadata = log_metadata, + .is_head = true + }; + + util::VFormatString(PutCharacters, std::addressof(print_data), fmt, vl); + + const LogBody log_body = { + .log_text = print_data.print_str_start, + .log_text_length = static_cast(print_data.print_str_cur - print_data.print_str_start), + .log_is_head = print_data.is_head, + .log_is_tail = true, + }; + CallAllLogObserver(print_data.log_metadata, log_body); } void CallAllLogObserver(const LogMetaData &log_metadata, const LogBody &log_body) { diff --git a/libraries/libstratosphere/source/lm/detail/lm_detail_log_observer.cpp b/libraries/libstratosphere/source/lm/detail/lm_detail_log_observer.cpp index f8de4ff55..30c10e4b0 100644 --- a/libraries/libstratosphere/source/lm/detail/lm_detail_log_observer.cpp +++ b/libraries/libstratosphere/source/lm/detail/lm_detail_log_observer.cpp @@ -22,8 +22,8 @@ namespace ams::lm::detail { os::SdkMutex g_log_observer_lock; u8 g_packet_transmitter_buffer[0x400]; - bool LogPacketTransmitterFlushFunction(const void *data, size_t data_size) { - /* TODO: lm OpenLogger, Log, SetDestination libnx bindings... */ + bool LogPacketTransmitterFlushFunction(const void *log_data, size_t log_data_size) { + /* TODO: libnx bindings. */ return true; } @@ -51,7 +51,7 @@ namespace ams::lm::detail { auto file_name_len = strlen(file_name); if (file_name /* && !util::VerifyUtf8String(file_name, file_name_len) */) { file_name = DefaultInvalidString; - file_name_len = strlen(DefaultInvalidString); + file_name_len = __builtin_strlen(DefaultInvalidString); } packet_transmitter.PushFileName(file_name, file_name_len); @@ -60,7 +60,7 @@ namespace ams::lm::detail { auto function_name_len = strlen(function_name); if (function_name /* && !util::VerifyUtf8String(function_name, function_name_len) */) { function_name = DefaultInvalidString; - function_name_len = strlen(DefaultInvalidString); + function_name_len = __builtin_strlen(DefaultInvalidString); } packet_transmitter.PushFunctionName(function_name, function_name_len); @@ -69,7 +69,7 @@ namespace ams::lm::detail { auto module_name_len = strlen(module_name); if (module_name /* && !util::VerifyUtf8String(module_name, module_name_len) */) { module_name = DefaultInvalidString; - module_name_len = strlen(DefaultInvalidString); + module_name_len = __builtin_strlen(DefaultInvalidString); } packet_transmitter.PushModuleName(module_name, module_name_len); @@ -78,7 +78,7 @@ namespace ams::lm::detail { auto thread_name_len = strlen(thread_name); if (thread_name /* && !util::VerifyUtf8String(thread_name, thread_name_len) */) { thread_name = DefaultInvalidString; - thread_name_len = strlen(DefaultInvalidString); + thread_name_len = __builtin_strlen(DefaultInvalidString); } packet_transmitter.PushThreadName(thread_name, thread_name_len); diff --git a/libraries/libstratosphere/source/lm/lm_api.cpp b/libraries/libstratosphere/source/lm/lm_api.cpp index 19d97603a..181dc4481 100644 --- a/libraries/libstratosphere/source/lm/lm_api.cpp +++ b/libraries/libstratosphere/source/lm/lm_api.cpp @@ -25,13 +25,16 @@ namespace ams::lm { namespace { - bool g_initialized; + bool g_initialized = false; } void Initialize() { AMS_ASSERT(!g_initialized); + + /* TODO: libnx bindings. */ /* R_ABORT_UNLESS(lmInitialize()); */ + /* Log by default via LogManager. */ diag::ReplaceDefaultLogObserver(detail::LogManagerLogObserver); g_initialized = true; @@ -39,7 +42,10 @@ namespace ams::lm { void Finalize() { AMS_ASSERT(g_initialized); + + /* TODO: libnx bindings. */ /* lmExit(); */ + diag::ResetDefaultLogObserver(); g_initialized = false; } diff --git a/libraries/libvapours/include/vapours/util/util_format_string.hpp b/libraries/libvapours/include/vapours/util/util_format_string.hpp index 0dd2faf45..6a0c4a9c5 100644 --- a/libraries/libvapours/include/vapours/util/util_format_string.hpp +++ b/libraries/libvapours/include/vapours/util/util_format_string.hpp @@ -26,4 +26,9 @@ namespace ams::util { int TSNPrintf(char *dst, size_t dst_size, const char *fmt, ...); int TVSNPrintf(char *dst, size_t dst_size, const char *fmt, std::va_list vl); + using PrintFunction = void (*)(void *user_data, const char *str, int unk); + + void FormatString(PrintFunction print_fn, void *user_data, const char *fmt, ...); + void VFormatString(PrintFunction print_fn, void *user_data, const char *fmt, std::va_list vl); + } \ No newline at end of file diff --git a/libraries/libvapours/source/util/util_format_string.cpp b/libraries/libvapours/source/util/util_format_string.cpp index b6510e773..b5c4183f0 100644 --- a/libraries/libvapours/source/util/util_format_string.cpp +++ b/libraries/libvapours/source/util/util_format_string.cpp @@ -431,4 +431,15 @@ namespace ams::util { return len; } + void FormatString(PrintFunction print_fn, void *user_data, const char *fmt, ...) { + std::va_list vl; + va_start(vl, fmt); + VFormatString(print_fn, user_data, fmt, vl); + va_end(vl); + } + + void VFormatString(PrintFunction print_fn, void *user_data, const char *fmt, std::va_list vl) { + /* TODO */ + } + } diff --git a/stratosphere/lm/source/impl/lm_log_server_proxy.cpp b/stratosphere/lm/source/impl/lm_log_server_proxy.cpp index 769857cfb..a7360bd9f 100644 --- a/stratosphere/lm/source/impl/lm_log_server_proxy.cpp +++ b/stratosphere/lm/source/impl/lm_log_server_proxy.cpp @@ -10,7 +10,8 @@ namespace ams::lm::impl { void LogServerProxy::DisposeHtcsThread() { this->finalize_event.Signal(); - /* nn::htcs::Close(this->htcs_client_fd); */ + /* TODO: htcs support */ + /* htcs::Close(this->htcs_client_fd); */ os::WaitThread(std::addressof(this->htcs_thread)); os::DestroyThread(std::addressof(this->htcs_thread)); } @@ -25,7 +26,7 @@ namespace ams::lm::impl { size_t offset = 0; auto send_data = reinterpret_cast(log_data); while (true) { - auto sent_size = htcs::Send(this->htcs_client_fd, send_data + offset, log_size - offset, 0); + const auto sent_size = htcs::Send(this->htcs_client_fd, send_data + offset, log_size - offset, 0); if (this->htcs_client_fd & 0x80000000) { break; } diff --git a/stratosphere/lm/source/impl/lm_sd_card_logging.cpp b/stratosphere/lm/source/impl/lm_sd_card_logging.cpp index d700754f7..ea31707e1 100644 --- a/stratosphere/lm/source/impl/lm_sd_card_logging.cpp +++ b/stratosphere/lm/source/impl/lm_sd_card_logging.cpp @@ -1,7 +1,7 @@ #include "lm_sd_card_logging.hpp" namespace ams::lm::impl { - + namespace { os::SystemEvent g_sd_card_detection_event; diff --git a/stratosphere/lm/source/lm_log_service.cpp b/stratosphere/lm/source/lm_log_service.cpp index 834e4dba8..cfb99365b 100644 --- a/stratosphere/lm/source/lm_log_service.cpp +++ b/stratosphere/lm/source/lm_log_service.cpp @@ -11,7 +11,7 @@ namespace ams::lm { namespace { - LogDestination g_log_destination = 1; + LogDestination g_log_destination = LogDestination_TargetManager; u8 g_logger_heap_memory[0x4000]; os::SdkMutex g_logger_heap_lock; @@ -52,14 +52,15 @@ namespace ams::lm { /* Set process ID. */ log_packet_header->SetProcessId(static_cast(this->process_id)); - if (g_log_destination & 1) { + if (g_log_destination & LogDestination_TargetManager) { + /* Log through normal means, which also implies logging to SD card if enabled. */ if (!impl::GetLogBuffer()->Log(log_buffer.GetPointer(), log_buffer.GetSize(), ShouldLogWithFlush())) { /* If logging through LogBuffer failed, increment packet drop count. */ impl::GetEventLogTransmitter()->IncrementLogPacketDropCount(); } } - if (!(g_log_destination & 2)) { + if (!(g_log_destination & LogDestination_Uart)) { /* TODO: what's done here? */ } diff --git a/stratosphere/lm/source/lm_log_service.hpp b/stratosphere/lm/source/lm_log_service.hpp index bbfd90087..ff9ee60d3 100644 --- a/stratosphere/lm/source/lm_log_service.hpp +++ b/stratosphere/lm/source/lm_log_service.hpp @@ -18,8 +18,14 @@ namespace ams::lm { - /* TODO: define a proper enum after identifying what each value means. */ - using LogDestination = u32; + /* Log destination. */ + enum LogDestination : u32 { + LogDestination_TargetManager = (1 << 0), + LogDestination_Uart = (1 << 1), + LogDestination_UartIfSleep = (1 << 2), + + LogDestination_All = 0xFFFF, + }; namespace impl { diff --git a/stratosphere/lm/source/lm_main.cpp b/stratosphere/lm/source/lm_main.cpp index b6065fc6e..435f3409b 100644 --- a/stratosphere/lm/source/lm_main.cpp +++ b/stratosphere/lm/source/lm_main.cpp @@ -131,7 +131,7 @@ namespace { else { /* Handle our module. */ g_pm_module.GetEventPointer()->Clear(); - if(R_SUCCEEDED(g_pm_module.GetRequest(std::addressof(cur_state), std::addressof(pm_flags)))) { + if (R_SUCCEEDED(g_pm_module.GetRequest(std::addressof(cur_state), std::addressof(pm_flags)))) { if (((prev_state == psc::PmState_ReadyAwakenCritical) && (cur_state == psc::PmState_ReadyAwaken)) || ((prev_state == psc::PmState_ReadyAwaken) && (cur_state == psc::PmState_ReadySleep)) || (cur_state == psc::PmState_ReadyShutdown)) { /* State changed, so allow/disallow flushing. */ g_disabled_flush = !g_disabled_flush;