Last month I blogged about Python logging and how to avoid using print statements in geoprocessing code. But your crufty old code isn't going to rewrite itself, and you're overworked already. An efficient fix would be optimal, and I've got one that only requires a little time to learn how to use Python decorators.
Say you have a module and function that does some geoprocessing work and prints various messages along the way. Something like this:
which, when run, produces output in your terminal.
Now, your function is much more gnarly than work(), and rewriting it will only sap your goodwill toward its author. You'd think it would be possible to somehow wrap the work() function, catching those print statements and redirecting them to a logger – while not breaking code that calls work() – all in a reusable fashion. And it is possible, using a decorator like the 'logprints' class in the code below:
import logging from StringIO import StringIO import sys logging.basicConfig( level=logging.DEBUG, format='%(asctime)s %(levelname)s %(message)s', filename='work.log', filemode='w' ) class logprints(object): def __init__(self, func): # Called when function is decorated self.func = func def __call__(self, *args, **kwargs): # Called when decorated function is called # save reference to stdout saved = sys.stdout # make a string buffer and redirect stdout net = StringIO() sys.stdout = net # call original function retval = self.func(*args, **kwargs) # restore stdout sys.stdout = saved # read captured lines and log them net.seek(0) for line in net.readlines(): logging.info(line.rstrip()) # return original function's return value(s) return retval @logprints def work(): print "Starting some work." print "Doing some work ..." print "Finished the work ..." if __name__ == "__main__": work()
The statement "@logprints" is interpreted as "decorate the immediately following function with the 'logprints' class." On import of this module, the method logprints.__init__() is called with 'work' as the sole argument. Afterwards, when work() is interpreted, logprints.__call__() is called. That method acts as a proxy for the original, now decorated, function. Here is the print capturing and logging decorator in action:
Yes, you could have redirected the output of the original script in the terminal, but remember that Python's logging module sets you up to do much more.
I've recently learned how to use parameterized decorators by following the examples in Bruce Eckel's article. I'm using one to deprecate functions in Shapely:
import warnings class deprecated(object): """Mark a function deprecated. """ def __init__(self, version="'unknown'"): self.version = version self.msg_tmpl = "Call to deprecated function '%s', to be removed in version %s" def __call__(self, func): def wrapping(*args, **kwargs): warnings.warn(self.msg_tmpl % (func.__name__, self.version), DeprecationWarning, stacklevel=2 ) return func(*args, **kwargs) wrapping.__name__ = func.__name__ wrapping.__doc__ = func.__doc__ wrapping.__dict__.update(func.__dict__) return wrapping
Marking a function deprecated like:
causes a warning to be emitted when the function is called:
Deprecation-marking decorators are a great solution (which I first saw used, in a different form, in Zope 3). Why would you want to rewrite a function that's going away in the next software version?
Decorators can also be chained. In Shapely I've factored the check for non-nullness of GEOS geometries into a decorator and chain it with the built-in property decorator:
To this effect:
The exception is raised by the 'exceptNull' decorator.
Not much specifically about GIS here, I'll admit, but GIS programming in Python is, or should be, just Python programming. Feel free to comment if you see any interesting applications of decorators.