Log message for revision 40476: Merge error reporting changes from trunk: - remove unused import. - change SimpleItem.py to use python logging module - log at error when standard_error_message can't be rendered - give more useful info about errors rendering standard_error_message to the browser. - all conflict errors are counted and logged at info - logging makes it clear where the conflict has been resolved and where it hasn't - errors seen by the user are rendered with standard_error_message and are sent to the error_log which will likely copy them to the event log, depending on the users setup. - also checking in a functional test for generating write conflict errors. (I'll be committing to CHANGES.TXT shortly, I just wanted to keep the merges simpler)
Changed: U Zope/branches/Zope-2_8-branch/lib/python/OFS/SimpleItem.py U Zope/branches/Zope-2_8-branch/lib/python/Products/Transience/Transience.py A Zope/branches/Zope-2_8-branch/lib/python/ZPublisher/tests/generate_conflicts.py U Zope/branches/Zope-2_8-branch/lib/python/Zope2/App/startup.py -=- Modified: Zope/branches/Zope-2_8-branch/lib/python/OFS/SimpleItem.py =================================================================== --- Zope/branches/Zope-2_8-branch/lib/python/OFS/SimpleItem.py 2005-12-02 15:10:44 UTC (rev 40475) +++ Zope/branches/Zope-2_8-branch/lib/python/OFS/SimpleItem.py 2005-12-02 15:44:31 UTC (rev 40476) @@ -30,10 +30,10 @@ from AccessControl import getSecurityManager, Unauthorized from AccessControl.ZopeSecurityPolicy import getRoles from Acquisition import aq_base, aq_parent, aq_inner, aq_acquire +from DocumentTemplate.html_quote import html_quote from DocumentTemplate.ustr import ustr from zExceptions.ExceptionFormatter import format_exception from zExceptions import Redirect -from zLOG import LOG, BLATHER from CopySupport import CopySource from Traversable import Traversable @@ -41,6 +41,8 @@ HTML=Globals.HTML +import logging +logger = logging.getLogger() class Item(Base, Resource, CopySource, App.Management.Tabs, Traversable, ZDOM.Element, @@ -210,17 +212,21 @@ else: v = HTML.__call__(s, client, REQUEST, **kwargs) except: - LOG('OFS', BLATHER, + logger.error( 'Exception while rendering an error message', - error=sys.exc_info()) + exc_info=True + ) try: strv = str(error_value) except: strv = ('<unprintable %s object>' % str(type(error_value).__name__)) v = strv + ( - " (Also, an error occurred while attempting " - "to render the standard error message.)") + (" (Also, the following error occurred while attempting " + "to render the standard error message, please see the " + "event log for full details: %s)")%( + html_quote(sys.exc_info()[1]), + )) raise error_type, v, tb finally: if hasattr(self, '_v_eek'): del self._v_eek Modified: Zope/branches/Zope-2_8-branch/lib/python/Products/Transience/Transience.py =================================================================== --- Zope/branches/Zope-2_8-branch/lib/python/Products/Transience/Transience.py 2005-12-02 15:10:44 UTC (rev 40475) +++ Zope/branches/Zope-2_8-branch/lib/python/Products/Transience/Transience.py 2005-12-02 15:44:31 UTC (rev 40476) @@ -36,7 +36,6 @@ from Persistence import Persistent from OFS.SimpleItem import SimpleItem -from ZPublisher.Publish import Retry from AccessControl import ClassSecurityInfo, getSecurityManager from AccessControl.SecurityManagement import newSecurityManager, \ setSecurityManager Copied: Zope/branches/Zope-2_8-branch/lib/python/ZPublisher/tests/generate_conflicts.py (from rev 40472, Zope/trunk/lib/python/ZPublisher/tests/generate_conflicts.py) Property changes on: Zope/branches/Zope-2_8-branch/lib/python/ZPublisher/tests/generate_conflicts.py ___________________________________________________________________ Name: svn:eol-style + native Modified: Zope/branches/Zope-2_8-branch/lib/python/Zope2/App/startup.py =================================================================== --- Zope/branches/Zope-2_8-branch/lib/python/Zope2/App/startup.py 2005-12-02 15:10:44 UTC (rev 40475) +++ Zope/branches/Zope-2_8-branch/lib/python/Zope2/App/startup.py 2005-12-02 15:44:31 UTC (rev 40476) @@ -18,9 +18,9 @@ from AccessControl.SecurityManagement import noSecurityManager from Acquisition import aq_acquire from App.config import getConfiguration +from time import asctime from types import StringType, ListType from zExceptions import Unauthorized -from zLOG import LOG, WARNING, INFO, BLATHER, log_time from ZODB.POSException import ConflictError import transaction import AccessControl.User @@ -28,6 +28,7 @@ import ExtensionClass import Globals import imp +import logging import OFS.Application import os import sys @@ -103,7 +104,7 @@ noSecurityManager() global startup_time - startup_time = log_time() + startup_time = asctime() Zope2.zpublisher_transactions_manager = TransactionsManager() Zope2.zpublisher_exception_hook = zpublisher_exception_hook @@ -132,8 +133,13 @@ def __init__(self,r): self.REQUEST=r conflict_errors = 0 +unresolved_conflict_errors = 0 +conflict_logger = logging.getLogger('ZODB.Conflict') + def zpublisher_exception_hook(published, REQUEST, t, v, traceback): + global unresolved_conflict_errors + global conflict_errors try: if isinstance(t, StringType): if t.lower() in ('unauthorized', 'redirect'): @@ -142,20 +148,31 @@ if t is SystemExit: raise if issubclass(t, ConflictError): - # First, we need to close the current connection. We'll - # do this by releasing the hold on it. There should be - # some sane protocol for this, but for now we'll use - # brute force: - global conflict_errors conflict_errors = conflict_errors + 1 - method_name = REQUEST.get('PATH_INFO', '') - err = ('ZODB conflict error at %s ' - '(%s conflicts since startup at %s)') - LOG(err % (method_name, conflict_errors, startup_time), - INFO, '') - LOG('Conflict traceback', BLATHER, '', error=sys.exc_info()) + # This logs _all_ conflict errors + conflict_logger.info( + '%s at %s (%i conflicts, of which %i' + ' were unresolved, since startup at %s)', + v, + REQUEST.get('PATH_INFO', '<unknown>'), + conflict_errors, + unresolved_conflict_errors, + startup_time + ) + # This debug logging really doesn't help a lot... + conflict_logger.debug('Conflict traceback',exc_info=True) raise ZPublisher.Retry(t, v, traceback) - if t is ZPublisher.Retry: v.reraise() + if t is ZPublisher.Retry: + try: + v.reraise() + except: + # we catch the re-raised exception so that it gets + # stored in the error log and gets rendered with + # standard_error_message + t, v, traceback = sys.exc_info() + if issubclass(t, ConflictError): + # ouch, a user saw this conflict error :-( + unresolved_conflict_errors += 1 try: log = aq_acquire(published, '__error_log__', containment=1) @@ -204,6 +221,7 @@ finally: traceback=None +ac_logger = logging.getLogger('event.AccessControl') class TransactionsManager: def begin(self, @@ -220,7 +238,7 @@ def recordMetaData(self, object, request, # Optimize global var lookups: hasattr=hasattr, getattr=getattr, - LOG=LOG, WARNING=WARNING, + logger=ac_logger, ): request_get = request.get if hasattr(object, 'getPhysicalPath'): _______________________________________________ Zope-Checkins maillist - Zope-Checkins@zope.org http://mail.zope.org/mailman/listinfo/zope-checkins