[Tutor] python logger

[Peter Otten]

rail shafigulin wrote:

> has anyone used python logger before? i'm trying to adapt it for my
> workplace. right now it is pretty simplistic for me. i'm trying to
> generate
> extra output by the LoggerAdapter.  however i'm getting errors.
> specifically i get the following message:
> 
> Traceback (most recent call last):
>   File "/usr/lib/python3.1/logging/__init__.py", line 770, in emit
>     msg = self.format(record)
>   File "/usr/lib/python3.1/logging/__init__.py", line 650, in format
>     return fmt.format(record)
>   File "/usr/lib/python3.1/logging/__init__.py", line 438, in format
>     record.message = record.getMessage()
>   File "/usr/lib/python3.1/logging/__init__.py", line 308, in getMessage
>     msg = msg % self.args
> TypeError: not all arguments converted during string formatting
> 
> i'm using
> this<http://docs.python.org/release/3.1.3/library/logging.html#using-
loggeradapters-to-impart-contextual-information>documentation.
> any
> 
> here is my code

[snip]

That's not the actual code; it fails with another exception:

Traceback (most recent call last):
  File "logger_orig.py", line 74, in <module>
    main()
  File "logger_orig.py", line 70, in main
    mylogadapter = logger.LoggerAdapter(mylogger, testinfo)
NameError: global name 'logger' is not defined

In the actual code the line

>   mylogadapter = logger.LoggerAdapter(mylogger, testinfo)

has probably logging instead of logger. Under that assumption:

Technically you get an error because you have a format string without any 
placeholders. When the info() method of a Logger (or LoggerAdapter) receives 
more than one argument it tries to use the first argument as a format string 
as demonstrated below:

>>> import logging
>>> logging.basicConfig(level=logging.INFO)
>>> logging.info("foo")
INFO:root:foo
>>> logging.info("foo", "bar")
Traceback (most recent call last):
  File "/usr/lib/python3.1/logging/__init__.py", line 770, in emit
    msg = self.format(record)
  File "/usr/lib/python3.1/logging/__init__.py", line 650, in format
    return fmt.format(record)
  File "/usr/lib/python3.1/logging/__init__.py", line 438, in format
    record.message = record.getMessage()
  File "/usr/lib/python3.1/logging/__init__.py", line 308, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
>>> logging.info("foo BAR:%s", "bar")
INFO:root:foo BAR:bar
>>> logging.info("foo BAR:%s BAZ:%s", "bar", "baz")
INFO:root:foo BAR:bar BAZ:baz

I've not used a LoggerAdapter myself, but as I read the docs it is meant to 
simplify the addition of extra data, e. g. if you have

common_extra = {"notes": "whatever"}
...
logger.info("one", extra_common_extra)
...
logger.info("two", extra=common_extra)
...
logger.info("three", extra=common_extra)
...

you can simplify that to

logger = logging.LoggingAdapter(logger, {"notes": "whatever"})
...
logger.info("one")
...
logger.info("two")
...
logger.info("three")

Applying the principle to your code:

def main():
    # recommended indent is 4 spaces
    testinfo = TestInfo(
        test_name='myname',
        description='mydescription',
        notes='mynotes',
        expected='myexpected',
        actual='myactual',
        status='Fail',
        timestamp='mystamp')

    mylogger = logging.getLogger('mylogger')
    mylogger.setLevel(logging.DEBUG)

    filehandler = logging.FileHandler('test.log')
    filehandler.setLevel(logging.DEBUG)

    # added to verify that testinfo is indeed passed on:
    formatter = logging.Formatter(logging.BASIC_FORMAT + " notes: 
%(notes)s")
    filehandler.setFormatter(formatter)

    mylogger.addHandler(filehandler)
    mylogadapter = logging.LoggerAdapter(mylogger, testinfo)
    mylogadapter.info('this is a log message')
    #without adapter the above line would be:
    #mylogger.info('this is a log message', extra=testinfo)

if __name__ == "__main__":
    main()