Edgewall Software

Ticket #7286: all-the-way_enhanced_logging.patch

File all-the-way_enhanced_logging.patch, 58.5 KB (added by Pedro Algarvio, aka, s0undt3ch <ufs@…>, 4 years ago)

  • trac/attachment.py

     
    112112            self.resource = Resource(parent_realm_or_attachment_resource, 
    113113                                     parent_id).child('attachment', filename) 
    114114        self.env = env 
     115        self.log = self.env.get_logger(__name__) 
    115116        self.parent_realm = self.resource.parent.realm 
    116117        self.parent_id = unicode(self.resource.parent.id) 
    117118        if self.resource.id: 
    … …  
    180181            try: 
    181182                os.unlink(self.path) 
    182183            except OSError: 
    183                 self.env.log.error('Failed to delete attachment file %s', 
    184                                    self.path, exc_info=True) 
     184                self.log.error('Failed to delete attachment file %s', 
     185                               self.path, exc_info=True) 
    185186                if handle_ta: 
    186187                    db.rollback() 
    187188                raise TracError(_('Could not delete attachment')) 
    188189 
    189         self.env.log.info('Attachment removed: %s' % self.title) 
     190        self.log.info('Attachment removed: %s', self.title) 
    190191        if handle_ta: 
    191192            db.commit() 
    192193 
    … …  
    233234            shutil.copyfileobj(fileobj, targetfile) 
    234235            self.resource.id = self.filename = filename 
    235236 
    236             self.env.log.info('New attachment: %s by %s', self.title, 
    237                               self.author) 
     237            self.log.info('New attachment: %s by %s', self.title, self.author) 
    238238 
    239239            if handle_ta: 
    240240                db.commit() 
    … …  
    269269        As this is usually done while deleting the parent resource, 
    270270        the `db` argument is ''not'' optional here. 
    271271        """ 
     272        log = env.get_logger(__name__) 
    272273        attachment_dir = None 
    273274        for attachment in list(cls.select(env, parent_realm, parent_id, db)): 
    274275            attachment_dir = os.path.dirname(attachment.path) 
    … …  
    277278            try: 
    278279                os.rmdir(attachment_dir) 
    279280            except OSError: 
    280                 env.log.error("Can't delete attachment directory %s", 
    281                               attachment_dir, exc_info=True) 
     281                log.error("Can't delete attachment directory %s", 
     282                          attachment_dir, exc_info=True) 
    282283             
    283284    select = classmethod(select) 
    284285    delete_all = classmethod(delete_all) 
    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: 
    … …  
    670671            add_link(req, 'alternate', raw_href, _('Original Format'), 
    671672                     mime_type) 
    672673 
    673             self.log.debug("Rendering preview of file %s with mime-type %s" 
    674                            % (attachment.filename, mime_type)) 
     674            self.log.debug("Rendering preview of file %s with mime-type %s", 
     675                           attachment.filename, mime_type) 
    675676 
    676677            data['preview'] = mimeview.preview_data( 
    677678                Context.from_request(req, attachment.resource), fd, 
    … …  
    748749        if legacy_action: 
    749750            decision = legacy_action in perm 
    750751            if not decision: 
    751                 self.env.log.debug('LegacyAttachmentPolicy denied %s ' 
    752                                    'access to %s. User needs %s' % 
    753                                    (username, resource, legacy_action)) 
     752                self.log.debug('LegacyAttachmentPolicy denied %s ' 
     753                               'access to %s. User needs %s', 
     754                               username, resource, legacy_action) 
    754755            return decision 
    755756        else: 
    756757            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 
    … …  
    347373 
    348374    def setup_log(self): 
    349375        """Initialize the logging sub-system.""" 
    350         from trac.log import logger_factory 
     376        from trac.log import setup_logging 
    351377        logtype = self.log_type 
    352378        logfile = self.log_file 
    353379        if logtype == 'file' and not os.path.isabs(logfile): 
    … …  
    358384                     .replace('%(path)s', self.path) \ 
    359385                     .replace('%(basename)s', os.path.basename(self.path)) \ 
    360386                     .replace('%(project)s', self.project_name) 
    361         self.log = logger_factory(logtype, logfile, self.log_level, self.path, 
    362                                   format=format) 
     387        # Setup but don't keep the root logger  
     388        setup_logging(logtype, logfile, self.log_level, self.path, 
     389                      format, self.log_filters) 
     390        # Get a logger for this module (more correct) 
     391        self.log = logging.getLogger("%s.%s" % (self.path, __name__)) 
     392         
     393    def get_logger(self, name): 
     394        """Get the correct logger for classes/functions which an env is passed 
     395        yet, it's not subclassing Component.""" 
     396        from trac.log import get_logger 
     397        return get_logger(self.path, name)  
    363398 
    364399    def get_known_users(self, cnx=None): 
    365400        """Generator that yields information about all known users, i.e. users 
    … …  
    551586                env.log.info('Reloading environment due to configuration ' 
    552587                             'change') 
    553588                env.shutdown() 
    554                 if hasattr(env.log, '_trac_handler'): 
    555                     hdlr = env.log._trac_handler 
    556                     env.log.removeHandler(hdlr) 
     589                env_root_logger = logging.getLogger(env.path) 
     590                if hasattr(env_root_logger, '_trac_handler'):                     
     591                    hdlr = env_root_logger._trac_handler 
     592                    env_root_logger.removeHandler(hdlr) 
    557593                    hdlr.close() 
     594                del env_root_logger 
    558595                del env_cache[env_path] 
    559596                env = None 
    560597            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

     
    531531            # The number of tickets is obtained. 
    532532            count_sql = 'SELECT COUNT(*) FROM (' + sql + ') AS tab' 
    533533            cursor.execute(count_sql, args) 
    534             self.env.log.debug("Query SQL(Get num items): " + count_sql) 
     534            self.log.debug("Query SQL(Get num items): " + count_sql) 
    535535            for row in cursor: 
    536536                pass 
    537537            self.num_items = row[0] 
    … …  
    539539            # The column name is obtained. 
    540540            get_col_name_sql = 'SELECT * FROM ( ' + sql + ' ) AS tab LIMIT 1' 
    541541            cursor.execute(get_col_name_sql, args) 
    542             self.env.log.debug("Query SQL(Get col names): " + get_col_name_sql) 
     542            self.log.debug("Query SQL(Get col names): " + get_col_name_sql) 
    543543            cols = get_column_names(cursor) 
    544544 
    545545            sort_col = req.args.get('sort', '') 
    546             self.env.log.debug("Colnum Names %s, Sort column %s" % 
     546            self.log.debug("Colnum Names %s, Sort column %s" % 
    547547                               (str(cols), sort_col)) 
    548548            order_cols = [] 
    549549            if '__group__' in cols: 
    … …  
    567567            sql = " ".join(['SELECT * FROM (', sql, ') AS tab', order_by]) 
    568568            sql =" ".join([sql, 'LIMIT', str(self.limit), 'OFFSET', 
    569569                           str(self.offset)]) 
    570             self.env.log.debug("Query SQL: " + sql) 
     570            self.log.debug("Query SQL: " + sql) 
    571571        cursor.execute(sql, args) 
    572         self.env.log.debug("Query SQL: " + sql) 
     572        self.log.debug("Query SQL: " + sql) 
    573573        # FIXME: fetchall should probably not be used. 
    574574        info = cursor.fetchall() or [] 
    575575        cols = get_column_names(cursor) 

  • 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

     
    646646                cursor.execute("UPDATE ticket SET milestone=%s WHERE " 
    647647                               "milestone=%s and status != 'closed'", 
    648648                                (retarget_to, old_name)) 
    649                 self.env.log.info('Tickets associated with milestone %s ' 
    650                                   'retargeted to %s' % (old_name, retarget_to)) 
     649                self.log.info('Tickets associated with milestone %s ' 
     650                              'retargeted to %s' % (old_name, retarget_to)) 
    651651        else: 
    652652            milestone.insert() 
    653653        db.commit() 

  • trac/ticket/query.py

     
    5353                 order=None, desc=0, group=None, groupdesc=0, verbose=0, 
    5454                 rows=None, page=1, 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 
    … …  
    240241        cursor = db.cursor() 
    241242 
    242243        count_sql = 'SELECT COUNT(*) FROM (' + sql + ') AS foo' 
    243         # self.env.log.debug("Count results in Query SQL: " + count_sql %  
    244         #                    tuple([repr(a) for a in args])) 
     244        # self.log.debug("Count results in Query SQL: " + count_sql %  
     245        #                tuple([repr(a) for a in args])) 
    245246 
    246247        cnt = 0 
    247248        cursor.execute(count_sql, args); 
    248249        for cnt, in cursor: 
    249250            break 
    250         self.env.log.debug("Count results in Query: %d" % cnt) 
     251        self.log.debug("Count results in Query: %d", cnt) 
    251252        return cnt 
    252253 
    253254    def execute(self, req, db=None, cached_ids=None): 
    … …  
    271272                raise TracError(_('Page %(page)s is beyond the number of ' 
    272273                                  'pages in the query', page=self.page)) 
    273274 
    274         self.env.log.debug("Query SQL: " + sql % tuple([repr(a) for a in args]))      
     275        self.log.debug("Query SQL: " + sql % tuple([repr(a) for a in args]))      
    275276        cursor.execute(sql, args) 
    276277        columns = get_column_names(cursor) 
    277278        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

     
    7070        from trac.db_default import schema 
    7171        for table in schema: 
    7272            for stmt in self.to_sql(table): 
    73                 self.env.log.debug(stmt) 
     73                self.log.debug(stmt) 
    7474                cursor.execute(stmt) 
    7575        cnx.commit() 
    7676 

  • 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 
    … …  
    211212        log_level = self.env.log_level 
    212213        log_file = self.env.log_file 
    213214        log_dir = os.path.join(self.env.path, 'log') 
     215        log_filters = self.config.getlist('logging', 'log_filters') 
     216        for idx, filter in enumerate(log_filters): 
     217            filter = filter.split(':') 
     218            if not (len(filter) > 1 and filter[1]): 
     219                log_filters[idx] = "%s:%s" % (filter[0], log_level) 
    214220 
    215221        log_types = [ 
    216222            dict(name='', label=_('None'), selected=False, disabled=False), 
    … …  
    229235 
    230236        if req.method == 'POST': 
    231237            changed = False 
    232  
    233             new_type = req.args.get('log_type') 
    234             if new_type and new_type not in ('stderr', 'file', 'syslog', 
    235                                              'eventlog'): 
    236                 raise TracError( 
    237                     _('Unknown log type %(type)s', type=new_type), 
    238                     _('Invalid log type') 
    239                 ) 
    240             if new_type != log_type: 
    241                 self.config.set('logging', 'log_type', new_type or 'none') 
     238            if 'add_filter' in req.args: 
     239                filter_module_name = req.args.get('filter_modname') 
     240                if not filter_module_name: 
     241                    raise TracError(_("Filter module name must not be empty")) 
     242                filter_log_level = req.args.get('filter_loglevel') 
     243                if filter_log_level and filter_log_level not in log_levels: 
     244                    raise TracError(_('Unknown log level %(level)s', 
     245                                      level=filter_log_level), 
     246                                    _('Invalid log level')) 
     247                for filter in log_filters: 
     248                    if filter.split(':')[0] == filter_module_name or \ 
     249                        filter.split(':')[0].rstrip('.*') == filter_module_name: 
     250                        raise TracError( 
     251                            _("A filter for module '%(module)s' already exists." 
     252                              " Remove that one first.", 
     253                              module=filter_module_name), 
     254                            _("Filter already exists")) 
     255                new_log_filter = "%s:%s" % (filter_module_name.rstrip('.*'), 
     256                                            filter_log_level) 
     257                log_filters.append(new_log_filter) 
     258                self.log.debug("Adding new filter '%s' to log_filters", 
     259                               new_log_filter) 
     260                self.config.set('logging', 'log_filters',', '.join(log_filters)) 
    242261                changed = True 
    243                 log_type = new_type 
    244  
    245             if log_type: 
    246                 new_level = req.args.get('log_level') 
    247                 if new_level and new_level not in log_levels: 
     262            elif 'delete_filters' in req.args: 
     263                selected = req.args.getlist('sel') 
     264                for filter in selected: 
     265                    self.log.debug("Removing filter '%s' from log_filters", 
     266                                   filter) 
     267                    log_filters.pop(log_filters.index(filter)) 
     268                self.config.set('logging', 'log_filters',', '.join(log_filters)) 
     269                changed = True 
     270            else: 
     271                new_type = req.args.get('log_type') 
     272                if new_type and new_type not in ('stderr', 'file', 'syslog', 
     273                                                 'eventlog'): 
    248274                    raise TracError( 
    249                         _('Unknown log level %(level)s', level=new_level), 
    250                         _('Invalid log level')) 
    251                 if new_level and new_level != log_level: 
    252                     self.config.set('logging', 'log_level', new_level) 
     275                        _('Unknown log type %(type)s', type=new_type), 
     276                        _('Invalid log type') 
     277                    ) 
     278                if new_type != log_type: 
     279                    self.config.set('logging', 'log_type', new_type or 'none') 
    253280                    changed = True 
    254                     log_evel = new_level 
    255             else: 
    256                 self.config.remove('logging', 'log_level') 
    257                 changed = True 
     281                    log_type = new_type 
    258282 
    259             if log_type == 'file': 
    260                 new_file = req.args.get('log_file', 'trac.log') 
    261                 if new_file != log_file: 
    262                     self.config.set('logging', 'log_file', new_file or '') 
     283                if log_type: 
     284                    new_level = req.args.get('log_level') 
     285                    if new_level and new_level not in log_levels: 
     286                        raise TracError( 
     287                            _('Unknown log level %(level)s', level=new_level), 
     288                            _('Invalid log level')) 
     289                    if new_level and new_level != log_level: 
     290                        self.config.set('logging', 'log_level', new_level) 
     291                        changed = True 
     292                        log_evel = new_level 
     293                else: 
     294                    self.config.remove('logging', 'log_level') 
    263295                    changed = True 
    264                     log_file = new_file 
    265                 if log_type == 'file' and not log_file: 
    266                     raise TracError(_('You must specify a log file'), 
    267                                     _('Missing field')) 
    268             else: 
    269                 self.config.remove('logging', 'log_file') 
    270                 changed = True 
    271296 
     297                if log_type == 'file': 
     298                    new_file = req.args.get('log_file', 'trac.log') 
     299                    if new_file != log_file: 
     300                        self.config.set('logging', 'log_file', new_file or '') 
     301                        changed = True 
     302                        log_file = new_file 
     303                    if log_type == 'file' and not log_file: 
     304                        raise TracError(_('You must specify a log file'), 
     305                                        _('Missing field')) 
     306                else: 
     307                    self.config.remove('logging', 'log_file') 
     308                    changed = True 
    272309            if changed: 
    273310                self.config.save() 
    274311            req.redirect(req.href.admin(cat, page)) 
    … …  
    276313        data = { 
    277314            'type': log_type, 'types': log_types, 
    278315            'level': log_level, 'levels': log_levels, 
    279             'file': log_file, 'dir': log_dir 
     316            'file': log_file, 'dir': log_dir, 
     317            'filters': log_filters 
    280318        } 
    281319        return 'admin_logging.html', {'log': data} 
    282320 

  • 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

     
    3838        distributions, errors = working_set.find_plugins( 
    3939            pkg_resources.Environment(search_path) 
    4040        ) 
     41        log = env.get_logger(__name__) 
    4142        for dist in distributions: 
    42             env.log.debug('Adding plugin %s from %s', dist, dist.location) 
     43            log.debug('Adding plugin %s from %s', dist, dist.location) 
    4344            working_set.add(dist) 
    4445 
    4546        def _log_error(item, e): 
    4647            if isinstance(e, DistributionNotFound): 
    47                 env.log.warning('Skipping "%s": ("%s" not found)', item, e) 
     48                log.warning('Skipping "%s": ("%s" not found)', item, e) 
    4849            elif isinstance(e, VersionConflict): 
    49                 env.log.error('Skipping "%s": (version conflict "%s")', 
    50                               item, e) 
     50                log.error('Skipping "%s": (version conflict "%s")', item, e) 
    5151            elif isinstance(e, UnknownExtra): 
    52                 env.log.error('Skipping "%s": (unknown extra "%s")', item, e) 
     52                log.error('Skipping "%s": (unknown extra "%s")', item, e) 
    5353            elif isinstance(e, ImportError): 
    54                 env.log.error('Skipping "%s": (can\'t import "%s")', item, e) 
     54                log.error('Skipping "%s": (can\'t import "%s")', item, e) 
    5555            else: 
    56                 env.log.error('Skipping "%s": (error "%s")', item, e) 
     56                log.error('Skipping "%s": (error "%s")', item, e) 
    5757 
    5858        for dist, e in errors.iteritems(): 
    5959            _log_error(dist, e) 
    6060 
    6161        for entry in working_set.iter_entry_points(entry_point_name): 
    62             env.log.debug('Loading %s from %s', entry.name, 
    63                           entry.dist.location) 
     62            log.debug('Loading %s from %s', entry.name, entry.dist.location) 
    6463            try: 
    6564                entry.load(require=True) 
    6665            except (ImportError, DistributionNotFound, VersionConflict, 
    … …  
    7776    manager if they define any components. 
    7877    """ 
    7978    def _load_py_files(env, search_path, auto_enable=None): 
     79        log = env.get_logger(__name__) 
    8080        for path in search_path: 
    8181            plugin_files = glob(os.path.join(path, '*.py')) 
    8282            for plugin_file in plugin_files: 
    8383                try: 
    8484                    plugin_name = os.path.basename(plugin_file[:-3]) 
    85                     env.log.debug('Loading file plugin %s from %s' % \ 
    86                                   (plugin_name, plugin_file)) 
     85                    log.debug('Loading file plugin %s from %s', 
     86                              plugin_name, plugin_file) 
    8787                    if plugin_name not in sys.modules: 
    8888                        module = imp.load_source(plugin_name, plugin_file) 
    8989                    if path == auto_enable: 
    9090                        _enable_plugin(env, plugin_name) 
    9191                except Exception, e: 
    92                     env.log.error('Failed to load plugin from %s', plugin_file, 
    93                                   exc_info=True) 
     92                    log.error('Failed to load plugin from %s', plugin_file, 
     93                              exc_info=True) 
    9494 
    9595    return _load_py_files 
    9696 

  • 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

     
    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() 
    … …  
    103104        # so that session doesn't get purged 
    104105        if now - self.last_visit > UPDATE_INTERVAL: 
    105106            self.last_visit = now 
    106             self.env.log.info("Refreshing session %s" % self.sid) 
     107            self.log.info("Refreshing session %s", self.sid) 
    107108            cursor.execute('UPDATE session SET last_visit=%s ' 
    108109                           'WHERE sid=%s AND authenticated=%s', 
    109110                           (self.last_visit, self.sid, authenticated)) 
    110111            # Purge expired sessions. We do this only when the session was 
    111112            # changed as to minimize the purging. 
    112113            mintime = now - PURGE_AGE 
    113             self.env.log.debug('Purging old, expired, sessions.') 
     114            self.log.debug('Purging old, expired, sessions.') 
    114115            cursor.execute("DELETE FROM session_attribute " 
    115116                           "WHERE authenticated=0 AND sid " 
    116117                           "IN (SELECT sid FROM session WHERE " 
    … …  
    174175            raise TracError(Markup('Session "%s" already exists.<br />' 
    175176                                   'Please choose a different session ID.') 
    176177                            % new_sid, 'Error renaming session') 
    177         self.env.log.debug('Changing session ID %s to %s' % (self.sid, new_sid)) 
     178        self.log.debug('Changing session ID %s to %s', self.sid, new_sid) 
    178179        cursor.execute("UPDATE session SET sid=%s WHERE sid=%s " 
    179180                       "AND authenticated=0", (new_sid, self.sid)) 
    180181        cursor.execute("UPDATE session_attribute SET sid=%s " 
    … …  
    208209            if not authenticated_flags[0]: 
    209210                # Update the anomymous session records so that the session ID 
    210211                # becomes the user name, and set the authenticated flag. 
    211                 self.env.log.debug('Promoting anonymous session %s to ' 
    212                                    'authenticated session for user %s', 
    213                                    sid, self.req.authname) 
     212                self.log.debug('Promoting anonymous session %s to ' 
     213                               'authenticated session for user %s', 
     214                               sid, self.req.authname) 
    214215                cursor.execute("UPDATE session SET sid=%s,authenticated=1 " 
    215216                               "WHERE sid=%s AND authenticated=0", 
    216217                               (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")