Debugging Your Code

Logging Namespace Train Wrecks

The class name you pass to the Kernel logging functions should be unique. If every wizard has a "test.py", and each one publishes its logs messages to "test.py", then everyone will see everyone else's log messages. It would be annoying, to say the least.

Instead, you should use the relative path to your python class, such as wiz/rhialto/python/scratch.py. For Java classes, you should use the fully-qualified classname, such as "wyvern.wiz.rhialto.java.Thingy". In the game Java classes, we usually define this at the top of the file:

private static final String MYCLASS = "wyvern.wiz.rhialto.java.Thingy";

Then all the logging statements in the file look like this:

Kernel.finer ( MYCLASS, "myMethod", "howdy howdy" );

Here's a fixed-up version of scratch.py, which sets the pathname in the initialize() method, and passes that to all the logging functions:

"""
scratch.py

An example spell, for demonstrating logging. There is
a bunch of logging code in this version of the spell. The class
passes a unique path to all the logging functions, to avoid
namespace collisions with other Wizard code. <p>

Copyright 2003 Cabochon Technologies, Inc.
Author: Steve Yegge
"""

from java.lang import String
from wyvern.lib import Timed, Range, Kernel
from wyvern.lib.classes.magic import Spell

class scratch(Spell, Timed):

def initialize(self):

# we initialize self.logname to our unique path
self.logname = 'wiz/rhialto/python/scratchlog.py'

<em>Kernel.finest(self.logname, 'initialize', 'calling superclass')em>
self.super__initialize()
self.setIntProperty('lore', 1)
self.setProperty('short', 'scratch')
<em>Kernel.finest(self.logname, 'initialize', 'done initializing')em>

def getArt(self):
<em>Kernel.entering(self.logname, 'getArt')em>
return self.INCANTATION

def getElement(self):
<em>Kernel.entering(self.logname, 'getElement')em>
return self.SPIRIT

def start(self):

<em>Kernel.fine(self.logname, 'start', 'looking for target')em>
# look for target, or use caster if there isn't one
self.target = self.findTargetObject(1)
if not self.target:
<em>Kernel.fine(self.logname, 'start', 'no target found!')em>
return

<em>Kernel.fine(self.logname, 'start', 'setting timer')em>
self.timer = Kernel.setRepeatingTimer ( 20000, self )

<em>Kernel.fine(self.logname, 'start', 'making dispellable')em>
self.makeDispellable()

self.getAgent().message('You cast scratch on ' + str(self.target))

def timerExpired(self):
<em>Kernel.fine(self.logname, 'timerExpired', 'entering')em>
target = self.target
roll = Range.percent()
pronoun = target.getGenderString()
name = target.getName()

<em>Kernel.finer(self.logname, 'timerExpired', 'name: ' + name)em>
<em>Kernel.finer(self.logname, 'timerExpired', 'rolled ' + str(roll))em>

if roll < 20:
<em>Kernel.finest(self.logname, 'timerExpired', 'scratching self')em>
target.message ( "You scratch yourself." )
target.broadcast ( name + " scratches " +
pronoun + "self vigorously." )
elif roll < 40:
<em>Kernel.finest(self.logname, 'timerExpired', 'scratching nose')em>
target.message ( "You rub your nose." )
target.broadcast ( name + " rubs " +
pronoun + " nose for a long while." )
elif roll < 60:
<em>Kernel.finest(self.logname, 'timerExpired', 'scratching ear')em>
target.message ( "You scratch your ear." )
target.broadcast ( name + " sticks " +
pronoun + " finger in " + pronoun +
" ear and scratches an itch." )
elif roll < 80:
<em>Kernel.finest(self.logname, 'timerExpired', 'belching')em>
target.message ( "You suddenly belch." )
target.broadcast ( name + " belches loudly, " +
"and looks very embarrassed about it." )
else:
<em>Kernel.finest(self.logname, 'timerExpired', 'smelling')em>
target.broadcast ( name + " smells terrible today." )

def dispel(self):
<em>Kernel.fine(self.logname, 'dispel', 'calling superclass')em>
self.super__dispel()

<em>Kernel.fine(self.logname, 'dispel', 'killing timer')em>
Kernel.killTimer(self.timer)
self.target.message ( "You suddenly feel more sophisticated." )

def __repr__(self):
return self.getProperty('short')

def toString(self):
return self.__repr__()

def getSpellDescription(self):
<em>Kernel.entering(self.logname, 'getSpellDescription')em>
return ("This " + self.getDescString() +
" lowers the target several rungs on the Social Ladder.")

Much better. For starters, we now pass a unique name to the Kernel logging functions, which means other people with 'scratch.py' classes won't stomp on us.

Also, if we change the name of the class, we only need to change the line that sets self.logname — in the old version, we would have had to change every single logging statement!

In the next lesson, we'll cover some performance issues, and then you should be ready to start using logging yourself.

<< Previous Chapter Next Chapter >>