TypeError: 'Logger' object is not callable

[John Shue <john@…>]

How to Reproduce

While doing a GET operation on /timeline, Trac issued an internal error.

Additional details:

This error also occurs when accessing the /browser URL. The issue appears to be caused by a member name collision in the tracext.hg.backend.trac_ui class. The trac_ui class uses trac_ui.log to store a Logger object, but the mercurial.ui base class is using log as a member function:

 def log(self, service, *msg, **opts):
        '''hook for logging facility extensions

        service should be a readily-identifiable subsystem, which will
        allow filtering.
        message should be a newline-terminated string to log.
        '''
        pass

The exception is raised when the mercurial.tags._readtagcache function is expecting trac_ui.log to be a function, when it is an instance of Logger. Here is the code from _readtagcache:

    ui.log('tagscache',
           'resolved %d tags cache entries from %d manifests in %0.4f '
           'seconds\n',
           len(cachefnode), len(newheads), duration)

I was able to fix the error by altering the code in backend.py to rename the trac_ui.log member to trac_ui._log:

--- backend.py  2014-07-28 09:37:09.000000000 -0400
+++ backend.py.new      2014-07-28 09:36:52.000000000 -0400
@@ -181,15 +181,15 @@
     def __init__(self, *args, **kwargs):
         ui.__init__(self, *args)
         self.setconfig('ui', 'interactive', 'off')
-        self.log = kwargs.get('log', args and args[0].log or None)
+        self._log = kwargs.get('log', args and args[0]._log or None)

     def write(self, *args, **opts):
         for a in args:
-            self.log.info('(mercurial status) %s', a)
+            self._log.info('(mercurial status) %s', a)

     def write_err(self, *args, **opts):
         for a in args:
-            self.log.warn('(mercurial warning) %s', a)
+            self._log.warn('(mercurial warning) %s', a)

     def plain(self, *args, **kw):
         return False # so that '[hg] hgrc' file can specify [ui] options

Request parameters:

{}

User agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/34.0.1847.131 Safari/537.36

System Information

Trac	1.0
Docutils	0.11
Genshi	0.7 (with speedups)
Mercurial	3.0
mod_wsgi	3.4 (WSGIProcessGroup WSGIApplicationGroup %{GLOBAL})
Pygments	1.6
pysqlite	2.6.0
Python	2.7.6 (default, May 15 2014, 18:23:58) [GCC 4.2.1 Compatible FreeBSD Clang 3.3 (tags/RELEASE_33/final 183502)]
pytz	2014.3
setuptools	2.0.1
SQLite	3.8.4.3
jQuery	1.7.2

Enabled Plugins

TracMercurial

1.0.0.3dev

Python Traceback

Traceback (most recent call last):
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/web/main.py", line 497, in _dispatch_request
    dispatcher.dispatch(req)
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/web/main.py", line 233, in dispatch
    content_type)
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/web/chrome.py", line 1000, in render_template
    encoding='utf-8')
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/core.py", line 184, in render
    return encode(generator, method=method, encoding=encoding, out=out)
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/output.py", line 58, in encode
    for chunk in iterator:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/output.py", line 350, in __call__
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/output.py", line 829, in __call__
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/output.py", line 669, in __call__
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/output.py", line 774, in __call__
    for kind, data, pos in chain(stream, [(None, None, None)]):
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/output.py", line 594, in __call__
    for ev in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/core.py", line 289, in _ensure
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/core.py", line 289, in _ensure
    for event in stream:
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/web/chrome.py", line 1137, in _strip_accesskeys
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/core.py", line 289, in _ensure
    for event in stream:
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/web/chrome.py", line 1126, in _generate
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 618, in _include
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/markup.py", line 378, in _match
    ctxt, start=idx + 1, **vars):
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/markup.py", line 378, in _match
    ctxt, start=idx + 1, **vars):
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/markup.py", line 326, in _match
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 558, in _flatten
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/core.py", line 289, in _ensure
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/path.py", line 588, in _generate
    subevent = next()
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 618, in _include
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/markup.py", line 315, in _strip
    event = next()
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 558, in _flatten
    for kind, data, pos in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/core.py", line 289, in _ensure
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/path.py", line 588, in _generate
    subevent = next()
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 618, in _include
    for event in stream:
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/markup.py", line 315, in _strip
    event = next()
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 578, in _flatten
    result = _eval_expr(data, ctxt, vars)
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/base.py", line 289, in _eval_expr
    retval = expr.evaluate(ctxt)
  File "/usr/local/lib/python2.7/site-packages/Genshi-0.7-py2.7-freebsd-10.0-RELEASE-p3-i386.egg/genshi/template/eval.py", line 177, in evaluate
    return eval(self.code, _globals, {'__data__': data})
  File "/usr/local/www/apache22/trac/eggs/Trac-1.0-py2.7.egg-tmp/trac/timeline/templates/timeline.html", line 49, in <Expression u"event.render('title', context)">
    <span class="time">${format_time(event.date, 'short')}</span> ${event.render('title', context)}
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/timeline/web_ui.py", line 355, in <lambda>
    provider.render_timeline_event(context, field, event)
  File "build/bdist.freebsd-10.0-RELEASE-i386/egg/trac/versioncontrol/web_ui/changeset.py", line 1037, in render_timeline_event
    for name in cset.get_tags():
  File "/usr/home/jshue/working/mercurial-plugin/tracext/hg/backend.py", line 1322, in get_tags
    return [self.repos.to_u(t) for t in self.ctx.tags()]
  File "/usr/local/lib/python2.7/site-packages/mercurial/context.py", line 369, in tags
    return self._repo.nodetags(self._node)
  File "/usr/local/lib/python2.7/site-packages/mercurial/localrepo.py", line 675, in nodetags
    if not self._tagscache.nodetagscache:
  File "/usr/local/lib/python2.7/site-packages/mercurial/util.py", line 287, in __get__
    result = self.func(obj)
  File "/usr/local/lib/python2.7/site-packages/mercurial/localrepo.py", line 598, in _tagscache
    cache.tags, cache.tagtypes = self._findtags()
  File "/usr/local/lib/python2.7/site-packages/mercurial/localrepo.py", line 635, in _findtags
    tagsmod.findglobaltags(self.ui, self, alltags, tagtypes)
  File "/usr/local/lib/python2.7/site-packages/mercurial/tags.py", line 31, in findglobaltags
    (heads, tagfnode, cachetags, shouldwrite) = _readtagcache(ui, repo)
  File "/usr/local/lib/python2.7/site-packages/mercurial/tags.py", line 261, in _readtagcache
    len(cachefnode), len(newheads), duration)
TypeError: 'Logger' object is not callable