[Zope3-checkins] SVN: Zope3/branches/srichter-twisted-integration/src/zope/app/server/ As promised, here are the tests for the logging code.

[Stephan Richter]

Log message for revision 30070:
  As promised, here are the tests for the logging code.
  

Changed:
  U   Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.py
  A   Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.txt
  U   Zope3/branches/srichter-twisted-integration/src/zope/app/server/tests/test_docs.py

-=-
Modified: Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.py
===================================================================
--- Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.py	2005-04-21 00:26:02 UTC (rev 30069)
+++ Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.py	2005-04-21 00:30:12 UTC (rev 30070)
@@ -81,13 +81,14 @@
             request.method,
             request.uri,
             '.'.join([str(x) for x in request.clientproto]))
-
+        
         self.logger.log(logging.INFO,
             '%s - %s [%s] "%s" %s %d "%s" "%s"' %(
                 request.chanRequest.transport.client[0],
                 request.response.headers.getRawHeaders(
                     'x-zope-principal', ['anonymous'])[-1],
-                self.logDateString(response.headers.getHeader('date', 0)),
+                self.logDateString(
+                    request.response.headers.getHeader('date', time.time())),
                 firstLine,
                 request.response.code,
                 request.bytesSent,

Added: Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.txt
===================================================================
--- Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.txt	2005-04-21 00:26:02 UTC (rev 30069)
+++ Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.txt	2005-04-21 00:30:12 UTC (rev 30070)
@@ -0,0 +1,84 @@
+=====================
+Logging using Twisted
+=====================
+
+In order to have access logs when using the Twisted servers, the best way is
+to hook into Twisted's logging framework. Thus we provide a logging observer
+that creates and emits a log entry via the standard Python logging
+framework. Note that this logging object *is* Twisted-dependent:
+
+Before we can create the observer and emit new log entries, we need to create
+a standard Python logger object that writes to an IO object that we can
+observe:
+
+  >>> import cStringIO
+  >>> logfile = cStringIO.StringIO()
+
+  >>> import logging
+  >>> logger = logging.getLogger('accesslog')
+  >>> logger.setLevel(logging.INFO)
+  >>> handler = logging.StreamHandler(logfile)
+  >>> handler.setFormatter(logging.Formatter('%(message)s'))
+  >>> logger.addHandler(handler)
+
+Now we create the observer for the access log:
+
+  >>> from zope.app.server import log
+  >>> observer = log.CommonAccessLoggingObserver()
+
+To start listening to Twisted logging calls, simply call ``start()``:
+
+  >>> import twisted.python.log
+  >>> observer.emit in twisted.python.log.theLogPublisher.observers
+  False
+  >>> observer.start()
+  >>> observer.emit in twisted.python.log.theLogPublisher.observers
+  True
+
+When the system emits an arbitrary log request, the observer does nothing
+
+  >>> from twisted.web2 import http, http_headers, iweb
+  >>> twisted.python.log.msg('foo bar')
+  >>> logfile.getvalue()
+  ''
+
+because it is listening only to specific log dictionaries. The dictionary must
+contain an `interface` key that specifies ``web2.iweb.IRequest`` and a `request`
+key that contains the HTTP request implementing ``web2.iweb.IRequest``:
+
+  >>> chanRequest = http.HTTPChannelRequest(None, 'GET /index.html HTTP/1.1', 1)
+  >>> chanRequest.transport.client = ('127.0.0.1', 0)
+  >>> request = http.Request(chanRequest, 'GET', '/index.html', (1, 1),
+  ...                        http_headers.Headers())
+  >>> request.response = http.Response()
+
+  >>> eventDict = {'interface': iweb.IRequest, 'request': request}
+
+If we now emit a log event, we should receive an entry:
+
+  >>> twisted.python.log.msg(**eventDict)
+  >>> print logfile.getvalue() #doctest: +ELLIPSIS
+  127.0.0.1 - anonymous [...] "GET /index.html HTTP/1.1" 200 0 "-" "-"
+  <BLANKLINE>
+
+If I now set the `referer` and `user-agent` headers, we get some more output:
+
+  >>> logfile = cStringIO.StringIO()
+  >>> handler.stream = logfile
+
+  >>> request.headers.setHeader('referer', 'http://localhost:8080/manage')
+  >>> request.headers.setHeader('user-agent', 'Mozilla 1.7')
+
+  >>> twisted.python.log.msg(**eventDict)
+  >>> print logfile.getvalue() #doctest: +ELLIPSIS
+  127.0.0.1 - anonymous [...] "GET /index.html HTTP/1.1" 200 0 
+  "http://localhost:8080/manage" "Mozilla 1.7"
+  <BLANKLINE>
+
+Finally, to end listening to Twisted logging calls, simply call ``stop()``:
+
+  >>> observer.emit in twisted.python.log.theLogPublisher.observers
+  True
+  >>> observer.stop()
+  >>> observer.emit in twisted.python.log.theLogPublisher.observers
+  False


Property changes on: Zope3/branches/srichter-twisted-integration/src/zope/app/server/log.txt
___________________________________________________________________
Name: svn:eol-style
   + native

Modified: Zope3/branches/srichter-twisted-integration/src/zope/app/server/tests/test_docs.py
===================================================================
--- Zope3/branches/srichter-twisted-integration/src/zope/app/server/tests/test_docs.py	2005-04-21 00:26:02 UTC (rev 30069)
+++ Zope3/branches/srichter-twisted-integration/src/zope/app/server/tests/test_docs.py	2005-04-21 00:30:12 UTC (rev 30070)
@@ -51,6 +51,9 @@
                              setUp=setUp, tearDown=tearDown,
                              globs={'pprint': doctestunit.pprint},
                              optionflags=doctest.NORMALIZE_WHITESPACE),
+        doctest.DocFileSuite('../log.txt',
+                             globs={'pprint': doctestunit.pprint},
+                             optionflags=doctest.NORMALIZE_WHITESPACE),
         ))