Skip to content

Commit 05ff06b

Browse files
reduzmihe
reduz
authored and
mihe
committed
Ability to print and log script backtraces
* Changes how stack information is stored in GDScript to a reverse linked list. * This makes it fast enough to leave it enabled all time time on debug. * Added a new script function script_backtrace() to get a string with the current script backtrace. * Added the script backtrace to the logger. * Added script backtrace to console logs (Windows, MacOS, Linux) using blue color. * Added a custom Logger class to help log errors from script.
1 parent ce88021 commit 05ff06b

27 files changed

+360
-114
lines changed

‎core/core_bind.cpp

+76
Original file line numberDiff line numberDiff line change
@@ -210,8 +210,55 @@ void ResourceSaver::_bind_methods() {
210210
BIND_BITFIELD_FLAG(FLAG_REPLACE_SUBRESOURCE_PATHS);
211211
}
212212

213+
////// LOGGER ///////
214+
215+
void Logger::_bind_methods() {
216+
GDVIRTUAL_BIND(_log_error, "function", "file", "line", "code", "rationale", "editor_notify", "error_type", "script_backtrace");
217+
GDVIRTUAL_BIND(_log_message, "message", "error");
218+
BIND_ENUM_CONSTANT(ERROR_TYPE_ERROR);
219+
BIND_ENUM_CONSTANT(ERROR_TYPE_WARNING);
220+
BIND_ENUM_CONSTANT(ERROR_TYPE_SCRIPT);
221+
BIND_ENUM_CONSTANT(ERROR_TYPE_SHADER);
222+
}
223+
224+
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 char *p_script_backtrace) {
225+
GDVIRTUAL_CALL(_log_error, p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type, p_script_backtrace);
226+
}
227+
228+
void Logger::log_message(const String &p_text, bool p_error) {
229+
GDVIRTUAL_CALL(_log_message, p_text, p_error);
230+
}
231+
213232
////// OS //////
214233

234+
void OS::LoggerBind::logv(const char *p_format, va_list p_list, bool p_err) {
235+
if (!should_log(p_err)) {
236+
return;
237+
}
238+
239+
const int static_buf_size = 1024;
240+
char static_buf[static_buf_size];
241+
char *buf = static_buf;
242+
va_list list_copy;
243+
va_copy(list_copy, p_list);
244+
int len = vsnprintf(buf, static_buf_size, p_format, p_list);
245+
if (len >= static_buf_size) {
246+
buf = (char *)Memory::alloc_static(len + 1);
247+
vsnprintf(buf, len + 1, p_format, list_copy);
248+
}
249+
va_end(list_copy);
250+
251+
String str;
252+
str.parse_utf8(buf, len);
253+
for (uint32_t i = 0; i < loggers.size(); i++) {
254+
loggers[i]->log_message(str, p_err);
255+
}
256+
257+
if (len >= static_buf_size) {
258+
Memory::free_static(buf);
259+
}
260+
}
261+
215262
PackedByteArray OS::get_entropy(int p_bytes) {
216263
PackedByteArray pba;
217264
pba.resize(p_bytes);
@@ -628,6 +675,22 @@ String OS::get_unique_id() const {
628675
return ::OS::get_singleton()->get_unique_id();
629676
}
630677

678+
void OS::add_logger(Ref<Logger> p_logger) {
679+
ERR_FAIL_COND(p_logger.is_null());
680+
if (!logger_bind) {
681+
logger_bind = memnew(LoggerBind);
682+
::OS::get_singleton()->add_logger(logger_bind);
683+
}
684+
685+
ERR_FAIL_COND(logger_bind->loggers.find(p_logger) != -1);
686+
logger_bind->loggers.push_back(p_logger);
687+
}
688+
689+
void OS::remove_logger(Ref<Logger> p_logger) {
690+
ERR_FAIL_COND(p_logger.is_null());
691+
logger_bind->loggers.erase(p_logger);
692+
}
693+
631694
OS *OS::singleton = nullptr;
632695

633696
void OS::_bind_methods() {
@@ -734,6 +797,9 @@ void OS::_bind_methods() {
734797
ClassDB::bind_method(D_METHOD("get_granted_permissions"), &OS::get_granted_permissions);
735798
ClassDB::bind_method(D_METHOD("revoke_granted_permissions"), &OS::revoke_granted_permissions);
736799

800+
ClassDB::bind_method(D_METHOD("add_logger", "logger"), &OS::add_logger);
801+
ClassDB::bind_method(D_METHOD("remove_logger", "logger"), &OS::remove_logger);
802+
737803
ADD_PROPERTY(PropertyInfo(Variant::BOOL, "low_processor_usage_mode"), "set_low_processor_usage_mode", "is_in_low_processor_usage_mode");
738804
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");
739805
ADD_PROPERTY(PropertyInfo(Variant::BOOL, "delta_smoothing"), "set_delta_smoothing", "is_delta_smoothing_enabled");
@@ -764,6 +830,16 @@ void OS::_bind_methods() {
764830
BIND_ENUM_CONSTANT(STD_HANDLE_UNKNOWN);
765831
}
766832

833+
OS::OS() {
834+
singleton = this;
835+
}
836+
837+
OS::~OS() {
838+
if (logger_bind) {
839+
logger_bind->clear();
840+
}
841+
}
842+
767843
////// Geometry2D //////
768844

769845
Geometry2D *Geometry2D::singleton = nullptr;

‎core/core_bind.h

+47-1
Original file line numberDiff line numberDiff line change
@@ -120,11 +120,52 @@ class ResourceSaver : public Object {
120120
ResourceSaver() { singleton = this; }
121121
};
122122

123+
class Logger : public RefCounted {
124+
GDCLASS(Logger, RefCounted);
125+
126+
public:
127+
enum ErrorType {
128+
ERROR_TYPE_ERROR,
129+
ERROR_TYPE_WARNING,
130+
ERROR_TYPE_SCRIPT,
131+
ERROR_TYPE_SHADER
132+
};
133+
134+
protected:
135+
GDVIRTUAL2(_log_message, String, bool);
136+
GDVIRTUAL8(_log_error, String, String, int, String, String, bool, int, String);
137+
static void _bind_methods();
138+
139+
public:
140+
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 char *p_script_backtrace = nullptr);
141+
virtual void log_message(const String &p_text, bool p_error);
142+
};
143+
123144
class OS : public Object {
124145
GDCLASS(OS, Object);
125146

126147
mutable HashMap<String, bool> feature_cache;
127148

149+
class LoggerBind : public ::Logger {
150+
public:
151+
LocalVector<Ref<core_bind::Logger>> loggers;
152+
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 char *p_script_backtrace = nullptr) override {
153+
if (!should_log(true)) {
154+
return;
155+
}
156+
157+
for (uint32_t i = 0; i < loggers.size(); i++) {
158+
loggers[i]->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, core_bind::Logger::ErrorType(p_type), p_script_backtrace);
159+
}
160+
}
161+
162+
virtual void logv(const char *p_format, va_list p_list, bool p_err) override _PRINTF_FORMAT_ATTRIBUTE_2_0;
163+
164+
void clear() { loggers.clear(); }
165+
};
166+
167+
LoggerBind *logger_bind = nullptr;
168+
128169
protected:
129170
static void _bind_methods();
130171
static OS *singleton;
@@ -275,9 +316,13 @@ class OS : public Object {
275316
Vector<String> get_granted_permissions() const;
276317
void revoke_granted_permissions();
277318

319+
void add_logger(Ref<Logger> p_logger);
320+
void remove_logger(Ref<Logger> p_logger);
321+
278322
static OS *get_singleton() { return singleton; }
279323

280-
OS() { singleton = this; }
324+
OS();
325+
~OS();
281326
};
282327

283328
class Geometry2D : public Object {
@@ -654,6 +699,7 @@ class EngineDebugger : public Object {
654699

655700
} // namespace core_bind
656701

702+
VARIANT_ENUM_CAST(core_bind::Logger::ErrorType);
657703
VARIANT_ENUM_CAST(core_bind::ResourceLoader::ThreadLoadStatus);
658704
VARIANT_ENUM_CAST(core_bind::ResourceLoader::CacheMode);
659705

‎core/error/error_macros.cpp

+3-1
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@
3131
#include "error_macros.h"
3232

3333
#include "core/io/logger.h"
34+
#include "core/object/script_language.h"
3435
#include "core/os/os.h"
3536
#include "core/string/ustring.h"
3637

@@ -90,7 +91,8 @@ void _err_print_error(const char *p_function, const char *p_file, int p_line, co
9091
// Main error printing function.
9192
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) {
9293
if (OS::get_singleton()) {
93-
OS::get_singleton()->print_error(p_function, p_file, p_line, p_error, p_message, p_editor_notify, (Logger::ErrorType)p_type);
94+
String script_backtrace = ScriptServer::get_current_script_backtrace();
95+
OS::get_singleton()->print_error(p_function, p_file, p_line, p_error, p_message, p_editor_notify, (Logger::ErrorType)p_type, script_backtrace.utf8().get_data());
9496
} else {
9597
// Fallback if errors happen before OS init or after it's destroyed.
9698
const char *err_details = (p_message && *p_message) ? p_message : p_error;

‎core/io/logger.cpp

+9-4
Original file line numberDiff line numberDiff line change
@@ -55,7 +55,7 @@ void Logger::set_flush_stdout_on_print(bool value) {
5555
_flush_stdout_on_print = value;
5656
}
5757

58-
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) {
58+
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 char *p_script_backtrace) {
5959
if (!should_log(true)) {
6060
return;
6161
}
@@ -87,7 +87,12 @@ void Logger::log_error(const char *p_function, const char *p_file, int p_line, c
8787
}
8888

8989
logf_error("%s: %s\n", err_type, err_details);
90-
logf_error(" at: %s (%s:%i)\n", p_function, p_file, p_line);
90+
91+
if (p_script_backtrace && p_script_backtrace[0] != 0) {
92+
logf_error(" at: %s (%s:%i)\n%s\n", p_function, p_file, p_line, p_script_backtrace);
93+
} else {
94+
logf_error(" at: %s (%s:%i)\n", p_function, p_file, p_line);
95+
}
9196
}
9297

9398
void Logger::logf(const char *p_format, ...) {
@@ -261,13 +266,13 @@ void CompositeLogger::logv(const char *p_format, va_list p_list, bool p_err) {
261266
}
262267
}
263268

264-
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) {
269+
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 char *p_script_backtrace) {
265270
if (!should_log(true)) {
266271
return;
267272
}
268273

269274
for (int i = 0; i < loggers.size(); ++i) {
270-
loggers[i]->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type);
275+
loggers[i]->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type, p_script_backtrace);
271276
}
272277
}
273278

‎core/io/logger.h

+2-2
Original file line numberDiff line numberDiff line change
@@ -56,7 +56,7 @@ class Logger {
5656
static void set_flush_stdout_on_print(bool value);
5757

5858
virtual void logv(const char *p_format, va_list p_list, bool p_err) _PRINTF_FORMAT_ATTRIBUTE_2_0 = 0;
59-
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);
59+
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 char *p_script_backtrace = nullptr);
6060

6161
void logf(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3;
6262
void logf_error(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3;
@@ -103,7 +103,7 @@ class CompositeLogger : public Logger {
103103
explicit CompositeLogger(const Vector<Logger *> &p_loggers);
104104

105105
virtual void logv(const char *p_format, va_list p_list, bool p_err) override _PRINTF_FORMAT_ATTRIBUTE_2_0;
106-
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;
106+
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 char *p_script_backtrace = nullptr) override;
107107

108108
void add_logger(Logger *p_logger);
109109

‎core/object/script_language.cpp

+15
Original file line numberDiff line numberDiff line change
@@ -518,6 +518,21 @@ void ScriptServer::save_global_classes() {
518518
ProjectSettings::get_singleton()->store_global_class_list(gcarr);
519519
}
520520

521+
String ScriptServer::get_current_script_backtrace() {
522+
String trace;
523+
for (int si = 0; si < get_language_count(); si++) {
524+
ScriptLanguage *sl = get_language(si);
525+
Vector<ScriptLanguage::StackInfo> stack = sl->debug_get_current_stack_info();
526+
if (stack.size()) {
527+
trace += "stack_language: " + sl->get_name();
528+
for (int i = 0; i < stack.size(); i++) {
529+
trace += "\n" + itos(i) + ": " + stack[i].func + " (" + stack[i].file + " : " + itos(stack[i].line) + ")";
530+
}
531+
}
532+
}
533+
return trace;
534+
}
535+
521536
////////////////////
522537

523538
ScriptCodeCompletionCache *ScriptCodeCompletionCache::singleton = nullptr;

‎core/object/script_language.h

+2
Original file line numberDiff line numberDiff line change
@@ -98,6 +98,8 @@ class ScriptServer {
9898
static void get_inheriters_list(const StringName &p_base_type, List<StringName> *r_classes);
9999
static void save_global_classes();
100100

101+
static String get_current_script_backtrace();
102+
101103
static void init_languages();
102104
static void finish_languages();
103105
static bool are_languages_initialized();

‎core/os/os.cpp

+2-2
Original file line numberDiff line numberDiff line change
@@ -84,13 +84,13 @@ String OS::get_identifier() const {
8484
return get_name().to_lower();
8585
}
8686

87-
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) {
87+
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 char *p_script_backtrace) {
8888
if (!_stderr_enabled) {
8989
return;
9090
}
9191

9292
if (_logger) {
93-
_logger->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type);
93+
_logger->log_error(p_function, p_file, p_line, p_code, p_rationale, p_editor_notify, p_type, p_script_backtrace);
9494
}
9595
}
9696

‎core/os/os.h

+3-2
Original file line numberDiff line numberDiff line change
@@ -111,7 +111,6 @@ class OS {
111111
bool _separate_thread_render = false;
112112

113113
// Functions used by Main to initialize/deinitialize the OS.
114-
void add_logger(Logger *p_logger);
115114

116115
virtual void initialize() = 0;
117116
virtual void initialize_joypads() = 0;
@@ -142,7 +141,7 @@ class OS {
142141
virtual Vector<String> get_video_adapter_driver_info() const = 0;
143142
virtual bool get_user_prefers_integrated_gpu() const { return false; }
144143

145-
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);
144+
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 char *p_script_backtrace = nullptr);
146145
void print(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3;
147146
void print_rich(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3;
148147
void printerr(const char *p_format, ...) _PRINTF_FORMAT_ATTRIBUTE_2_3;
@@ -345,6 +344,8 @@ class OS {
345344

346345
virtual Error setup_remote_filesystem(const String &p_server_host, int p_port, const String &p_password, String &r_project_path);
347346

347+
void add_logger(Logger *p_logger);
348+
348349
enum PreferredTextureFormat {
349350
PREFERRED_TEXTURE_FORMAT_S3TC_BPTC,
350351
PREFERRED_TEXTURE_FORMAT_ETC2_ASTC

‎core/register_core_types.cpp

+1
Original file line numberDiff line numberDiff line change
@@ -244,6 +244,7 @@ void register_core_types() {
244244
GDREGISTER_CLASS(core_bind::Thread);
245245
GDREGISTER_CLASS(core_bind::Mutex);
246246
GDREGISTER_CLASS(core_bind::Semaphore);
247+
GDREGISTER_VIRTUAL_CLASS(core_bind::Logger);
247248

248249
GDREGISTER_CLASS(XMLParser);
249250
GDREGISTER_CLASS(JSON);

‎core/variant/variant_utility.cpp

+7
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@
3232

3333
#include "core/io/marshalls.h"
3434
#include "core/object/ref_counted.h"
35+
#include "core/object/script_language.h"
3536
#include "core/os/os.h"
3637
#include "core/templates/oa_hash_map.h"
3738
#include "core/templates/rid.h"
@@ -1236,6 +1237,10 @@ bool VariantUtilityFunctions::is_same(const Variant &p_a, const Variant &p_b) {
12361237
return p_a.identity_compare(p_b);
12371238
}
12381239

1240+
String VariantUtilityFunctions::script_backtrace() {
1241+
return ScriptServer::get_current_script_backtrace();
1242+
}
1243+
12391244
#ifdef DEBUG_METHODS_ENABLED
12401245
#define VCALLR *ret = p_func(VariantCasterAndValidate<P>::cast(p_args, Is, r_error)...)
12411246
#define VCALL p_func(VariantCasterAndValidate<P>::cast(p_args, Is, r_error)...)
@@ -1855,6 +1860,8 @@ void Variant::_register_variant_utility_functions() {
18551860
FUNCBINDR(rid_from_int64, sarray("base"), Variant::UTILITY_FUNC_TYPE_GENERAL);
18561861

18571862
FUNCBINDR(is_same, sarray("a", "b"), Variant::UTILITY_FUNC_TYPE_GENERAL);
1863+
1864+
FUNCBINDR(script_backtrace, sarray(), Variant::UTILITY_FUNC_TYPE_GENERAL);
18581865
}
18591866

18601867
void Variant::_unregister_variant_utility_functions() {

‎core/variant/variant_utility.h

+1
Original file line numberDiff line numberDiff line change
@@ -154,6 +154,7 @@ struct VariantUtilityFunctions {
154154
static uint64_t rid_allocate_id();
155155
static RID rid_from_int64(uint64_t p_base);
156156
static bool is_same(const Variant &p_a, const Variant &p_b);
157+
static String script_backtrace();
157158
};
158159

159160
#endif // VARIANT_UTILITY_H

‎doc/classes/@GlobalScope.xml

+6
Original file line numberDiff line numberDiff line change
@@ -1160,6 +1160,12 @@
11601160
A type-safe version of [method round], returning an [int].
11611161
</description>
11621162
</method>
1163+
<method name="script_backtrace">
1164+
<return type="String" />
1165+
<description>
1166+
Returns a multiple line text with the current call stack information of running scripts.
1167+
</description>
1168+
</method>
11631169
<method name="seed">
11641170
<return type="void" />
11651171
<param index="0" name="base" type="int" />

0 commit comments

Comments
 (0)