--- a/gpp/donations/views.py	Thu Jun 11 01:33:38 2009 +0000
+++ b/gpp/donations/views.py	Fri Jun 12 01:06:05 2009 +0000
@@ -58,70 +58,84 @@
 def ipn(request):
     """
     This function is the IPN listener and handles the IPN POST from Paypal.
+    The algorithm here roughly follows the outline described in chapter 2
+    of Paypal's IPNGuide.pdf "Implementing an IPN Listener".
+    """
+    import logging
 
-    TODO: Add logging.
-    """
-    parameters = None
-    try:
-        if request['payment_status'] == 'Completed':
-            if request.POST:
-              parameters = request.POST.copy()
-            else:
-              parameters = request.GET.copy()
+    # Log some info about this IPN event
+    ip = request.META.get('REMOTE_ADDR', '?')
+    parameters = request.POST.copy()
+    logging.info('IPN from %s; post data: %s' % (ip, parameters.urlencode()))
 
-        if parameters:
-            parameters['cmd']='_notify-validate'
-            req = urllib2.Request(paypal_params()[0], parameters.urlencode())
-            req.add_header("Content-type", "application/x-www-form-urlencoded")
-            response = urllib2.urlopen(req)
-            status = response.read()
-            if status != "VERIFIED":
-                parameters = None
+    # Now we follow the instructions in chapter 2 of the Paypal IPNGuide.pdf.
+    # Create a request that contains exactly the same IPN variables and values in
+    # the same order, preceded with cmd=_notify-validate
+    parameters['cmd']='_notify-validate'
 
-        if parameters:
-            # is this a donation to the site?
-            try:
-                item_number = int(parameters['item_number'])
-            except ValueError:
-                pass
-            else:
-                if item_number == settings.DONATIONS_ITEM_NUM or \
-                   item_number == settings.DONATIONS_ITEM_ANON_NUM:
-                    process_donation(item_number, parameters)
+    # Post the request back to Paypal (either to the sandbox or the real deal).
+    req = urllib2.Request(paypal_params()[0], parameters.urlencode())
+    req.add_header("Content-type", "application/x-www-form-urlencoded")
+    response = urllib2.urlopen(req)
 
-            return HttpResponse("Ok")
+    # Wait for the response from Paypal, which should be either VERIFIED or INVALID.
+    status = response.read()
+    if status != 'VERIFIED':
+        logging.warning('IPN: Payapl did not verify; status was %s' % status)
+        return HttpResponse()
 
-    except Exception, e:
-        # print "An exeption was caught: " + str(e)
-        pass
+    # Response was VERIFIED; act on this if it is a Completed donation, 
+    # otherwise don't handle it (we are just a donations application. Here
+    # is where we could be expanded to be a more general payment processor).
 
-    return HttpResponseServerError("Error")
+    payment_status = parameters.get('payment_status')
+    if payment_status != 'Completed':
+        logging.info('IPN: payment_status is %s; we are done.' % payment_status)
+        return HttpResponse()
+
+    # Is this a donation to the site?
+    item_number = parameters.get('item_number')
+    if item_number == settings.DONATIONS_ITEM_NUM or \
+       item_number == settings.DONATIONS_ITEM_ANON_NUM:
+        process_donation(item_number, parameters)
+    else:
+        logging.info('IPN: not a donation; done.')
+
+    return HttpResponse()
 
 
 def process_donation(item_number, params):
     """
-    Constructs a donation object from the parameters and stores
-    in the database.
+    A few validity and duplicate checks are made on the donation params.
+    If everything is ok, construct a donation object from the parameters and 
+    store it in the database.
     """
+    import logging
+
     # Has this transaction been processed before?
-    if 'txn_id' not in params:
+    txn_id = params.get('txn_id')
+    if txn_id is None:
+        logging.error('IPN: missing txn_id')
         return
-    txn_id = params['txn_id']
+
     try:
         donation = Donation.objects.get(txn_id__exact=txn_id)
     except Donation.DoesNotExist:
         pass
     else:
+        logging.warning('IPN: duplicate txn_id')
         return      # no exception, this is a duplicate
 
     # Is the email address ours?
     business = params.get('business')
     if business != paypal_params()[1]:
+        logging.warning('IPN: invalid business: %s' % business)
         return
 
     # is this a payment received?
     txn_type = params.get('txn_type')
     if txn_type != 'web_accept':
+        logging.warning('IPN: invalid txn_type: %s' % txn_type)
         return
 
     # Looks like a donation, save it to the database.
@@ -149,12 +163,14 @@
         mc_gross = decimal.Decimal(params['mc_gross'])
         mc_fee = decimal.Decimal(params['mc_fee'])
     except KeyError, decimal.InvalidOperation:
+        logging.error('IPN: invalid/missing mc_gross or mc_fee')
         return
 
     try:
         payment_date = datetime.datetime.strptime(params['payment_date'], 
                 PP_DATE_FMT)
     except KeyError, ValueError:
+        logging.error('IPN: invalid/missing payment_date')
         return
 
     donation = Donation(
@@ -173,4 +189,5 @@
         payment_date=payment_date)
 
     donation.save()
+    logging.info('IPN: donation saved')