Edgewall Software

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

File all-the-way_enhanced_logging.5.patch, 58.4 KB (added by palgarvio, 3 years ago)

Updated to [7715]

  • 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 
    … …  
    1516# Author: Jonas Borgström <jonas@edgewall.com> 
    1617 
    1718import os.path 
     19import logging 
    1820try: 
    1921    import threading 
    2022except ImportError: 
    … …  
    156158         - $(path)s     the path for the current environment 
    157159         - $(basename)s the last path component of the current environment 
    158160         - $(project)s  the project name 
    159  
    160          Note the usage of `$(...)s` instead of `%(...)s` as the latter form 
    161          would be interpreted by the ConfigParser itself. 
    162  
    163          Example: 
     161         
     162        Note the usage of `$(...)s` instead of `%(...)s` as the latter form 
     163        would be interpreted by the ConfigParser itself. 
     164         
     165        Example: 
    164166         ($(thread)d) Trac[$(basename)s:$(module)s] $(levelname)s: $(message)s 
    165  
    166          (since 0.10.5)""") 
     167         
     168        (since 0.10.5)""") 
     169    log_filters = ListOption('logging', 'log_filters', [], doc= 
     170        """Custom logging handlers. 
     171         
     172        If nothing set, logging will be as it was, nothing is changed. 
     173         
     174        Example usage is: 
     175        log_filters = trac:WARNING, trac.ticket:DEBUG 
     176         
     177        The above would translate to: 
     178            * all messages who's module name starts with `trac` and log level 
     179            is higher than `WARNING` are logged; 
     180            * all messages who's module name starts with `trac.ticket` and log 
     181            level is higher than `DEBUG` are logged; 
     182            * all other messages who's module name does not start with any of 
     183            the above and for which their level is higher than the default 
     184            `log_level` will be logged; 
     185         
     186        This way you can narrow the debugging messages to the modules you 
     187        wish to. The same applies to a plugin you're coding: 
     188        log_filters = trac:ERROR, my.plug.module:DEBUG 
     189         
     190        (since 0.12)""") 
    167191 
    168192    def __init__(self, path, create=False, options=[]): 
    169193        """Initialize the Trac environment. 
    … …  
    210234        environment configuration) and `log` (a logger object).""" 
    211235        component.env = self 
    212236        component.config = self.config 
    213         component.log = self.log 
     237        component.log = logging.getLogger( 
     238            "%s.%s" % (self.path, component.__class__.__module__) 
     239        ) 
    214240 
    215241    def is_component_enabled(self, cls): 
    216242        """Implemented to only allow activation of components that are not 
    … …  
    362388 
    363389    def setup_log(self): 
    364390        """Initialize the logging sub-system.""" 
    365         from trac.log import logger_factory 
     391        from trac.log import setup_logging 
    366392        logtype = self.log_type 
    367393        logfile = self.log_file 
    368394        if logtype == 'file' and not os.path.isabs(logfile): 
    … …  
    373399                     .replace('%(path)s', self.path) \ 
    374400                     .replace('%(basename)s', os.path.basename(self.path)) \ 
    375401                     .replace('%(project)s', self.project_name) 
    376         self.log = logger_factory(logtype, logfile, self.log_level, self.path, 
    377                                   format=format) 
     402        # Setup but don't keep the root logger  
     403        setup_logging(logtype, logfile, self.log_level, self.path, 
     404                      format, self.log_filters) 
     405         
     406        class CheckDeprecatedLoggingUsage(object): 
     407            """Proxy class to warn users of bad logging usage""" 
     408            log = logging.getLogger("%s.%s" % (self.path, __name__)) 
     409            def check_deprecated_use(self): 
     410                import inspect 
     411                caller = inspect.stack()[2] 
     412                if 'env.log' in caller[4][0]: 
     413                    self.log.warn( 
     414                        _("""Please stop logging through "env.log" on "%s". \ 
     415The code issuing this is "%s". This usage is now deprecated. Instead, if \ 
     416it's a trac Component, please use "self.log", if it's just a function which \ 
     417get's passed a trac env, get a logger like "log = env.get_logger(__name__)" \ 
     418and log through that. This practice provides good and usefull logging."""), 
     419                        caller[1], caller[4][0].strip()) 
     420                del caller 
     421            def __getattribute__(self, name): 
     422                if name in ('log', 'check_deprecated_use'): 
     423                    return object.__getattribute__(self, name) 
     424                self.check_deprecated_use() 
     425                return getattr(self.log, name) 
     426                 
     427        # Get a logger for this module 
     428        self.log = CheckDeprecatedLoggingUsage() 
     429         
     430    def get_logger(self, name): 
     431        """Get the correct logger for classes/functions which an env is passed, 
     432        yet, it's not subclassing Component.""" 
     433        from trac.log import get_logger 
     434        return get_logger(self.path, name) 
    378435 
    379436    def get_known_users(self, cnx=None): 
    380437        """Generator that yields information about all known users, i.e. users 
    … …  
    567624                env.log.info('Reloading environment due to configuration ' 
    568625                             'change') 
    569626                env.shutdown() 
    570                 if hasattr(env.log, '_trac_handler'): 
    571                     hdlr = env.log._trac_handler 
    572                     env.log.removeHandler(hdlr) 
     627                env_root_logger = logging.getLogger(env.path) 
     628                if hasattr(env_root_logger, '_trac_handler'):                     
     629                    hdlr = env_root_logger._trac_handler 
     630                    env_root_logger.removeHandler(hdlr) 
    573631                    hdlr.close() 
     632                del env_root_logger 
    574633                del env_cache[env_path] 
    575634                env = None 
    576635            if env is None: 

  • 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() 
    … …  
    272272        As this is usually done while deleting the parent resource, 
    273273        the `db` argument is ''not'' optional here. 
    274274        """ 
     275        log = env.get_logger(__name__) 
    275276        attachment_dir = None 
    276277        for attachment in list(cls.select(env, parent_realm, parent_id, db)): 
    277278            attachment_dir = os.path.dirname(attachment.path) 
    … …  
    280281            try: 
    281282                os.rmdir(attachment_dir) 
    282283            except OSError: 
    283                 env.log.error("Can't delete attachment directory %s", 
    284                               attachment_dir, exc_info=True) 
     284                log.error("Can't delete attachment directory %s", 
     285                          attachment_dir, exc_info=True) 
    285286             
    286287    def open(self): 
    287         self.env.log.debug('Trying to open attachment at %s', self.path) 
     288        self.log.debug('Trying to open attachment at %s', self.path) 
    288289        try: 
    289290            fd = open(self.path, 'rb') 
    290291        except IOError: 
    … …  
    692693            add_link(req, 'alternate', raw_href, _('Original Format'), 
    693694                     mime_type) 
    694695 
    695             self.log.debug("Rendering preview of file %s with mime-type %s" 
    696                            % (attachment.filename, mime_type)) 
     696            self.log.debug("Rendering preview of file %s with mime-type %s", 
     697                           attachment.filename, mime_type) 
    697698 
    698699            data['preview'] = mimeview.preview_data( 
    699700                Context.from_request(req, attachment.resource), fd, 
    … …  
    770771        if legacy_action: 
    771772            decision = legacy_action in perm 
    772773            if not decision: 
    773                 self.env.log.debug('LegacyAttachmentPolicy denied %s ' 
    774                                    'access to %s. User needs %s' % 
    775                                    (username, resource, legacy_action)) 
     774                self.log.debug('LegacyAttachmentPolicy denied %s ' 
     775                               'access to %s. User needs %s', 
     776                               username, resource, legacy_action) 
    776777            return decision 
    777778        else: 
    778779            for d in self.delegates: 

  • 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

     
    558558            # The column name is obtained. 
    559559            get_col_name_sql = 'SELECT * FROM ( ' + sql + ' ) AS tab LIMIT 1' 
    560560            cursor.execute(get_col_name_sql, args) 
    561             self.env.log.debug("Query SQL(Get col names): " + get_col_name_sql) 
     561            self.log.debug("Query SQL(Get col names): " + get_col_name_sql) 
    562562            cols = get_column_names(cursor) 
    563563 
    564564            sort_col = req.args.get('sort', '') 

  • trac/ticket/model.py

     
    4646     
    4747    def __init__(self, env, tkt_id=None, db=None, version=None): 
    4848        self.env = env 
     49        self.log = self.env.get_logger(__name__) 
    4950        self.resource = Resource('ticket', tkt_id, version) 
    5051        self.fields = TicketSystem(self.env).get_ticket_fields() 
    5152        self.time_fields = [f['name'] for f in self.fields 
    … …  
    8586                    try: 
    8687                        default = options[int(default)] 
    8788                    except (ValueError, IndexError): 
    88                         self.env.log.warning('Invalid default value "%s" ' 
    89                                              'for custom field "%s"' 
    90                                              % (default, field['name'])) 
     89                        self.log.warning('Invalid default value "%s" for ' 
     90                                         'custom field "%s"', default, 
     91                                         field['name']) 
    9192            if default: 
    9293                self.values.setdefault(field['name'], default) 
    9394 
    … …  
    377378        if not self.ticket_col: 
    378379            self.ticket_col = self.type 
    379380        self.env = env 
     381        self.log = self.env.get_logger(__name__) 
    380382        if name: 
    381383            name = simplify_whitespace(name) 
    382384        if name: 
    … …  
    406408            handle_ta = False 
    407409 
    408410        cursor = db.cursor() 
    409         self.env.log.info('Deleting %s %s' % (self.type, self.name)) 
     411        self.log.info('Deleting %s %s', self.type, self.name) 
    410412        cursor.execute("DELETE FROM enum WHERE type=%s AND value=%s", 
    411413                       (self.type, self._old_value)) 
    412414        # Re-order any enums that have higher value than deleted (close gap) 
    … …  
    435437            handle_ta = False 
    436438 
    437439        cursor = db.cursor() 
    438         self.env.log.debug("Creating new %s '%s'" % (self.type, self.name)) 
     440        self.log.debug("Creating new %s '%s'", self.type, self.name) 
    439441        if not self.value: 
    440442            cursor.execute(("SELECT COALESCE(MAX(%s),0) FROM enum " 
    441443                            "WHERE type=%%s") % db.cast('value', 'int'), 
    … …  
    461463            handle_ta = False 
    462464 
    463465        cursor = db.cursor() 
    464         self.env.log.info('Updating %s "%s"' % (self.type, self.name)) 
     466        self.log.info('Updating %s "%s"', self.type, self.name) 
    465467        cursor.execute("UPDATE enum SET name=%s,value=%s " 
    466468                       "WHERE type=%s AND name=%s", 
    467469                       (self.name, self.value, self.type, self._old_name)) 
    … …  
    525527 
    526528    def __init__(self, env, name=None, db=None): 
    527529        self.env = env 
     530        self.log = self.env.get_logger(__name__) 
    528531        if name: 
    529532            name = simplify_whitespace(name) 
    530533        if name: 
    … …  
    556559            handle_ta = False 
    557560 
    558561        cursor = db.cursor() 
    559         self.env.log.info('Deleting component %s' % self.name) 
     562        self.log.info('Deleting component %s', self.name) 
    560563        cursor.execute("DELETE FROM component WHERE name=%s", (self.name,)) 
    561564 
    562565        self.name = self._old_name = None 
    … …  
    576579            handle_ta = False 
    577580 
    578581        cursor = db.cursor() 
    579         self.env.log.debug("Creating new component '%s'" % self.name) 
     582        self.log.debug("Creating new component '%s'", self.name) 
    580583        cursor.execute("INSERT INTO component (name,owner,description) " 
    581584                       "VALUES (%s,%s,%s)", 
    582585                       (self.name, self.owner, self.description)) 
    … …  
    596599            handle_ta = False 
    597600 
    598601        cursor = db.cursor() 
    599         self.env.log.info('Updating component "%s"' % self.name) 
     602        self.log.info('Updating component "%s"', self.name) 
    600603        cursor.execute("UPDATE component SET name=%s,owner=%s,description=%s " 
    601604                       "WHERE name=%s", 
    602605                       (self.name, self.owner, self.description, 
    … …  
    630633 
    631634    def __init__(self, env, name=None, db=None): 
    632635        self.env = env 
     636        self.log = self.env.get_logger(__name__) 
    633637        if name: 
    634638            self._fetch(name, db) 
    635639            self._old_name = name 
    … …  
    675679            handle_ta = False 
    676680 
    677681        cursor = db.cursor() 
    678         self.env.log.info('Deleting milestone %s' % self.name) 
     682        self.log.info('Deleting milestone %s', self.name) 
    679683        cursor.execute("DELETE FROM milestone WHERE name=%s", (self.name,)) 
    680684 
    681685        # Retarget/reset tickets associated with this milestone 
    … …  
    702706 
    703707        self.name = simplify_whitespace(self.name) 
    704708        cursor = db.cursor() 
    705         self.env.log.debug("Creating new milestone '%s'" % self.name) 
     709        self.log.debug("Creating new milestone '%s'", self.name) 
    706710        cursor.execute("INSERT INTO milestone (name,due,completed,description) " 
    707711                       "VALUES (%s,%s,%s,%s)", 
    708712                       (self.name, to_timestamp(self.due), to_timestamp(self.completed), 
    … …  
    722726 
    723727        self.name = simplify_whitespace(self.name) 
    724728        cursor = db.cursor() 
    725         self.env.log.info('Updating milestone "%s"' % self.name) 
     729        self.log.info('Updating milestone "%s"', self.name) 
    726730        cursor.execute("UPDATE milestone SET name=%s,due=%s," 
    727731                       "completed=%s,description=%s WHERE name=%s", 
    728732                       (self.name, to_timestamp(self.due), to_timestamp(self.completed), 
    729733                        self.description, 
    730734                        self._old_name)) 
    731         self.env.log.info('Updating milestone field of all tickets ' 
    732                           'associated with milestone "%s"' % self.name) 
     735        self.log.info('Updating milestone field of all tickets associated ' 
     736                      'with milestone "%s"', self.name) 
    733737        cursor.execute("UPDATE ticket SET milestone=%s WHERE milestone=%s", 
    734738                       (self.name, self._old_name)) 
    735739        self._old_name = self.name 
    … …  
    763767 
    764768    def __init__(self, env, name=None, db=None): 
    765769        self.env = env 
     770        self.log = self.env.get_logger(__name__) 
    766771        if name: 
    767772            if not db: 
    768773                db = self.env.get_db_cnx() 
    … …  
    792797            handle_ta = False 
    793798 
    794799        cursor = db.cursor() 
    795         self.env.log.info('Deleting version %s' % self.name) 
     800        self.log.info('Deleting version %s', self.name) 
    796801        cursor.execute("DELETE FROM version WHERE name=%s", (self.name,)) 
    797802 
    798803        self.name = self._old_name = None 
    … …  
    812817            handle_ta = False 
    813818 
    814819        cursor = db.cursor() 
    815         self.env.log.debug("Creating new version '%s'" % self.name) 
     820        self.log.debug("Creating new version '%s'", self.name) 
    816821        cursor.execute("INSERT INTO version (name,time,description) " 
    817822                       "VALUES (%s,%s,%s)", 
    818823                       (self.name, to_timestamp(self.time), self.description)) 
    … …  
    832837            handle_ta = False 
    833838 
    834839        cursor = db.cursor() 
    835         self.env.log.info('Updating version "%s"' % self.name) 
     840        self.log.info('Updating version "%s"', self.name) 
    836841        cursor.execute("UPDATE version SET name=%s,time=%s,description=%s " 
    837842                       "WHERE name=%s", 
    838843                       (self.name, to_timestamp(self.time), self.description, 

  • trac/ticket/roadmap.py

     
    653653                cursor.execute("UPDATE ticket SET milestone=%s WHERE " 
    654654                               "milestone=%s and status != 'closed'", 
    655655                                (retarget_to, old_name)) 
    656                 self.env.log.info('Tickets associated with milestone %s ' 
    657                                   'retargeted to %s' % (old_name, retarget_to)) 
     656                self.log.info('Tickets associated with milestone %s ' 
     657                              'retargeted to %s' % (old_name, retarget_to)) 
    658658        else: 
    659659            milestone.insert() 
    660660        db.commit() 

  • trac/ticket/query.py

     
    5454                 order=None, desc=0, group=None, groupdesc=0, verbose=0, 
    5555                 rows=None, page=None, max=None): 
    5656        self.env = env 
     57        self.log = self.env.get_logger(__name__) 
    5758        self.id = report # if not None, it's the corresponding saved query 
    5859        self.constraints = constraints or {} 
    5960        synonyms = TicketSystem(self.env).get_field_synonyms() 
    … …  
    234235        cursor = db.cursor() 
    235236 
    236237        count_sql = 'SELECT COUNT(*) FROM (' + sql + ') AS foo' 
    237         # self.env.log.debug("Count results in Query SQL: " + count_sql %  
    238         #                    tuple([repr(a) for a in args])) 
     238        # self.log.debug("Count results in Query SQL: " + count_sql %  
     239        #                tuple([repr(a) for a in args])) 
    239240 
    240241        cnt = 0 
    241242        try: 
    … …  
    245246            raise 
    246247        for cnt, in cursor: 
    247248            break 
    248         self.env.log.debug("Count results in Query: %d" % cnt) 
     249        self.log.debug("Count results in Query: %d" % cnt) 
    249250        return cnt 
    250251 
    251252    def execute(self, req, db=None, cached_ids=None): 
    … …  
    269270                raise TracError(_('Page %(page)s is beyond the number of ' 
    270271                                  'pages in the query', page=self.page)) 
    271272 
    272         self.env.log.debug("Query SQL: " + sql % tuple([repr(a) for a in args]))      
     273        self.log.debug("Query SQL: " + sql % tuple([repr(a) for a in args]))      
    273274        try: 
    274275            cursor.execute(sql, args) 
    275276        except: 

  • 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

     
    226226        cursor = db.cursor() 
    227227        cursor.execute("INSERT INTO permission VALUES (%s, %s)", 
    228228                       (username, action)) 
    229         self.log.info('Granted permission for %s to %s' % (action, username)) 
     229        self.log.info('Granted permission for %s to %s', action, username) 
    230230        db.commit() 
    231231 
    232232    def revoke_permission(self, username, action): 
    … …  
    235235        cursor = db.cursor() 
    236236        cursor.execute("DELETE FROM permission WHERE username=%s AND action=%s", 
    237237                       (username, action)) 
    238         self.log.info('Revoked permission for %s to %s' % (action, username)) 
     238        self.log.info('Revoked permission for %s to %s', action, username) 
    239239        db.commit() 
    240240 
    241241 
    … …  
    426426                                               perm) 
    427427            if decision is not None: 
    428428                if not decision: 
    429                     self.log.debug("%s denies %s performing %s on %r" % 
    430                                    (policy.__class__.__name__, username, 
    431                                     action, resource)) 
     429                    self.log.debug("%s denies %s performing %s on %r", 
     430                                   policy.__class__.__name__, username, 
     431                                   action, resource) 
    432432                return decision 
    433         self.log.debug("No policy allowed %s performing %s on %r" % 
    434                        (username, action, resource)) 
     433        self.log.debug("No policy allowed %s performing %s on %r", 
     434                       username, action, resource) 
    435435        return False 
    436436 
    437437    # IPermissionRequestor methods 
    … …  
    550550 
    551551    def permissions(self): 
    552552        """Deprecated (but still used by the HDF compatibility layer)""" 
    553         self.env.log.warning('perm.permissions() is deprecated and ' 
    554                              'is only present for HDF compatibility') 
     553        self.log.warning('perm.permissions() is deprecated and ' 
     554                         'is only present for HDF compatibility') 
    555555        perm = PermissionSystem(self.env) 
    556556        actions = perm.get_user_permissions(self.username) 
    557557        return [action for action in actions if action in self] 

  • trac/loader.py

     
    3737        distributions, errors = working_set.find_plugins( 
    3838            pkg_resources.Environment(search_path) 
    3939        ) 
     40        log = env.get_logger(__name__) 
    4041        for dist in distributions: 
    41             env.log.debug('Adding plugin %s from %s', dist, dist.location) 
     42            log.debug('Adding plugin %s from %s', dist, dist.location) 
    4243            working_set.add(dist) 
    4344 
    4445        def _log_error(item, e): 
    4546            if isinstance(e, DistributionNotFound): 
    46                 env.log.debug('Skipping "%s": ("%s" not found)', item, e) 
     47                log.debug('Skipping "%s": ("%s" not found)', item, e) 
    4748            elif isinstance(e, VersionConflict): 
    48                 env.log.error('Skipping "%s": (version conflict "%s")', 
    49                               item, e) 
     49                log.error('Skipping "%s": (version conflict "%s")', 
     50                          item, e) 
    5051            elif isinstance(e, UnknownExtra): 
    51                 env.log.error('Skipping "%s": (unknown extra "%s")', item, e) 
     52                log.error('Skipping "%s": (unknown extra "%s")', item, e) 
    5253            elif isinstance(e, ImportError): 
    53                 env.log.error('Skipping "%s": (can\'t import "%s")', item, e) 
     54                log.error('Skipping "%s": (can\'t import "%s")', item, e) 
    5455            else: 
    55                 env.log.error('Skipping "%s": (error "%s")', item, e) 
     56                log.error('Skipping "%s": (error "%s")', item, e) 
    5657 
    5758        for dist, e in errors.iteritems(): 
    5859            _log_error(dist, e) 
    5960 
    6061        for entry in working_set.iter_entry_points(entry_point_name): 
    61             env.log.debug('Loading %s from %s', entry.name, 
    62                           entry.dist.location) 
     62            log.debug('Loading %s from %s', entry.name, 
     63                      entry.dist.location) 
    6364            try: 
    6465                entry.load(require=True) 
    6566            except (ImportError, DistributionNotFound, VersionConflict, 
    … …  
    7677    manager if they define any components. 
    7778    """ 
    7879    def _load_py_files(env, search_path, auto_enable=None): 
     80        log = env.get_logger(__name__) 
    7981        for path in search_path: 
    8082            plugin_files = glob(os.path.join(path, '*.py')) 
    8183            for plugin_file in plugin_files: 
    8284                try: 
    8385                    plugin_name = os.path.basename(plugin_file[:-3]) 
    84                     env.log.debug('Loading file plugin %s from %s' % \ 
    85                                   (plugin_name, plugin_file)) 
     86                    log.debug('Loading file plugin %s from %s', 
     87                              plugin_name, plugin_file) 
    8688                    if plugin_name not in sys.modules: 
    8789                        module = imp.load_source(plugin_name, plugin_file) 
    8890                    if path == auto_enable: 
    8991                        _enable_plugin(env, plugin_name) 
    9092                except Exception, e: 
    91                     env.log.error('Failed to load plugin from %s', plugin_file, 
    92                                   exc_info=True) 
     93                    log.error('Failed to load plugin from %s', plugin_file, 
     94                              exc_info=True) 
    9395 
    9496    return _load_py_files 
    9597 

  • 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/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

     
    7575        """ 
    7676        self.formatter = formatter 
    7777        self.env = formatter.env 
     78        self.log = self.env.get_logger(__name__) 
    7879        self.name = name 
    7980        self.args = args 
    8081        self.error = None 
    … …  
    134135            stream = Stream(HTMLParser(StringIO(text))) 
    135136            return (stream | self._sanitizer).render('xhtml', encoding=None) 
    136137        except ParseError, e: 
    137             self.env.log.warn(e) 
     138            self.log.warn(e) 
    138139            line = unicode(text).splitlines()[e.lineno - 1].strip() 
    139140            return system_message(_('HTML parsing error: %(message)s', 
    140141                                    message=escape(e.msg)), line) 
    … …  
    167168    # generic processors 
    168169 
    169170    def _legacy_macro_processor(self, text): # TODO: remove in 0.12 
    170         self.env.log.warning('Executing pre-0.11 Wiki macro %s by provider %s' 
    171                              % (self.name, self.macro_provider)) 
     171        self.log.warning('Executing pre-0.11 Wiki macro %s by provider %s', 
     172                         self.name, self.macro_provider) 
    172173        return self.macro_provider.render_macro(self.formatter.req, self.name, 
    173174                                                text) 
    174175 
    175176    def _macro_processor(self, text): 
    176         self.env.log.debug('Executing Wiki macro %s by provider %s' 
    177                            % (self.name, self.macro_provider)) 
     177        self.log.debug('Executing Wiki macro %s by provider %s', 
     178                       self.name, self.macro_provider) 
    178179        return self.macro_provider.expand_macro(self.formatter, self.name, 
    179180                                                text) 
    180181 
    … …  
    239240    def __init__(self, env, context): 
    240241        """Note: `req` is still temporarily used.""" 
    241242        self.env = env 
     243        self.log = self.env.get_logger(__name__) 
    242244        self.context = context 
    243245        self.req = context.req 
    244246        self.href = context.href 
    … …  
    481483            macro = WikiProcessor(self, name) 
    482484            return macro.process(args, in_paragraph=True) 
    483485        except Exception, e: 
    484             self.env.log.error('Macro %s(%s) failed' % (name, args), 
    485                                exc_info=True) 
     486            self.log.error('Macro %s(%s) failed', name, args, exc_info=True) 
    486487            return system_message('Error: Macro %s(%s) failed' % (name, args), 
    487488                                  e) 
    488489 

  • 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.translation import _ 
     24 
     25def setup_logging(logtype='syslog', logfile=None, level='WARNING', logid='Trac', 
     26                  format=None, filters=()): 
     27    env_root_logger = logging.getLogger(logid) 
     28         
    2529    logtype = logtype.lower() 
    2630    if logtype == 'file': 
    2731        hdlr = logging.FileHandler(logfile) 
    2832    elif logtype in ('winlog', 'eventlog', 'nteventlog'): 
    2933        # Requires win32 extensions 
    30         hdlr = logging.handlers.NTEventLogHandler(logid, 
    31                                                   logtype='Application') 
     34        hdlr = logging.handlers.NTEventLogHandler(logid, logtype='Application') 
    3235    elif logtype in ('syslog', 'unix'): 
    3336        hdlr = logging.handlers.SysLogHandler('/dev/log') 
    3437    elif logtype in ('stderr'): 
    … …  
    4750        datefmt = '%X' 
    4851    level = level.upper() 
    4952    if level in ('DEBUG', 'ALL'): 
    50         logger.setLevel(logging.DEBUG) 
     53        env_root_logger.setLevel(logging.DEBUG) 
    5154    elif level == 'INFO': 
    52         logger.setLevel(logging.INFO) 
     55        env_root_logger.setLevel(logging.INFO) 
    5356    elif level == 'ERROR': 
    54         logger.setLevel(logging.ERROR) 
     57        env_root_logger.setLevel(logging.ERROR) 
    5558    elif level == 'CRITICAL': 
    56         logger.setLevel(logging.CRITICAL) 
     59        env_root_logger.setLevel(logging.CRITICAL) 
    5760    else: 
    58         logger.setLevel(logging.WARNING) 
    59     formatter = logging.Formatter(format, datefmt) 
    60     hdlr.setFormatter(formatter) 
    61     logger.addHandler(hdlr) 
     61        env_root_logger.setLevel(logging.WARNING) 
    6262 
     63    hdlr.setFormatter(TracFormatter(logid, format, datefmt)) 
     64    # Assign handler right away to be able to log filter errors 
     65    env_root_logger.addHandler(hdlr)     
     66     
     67    if filters: 
     68        hdlr.addFilter(TracFilter(filters, level, logid)) 
     69         
    6370    # Remember our handler so that we can remove it later 
    64     logger._trac_handler = hdlr  
     71    env_root_logger._trac_handler = hdlr 
     72     
     73    # Return env logger for tests that expect it 
     74    # For components, they will have self.log 
     75    # For classes/functions which get passed an env use env.get_logger(__name__) 
     76    return env_root_logger 
     77 
     78 
     79class TracFilter(logging.Filter): 
     80    def __init__(self, trac_filters=(), default_level='DEBUG', name=''): 
     81        self.qns = [] 
     82        for filter in trac_filters: 
     83            filter = filter.split(':') 
     84            if len(filter) > 1 and filter[1]: 
     85                qn, lvl = filter[0].rstrip('.*'), filter[1] 
     86            else: 
     87                qn, lvl = filter[0].rstrip('.*'), default_level 
     88            path_and_qn = "%s.%s" % (name, qn) 
     89             
     90            if lvl == 'ALL': 
     91                lvl = 'DEBUG' 
     92                 
     93            if lvl not in logging._levelNames: 
     94                logging.getLogger("%s.%s" % (name, __name__)).warning( 
     95                    _("Level '%(level)s' for filter '%(filter)s' not know. " 
     96                      "Ignoring filter.", 
     97                      level=lvl.upper(), filter=':'.join(filter))) 
     98                continue 
     99                             
     100            self.qns.append((path_and_qn, logging.getLevelName(lvl.upper()))) 
     101             
     102        self.qns = sorted(self.qns, key=lambda x: len(x[0]), reverse=True) 
     103         
     104        logging.Filter.__init__(self, name) 
     105 
     106    def filter(self, record): 
     107        for qn, level in self.qns: 
     108            if record.name.startswith("%s." % qn) or record.name == qn: 
     109                # Match trac, trac.web but not tracforge 
     110                if level <= record.levelno: 
     111                    return 1 
     112                return 0 
     113        # No point returning `logging.Filter.filter(self, record)` 
     114        # All logging messages will arrive to the filter with self.name at 
     115        # least equal to environment path, ie, self.name 
     116        return 1 
     117 
     118 
     119class TracFormatter(logging.Formatter): 
     120 
     121    def __init__(self, env_path, fmt, datefmt): 
     122        self.env_path = env_path 
     123        # Calculate strip length at init time, no need to keep calculating it 
     124        self.strip_length = len(env_path)+1 
     125        logging.Formatter.__init__(self, fmt, datefmt) 
     126 
     127    def format(self, record): 
     128        # get full dotted module name and stick that under record.module 
     129        if record.name.startswith(self.env_path): 
     130            record.module = record.name[self.strip_length:] 
     131        return logging.Formatter.format(self, record) 
    65132 
    66     return logger 
     133def get_logger(env_path, name): 
     134    """Helper function to get the correct logger for the passed class or 
     135    env and name.""" 
     136    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() 
    … …  
    118119        # so that session doesn't get purged 
    119120        if now - self.last_visit > UPDATE_INTERVAL: 
    120121            self.last_visit = now 
    121             self.env.log.info("Refreshing session %s" % self.sid) 
     122            self.log.info("Refreshing session %s", self.sid) 
    122123            cursor.execute('UPDATE session SET last_visit=%s ' 
    123124                           'WHERE sid=%s AND authenticated=%s', 
    124125                           (self.last_visit, self.sid, authenticated)) 
    125126            # Purge expired sessions. We do this only when the session was 
    126127            # changed as to minimize the purging. 
    127128            mintime = now - PURGE_AGE 
    128             self.env.log.debug('Purging old, expired, sessions.') 
     129            self.log.debug('Purging old, expired, sessions.') 
    129130            cursor.execute("DELETE FROM session_attribute " 
    130131                           "WHERE authenticated=0 AND sid " 
    131132                           "IN (SELECT sid FROM session WHERE " 
    … …  
    191192            raise TracError(Markup('Session "%s" already exists.<br />' 
    192193                                   'Please choose a different session ID.') 
    193194                            % new_sid, 'Error renaming session') 
    194         self.env.log.debug('Changing session ID %s to %s' % (self.sid, new_sid)) 
     195        self.log.debug('Changing session ID %s to %s', self.sid, new_sid) 
    195196        cursor.execute("UPDATE session SET sid=%s WHERE sid=%s " 
    196197                       "AND authenticated=0", (new_sid, self.sid)) 
    197198        cursor.execute("UPDATE session_attribute SET sid=%s " 
    … …  
    225226            if not authenticated_flags[0]: 
    226227                # Update the anomymous session records so that the session ID 
    227228                # becomes the user name, and set the authenticated flag. 
    228                 self.env.log.debug('Promoting anonymous session %s to ' 
    229                                    'authenticated session for user %s', 
    230                                    sid, self.req.authname) 
     229                self.log.debug('Promoting anonymous session %s to ' 
     230                               'authenticated session for user %s', 
     231                               sid, self.req.authname) 
    231232                cursor.execute("UPDATE session SET sid=%s,authenticated=1 " 
    232233                               "WHERE sid=%s AND authenticated=0", 
    233234                               (self.req.authname, sid)) 

  • trac/web/main.py

     
    422422                                       environ['trac.web.version'])) 
    423423    except TracError, e: 
    424424        env_error = e 
    425  
     425     
     426    log = env.get_logger(__name__) 
    426427    req = Request(environ, start_response) 
    427428    try: 
    428429        return _dispatch_request(req, env, env_error) 
    … …  
    436437            #       objects with a __del__ method caught in a cycle) 
    437438            ##gc.set_debug(gc.DEBUG_UNCOLLECTABLE) 
    438439            unreachable = gc.collect() 
    439             env.log.debug("%d unreachable objects found.", unreachable) 
     440            log.debug("%d unreachable objects found.", unreachable) 
    440441            ##uncollectable = len(gc.garbage) 
    441442            ##if uncollectable: 
    442443            ##    del gc.garbage[:] 
    443             ##    env.log.warn("%d uncollectable objects found.", uncollectable) 
     444            ##    log.warn("%d uncollectable objects found.", uncollectable) 
    444445 
    445446def _dispatch_request(req, env, env_error): 
    446447    resp = [] 
    447448 
     449    log = env.get_logger(__name__) 
    448450    # fixup env.abs_href if `[trac] base_url` was not specified 
    449451    if env and not env.abs_href.base: 
    450452        env._abs_href = req.abs_href 
    … …  
    461463 
    462464    except HTTPException, e: 
    463465        if env: 
    464             env.log.warn(e) 
     466            log.warn(e) 
    465467        title = 'Error' 
    466468        if e.reason: 
    467469            if 'error' in e.reason.lower(): 
    … …  
    483485 
    484486    except Exception, e: 
    485487        if env: 
    486             env.log.exception(e) 
     488            log.exception(e) 
    487489 
    488490        exc_info = sys.exc_info() 
    489491        try: 

  • trac/notification.py

     
    119119 
    120120    def __init__(self, env): 
    121121        self.env = env 
     122        self.log = self.env.get_logger(__name__) 
    122123        self.config = env.config 
    123124        self.db = env.get_db_cnx() 
    124125 
    … …  
    289290                if domain: 
    290291                    address = "%s@%s" % (address, domain) 
    291292                else: 
    292                     self.env.log.info("Email address w/o domain: %s" % address) 
     293                    self.log.info("Email address w/o domain: %s", address) 
    293294                    return None 
    294295 
    295296        mo = self.shortaddr_re.search(address) 
    … …  
    298299        mo = self.longaddr_re.search(address) 
    299300        if mo: 
    300301            return mo.group(2) 
    301         self.env.log.info("Invalid email address: %s" % address) 
     302        self.log.info("Invalid email address: %s", address) 
    302303        return None 
    303304 
    304305    def encode_header(self, key, value): 
    … …  
    376377         
    377378        # if there is not valid recipient, leave immediately 
    378379        if len(recipients) < 1: 
    379             self.env.log.info('no recipient for a ticket notification') 
     380            self.log.info('no recipient for a ticket notification') 
    380381            return 
    381382 
    382383        pcc = accaddrs 
    … …  
    402403        msg.set_charset(self._charset) 
    403404        self.add_headers(msg, headers); 
    404405        self.add_headers(msg, mime_headers); 
    405         self.env.log.info("Sending SMTP notification to %s:%d to %s" 
    406                            % (self.smtp_server, self.smtp_port, recipients)) 
     406        self.log.info("Sending SMTP notification to %s:%d to %s", 
     407                      self.smtp_server, self.smtp_port, recipients) 
    407408        msgtext = msg.as_string() 
    408409        # Ensure the message complies with RFC2822: use CRLF line endings 
    409410        recrlf = re.compile("\r?\n")