Debugging Your Code

Exception Handling

Exceptions are like the "You Are Here" spot on a map. They show you exactly how you got to a particular line of code in your method, by walking you backwards to the method that called you, and then the method that called the caller, and so on, up until your head explodes. They're great!

Exceptions get "thrown" in Java, or "raised" in Jython, when something goes wrong. When an Exception is thrown, it's like a bullet that goes speeding back up through all the callers, until it gets to someone who wants to deal with the problem.

If you want to deal with the problem, you can "catch" the exception. Some Java and Wyvern API calls require that you catch the Exceptions they throw, or at least declare you're going to throw them up to your caller.

Without worrying too much about how to use them, let's see one in action. Here's an example of a fairly helpful Exception stack trace:

java.lang.IllegalArgumentException: Spell.getArtName: Invalid art: 77
        at wyvern.lib.classes.magic.Spell.getArtName(Spell.java:523)
        at wyvern.lib.classes.magic.Spell.getRequiredMana(Spell.java:467)
        at wyvern.lib.commands.CastCommand.adjustCasterMana(CastCommand.java:519)
        at wyvern.lib.commands.CastCommand.execute(CastCommand.java:463)
        at wyvern.kernel.kernel.Executive.dispatchEvent(Executive.java:852)
        at wyvern.kernel.kernel.Executive.workerLoop(Executive.java:750)
        at wyvern.kernel.kernel.Executive.access$0(Executive.java:43)
        at wyvern.kernel.kernel.Executive$WorkerThread.run(Executive.java:719)

Let's say you're debugging your class, watching log messages on your console, when you suddenly see one of these huge stack traces. What do you do?

Well, the one above actually tells you exactly what went wrong, if you look closely at it. The top line is the exception message. It says:

java.lang.IllegalArgumentException: Spell.getArtName: Invalid art: 77

That's not terribly useful, but it does tell us a few things:

  • there was an "illegal argument" of some sort, meaning a bad parameter was passed to someone

  • it's something related to a Spell, and in particular, the Art for the spell.

Let's keep looking further up the stack trace. It's a little backwards - you look down the list to go "up" the trace, where "up" means "tracing back to the caller". Up, down, whatever. Doesn't matter, as long as we find what we need to know.

The next thing we see is

at wyvern.lib.classes.magic.Spell.getArtName(Spell.java:523)

Well, now that's interesting. This is an extremely exact location in the code base. It tells us that the exception was thrown on line 523 of Spell.java. The class is wyvern.lib.classes.magic.Spell, and the method is getArtName(). Sounds like it's in the Wyvern game engine, and we can't look at that code. But we know more about what's going on, so let's keep looking to see what else we can find.

The next three lines of the stack trace look like this:

at wyvern.lib.classes.magic.Spell.getRequiredMana(Spell.java:467)
at wyvern.lib.commands.CastCommand.adjustCasterMana(CastCommand.java:519)
at wyvern.lib.commands.CastCommand.execute(CastCommand.java:463)

This is all still in the Wyvern game engine, but it's clear that the spell system is unhappy about something. First we were in CastCommand.execute() (any guesses as to what that does?). It went to adjustCasterMana, and then Spell.getRequiredMana(), and then Spell.getArtName(). Then it finally puked, saying that the art name was "77". It doesn't take a Sherlock Holmes to realize that we probably passed in an invalid spell Art when we were casting a spell.

And in fact, that's exactly what happened. I generated the stack trace above by changing the getArt() method in scratch.py to this:

<span class='keyword'>def</span> <span class='function'>getArt</span>(self):<br>        <span class='keyword'></span>return<span class='keyword'></span> <span class='keyword'></span>77<span class='keyword'></span>

OK, so I contrived this example by deliberately breaking my code. But you can see that Exceptions can often show you how your code (or the Wyvern engine code, in some cases) is misbehaving.

Unfortunately, Exceptions aren't always so useful. As another example, I changed my hooktest1.py class, which is covered in detail in the Hooks Tutorial, to throw an Exception, just to see where we were. My changes are the lines highlighted below:

<span class='keyword'></span>from<span class='keyword'></span> <span class='keyword'></span>wyvern<span class='keyword'></span>.<span class='keyword'></span>lib<span class='keyword'></span> <span class='keyword'></span>import<span class='keyword'></span> <span class='keyword'></span>HookCallback<span class='keyword'></span><br><span class='keyword'></span>from<span class='keyword'></span> <span class='keyword'></span>wyvern<span class='keyword'></span>.<span class='keyword'></span>lib<span class='keyword'></span>.<span class='keyword'></span>classes<span class='keyword'></span> <span class='keyword'></span>import<span class='keyword'></span> <span class='keyword'></span>DynamicObject<span class='keyword'></span><br><span class='keyword'></span>from<span class='keyword'></span> <span class='keyword'></span>wyvern<span class='keyword'></span>.<span class='keyword'></span>lib<span class='keyword'></span>.<span class='keyword'></span>properties<span class='keyword'></span> <span class='keyword'></span>import<span class='keyword'></span> <span class='keyword'></span>PickupInterest<span class='keyword'></span><br><span class="code_callout">from java.lang import RuntimeException</span><br><br><span class='keyword'>class</span> <span class='function'>hooktest1</span>(DynamicObject, HookCallback, PickupInterest):<br><br>    <span class='keyword'>def</span> <span class='function'>initialize</span>(self):<br>        <span class='keyword'></span><span class='instance'>self</span><span class='keyword'></span>.<span class='keyword'></span>super__initialize<span class='keyword'></span>()<br><br>        <span class='keyword'></span><span class='instance'>self</span><span class='keyword'></span>.<span class='keyword'></span>setDefaultImage<span class='keyword'></span>(<span class='string'>"<span class='keyword'></span>objects<span class='keyword'></span>/<span class='keyword'></span>skull<span class='keyword'></span>"</span>)<br><br>    <span class='keyword'>def</span> <span class='function'>toString</span>(self):<br>        <span class='keyword'></span>return<span class='keyword'></span> <span class='string'>"<span class='keyword'></span>Mr<span class='keyword'></span>. <span class='keyword'></span>Sensitive<span class='keyword'></span>"</span><br><br>    <span class='keyword'>def</span> <span class='function'>pickedUp</span>(self, agent):<br>        <span class='keyword'></span>agent<span class='keyword'></span>.<span class='keyword'></span>addHook<span class='keyword'></span>(<span class='keyword'></span><span class='instance'>self</span><span class='keyword'></span>, '<span class='keyword'></span>dropPostHook<span class='keyword'></span>')<br><br>    <span class='keyword'>def</span> <span class='function'>dropped</span>(self, agent):<br>        <span class='keyword'></span>pass<span class='keyword'></span><br><br>    <span class='keyword'>def</span> <span class='function'>hookEvent</span>(self, hookName, event):<br>        <span class="code_callout">raise RuntimeException("I'm in hookEvent!")</span><br>        <span class='keyword'></span>if<span class='keyword'></span> <span class='keyword'></span><span class='instance'>self</span><span class='keyword'></span> <span class='keyword'></span>is<span class='keyword'></span> <span class='keyword'></span>event<span class='keyword'></span>.<span class='keyword'></span>getTarget<span class='keyword'></span>():<br>            <span class='keyword'></span>agent<span class='keyword'></span> = <span class='keyword'></span>event<span class='keyword'></span>.<span class='keyword'></span>getAgent<span class='keyword'></span>()<br>            <span class='keyword'></span>agent<span class='keyword'></span>.<span class='keyword'></span>message<span class='keyword'></span>(<span class='keyword'></span><span class='instance'>self</span><span class='keyword'></span>.<span class='keyword'></span>toString<span class='keyword'></span>() + ' <span class='keyword'></span>says<span class='keyword'></span>:  <span class='keyword'></span>Ouch<span class='keyword'></span>!')<br>            <span class='keyword'></span>agent<span class='keyword'></span>.<span class='keyword'></span>removeHook<span class='keyword'></span>(<span class='keyword'></span><span class='instance'>self</span><span class='keyword'></span>, '<span class='keyword'></span>dropPostHook<span class='keyword'></span>')

The idea is that I'd drop the Mr. Sensitive object, and in its dropPostHook, it would throw an Exception to show exactly how we got there. However, the result is, well... it looks almost as ugly as Perl code:

java.lang.RuntimeException: I'm in hookEvent!
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0\
		(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance\
		(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance\
		(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:274)
        at org.python.core.PyReflectedConstructor.__call__\
		(PyReflectedConstructor.java)
        at org.python.core.PyJavaInstance.__init__(PyJavaInstance.java)
        at org.python.core.PyJavaClass.__call__(PyJavaClass.java)
        at org.python.core.PyObject.__call__(PyObject.java)
        at org.python.pycode._pyx69.hookEvent$6\
		(/games/wyvern/wiz/rhialto/python/hooktest1.py:23)
        at org.python.pycode._pyx69.call_function\
		(/games/wyvern/wiz/rhialto/python/hooktest1.py)
        at org.python.core.PyTableCode.call(PyTableCode.java)
        at org.python.core.PyTableCode.call(PyTableCode.java)
        at org.python.core.PyTableCode.call(PyTableCode.java)
        at org.python.core.PyFunction.__call__(PyFunction.java)
        at org.python.core.PyMethod.__call__(PyMethod.java)
        at org.python.core.PyObject.__call__(PyObject.java)
        at org.python.core.PyObject._jcallexc(PyObject.java)
        at org.python.core.PyObject._jcall(PyObject.java)
        at org.python.proxies.main$hooktest1$35.hookEvent(Unknown Source)
        at wyvern.kernel.commands.HookList.callHooks(HookList.java:245)
        at wyvern.kernel.commands.HookList.runPostHook(HookList.java:136)
        at wyvern.kernel.commands.AbstractCommandable.runPostHook\
		(AbstractCommandable.java:397)
        at wyvern.kernel.commands.EventImpl.runPostHooks(EventImpl.java:723)
        at wyvern.kernel.kernel.Executive.dispatchEvent(Executive.java:855)
        at wyvern.kernel.kernel.Executive.workerLoop(Executive.java:750)
        at wyvern.kernel.kernel.Executive.access$0(Executive.java:43)
        at wyvern.kernel.kernel.Executive$WorkerThread.run(Executive.java:719)

Unfortunately, Jython exceptions can be really long, because Jython is doing a lot of "stuff" under the covers in order to make it so useful.

However, if you take out all the lines starting with "sun.reflect" and "org.python", except for the ones that mention my hooktest1.py class, you get something slightly more readable:

java.lang.RuntimeException: I'm in hookEvent!
        at org.python.pycode._pyx69.hookEvent$6(/games/wyvern/wiz/rhialto/python/hooktest1.py:23)
        at org.python.pycode._pyx69.call_function(/games/wyvern/wiz/rhialto/python/hooktest1.py)
        at org.python.proxies.main$hooktest1$35.hookEvent(Unknown Source)
        at wyvern.kernel.commands.HookList.callHooks(HookList.java:245)
        at wyvern.kernel.commands.HookList.runPostHook(HookList.java:136)
        at wyvern.kernel.commands.AbstractCommandable.runPostHook(AbstractCommandable.java:397)
        at wyvern.kernel.commands.EventImpl.runPostHooks(EventImpl.java:723)
        at wyvern.kernel.kernel.Executive.dispatchEvent(Executive.java:855)
        at wyvern.kernel.kernel.Executive.workerLoop(Executive.java:750)
        at wyvern.kernel.kernel.Executive.access$0(Executive.java:43)
        at wyvern.kernel.kernel.Executive$WorkerThread.run(Executive.java:719)

With this, we can deduce three things:

  • my Exception was raised on line 23 of hooktest1.py
  • it might have originated from the game engine running "post hooks"
  • I should have picked a better example

But at least you've seen Exceptions at their worst, and now you know that you can sometimes extract useful information from the stack traces.

In the next lesson, we'll show you how to catch and log Exceptions effectively.

<< Previous Chapter Next Chapter >>