Opened 10 years ago

Closed 10 years ago

#176 closed task (complete)

python logging framework

Reported by: jreed Owned by: zzchen_pku
Priority: medium Milestone: 05. 3rd Incremental Release: Serious Secondary
Component: logging Version:
Keywords: Cc:
CVSS Scoring: Parent Tickets:
Sensitive: no Defect Severity:
Sub-Project: Feature Depending on Ticket:
Estimated Difficulty: Add Hours to Ticket:
Total Hours: Internal?:

Description (last modified by jreed)

This is for task 73 from April 2010 face-to-face meeting.

The "start implementing this right away" will be done using python
first. The task is to convert a python module over to
log4python (xfrin or xfrout or cmdctl daemon or...)". I assume it is
just http://docs.python.org/library/logging.html

This is for testing and experimenting with logging ideas. We will also need to consider what BIND 9 currently does.

Subtickets

Change History (21)

comment:1 Changed 10 years ago by jreed

  • Description modified (diff)

comment:2 Changed 10 years ago by zzchen_pku

  • Status changed from new to accepted

comment:3 Changed 10 years ago by shane

  • Component changed from Unclassified to logging

comment:4 Changed 10 years ago by zzchen_pku

  • Owner changed from zzchen_pku to UnAssigned
  • Status changed from accepted to reviewing

Ready for review in branches/trac176.

Currently, python logging module supports four channels(null, file, syslog and stderr) and five levels (debug, info, warning, error and critical), more levels will be added later.

The logging severity and file channel configurations can be reconfigured at runtime through bindctl. xfrout module has been updated as the first module to use logging framework.

comment:5 Changed 10 years ago by zzchen_pku

  • Owner changed from UnAssigned to shane

comment:6 follow-up: Changed 10 years ago by shane

  • Owner changed from shane to zzchen_pku

In general, I think this is a good start and should be merged.

For the next release, we need to make sure we have more documentation, and probably a bit of discussion on a couple of the points below.


I see some print() in the main function. This is probably okay, but I was thinking:

  • Maybe some of these should also go to the logging system.
  • Maybe these should go to stderr instead of stdout.

In XfroutServer's __init__() function, we see:

    self._log = None
      ...
    self._log = isc.log.ModuleLogger(self._config_data.get('log_name'), self._config_data.get('log_file'),
                                         self._config_data.get('severity'), self._config_data.get('versions'),
                                         self._config_data.get('ma

No need to set it to None the first time! :)

In UnixSockServer's shutdown() method, don't leave the commented-out pass statement in there.

I think the default logging should be to something other than /var/log/xfrout.log. Probably it should go to something like @@LOCALSTATEDIR@@, except defined for logging, if there is such a thing...


In log.py:

In the ModuleLogger class, with the __init__() function, we need to document that to disable logging set log_file=.

Typo: Ture -> True

Also, for now it is fine, but I think maybe we should consider the design of how the ModuleLogger is created. Perhaps it would be easier to simply say something like:

    self._log.update_config(self._config_data))

And have the logging stuff use the .get() functions for you. I'm thinking this would be simpler, and actually make it easier to update the logging. Perhaps we can make this a backlog ticket, or just put it in a TODO file?

There are times when we need to only log to syslog(), for example.

In add_syslog_handler, there is no way to set facility, so the comment should just say "LOG_USER is used", rather than "If facility is not specified".

I'm not sure why we need the NullHandler by default... if it really just sends to nowhere, maybe we should leave it out completely? Or does it do something?


I had to change the tests to something other than /var/log to run. This is kind of related to the comment above about /var/log - but for testing I just made it go to /tmp. This is not necessarily the best solution, but it worked.

It might be nice to send the output to someplace other than stdout when running the tests. This could be done by something like:

def setUp(self):
      ...
    self.save_stdout = sys.stdout
    sys.stdout = open(os.devnull, "w")

      ...
def tearDown(self):
    sys.stdout = self.save_stdout
      ...

This will make "pytest" output a little easier to read.

comment:7 follow-up: Changed 10 years ago by zhanglikun

Some comment to the code.

  1. Change class name 'RotatingFilehandler?' to a new one, since you'd better don't make one class and its sub class share one same class name.
  2. Update funtion comment to follow python coding style(http://www.python.org/dev/peps/pep-0008/), change
'''
How are you
'''

to

'''How are you'''

comment:8 Changed 10 years ago by zhanglikun

Sorry, continue my comment:
change

'''
How are you
I am fine
'''

to

'''How are you
I am fine'''
  1. You'd better give a better name to class SLHandler? Since I thought it's about SSL.
  1. If the function or variable in class won't be called directly by others, add undercore '_' to function or variable name.
  1. test case 'test_log_message' in log_test.py should be redesigned properly.

Anyway, I suggest to delay merging code to trunk before fixing these problems.

comment:9 in reply to: ↑ 6 Changed 10 years ago by zzchen_pku

Replying to shane:

Thanks, Shane.

In general, I think this is a good start and should be merged.

For the next release, we need to make sure we have more documentation, and probably a bit of discussion on a couple of the points below.

Agree.

I see some print() in the main function. This is probably okay, but I was thinking:

  • Maybe some of these should also go to the logging system.
  • Maybe these should go to stderr instead of stdout.

I just did a simple test in Xfrout module, so some 'print' sentences haven't been replaced by log yet.

In log.py:

In the ModuleLogger class, with the __init__() function, we need to document that to disable logging set log_file=.

Good suggestions, I'll take your advices.

comment:10 in reply to: ↑ 7 Changed 10 years ago by zzchen_pku

Replying to zhanglikun:

Some comment to the code.

Thank you for your comments.
I have modified the code according to python coding style.

comment:11 Changed 10 years ago by shane

  • Milestone changed from 04. 2nd Incremental Release: Early Adopters to 05. 3rd Incremental Release

comment:12 Changed 10 years ago by jreed

log_test.py should probably write to the builddir or use mkstemp or something instead of hardcoded tmp file names.

comment:13 follow-up: Changed 10 years ago by jreed

When Xfrout failed to start due to not finding library, it logged:

2010-06-14 10:48:56,541: Xfrout: WARNING: Xfrout process is shutting down!

but didn't say reason why. (I may be mistaken about this logging though.)

Is it normal to have a comma in a time (56,541 seconds?)

Need some docs/explanation for the configuration tunables.
severity, versions, and max_bytes configuration names should maybe be prefixed with "log_" if they are related to logging.

How to enable syslog? (I didn't read source yet.)

Log file maybe should be in a "log" subdirectory by default.

Thank you very much for your work on adding logging! This is great!

comment:14 in reply to: ↑ 13 Changed 10 years ago by zzchen_pku

Replying to jreed:

Is it normal to have a comma in a time (56,541 seconds?)

The current time format : 19-May-2010 19:43:04.280

Need some docs/explanation for the configuration tunables.

http://bind10.isc.org/wiki/PythonLogging
Welcome your comments.

severity, versions, and max_bytes configuration names should maybe be prefixed with "log_" if they are related to logging.

Done.

How to enable syslog? (I didn't read source yet.)

Currently, syslog channel works for background process, it will be enabled if set verbose to False.

Log file maybe should be in a "log" subdirectory by default.

Done.
Thank you very much for your review.

comment:15 Changed 10 years ago by zzchen_pku

So what should I do now?
Is it okay to merge this branch into trunk?

comment:16 follow-up: Changed 10 years ago by jreed

         To pass exception information, use the keyword argument exc_info with
        a true value, e.g.
 
        logger.log_message('info', "We have a %s", "mysterious problem").

Is "exc_info" above a typo?

Also I don't see any unit testing for _encodeLevel and emit.

Is "emit" an acceptable function name? Seems to vague to me. Or is that the name defined by log4python?

comment:17 Changed 10 years ago by shane

I think this is okay to merge into trunk.

comment:18 in reply to: ↑ 16 Changed 10 years ago by zzchen_pku

Replying to jreed:

Is "exc_info" above a typo?

No, you can find it in the log4python library.

class Logger(Filterer):
   ...
   def _log(self, level, msg, args, exc_info=None, extra=None):
   ...

Also I don't see any unit testing for _encodeLevel and emit.

Ok, I'll add it.

Is "emit" an acceptable function name? Seems to vague to me. Or is that the name defined by log4python?

Yeah, it is defined by log4python, i just rewrite it.

comment:19 Changed 10 years ago by zzchen_pku

  • Resolution set to fixed
  • Status changed from reviewing to closed

Merged into r2338.

comment:20 Changed 10 years ago by zzchen_pku

  • Resolution fixed deleted
  • Status changed from closed to reopened

comment:21 Changed 10 years ago by shane

  • Resolution set to complete
  • Status changed from reopened to closed
Note: See TracTickets for help on using tickets.