From 5a7c756a98015da501e56ad248b7a901199f16e9 Mon Sep 17 00:00:00 2001
From: benoitc <bchesneau@gmail.com>
Date: Sat, 25 Feb 2012 14:44:38 +0100
Subject: [PATCH] close #304 .

Intoduce a change in log access format:

- request headers are now added to the log format using the
  {HeaderName}i variable
- response headers are now handled using the {HeaderName}o variables
- headers name are insensitive
- non existent keys in the log access format are replaced by '-'
---
 examples/test.py          |  6 ++++--
 gunicorn/config.py        |  7 +++----
 gunicorn/glogging.py      | 38 +++++++++++++++++++++++++++++++-------
 gunicorn/workers/async.py |  2 +-
 gunicorn/workers/sync.py  |  2 +-
 5 files changed, 40 insertions(+), 15 deletions(-)

diff --git a/examples/test.py b/examples/test.py
index e7db581a..e7f44955 100644
--- a/examples/test.py
+++ b/examples/test.py
@@ -8,16 +8,18 @@
 from wsgiref.validate import validator
 import sys
 
+from gunicorn import __version__
 #@validator
 def app(environ, start_response):
     """Simplest possible application object"""
     data = 'Hello, World!\n'
     status = '200 OK'
     print("print to stdout in test app")
-    sys.stderr.write("stderr, print to stderr in test app")
+    sys.stderr.write("stderr, print to stderr in test app\n")
     response_headers = [
         ('Content-type','text/plain'),
-        ('Content-Length', str(len(data)))
+        ('Content-Length', str(len(data))),
+        ('X-Gunicorn-Version', __version__)
     ]
     start_response(status, response_headers)
     return iter([data])
diff --git a/gunicorn/config.py b/gunicorn/config.py
index f7b7e5b6..026161ff 100644
--- a/gunicorn/config.py
+++ b/gunicorn/config.py
@@ -678,7 +678,7 @@ class AccessLogFormat(Setting):
     cli = ["--access-logformat"]
     meta = "STRING"
     validator = validate_string
-    default = "%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"'
+    default = '"%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"'
     desc = """\
         The Access log format .
 
@@ -699,9 +699,8 @@ class AccessLogFormat(Setting):
         T: request time in seconds
         D: request time in microseconds,
         p: process ID
-
-        You can also pass any WSGI request header as a parameter.
-        (ex '%(HTTP_HOST)s').
+        {Header}i: request header
+        {Header}o: response header
         """
 
 class ErrorLog(Setting):
diff --git a/gunicorn/glogging.py b/gunicorn/glogging.py
index 34b7dedd..ad2f57c4 100644
--- a/gunicorn/glogging.py
+++ b/gunicorn/glogging.py
@@ -54,6 +54,26 @@ class LazyWriter(object):
     def flush(self):
         self.open().flush()
 
+class SafeAtoms(dict):
+
+    def __init__(self, atoms):
+        dict.__init__(self)
+        for key, value in atoms.items():
+            self[key] = value.replace('"', '\\"')
+
+    def __getitem__(self, k):
+        if k.startswith("{"):
+            kl = k.lower()
+            if kl in self:
+                return super(SafeAtoms, self).__getitem__(kl)
+            else:
+                return "-"
+        if k in self:
+            return super(SafeAtoms, self).__getitem__(k)
+        else:
+            return '-'
+
+
 class Logger(object):
 
     LOG_LEVELS = {
@@ -129,7 +149,7 @@ class Logger(object):
             lvl = self.LOG_LEVELS.get(lvl.lower(), logging.INFO)
         self.error_log.log(lvl, msg, *args, **kwargs)
 
-    def access(self, resp, environ, request_time):
+    def access(self, resp, req, environ, request_time):
         """ Seee http://httpd.apache.org/docs/2.0/logs.html#combined
         for format details
         """
@@ -154,15 +174,19 @@ class Logger(object):
                 'p': "<%s>" % os.getpid()
                 }
 
-        # add WSGI request headers
-        atoms.update(dict([(k,v) for k, v in environ.items() \
-                if k.startswith('HTTP_')]))
+        # add request headers
+        atoms.update(dict([("{%s}i" % k.lower(),v) for k, v in req.headers]))
 
-        for k, v in atoms.items():
-            atoms[k] = v.replace('"', '\\"')
+        # add response headers
+        atoms.update(dict([("{%s}o" % k.lower(),v) for k, v in resp.headers]))
+
+        # wrap atoms:
+        # - make sure atoms will be test case insensitively
+        # - if atom doesn't exist replace it by '-'
+        safe_atoms = SafeAtoms(atoms)
 
         try:
-            self.access_log.info(self.cfg.access_log_format % atoms)
+            self.access_log.info(self.cfg.access_log_format % safe_atoms)
         except:
             self.error(traceback.format_exc())
 
diff --git a/gunicorn/workers/async.py b/gunicorn/workers/async.py
index 59e51943..d207e76f 100644
--- a/gunicorn/workers/async.py
+++ b/gunicorn/workers/async.py
@@ -69,7 +69,7 @@ class AsyncWorker(base.Worker):
                     resp.write(item)
                 resp.close()
                 request_time = datetime.now() - request_start
-                self.log.access(resp, environ, request_time)
+                self.log.access(resp, req, environ, request_time)
             finally:
                 if hasattr(respiter, "close"):
                   respiter.close()
diff --git a/gunicorn/workers/sync.py b/gunicorn/workers/sync.py
index 642dcb32..53e70cad 100644
--- a/gunicorn/workers/sync.py
+++ b/gunicorn/workers/sync.py
@@ -105,7 +105,7 @@ class SyncWorker(base.Worker):
                         resp.write(item)
                 resp.close()
                 request_time = datetime.now() - request_start
-                self.log.access(resp, environ, request_time)
+                self.log.access(resp, req, environ, request_time)
             finally:
                 if hasattr(respiter, "close"):
                     respiter.close()