to be pythonic: should caller or callee log?

[Ethan Furman]

On 09/03/2013 09:07 AM, Gildor Oronar wrote:
> What would you choose? Do you put logging routine into caller or callee? My intuitive answer is "callee does the
> logging, because that's where action takes place", like this:
>
> class Account():
>      def transaction(self, amount, target):
>          logging.info("Start transaction of %s to %s" % (amount, target))
>          ...
>
> So far so good, but we grew up to have 10 different account classes:
>
> class AbsctractAccount():
>
> class CreditAccount(AbstractAccount):
>      def transaction(self, amount, target):
>          logging.info("Start transaction of %s to %s" % (amount, target))
>          ...
>
> class DebitAccount(AbstractAccount):
>      def transaction(self, amount, target):
>          logging.info("Start transaction of %s to %s" % (amount, target))
>          ...
>
> class SomeOtherAccount(...)
>      ....
>
> Then letting the callee do the logging is also tedious now.
>
> What is the best practise here?
>
> If, for the convenience, we define transaction function in AbstractAccount to just do the logging, and change inherited
> classes, like this:
>
> class AbsctractAccount():
>      def transaction(self, amount, target):
>          logging.info("Start transaction of %s to %s" % (amount, target))
>
> class DebitAccount(AbstractAccount):
>      def transaction(self, amount, target):
>          super().transaction(amount,target)
>          ....

In this instance you're not really gaining anything by using inheritance: before you had one line for logging, after you 
have one line to call super(); in either case if you forget the one line you don't get a log entry.

I would say it is not really the caller's or the callee's job to do the logging, even though it should be done.  What 
would be really handy is a function that sat in between the caller and callee that logged for you -- you know, a decorator:

     # not tested, but hopefully you get the idea
     def log(func):
         def wrapper(*args, **kwds):
             text = []
             if args:
                 text.append(str(args))
             if kwds:
                 text.append(str(kwds))
             text = ', '.join(text)
             if text:
	        logging.info("%s called with %s" % (func.__name__, text)
             else:
                 logging.info("%s called" % func.__name__)
             return func(*args, **kwds)
         return wrapper

Then you can say:

      class WhateverAccount:

         @log
         def transaction(self, amount, target):
             ...

True, you still one line, but moves the logging concern outside the function, where it doesn't really belong.  It also 
makes it really easy to see if a function will be logged or not.

--
~Ethan~