[Zope] How to log real user and ip in Z2.log behind squid/apache?

[Dennis Allison]

This patch, due to  Paul Tiemann <pault at center7.com>, should do half
the task.   As Paul originally put it --


I've got a "fix" for your problem.  It wouldn't have
been my first choice to do it the way I did, but it
works, and it's quicker than my other options were...

(Some history)
I had the same problem with cookie-based authentication.
The root of the problem lies in the log() method of the
file ZServer/medusa/http_server.py.  That method uses the
'Authorization' header of the request to determine the
name of the user.  Due to the architecture of the internal
objects used to represent the request at this level (not
the "REQUEST" we're usually used to using, but another
lower-level request object) the 'Authorization' header
is a read-only field.  I believe it's the __get_item__
and __set_item__ methods that are custom for that request
object, so that all attempts to "set" the Authorization
HTTP header will just be dumped into the list of response
headers.  Since I could see no other way to get around the
problem by making a change in the 'CookieCrumbler', or in my
case 'LDAPUserFolder' products, I decided to just fix the
problem by monkey-patching the log() method in the
http_server.py file itself.

To do that, you can do something like this:

1) Add two lines like these to the top of http_server.py
   for the import you'll need below to make parsing
   the cookies easier.

# PAUL DID THIS SHAMEFUL THING
from ZPublisher.HTTPRequest import parse_cookie

2) Down near line 290, you have the part that determines
   the name that will go to the Z2.log file.  Here, you
   see 'name' being set to 'Anonymous', then there is
   an 'if auth is not None:' block which determines
   the name from the "Authorization" header.  In my case,
   I added an 'else:' block below the if which has this
   dirty patch of code:

try:
  auth_cookie_name = "my_auth" # probably '__ac'?
  cookie = None
  try:
    cookies = {}
    header_value = self.get_header("Cookie")
    if header_value:
      parse_cookie(header_value, cookies)
      cookie = cookies.get(auth_cookie_name, None)
  except:
    name = "Anonymous"

  if cookie is not None:
    cookie = unquote( cookie )
    try:
      cookie = base64.decodestring( cookie )
      name, password = tuple( cookie.split( ':', 1 ) )
    except: name = "Unknown (bad auth cookie)"
except:
  name = "Failure!"

Note that the way I solved the problem is "brittle" because
should you ever change your auth_cookie_name, and forget
to change it in http_server.py as well, you'll stop
seeing correct values in your logs.

One more important note:  Since you have more than one
acl_users, you might want to put the 'Cookie' based
name-fetch code before the 'Authorization' header based
stuff.  It would be possible for you to log in as admin,
then use the cookie-based login page to authenticate as
a normal user, in which case your browser will be sending
the 'Authorization' header, as well as the cookie, and
that would cause the standard acl_users username to be
logged...


Here's the patch to the ZServer/medusa/http_server.py module.

This does not fix the headers.  If you need to do that you must
buffer them and rewrite.  Ssuid and similar proxies pass along 
the IP address in a header.  You need to capture the header, 
extract the IP, and insert it into the logmessage.


a--- http_server.py      2004-06-24 15:53:00.000000000 +0000
+++ my_http_server.py   2003-07-06 22:34:02.000000000 +0000
@@ -36,6 +36,9 @@
 from counter import counter
 from urllib import unquote

+# Paul's Patch (a shameful thing) to make names register properly
+from ZPublisher.HTTPRequest import parse_cookie
+
 #
===========================================================================
 #                                                      Request Object
 #
===========================================================================
@@ -277,6 +280,7 @@

         auth=self.get_header('Authorization')
         name='Anonymous'
+       
         if auth is not None:
             if string.lower(auth[:6]) == 'basic ':
                 try: decoded=base64.decodestring(auth[6:])
@@ -286,6 +290,29 @@
                     name = 'Unknown (bad auth string)'
                 else:
                     name = t[0]
+        else:
+        # start of patch
+            try:
+                auth_cookie_name='__ac'
+                cookie= None
+                try:
+                    cookies = {}
+                    header_value = self.get_header("Cookie")
+                    if header_value:
+                        parse_cookie(header_value, cookies)
+                        cookie = cookies.get(auth_cookie_name, None)
+                except:
+                    name = 'Anonymous'
+
+                if cookie is not None:
+                    cookie = unquote(cookie)
+                    try:
+                        cookie = base64.decodestring(cookie)
+                        name, password = tuple( cookie.split(':',1))
+                    except: name= "Unknown (bad auth cookie)"
+            except:
+                name = "Failure!"
+        # end of patch

         self.channel.server.logger.log (
             self.channel.addr[0],





On Wed, 23 Jun 2004, Choo Zhi Min wrote:

> Hi,
> 
> I run zope-2.7.1 behind squid and apache. Z2.log captures the ip of  
> squid/apache (they are on the same machine), and the user is always  
> Anonymous. How to configure Z2.log to log the real ip of users and their  
> login name?
> 
> 
> I tried "trusted-proxy" in zope.conf but didn't work. May be it's not  
> related.
> 
> 
> Thanks and regards,
> ZhiMIn
> 
> 
> _______________________________________________
> Zope maillist  -  Zope at zope.org
> http://mail.zope.org/mailman-20/listinfo/zope
> **   No cross posts or HTML encoding!  **
> (Related lists - 
>  http://mail.zope.org/mailman-20/listinfo/zope-announce
>  http://mail.zope.org/mailman-20/listinfo/zope-dev )
>