Build a D&D 5e Gameplay Simulation, Part 17

To more easily explain the actions the simulation is making, more telemetry than the tracing added in Part 15 is needed. Context and event publishing help to clarify what happened during each simulation. They’ll help to find all kinds of errors that would be hard to identify while coding.

This series of posts is dedicated to building tools that support a simulation of simplified D&D gameplay. To implement the simulation I’ll be using git, Python, PostgreSQL, Elastic, and Docker. The idea behind these blog posts is to document my progress through this project and interesting bits I find along the way. If you’d like to start from the beginning, have a look at part 1. It talks about where this idea came from, and what I’d like to accomplish. The GitHub repository for this project holds the latest version of the files mentioned in these posts. To follow along, part 6 describes how to set up the environment.

One of the challenges in any complex system would be to know what each of the pieces in it is doing before a catastrophic error. This simulation is no different in that respect. While working through implementing the mechanics around the different types of melee and magic one question kept coming up, “Why did it decide to do that?” So, a couple of years ago (jeez, it’s been a while since I posted) I decided to find a way to figure that out without having to add more code each time a question comes up. After a bit of research it became apparent that a good way to implement this would be to record all of the relevant events with their context in the simulation. Charity Majors sums this up terrifically in her SRECon18 Europe presentation by asking, “Can you debug your code and it’s behavior using it’s output without shipping new code?”

Thinking in terms of events changed how I think about this project and programming in general. It took some time to get accustomed to and implement the pieces that would support that change. Core to this approach would be implementing an object that could be passed around in the same manner as the logger. I wanted to be able to not only show what was going on currently, but also what led up to that point. Borrowing the idea of a breadcrumb trail from a web page, tracking that through the execution appealed to me because it might roughly follow the tracing output and be easier use both together.

Ctx.py makes that happen for this project. Defined in it is a python dataclass called ctx that will keep track of the pieces of information that will make each step unique enough to search through (providing a data set with high cardinality). Included in that dataclass will be a list of Crumb dataclasses. Each Crumb holds information about any relevant event as well as a way for each one to record specifics (audit_json dict).

To keep from littering up the code with a lot of work with the ctx class, a decorator was written so that it could be easily added or removed from a method. A decorator is a function that takes another function and extends the behavior of the latter function without explicitly modifying it. So, it allows a function to be extended without modifying it’s code. After working a bit with how dataclasses worked, it seemed like a good way to be able to swap in or out the context functionality. As the code developed, it also became a way to write more in depth testing, because it’s possible to evaluate the work a method did in flight, not just the result.

The next step to get this working was to actually structure the log output. The Rpglogging sets that up using the terrific structlog package. The end result of this is a log file containing JSON output for each relevant event in the simulation.

Here’s a bit of logging from an encounter run. It’s showing when an ability score was being rolled for a character. This roll_audit record shows the specifics about how total for the value was computed.

{
    "msg": {
        "app_username": "encounter_class_init",
        "study_name": "",
        "study_instance_id": -1,
        "series_id": -1,
        "encounter_id": -1,
        "trace_id": "",
        "request_type": "Standard",
        "round": 0,
        "turn": 0,
        "log_id": 10,
        "crumb": {
            "className": "Die",
            "methodName": "_perform_roll",
            "methodParams": {
                "rolls": 4,
                "dropvalue": true,
                "dropfrom": "Low"
            },
            "rollIds": [
                "MJS86HZADYXOIU"
            ],
            "userName": null,
            "parent_id": "EVD9WQF60MKWQPIHB3NNDB",
            "event_id": "EVM46VOI5JAKHSEGMVWLI5",
            "call_depth": 7,
            "audit_json": {},
            "timestamp": "2021-04-04 18:07:10.327328"
        },
        "crumbs": [],
        "_text": "roll_audit",
        "_json": {
            "die_used": 6,
            "roll_id": "MJS86HZADYXOIU",
            "die_rolls": 4,
            "die_total_used": 11,
            "base_roll": [
                1,
                3,
                5,
                3
            ],
            "adjustment_values": {
                "dropvalue": true,
                "dropfrom": "Low"
            }
        }
    },
    "extra": {
        "logger": "encounter_main_test",
        "level": "info",
        "timestamp": "2021-04-04T23:07:10.453292Z"
    }
}

With that working, next up is the challenge of adding the machanics of magic to the simulation. Until next time, Go Play!