Twiggy is a more Pythonic logger
Project description
Flubberage:
author Peter Fein
email pfein@pobox.com
Usage:
Make display work:
>>> import sys; sys.stderr = sys.stdout
Setup is simple
In your main.py:
>>> import twiggy >>> twiggy.quick_setup()
Logging Messages
>>> from twiggy import *
Main interface is the the magic log:
>>> log #doctest:+ELLIPSIS <twiggy.Logger.Logger object at 0x...>
It works out of the box, using standard levels:
>>> log.debug('You may not care') DEBUG:You may not care >>> log.error('OMFG! Pants on fire!') ERROR:OMFG! Pants on fire!
It supports a variety of format strings, defaulting to new-style:
>>> log.info('I wear {0} on my {where}', 'pants', where='legs') INFO:I wear pants on my legs
Old style works fine though:
>>> log.options(style='percent').info('I like %s', "bikes") INFO:I like bikes
As do templates:
>>> log.options(style='dollar').info('$what kill', what='Cars') INFO:Cars kill
You can name your loggers:
>>> mylog = log.name('alfredo') >>> mylog.debug('hello') DEBUG:alfredo:hello
But the name has no relation to the object; it’s just for human use:
>>> mylog is log.name('alfredo') False
Emitting Messages
Emitters are loosely coupled:
>>> twiggy.emitters #doctest:+ELLIPSIS {'*': <twiggy.Emitter.Emitter object at 0x...>}
You can set a min_level on Emitters:
>>> twiggy.emitters['*'].min_level = twiggy.Levels.INFO >>> log.debug("Help, help I'm being suppressed") >>> log.info("I'm not quite dead yet") INFO:I'm not quite dead yet
You can filter on regexes, or with arbitrary functions:
>>> twiggy.emitters['*'].filter = ".*pants.*" >>> log.info("Got my {0} on", "pants") INFO:Got my pants on >>> log.info("Got my {0} on", "shirt")
Let’s reset all that:
>>> twiggy.emitters['*'].filter = True >>> twiggy.emitters['*'].min_level = twiggy.Levels.DEBUG
Better output
Newlines are suppressed by default; that can be turned off per-message:
>>> log.info('user\ninput\nannoys\nus') INFO:user\ninput\nannoys\nus
>>> log.options(suppress_newlines=False).info('we\ndeal') INFO:we deal
Exceptions are prefixed. Can also pass exc_info. Use ‘\n’ as a prefix to fold into a single line:
>>> try: ... 1/0 ... except: ... log.trace('error').warning('oh noes') #doctest:+ELLIPSIS WARNING:oh noes TRACE Traceback (most recent call last): TRACE File "<doctest notes.txt[...]>", line 2, in <module> TRACE 1/0 TRACE ZeroDivisionError: integer division or modulo by zero
Method Chaining
I like this chained style a lot.
>>> log.name('benito').info('hi there') INFO:benito:hi there
It makes structured logging easy:
>>> log.fields(paths=42).info('Going for a walk') INFO:paths=42:Going for a walk
Short cut. Great for runtime statistics gathering.
>>> log.struct(paths=42, dolphins='thankful') INFO:dolphins=thankful:paths=42:
Partial binding can be useful for webapps:
>>> per_request_log = log.fields(request_id='12345') >>> per_request_log.fields(rows=100, user='frank').info('frobnicating database') INFO:request_id=12345:rows=100:user=frank:frobnicating database >>> per_request_log.fields(bytes=5678).info('sending page over tubes') INFO:bytes=5678:request_id=12345:sending page over tubes
Chained style is awesome:
>>> log.name('donjuan').fields(pants='sexy').info("hello, {who} want to {what}?", who='ladies', what='dance') INFO:donjuan:pants=sexy:hello, ladies want to dance?
Dynamic!
Any functions in args/fields are called and the value substitued:
>>> import os >>> from twiggy.lib import thread_name >>> thread_name() 'MainThread' >>> log.fields(pid=os.getpid).info("I'm in thread {0}", thread_name) #doctest:+ELLIPSIS INFO:pid=1076:I'm in thread MainThread
This can be useful with partially-bound loggers, which let’s us do some cool stuff:
>>> class ThreadTracker(object): ... def __init__(self, obj): ... self.__obj = obj ... # a partially bound logger ... self.__log = log.name("tracker").fields(obj_id=id(obj), thread=thread_name) ... self.__log.debug("started tracking") ... def __getattr__(self, attr): ... self.__log.debug("accessed {0}", attr) ... return getattr(self.__obj, attr) ... >>> class Bunch(object): ... pass ... >>> foo = Bunch() >>> foo.bar = 42 >>> tracked = ThreadTracker(foo) DEBUG:tracker:obj_id=14063980:thread=MainThread:started tracking >>> tracked.bar DEBUG:tracker:obj_id=14063980:thread=MainThread:accessed bar 42 >>> import threading >>> t=threading.Thread(target = lambda: tracked.bar * 2, name = "TheDoubler") >>> t.start() DEBUG:tracker:obj_id=14063980:thread=TheDoubler:accessed bar
If you really want to log a callable, repr() it or wrap it in lambda.
Optimizations
As an optimization, a min_level can be set on loggers:
>>> mylog.min_level = twiggy.Levels.INFO >>> mylog.info("You see this") INFO:alfredo:You see this >>> mylog.debug("This is hidden")
They also take a filter that operates on format_spec. The use case is efficiently shutting off specific messages in a library which is doing something stupid:
>>> mylog.filter = lambda s: "shenanigans" not in s >>> mylog.info("Starting silliness") INFO:alfredo:Starting silliness >>> for i in xrange(3): # for large values of 3 ... mylog.info("I call shenanigans!") >>> mylog.info("End silliness") INFO:alfredo:End silliness