diff --git a/core/core_bind.cpp b/core/core_bind.cpp index f5c69b9b9802..08d97aeecf73 100644 --- a/core/core_bind.cpp +++ b/core/core_bind.cpp @@ -1900,4 +1900,53 @@ void EngineDebugger::_bind_methods() { ClassDB::bind_method(D_METHOD("send_message", "message", "data"), &EngineDebugger::send_message); } +////// LogManager ////// +// This is the client-facing part of the user log hooking system. +// It's basically just a shunt that passes callbacks to the persistent UserLogManagerLogger singleton. + +LogManager *LogManager::singleton = nullptr; + +LogManager::LogManager() { + ERR_FAIL_COND_MSG(singleton != nullptr, "Somehow created two LogManagers."); + + singleton = this; +} + +LogManager::~LogManager() { + ERR_FAIL_COND_MSG(singleton != this, "LogManager::singleton not correct on exit."); + + singleton = nullptr; +} + +void LogManager::register_log_capture_non_thread_safe(const Callable &p_callable) { + UserLogManagerLogger *log_manager = UserLogManagerLogger::get_singleton(); + ERR_FAIL_NULL_MSG(log_manager, "log_manager not yet initialized. This shouldn't be possible."); + log_manager->register_log_capture_non_thread_safe(p_callable); +} + +void LogManager::unregister_log_capture_non_thread_safe(const Callable &p_callable) { + UserLogManagerLogger *log_manager = UserLogManagerLogger::get_singleton(); + ERR_FAIL_NULL_MSG(log_manager, "log_manager not yet initialized. This shouldn't be possible."); + log_manager->unregister_log_capture_non_thread_safe(p_callable); +} + +void LogManager::register_log_capture_buffered(const Callable &p_callable) { + UserLogManagerLogger *log_manager = UserLogManagerLogger::get_singleton(); + ERR_FAIL_NULL_MSG(log_manager, "log_manager not yet initialized. This shouldn't be possible."); + log_manager->register_log_capture_buffered(p_callable); +} + +void LogManager::unregister_log_capture_buffered(const Callable &p_callable) { + UserLogManagerLogger *log_manager = UserLogManagerLogger::get_singleton(); + ERR_FAIL_NULL_MSG(log_manager, "log_manager not yet initialized. This shouldn't be possible."); + log_manager->unregister_log_capture_buffered(p_callable); +} + +void LogManager::_bind_methods() { + ClassDB::bind_method(D_METHOD("register_log_capture_non_thread_safe", "callable"), &LogManager::register_log_capture_non_thread_safe); + ClassDB::bind_method(D_METHOD("unregister_log_capture_non_thread_safe", "callable"), &LogManager::unregister_log_capture_non_thread_safe); + ClassDB::bind_method(D_METHOD("register_log_capture_buffered", "callable"), &LogManager::register_log_capture_buffered); + ClassDB::bind_method(D_METHOD("unregister_log_capture_buffered", "callable"), &LogManager::unregister_log_capture_buffered); +} + } // namespace core_bind diff --git a/core/core_bind.h b/core/core_bind.h index f884426881ef..d80de84e925e 100644 --- a/core/core_bind.h +++ b/core/core_bind.h @@ -567,6 +567,26 @@ class EngineDebugger : public Object { ~EngineDebugger(); }; +class LogManager : public Object { + GDCLASS(LogManager, Object); + +protected: + static void _bind_methods(); + static LogManager *singleton; + +public: + LogManager(); + ~LogManager(); + + static LogManager *get_singleton() { return singleton; } + + void register_log_capture_non_thread_safe(const Callable &p_callable); + void unregister_log_capture_non_thread_safe(const Callable &p_callable); + + void register_log_capture_buffered(const Callable &p_callable); + void unregister_log_capture_buffered(const Callable &p_callable); +}; + } // namespace core_bind VARIANT_ENUM_CAST(core_bind::ResourceLoader::ThreadLoadStatus); diff --git a/core/io/logger.cpp b/core/io/logger.cpp index 441df7f5d12d..b92ed105d164 100644 --- a/core/io/logger.cpp +++ b/core/io/logger.cpp @@ -34,6 +34,7 @@ #include "core/core_globals.h" #include "core/io/dir_access.h" #include "core/os/os.h" +#include "core/os/thread.h" #include "core/os/time.h" #include "core/string/print_string.h" @@ -266,3 +267,362 @@ CompositeLogger::~CompositeLogger() { memdelete(loggers[i]); } } + +////// UserLogManagerLogger ////// +// This is the internal user log hooking system, which does all the hard work. + +UserLogManagerLogger *UserLogManagerLogger::singleton = nullptr; + +UserLogManagerLogger::UserLogManagerLogger() { + ERR_FAIL_COND_MSG(singleton != nullptr, "Somehow created two UserLogManagerLoggers."); + + singleton = this; + + pre_buffering.set(); + + // this is about to get overwritten by `recalculate_state` + state.set(STATE_OFF); + + // we don't technically have to lock the mutex here but I'd rather preserve the formal recalculate_state mandatory-mutex invariant + MutexLock lock(mutex); + recalculate_state(); +} + +UserLogManagerLogger::~UserLogManagerLogger() { + ERR_FAIL_COND_MSG(singleton != this, "UserLogManagerLogger::singleton not correct on exit."); + + singleton = nullptr; + + // there's no messages still in-flight, right? + // right? +} + +void UserLogManagerLogger::logv(const char *p_format, va_list p_list, bool p_err) { + if (state.get() == STATE_OFF) { + // don't jump through the formatting hoops, just drop the message + // if there's a hook active (or we're in the buffering zone), `state` will never transition through STATE_OFF + // if at any point there isn't a hook active, dropping messages is valid + return; + } + + va_list list_copy; + va_copy(list_copy, p_list); + + int len = vsnprintf(nullptr, 0, p_format, p_list); + + char *buf = (char *)Memory::alloc_static(len + 1); + vsnprintf(buf, len + 1, p_format, list_copy); + va_end(list_copy); + + Dictionary message; + message["text"] = buf; + message["type"] = "info"; + + process(message); + + Memory::free_static(buf); +} + +void UserLogManagerLogger::log_error(const char *p_function, const char *p_file, int p_line, const char *p_code, const char *p_rationale, bool p_editor_notify, ErrorType p_type) { + if (state.get() == STATE_OFF) { + // don't jump through the formatting hoops, just drop the message + // if there's a hook active (or we're in the buffering zone), `state` will never transition through STATE_OFF + // if at any point there isn't a hook active, dropping messages is valid + return; + } + + Dictionary message; + message["function"] = p_function; + message["file"] = p_file; + message["line"] = p_line; + message["text"] = p_code; + message["rationale"] = p_rationale; + switch (p_type) { + case ERR_ERROR: + message["type"] = "error"; + break; + case ERR_WARNING: + message["type"] = "warning"; + break; + case ERR_SCRIPT: + message["type"] = "script"; + break; + case ERR_SHADER: + message["type"] = "shader"; + break; + + default: + // this is an error but I don't want to start spamming error messages *in the error handler* + // that way lies madness and infinite loops/stack overflows + message["type"] = "unknown"; + break; + } + + process(message); +} + +void UserLogManagerLogger::register_log_capture_non_thread_safe(const Callable &p_callable) { + // It gets *extremely* hard to guarantee the proper semantics if you're allowed to call this from other threads. + ERR_FAIL_COND_MSG(!Thread::is_main_thread(), "This call is forbidden outside the main thread."); + + if (pre_buffering.is_set()) { + // Time to dispatch our messages! This catches this particular hook up to "realtime", replaying all buffered messages in fast-forward. + + // We can be certain nobody is *removing* things from the buffer right now + // Nothing is ever removed from the buffer except for frame transitions and state changes + // Frame transitions are locked to the main thread, and so are we + // and Frame 0 is guaranteed to be STATE_BUFFERED + + // Adding things to the buffer is fine, we'll just loop until they're done; this is why we're not using an iterator but rather an index + int index_to_send = 0; + + while (true) { + Dictionary to_send; + { + // We do still need to lock the mutex while grabbing the Dictionary, though, just in case the buffer is being reallocated at this moment + MutexLock lock(mutex); + + if (index_to_send >= buffered_logs.size()) { + // Never mind that whole "send a message" plan! + + // We've reached the end of the log, and because it's locked, + // we can be sure that no new messages will be added at this exact moment. + // Add ourselves to the captures so we'll intercept future messages. + register_callable(captures_non_thread_safe, p_callable); + + // This does mean that "the buffer" and "the non_thread_safe callables" are, in some cases, updated atomically + // This is important; see process() + + // conceptually recalculate_state() gets called here + // but in practice we don't because we know we're on frame 0 and therefore no change of state will be happening + + // We're done! + break; + } + + // We haven't reached the end; grab another message + to_send = buffered_logs[index_to_send++]; + + // Unlock the mutex to avoid deadlocks in case our dispatch adds/removes callbacks or logs messages + } + + // Off you go, while no locks are held! + dispatch_message(to_send, p_callable); + } + } else { + // it's not Frame 0, therefore we don't have to mess around with the buffer at all + // just lock, register ourselves as a callable, and recalculate the state so we can start capturing messages + MutexLock lock(mutex); + register_callable(captures_non_thread_safe, p_callable); + recalculate_state(); + } +} + +void UserLogManagerLogger::unregister_log_capture_non_thread_safe(const Callable &p_callable) { + // It gets *extremely* hard to guarantee the proper semantics if you're allowed to call this from other threads. + ERR_FAIL_COND_MSG(!Thread::is_main_thread(), "This call is forbidden outside the main thread."); + + MutexLock lock(mutex); + unregister_callable(captures_non_thread_safe, p_callable); + recalculate_state(); +} + +void UserLogManagerLogger::register_log_capture_buffered(const Callable &p_callable) { + // It gets *extremely* hard to guarantee the proper semantics if you're allowed to call this from other threads. + ERR_FAIL_COND_MSG(!Thread::is_main_thread(), "This call is forbidden outside the main thread."); + + MutexLock lock(mutex); + register_callable(captures_buffered, p_callable); + recalculate_state(); +} + +void UserLogManagerLogger::unregister_log_capture_buffered(const Callable &p_callable) { + // It gets *extremely* hard to guarantee the proper semantics if you're allowed to call this from other threads. + ERR_FAIL_COND_MSG(!Thread::is_main_thread(), "This call is forbidden outside the main thread."); + + MutexLock lock(mutex); + unregister_callable(captures_buffered, p_callable); + recalculate_state(); +} + +void UserLogManagerLogger::flush() { + // if you're not sure why this is important, go read the giant comment near the end of recalculate_state + // it avoids a nearly-impossible race condition + ERR_FAIL_COND_MSG(!Thread::is_main_thread(), "This call is forbidden outside the main thread."); + + // This flushes our buffer and recycles it for the next frame. + // If we don't have a buffer, we have nothing to do. + if (state.get() != STATE_BUFFERING) { + return; + } + + // "Send all our buffered messages to all our buffered log readers" + // To avoid inconsistent message delivery of anything that's already been buffered, we swap the entire buffer first + // Anything that gets delivered while we're writing these messages gets to wait for next frame. + // (We could loop until the buffer is empty) + Vector buffered_logs_mirror; + { + MutexLock lock(mutex); + SWAP(buffered_logs_mirror, buffered_logs); + } + + // Dispatch to all the buffered callables, in a thread-safe manner + // Any buffered callables that disable themselves stop getting messages ASAP + // any buffered callables that get attached might start getting messages midway through + // we're ok with that, it's still a chronologically coherent block + for (const Dictionary &log : buffered_logs_mirror) { + // This is the same index-as-iterator-to-avoid-lock-issues dance we do in register_log_capture_non_thread_safe() + int index_to_send_to = 0; + + while (true) { + Callable callable; + { + MutexLock lock(mutex); + if (index_to_send_to >= captures_buffered.size()) { + // we done! + break; + } + + callable = captures_buffered[index_to_send_to++]; + } + + dispatch_message(log, callable); + } + } + + if (pre_buffering.is_set()) { + // Buffering is done! + // Read the comment near the bottom of recalculate_state for a possible race condition and how it's dealt with. + // IT IS REALLY IMPORTANT THAT THIS HAPPENS ONLY ON THE MAIN THREAD. + MutexLock lock(mutex); + pre_buffering.clear(); + recalculate_state(); + } +} + +void UserLogManagerLogger::process(const Dictionary &p_message) { + Vector captures_non_thread_safe_mirror; + { + // Shove another item into the buffer, if we need to. + + // We also atomically grab `captures_non_thread_safe` to avoid race conditions, in the extraordinarily unlikely case where: + // * this function buffers a message, releases the lock, and is immediately preempted + // * in another thread, an already-running register_log_capture_non_thread_safe dispatches our new message from the buffer + // * that same register_log_capture_non_thread_safe gets to the end of the buffer and adds itself to captures_non_thread_safe + // * this function resumes, reaches the captures_non_thread_safe section, and sends the same message again + + // register_log_capture_non_thread_safe intentionally finishes the buffered log message replay atomically with adding a new handler to the vector + // so we do the same thing here, adding a message to the log atomically with copying the handlers + // Vector COW behavior prevents this from being expensive in the common case + MutexLock lock(mutex); + if (state.get() == STATE_BUFFERING) { + buffered_logs.append(p_message); + } + captures_non_thread_safe_mirror = captures_non_thread_safe; + } + + // Dispatch to all the non_thread_safe callables at the moment we added to the buffer + // We actually don't have to care about cutesy thread-safety for once because we're working off a local copy of the captures list + + for (const Callable &callable : captures_non_thread_safe_mirror) { + dispatch_message(p_message, callable); + } +} + +void UserLogManagerLogger::dispatch_message(const Dictionary &p_message, const Callable &p_callable) { + // ideally we should verify that the mutex is *not* held by this thread, but the current API provides no way to do that + // (it's possible it's already been scooped up by another thread, that's fine) + + if (!p_callable.is_valid()) { + // in most cases, this is going to be a deleted callable, so ignore it; + // is_null() would be enough for that, we intentionally invalidate it to null in register_callable + // + // it's apparently possible for callables to be yanked out from under us, though, and if we call them, we crash + // so, do the full is_valid() check + // + // (easier to put the check here than everywhere that calls this) + return; + } + + Variant message_variant = p_message; + const Variant *args[1] = { &message_variant }; + Variant retval; + Callable::CallError err; + p_callable.callp(args, 1, retval, err); +} + +void UserLogManagerLogger::recalculate_state() { + // we should verify that the mutex is held (ideally by this thread) but the current API provides no way to do that + // (aside from switching to a non-recursive mutex and trying to lock it and hoping it fails, which, no) + + State new_state = STATE_OFF; + + if (pre_buffering.is_set()) { + // We always buffer on the first frame, in case someone hooks to us and expects a replay + new_state = STATE_BUFFERING; + } else if (!captures_buffered.is_empty()) { + // Anything buffering means we need to preserve the buffer + new_state = STATE_BUFFERING; + } else if (!captures_non_thread_safe.is_empty()) { + // Anything non-buffering means we still need to process + new_state = STATE_PASSTHROUGH; + } + // Otherwise, we're off + + // if we're transitioning from buffering to anything else, we need to clear the buffer + if (state.get() == STATE_BUFFERING && new_state != STATE_BUFFERING) { + // NOTE: this line is why the register/unregister functions are locked to the main thread! + + // imagine this set of events: + // * we're on frame 0 + // * non-main thread: we register a non_thread_safe handler + // * non-main thread: the non_thread_safe handler starts replaying the buffer + // * main thread: on the main thread, we transition to frame 1 + // * main thread: flush() calls this function + // * main thread: we decide to clear the buffer between locks as it's being replayed in the non-main thread + // * non-main thread: this doesn't crash, because our index iteration is safe, but this does prematurely terminate the replay + // * non-main thread: the non_thread_safe handler gets hooked properly and starts echoing live messages + + // end result, a bunch of "guaranteed to be replayed" messages vanish into the ether + + // I don't like cases that end up with a batch of log messages mysteriously vanishing! + // non_thread_safe replays happen only on frame 0 + // so this can be fixed by just ensuring that the frame0-frame1 transition must happen on the same thread as all non_thread_safe buffer replays + // thus ensuring they cannot happen in parallel + // and because the frame0-frame1 transition is locked to the main thread, + // the non_thread_safe buffer replays must also be locked to the main thread, + // and because those are part of the non_thread_safe_register function, + // the non_thread_safe_register function must (ironically) be locked to the main thread. + // for symmetry's sake, so is everything else (and because frankly the threading in this area is knotty enough already) + + buffered_logs.clear(); + } + + state.set(new_state); +} + +void UserLogManagerLogger::register_callable(Vector &p_vector, const Callable &p_callable) { + // we should verify that the mutex is held (ideally by this thread) but the current API provides no way to do that + + // right now we're just letting people double-register if they want + // this should maybe be a warning but that gets hairy with register_log_capture_non_thread_safe + // so instead I'm just saying "you registered it twice, what did you expect would happen" + int index = p_vector.find(Callable()); + if (index != -1) { + // reuse an empty Callable() slot if there is one + p_vector.write[index] = p_callable; + } else { + p_vector.append(p_callable); + } +} + +void UserLogManagerLogger::unregister_callable(Vector &p_vector, const Callable &p_callable) { + // we should verify that the mutex is held (ideally by this thread) but the current API provides no way to do that + + // find the index and replace it with Callable() to invalidate it without moving indices around, which would break in-flight iterators in other threads + // to parallel the register-twice semantics we're intentionally removing exactly one copy here + int index = p_vector.find(p_callable); + if (index != -1) { + p_vector.write[index] = Callable(); + } +} diff --git a/core/io/logger.h b/core/io/logger.h index 3cd18965c545..607cfc67260d 100644 --- a/core/io/logger.h +++ b/core/io/logger.h @@ -106,4 +106,67 @@ class CompositeLogger : public Logger { virtual ~CompositeLogger(); }; +class UserLogManagerLogger : public Logger { + static UserLogManagerLogger *singleton; + + Vector buffered_logs; + + // Stored as Vector so we can iterate over it in a thread-safe manner without holding a lock + // Deleted items are replaced by Callable(), with the slot later reused, to avoid problems with in-flight iterators + // This technically means adding and removing a capture is O(n^2) but it's hard to imagine any sensible scenario where n>4 + Vector captures_non_thread_safe; + Vector captures_buffered; + + enum State { + STATE_OFF, // log messages are not processed in any way + STATE_PASSTHROUGH, // log messages are processed but sent straight to non_thread_safe + STATE_BUFFERING, // log messages are processed and buffered until the next flush (and maybe sent straight to non_thread_safe also) + }; + SafeNumeric state; + + // whether we're in the first-frame Prebuffering mode or not + SafeFlag pre_buffering; + + // This is expected to be called from multiple threads. + // Right now we have a single mutex that applies to any access of any collection, as well as `state` transitions. + // It's possible this should be split into multiple contextual states, but, man, good luck figuring out the details on that one. + // You *must* release this mutex before calling any of the callables! + // They might add log messages or add/remove callables of their own! + Mutex mutex; + +public: + UserLogManagerLogger(); + ~UserLogManagerLogger(); + + static UserLogManagerLogger *get_singleton() { return singleton; } + + // Log input interface + virtual void logv(const char *p_format, va_list p_list, bool p_err) override _PRINTF_FORMAT_ATTRIBUTE_2_0; + virtual void log_error(const char *p_function, const char *p_file, int p_line, const char *p_code, const char *p_rationale, bool p_editor_notify, ErrorType p_type = ERR_ERROR) override; + + // Callback registration/unregistration (via LogManager) + // Must be called from the main thread + void register_log_capture_non_thread_safe(const Callable &p_callable); + void unregister_log_capture_non_thread_safe(const Callable &p_callable); + void register_log_capture_buffered(const Callable &p_callable); + void unregister_log_capture_buffered(const Callable &p_callable); + + // Buffer flush notification (currently on a per-frame basis) + // Must be called from the main thread + void flush(); + +private: + void process(const Dictionary &p_message); + + static void dispatch_message(const Dictionary &p_message, const Callable &p_callable); + + // General "figure out what you should be doing" callback. + // `mutex` *must* be held when calling this. + void recalculate_state(); + + // small utility functions for our sparse vector behavior, assumes the mutex is already held + static void register_callable(Vector &p_vector, const Callable &p_callable); + static void unregister_callable(Vector &p_vector, const Callable &p_callable); +}; + #endif // LOGGER_H diff --git a/core/register_core_types.cpp b/core/register_core_types.cpp index 4c1ed8a69a83..bda256512fe8 100644 --- a/core/register_core_types.cpp +++ b/core/register_core_types.cpp @@ -100,6 +100,7 @@ static core_bind::Engine *_engine = nullptr; static core_bind::special::ClassDB *_classdb = nullptr; static core_bind::Marshalls *_marshalls = nullptr; static core_bind::EngineDebugger *_engine_debugger = nullptr; +static core_bind::LogManager *_log_manager = nullptr; static IP *ip = nullptr; static Time *_time = nullptr; @@ -292,6 +293,7 @@ void register_core_types() { _classdb = memnew(core_bind::special::ClassDB); _marshalls = memnew(core_bind::Marshalls); _engine_debugger = memnew(core_bind::EngineDebugger); + _log_manager = memnew(core_bind::LogManager); GDREGISTER_NATIVE_STRUCT(ObjectID, "uint64_t id = 0"); GDREGISTER_NATIVE_STRUCT(AudioFrame, "float left;float right"); @@ -330,6 +332,7 @@ void register_core_singletons() { GDREGISTER_CLASS(InputMap); GDREGISTER_CLASS(Expression); GDREGISTER_CLASS(core_bind::EngineDebugger); + GDREGISTER_CLASS(core_bind::LogManager); GDREGISTER_CLASS(Time); Engine::get_singleton()->add_singleton(Engine::Singleton("ProjectSettings", ProjectSettings::get_singleton())); @@ -346,6 +349,7 @@ void register_core_singletons() { Engine::get_singleton()->add_singleton(Engine::Singleton("Input", Input::get_singleton())); Engine::get_singleton()->add_singleton(Engine::Singleton("InputMap", InputMap::get_singleton())); Engine::get_singleton()->add_singleton(Engine::Singleton("EngineDebugger", core_bind::EngineDebugger::get_singleton())); + Engine::get_singleton()->add_singleton(Engine::Singleton("LogManager", core_bind::LogManager::get_singleton())); Engine::get_singleton()->add_singleton(Engine::Singleton("Time", Time::get_singleton())); Engine::get_singleton()->add_singleton(Engine::Singleton("GDExtensionManager", GDExtensionManager::get_singleton())); Engine::get_singleton()->add_singleton(Engine::Singleton("ResourceUID", ResourceUID::get_singleton())); @@ -384,6 +388,7 @@ void unregister_core_types() { memdelete(worker_thread_pool); + memdelete(_log_manager); memdelete(_engine_debugger); memdelete(_marshalls); memdelete(_classdb); diff --git a/doc/classes/@GlobalScope.xml b/doc/classes/@GlobalScope.xml index 4cf5a88dd780..c6b29f8c210d 100644 --- a/doc/classes/@GlobalScope.xml +++ b/doc/classes/@GlobalScope.xml @@ -1586,6 +1586,9 @@ The [JavaScriptBridge] singleton. [b]Note:[/b] Only implemented on the Web platform. + + The [LogManager] singleton. + The [Marshalls] singleton. diff --git a/doc/classes/LogManager.xml b/doc/classes/LogManager.xml new file mode 100644 index 000000000000..026a122148cd --- /dev/null +++ b/doc/classes/LogManager.xml @@ -0,0 +1,58 @@ + + + + Exposes the internal logging systems. + + + [LogManager] provides callbacks to receive log messages, both from scripts and from internal editor functionality. + + + + + + + + + Registers a buffered callback for the log capture system. + Your callback will occasionally be called when log messages have been output. This is guaranteed to happen on the main thread and preserve message order; however, there may be some delay (at most, one frame) between the message being sent and the callback being called. + Your callback will be called with a single Variant containing a dictionary with fields. It is guaranteed to include: + [code]type[/code]: The type of message. Currently "error", "warning", "info", "script", and "shader". + [code]text[/code]: The message text. + Optionally, the dictionary may contain: + [code]file[/code]: The source file the message originated from. + [code]line[/code]: The line number the message originated from. + [code]function[/code]: The function the message originated from. + [code]rationale[/code]: Further detailed information about the message. + If the callback is registered before the first frame, it will immediately replay all messages from the start of the game, in order. + [b]Note:[/b] This function may be called on the main thread only. + + + + + + + Registers a non_thread_safe callback for the log capture system. + Your callback will be called whenever a log message is output. This may happen in any thread or in any situation. [b]Your callback must be fully thread-safe, and it must not block.[/b] It may be called from any thread, including the main thread, even if another callback is currently being called. It may be called twice in parallel. It may be called in scenarios where you are disallowed from modifying Node values or creating Nodes. If you do anything to create a log message from this function, it may be called recursively, and this can potentially result in a stack overflow. Any or all of these things may happen before this register call returns. [b]Treat this function with extreme care.[/b] + Your callback will be called with a single Variant containing a dictionary with fields, containing the same information as the dictionary passed to [method register_log_capture_buffered]. + If the callback is registered before the first frame, it will immediately replay all messages from the start of the game, in order. + [b]Note:[/b] This function may be called on the main thread only. + + + + + + + Unregisters a buffered callback for the log capture system. Messages being sent to the callback will cease immediately. + [b]Note:[/b] This function may be called on the main thread only. + + + + + + + Unregisters a non_thread_safe callback for the log capture system. Your callback may continue to receive messages for a short time after this function is called. + [b]Note:[/b] This function may be called on the main thread only. + + + + diff --git a/main/main.cpp b/main/main.cpp index 4c9c159f47da..31f76cb0a20f 100644 --- a/main/main.cpp +++ b/main/main.cpp @@ -854,6 +854,15 @@ Error Main::setup(const char *execpath, int argc, char *argv[], bool p_second_ph OS::get_singleton()->initialize(); + // Add our logger so we can log *everything* + // This must be extremely early so it can record every log so we can catch Godot startup errors + // At the moment the log subsystem owns this object, which prevents us from easily removing it + // I'm just living with that, but if a conditional per log message ends up being too much overhead, + // it could be turned into its own global that manages its own registration and deregistration + // This is also likely necessary if it starts using other log attachments + // such as add_error_handler, add_print_handler, register_message_capture, and EditorToaster. + OS::get_singleton()->add_logger(memnew(UserLogManagerLogger())); + // Benchmark tracking must be done after `OS::get_singleton()->initialize()` as on some // platforms, it's used to set up the time utilities. OS::get_singleton()->benchmark_begin_measure("Startup", "Total"); @@ -3990,6 +3999,11 @@ bool Main::iteration() { } } + // trigger the logger flush now + // this could be moved before the frame update, but the first time it updates changes behavior a bit + // and it's convenient to say "behavior is X before the first frame" + UserLogManagerLogger::get_singleton()->flush(); + process_ticks = OS::get_singleton()->get_ticks_usec() - process_begin; process_max = MAX(process_ticks, process_max); uint64_t frame_time = OS::get_singleton()->get_ticks_usec() - ticks;