Edgewall Software
Modify

Opened 3 years ago

Closed 2 years ago

Last modified 2 years ago

#12680 closed defect (fixed)

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

Reported by: Christian Boos Owned by: Christian Boos
Priority: normal Milestone: 1.3.2
Component: rendering Version: 1.3dev
Severity: normal Keywords:
Cc: Branch:
Release Notes:

Improved exception trapping and logging when executing ExtensionPoints: IEnvironmentSetupParticipant, INavigationContributor and ITimelineEventProvider.

API Changes:

Added context managers for wrapping execution of extension point methods:

  • Environment.component_guard in trac.env, which logs a TracError at warning level, and a Exception a error level with a traceback.
  • component_guard in trac.web.chrome, which executes Environment.component_guard and also renders a warning.

Description

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)

Attachments (2)

Screen Shot 2017-05-21 at 15.50.50.png (42.6 KB ) - added by Ryan J Ollos 2 years ago.
Screen Shot 2017-05-21 at 15.51.14.png (18.2 KB ) - added by Ryan J Ollos 2 years ago.

Download all attachments as: .zip

Change History (18)

comment:1 by Ryan J Ollos, 3 years ago

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.

comment:3 by Ryan J Ollos, 3 years ago

Fix committed in th:r16224.

in reply to:  1 comment:4 by Christian Boos, 3 years ago

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.

comment:5 by Christian Boos, 3 years ago

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

  • trac/env.py

     
    1616
    1717"""Trac Environment model and related APIs."""
    1818
     19from contextlib import contextmanager
    1920import hashlib
    2021import os.path
    2122import setuptools
     
    354355        self._component_rules[self._component_name(cls)] = True
    355356        super(Environment, self).enable_component(cls)
    356357
     358    @contextmanager
     359    def component_guard(self, component):
     360        """Swallows any runtime exception raised when working with a component
     361        and logs the error.
     362
     363        """
     364        try:
     365            yield
     366        except Exception as e:
     367            self.log.error("component %s failed with %s", component,
     368                           exception_to_unicode(e, traceback=True))
     369
    357370    def verify(self):
    358371        """Verify that the provided path points to a valid Trac environment
    359372        directory."""
  • trac/wiki/model.py

     
    175175        self.time = t
    176176
    177177        for listener in WikiSystem(self.env).change_listeners:
    178             if self.version == 1:
    179                 listener.wiki_page_added(self)
    180             else:
    181                 listener.wiki_page_changed(self, self.version, t, comment,
    182                                            author)
     178            with self.env.component_guard(listener):
     179                if self.version == 1:
     180                    listener.wiki_page_added(self)
     181                else:
     182                    listener.wiki_page_changed(self, self.version, t, comment,
     183                                               author)
    183184
    184185        self.old_readonly = self.readonly
    185186        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

    diff --git a/trac/web/chrome.py b/trac/web/chrome.py
    index 1b76dd58c..48d4ae0c8 100644
    a b other forms of web content are also using facilities provided here.  
    2222
    2323"""
    2424
     25from contextlib import contextmanager
    2526import datetime
    2627from functools import partial
    2728import itertools
    def _save_messages(req, url, permanent):  
    387388        for (i, message) in enumerate(req.chrome[type_]):
    388389            req.session['chrome.%s.%d' % (type_, i)] = escape(message, False)
    389390
     391           
     392@contextmanager
     393def component_guard(env, req, component):
     394    """Swallows any runtime exception raised when working with a
     395    component, logs the error and adds a warning for the user.
     396
     397    """
     398    with env.component_guard(component):
     399        try:
     400            yield
     401        except Exception as e:
     402            req.add_warning(_("Component %(component)s failed with %(exc)s",
     403                              component=component, exc=exception_to_unicode(e)))
     404            raise
     405
    390406
    391407class Chrome(Component):
    392408    """Web site chrome assembly manager.

(untested)

comment:6 by Ryan J Ollos, 3 years ago

Those changes look really nice!

comment:7 by Christian Boos, 3 years ago

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)
Last edited 3 years ago by Ryan J Ollos (previous) (diff)

comment:8 by Christian Boos, 3 years ago

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?

comment:9 by Ryan J Ollos, 3 years ago

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)

in reply to:  9 ; comment:10 by Christian Boos, 3 years ago

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 ;-)

in reply to:  10 comment:11 by Christian Boos, 3 years ago

See new branch:

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

comment:12 by Ryan J Ollos, 3 years ago

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.

comment:13 by Christian Boos, 3 years ago

Owner: set to Christian Boos
Status: newassigned

by Ryan J Ollos, 2 years ago

by Ryan J Ollos, 2 years ago

comment:14 by Ryan J Ollos, 2 years ago

API Changes: modified (diff)
Owner: changed from Christian Boos to Ryan J Ollos
Release Notes: modified (diff)
  • 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.

comment:15 by Ryan J Ollos, 2 years ago

Resolution: fixed
Status: assignedclosed

Committed to trunk in r15939.

comment:16 by Ryan J Ollos, 2 years ago

Owner: changed from Ryan J Ollos to Christian Boos

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Christian Boos.
The resolution will be deleted. Next status will be 'reopened'.
to as closed The owner will be changed from Christian Boos to the specified user.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.