Edgewall Software

Ticket #7286: all-the-way_enhanced_logging.2.patch

File all-the-way_enhanced_logging.2.patch, 58.9 KB (added by palgarvio, 4 years ago)

This one also issues some warnings of bad env.log deprecated usage.

  • trac/attachment.py

     
    113113            self.resource = Resource(parent_realm_or_attachment_resource, 
    114114                                     parent_id).child('attachment', filename) 
    115115        self.env = env 
     116        self.log = self.env.get_logger(__name__) 
    116117        self.parent_realm = self.resource.parent.realm 
    117118        self.parent_id = unicode(self.resource.parent.id) 
    118119        if self.resource.id: 
     
    181182            try: 
    182183                os.unlink(self.path) 
    183184            except OSError: 
    184                 self.env.log.error('Failed to delete attachment file %s', 
    185                                    self.path, exc_info=True) 
     185                self.log.error('Failed to delete attachment file %s', 
     186                               self.path, exc_info=True) 
    186187                if handle_ta: 
    187188                    db.rollback() 
    188189                raise TracError(_('Could not delete attachment')) 
    189190 
    190         self.env.log.info('Attachment removed: %s' % self.title) 
     191        self.log.info('Attachment removed: %s', self.title) 
    191192        if handle_ta: 
    192193            db.commit() 
    193194 
     
    234235            shutil.copyfileobj(fileobj, targetfile) 
    235236            self.resource.id = self.filename = filename 
    236237 
    237             self.env.log.info('New attachment: %s by %s', self.title, 
    238                               self.author) 
     238            self.log.info('New attachment: %s by %s', self.title, self.author) 
    239239 
    240240            if handle_ta: 
    241241                db.commit() 
     
    270270        As this is usually done while deleting the parent resource, 
    271271        the `db` argument is ''not'' optional here. 
    272272        """ 
     273        log = env.get_logger(__name__) 
    273274        attachment_dir = None 
    274275        for attachment in list(cls.select(env, parent_realm, parent_id, db)): 
    275276            attachment_dir = os.path.dirname(attachment.path) 
     
    278279            try: 
    279280                os.rmdir(attachment_dir) 
    280281            except OSError: 
    281                 env.log.error("Can't delete attachment directory %s", 
    282                               attachment_dir, exc_info=True) 
     282                log.error("Can't delete attachment directory %s", 
     283                          attachment_dir, exc_info=True) 
    283284             
    284285    select = classmethod(select) 
    285286    delete_all = classmethod(delete_all) 
    286287 
    287288    def open(self): 
    288         self.env.log.debug('Trying to open attachment at %s', self.path) 
     289        self.log.debug('Trying to open attachment at %s', self.path) 
    289290        try: 
    290291            fd = open(self.path, 'rb') 
    291292        except IOError: 
     
    694695            add_link(req, 'alternate', raw_href, _('Original Format'), 
    695696                     mime_type) 
    696697 
    697             self.log.debug("Rendering preview of file %s with mime-type %s" 
    698                            % (attachment.filename, mime_type)) 
     698            self.log.debug("Rendering preview of file %s with mime-type %s", 
     699                           attachment.filename, mime_type) 
    699700 
    700701            data['preview'] = mimeview.preview_data( 
    701702                Context.from_request(req, attachment.resource), fd, 
     
    772773        if legacy_action: 
    773774            decision = legacy_action in perm 
    774775            if not decision: 
    775                 self.env.log.debug('LegacyAttachmentPolicy denied %s ' 
    776                                    'access to %s. User needs %s' % 
    777                                    (username, resource, legacy_action)) 
     776                self.log.debug('LegacyAttachmentPolicy denied %s ' 
     777                               'access to %s. User needs %s', 
     778                               username, resource, legacy_action) 
    778779            return decision 
    779780        else: 
    780781            for d in self.delegates: 
  • trac/env.py

     
    22# 
    33# Copyright (C) 2003-2008 Edgewall Software 
    44# Copyright (C) 2003-2007 Jonas Borgström <jonas@edgewall.com> 
     5# Copyright (C) 2008 Pedro Algarvio <ufs@ufsoft.org> 
    56# All rights reserved. 
    67# 
    78# This software is licensed as described in the file COPYING, which 
     
    1415# 
    1516# Author: Jonas Borgström <jonas@edgewall.com> 
    1617 
     18import logging 
    1719import os 
    1820try: 
    1921    import threading 
     
    147149         - $(path)s     the path for the current environment 
    148150         - $(basename)s the last path component of the current environment 
    149151         - $(project)s  the project name 
    150  
    151          Note the usage of `$(...)s` instead of `%(...)s` as the latter form 
    152          would be interpreted by the ConfigParser itself. 
    153  
    154          Example: 
     152         
     153        Note the usage of `$(...)s` instead of `%(...)s` as the latter form 
     154        would be interpreted by the ConfigParser itself. 
     155         
     156        Example: 
    155157         ($(thread)d) Trac[$(basename)s:$(module)s] $(levelname)s: $(message)s 
    156  
    157          (since 0.10.5)""") 
     158         
     159        (since 0.10.5)""") 
     160    log_filters = ListOption('logging', 'log_filters', [], doc= 
     161        """Custom logging handlers. 
     162         
     163        If nothing set, logging will be as it was, nothing is changed. 
     164         
     165        Example usage is: 
     166        log_filters = trac:WARNING, trac.ticket:DEBUG 
     167         
     168        The above would translate to: 
     169            * all messages who's module name starts with `trac` and log level 
     170            is higher than `WARNING` are logged; 
     171            * all messages who's module name starts with `trac.ticket` and log 
     172            level is higher than `DEBUG` are logged; 
     173            * all other messages who's module name does not start with any of 
     174            the above and for which their level is higher than the default 
     175            `log_level` will be logged; 
     176         
     177        This way you can narrow the debugging messages to the modules you 
     178        wish to. The same applies to a plugin you're coding: 
     179        log_filters = trac:ERROR, my.plug.module:DEBUG 
     180         
     181        (since 0.12)""") 
    158182 
    159183    def __init__(self, path, create=False, options=[]): 
    160184        """Initialize the Trac environment. 
     
    201225        environment configuration) and `log` (a logger object).""" 
    202226        component.env = self 
    203227        component.config = self.config 
    204         component.log = self.log 
     228        component.log = logging.getLogger( 
     229            "%s.%s" % (self.path, component.__class__.__module__) 
     230        ) 
    205231 
    206232    def is_component_enabled(self, cls): 
    207233        """Implemented to only allow activation of components that are not 
     
    353379 
    354380    def setup_log(self): 
    355381        """Initialize the logging sub-system.""" 
    356         from trac.log import logger_factory 
     382        from trac.log import setup_logging 
    357383        logtype = self.log_type 
    358384        logfile = self.log_file 
    359385        if logtype == 'file' and not os.path.isabs(logfile): 
     
    364390                     .replace('%(path)s', self.path) \ 
    365391                     .replace('%(basename)s', os.path.basename(self.path)) \ 
    366392                     .replace('%(project)s', self.project_name) 
    367         self.log = logger_factory(logtype, logfile, self.log_level, self.path, 
    368                                   format=format) 
     393        # Setup but don't keep the root logger  
     394        setup_logging(logtype, logfile, self.log_level, self.path, 
     395                      format, self.log_filters) 
     396         
     397        class CheckDeprecatedLoggingUsage(object): 
     398            """Proxy class to warn users of bad logging usage""" 
     399            log = logging.getLogger("%s.%s" % (self.path, __name__)) 
     400            def check_deprecated_use(self): 
     401                import inspect 
     402                caller = inspect.stack()[2] 
     403                if 'env.log' in caller[4][0]: 
     404                    self.log.warn( 
     405                        _("""Please stop logging through "env.log" on "%s". \ 
     406The code issuing this is "%s". This usage is now deprecated. Instead, if \ 
     407it's a trac Component, please use "self.log", if it's just a function which \ 
     408get's passed a trac env, get a logger like "log = env.get_logger(__name__)" \ 
     409and log through that. This practice provides good and usefull logging."""), 
     410                        caller[1], caller[4][0].strip()) 
     411                del caller 
     412            def __getattribute__(self, name): 
     413                if name in ('log', 'check_deprecated_use'): 
     414                    return object.__getattribute__(self, name) 
     415                self.check_deprecated_use() 
     416                return getattr(self.log, name) 
     417                 
     418        # Get a logger for this module 
     419        self.log = CheckDeprecatedLoggingUsage() 
     420         
     421    def get_logger(self, name): 
     422        """Get the correct logger for classes/functions which an env is passed, 
     423        yet, it's not subclassing Component.""" 
     424        from trac.log import get_logger 
     425        return get_logger(self.path, name) 
    369426 
    370427    def get_known_users(self, cnx=None): 
    371428        """Generator that yields information about all known users, i.e. users 
     
    557614                env.log.info('Reloading environment due to configuration ' 
    558615                             'change') 
    559616                env.shutdown() 
    560                 if hasattr(env.log, '_trac_handler'): 
    561                     hdlr = env.log._trac_handler 
    562                     env.log.removeHandler(hdlr) 
     617                env_root_logger = logging.getLogger(env.path) 
     618                if hasattr(env_root_logger, '_trac_handler'):                     
     619                    hdlr = env_root_logger._trac_handler 
     620                    env_root_logger.removeHandler(hdlr) 
    563621                    hdlr.close() 
     622                del env_root_logger 
    564623                del env_cache[env_path] 
    565624                env = None 
    566625            if env is None: 
  • trac/mimeview/enscript.py

     
    136136        mimetype = mimetype.split(';', 1)[0] # strip off charset 
    137137        mode = self._types[mimetype][0] 
    138138        cmdline += ' --color -h -q --language=html -p - -E%s' % mode 
    139         self.env.log.debug("Enscript command line: %s" % cmdline) 
     139        self.log.debug("Enscript command line: %s", cmdline) 
    140140 
    141141        np = NaivePopen(cmdline, content.encode('utf-8'), capturestderr=1) 
    142142        if np.errorlevel or np.err: 
  • trac/mimeview/php.py

     
    8181    def render(self, context, mimetype, content, filename=None, rev=None): 
    8282        # -n to ignore php.ini so we're using default colors 
    8383        cmdline = '%s -sn' % self.path 
    84         self.env.log.debug("PHP command line: %s" % cmdline) 
     84        self.log.debug("PHP command line: %s", cmdline) 
    8585 
    8686        content = content_to_unicode(self.env, content, mimetype) 
    8787        content = content.encode('utf-8') 
  • trac/ticket/tests/query.py

     
    1 from trac.log import logger_factory 
     1from trac.log import setup_logging 
    22from trac.mimeview import Context 
    33from trac.test import Mock, EnvironmentStub, MockPerm 
    44from trac.ticket.query import Query, QueryModule 
  • trac/ticket/report.py

     
    547547            # The column name is obtained. 
    548548            get_col_name_sql = 'SELECT * FROM ( ' + sql + ' ) AS tab LIMIT 1' 
    549549            cursor.execute(get_col_name_sql, args) 
    550             self.env.log.debug("Query SQL(Get col names): " + get_col_name_sql) 
     550            self.log.debug("Query SQL(Get col names): " + get_col_name_sql) 
    551551            cols = get_column_names(cursor) 
    552552 
    553553            sort_col = req.args.get('sort', '') 
  • trac/ticket/model.py

     
    4040 
    4141    def __init__(self, env, tkt_id=None, db=None, version=None): 
    4242        self.env = env 
     43        self.log = self.env.get_logger(__name__) 
    4344        self.resource = Resource('ticket', tkt_id, version) 
    4445        self.fields = TicketSystem(self.env).get_ticket_fields() 
    4546        self.values = {} 
     
    7778                    try: 
    7879                        default = options[int(default)] 
    7980                    except (ValueError, IndexError): 
    80                         self.env.log.warning('Invalid default value "%s" ' 
    81                                              'for custom field "%s"' 
    82                                              % (default, field['name'])) 
     81                        self.log.warning('Invalid default value "%s" for ' 
     82                                         'custom field "%s"', default, 
     83                                         field['name']) 
    8384            if default: 
    8485                self.values.setdefault(field['name'], default) 
    8586 
     
    350351        if not self.ticket_col: 
    351352            self.ticket_col = self.type 
    352353        self.env = env 
     354        self.log = self.env.get_logger(__name__) 
    353355        if name: 
    354356            name = simplify_whitespace(name) 
    355357        if name: 
     
    379381            handle_ta = False 
    380382 
    381383        cursor = db.cursor() 
    382         self.env.log.info('Deleting %s %s' % (self.type, self.name)) 
     384        self.log.info('Deleting %s %s', self.type, self.name) 
    383385        cursor.execute("DELETE FROM enum WHERE type=%s AND value=%s", 
    384386                       (self.type, self._old_value)) 
    385387        # Re-order any enums that have higher value than deleted (close gap) 
     
    407409            handle_ta = False 
    408410 
    409411        cursor = db.cursor() 
    410         self.env.log.debug("Creating new %s '%s'" % (self.type, self.name)) 
     412        self.log.debug("Creating new %s '%s'", self.type, self.name) 
    411413        if not self.value: 
    412414            cursor.execute(("SELECT COALESCE(MAX(%s),0) FROM enum " 
    413415                            "WHERE type=%%s") % db.cast('value', 'int'), 
     
    432434            handle_ta = False 
    433435 
    434436        cursor = db.cursor() 
    435         self.env.log.info('Updating %s "%s"' % (self.type, self.name)) 
     437        self.log.info('Updating %s "%s"', self.type, self.name) 
    436438        cursor.execute("UPDATE enum SET name=%s,value=%s " 
    437439                       "WHERE type=%s AND name=%s", 
    438440                       (self.name, self.value, self.type, self._old_name)) 
     
    494496 
    495497    def __init__(self, env, name=None, db=None): 
    496498        self.env = env 
     499        self.log = self.env.get_logger(__name__) 
    497500        if name: 
    498501            name = simplify_whitespace(name) 
    499502        if name: 
     
    525528            handle_ta = False 
    526529 
    527530        cursor = db.cursor() 
    528         self.env.log.info('Deleting component %s' % self.name) 
     531        self.log.info('Deleting component %s', self.name) 
    529532        cursor.execute("DELETE FROM component WHERE name=%s", (self.name,)) 
    530533 
    531534        self.name = self._old_name = None 
     
    544547            handle_ta = False 
    545548 
    546549        cursor = db.cursor() 
    547         self.env.log.debug("Creating new component '%s'" % self.name) 
     550        self.log.debug("Creating new component '%s'", self.name) 
    548551        cursor.execute("INSERT INTO component (name,owner,description) " 
    549552                       "VALUES (%s,%s,%s)", 
    550553                       (self.name, self.owner, self.description)) 
     
    563566            handle_ta = False 
    564567 
    565568        cursor = db.cursor() 
    566         self.env.log.info('Updating component "%s"' % self.name) 
     569        self.log.info('Updating component "%s"', self.name) 
    567570        cursor.execute("UPDATE component SET name=%s,owner=%s,description=%s " 
    568571                       "WHERE name=%s", 
    569572                       (self.name, self.owner, self.description, 
     
    596599 
    597600    def __init__(self, env, name=None, db=None): 
    598601        self.env = env 
     602        self.log = self.env.get_logger(__name__) 
    599603        if name: 
    600604            self._fetch(name, db) 
    601605            self._old_name = name 
     
    641645            handle_ta = False 
    642646 
    643647        cursor = db.cursor() 
    644         self.env.log.info('Deleting milestone %s' % self.name) 
     648        self.log.info('Deleting milestone %s', self.name) 
    645649        cursor.execute("DELETE FROM milestone WHERE name=%s", (self.name,)) 
    646650 
    647651        # Retarget/reset tickets associated with this milestone 
     
    667671 
    668672        self.name = simplify_whitespace(self.name) 
    669673        cursor = db.cursor() 
    670         self.env.log.debug("Creating new milestone '%s'" % self.name) 
     674        self.log.debug("Creating new milestone '%s'", self.name) 
    671675        cursor.execute("INSERT INTO milestone (name,due,completed,description) " 
    672676                       "VALUES (%s,%s,%s,%s)", 
    673677                       (self.name, to_timestamp(self.due), to_timestamp(self.completed), 
     
    686690 
    687691        self.name = simplify_whitespace(self.name) 
    688692        cursor = db.cursor() 
    689         self.env.log.info('Updating milestone "%s"' % self.name) 
     693        self.log.info('Updating milestone "%s"', self.name) 
    690694        cursor.execute("UPDATE milestone SET name=%s,due=%s," 
    691695                       "completed=%s,description=%s WHERE name=%s", 
    692696                       (self.name, to_timestamp(self.due), to_timestamp(self.completed), 
    693697                        self.description, 
    694698                        self._old_name)) 
    695         self.env.log.info('Updating milestone field of all tickets ' 
    696                           'associated with milestone "%s"' % self.name) 
     699        self.log.info('Updating milestone field of all tickets associated ' 
     700                      'with milestone "%s"', self.name) 
    697701        cursor.execute("UPDATE ticket SET milestone=%s WHERE milestone=%s", 
    698702                       (self.name, self._old_name)) 
    699703        self._old_name = self.name 
     
    726730 
    727731    def __init__(self, env, name=None, db=None): 
    728732        self.env = env 
     733        self.log = self.env.get_logger(__name__) 
    729734        if name: 
    730735            if not db: 
    731736                db = self.env.get_db_cnx() 
     
    755760            handle_ta = False 
    756761 
    757762        cursor = db.cursor() 
    758         self.env.log.info('Deleting version %s' % self.name) 
     763        self.log.info('Deleting version %s', self.name) 
    759764        cursor.execute("DELETE FROM version WHERE name=%s", (self.name,)) 
    760765 
    761766        self.name = self._old_name = None 
     
    774779            handle_ta = False 
    775780 
    776781        cursor = db.cursor() 
    777         self.env.log.debug("Creating new version '%s'" % self.name) 
     782        self.log.debug("Creating new version '%s'", self.name) 
    778783        cursor.execute("INSERT INTO version (name,time,description) " 
    779784                       "VALUES (%s,%s,%s)", 
    780785                       (self.name, to_timestamp(self.time), self.description)) 
     
    793798            handle_ta = False 
    794799 
    795800        cursor = db.cursor() 
    796         self.env.log.info('Updating version "%s"' % self.name) 
     801        self.log.info('Updating version "%s"', self.name) 
    797802        cursor.execute("UPDATE version SET name=%s,time=%s,description=%s " 
    798803                       "WHERE name=%s", 
    799804                       (self.name, to_timestamp(self.time), self.description, 
  • trac/ticket/roadmap.py

     
    648648                cursor.execute("UPDATE ticket SET milestone=%s WHERE " 
    649649                               "milestone=%s and status != 'closed'", 
    650650                                (retarget_to, old_name)) 
    651                 self.env.log.info('Tickets associated with milestone %s ' 
    652                                   'retargeted to %s' % (old_name, retarget_to)) 
     651                self.log.info('Tickets associated with milestone %s ' 
     652                              'retargeted to %s' % (old_name, retarget_to)) 
    653653        else: 
    654654            milestone.insert() 
    655655        db.commit() 
  • trac/ticket/query.py

     
    5353                 order=None, desc=0, group=None, groupdesc=0, verbose=0, 
    5454                 rows=None, page=None, max=None): 
    5555        self.env = env 
     56        self.log = self.env.get_logger(__name__) 
    5657        self.id = report # if not None, it's the corresponding saved query 
    5758        self.constraints = constraints or {} 
    5859        self.order = order 
     
    235236        cursor = db.cursor() 
    236237 
    237238        count_sql = 'SELECT COUNT(*) FROM (' + sql + ') AS foo' 
    238         # self.env.log.debug("Count results in Query SQL: " + count_sql %  
    239         #                    tuple([repr(a) for a in args])) 
     239        # self.log.debug("Count results in Query SQL: " + count_sql %  
     240        #                tuple([repr(a) for a in args])) 
    240241 
    241242        cnt = 0 
    242243        cursor.execute(count_sql, args); 
    243244        for cnt, in cursor: 
    244245            break 
    245         self.env.log.debug("Count results in Query: %d" % cnt) 
     246        self.log.debug("Count results in Query: %d", cnt) 
    246247        return cnt 
    247248 
    248249    def execute(self, req, db=None, cached_ids=None): 
     
    266267                raise TracError(_('Page %(page)s is beyond the number of ' 
    267268                                  'pages in the query', page=self.page)) 
    268269 
    269         self.env.log.debug("Query SQL: " + sql % tuple([repr(a) for a in args]))      
     270        self.log.debug("Query SQL: " + sql % tuple([repr(a) for a in args]))      
    270271        cursor.execute(sql, args) 
    271272        columns = get_column_names(cursor) 
    272273        fields = [] 
  • trac/htdocs/css/admin.css

     
    2121 
    2222#tabcontent { padding: 0.4em 2em; margin-left: 12em; min-height: 300px; } 
    2323#tabcontent h2 { color: #333; margin-top: 0; } 
    24 p.help { color: #666; font-size: 90%; margin: 1em .5em .5em; } 
     24div.help, p.help { color: #666; font-size: 90%; margin: 1em .5em .5em; } 
    2525 
    2626#enumlist tbody td { vertical-align: middle; } 
    2727 
  • trac/db/mysql_backend.py

     
    8787        from trac.db_default import schema 
    8888        for table in schema: 
    8989            for stmt in self.to_sql(table): 
    90                 self.env.log.debug(stmt) 
     90                self.log.debug(stmt) 
    9191                cursor.execute(stmt) 
    9292        cnx.commit() 
    9393 
  • trac/versioncontrol/tests/svn_fs.py

     
    3030except: 
    3131    has_svn = False 
    3232 
    33 from trac.log import logger_factory 
     33from trac.log import setup_logging 
    3434from trac.test import TestSetup 
    3535from trac.core import TracError 
    3636from trac.util.datefmt import utc 
     
    8585 
    8686    def setUp(self): 
    8787        self.repos = SubversionRepository(REPOS_PATH, None, 
    88                                           logger_factory('test')) 
     88                                          setup_logging('test')) 
    8989 
    9090    def tearDown(self): 
    9191        self.repos = None 
     
    460460 
    461461    def setUp(self): 
    462462        self.repos = SubversionRepository(REPOS_PATH + '/trunk', None, 
    463                                           logger_factory('test')) 
     463                                          setup_logging('test')) 
    464464 
    465465    def tearDown(self): 
    466466        self.repos = None 
     
    688688 
    689689    def setUp(self): 
    690690        self.repos = SubversionRepository(REPOS_PATH + '/trunk/dir1', None, 
    691                                           logger_factory('test')) 
     691                                          setup_logging('test')) 
    692692 
    693693    def tearDown(self): 
    694694        self.repos = None 
     
    708708 
    709709    def setUp(self): 
    710710        self.repos = SubversionRepository(REPOS_PATH + '/tags/v1', None, 
    711                                           logger_factory('test')) 
     711                                          setup_logging('test')) 
    712712 
    713713    def tearDown(self): 
    714714        self.repos = None 
     
    726726 
    727727    def setUp(self): 
    728728        self.repos = SubversionRepository(REPOS_PATH + '/branches', None, 
    729                                           logger_factory('test')) 
     729                                          setup_logging('test')) 
    730730 
    731731    def tearDown(self): 
    732732        self.repos = None 
  • trac/versioncontrol/tests/cache.py

     
    1616 
    1717from datetime import datetime 
    1818 
    19 from trac.log import logger_factory 
     19from trac.log import setup_logging 
    2020from trac.test import Mock, InMemoryDatabase 
    2121from trac.util.datefmt import to_timestamp, utc 
    2222from trac.versioncontrol import Repository, Changeset, Node, NoSuchChangeset 
     
    3030 
    3131    def setUp(self): 
    3232        self.db = InMemoryDatabase() 
    33         self.log = logger_factory('test') 
     33        self.log = setup_logging('test') 
    3434        cursor = self.db.cursor() 
    3535        cursor.execute("INSERT INTO system (name, value) VALUES (%s,%s)", 
    3636                       ('youngest_rev', '')) 
  • trac/admin/web_ui.py

     
    22# 
    33# Copyright (C) 2005-2008 Edgewall Software 
    44# Copyright (C) 2005 Jonas Borgström <jonas@edgewall.com> 
     5# Copyright (C) 2008 Pedro Algarvio <ufs@ufsoft.org> 
    56# All rights reserved. 
    67# 
    78# This software is licensed as described in the file COPYING, which 
     
    215216        log_level = self.env.log_level 
    216217        log_file = self.env.log_file 
    217218        log_dir = os.path.join(self.env.path, 'log') 
     219        log_filters = self.config.getlist('logging', 'log_filters') 
     220        for idx, filter in enumerate(log_filters): 
     221            filter = filter.split(':') 
     222            if not (len(filter) > 1 and filter[1]): 
     223                log_filters[idx] = "%s:%s" % (filter[0], log_level) 
    218224 
    219225        log_types = [ 
    220226            dict(name='', label=_('None'), selected=False, disabled=False), 
     
    233239 
    234240        if req.method == 'POST': 
    235241            changed = False 
    236  
    237             new_type = req.args.get('log_type') 
    238             if new_type and new_type not in ('stderr', 'file', 'syslog', 
    239                                              'eventlog'): 
    240                 raise TracError( 
    241                     _('Unknown log type %(type)s', type=new_type), 
    242                     _('Invalid log type') 
    243                 ) 
    244             if new_type != log_type: 
    245                 self.config.set('logging', 'log_type', new_type or 'none') 
     242            if 'add_filter' in req.args: 
     243                filter_module_name = req.args.get('filter_modname') 
     244                if not filter_module_name: 
     245                    raise TracError(_("Filter module name must not be empty")) 
     246                filter_log_level = req.args.get('filter_loglevel') 
     247                if filter_log_level and filter_log_level not in log_levels: 
     248                    raise TracError(_('Unknown log level %(level)s', 
     249                                      level=filter_log_level), 
     250                                    _('Invalid log level')) 
     251                for filter in log_filters: 
     252                    if filter.split(':')[0] == filter_module_name or \ 
     253                        filter.split(':')[0].rstrip('.*') == filter_module_name: 
     254                        raise TracError( 
     255                            _("A filter for module '%(module)s' already exists." 
     256                              " Remove that one first.", 
     257                              module=filter_module_name), 
     258                            _("Filter already exists")) 
     259                new_log_filter = "%s:%s" % (filter_module_name.rstrip('.*'), 
     260                                            filter_log_level) 
     261                log_filters.append(new_log_filter) 
     262                self.log.debug("Adding new filter '%s' to log_filters", 
     263                               new_log_filter) 
     264                self.config.set('logging', 'log_filters',', '.join(log_filters)) 
    246265                changed = True 
    247                 log_type = new_type 
    248  
    249             if log_type: 
    250                 new_level = req.args.get('log_level') 
    251                 if new_level and new_level not in log_levels: 
     266            elif 'delete_filters' in req.args: 
     267                selected = req.args.getlist('sel') 
     268                for filter in selected: 
     269                    self.log.debug("Removing filter '%s' from log_filters", 
     270                                   filter) 
     271                    log_filters.pop(log_filters.index(filter)) 
     272                self.config.set('logging', 'log_filters',', '.join(log_filters)) 
     273                changed = True 
     274            else: 
     275                new_type = req.args.get('log_type') 
     276                if new_type and new_type not in ('stderr', 'file', 'syslog', 
     277                                                 'eventlog'): 
    252278                    raise TracError( 
    253                         _('Unknown log level %(level)s', level=new_level), 
    254                         _('Invalid log level')) 
    255                 if new_level and new_level != log_level: 
    256                     self.config.set('logging', 'log_level', new_level) 
     279                        _('Unknown log type %(type)s', type=new_type), 
     280                        _('Invalid log type') 
     281                    ) 
     282                if new_type != log_type: 
     283                    self.config.set('logging', 'log_type', new_type or 'none') 
    257284                    changed = True 
    258                     log_evel = new_level 
    259             else: 
    260                 self.config.remove('logging', 'log_level') 
    261                 changed = True 
     285                    log_type = new_type 
    262286 
    263             if log_type == 'file': 
    264                 new_file = req.args.get('log_file', 'trac.log') 
    265                 if new_file != log_file: 
    266                     self.config.set('logging', 'log_file', new_file or '') 
     287                if log_type: 
     288                    new_level = req.args.get('log_level') 
     289                    if new_level and new_level not in log_levels: 
     290                        raise TracError( 
     291                            _('Unknown log level %(level)s', level=new_level), 
     292                            _('Invalid log level')) 
     293                    if new_level and new_level != log_level: 
     294                        self.config.set('logging', 'log_level', new_level) 
     295                        changed = True 
     296                        log_evel = new_level 
     297                else: 
     298                    self.config.remove('logging', 'log_level') 
    267299                    changed = True 
    268                     log_file = new_file 
    269                 if log_type == 'file' and not log_file: 
    270                     raise TracError(_('You must specify a log file'), 
    271                                     _('Missing field')) 
    272             else: 
    273                 self.config.remove('logging', 'log_file') 
    274                 changed = True 
    275300 
     301                if log_type == 'file': 
     302                    new_file = req.args.get('log_file', 'trac.log') 
     303                    if new_file != log_file: 
     304                        self.config.set('logging', 'log_file', new_file or '') 
     305                        changed = True 
     306                        log_file = new_file 
     307                    if log_type == 'file' and not log_file: 
     308                        raise TracError(_('You must specify a log file'), 
     309                                        _('Missing field')) 
     310                else: 
     311                    self.config.remove('logging', 'log_file') 
     312                    changed = True 
    276313            if changed: 
    277314                self.config.save() 
    278315            req.redirect(req.href.admin(cat, page)) 
     
    280317        data = { 
    281318            'type': log_type, 'types': log_types, 
    282319            'level': log_level, 'levels': log_levels, 
    283             'file': log_file, 'dir': log_dir 
     320            'file': log_file, 'dir': log_dir, 
     321            'filters': log_filters 
    284322        } 
    285323        return 'admin_logging.html', {'log': data} 
    286324 
  • trac/admin/tests/console.py

     
    7171        return True 
    7272 
    7373    def setup_log(self): 
    74         from trac.log import logger_factory 
    75         self.log = logger_factory('null') 
     74        from trac.log import setup_logging 
     75        self.log = setup_logging('null') 
    7676 
    7777    def is_component_enabled(self, cls): 
    7878        return cls.__module__.startswith('trac.') and \ 
  • trac/admin/templates/admin_logging.html

     
    5454        </div> 
    5555      </fieldset> 
    5656    </form> 
     57 
     58    <fieldset> 
     59      <legend>Logging Filters</legend> 
     60 
     61      <form class="addnew" id="newlog_filters" name="newlog_filters" method="post"> 
     62        <fieldset> 
     63          <legend>Add New Logging Filter</legend> 
     64          <table> 
     65            <tr class="field"> 
     66              <th><label for="filter_modname">Module:</label></th> 
     67              <td><input type="text" id="filter_modname" name="filter_modname"/></td> 
     68            </tr> 
     69            <tr class="field"> 
     70              <th><label for="filter_loglevel">Log level:</label></th> 
     71              <td> 
     72                <select id="filter_loglevel" name="filter_loglevel"> 
     73                  <option py:for="level in log.levels">$level</option> 
     74                </select> 
     75              </td> 
     76            </tr> 
     77          </table> 
     78        <div class="buttons"> 
     79          <input type="submit" name="add_filter" value="${_('Add Filter')}"/> 
     80        </div> 
     81        </fieldset> 
     82      </form> 
     83 
     84      <p class="help">If nothing set, logging will be as it was, nothing is 
     85      changed.</p> 
     86 
     87      <form class="mod" id="log_filters" name="log_filters" method="post"> 
     88        <div class="field"> 
     89          <table class="listing" id="filters_table"> 
     90            <thead> 
     91              <tr> 
     92                <th class="sel">&nbsp;</th> 
     93                <th>Module</th> 
     94                <th>Log level</th> 
     95              </tr> 
     96            </thead> 
     97            <tbody py:if="log.filters"> 
     98              <tr py:for="mod, level in [f.split(':') for f in log.filters]"> 
     99                <td class="sel"><input type="checkbox" name="sel" value="$mod:$level"/></td> 
     100                <td>$mod</td> 
     101                <td>$level</td> 
     102              </tr> 
     103            </tbody> 
     104            <tbody py:if="not log.filters"> 
     105              <tr><td colspan="3"> 
     106                <center><b>No Filters Available</b></center> 
     107              </td></tr> 
     108            </tbody> 
     109          </table> 
     110        </div> 
     111        <div class="buttons" py:if="log.filters"> 
     112          <input type="submit" name="delete_filters" value="${_('Delete Selected Filters')}"/> 
     113        </div> 
     114 
     115        <div class="help"> 
     116          <p>Example usage is:</p> 
     117<pre> 
     118  [logging] 
     119  log_filters = trac:WARNING, trac.ticket:DEBUG 
     120</pre>   
     121          <p>The above would translate to:</p>   
     122          <ul> 
     123            <li>all messages who's module name starts with <b><tt>trac</tt></b> 
     124            and log level is higher than <b><tt>WARNING</tt></b> are logged;</li> 
     125             
     126            <li>all messages who's module name starts with <b><tt>trac.ticket</tt></b> 
     127            and log level is higher than <b><tt>DEBUG</tt></b> are logged;</li> 
     128   
     129            <li>all other messages who's module name <b>does not</b> start with either 
     130            <b><tt>trac</tt></b> or <b><tt>trac.ticket</tt></b> will be logged if 
     131            their level is higher than the default <b><tt>log_level</tt></b>;</li> 
     132          </ul> 
     133   
     134          <p>This way you can narrow the debugging messages to the modules you wish to.</p> 
     135          <p>The same applies to a plugin you're coding:</p> 
     136<pre> 
     137  [logging] 
     138  log_filters = trac:ERROR, my.plug.module:DEBUG 
     139</pre> 
     140        </div> 
     141      </form> 
     142    </fieldset> 
    57143  </body> 
    58144 
    59145</html> 
  • trac/perm.py

     
    224224        cursor = db.cursor() 
    225225        cursor.execute("INSERT INTO permission VALUES (%s, %s)", 
    226226                       (username, action)) 
    227         self.log.info('Granted permission for %s to %s' % (action, username)) 
     227        self.log.info('Granted permission for %s to %s', action, username) 
    228228        db.commit() 
    229229 
    230230    def revoke_permission(self, username, action): 
     
    233233        cursor = db.cursor() 
    234234        cursor.execute("DELETE FROM permission WHERE username=%s AND action=%s", 
    235235                       (username, action)) 
    236         self.log.info('Revoked permission for %s to %s' % (action, username)) 
     236        self.log.info('Revoked permission for %s to %s', action, username) 
    237237        db.commit() 
    238238 
    239239 
     
    424424                                               perm) 
    425425            if decision is not None: 
    426426                if not decision: 
    427                     self.log.debug("%s denies %s performing %s on %r" % 
    428                                    (policy.__class__.__name__, username, 
    429                                     action, resource)) 
     427                    self.log.debug("%s denies %s performing %s on %r", 
     428                                   policy.__class__.__name__, username, 
     429                                   action, resource) 
    430430                return decision 
    431         self.log.debug("No policy allowed %s performing %s on %r" % 
    432                        (username, action, resource)) 
     431        self.log.debug("No policy allowed %s performing %s on %r", 
     432                       username, action, resource) 
    433433        return False 
    434434 
    435435    # IPermissionRequestor methods 
     
    548548 
    549549    def permissions(self): 
    550550        """Deprecated (but still used by the HDF compatibility layer)""" 
    551         self.env.log.warning('perm.permissions() is deprecated and ' 
    552                              'is only present for HDF compatibility') 
     551        self.log.warning('perm.permissions() is deprecated and ' 
     552                         'is only present for HDF compatibility') 
    553553        perm = PermissionSystem(self.env) 
    554554        actions = perm.get_user_permissions(self.username) 
    555555        return [action for action in actions if action in self] 
  • trac/loader.py

     
    3939        distributions, errors = working_set.find_plugins( 
    4040            pkg_resources.Environment(search_path) 
    4141        ) 
     42        log = env.get_logger(__name__) 
    4243        for dist in distributions: 
    43             env.log.debug('Adding plugin %s from %s', dist, dist.location) 
     44            log.debug('Adding plugin %s from %s', dist, dist.location) 
    4445            working_set.add(dist) 
    4546 
    4647        def _log_error(item, e): 
    4748            if isinstance(e, DistributionNotFound): 
    48                 env.log.debug('Skipping "%s": ("%s" not found)', item, e) 
     49                log.debug('Skipping "%s": ("%s" not found)', item, e) 
    4950            elif isinstance(e, VersionConflict): 
    50                 env.log.error('Skipping "%s": (version conflict "%s")', 
    51                               item, e) 
     51                log.error('Skipping "%s": (version conflict "%s")', 
     52                          item, e) 
    5253            elif isinstance(e, UnknownExtra): 
    53                 env.log.error('Skipping "%s": (unknown extra "%s")', item, e) 
     54                log.error('Skipping "%s": (unknown extra "%s")', item, e) 
    5455            elif isinstance(e, ImportError): 
    55                 env.log.error('Skipping "%s": (can\'t import "%s")', item, e) 
     56                log.error('Skipping "%s": (can\'t import "%s")', item, e) 
    5657            else: 
    57                 env.log.error('Skipping "%s": (error "%s")', item, e) 
     58                log.error('Skipping "%s": (error "%s")', item, e) 
    5859 
    5960        for dist, e in errors.iteritems(): 
    6061            _log_error(dist, e) 
    6162 
    6263        for entry in working_set.iter_entry_points(entry_point_name): 
    63             env.log.debug('Loading %s from %s', entry.name, 
    64                           entry.dist.location) 
     64            log.debug('Loading %s from %s', entry.name, 
     65                      entry.dist.location) 
    6566            try: 
    6667                entry.load(require=True) 
    6768            except (ImportError, DistributionNotFound, VersionConflict, 
     
    7879    manager if they define any components. 
    7980    """ 
    8081    def _load_py_files(env, search_path, auto_enable=None): 
     82        log = env.get_logger(__name__) 
    8183        for path in search_path: 
    8284            plugin_files = glob(os.path.join(path, '*.py')) 
    8385            for plugin_file in plugin_files: 
    8486                try: 
    8587                    plugin_name = os.path.basename(plugin_file[:-3]) 
    86                     env.log.debug('Loading file plugin %s from %s' % \ 
    87                                   (plugin_name, plugin_file)) 
     88                    log.debug('Loading file plugin %s from %s', 
     89                              plugin_name, plugin_file) 
    8890                    if plugin_name not in sys.modules: 
    8991                        module = imp.load_source(plugin_name, plugin_file) 
    9092                    if path == auto_enable: 
    9193                        _enable_plugin(env, plugin_name) 
    9294                except Exception, e: 
    93                     env.log.error('Failed to load plugin from %s', plugin_file, 
    94                                   exc_info=True) 
     95                    log.error('Failed to load plugin from %s', plugin_file, 
     96                              exc_info=True) 
    9597 
    9698    return _load_py_files 
    9799 
  • trac/tests/attachment.py

     
    77import time 
    88 
    99from trac.attachment import Attachment, AttachmentModule 
    10 from trac.log import logger_factory 
     10from trac.log import setup_logging 
    1111from trac.test import EnvironmentStub, Mock 
    1212from trac.wiki.formatter import Formatter 
    1313 
  • trac/wiki/web_ui.py

     
    8080        return 'wiki' 
    8181 
    8282    def get_navigation_items(self, req): 
     83        self.env.log.debug('\n\nFOOOO BAAAARRRR\n\n') 
    8384        if 'WIKI_VIEW' in req.perm('wiki'): 
    8485            yield ('mainnav', 'wiki', 
    8586                   tag.a(_('Wiki'), href=req.href.wiki(), accesskey=1)) 
  • trac/wiki/model.py

     
    4747            self.readonly = 0 
    4848        self.old_text = self.text 
    4949        self.old_readonly = self.readonly 
     50        self.log = self.env.get_logger(__name__) 
    5051 
    5152    def _fetch(self, name, version=None, db=None): 
    5253        if not db: 
     
    9192        if version is None: 
    9293            # Delete a wiki page completely 
    9394            cursor.execute("DELETE FROM wiki WHERE name=%s", (self.name,)) 
    94             self.env.log.info('Deleted page %s' % self.name) 
     95            self.log.info('Deleted page %s' % self.name) 
    9596        else: 
    9697            # Delete only a specific page version 
    9798            cursor.execute("DELETE FROM wiki WHERE name=%s and version=%s", 
    9899                           (self.name, version)) 
    99             self.env.log.info('Deleted version %d of page %s' 
     100            self.log.info('Deleted version %d of page %s' 
    100101                              % (version, self.name)) 
    101102 
    102103        if version is None or version == self.version: 
  • trac/wiki/formatter.py

     
    7474        """ 
    7575        self.formatter = formatter 
    7676        self.env = formatter.env 
     77        self.log = self.env.get_logger(__name__) 
    7778        self.name = name 
    7879        self.args = args 
    7980        self.error = None 
     
    127128            stream = Stream(HTMLParser(StringIO(text))) 
    128129            return (stream | self._sanitizer).render('xhtml', encoding=None) 
    129130        except ParseError, e: 
    130             self.env.log.warn(e) 
     131            self.log.warn(e) 
    131132            line = unicode(text).splitlines()[e.lineno - 1].strip() 
    132133            return system_message(_('HTML parsing error: %(message)s', 
    133134                                    message=escape(e.msg)), line) 
     
    154155    # generic processors 
    155156 
    156157    def _legacy_macro_processor(self, text): # TODO: remove in 0.12 
    157         self.env.log.warning('Executing pre-0.11 Wiki macro %s by provider %s' 
    158                              % (self.name, self.macro_provider)) 
     158        self.log.warning('Executing pre-0.11 Wiki macro %s by provider %s', 
     159                         self.name, self.macro_provider) 
    159160        return self.macro_provider.render_macro(self.formatter.req, self.name, 
    160161                                                text) 
    161162 
    162163    def _macro_processor(self, text): 
    163         self.env.log.debug('Executing Wiki macro %s by provider %s' 
    164                            % (self.name, self.macro_provider)) 
     164        self.log.debug('Executing Wiki macro %s by provider %s', 
     165                       self.name, self.macro_provider) 
    165166        return self.macro_provider.expand_macro(self.formatter, self.name, 
    166167                                                text) 
    167168 
     
    225226    def __init__(self, env, context): 
    226227        """Note: `req` is still temporarily used.""" 
    227228        self.env = env 
     229        self.log = self.env.get_logger(__name__) 
    228230        self.context = context 
    229231        self.req = context.req 
    230232        self.href = context.href 
     
    467469            macro = WikiProcessor(self, name) 
    468470            return macro.process(args, in_paragraph=True) 
    469471        except Exception, e: 
    470             self.env.log.error('Macro %s(%s) failed' % (name, args), 
    471                                exc_info=True) 
     472            self.log.error('Macro %s(%s) failed', name, args, exc_info=True) 
    472473            return system_message('Error: Macro %s(%s) failed' % (name, args), 
    473474                                  e) 
    474475 
  • trac/test.py

     
    186186        # better solution than this. 
    187187        load_workflow_config_snippet(self.config, 'basic-workflow.ini') 
    188188 
    189         from trac.log import logger_factory 
    190         self.log = logger_factory('test') 
     189        from trac.log import setup_logging 
     190        self.log = setup_logging(logid='test') 
    191191 
    192192        from trac.web.href import Href 
    193193        self.href = Href('/trac.cgi') 
  • trac/log.py

     
    33# Copyright (C) 2003-2008 Edgewall Software 
    44# Copyright (C) 2003-2005 Daniel Lundin <daniel@edgewall.com> 
    55# Copyright (C) 2006 Christian Boos <cboos@neuf.fr> 
     6# Copyright (C) 2008 Pedro Algarvio <ufs@ufsoft.org> 
    67# All rights reserved. 
    78# 
    89# This software is licensed as described in the file COPYING, which 
     
    1920import logging.handlers 
    2021import sys 
    2122 
    22 def logger_factory(logtype='syslog', logfile=None, level='WARNING', 
    23                    logid='Trac', format=None): 
    24     logger = logging.getLogger(logid) 
     23from trac.util.compat import sorted 
     24from trac.util.translation import _ 
     25 
     26 
     27def setup_logging(logtype='syslog', logfile=None, level='WARNING', logid='Trac', 
     28                  format=None, filters=()): 
     29    env_root_logger = logging.getLogger(logid) 
     30         
    2531    logtype = logtype.lower() 
    2632    if logtype == 'file': 
    2733        hdlr = logging.FileHandler(logfile) 
    2834    elif logtype in ('winlog', 'eventlog', 'nteventlog'): 
    2935        # Requires win32 extensions 
    30         hdlr = logging.handlers.NTEventLogHandler(logid, 
    31                                                   logtype='Application') 
     36        hdlr = logging.handlers.NTEventLogHandler(logid, logtype='Application') 
    3237    elif logtype in ('syslog', 'unix'): 
    3338        hdlr = logging.handlers.SysLogHandler('/dev/log') 
    3439    elif logtype in ('stderr'): 
     
    4752        datefmt = '%X' 
    4853    level = level.upper() 
    4954    if level in ('DEBUG', 'ALL'): 
    50         logger.setLevel(logging.DEBUG) 
     55        env_root_logger.setLevel(logging.DEBUG) 
    5156    elif level == 'INFO': 
    52         logger.setLevel(logging.INFO) 
     57        env_root_logger.setLevel(logging.INFO) 
    5358    elif level == 'ERROR': 
    54         logger.setLevel(logging.ERROR) 
     59        env_root_logger.setLevel(logging.ERROR) 
    5560    elif level == 'CRITICAL': 
    56         logger.setLevel(logging.CRITICAL) 
     61        env_root_logger.setLevel(logging.CRITICAL) 
    5762    else: 
    58         logger.setLevel(logging.WARNING) 
    59     formatter = logging.Formatter(format, datefmt) 
    60     hdlr.setFormatter(formatter) 
    61     logger.addHandler(hdlr) 
     63        env_root_logger.setLevel(logging.WARNING) 
    6264 
     65    hdlr.setFormatter(TracFormatter(logid, format, datefmt)) 
     66    # Assign handler right away to be able to log filter errors 
     67    env_root_logger.addHandler(hdlr)     
     68     
     69    if filters: 
     70        hdlr.addFilter(TracFilter(filters, level, logid)) 
     71         
    6372    # Remember our handler so that we can remove it later 
    64     logger._trac_handler = hdlr  
     73    env_root_logger._trac_handler = hdlr 
     74     
     75    # Return env logger for tests that expect it 
     76    # For components, they will have self.log 
     77    # For classes/functions which get passed an env use env.get_logger(__name__) 
     78    return env_root_logger 
     79 
     80 
     81class TracFilter(logging.Filter): 
     82    def __init__(self, trac_filters=(), default_level='DEBUG', name=''): 
     83        self.qns = [] 
     84        for filter in trac_filters: 
     85            filter = filter.split(':') 
     86            if len(filter) > 1 and filter[1]: 
     87                qn, lvl = filter[0].rstrip('.*'), filter[1] 
     88            else: 
     89                qn, lvl = filter[0].rstrip('.*'), default_level 
     90            path_and_qn = "%s.%s" % (name, qn) 
     91             
     92            if lvl == 'ALL': 
     93                lvl = 'DEBUG' 
     94                 
     95            if lvl not in logging._levelNames: 
     96                logging.getLogger("%s.%s" % (name, __name__)).warning( 
     97                    _("Level '%(level)s' for filter '%(filter)s' not know. " 
     98                      "Ignoring filter.", 
     99                      level=lvl.upper(), filter=':'.join(filter))) 
     100                continue 
     101                             
     102            self.qns.append((path_and_qn, logging.getLevelName(lvl.upper()))) 
     103             
     104        self.qns = sorted(self.qns, key=lambda x: len(x[0]), reverse=True) 
     105         
     106        logging.Filter.__init__(self, name) 
     107 
     108    def filter(self, record): 
     109        for qn, level in self.qns: 
     110            if record.name.startswith("%s." % qn) or record.name == qn: 
     111                # Match trac, trac.web but not tracforge 
     112                if level <= record.levelno: 
     113                    return 1 
     114                return 0 
     115        # No point returning `logging.Filter.filter(self, record)` 
     116        # All logging messages will arrive to the filter with self.name at 
     117        # least equal to environment path, ie, self.name 
     118        return 1 
     119 
     120 
     121class TracFormatter(logging.Formatter): 
     122 
     123    def __init__(self, env_path, fmt, datefmt): 
     124        self.env_path = env_path 
     125        # Calculate strip length at init time, no need to keep calculating it 
     126        self.strip_length = len(env_path)+1 
     127        logging.Formatter.__init__(self, fmt, datefmt) 
     128 
     129    def format(self, record): 
     130        # get full dotted module name and stick that under record.module 
     131        if record.name.startswith(self.env_path): 
     132            record.module = record.name[self.strip_length:] 
     133        return logging.Formatter.format(self, record) 
    65134 
    66     return logger 
     135def get_logger(env_path, name): 
     136    """Helper function to get the correct logger for the passed class or 
     137    env and name.""" 
     138    return logging.getLogger("%s.%s" % (env_path, name)) 
  • trac/web/tests/session.py

     
    33import unittest 
    44 
    55from trac.core import TracError 
    6 from trac.log import logger_factory 
     6from trac.log import setup_logging 
    77from trac.test import EnvironmentStub, Mock 
    88from trac.web.href import Href 
    99from trac.web.session import DetachedSession, Session, PURGE_AGE, UPDATE_INTERVAL 
  • trac/web/session.py

     
    3333    def __init__(self, env, sid): 
    3434        dict.__init__(self) 
    3535        self.env = env 
     36        self.log = self.env.get_logger(__name__) 
    3637        self.sid = None 
    3738        self.last_visit = 0 
    3839        self._new = True 
     
    4344            self.authenticated = False 
    4445 
    4546    def get_session(self, sid, authenticated=False): 
    46         self.env.log.debug('Retrieving session for ID %r', sid) 
     47        self.log.debug('Retrieving session for ID %r', sid) 
    4748 
    4849        db = self.env.get_db_cnx() 
    4950        cursor = db.cursor() 
     
    111112        # so that session doesn't get purged 
    112113        if now - self.last_visit > UPDATE_INTERVAL: 
    113114            self.last_visit = now 
    114             self.env.log.info("Refreshing session %s" % self.sid) 
     115            self.log.info("Refreshing session %s", self.sid) 
    115116            cursor.execute('UPDATE session SET last_visit=%s ' 
    116117                           'WHERE sid=%s AND authenticated=%s', 
    117118                           (self.last_visit, self.sid, authenticated)) 
    118119            # Purge expired sessions. We do this only when the session was 
    119120            # changed as to minimize the purging. 
    120121            mintime = now - PURGE_AGE 
    121             self.env.log.debug('Purging old, expired, sessions.') 
     122            self.log.debug('Purging old, expired, sessions.') 
    122123            cursor.execute("DELETE FROM session_attribute " 
    123124                           "WHERE authenticated=0 AND sid " 
    124125                           "IN (SELECT sid FROM session WHERE " 
     
    182183            raise TracError(Markup('Session "%s" already exists.<br />' 
    183184                                   'Please choose a different session ID.') 
    184185                            % new_sid, 'Error renaming session') 
    185         self.env.log.debug('Changing session ID %s to %s' % (self.sid, new_sid)) 
     186        self.log.debug('Changing session ID %s to %s', self.sid, new_sid) 
    186187        cursor.execute("UPDATE session SET sid=%s WHERE sid=%s " 
    187188                       "AND authenticated=0", (new_sid, self.sid)) 
    188189        cursor.execute("UPDATE session_attribute SET sid=%s " 
     
    216217            if not authenticated_flags[0]: 
    217218                # Update the anomymous session records so that the session ID 
    218219                # becomes the user name, and set the authenticated flag. 
    219                 self.env.log.debug('Promoting anonymous session %s to ' 
    220                                    'authenticated session for user %s', 
    221                                    sid, self.req.authname) 
     220                self.log.debug('Promoting anonymous session %s to ' 
     221                               'authenticated session for user %s', 
     222                               sid, self.req.authname) 
    222223                cursor.execute("UPDATE session SET sid=%s,authenticated=1 " 
    223224                               "WHERE sid=%s AND authenticated=0", 
    224225                               (self.req.authname, sid)) 
  • trac/web/main.py

     
    412412                                       environ['trac.web.version'])) 
    413413    except TracError, e: 
    414414        env_error = e 
    415  
     415     
     416    log = env.get_logger(__name__) 
    416417    req = Request(environ, start_response) 
    417418    try: 
    418419        return _dispatch_request(req, env, env_error) 
     
    426427            #       objects with a __del__ method caught in a cycle) 
    427428            ##gc.set_debug(gc.DEBUG_UNCOLLECTABLE) 
    428429            unreachable = gc.collect() 
    429             env.log.debug("%d unreachable objects found.", unreachable) 
     430            log.debug("%d unreachable objects found.", unreachable) 
    430431            ##uncollectable = len(gc.garbage) 
    431432            ##if uncollectable: 
    432433            ##    del gc.garbage[:] 
    433             ##    env.log.warn("%d uncollectable objects found.", uncollectable) 
     434            ##    log.warn("%d uncollectable objects found.", uncollectable) 
    434435 
    435436def _dispatch_request(req, env, env_error): 
    436437    resp = [] 
    437438 
     439    log = env.get_logger(__name__) 
    438440    # fixup env.abs_href if `[trac] base_url` was not specified 
    439441    if env and not env.abs_href.base: 
    440442        env._abs_href = req.abs_href 
     
    451453 
    452454    except HTTPException, e: 
    453455        if env: 
    454             env.log.warn(e) 
     456            log.warn(e) 
    455457        title = 'Error' 
    456458        if e.reason: 
    457459            if 'error' in e.reason.lower(): 
     
    467469 
    468470    except Exception, e: 
    469471        if env: 
    470             env.log.exception(e) 
     472            log.exception(e) 
    471473 
    472474        exc_info = sys.exc_info() 
    473475        try: 
  • trac/notification.py

     
    114114 
    115115    def __init__(self, env): 
    116116        self.env = env 
     117        self.log = self.env.get_logger(__name__) 
    117118        self.config = env.config 
    118119        self.db = env.get_db_cnx() 
    119120 
     
    284285                if domain: 
    285286                    address = "%s@%s" % (address, domain) 
    286287                else: 
    287                     self.env.log.info("Email address w/o domain: %s" % address) 
     288                    self.log.info("Email address w/o domain: %s", address) 
    288289                    return None 
    289290 
    290291        mo = self.shortaddr_re.search(address) 
     
    293294        mo = self.longaddr_re.search(address) 
    294295        if mo: 
    295296            return mo.group(2) 
    296         self.env.log.info("Invalid email address: %s" % address) 
     297        self.log.info("Invalid email address: %s", address) 
    297298        return None 
    298299 
    299300    def encode_header(self, key, value): 
     
    371372         
    372373        # if there is not valid recipient, leave immediately 
    373374        if len(recipients) < 1: 
    374             self.env.log.info('no recipient for a ticket notification') 
     375            self.log.info('no recipient for a ticket notification') 
    375376            return 
    376377 
    377378        pcc = accaddrs 
     
    397398        msg.set_charset(self._charset) 
    398399        self.add_headers(msg, headers); 
    399400        self.add_headers(msg, mime_headers); 
    400         self.env.log.info("Sending SMTP notification to %s:%d to %s" 
    401                            % (self.smtp_server, self.smtp_port, recipients)) 
     401        self.log.info("Sending SMTP notification to %s:%d to %s", 
     402                      self.smtp_server, self.smtp_port, recipients) 
    402403        msgtext = msg.as_string() 
    403404        # Ensure the message complies with RFC2822: use CRLF line endings 
    404405        recrlf = re.compile("\r?\n")