GameMaker: trace/log function with position information

A scribble reads: "scr_test:6: hello!"

Have you ever wanted to automatically show file+line in your debug output so that you don't have to guess which of three places did a line reading "oh no" come out?

Classic

This works in any GM version released after 2020 or so:

function trace() {
    var _msg = debug_get_callstack(2)[1] + ":";
    for (var _argi = 0; _argi < argument_count; _argi++) {
        _msg += " " + string(argument[_argi]);
    }
    show_debug_message(_msg);
}

If you have scr_test that has the following inside,

function scr_test() {
    scr_test_trace();
}
function scr_test_trace() {
    trace("hey hey", 1, 2);
}

the output will be:

gml_Script_scr_test_trace:5: hey hey 1 2

Instead of the file name you have a script name, but that works.

Macros (GM2023+ / LTS2024+)

Recent versions of GameMaker introduced _GMFILE_ and _GMLINE_ macros that expand to point at their use location at compile.

So, if we did

show_debug_message(_GMFILE_
    + ":" + string(_GMLINE_)
    + ": " + string(value)
)

that would get us the same file:line: message format that debug_get_callstack did.

The macros cannot be inside the trace function because then they'll just point at it instead, but writing all of that by hand doesn't sound very exciting, does it?

Fortunately, these macros are allowed inside user-created macros, so you could do something like

#macro TP _GMFILE_ + ":" + string(_GMLINE_) + ":"
show_debug_message(TP + "hello!");

and that would work, but can we do better?


Macros don't have to be "complete" expressions or statements, so we can do something like this:

#macro trace global.__trace_p = _GMFILE_ + ":" + string(_GMLINE_) + ":"; __trace

and define a __trace function that reads that variable instead of calling debug_get_callstack. This way, when you do

trace("hi!");

it will expand into

global.__trace_p = "scr_test:2:"; __trace("hi!");

and all will be well.


But there's a certain caveat: if you were to do

if (DEBUG) trace(x, y);

this would still expand "literally", becoming

if (DEBUG)
  global.__trace_p = "scr_test:2:";
  __trace(x, y);

and thus escaping the condition.


The simplest workaround I could think of is to use a single-step for-loop, like so:

for (global.__trace_p = ...; ; break) ...

And thus the combined code is:

#macro trace for (global.__trace_p = _GMFILE_ + ":" + string(_GMLINE_) + ":";;break) __trace
function __trace() {
    var _msg = global.__trace_p;
    for (var _argi = 0; _argi < argument_count; _argi++) {
        _msg += " " + string(argument[_argi]);
    }
    show_debug_message(_msg);
}

2023.8 edition

If you're getting a @@FILENAME@@ instead of the usual location, you must be using one of several GameMaker runtime versions that have a bug with constant propagation (_GMFILE_ is OK, _GMFILE_ + ":" is not).

Here's a version of the script that avoids this problem by passing file/line as separate arguments to a function:

#macro trace repeat (__trace_1(_GMFILE_, ":" + string(_GMLINE_) + ":")) __trace
function __trace_1(_file, _line) {
    global.__trace_p = _file + _line;
    return 1;
}
function __trace() {
    var _msg = global.__trace_p;
    for (var _argi = 0; _argi < argument_count; _argi++) {
        _msg += " " + string(argument[_argi]);
    }
    show_debug_message(_msg);
}

Shout out to Red for suggesting to use repeat instead of a for, which looks a little nicer but probably doesn't change anything.

Cool Buffer Edition

Should a debug output script be optimized? I guess it doesn't hurt to.

#macro trace repeat (__trace_pre(_GMFILE_, ":" + string(_GMLINE_) + ":")) __trace
global.__trace_buf = -1;
global.__trace_map = -1;
function __trace_pre(_file, _line) {
    var _buf = global.__trace_buf;
    if (_buf == -1) {
        _buf = buffer_create(1024, buffer_grow, 1);
        global.__trace_buf = _buf;
        global.__trace_map = ds_map_create();
    } else buffer_seek(_buf, buffer_seek_start, 0);
    var _pre = global.__trace_map[?_file];
    if (_pre == undefined) {
        _pre = __trace_parse(_file);
        global.__trace_map[?_file] = _pre;
    }
    buffer_write(_buf, buffer_text, _pre);
    buffer_write(_buf, buffer_text, _line);
    return 1;
}
function __trace() {
    var _buf = global.__trace_buf;
    for (var i = 0; i < argument_count; i++) {
        buffer_write(_buf, buffer_u8, ord(" "));
        buffer_write(_buf, buffer_text, string(argument[i]));
    }
    buffer_write(_buf, buffer_u8, 0);
    buffer_seek(_buf, buffer_seek_start, 0);
    show_debug_message(buffer_read(_buf, buffer_string));
}
function __trace_parse(_file) {
    if (string_starts_with(_file, "gml_GlobalScript_")) {
        return string_delete(_file, 1, 17);
    }
    if (string_starts_with(_file, "gml_Object_")) {
        return string_delete(_file, 1, 11);
    }
    return _file;
}

Another addition here is that the script will auto-trim the script/object prefixes in names.


And that's about it!

Related posts:

3 thoughts on “GameMaker: trace/log function with position information

  1. It occurs to me that if you are optimizing two things could be achieved here. replace the `repeat` with an `if` which should save exactly one byte instruction, and generate the buffer and map at game init, idk why you initialize them into `-1`. Maybe you had a good reason for this with version control?

    • Using an if would cause undesired behaviour if you had if (...) trace("oh no"); else ...

      For initialization, avoiding one comparison is but a minor optimization. I like having scripts create their data structures on first use where possible.

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.