source: main/waeup.kofa/trunk/src/waeup/kofa/utils/logger.py @ 13936

Last change on this file since 13936 was 13776, checked in by Henrik Bettermann, 9 years ago

Do not import deprecated DatedRotatingFileHandler?.

  • Property svn:keywords set to Id
File size: 13.4 KB
Line 
1## $Id: logger.py 13776 2016-03-11 11:45:01Z henrik $
2##
3## Copyright (C) 2011 Uli Fouquet & Henrik Bettermann
4## This program is free software; you can redistribute it and/or modify
5## it under the terms of the GNU General Public License as published by
6## the Free Software Foundation; either version 2 of the License, or
7## (at your option) any later version.
8##
9## This program is distributed in the hope that it will be useful,
10## but WITHOUT ANY WARRANTY; without even the implied warranty of
11## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12## GNU General Public License for more details.
13##
14## You should have received a copy of the GNU General Public License
15## along with this program; if not, write to the Free Software
16## Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
17##
18"""
19Convenience stuff for logging.
20
21Main component of :mod:`waeup.kofa.utils.logging` is a mix-in class
22:class:`waeup.kofa.utils.logging.Logger`. Classes derived (also) from
23that mix-in provide a `logger` attribute that returns a regular Python
24logger logging to a rotating log file stored in the datacenter storage
25path.
26
27Deriving components (classes) should set their own `logger_name` and
28`logger_filename` attribute.
29
30The `logger_name` tells under which name the logger should be
31registered Python-wise. This is usually a dotted name string like
32``waeup.kofa.${sitename}.mycomponent`` which should be unique. If you
33pick a name already used by another component, trouble is ahead. The
34``${sitename}`` chunk of the name can be set literally like this. The
35logger machinery will turn it into some real site name at time of
36logging.
37
38The `logger_filename` attribute tells how the logfile should be
39named. This should be some base filename like
40``mycomponent.log``. Please note, that some logfile names are already
41used: ``main.log``, ``applications.log``, and ``datacenter.log``.
42
43The `Logger` mix-in also cares for updating the logging handlers when
44a datacenter location moves. That means you do not have to write your
45own event handlers for the purpose. Just derive from `Logger`, set
46your `logger_name` and `logger_filename` attribute and off you go::
47
48  from waeup.kofa.utils.logger import Logger
49
50  class MyComponent(object, Logger):
51      # Yes that's a complete working class
52      logger_name = 'waeup.kofa.${sitename}.mycomponent
53      logger_filename = 'mycomponent.log'
54
55      def do_something(self):
56           # demomstrate how to use logging from methods
57           self.logger.info('About to do something')
58           try:
59               # Do something here
60           except IOError:
61               self.logger.warn('Something went wrong')
62               return
63           self.logger.info('I did it')
64
65As you can see from that example, methods of the class can log
66messages simply by calling `self.logger`.
67
68The datacenter and its storage are created automatically when you
69create a :class:`waeup.kofa.app.University`. This also means that
70logging with the `Logger` mix-in will work only inside so-called sites
71(`University` instances put into ZODB are such `sites`).
72
73Other components in this module help to make everything work.
74"""
75import os
76import grok
77import logging
78from logging.handlers import WatchedFileHandler
79from string import Template
80from zope import schema
81from zope.component import queryUtility
82from zope.interface import Interface, Attribute, implements
83from waeup.kofa.interfaces import (
84    IDataCenter, IDataCenterStorageMovedEvent, ILoggerCollector)
85from waeup.kofa.utils.helpers import get_current_principal
86
87#: Default logging level (`logging.INFO`)
88LEVEL = logging.INFO
89
90class ILogger(Interface):
91    logger_name = schema.TextLine(
92        title = u'A Python logger name')
93    logger_filename = schema.TextLine(
94        title = u'A filename for the log file to use (basename)')
95    logger = Attribute("Get a Python logger instance already set up")
96    def logger_setup(logger):
97        """Setup a logger.
98
99        `logger` is an instance of :class:`logging.Logger`.
100        """
101
102    def logger_get_logfile_path():
103        """Get path to logfile used.
104
105        Return `None` if the file path cannot be computed.
106        """
107
108    def logger_get_logdir():
109        """Get the directory of the logfile.
110
111        Return `None` if the directory path cannot be computed.
112        """
113
114class ContextFilter(logging.Filter):
115    """
116    This is a filter which injects contextual information into the log.
117
118    """
119
120    def filter(self, record):
121        user = get_current_principal()
122        record.user = getattr(user, 'id', 'system')
123        return True
124
125class Logger(object):
126    """Mixin-class that for logging support.
127
128    Classes that (also) inherit from this class provide support for
129    logging with waeup sites.
130
131    By default a `logger` attribute is provided which returns a
132    regular Python logger. This logger has already registered a file
133    rotating log handler that writes log messages to a file `main.log`
134    in datacenters ``log/`` directory. This is the main log file also
135    used by other components. Therefore you can pick another filename
136    by setting the `logger_filename` attribute.
137
138    All methods and attributes of this mix-in start with ``logger_``
139    in order not to interfere with already existing names of a class.
140
141    Method names do not follow the usual Zope habit (CamelCase) but
142    PEP8 convention (lower_case_with_underscores).
143    """
144
145    #: The filename to use when logging.
146    logger_filename = 'main.log'
147
148    #: The Python logger name used when
149    #: logging. ``'waeup.kofa.${sitename}'`` by default. You can use the
150    #: ``${sitename}`` placeholder in that string, which will be
151    #: replaced by the actual used site name.
152    logger_name = 'waeup.kofa.${sitename}'
153
154    #: The format to use when logging.
155    logger_format_str = '%(asctime)s - %(levelname)s - %(user)s - %(message)s'
156
157    implements(ILogger)
158
159    @property
160    def logger(self):
161        """Get a logger instance.
162
163        Returns a standard logger object as provided by :mod:`logging`
164        module from the standard library.
165
166        Other components can use this logger to perform log entries
167        into the logfile of this component.
168
169        The logger is initialized the first time it is called.
170
171        The logger is only available when used inside a site.
172
173        .. note:: The logger default level is
174                  :data:`logging.WARN`. Use
175                  :meth:`logging.Logger.setLevel` to set a different level.
176        """
177        site = grok.getSite()
178        sitename = getattr(site, '__name__', None)
179        loggername = Template(self.logger_name).substitute(
180            dict(sitename='%s' % sitename))
181        logger = logging.getLogger(loggername)
182        if site is None or sitename is None:
183            # Site not added to ZODB yet. Log to commandline
184            return logger
185        if len(logger.handlers) != 1:
186            handlers = [x for x in logger.handlers]
187            for handler in handlers:
188                handler.flush()
189                handler.close()
190                logger.removeHandler(handler)
191            logger = self.logger_setup(logger)
192        if logger is None:
193            # It might happen, that we have no logger now.
194            logger = logging.getLogger(loggername)
195        return logger
196
197    def logger_setup(self, logger):
198        """Setup logger.
199
200        The logfile will be stored in the datacenter logs/ dir.
201        """
202        filename = self.logger_get_logfile_path()
203        if filename is None:
204            return
205        collector = queryUtility(ILoggerCollector)
206        if collector is not None:
207            site = grok.getSite()
208            collector.registerLogger(site, self)
209
210        # Create a rotating file handler logger.
211        handler = WatchedFileHandler(
212            filename, encoding='utf-8')
213        handler.setLevel(LEVEL)
214        formatter = logging.Formatter(self.logger_format_str)
215        handler.setFormatter(formatter)
216
217        # Don't send log msgs to ancestors. This stops displaying
218        # logmessages on the commandline.
219        logger.propagate = False
220        logger.addHandler(handler)
221        logger.setLevel(LEVEL)
222
223        flt = ContextFilter()
224        logger.addFilter(flt)
225        return logger
226
227    def logger_get_logfile_path(self):
228        """Get the path to the logfile used.
229
230        Returns the path to a file in local sites datacenter ``log/``
231        directory (dependent on :meth:`logger_get_logdir`) and with
232        :attr:`logger_filename` as basename.
233
234        Override this method if you want a complete different
235        computation of the logfile path. If you only want a different
236        logfile name, set :attr:`logger_filename`. If you only want a
237        different path to the logfile override
238        :meth:`logger_get_logdir` instead.
239
240        Returns ``None`` if no logdir can be fetched.
241
242        .. note:: creates the logfile dir if it does not exist.
243
244        """
245        logdir = self.logger_get_logdir()
246        if logdir is None:
247            return None
248        return os.path.join(logdir, self.logger_filename)
249
250    def logger_get_logdir(self):
251        """Get log dir where logfile should be put.
252
253        Returns the path to the logfile directory. If no site is set,
254        ``None`` is returned. The same applies, if the site has no
255        datacenter.
256
257        If the dir dies not exist already it will be created. Only the
258        last part of the directory path will be created.
259        """
260        site = grok.getSite()
261        if site is None:
262            return None
263        datacenter = site.get('datacenter', None)
264        if datacenter is None:
265            return None
266        logdir = os.path.join(datacenter.storage, 'logs')
267        if not os.path.exists(logdir):
268            os.mkdir(logdir)
269        return logdir
270
271    def logger_logfile_changed(self):
272        """React on logfile location change.
273
274        If the logfile changed, we can set a different logfile. While
275        changing the logfile is a rather critical operation you might
276        not do often in production use, we have to cope with that
277        especially in tests.
278
279        What this method does by default (unless you override it):
280
281        - It fetches the current logger and
282
283          - Removes flushes, closes, and removes all handlers
284
285          - Sets up new handler(s).
286
287        All this, of course, requires to be 'in a site'.
288
289        Use this method to handle moves of datacenters, for instance
290        by writing an appropriate event handler.
291        """
292        logger = self.logger
293        self.logger_shutdown()
294        self.logger_setup(logger)
295        return
296
297    def logger_shutdown(self):
298        """Remove all specific logger setup.
299        """
300        logger = self.logger
301        handlers = [x for x in logger.handlers]
302        for handler in handlers:
303            handler.flush()
304            handler.close()
305            logger.removeHandler(handler)
306        collector = queryUtility(ILoggerCollector)
307        if collector is not None:
308            collector.unregisterLogger(grok.getSite(), self)
309        return
310
311
312class LoggerCollector(dict, grok.GlobalUtility):
313    """A global utility providing `ILoggerCollector`.
314
315    A logging collector collects logging components. This helps to
316    inform them when a logfile location changes.
317
318    Logging components are registered per site they belong to.
319    """
320
321    implements(ILoggerCollector)
322
323    def getLoggers(self, site):
324        name = getattr(site, '__name__', None)
325        if name is None:
326            return []
327        if name not in self.keys():
328            return []
329        return self[name]
330
331    def registerLogger(self, site, logging_component):
332        name = getattr(site, '__name__', None)
333        if name is None:
334            return
335        if not name in self.keys():
336            # new component
337            self[name] = []
338        if logging_component in self[name]:
339            # already registered
340            return
341        self[name].append(logging_component)
342        return
343
344    def unregisterLogger(self, site, logging_component):
345        name = getattr(site, '__name__', None)
346        if name is None or name not in self.keys():
347            return
348        if logging_component not in self[name]:
349            return
350        self[name].remove(logging_component)
351        return
352
353@grok.subscribe(IDataCenter, IDataCenterStorageMovedEvent)
354def handle_datacenter_storage_moved(obj, event):
355    """Event handler, in case datacenter storage moves.
356
357    By default all our logfiles (yes, we produce a whole bunch of it)
358    are located in a ``log/`` dir of a local datacenter, the
359    datacenter 'storage'. If this path changes because the datacenter
360    is moved an appropriate event is triggered and we can react.
361
362    Via the global ILoggerCollector utility, a small piece that allows
363    self-registering of logging components, we can lookup components
364    whose logfile path has to be set up anew.
365
366    Each component we call has to provide ILogger or, more specific,
367    the :meth:`logger_logfile_changed` method of this interface.
368    """
369    site = grok.getSite()
370    if site is None:
371        return
372    collector = queryUtility(ILoggerCollector)
373    loggers = collector.getLoggers(site)
374    for logger in loggers:
375        if hasattr(logger, 'logger_logfile_changed'):
376            logger.logger_logfile_changed()
377    return
378
379from waeup.kofa.interfaces import IUniversity
380@grok.subscribe(IUniversity, grok.IObjectRemovedEvent)
381def handle_site_removed(obj, event):
382    collector = queryUtility(ILoggerCollector)
383    name = getattr(obj, '__name__', None)
384    if name is None:
385        return
386    if name not in collector.keys():
387        return
388    del collector[name]
389    return
Note: See TracBrowser for help on using the repository browser.