From d1dcb40d565174e88627fc6395890d0bac88f756 Mon Sep 17 00:00:00 2001 From: reduz Date: Mon, 31 Mar 2025 21:39:43 +0200 Subject: [PATCH] Ability to print and log script backtraces Co-authored-by: Mikael Hermansson --- core/core_bind.cpp | 117 +++++++++++ core/core_bind.h | 47 ++++- core/error/error_macros.cpp | 11 +- core/io/logger.cpp | 10 +- core/io/logger.h | 5 +- core/object/script_backtrace.cpp | 196 +++++++++++++++++++ core/object/script_backtrace.h | 87 ++++++++ core/object/script_language.cpp | 11 ++ core/object/script_language.h | 3 + core/os/os.cpp | 4 +- core/os/os.h | 5 +- core/register_core_types.cpp | 4 +- core/variant/variant_utility.cpp | 1 + doc/classes/Engine.xml | 10 + doc/classes/Logger.xml | 54 +++++ doc/classes/OS.xml | 14 ++ doc/classes/ProjectSettings.xml | 10 + doc/classes/ScriptBacktrace.xml | 128 ++++++++++++ drivers/unix/os_unix.cpp | 17 +- drivers/unix/os_unix.h | 2 +- modules/gdscript/gdscript.cpp | 15 +- modules/gdscript/gdscript.h | 57 ++++-- modules/gdscript/gdscript_byte_codegen.cpp | 2 +- modules/gdscript/gdscript_function.cpp | 6 +- modules/gdscript/gdscript_vm.cpp | 20 +- modules/mono/csharp_script.cpp | 4 - platform/ios/ios_terminal_logger.h | 2 +- platform/ios/ios_terminal_logger.mm | 8 +- platform/macos/macos_terminal_logger.h | 2 +- platform/macos/macos_terminal_logger.mm | 22 ++- platform/windows/windows_terminal_logger.cpp | 32 ++- platform/windows/windows_terminal_logger.h | 2 +- 32 files changed, 813 insertions(+), 95 deletions(-) create mode 100644 core/object/script_backtrace.cpp create mode 100644 core/object/script_backtrace.h create mode 100644 doc/classes/Logger.xml create mode 100644 doc/classes/ScriptBacktrace.xml diff --git a/core/core_bind.cpp b/core/core_bind.cpp index 0a1faf7940..785c1d6d95 100644 --- a/core/core_bind.cpp +++ b/core/core_bind.cpp @@ -210,8 +210,79 @@ void ResourceSaver::_bind_methods() { BIND_BITFIELD_FLAG(FLAG_REPLACE_SUBRESOURCE_PATHS); } +////// Logger /////// + +void Logger::_bind_methods() { + GDVIRTUAL_BIND(_log_error, "function", "file", "line", "code", "rationale", "editor_notify", "error_type", "script_backtraces"); + GDVIRTUAL_BIND(_log_message, "message", "error"); + BIND_ENUM_CONSTANT(ERROR_TYPE_ERROR); + BIND_ENUM_CONSTANT(ERROR_TYPE_WARNING); + BIND_ENUM_CONSTANT(ERROR_TYPE_SCRIPT); + BIND_ENUM_CONSTANT(ERROR_TYPE_SHADER); +} + +void Logger::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, const TypedArray &p_script_backtraces) { + GDVIRTUAL_CALL(_log_error, String::utf8(p_function), String::utf8(p_file), p_line, String::utf8(p_code), String::utf8(p_rationale), p_editor_notify, p_type, p_script_backtraces); +} + +void Logger::log_message(const String &p_text, bool p_error) { + GDVIRTUAL_CALL(_log_message, p_text, p_error); +} + ////// OS ////// +void OS::LoggerBind::logv(const char *p_format, va_list p_list, bool p_err) { + if (!should_log(p_err) || is_logging) { + return; + } + + is_logging = true; + + constexpr int static_buf_size = 1024; + char static_buf[static_buf_size] = { '\0' }; + char *buf = static_buf; + va_list list_copy; + va_copy(list_copy, p_list); + int len = vsnprintf(buf, static_buf_size, p_format, p_list); + if (len >= static_buf_size) { + buf = (char *)Memory::alloc_static(len + 1); + vsnprintf(buf, len + 1, p_format, list_copy); + } + va_end(list_copy); + + String str; + str.append_utf8(buf, len); + for (Ref &logger : loggers) { + logger->log_message(str, p_err); + } + + if (len >= static_buf_size) { + Memory::free_static(buf); + } + + is_logging = false; +} + +void OS::LoggerBind::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, const Vector> &p_script_backtraces) { + if (!should_log(true) || is_logging) { + return; + } + + TypedArray backtraces; + backtraces.resize(p_script_backtraces.size()); + for (int i = 0; i < p_script_backtraces.size(); i++) { + backtraces[i] = p_script_backtraces[i]; + } + + is_logging = true; + + for (Ref &logger : loggers) { + logger->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, CoreBind::Logger::ErrorType(p_type), backtraces); + } + + is_logging = false; +} + PackedByteArray OS::get_entropy(int p_bytes) { PackedByteArray pba; pba.resize(p_bytes); @@ -628,6 +699,24 @@ String OS::get_unique_id() const { return ::OS::get_singleton()->get_unique_id(); } +void OS::add_logger(const Ref &p_logger) { + ERR_FAIL_COND(p_logger.is_null()); + + if (!logger_bind) { + logger_bind = memnew(LoggerBind); + ::OS::get_singleton()->add_logger(logger_bind); + } + + ERR_FAIL_COND_MSG(logger_bind->loggers.find(p_logger) != -1, "Could not add logger, as it has already been added."); + logger_bind->loggers.push_back(p_logger); +} + +void OS::remove_logger(const Ref &p_logger) { + ERR_FAIL_COND(p_logger.is_null()); + ERR_FAIL_COND_MSG(!logger_bind || logger_bind->loggers.find(p_logger) == -1, "Could not remove logger, as it hasn't been added."); + logger_bind->loggers.erase(p_logger); +} + OS *OS::singleton = nullptr; void OS::_bind_methods() { @@ -734,6 +823,9 @@ void OS::_bind_methods() { ClassDB::bind_method(D_METHOD("get_granted_permissions"), &OS::get_granted_permissions); ClassDB::bind_method(D_METHOD("revoke_granted_permissions"), &OS::revoke_granted_permissions); + ClassDB::bind_method(D_METHOD("add_logger", "logger"), &OS::add_logger); + ClassDB::bind_method(D_METHOD("remove_logger", "logger"), &OS::remove_logger); + ADD_PROPERTY(PropertyInfo(Variant::BOOL, "low_processor_usage_mode"), "set_low_processor_usage_mode", "is_in_low_processor_usage_mode"); ADD_PROPERTY(PropertyInfo(Variant::INT, "low_processor_usage_mode_sleep_usec"), "set_low_processor_usage_mode_sleep_usec", "get_low_processor_usage_mode_sleep_usec"); ADD_PROPERTY(PropertyInfo(Variant::BOOL, "delta_smoothing"), "set_delta_smoothing", "is_delta_smoothing_enabled"); @@ -764,6 +856,20 @@ void OS::_bind_methods() { BIND_ENUM_CONSTANT(STD_HANDLE_UNKNOWN); } +OS::OS() { + singleton = this; +} + +OS::~OS() { + if (singleton == this) { + singleton = nullptr; + } + + if (logger_bind) { + logger_bind->clear(); + } +} + ////// Geometry2D ////// Geometry2D *Geometry2D::singleton = nullptr; @@ -1901,6 +2007,16 @@ ScriptLanguage *Engine::get_script_language(int p_index) const { return ScriptServer::get_language(p_index); } +TypedArray Engine::capture_script_backtraces(bool p_include_variables) const { + Vector> backtraces = ScriptServer::capture_script_backtraces(p_include_variables); + TypedArray result; + result.resize(backtraces.size()); + for (int i = 0; i < backtraces.size(); i++) { + result[i] = backtraces[i]; + } + return result; +} + void Engine::set_editor_hint(bool p_enabled) { ::Engine::get_singleton()->set_editor_hint(p_enabled); } @@ -1988,6 +2104,7 @@ void Engine::_bind_methods() { ClassDB::bind_method(D_METHOD("unregister_script_language", "language"), &Engine::unregister_script_language); ClassDB::bind_method(D_METHOD("get_script_language_count"), &Engine::get_script_language_count); ClassDB::bind_method(D_METHOD("get_script_language", "index"), &Engine::get_script_language); + ClassDB::bind_method(D_METHOD("capture_script_backtraces", "include_variables"), &Engine::capture_script_backtraces, DEFVAL(false)); ClassDB::bind_method(D_METHOD("is_editor_hint"), &Engine::is_editor_hint); ClassDB::bind_method(D_METHOD("is_embedded_in_editor"), &Engine::is_embedded_in_editor); diff --git a/core/core_bind.h b/core/core_bind.h index ec74c53d5a..5f8f3165a6 100644 --- a/core/core_bind.h +++ b/core/core_bind.h @@ -33,13 +33,13 @@ #include "core/debugger/engine_profiler.h" #include "core/io/resource_loader.h" #include "core/io/resource_saver.h" +#include "core/object/script_backtrace.h" #include "core/os/semaphore.h" #include "core/os/thread.h" #include "core/templates/safe_refcount.h" +#include "core/variant/typed_array.h" class MainLoop; -template -class TypedArray; namespace CoreBind { @@ -119,11 +119,46 @@ public: ResourceSaver() { singleton = this; } }; +class Logger : public RefCounted { + GDCLASS(Logger, RefCounted); + +public: + enum ErrorType { + ERROR_TYPE_ERROR, + ERROR_TYPE_WARNING, + ERROR_TYPE_SCRIPT, + ERROR_TYPE_SHADER, + }; + +protected: + GDVIRTUAL2(_log_message, String, bool); + GDVIRTUAL8(_log_error, String, String, int, String, String, bool, int, TypedArray); + static void _bind_methods(); + +public: + 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 = false, ErrorType p_type = ERROR_TYPE_ERROR, const TypedArray &p_script_backtraces = {}); + virtual void log_message(const String &p_text, bool p_error); +}; + class OS : public Object { GDCLASS(OS, Object); mutable HashMap feature_cache; + class LoggerBind : public ::Logger { + inline static thread_local bool is_logging = false; + + public: + LocalVector> loggers; + + 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 = false, ErrorType p_type = ERR_ERROR, const Vector> &p_script_backtraces = {}) override; + + void clear() { loggers.clear(); } + }; + + LoggerBind *logger_bind = nullptr; + protected: static void _bind_methods(); static OS *singleton; @@ -274,9 +309,13 @@ public: Vector get_granted_permissions() const; void revoke_granted_permissions(); + void add_logger(const Ref &p_logger); + void remove_logger(const Ref &p_logger); + static OS *get_singleton() { return singleton; } - OS() { singleton = this; } + OS(); + ~OS(); }; class Geometry2D : public Object { @@ -579,6 +618,7 @@ public: Error unregister_script_language(const ScriptLanguage *p_language); int get_script_language_count(); ScriptLanguage *get_script_language(int p_index) const; + TypedArray capture_script_backtraces(bool p_include_variables = false) const; void set_editor_hint(bool p_enabled); bool is_editor_hint() const; @@ -653,6 +693,7 @@ public: } // namespace CoreBind +VARIANT_ENUM_CAST(CoreBind::Logger::ErrorType); VARIANT_ENUM_CAST(CoreBind::ResourceLoader::ThreadLoadStatus); VARIANT_ENUM_CAST(CoreBind::ResourceLoader::CacheMode); diff --git a/core/error/error_macros.cpp b/core/error/error_macros.cpp index adf58f5b67..f1b7d8eb12 100644 --- a/core/error/error_macros.cpp +++ b/core/error/error_macros.cpp @@ -32,6 +32,7 @@ #include "core/io/logger.h" #include "core/object/object_id.h" +#include "core/object/script_language.h" #include "core/os/os.h" #include "core/string/ustring.h" @@ -91,7 +92,15 @@ void _err_print_error(const char *p_function, const char *p_file, int p_line, co // Main error printing function. void _err_print_error(const char *p_function, const char *p_file, int p_line, const char *p_error, const char *p_message, bool p_editor_notify, ErrorHandlerType p_type) { if (OS::get_singleton()) { - OS::get_singleton()->print_error(p_function, p_file, p_line, p_error, p_message, p_editor_notify, (Logger::ErrorType)p_type); + Vector> script_backtraces; + + // If script languages aren't initialized, we could be in the process of shutting down, in which case we don't want to allocate any objects, as we could be + // logging ObjectDB leaks, where ObjectDB would be locked, thus causing a deadlock. + if (ScriptServer::are_languages_initialized()) { + script_backtraces = ScriptServer::capture_script_backtraces(false); + } + + OS::get_singleton()->print_error(p_function, p_file, p_line, p_error, p_message, p_editor_notify, (Logger::ErrorType)p_type, script_backtraces); } else { // Fallback if errors happen before OS init or after it's destroyed. const char *err_details = (p_message && *p_message) ? p_message : p_error; diff --git a/core/io/logger.cpp b/core/io/logger.cpp index d6094fcc10..827e309c8e 100644 --- a/core/io/logger.cpp +++ b/core/io/logger.cpp @@ -55,7 +55,7 @@ void Logger::set_flush_stdout_on_print(bool value) { _flush_stdout_on_print = value; } -void Logger::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) { +void Logger::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, const Vector> &p_script_backtraces) { if (!should_log(true)) { return; } @@ -88,6 +88,10 @@ void Logger::log_error(const char *p_function, const char *p_file, int p_line, c logf_error("%s: %s\n", err_type, err_details); logf_error(" at: %s (%s:%i)\n", p_function, p_file, p_line); + + for (const Ref &backtrace : p_script_backtraces) { + logf_error("%s\n", backtrace->format(3).utf8().get_data()); + } } void Logger::logf(const char *p_format, ...) { @@ -263,13 +267,13 @@ void CompositeLogger::logv(const char *p_format, va_list p_list, bool p_err) { } } -void CompositeLogger::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) { +void CompositeLogger::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, const Vector> &p_script_backtraces) { if (!should_log(true)) { return; } for (int i = 0; i < loggers.size(); ++i) { - loggers[i]->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type); + loggers[i]->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type, p_script_backtraces); } } diff --git a/core/io/logger.h b/core/io/logger.h index f3d8acade5..7d23103bbc 100644 --- a/core/io/logger.h +++ b/core/io/logger.h @@ -31,6 +31,7 @@ #pragma once #include "core/io/file_access.h" +#include "core/object/script_backtrace.h" #include "core/string/ustring.h" #include "core/templates/vector.h" @@ -55,7 +56,7 @@ public: static void set_flush_stdout_on_print(bool value); virtual void logv(const char *p_format, va_list p_list, bool p_err) _PRINTF_FORMAT_ATTRIBUTE_2_0 = 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 = false, ErrorType p_type = ERR_ERROR); + 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 = false, ErrorType p_type = ERR_ERROR, const Vector> &p_script_backtraces = {}); void logf(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3; void logf_error(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3; @@ -102,7 +103,7 @@ public: explicit CompositeLogger(const Vector &p_loggers); 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; + 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, const Vector> &p_script_backtraces = {}) override; void add_logger(Logger *p_logger); diff --git a/core/object/script_backtrace.cpp b/core/object/script_backtrace.cpp new file mode 100644 index 0000000000..e9548f83ee --- /dev/null +++ b/core/object/script_backtrace.cpp @@ -0,0 +1,196 @@ +/**************************************************************************/ +/* script_backtrace.cpp */ +/**************************************************************************/ +/* This file is part of: */ +/* GODOT ENGINE */ +/* https://godotengine.org */ +/**************************************************************************/ +/* Copyright (c) 2014-present Godot Engine contributors (see AUTHORS.md). */ +/* Copyright (c) 2007-2014 Juan Linietsky, Ariel Manzur. */ +/* */ +/* Permission is hereby granted, free of charge, to any person obtaining */ +/* a copy of this software and associated documentation files (the */ +/* "Software"), to deal in the Software without restriction, including */ +/* without limitation the rights to use, copy, modify, merge, publish, */ +/* distribute, sublicense, and/or sell copies of the Software, and to */ +/* permit persons to whom the Software is furnished to do so, subject to */ +/* the following conditions: */ +/* */ +/* The above copyright notice and this permission notice shall be */ +/* included in all copies or substantial portions of the Software. */ +/* */ +/* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, */ +/* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF */ +/* MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. */ +/* IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY */ +/* CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, */ +/* TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE */ +/* SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. */ +/**************************************************************************/ + +#include "script_backtrace.h" + +#include "core/object/script_language.h" + +void ScriptBacktrace::_store_variables(const List &p_names, const List &p_values, LocalVector &r_variables) { + r_variables.reserve(p_names.size()); + + const List::Element *name = p_names.front(); + const List::Element *value = p_values.front(); + + for (int i = 0; i < p_names.size(); i++) { + StackVariable variable; + variable.name = name->get(); + variable.value = value->get(); + r_variables.push_back(std::move(variable)); + + name = name->next(); + value = value->next(); + } +} + +void ScriptBacktrace::_bind_methods() { + ClassDB::bind_method(D_METHOD("get_language_name"), &ScriptBacktrace::get_language_name); + + ClassDB::bind_method(D_METHOD("get_frame_count"), &ScriptBacktrace::get_frame_count); + ClassDB::bind_method(D_METHOD("get_frame_function", "index"), &ScriptBacktrace::get_frame_function); + ClassDB::bind_method(D_METHOD("get_frame_file", "index"), &ScriptBacktrace::get_frame_file); + ClassDB::bind_method(D_METHOD("get_frame_line", "index"), &ScriptBacktrace::get_frame_line); + + ClassDB::bind_method(D_METHOD("get_global_variable_count"), &ScriptBacktrace::get_global_variable_count); + ClassDB::bind_method(D_METHOD("get_global_variable_name", "variable_index"), &ScriptBacktrace::get_global_variable_name); + ClassDB::bind_method(D_METHOD("get_global_variable_value", "variable_index"), &ScriptBacktrace::get_global_variable_value); + + ClassDB::bind_method(D_METHOD("get_local_variable_count", "frame_index"), &ScriptBacktrace::get_local_variable_count); + ClassDB::bind_method(D_METHOD("get_local_variable_name", "frame_index", "variable_index"), &ScriptBacktrace::get_local_variable_name); + ClassDB::bind_method(D_METHOD("get_local_variable_value", "frame_index", "variable_index"), &ScriptBacktrace::get_local_variable_value); + + ClassDB::bind_method(D_METHOD("get_member_variable_count", "frame_index"), &ScriptBacktrace::get_member_variable_count); + ClassDB::bind_method(D_METHOD("get_member_variable_name", "frame_index", "variable_index"), &ScriptBacktrace::get_member_variable_name); + ClassDB::bind_method(D_METHOD("get_member_variable_value", "frame_index", "variable_index"), &ScriptBacktrace::get_member_variable_value); + + ClassDB::bind_method(D_METHOD("format", "indent_all", "indent_frames"), &ScriptBacktrace::format, DEFVAL(0), DEFVAL(4)); +} + +ScriptBacktrace::ScriptBacktrace(ScriptLanguage *p_language, bool p_include_variables) { + language_name = p_language->get_name(); + + Vector stack_infos = p_language->debug_get_current_stack_info(); + stack_frames.reserve(stack_infos.size()); + + if (p_include_variables) { + List globals_names; + List globals_values; + p_language->debug_get_globals(&globals_names, &globals_values); + _store_variables(globals_names, globals_values, global_variables); + } + + for (int i = 0; i < stack_infos.size(); i++) { + const ScriptLanguage::StackInfo &stack_info = stack_infos[i]; + + StackFrame stack_frame; + stack_frame.function = stack_info.func; + stack_frame.file = stack_info.file; + stack_frame.line = stack_info.line; + + if (p_include_variables) { + List locals_names; + List locals_values; + p_language->debug_get_stack_level_locals(i, &locals_names, &locals_values); + _store_variables(locals_names, locals_values, stack_frame.local_variables); + + List members_names; + List members_values; + p_language->debug_get_stack_level_members(i, &members_names, &members_values); + _store_variables(members_names, members_values, stack_frame.member_variables); + } + + stack_frames.push_back(std::move(stack_frame)); + } +} + +String ScriptBacktrace::get_frame_function(int p_index) const { + ERR_FAIL_INDEX_V(p_index, (int)stack_frames.size(), String()); + return stack_frames[p_index].function; +} + +String ScriptBacktrace::get_frame_file(int p_index) const { + ERR_FAIL_INDEX_V(p_index, (int)stack_frames.size(), String()); + return stack_frames[p_index].file; +} + +int ScriptBacktrace::get_frame_line(int p_index) const { + ERR_FAIL_INDEX_V(p_index, (int)stack_frames.size(), -1); + return stack_frames[p_index].line; +} + +String ScriptBacktrace::get_global_variable_name(int p_variable_index) const { + ERR_FAIL_INDEX_V(p_variable_index, (int)global_variables.size(), String()); + return global_variables[p_variable_index].name; +} + +Variant ScriptBacktrace::get_global_variable_value(int p_variable_index) const { + ERR_FAIL_INDEX_V(p_variable_index, (int)global_variables.size(), String()); + return global_variables[p_variable_index].value; +} + +int ScriptBacktrace::get_local_variable_count(int p_frame_index) const { + ERR_FAIL_INDEX_V(p_frame_index, (int)stack_frames.size(), 0); + return (int)stack_frames[p_frame_index].local_variables.size(); +} + +String ScriptBacktrace::get_local_variable_name(int p_frame_index, int p_variable_index) const { + ERR_FAIL_INDEX_V(p_frame_index, (int)stack_frames.size(), String()); + const LocalVector &local_variables = stack_frames[p_frame_index].local_variables; + ERR_FAIL_INDEX_V(p_variable_index, (int)local_variables.size(), String()); + return local_variables[p_variable_index].name; +} + +Variant ScriptBacktrace::get_local_variable_value(int p_frame_index, int p_variable_index) const { + ERR_FAIL_INDEX_V(p_frame_index, (int)stack_frames.size(), String()); + const LocalVector &variables = stack_frames[p_frame_index].local_variables; + ERR_FAIL_INDEX_V(p_variable_index, (int)variables.size(), String()); + return variables[p_variable_index].value; +} + +int ScriptBacktrace::get_member_variable_count(int p_frame_index) const { + ERR_FAIL_INDEX_V(p_frame_index, (int)stack_frames.size(), 0); + return (int)stack_frames[p_frame_index].member_variables.size(); +} + +String ScriptBacktrace::get_member_variable_name(int p_frame_index, int p_variable_index) const { + ERR_FAIL_INDEX_V(p_frame_index, (int)stack_frames.size(), String()); + const LocalVector &variables = stack_frames[p_frame_index].member_variables; + ERR_FAIL_INDEX_V(p_variable_index, (int)variables.size(), String()); + return variables[p_variable_index].name; +} + +Variant ScriptBacktrace::get_member_variable_value(int p_frame_index, int p_variable_index) const { + ERR_FAIL_INDEX_V(p_frame_index, (int)stack_frames.size(), String()); + const LocalVector &variables = stack_frames[p_frame_index].member_variables; + ERR_FAIL_INDEX_V(p_variable_index, (int)variables.size(), String()); + return variables[p_variable_index].value; +} + +String ScriptBacktrace::format(int p_indent_all, int p_indent_frames) const { + if (stack_frames.is_empty()) { + return String(); + } + + static const String space = String::chr(U' '); + String indent_all = space.repeat(p_indent_all); + String indent_frames = space.repeat(p_indent_frames); + String indent_total = indent_all + indent_frames; + + String result = indent_all + language_name + " backtrace (most recent call first):"; + for (int i = 0; i < (int)stack_frames.size(); i++) { + const StackFrame &stack_frame = stack_frames[i]; + result += "\n" + indent_total + "[" + itos(i) + "] " + stack_frame.function; + + if (!stack_frame.file.is_empty()) { + result += " (" + stack_frame.file + ":" + itos(stack_frame.line) + ")"; + } + } + + return result; +} diff --git a/core/object/script_backtrace.h b/core/object/script_backtrace.h new file mode 100644 index 0000000000..cd500730a3 --- /dev/null +++ b/core/object/script_backtrace.h @@ -0,0 +1,87 @@ +/**************************************************************************/ +/* script_backtrace.h */ +/**************************************************************************/ +/* This file is part of: */ +/* GODOT ENGINE */ +/* https://godotengine.org */ +/**************************************************************************/ +/* Copyright (c) 2014-present Godot Engine contributors (see AUTHORS.md). */ +/* Copyright (c) 2007-2014 Juan Linietsky, Ariel Manzur. */ +/* */ +/* Permission is hereby granted, free of charge, to any person obtaining */ +/* a copy of this software and associated documentation files (the */ +/* "Software"), to deal in the Software without restriction, including */ +/* without limitation the rights to use, copy, modify, merge, publish, */ +/* distribute, sublicense, and/or sell copies of the Software, and to */ +/* permit persons to whom the Software is furnished to do so, subject to */ +/* the following conditions: */ +/* */ +/* The above copyright notice and this permission notice shall be */ +/* included in all copies or substantial portions of the Software. */ +/* */ +/* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, */ +/* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF */ +/* MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. */ +/* IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY */ +/* CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, */ +/* TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE */ +/* SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. */ +/**************************************************************************/ + +#pragma once + +#include "core/object/ref_counted.h" + +class ScriptLanguage; + +class ScriptBacktrace : public RefCounted { + GDCLASS(ScriptBacktrace, RefCounted); + + struct StackVariable { + String name; + Variant value; + }; + + struct StackFrame { + LocalVector local_variables; + LocalVector member_variables; + String function; + String file; + int line = 0; + }; + + LocalVector stack_frames; + LocalVector global_variables; + String language_name; + + static void _store_variables(const List &p_names, const List &p_values, LocalVector &r_variables); + +protected: + static void _bind_methods(); + +public: + ScriptBacktrace() = default; + ScriptBacktrace(ScriptLanguage *p_language, bool p_include_variables = false); + + String get_language_name() const { return language_name; } + + int get_frame_count() const { return stack_frames.size(); } + String get_frame_function(int p_index) const; + String get_frame_file(int p_index) const; + int get_frame_line(int p_index) const; + + int get_global_variable_count() const { return global_variables.size(); } + String get_global_variable_name(int p_variable_index) const; + Variant get_global_variable_value(int p_variable_index) const; + + int get_local_variable_count(int p_frame_index) const; + String get_local_variable_name(int p_frame_index, int p_variable_index) const; + Variant get_local_variable_value(int p_frame_index, int p_variable_index) const; + + int get_member_variable_count(int p_frame_index) const; + String get_member_variable_name(int p_frame_index, int p_variable_index) const; + Variant get_member_variable_value(int p_frame_index, int p_variable_index) const; + + String format(int p_indent_all = 0, int p_indent_frames = 4) const; + virtual String to_string() override { return format(); } +}; diff --git a/core/object/script_language.cpp b/core/object/script_language.cpp index 33bf7ab48a..b5ce3f3c54 100644 --- a/core/object/script_language.cpp +++ b/core/object/script_language.cpp @@ -535,6 +535,17 @@ void ScriptServer::save_global_classes() { ProjectSettings::get_singleton()->store_global_class_list(gcarr); } +Vector> ScriptServer::capture_script_backtraces(bool p_include_variables) { + int language_count = ScriptServer::get_language_count(); + Vector> result; + result.resize(language_count); + for (int i = 0; i < language_count; i++) { + ScriptLanguage *language = ScriptServer::get_language(i); + result.write[i].instantiate(language, p_include_variables); + } + return result; +} + //////////////////// ScriptCodeCompletionCache *ScriptCodeCompletionCache::singleton = nullptr; diff --git a/core/object/script_language.h b/core/object/script_language.h index 7d439da6ca..056f543905 100644 --- a/core/object/script_language.h +++ b/core/object/script_language.h @@ -32,6 +32,7 @@ #include "core/doc_data.h" #include "core/io/resource.h" +#include "core/object/script_backtrace.h" #include "core/object/script_instance.h" #include "core/templates/pair.h" #include "core/templates/safe_refcount.h" @@ -101,6 +102,8 @@ public: static void get_inheriters_list(const StringName &p_base_type, List *r_classes); static void save_global_classes(); + static Vector> capture_script_backtraces(bool p_include_variables = false); + static void init_languages(); static void finish_languages(); static bool are_languages_initialized(); diff --git a/core/os/os.cpp b/core/os/os.cpp index 385d1f4480..d0045f5588 100644 --- a/core/os/os.cpp +++ b/core/os/os.cpp @@ -84,13 +84,13 @@ String OS::get_identifier() const { return get_name().to_lower(); } -void OS::print_error(const char *p_function, const char *p_file, int p_line, const char *p_code, const char *p_rationale, bool p_editor_notify, Logger::ErrorType p_type) { +void OS::print_error(const char *p_function, const char *p_file, int p_line, const char *p_code, const char *p_rationale, bool p_editor_notify, Logger::ErrorType p_type, const Vector> &p_script_backtraces) { if (!_stderr_enabled) { return; } if (_logger) { - _logger->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type); + _logger->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type, p_script_backtraces); } } diff --git a/core/os/os.h b/core/os/os.h index 51ea976d58..7d5589beb4 100644 --- a/core/os/os.h +++ b/core/os/os.h @@ -111,7 +111,6 @@ protected: bool _silent_crash_handler = false; // Functions used by Main to initialize/deinitialize the OS. - void add_logger(Logger *p_logger); virtual void initialize() = 0; virtual void initialize_joypads() = 0; @@ -142,7 +141,7 @@ public: virtual Vector get_video_adapter_driver_info() const = 0; virtual bool get_user_prefers_integrated_gpu() const { return false; } - void print_error(const char *p_function, const char *p_file, int p_line, const char *p_code, const char *p_rationale, bool p_editor_notify = false, Logger::ErrorType p_type = Logger::ERR_ERROR); + void print_error(const char *p_function, const char *p_file, int p_line, const char *p_code, const char *p_rationale, bool p_editor_notify = false, Logger::ErrorType p_type = Logger::ERR_ERROR, const Vector> &p_script_backtraces = {}); void print(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3; void print_rich(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3; void printerr(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3; @@ -353,6 +352,8 @@ public: virtual Error setup_remote_filesystem(const String &p_server_host, int p_port, const String &p_password, String &r_project_path); + void add_logger(Logger *p_logger); + enum PreferredTextureFormat { PREFERRED_TEXTURE_FORMAT_S3TC_BPTC, PREFERRED_TEXTURE_FORMAT_ETC2_ASTC diff --git a/core/register_core_types.cpp b/core/register_core_types.cpp index d76ebc2a35..4b17a9fb3e 100644 --- a/core/register_core_types.cpp +++ b/core/register_core_types.cpp @@ -71,6 +71,7 @@ #include "core/math/random_number_generator.h" #include "core/math/triangle_mesh.h" #include "core/object/class_db.h" +#include "core/object/script_backtrace.h" #include "core/object/script_language_extension.h" #include "core/object/undo_redo.h" #include "core/object/worker_thread_pool.h" @@ -162,7 +163,7 @@ void register_core_types() { GDREGISTER_ABSTRACT_CLASS(Script); GDREGISTER_ABSTRACT_CLASS(ScriptLanguage); - + GDREGISTER_CLASS(ScriptBacktrace); GDREGISTER_VIRTUAL_CLASS(ScriptExtension); GDREGISTER_VIRTUAL_CLASS(ScriptLanguageExtension); @@ -254,6 +255,7 @@ void register_core_types() { GDREGISTER_CLASS(CoreBind::Thread); GDREGISTER_CLASS(CoreBind::Mutex); GDREGISTER_CLASS(CoreBind::Semaphore); + GDREGISTER_VIRTUAL_CLASS(CoreBind::Logger); GDREGISTER_CLASS(XMLParser); GDREGISTER_CLASS(JSON); diff --git a/core/variant/variant_utility.cpp b/core/variant/variant_utility.cpp index b07cc2a85b..7ed71a5e3c 100644 --- a/core/variant/variant_utility.cpp +++ b/core/variant/variant_utility.cpp @@ -32,6 +32,7 @@ #include "core/io/marshalls.h" #include "core/object/ref_counted.h" +#include "core/object/script_language.h" #include "core/os/os.h" #include "core/templates/oa_hash_map.h" #include "core/templates/rid.h" diff --git a/doc/classes/Engine.xml b/doc/classes/Engine.xml index ed21f82966..9ca4a02c7b 100644 --- a/doc/classes/Engine.xml +++ b/doc/classes/Engine.xml @@ -9,6 +9,16 @@ + + + + + Captures and returns backtraces from all registered script languages. + By default, the returned [ScriptBacktrace] will only contain stack frames in editor builds and debug builds. To enable them for release builds as well, you need to enable [member ProjectSettings.debug/settings/gdscript/always_track_call_stacks]. + If [param include_variables] is [code]true[/code], the backtrace will also include the names and values of any global variables (e.g. autoload singletons) at the point of the capture, as well as local variables and class member variables at each stack frame. This will however will only be respected when running the game with a debugger attached, like when running the game from the editor. To enable it for export builds as well, you need to enable [member ProjectSettings.debug/settings/gdscript/always_track_local_variables]. + [b]Warning:[/b] When [param include_variables] is [code]true[/code], any captured variables can potentially (e.g. with GDScript backtraces) be their actual values, including any object references. This means that storing such a [ScriptBacktrace] will prevent those objects from being deallocated, so it's generally recommended not to do so. + + diff --git a/doc/classes/Logger.xml b/doc/classes/Logger.xml new file mode 100644 index 0000000000..026bce7a2c --- /dev/null +++ b/doc/classes/Logger.xml @@ -0,0 +1,54 @@ + + + + Custom logger to receive messages from the internal error/warning stream. + + + Custom logger to receive messages from the internal error/warning stream. Loggers are registered via [method OS.add_logger]. + + + + + + + + + + + + + + + + Called when an error is logged. The error provides the [param function], [param file], and [param line] that it originated from, as well as either the [param code] that generated the error or a [param rationale]. + The type of error provided by [param error_type] is described in the [enum ErrorType] enumeration. + Additionally, [param script_backtraces] provides backtraces for each of the script languages. These will only contain stack frames in editor builds and debug builds by default. To enable them for release builds as well, you need to enable [member ProjectSettings.debug/settings/gdscript/always_track_call_stacks]. + [b]Warning:[/b] This function may be called from multiple different threads, so you may need to do your own locking. + [b]Note:[/b] [param script_backtraces] will not contain any captured variables, due to its prohibitively high cost. To get those you will need to capture the backtraces yourself, from within the [Logger] virtual methods, using [method Engine.capture_script_backtraces]. + + + + + + + + Called when a message is logged. If [param error] is [code]true[/code], then this message was meant to be sent to [code]stderr[/code]. + [b]Warning:[/b] This function may be called from multiple different threads, so you may need to do your own locking. + + + + + + The message received is an error. + + + The message received is a warning. + + + The message received is a script error. + + + The message received is a shader error. + + + diff --git a/doc/classes/OS.xml b/doc/classes/OS.xml index 9e9ba92d0f..bd3cddd266 100644 --- a/doc/classes/OS.xml +++ b/doc/classes/OS.xml @@ -11,6 +11,13 @@ https://godotengine.org/asset-library/asset/2789 + + + + + Add a custom logger to intercept the internal message stream. + + @@ -743,6 +750,13 @@ [b]Note:[/b] On exported Windows builds, run the console wrapper executable to access the terminal. If standard input is console, calling this method without console wrapped will freeze permanently. If standard input is pipe or file, it can be used without console wrapper. If you need a single executable with full console support, use a custom build compiled with the [code]windows_subsystem=console[/code] flag. + + + + + Remove a custom logger added by [method add_logger]. + + diff --git a/doc/classes/ProjectSettings.xml b/doc/classes/ProjectSettings.xml index 5efb668228..8f101c711b 100644 --- a/doc/classes/ProjectSettings.xml +++ b/doc/classes/ProjectSettings.xml @@ -630,6 +630,16 @@ Editor-only override for [member debug/settings/crash_handler/message]. Does not affect exported projects in debug or release mode. + + Whether GDScript call stacks will be tracked in release builds, thus allowing [method Engine.capture_script_backtraces] to function. + Enabling this comes at the cost of roughly 40 KiB for every thread that runs any GDScript code. + [b]Note:[/b] This setting has no effect on editor builds or debug builds, where GDScript call stacks are tracked regardless. + + + Whether GDScript local variables will be tracked in all builds, including export builds, thus allowing [method Engine.capture_script_backtraces] to capture them when enabling its [code]include_variables[/code] parameter. + Enabling this comes at the cost of roughly 50 bytes of memory per local variable, for every compiled class in the entire project, so can be several MiB in larger projects. + [b]Note:[/b] This setting has no effect when running the game from the editor, where GDScript local variables are tracked regardless. + Maximum call stack allowed for debugging GDScript. diff --git a/doc/classes/ScriptBacktrace.xml b/doc/classes/ScriptBacktrace.xml new file mode 100644 index 0000000000..1e8e5b6132 --- /dev/null +++ b/doc/classes/ScriptBacktrace.xml @@ -0,0 +1,128 @@ + + + + A captured backtrace of a specific script language. + + + [ScriptBacktrace] holds an already captured backtrace of a specific script language, such as GDScript or C#, which are captured using [method Engine.capture_script_backtraces]. + See [member ProjectSettings.debug/settings/gdscript/always_track_call_stacks] and [member ProjectSettings.debug/settings/gdscript/always_track_local_variables] for ways of controlling the contents of this class. + + + + + + + + + + Converts the backtrace to a [String], where the entire string will be indented by [param indent_all] number of spaces, and the individual stack frames will be additionally indented by [param indent_frames] number of spaces. + [b]Note:[/b] Calling [method Object.to_string] on a [ScriptBacktrace] will produce the same output as calling [method format] with all parameters left at their default values. + + + + + + Returns the number of stack frames in the backtrace. + + + + + + + Returns the file name of the call site represented by the stack frame at the specified index. + + + + + + + Returns the name of the function called at the stack frame at the specified index. + + + + + + + Returns the line number of the call site represented by the stack frame at the specified index. + + + + + + Returns the number of global variables (e.g. autoload singletons) in the backtrace. + [b]Note:[/b] This will be non-zero only if the [code]include_variables[/code] parameter was [code]true[/code] when capturing the backtrace with [method Engine.capture_script_backtraces]. + + + + + + + Returns the name of the global variable at the specified index. + + + + + + + Returns the value of the global variable at the specified index. + [b]Warning:[/b] With GDScript backtraces, the returned [Variant] will be the variable's actual value, including any object references. This means that storing the returned [Variant] will prevent any such object from being deallocated, so it's generally recommended not to do so. + + + + + + Returns the name of the script language that this backtrace was captured from. + + + + + + + Returns the number of local variables in the stack frame at the specified index. + [b]Note:[/b] This will be non-zero only if the [code]include_variables[/code] parameter was [code]true[/code] when capturing the backtrace with [method Engine.capture_script_backtraces]. + + + + + + + + Returns the name of the local variable at the specified [param variable_index] in the stack frame at the specified [param frame_index]. + + + + + + + + Returns the value of the local variable at the specified [param variable_index] in the stack frame at the specified [param frame_index]. + [b]Warning:[/b] With GDScript backtraces, the returned [Variant] will be the variable's actual value, including any object references. This means that storing the returned [Variant] will prevent any such object from being deallocated, so it's generally recommended not to do so. + + + + + + + Returns the number of member variables in the stack frame at the specified index. + [b]Note:[/b] This will be non-zero only if the [code]include_variables[/code] parameter was [code]true[/code] when capturing the backtrace with [method Engine.capture_script_backtraces]. + + + + + + + + Returns the name of the member variable at the specified [param variable_index] in the stack frame at the specified [param frame_index]. + + + + + + + + Returns the value of the member variable at the specified [param variable_index] in the stack frame at the specified [param frame_index]. + [b]Warning:[/b] With GDScript backtraces, the returned [Variant] will be the variable's actual value, including any object references. This means that storing the returned [Variant] will prevent any such object from being deallocated, so it's generally recommended not to do so. + + + + diff --git a/drivers/unix/os_unix.cpp b/drivers/unix/os_unix.cpp index a6c3095bcb..5f4cfa332c 100644 --- a/drivers/unix/os_unix.cpp +++ b/drivers/unix/os_unix.cpp @@ -1151,7 +1151,7 @@ String OS_Unix::get_executable_path() const { #endif } -void UnixTerminalLogger::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) { +void UnixTerminalLogger::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, const Vector> &p_script_backtraces) { if (!should_log(true)) { return; } @@ -1178,25 +1178,32 @@ void UnixTerminalLogger::log_error(const char *p_function, const char *p_file, i const char *cyan_bold = tty ? "\E[1;36m" : ""; const char *reset = tty ? "\E[0m" : ""; + const char *indent = ""; switch (p_type) { case ERR_WARNING: + indent = " "; logf_error("%sWARNING:%s %s\n", yellow_bold, yellow, err_details); - logf_error("%s at: %s (%s:%i)%s\n", gray, p_function, p_file, p_line, reset); break; case ERR_SCRIPT: + indent = " "; logf_error("%sSCRIPT ERROR:%s %s\n", magenta_bold, magenta, err_details); - logf_error("%s at: %s (%s:%i)%s\n", gray, p_function, p_file, p_line, reset); break; case ERR_SHADER: + indent = " "; logf_error("%sSHADER ERROR:%s %s\n", cyan_bold, cyan, err_details); - logf_error("%s at: %s (%s:%i)%s\n", gray, p_function, p_file, p_line, reset); break; case ERR_ERROR: default: + indent = " "; logf_error("%sERROR:%s %s\n", red_bold, red, err_details); - logf_error("%s at: %s (%s:%i)%s\n", gray, p_function, p_file, p_line, reset); break; } + + logf_error("%s%sat: %s (%s:%i)%s\n", gray, indent, p_function, p_file, p_line, reset); + + for (const Ref &backtrace : p_script_backtraces) { + logf_error("%s%s%s\n", gray, backtrace->format(strlen(indent)).utf8().get_data(), reset); + } } UnixTerminalLogger::~UnixTerminalLogger() {} diff --git a/drivers/unix/os_unix.h b/drivers/unix/os_unix.h index 8fde52b5ff..afca9d6901 100644 --- a/drivers/unix/os_unix.h +++ b/drivers/unix/os_unix.h @@ -141,7 +141,7 @@ public: class UnixTerminalLogger : public StdLogger { public: - 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 = false, ErrorType p_type = ERR_ERROR) override; + 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 = false, ErrorType p_type = ERR_ERROR, const Vector> &p_script_backtraces = {}) override; virtual ~UnixTerminalLogger(); }; diff --git a/modules/gdscript/gdscript.cpp b/modules/gdscript/gdscript.cpp index 325d3a8e08..4bcc96d454 100644 --- a/modules/gdscript/gdscript.cpp +++ b/modules/gdscript/gdscript.cpp @@ -2942,17 +2942,14 @@ GDScriptLanguage::GDScriptLanguage() { script_frame_time = 0; #endif - int dmcs = GLOBAL_DEF(PropertyInfo(Variant::INT, "debug/settings/gdscript/max_call_stack", PROPERTY_HINT_RANGE, "512," + itos(GDScriptFunction::MAX_CALL_DEPTH - 1) + ",1"), 1024); - - if (EngineDebugger::is_active()) { - //debugging enabled! - - _debug_max_call_stack = dmcs; - } else { - _debug_max_call_stack = 0; - } + _debug_max_call_stack = GLOBAL_DEF_RST(PropertyInfo(Variant::INT, "debug/settings/gdscript/max_call_stack", PROPERTY_HINT_RANGE, "512," + itos(GDScriptFunction::MAX_CALL_DEPTH - 1) + ",1"), 1024); + track_call_stack = GLOBAL_DEF_RST("debug/settings/gdscript/always_track_call_stacks", false); + track_locals = GLOBAL_DEF_RST("debug/settings/gdscript/always_track_local_variables", false); #ifdef DEBUG_ENABLED + track_call_stack = true; + track_locals = track_locals || EngineDebugger::is_active(); + GLOBAL_DEF("debug/gdscript/warnings/enable", true); GLOBAL_DEF("debug/gdscript/warnings/exclude_addons", true); GLOBAL_DEF("debug/gdscript/warnings/renamed_in_godot_4_hint", true); diff --git a/modules/gdscript/gdscript.h b/modules/gdscript/gdscript.h index 11e00b4c3c..4c138860bc 100644 --- a/modules/gdscript/gdscript.h +++ b/modules/gdscript/gdscript.h @@ -455,6 +455,8 @@ class GDScriptLanguage : public ScriptLanguage { static thread_local CallStack _call_stack; int _debug_max_call_stack = 0; + bool track_call_stack = false; + bool track_locals = false; void _add_global(const StringName &p_name, const Variant &p_value); void _remove_global(const StringName &p_name); @@ -487,37 +489,63 @@ public: bool debug_break_parse(const String &p_file, int p_line, const String &p_error); _FORCE_INLINE_ void enter_function(GDScriptInstance *p_instance, GDScriptFunction *p_function, Variant *p_stack, int *p_ip, int *p_line) { + if (!track_call_stack) { + return; + } + if (unlikely(_call_stack.levels == nullptr)) { _call_stack.levels = memnew_arr(CallLevel, _debug_max_call_stack + 1); } - if (EngineDebugger::get_script_debugger()->get_lines_left() > 0 && EngineDebugger::get_script_debugger()->get_depth() >= 0) { - EngineDebugger::get_script_debugger()->set_depth(EngineDebugger::get_script_debugger()->get_depth() + 1); +#ifdef DEBUG_ENABLED + ScriptDebugger *script_debugger = EngineDebugger::get_script_debugger(); + if (script_debugger != nullptr && script_debugger->get_lines_left() > 0 && script_debugger->get_depth() >= 0) { + script_debugger->set_depth(script_debugger->get_depth() + 1); } +#endif - if (_call_stack.stack_pos >= _debug_max_call_stack) { - //stack overflow + if (unlikely(_call_stack.stack_pos >= _debug_max_call_stack)) { _debug_error = vformat("Stack overflow (stack size: %s). Check for infinite recursion in your script.", _debug_max_call_stack); - EngineDebugger::get_script_debugger()->debug(this); + +#ifdef DEBUG_ENABLED + if (script_debugger != nullptr) { + script_debugger->debug(this); + } +#endif + return; } - _call_stack.levels[_call_stack.stack_pos].stack = p_stack; - _call_stack.levels[_call_stack.stack_pos].instance = p_instance; - _call_stack.levels[_call_stack.stack_pos].function = p_function; - _call_stack.levels[_call_stack.stack_pos].ip = p_ip; - _call_stack.levels[_call_stack.stack_pos].line = p_line; + CallLevel &call_level = _call_stack.levels[_call_stack.stack_pos]; + call_level.stack = p_stack; + call_level.instance = p_instance; + call_level.function = p_function; + call_level.ip = p_ip; + call_level.line = p_line; _call_stack.stack_pos++; } _FORCE_INLINE_ void exit_function() { - if (EngineDebugger::get_script_debugger()->get_lines_left() > 0 && EngineDebugger::get_script_debugger()->get_depth() >= 0) { - EngineDebugger::get_script_debugger()->set_depth(EngineDebugger::get_script_debugger()->get_depth() - 1); + if (!track_call_stack) { + return; } - if (_call_stack.stack_pos == 0) { +#ifdef DEBUG_ENABLED + ScriptDebugger *script_debugger = EngineDebugger::get_script_debugger(); + if (script_debugger != nullptr && script_debugger->get_lines_left() > 0 && script_debugger->get_depth() >= 0) { + script_debugger->set_depth(script_debugger->get_depth() - 1); + } +#endif + + if (unlikely(_call_stack.stack_pos == 0)) { _debug_error = "Stack Underflow (Engine Bug)"; - EngineDebugger::get_script_debugger()->debug(this); + +#ifdef DEBUG_ENABLED + if (script_debugger != nullptr) { + script_debugger->debug(this); + } +#endif + return; } @@ -551,6 +579,7 @@ public: } strings; + _FORCE_INLINE_ bool should_track_locals() const { return track_locals; } _FORCE_INLINE_ int get_global_array_size() const { return global_array.size(); } _FORCE_INLINE_ Variant *get_global_array() { return _global_array; } _FORCE_INLINE_ const HashMap &get_global_map() const { return globals; } diff --git a/modules/gdscript/gdscript_byte_codegen.cpp b/modules/gdscript/gdscript_byte_codegen.cpp index 122e9cb4ba..c473feb717 100644 --- a/modules/gdscript/gdscript_byte_codegen.cpp +++ b/modules/gdscript/gdscript_byte_codegen.cpp @@ -161,7 +161,7 @@ void GDScriptByteCodeGenerator::end_parameters() { void GDScriptByteCodeGenerator::write_start(GDScript *p_script, const StringName &p_function_name, bool p_static, Variant p_rpc_config, const GDScriptDataType &p_return_type) { function = memnew(GDScriptFunction); - debug_stack = EngineDebugger::is_active(); + debug_stack = GDScriptLanguage::get_singleton()->should_track_locals(); function->name = p_function_name; function->_script = p_script; diff --git a/modules/gdscript/gdscript_function.cpp b/modules/gdscript/gdscript_function.cpp index 372c212d2b..85e25a3c13 100644 --- a/modules/gdscript/gdscript_function.cpp +++ b/modules/gdscript/gdscript_function.cpp @@ -237,11 +237,9 @@ Variant GDScriptFunctionState::resume(const Variant &p_arg) { emit_signal(SNAME("completed"), ret); } -#ifdef DEBUG_ENABLED - if (EngineDebugger::is_active()) { - GDScriptLanguage::get_singleton()->exit_function(); - } + GDScriptLanguage::get_singleton()->exit_function(); +#ifdef DEBUG_ENABLED _clear_stack(); #endif } diff --git a/modules/gdscript/gdscript_vm.cpp b/modules/gdscript/gdscript_vm.cpp index 81c8ce939a..d0892ec142 100644 --- a/modules/gdscript/gdscript_vm.cpp +++ b/modules/gdscript/gdscript_vm.cpp @@ -621,12 +621,9 @@ Variant GDScriptFunction::call(GDScriptInstance *p_instance, const Variant **p_a String err_text; + GDScriptLanguage::get_singleton()->enter_function(p_instance, this, stack, &ip, &line); + #ifdef DEBUG_ENABLED - - if (EngineDebugger::is_active()) { - GDScriptLanguage::get_singleton()->enter_function(p_instance, this, stack, &ip, &line); - } - #define GD_ERR_BREAK(m_cond) \ { \ if (unlikely(m_cond)) { \ @@ -698,10 +695,10 @@ Variant GDScriptFunction::call(GDScriptInstance *p_instance, const Variant **p_a profile.frame_call_count.increment(); } bool exit_ok = false; - bool awaited = false; int variant_address_limits[ADDR_TYPE_MAX] = { _stack_size, _constant_count, p_instance ? (int)p_instance->members.size() : 0 }; #endif + bool awaited = false; Variant *variant_addresses[ADDR_TYPE_MAX] = { stack, _constants_ptr, p_instance ? p_instance->members.ptrw() : nullptr }; #ifdef DEBUG_ENABLED @@ -2567,9 +2564,10 @@ Variant GDScriptFunction::call(GDScriptInstance *p_instance, const Variant **p_a OPCODE_BREAK; } + awaited = true; + #ifdef DEBUG_ENABLED exit_ok = true; - awaited = true; #endif OPCODE_BREAK; } @@ -3865,23 +3863,19 @@ Variant GDScriptFunction::call(GDScriptInstance *p_instance, const Variant **p_a GDScriptLanguage::get_singleton()->script_frame_time += time_taken - function_call_time; } } +#endif // Check if this is not the last time it was interrupted by `await` or if it's the first time executing. // If that is the case then we exit the function as normal. Otherwise we postpone it until the last `await` is completed. // This ensures the call stack can be properly shown when using `await`, showing what resumed the function. if (!p_state || awaited) { - if (EngineDebugger::is_active()) { - GDScriptLanguage::get_singleton()->exit_function(); - } -#endif + GDScriptLanguage::get_singleton()->exit_function(); // Free stack, except reserved addresses. for (int i = FIXED_ADDRESSES_MAX; i < _stack_size; i++) { stack[i].~Variant(); } -#ifdef DEBUG_ENABLED } -#endif // Always free reserved addresses, since they are never copied. for (int i = 0; i < FIXED_ADDRESSES_MAX; i++) { diff --git a/modules/mono/csharp_script.cpp b/modules/mono/csharp_script.cpp index 8abd2126f1..7c991d3a34 100644 --- a/modules/mono/csharp_script.cpp +++ b/modules/mono/csharp_script.cpp @@ -490,7 +490,6 @@ String CSharpLanguage::debug_get_stack_level_source(int p_level) const { } Vector CSharpLanguage::debug_get_current_stack_info() { -#ifdef DEBUG_ENABLED // Printing an error here will result in endless recursion, so we must be careful static thread_local bool _recursion_flag_ = false; if (_recursion_flag_) { @@ -512,9 +511,6 @@ Vector CSharpLanguage::debug_get_current_stack_info() } return si; -#else - return Vector(); -#endif } void CSharpLanguage::post_unsafe_reference(Object *p_obj) { diff --git a/platform/ios/ios_terminal_logger.h b/platform/ios/ios_terminal_logger.h index 8365ace134..7f4f0445d2 100644 --- a/platform/ios/ios_terminal_logger.h +++ b/platform/ios/ios_terminal_logger.h @@ -36,7 +36,7 @@ class IOSTerminalLogger : public StdLogger { public: - 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 = false, ErrorType p_type = ERR_ERROR) override; + 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 = false, ErrorType p_type = ERR_ERROR, const Vector> &p_script_backtraces = {}) override; }; #endif // IOS_ENABLED diff --git a/platform/ios/ios_terminal_logger.mm b/platform/ios/ios_terminal_logger.mm index c5a6d1113a..1e6071b8e9 100644 --- a/platform/ios/ios_terminal_logger.mm +++ b/platform/ios/ios_terminal_logger.mm @@ -34,7 +34,7 @@ #import -void IOSTerminalLogger::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) { +void IOSTerminalLogger::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, const Vector> &p_script_backtraces) { if (!should_log(true)) { return; } @@ -48,7 +48,7 @@ void IOSTerminalLogger::log_error(const char *p_function, const char *p_file, in switch (p_type) { case ERR_WARNING: - os_log_info(OS_LOG_DEFAULT, + os_log_error(OS_LOG_DEFAULT, "WARNING: %{public}s\nat: %{public}s (%{public}s:%i)", err_details, p_function, p_file, p_line); break; @@ -69,6 +69,10 @@ void IOSTerminalLogger::log_error(const char *p_function, const char *p_file, in err_details, p_function, p_file, p_line); break; } + + for (const Ref &backtrace : p_script_backtraces) { + os_log_error(OS_LOG_DEFAULT, "%{public}s", backtrace->format().utf8().get_data()); + } } #endif // IOS_ENABLED diff --git a/platform/macos/macos_terminal_logger.h b/platform/macos/macos_terminal_logger.h index 5e3d88c417..ed45563b7d 100644 --- a/platform/macos/macos_terminal_logger.h +++ b/platform/macos/macos_terminal_logger.h @@ -36,7 +36,7 @@ class MacOSTerminalLogger : public StdLogger { public: - 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 = false, ErrorType p_type = ERR_ERROR) override; + 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 = false, ErrorType p_type = ERR_ERROR, const Vector> &p_script_backtraces = {}) override; }; #endif // MACOS_ENABLED diff --git a/platform/macos/macos_terminal_logger.mm b/platform/macos/macos_terminal_logger.mm index cf4a40e3fd..80840d96d9 100644 --- a/platform/macos/macos_terminal_logger.mm +++ b/platform/macos/macos_terminal_logger.mm @@ -34,7 +34,7 @@ #include -void MacOSTerminalLogger::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) { +void MacOSTerminalLogger::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, const Vector> &p_script_backtraces) { if (!should_log(true)) { return; } @@ -46,37 +46,47 @@ void MacOSTerminalLogger::log_error(const char *p_function, const char *p_file, err_details = p_code; } + const char *indent = ""; switch (p_type) { case ERR_WARNING: - os_log_info(OS_LOG_DEFAULT, + indent = " "; + os_log_error(OS_LOG_DEFAULT, "WARNING: %{public}s\nat: %{public}s (%{public}s:%i)", err_details, p_function, p_file, p_line); logf_error("\E[1;33mWARNING:\E[0;93m %s\n", err_details); - logf_error("\E[0;90m at: %s (%s:%i)\E[0m\n", p_function, p_file, p_line); + logf_error("\E[0;90m%sat: %s (%s:%i)\E[0m\n", indent, p_function, p_file, p_line); break; case ERR_SCRIPT: + indent = " "; os_log_error(OS_LOG_DEFAULT, "SCRIPT ERROR: %{public}s\nat: %{public}s (%{public}s:%i)", err_details, p_function, p_file, p_line); logf_error("\E[1;35mSCRIPT ERROR:\E[0;95m %s\n", err_details); - logf_error("\E[0;90m at: %s (%s:%i)\E[0m\n", p_function, p_file, p_line); + logf_error("\E[0;90m%sat: %s (%s:%i)\E[0m\n", indent, p_function, p_file, p_line); break; case ERR_SHADER: + indent = " "; os_log_error(OS_LOG_DEFAULT, "SHADER ERROR: %{public}s\nat: %{public}s (%{public}s:%i)", err_details, p_function, p_file, p_line); logf_error("\E[1;36mSHADER ERROR:\E[0;96m %s\n", err_details); - logf_error("\E[0;90m at: %s (%s:%i)\E[0m\n", p_function, p_file, p_line); + logf_error("\E[0;90m%sat: %s (%s:%i)\E[0m\n", indent, p_function, p_file, p_line); break; case ERR_ERROR: default: + indent = " "; os_log_error(OS_LOG_DEFAULT, "ERROR: %{public}s\nat: %{public}s (%{public}s:%i)", err_details, p_function, p_file, p_line); logf_error("\E[1;31mERROR:\E[0;91m %s\n", err_details); - logf_error("\E[0;90m at: %s (%s:%i)\E[0m\n", p_function, p_file, p_line); + logf_error("\E[0;90m%sat: %s (%s:%i)\E[0m\n", indent, p_function, p_file, p_line); break; } + + for (const Ref &backtrace : p_script_backtraces) { + os_log_error(OS_LOG_DEFAULT, "%{public}s", backtrace->format().utf8().get_data()); + logf_error("\E[0;90m%s\E[0m\n", backtrace->format(strlen(indent)).utf8().get_data()); + } } #endif // MACOS_ENABLED diff --git a/platform/windows/windows_terminal_logger.cpp b/platform/windows/windows_terminal_logger.cpp index 27473e3cdd..4e541b3dde 100644 --- a/platform/windows/windows_terminal_logger.cpp +++ b/platform/windows/windows_terminal_logger.cpp @@ -74,14 +74,14 @@ void WindowsTerminalLogger::logv(const char *p_format, va_list p_list, bool p_er #endif } -void WindowsTerminalLogger::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) { +void WindowsTerminalLogger::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, const Vector> &p_script_backtraces) { if (!should_log(true)) { return; } HANDLE hCon = GetStdHandle(STD_OUTPUT_HANDLE); if (OS::get_singleton()->get_stdout_type() != OS::STD_HANDLE_CONSOLE || !hCon || hCon == INVALID_HANDLE_VALUE) { - StdLogger::log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type); + StdLogger::log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type, p_script_backtraces); } else { CONSOLE_SCREEN_BUFFER_INFO sbi; //original GetConsoleScreenBufferInfo(hCon, &sbi); @@ -107,17 +107,22 @@ void WindowsTerminalLogger::log_error(const char *p_function, const char *p_file basecol |= current_bg; SetConsoleTextAttribute(hCon, basecol | FOREGROUND_INTENSITY); + const char *indent = ""; switch (p_type) { case ERR_ERROR: + indent = " "; logf_error("ERROR:"); break; case ERR_WARNING: + indent = " "; logf_error("WARNING:"); break; case ERR_SCRIPT: + indent = " "; logf_error("SCRIPT ERROR:"); break; case ERR_SHADER: + indent = " "; logf_error("SHADER ERROR:"); break; } @@ -131,25 +136,14 @@ void WindowsTerminalLogger::log_error(const char *p_function, const char *p_file // `FOREGROUND_INTENSITY` alone results in gray text. SetConsoleTextAttribute(hCon, FOREGROUND_INTENSITY); - switch (p_type) { - case ERR_ERROR: - logf_error(" at: "); - break; - case ERR_WARNING: - logf_error(" at: "); - break; - case ERR_SCRIPT: - logf_error(" at: "); - break; - case ERR_SHADER: - logf_error(" at: "); - break; + if (p_rationale && p_rationale[0]) { + logf_error("%sat: (%s:%i)\n", indent, p_file, p_line); + } else { + logf_error("%sat: %s (%s:%i)\n", indent, p_function, p_file, p_line); } - if (p_rationale && p_rationale[0]) { - logf_error("(%s:%i)\n", p_file, p_line); - } else { - logf_error("%s (%s:%i)\n", p_function, p_file, p_line); + for (const Ref &backtrace : p_script_backtraces) { + logf_error("%s\n", backtrace->format(strlen(indent)).utf8().get_data()); } SetConsoleTextAttribute(hCon, sbi.wAttributes); diff --git a/platform/windows/windows_terminal_logger.h b/platform/windows/windows_terminal_logger.h index 69b813b407..421c0a8204 100644 --- a/platform/windows/windows_terminal_logger.h +++ b/platform/windows/windows_terminal_logger.h @@ -37,7 +37,7 @@ class WindowsTerminalLogger : public StdLogger { public: virtual void logv(const char *p_format, va_list p_list, bool p_err) override; - 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 = false, ErrorType p_type = ERR_ERROR) override; + 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 = false, ErrorType p_type = ERR_ERROR, const Vector> &p_script_backtraces = {}) override; virtual ~WindowsTerminalLogger(); };