TypeError: wiki_page_changed() takes exactly 7 arguments (6 given)

[Christian Boos]

How to Reproduce

While doing a POST operation on /wiki/TracDev/PortingFromGenshiToJinja/Checker, Trac issued an internal error.

One of the plugins didn't like [15027]…

Request parameters:

{u'__FORM_TOKEN': u'0597b3a863295b65050cb277',
 u'action': u'edit',
 u'comment': u'',
 u'from_editor': u'1',
 'page': u'TracDev/PortingFromGenshiToJinja/Checker',
 u'save': u'Enregistrer les modifications',
 u'scroll_bar_pos': u'0',
 u'sidebyside': u'on',
 u'text': u'See [wiki:"TracDev/JinjaChecker"].',
 u'version': u'1'}

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

System Information

Trac	1.3.2.dev0
Babel	2.3.4
dnspython	1.12.0
Docutils	0.12
Genshi	0.7 (with speedups)
GIT	2.1.4
Jinja2	2.9.5
Mercurial	3.1.2
mod_wsgi	4.5.13 (WSGIProcessGroup trac WSGIApplicationGroup %{GLOBAL})
Pillow	2.6.1
PostgreSQL	server: 9.4.10, client: 9.4.10
psycopg2	2.5.4
Pygments	2.0.1
Python	2.7.9 (default, Jun 29 2016, 13:11:10) [GCC 4.9.2]
pytz	2012c
setuptools	18.2
SpamBayes	1.1b1
Subversion	1.8.10 (r1615264)
jQuery	1.11.3
jQuery UI	1.11.4
jQuery Timepicker	1.5.5

Enabled Plugins

help-guide-version-notice	N/A
milestone-to-version	r15098
StatusFixer	r6326
TracMercurial	1.0.0.7.dev0
TracSpamFilter	1.3.0.dev0
TracVote	0.6.0.dev0
TracWikiExtras	1.3.1.dev0
TranslatedPagesMacro	0.5

Interface Customization

shared-htdocs
shared-templates
site-htdocs
site-templates	site.html, site_leftbox.html

Python Traceback

Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/trac/web/main.py", line 630, in _dispatch_request
    dispatcher.dispatch(req)
  File "build/bdist.linux-x86_64/egg/trac/web/main.py", line 252, in dispatch
    resp = chosen_handler.process_request(req)
  File "build/bdist.linux-x86_64/egg/trac/wiki/web_ui.py", line 146, in process_request
    return self._do_save(req, versioned_page)
  File "build/bdist.linux-x86_64/egg/trac/wiki/web_ui.py", line 359, in _do_save
    page.save(get_reporter_id(req, 'author'), req.args.get('comment'))
  File "build/bdist.linux-x86_64/egg/trac/wiki/model.py", line 182, in save
    author)
TypeError: wiki_page_changed() takes exactly 7 arguments (6 given)

[Ryan J Ollos]

I wonder if there is a way to improve that traceback with a change where wiki_page_changed is called: tags/trac-1.2/trac/wiki/model.py@:191-192,194-195#L185​. Maybe we should catch exceptions and log the name of the listener? Trac might be more robust if listeners that generate an exception were skipped. We could add_warning to a page after skipping a listener.

[Ryan J Ollos]

I'll push a fix for TracVote: ​browser:voteplugin/trunk/tracvote/__init__.py@16141#L421.

[Ryan J Ollos]

Fix committed in ​th:r16224.

[Christian Boos]

Replying to Ryan J Ollos:

I wonder if there is a way to improve that traceback with a change where wiki_page_changed is called: tags/trac-1.2/trac/wiki/model.py@:191-192,194-195#L185​. Maybe we should catch exceptions and log the name of the listener? Trac might be more robust if listeners that generate an exception were skipped. We could add_warning to a page after skipping a listener.

Yes, exactly. When creating the ticket, I wasn't sure if we wanted to have a check on the arity of the listener, but now seeing that you actually removed that check on purpose (I'm OK with that), I think the problem is rather to find a clear way to trap or signal the error. As you can see in the traceback, there's no mention of the tracvote code itself, so this makes troubleshooting the problem quite hard.

So I'm thinking of a context handler which would catch and report any error happening in a component.

Something like:

    for listener in WikiSystem(self.env).change_listeners:
        with component_guard(listener, req):
            if self.version == 1:
                listener.wiki_page_added(self)
            else:
                listener.wiki_page_changed(self, self.version, t, comment,
                                           author)

If component_guard takes a req, it uses it to log a warning in case of errors. We could also add some more arguments to decide precisely what kind of exception we swallow or let pass.

[Christian Boos]

Ok, in this particular case we don't have a req. What about:

trac/env.py

@@ -16 +16 @@
 
 """Trac Environment model and related APIs."""
 
+from contextlib import contextmanager
 import hashlib
 import os.path
 import setuptools
@@ -354 +355 @@
         self._component_rules[self._component_name(cls)] = True
         super(Environment, self).enable_component(cls)
 
+    @contextmanager
+    def component_guard(self, component):
+        """Swallows any runtime exception raised when working with a component
+        and logs the error.
+
+        """
+        try:
+            yield
+        except Exception as e:
+            self.log.error("component %s failed with %s", component,
+                           exception_to_unicode(e, traceback=True))
+
     def verify(self):
         """Verify that the provided path points to a valid Trac environment
         directory."""

trac/wiki/model.py

@@ -175 +175 @@
         self.time = t
 
         for listener in WikiSystem(self.env).change_listeners:
-            if self.version == 1:
-                listener.wiki_page_added(self)
-            else:
-                listener.wiki_page_changed(self, self.version, t, comment,
-                                           author)
+            with self.env.component_guard(listener):
+                if self.version == 1:
+                    listener.wiki_page_added(self)
+                else:
+                    listener.wiki_page_changed(self, self.version, t, comment,
+                                               author)
 
         self.old_readonly = self.readonly
         self.old_text = self.text

Which would log the following error in this specific situation:

14412 Trac[cblaptop-trac:component_guard() in D:\Trac\repos\trunk\trac\env.py:368] ERROR: component <Component tracvote.VoteSystem> failed with 
Traceback (most recent call last):
  File "D:\Trac\repos\trunk\trac\env.py", line 365, in component_guard
    yield
  File "D:\Trac\repos\trunk\trac\wiki\model.py", line 183, in save
    author)
TypeError: wiki_page_changed() takes exactly 7 arguments (6 given)

Besides, we could have another component_guard (e.g. in trac/web/chrome.py) which does add the warning when we have a req available:

trac/web/chrome.py

@@ -22 +22 @@
 
 """
 
+from contextlib import contextmanager
 import datetime
 from functools import partial
 import itertools
@@ -387 +388 @@
         for (i, message) in enumerate(req.chrome[type_]):
             req.session['chrome.%s.%d' % (type_, i)] = escape(message, False)
 
+            
+@contextmanager
+def component_guard(env, req, component):
+    """Swallows any runtime exception raised when working with a
+    component, logs the error and adds a warning for the user.
+
+    """
+    with env.component_guard(component):
+        try:
+            yield
+        except Exception as e:
+            req.add_warning(_("Component %(component)s failed with %(exc)s",
+                              component=component, exc=exception_to_unicode(e)))
+            raise
+
 
 class Chrome(Component):
     """Web site chrome assembly manager.

(untested)

[Ryan J Ollos]

Those changes look really nice!

[Christian Boos]

I think we can even use this approach to simplify the timeline web_ui.py code, which used to do something like that.

Please try out log:cboos.git@t12680-component_guard.

I'd like to generalize the use of this component_guard, but I still wonder if there wouldn't be some even better way to do this, combining the try/except with the iteration on the components. If only we could yield multiple times in the context manager… We could use an inline function and a decorator, a bit like we did with the 0.12 DB API, but it's not that nice either:

        @for_each_component(WikiSystem(self.env).change_listeners):
        def notify(listener):
            if self.version == 1:
                listener.wiki_page_added(self)
            else:
                listener.wiki_page_changed(self, self.version, t, comment, author)

[Christian Boos]

• [2505857e/cboos.git] (#12680) experiment with with_each_component decorators

The (+):

• takes care of the iteration
• one less level of indent

The (-):

• the @ syntax is not nice in the middle of the execution flow
• no possibility to modify variables from the outer context, so we need to pass them as arguments; cumbersome

That was an experiment to force some Rubyesque notions onto Python ;-) Maybe we'll better leave this at the component_guard stage?

[Ryan J Ollos]

Another possible use-case:

2017-02-11 20:08:07,415 Trac[console] ERROR: Exception in trac-admin command: u'upgrade'
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/trac/admin/console.py", line 112, in onecmd
    rv = cmd.Cmd.onecmd(self, line) or 0
  File "/usr/lib/python2.7/cmd.py", line 220, in onecmd
    return self.default(line)
  File "build/bdist.linux-x86_64/egg/trac/admin/console.py", line 291, in default
    return self.cmd_mgr.execute_command(*args)
  File "build/bdist.linux-x86_64/egg/trac/admin/api.py", line 135, in execute_command
    return f(*fargs)
  File "build/bdist.linux-x86_64/egg/trac/env.py", line 949, in _do_upgrade
    self.env.upgrade(backup=no_backup is None)
  File "build/bdist.linux-x86_64/egg/trac/env.py", line 691, in upgrade
    if participant.environment_needs_upgrade():
TypeError: environment_needs_upgrade() takes exactly 2 arguments (1 given)

[Christian Boos]

Replying to Ryan J Ollos:

Another possible use-case:

...
TypeError: environment_needs_upgrade() takes exactly 2 arguments (1 given)

Oh yes, this one made me suffer too ;-)

[Christian Boos]

See new branch:

• [2e9b6775/cboos.git] (#12680) use component_guard during the upgrade process
• [a9352068/cboos.git] (#12680) introduce a component_guard context manager

I think that in the case of an environment upgrade, component errors shouldn't be skipped over, hence the reraise flag.

[Ryan J Ollos]

Looks good. We may be able to partly address #12428. I'll try using the context manager for: tags/trac-1.2/trac/web/chrome.py?marks=819,845-854#L818​.

[Ryan J Ollos]

• The warning displayed when an INavigationContributor fails has changed:
  • Before:
    close Warning: Error with navigation contributor "WikiModule"
  • After:
    close Warning: WikiModule failed with TracError: You did wrong!
    • The exception is still logged at warning level for TracError and error level with traceback otherwise. The main change is that we don't specify to the user that the error came from a "navigation contributor", but that doesn't seem important anyway.
• Similar behavior for timeline event providers, however failing event providers are skipped and add a warning, rather than rendering a TracError in the timeline.
  • Before:
  • After:

Proposed changes in log:rjollos.git:t12680-component_guard.3.

[Ryan J Ollos]

Committed to trunk in r15939.