further changes to ConflictError logging:

- all conflict errors are counted and logged at info, as they were before Florent's change
- 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)

lib/python/ZPublisher/tests/generate_conflicts.py

+## This script requires:
+## - python2.4
+## - Zope 3's zope.testbrowser package:
+##   http://www.zope.org/Members/benji_york/ZopeTestbrowser-0.9.0.tgz
+##
+## The just run:
+## $python2.4 generate_conflicts.py
+import base64
+import string
+import threading
+import urllib2
+
+from zope.testbrowser.browser import Browser
+
+# create our browser
+class AuthBrowser(Browser):
+
+    def addBasicAuth(self,username,password):        
+        self.addHeader(
+            'Authorization',
+            'Basic '+base64.encodestring(username+':'+password).strip()
+            )
+
+    def open(self,uri,include_server=True):
+        if include_server:
+            uri = server+uri
+        return Browser.open(self,uri)
+
+browser = AuthBrowser()
+
+# constants
+server = 'http://localhost:8080'
+# the following user must be able to view the management screens
+# and create file objects
+username = 'username'
+password = 'password'
+browser.addBasicAuth(username,password)
+threads = 10
+filename = 'conflict.txt'
+filesize = 10000
+hits = 5
+
+# delete the file if it's already there
+browser.open('/manage_main')
+if filename in [c.optionValue
+                for c in browser.getControl(name='ids:list').controls]:
+    browser.open('/manage_delObjects?ids:list='+filename)
+
+# create it
+browser.open('/manage_addFile?id='+filename)
+
+# edit it, hopefully causing conflicts
+data = 'X'*filesize
+class EditThread(threading.Thread):
+
+    def __init__(self,i):
+        self.conflicts = 0
+        self.browser = AuthBrowser()
+        self.browser.handleErrors = False
+        self.browser.addBasicAuth(username,password)
+        threading.Thread.__init__(self,name=str(i))
+        
+    def run(self):
+        for i in range(1,hits+1):            
+            self.browser.open('/conflict.txt/manage_main')
+            self.browser.getControl(name='title').value='Test Title'
+            self.browser.getControl(name='filedata:text').value = data
+            try:
+                self.browser.getControl(name='manage_edit:method').click()
+            except urllib2.HTTPError,e:
+                # print e.read()
+                self.conflicts += 1
+                print "Thread %s - CONFLICT" % self.getName()
+            else:
+                print "Thread %s - EDIT" % self.getName()
+
+thread_objects = []
+for i in range(1,threads+1):
+    t = EditThread(i)
+    thread_objects.append(t)
+    t.start()
+for t in thread_objects:
+    t.join()
+total = 0
+print
+for t in thread_objects:
+    print "Thread %s - %i conflicts seen" % (t.getName(),t.conflicts)
+    total += t.conflicts
+print
+print "%i conflicts seen by browsers" % total
+

lib/python/Zope2/App/startup.py

@@ -18,9 +18,9 @@ from AccessControl.SecurityManagement import newSecurityManager
 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, ERROR, WARNING, INFO, BLATHER, log_time
 from ZODB.POSException import ConflictError
 import transaction
 import AccessControl.User
@@ -28,6 +28,7 @@ import App.FindHomes
 import ExtensionClass
 import Globals
 import imp
+import logging
 import OFS.Application
 import os
 import sys
@@ -103,7 +104,7 @@ def startup():
     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 @@ class RequestContainer(ExtensionClass.Base):
     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,25 +148,31 @@ def zpublisher_exception_hook(published, REQUEST, t, v, traceback):
             if t is SystemExit:
                 raise
             if issubclass(t, ConflictError):
-                global conflict_errors
                 conflict_errors = conflict_errors + 1
-                method_name = REQUEST.get('PATH_INFO', '')
-                LOG('ZODB', BLATHER, "%s at %s: %s"
-                    " (%s conflicts since startup at %s)"
-                    % (v.__class__.__name__, method_name, v,
-                       conflict_errors, startup_time),
-                    error=(t, v, traceback))
+                # 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:
-                # An exception that can't be retried anymore
-                # Retrieve the original exception
-                try: v.reraise()
-                except: t, v, traceback = sys.exc_info()
-                # Log it as ERROR
-                method_name = REQUEST.get('PATH_INFO', '')
-                LOG('Publisher', ERROR, "Unhandled %s at %s: %s"
-                    % (v.__class__.__name__, method_name, v))
-                # Then fall through to display the error to the user
+                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)