to be pythonic: should caller or callee log?

[Gildor Oronar]

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))
...

if '__name__' == '__main__'
....
account.transaction(amount, target)


Simple and easy. Put logging code to the caller would be tedious - the
function is called about 20 times in different places.

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)
....

Then we gethered logging code pieces all to one place, but it begets two
other problems.

1. It is a "surprise" that super().transaction must be called first, not
last, and that it does only the logging.

2. The code used to check whether "transaction" is implemented:

if hasAttr(DebitAccount, 'transaction'): # clear to read

has to be changed to check whether "transaction" is inherited:

if not DebitAccount.transaction is AbstractAccount.transaction:

whose purpose is confusing, and whose cause is a little surprise too.
Also, the pythonic "boldly calling and watching for exception" stopped
working, because instead of getting AttributeError, we would get a line
of log and nothing more.

 

[Terry Reedy]

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))
...

if '__name__' == '__main__'
....
account.transaction(amount, target)


Simple and easy. Put logging code to the caller would be tedious - the
function is called about 20 times in different places.

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)
....

Then we gethered logging code pieces all to one place, but it begets two
other problems.

1. It is a "surprise" that super().transaction must be called first,

Not to me ;-). That is fairly standard in super examples I have seen posted.

not last, and that it does only the logging.

If that is the only thing in common ...

2. The code used to check whether "transaction" is implemented:
if hasAttr(DebitAccount, 'transaction'): # clear to read
has to be changed to check whether "transaction" is inherited:
if not DebitAccount.transaction is AbstractAccount.transaction:

whose purpose is confusing, and whose cause is a little surprise too.

I would expect that every account class has a transaction method.
* If so, just call it, but
assertIsNot(DebitAccount.transaction, AbstractAccount.transaction)
for every subclass in your test suite.
* If not, perhaps you need an abstract subclass TransAccount. Then use
hasattr in production code and the isnot test in test code.

Also, the pythonic "boldly calling and watching for exception" stopped
working, because instead of getting AttributeError, we would get a line
of log and nothing more.

This is what test suites are for.

 

[Ethan Furman]

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.

 

[Gildor Oronar]

El 04/09/13 10:26, Ethan Furman escribió:

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:

Thanks a lot! My knowledge to decorator is so limited to @staticmethod
that I don't know I can write my own decorator. This is a good lesson to
learn.

Your example lead me to explore and find this article which addressed
the case of using decorator to log:

http://simeonfranklin.com/blog/2012/jul/1/python-decorators-in-12-steps/
(To googler who find this post: search 'log' in the above article)

 

[Gildor Oronar]

Thanks:

El 04/09/13 05:01, Terry Reedy escribió:

I would expect that every account class has a transaction method.
* If so, just call it, but
assertIsNot(DebitAccount.transaction, AbstractAccount.transaction)
for every subclass in your test suite.
* If not, perhaps you need an abstract subclass TransAccount. Then use
hasattr in production code and the isnot test in test code.

I would assume that you categorize this as a unit test problem, because
you consider an Acount not implementing Transaction is a bug, right?

There are two occassions an account is intended not having Transaction
function, both not test-related:

1. The acount doesn't offer this feature. e.g. Certificate of Deposit.
This can be in TransAccount.

2. The 3rd-party account offer this feature but doesn't qualify the
software's requirement, e.g. not returning the result in 3 seconds, and
is avoided when planning the deal (I am writing an auto-trade software).
This case you cannot categorize those who can into TransAccount,
beacause 1) that naming imply other accounts don't do transaction but
they do, just not good enough; 2) when other accounts becomes good
enough, the change (to inheritance) is a bit too invasive.

 

[Xaxa Urtiz]

Le mercredi 4 septembre 2013 09:44:27 UTC+2, Gildor Oronar a écrit :

Thanks:



El 04/09/13 05:01, Terry Reedy escribió:











I would assume that you categorize this as a unit test problem, because

you consider an Acount not implementing Transaction is a bug, right?



There are two occassions an account is intended not having Transaction

function, both not test-related:



1. The acount doesn't offer this feature. e.g. Certificate of Deposit.

This can be in TransAccount.



2. The 3rd-party account offer this feature but doesn't qualify the

software's requirement, e.g. not returning the result in 3 seconds, and

is avoided when planning the deal (I am writing an auto-trade software).

This case you cannot categorize those who can into TransAccount,

beacause 1) that naming imply other accounts don't do transaction but

they do, just not good enough; 2) when other accounts becomes good

enough, the change (to inheritance) is a bit too invasive.

Hello,
and what about something like that :


class AbsctractAccount():
def transaction(self, amount, target):
logging.info("Start transaction of %s to %s" % (amount, target))
self.DoTransaction(amount,target)

def DoTransaction(self,amount,target):
pass # or raise notimplemented or do not implement this methods inthe abstract class
...

class DebitAccount(AbstractAccount):
def DoTransaction(self, amount, target):
...

class SomeOtherAccount(...)
....
like that you only have to write the logging function once.

 

[Gildor Oronar]

El 04/09/13 20:14, Xaxa Urtiz escribió:

and what about something like that :


class AbsctractAccount():
def transaction(self, amount, target):
logging.info("Start transaction of %s to %s" % (amount, target))
self.DoTransaction(amount,target)

def DoTransaction(self,amount,target):
pass # or raise notimplemented or do not implement this methods in the abstract class
...

class DebitAccount(AbstractAccount):
def DoTransaction(self, amount, target):
...

class SomeOtherAccount(...)
....
like that you only have to write the logging function once.

Thanks for the hint! This also work well, and has the advantage of being
specific to this function -- I did use decorator as Ethan suggested,
which works for most of the case, but there is function (other than
transaction) needs specialized logging because the function doesn't
return anything but changes a class variable -- using a special
decorator for just one function is over-generalizing, and your method
kicks in.