GameMaker: debugging random generation

Example output from the function showing where and when `random` and `choose` functions were called from, their arguments, and their outputs.

Have you ever been working on procedural generation, deterministic netcode, or anything else where the order of operations is important?

This is a post about how to debug order of execution for random number generation functions or built-in functions in general.

Function hooking in GameMaker

In GameMaker, you can use macros to override built-in functions: 

#macro random my_random

This is situationally useful - for example, my INI extension has a "drop-in" version that replaces the built-in INI functions with its own - this way you get the extension's advantages without having to change your existing code.

A lesser-known feature is that if you reference the same function in another macro, that macro will point to the original function: 

#macro random my_random
#macro orig_random random
random(1); // calls my_random()
orig_random(1); // calls the original random()

This is handy on a few occasions, but especially for making debugging tools.

Basic hooking

You could put little structs with information about the call and result in a list: 

#macro random_log_tag global.__random_log_tag
random_log_tag = "?";
global.__random_list = ds_list_create();

#macro random random_hook
#macro random_base random
function random_hook(_max) {
    var _result = random_base(_max);
    if (ds_list_size(global.__random_list) >= 1024) { // too many entries
        ds_list_delete(global.__random_list, 0);
    }
    ds_list_add(global.__random_list, {
        tag: random_log_tag,
        func: "random",
        args: [_max],
        result: _result,
        stack: debug_get_callstack(),
    });
    return _result;
}

And have a function that prints these on demand: 

function random_log_display() {
    var n = ds_list_size(global.__random_list);
    for (var i = 0; i < n; i++) {
        var _item = global.__random_list[|i];
        show_debug_message(_item.tag + "\t"
            + _item.func + string(_item.args)
            + " -> " + string(_item.result)
        );
        var _stack = _item.stack;
        var _stack_len = array_length(_stack);
        for (var k = 1; k < _stack_len; k++) {
            var _line = _stack[k];
            if (is_string(_line)) show_debug_message("\t" + _line);
        }
    }
}

A few short notes here:

  • We start printing the call stack from the second item because the first one is the "hook".
  • That is_string check is there because sometimes you get a 0 at the end of the call stack. Probably happens because GM has to create an array for these ahead of the time, but not every item might contain printable information.

And with that, if you did 

function scr_test() {
    random(1);
    random(2);
    random_log_display();
}

You would see something like 

?   random[ 1 ] -> 0.90
    gml_Script_scr_test:2
    gml_Object_obj_test_Create_0:1
?   random[ 2 ] -> 0.61
    gml_Script_scr_test:3
    gml_Object_obj_test_Create_0:1

And that's pretty good, right?

How to use this

Once you have RNG outputs from two runs, you can compare these using a text diff tool.

There's no shortage of these now - there are dedicated tools (like Beyond Compare), many editors have them, and you can even find online ones!

Improvements

As evidenced by ds_list_find_value / ds_list_set, GameMaker's ds_list data structures are implemented on top of one or other native array type.

That, in turn, means that ds_list_delete has to move items around when deleting something from the beginning of a list.

GameMaker also has a ds_queue data structure, but you can't iterate a queue, so you would have to clear it to print the log or copy items to a temporary queue, and isn't that a little awkward

Instead we can store last N items by having an array that we treat as a cyclic buffer with a "write position".

As in, if it had capacity of 4 and we kept adding numbers it, it'd look like this: 

[0, 0, 0, 0] p=0
[1, 0, 0, 0] p=1
[1, 2, 0, 0] p=2
[1, 2, 3, 0] p=3
[1, 2, 3, 4] p=0
[5, 2, 3, 4] p=1
[5, 6, 3, 4] p=2

You get the idea.

Implementation-wise, that'd be: 

#macro random_log_tag global.__random_log_tag
random_log_tag = "?";
#macro random_log_size 1024
global.__random_log_items = array_create(random_log_size);
global.__random_log_index = 0;

#macro random random_hook
#macro random_base random
function random_hook(_max) {
    var _result = random_base(_max);
    global.__random_log_items[@global.__random_log_index] = {
        tag: random_log_tag,
        func: "random",
        args: [_max],
        result: _result,
        stack: debug_get_callstack(),
    };
    global.__random_log_index = (global.__random_log_index + 1) % random_log_size;
    return _result;
}

And then to print it we go from the next index and wrap around: 

function random_log_display() {
    var i = global.__random_log_index;
    repeat (random_log_size) {
        i = (i + 1) % random_log_size;
        var _item = global.__random_log_items[i];
        if (!is_struct(_item)) continue;
        //
        show_debug_message(_item.tag + "\t"
            + _item.func + string(_item.args)
            + " -> " + string(_item.result)
        );
        var _stack = _item.stack;
        var _stack_len = array_length(_stack);
        for (var k = 1; k < _stack_len; k++) {
            var _line = _stack[k];
            if (is_string(_line)) show_debug_message("\t" + _line);
        }
    }
}

The output remains the same.

Removing boilerplate

There are a 10-something functions that modify random number generator state in GameMaker, and hooks for all of these would have roughly the same code inside. So could that code be shorter?

You could make another function to pass metadata to, like so: 

// ...

function random_log_inner(_func, _args, _result) {
    global.__random_log_items[@global.__random_log_index] = {
        tag: random_log_tag,
        func: _func,
        args: _args,
        result: _result,
        stack: debug_get_callstack(),
    };
    global.__random_log_index = (global.__random_log_index + 1) % random_log_size;
}

function random_hook(_max) {
    var _result = random_base(_max);
    random_log_inner("random", [_max], _result);
    return _result;
}

Or use a macro?

Now that macros can access the argument array in LTS/Stable/Beta, it's possible to make a macro that packs up the arguments all by itself! 

// ...

#macro random_log_macro { \
    var _args = array_create(argument_count); \
    for (var _argi = 0; _argi < argument_count; _argi++) { \
        _args[_argi] = argument[_argi]; \
    } \
    global.__random_log_items[@global.__random_log_index] = { \
        tag: random_log_tag, \
        func: _func, \
        args: _args, \
        result: _result, \
        stack: debug_get_callstack(), \
    }; \
    global.__random_log_index = (global.__random_log_index + 1) % random_log_size; \
}

function random_hook(_max) {
    var _result = random_base(_max);
    var _func = "random";
    random_log_macro;
    return _result;
}

Or a Cooler Macro?

I don't like how you have to set the _func variable before using the macro.

Could be using _GMFUNCTION_ macro, but that isn't in LTS just yet.

However, it's possible to use the same "macro that ends on an expression" trick (as seen in trace) to make a macro that looks like a function but isn't one: 

#macro pseudo_func for (var _value; ; { \
    show_debug_message(_value); \
    break; \
}) _value =

And then if you did 

pseudo_func("hello");

that would be the same as 

for (var _value; ; {
    show_debug_message(_value);
    break;
}) _value = ("hello");

and it would print "hello"!

The updated macro + its use would be the following: 

#macro random_log_macro for (var _func; ; { \
    var _args = array_create(argument_count); \
    for (var _argi = 0; _argi < argument_count; _argi++) { \
        _args[_argi] = argument[_argi]; \
    } \
    global.__random_log_items[@global.__random_log_index] = { \
        tag: random_log_tag, \
        func: _func, \
        args: _args, \
        result: _result, \
        stack: debug_get_callstack(), \
    }; \
    global.__random_log_index = (global.__random_log_index + 1) % random_log_size; \
    break; \
}) _func =

function random_hook(_max) {
    var _result = random_base(_max);
    random_log_macro("random");
    return _result;
}

Further improvements?

I also made a slightly bigger version of this script that wouldn't fit in this post.

Notable changes are:

  • "print" function that returns a string

  • Output is nicer, like so: 

    ?   random(10) -> 3.0293804733082652
    gml_Object_obj_test_Create_0:6
?   choose("A", "B", "C") -> "C"
    gml_Object_obj_test_Create_0:7

    You can even tell apart numbers and strings!

  • Metadata and arguments are packed in an array instead of a struct, though I can't tell how much this really helps.

You can grab it from itch, GitHub, or just...

Limitations

Since we're storing arguments instead of printing them on spot (that'd cost!), if you are doing a choose() or random_log() on structs/arrays, upon printing you'll see the current value of struct/array rather than the one as of the function being called.

Thanks for reading!

Related posts:

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.