The Poor Man’s Debugging Toolkit: Source Reloading

A little more than three years ago I watched Notch live coding a game called 0x10c. What fascinated me was his use of hot-swapping code while the game was running. It closed the feedback loop of game development and left a lasting impact on me. When the development feedback loop is less than one second amazing things start to happen.

The Effects of Reloading Code

When a developer gets feedback in real time s/he can narrow down the problem space by doing instead of thinking. Don’t get me wrong; thinking is great. The hardest problems have been solved by thinking. But thinking is slower than doing, and when we’re doing something we tend not to think of there being a problem at all.

Constants

Manipulating constant values is one of the first things that becomes noticeably easier. If I want to change the color of a game object, my workflow is almost the same, but orders of magnitude faster.

The old workflow:
1. Edit the value.
2. Save the file.
3. Compile/Start the game and wait some time for it to finish. (slow!)
4. View the results.

Becomes this:
1. Edit the value.
2. Save the file.
3. View the results.

Step three in the old workflow is by far the slowest step. A compile and restart of the game, even if it takes 20 seconds, is at least ten times slower than the other steps combined. Having both the editor and game visible allows the developer to edit and save while viewing the results without having to switch windows. Have two monitors? Even better!

Behavior

Adding and changing game logic both become easier in a tight feedback loop. Designing menus, new character actions, and crafting recipes are all things I’ve finished faster because of a fast feedback loop. When creating menus, sizing panes, placing text, and wiring up keyboard controls are all faster when I can immediately interact with the changes. Adding a character action is a matter of manipulating the game state transition table and adding a method to accept the old game state and spit out a new game state with the right changes. Finally, creating crafting recipes is just a matter of adding a new recipe to the recipe list while having the crafting menu open and viewing the output as I save the source files.

You might be asking, “What about the repl? This is what the repl is for! Use the repl.” The repl is fine. I like testing out code in the repl, but the repl does not automatically reload code when a source file is changed. Sure, I could use (use '... :reload) to reload individual namespaces, but the fact that I have to do it by hand lengthens the feedback loop too much. I usually have a repl open for testing out snippets. But that’s it.

Setup

From a high level, we need a few parts. The first part is to track when source files have been changed. The second part is to perform an action when a change is detected. The last part is to add a level of indirection so that the game loop can refer to the new function definitions when the code is reloaded.

Let’s start with tracking namespace changes. start-nstracker will look for changes in the paths src, and target/generated-src/cljbecause we’re using cljx to target both Clojure and ClojureScript. The function ns-tracker, returns a function we bind to the variable track. When track is called it returns a list of changed namespaces. We just call check-namespace-changes in an infinite loop in a background thread.

(defn start-nstracker []
 (let [track (ns-tracker ["src" "target/generated-src/clj"])]
   (doto
     (Thread.
       #(while true
         (check-namespace-changes track)))
     (.setDaemon true)
     (.start))))

Our function check-namespace-changes invokes track and for each changed namespace, we reload it. We’ll also sleep a little so that the background thread doesn’t hog resources.

(defn check-namespace-changes [track]
 (try
   (doseq [ns-sym (track)]
     (log/info "Reloading namespace:" ns-sym)
     (require ns-sym :reload)
     (log/info "Done."))
   (catch Throwable e (log/error e)))
   (Thread/sleep 500))

The game loop looks like this.

(defn -main []
  (let [default-setup-fn (constantly {})
        default-tick-fn  (fn [state] (log/info "default tick fn") (Thread/sleep 5000) state)
        get-setup-fn     (fn [] (if-let [f (resolve 'robinson.main/setup)] f default-setup-fn))
        get-tick-fn      (fn [] (if-let [f (resolve 'robinson.main/tick)] f default-tick-fn))]
    (start-nstracker)
    ; loop when setup-fn changes
    (loop [setup-fn     (get-setup-fn)
           setup-fn-var (var-get setup-fn)]
      ; start with initial state from setup-fn
      (setup-fn
        (fn [state]
          (go-loop [state state]
            ; start with initial state from setup-fn
            ; setup function changed? restart with new setup
             (when (identical? (var-get (get-setup-fn)) setup-fn-var)
              (if (nil? state)
                ;; nil state, exit
                (do
                  (log/info "Got nil state. Exiting.")
                  (async/>! done-chan true)
                  (System/exit 0))
                ; tick the last state through the tick-fn to get the new state
                (let [new-state (try
                                  (let [keyin (if (= (rw/current-state state) :sleep)
                                                  \.
                                                (let [key-chan (aterminal/get-key-chan (state :screen))]
                                                  (log/info  "waiting for key-chan")
                                                  (async/<! key-chan)))]
                                     (if keyin
                                       ((get-tick-fn) state keyin)
                                       state))
                                  (catch Throwable e
                                    (log/error e)
                                    state))]
                    (recur new-state)))))))
      ; setup function changed, restart with new setup
      (let [setup-fn  (get-setup-fn)
            setup-var (var-get setup-fn)]
        (log/info "(Re)starting loop with new setup-fn")
        (recur setup-fn setup-var)))
        (async/<!! done-chan)
        (log/info "Core exiting")))

Before the game loop starts, we need to we need to define a few functions to resolve our setup, and tick functions. The outer loop iterates when the setup function changes and the game restarts with a new initial state. We’ll call (start-nstracker) and (setup-fn) to start tracking namespace changes and to generate the initial game state before entering the game loop.

The setup-fn function takes a callback that accepts the initial game state. The inner go-loop is the game loop. The tick function takes a game state and keyboard input and returns a new game state. Inside the game loop, we can call ((get-tick-fn) state keyin) to pass the game state through the tick function to get a new game state.

When the source changes in the background, the game loop won’t miss a beat, the new definitions will be available for use immediately so the developer can see the changes taking effect.

Caveats

There are a few cases that aren’t covered by this framework.

If a function that is called by the setup function the change will be detected, but it won’t trigger a reinitialization of the game state. I have to trigger an in-game death and start a new game. I have a hotkey that does this, so it doesn’t require an application restart, but it isn’t automatic.

When the changes make presumptions about the layout of data in the game state, the game state has to be reinitialized. Again this doesn’t require an application restart, but the developer may have to recreate a particular game state again. This comes down to what is essentially a versioning and migration issue. If the original code depends on the player record having a field named :hp and the code is changed to use :health-points, the game state will not be converted to use the new convention.

Technically, it’s possible to add a bit of migration code that performs the conversion on the next tick, but it’s rarely worth it in practice so it is easier to just reinitialize the game state with the new code.

Take Away

It’s interesting to program in what amounts to a live coding session. The great part about tracking files and automatically reloading them is that the code on disk matches what’s being executed. If the game crashes or the computer freezes, short of drive failure, no work is lost. I will usually give the feature a final test outside the auto-reloading environment, and then it’s just a matter of committing the changes. It really is that easy.

The Poor Man’s Debugging Toolkit: Using Clojure.inspector

When debugging a problem in Robinson, I will often print out values to the log. I can try to see the values of variables at certain points during execution. Often, these values will be some subset of the game state.

I’d like print the whole game state to the log, but it’s too much data to process visually. So I find myself printing small parts of the game state trying to hone in on the right part to show the problem. It takes far too long and it’s frustrating. I have to guess and check until I find the right data.

Enter Clojure.inspector

I stumbled on Adam Bard’s Clojure.core: Batteries (almost) included writeup on useful Clojure libraries. There is a small reference to clojure.inspector in the forward that caught my eye.

Clojure.inspector is a very small namespace of just three documented functions: inspect, inspect-table, and inspect-tree. The functions all display a GUI showing data — inspect is for viewing objects, inspect-table for viewing sequences, and inspect-tree for hierarchical data.

Wait, the game state is hierarchical data!

This is perfect.

Solution

Given the right tool, all problems are trivial. Let’s add inspector as a required namespace to Robinson’s update namesapce so that we can trigger inspection when a key is press.

(ns robinson.update
  (:require 
    ...
    clojure.inspector
    ...

And then we can wire up the keyboard so that when 5 is pressed we can inspect the game state. This snippet lies in the middle of a state machine definition mentioned in this post.

...
\5 [(fn [state]
      (clojure.inspector/inspect-tree (get state :world))
    :normal
    false]
...

That’s it. It was almost too easy.

The inspector window looks like this and it’s so useful. I’ve already caught at least one bug just by examining values.
Screenshot of inspector

Use it!

Since game states are passed to almost every logic related function in Robinson, I’ll have many opportunities to apply inspect-tree during future debugging sessions and in the meantime, I can always press 5 to peek under the hood.

If you find yourself trying to cherry-pick values to print to the log, try using clojure.inspector. It’s a big bang for your coding buck.