Debugging a Test Failure

So you'd like to contribute to Magpie. Awesome! You've discovered a test that's failing when you run test.py and you want to debug it. This little guide will try to help you get started.

How do you know something's wrong?

Magpie has two sets of tests. There is a small set of unit tests written in C++. Those mainly test the base internal types like Array<T>. These probably won't help you much. (I would like to expand these at some point, but for now you can probably ignore them.)

The main set of tests is in test/ in the repo. Each file in there is a Magpie script with a couple of special comments that indicate what the test should do when run:

• A comment like // expect: foo means the program should print foo. The output should be printed in the order the comments appear in the script.

• A comment like // expect exit 3 means the program should exit with the given exit code. This is usually used to test that programs fail by throwing an uncaught error. Most tests that validate that an error is thrown catch it and then validate that it was caught, but errors that are thrown at the top level use this instead. (For example, defining a variable at the top level that is initialized to another variable that hasn't itself been initialized yet.)

• A comment like // expect error means the program should generate a compile error on that line. Magpie defines some things as compile errors and these tests validate that. Similarly, a comment like // expect error line 123 means the program should generate a compile error on the specified line. This is used to test that compile errors appear in places where the expect error comment itself would interfere with the test.

Tracking down the bug

So you have a test failing. When you run test.py, you get something like:

$ ./script/test.py 
FAIL: test/functions/implicit_parameters.mag
      Expected return code 0 and got 1.

240 tests passed. 1 tests failed.

The first thing you can do is run the test directly:

$ ./magpie test/functions/implicit_parameters.mag

Sometimes the full stderr and stdout will give you some more information. A failure can look like one of a few things:

A uncaught error

If a program throws an error that isn't caught, Magpie will print out a stack trace and exit. It will look a bit like:

$ ./magpie test/functions/implicit_parameters.mag 
[test/functions/implicit_parameters.mag line 22]
    throw "Show what uncaught error stack trace looks like"
[/Users/rnystrom/dev/magpie/core/core.mag line 190]
def (is Function) _call(arg) native "functionCall"
[/Users/rnystrom/dev/magpie/core/core.mag line 170]
    func _call(0: (0: a))
[test/functions/implicit_parameters.mag line 24]
end call("assign") // expect: assign
Uncaught error.

The top of the stack is the first line printed, so start there. That can give you an idea of where the error lies.

An assertion failure

The C++ codebase uses an ASSERT() macro to codify requirements about the internal state of the VM. It's a programmatic error for an assert to fail. In a debug build (which is usually the default and what you should be running to... uh... debug), an assertion failure will look a bit like:

$ ./magpie test/functions/implicit_parameters.mag 
ASSERTION FAILED /Users/rnystrom/dev/magpie/src/VM/Fiber.cpp:288 - Temporarily broke OP_EQUAL to show what an assert failure looks like.
./magpie: line 20: 63517 Abort trap: 6           ./$MAGPIE $@

If you see something like that, look at the offending code. Put a breakpoint there and then work backwards to figure out how it got into that state.

A null pointer dereference

One specific assertion failure that's most common is dereferencing a null pointer. It looks like:

ASSERTION FAILED src/Memory/Memory.h:114 - Cannot dereference NULL pointer.
./magpie: line 20: 63595 Abort trap: 6           ./$MAGPIE $@

If you see this, it means a variable of type gc<T> was derefenced when null.

Finding the bug

Debugging C++ code can be generally hard. Debugging a bytecode VM is even harder (though it could be worse, at least it's not a JIT). If there is a bug in the core bytecode interpreter itself, you'll want to get familiar with Magpie's bytecode instruction set.

The opcodes are defined and documented in Bytecode.h. The main interpreter loop that executes each bytecode is in Fiber.cpp.

One thing that often helps is to dump the bytecode for a method or function when it gets compiled. This can be quicker than stepping through each instruction as its invoked. If the error is in the compiler and the generated code itself is wrong, this is likely the easiest way to track it down.

To do that, go into Compiler.cpp. Look for lines like:

gc<Chunk> code = ExprCompiler(compiler).compile...

After those, add:

code->debugTrace(vm);

You may also want to add std::cout << ast or something similar to print the corresponding source. Most objects in Magpie implement << and can be helpfully dumped to stdout.

Then when you run the script, you'll get the disassembled bytecode dumped out.

Good luck, and thanks! As always, get in touch and I'll do what I can to help you track down the issue. If/when you get it fixed, commit it in a branch and send a pull request.