# HG changeset patch
# User Brian Neal <bgneal@gmail.com>
# Date 1296417752 0
# Node ID 767cedc7d12ae3fe23f92a49735f8305a8defbda
# Parent  36373d9956112220d8a3694ec18952174642ed7f
Fixing #144; integrate with new Django logging support. Also added unit tests for Donations app.

diff -r 36373d995611 -r 767cedc7d12a gpp/accounts/forms.py
--- a/gpp/accounts/forms.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/accounts/forms.py	Sun Jan 30 20:02:32 2011 +0000
@@ -24,13 +24,13 @@
     email = forms.EmailField()
     password1 = forms.CharField(label = "Password", widget = forms.PasswordInput)
     password2 = forms.CharField(label = "Password confirmation", widget = forms.PasswordInput)
-    agree_age = forms.BooleanField(required=True, 
+    agree_age = forms.BooleanField(required=True,
         label='I certify that I am over the age of 13',
         error_messages={
             'required': 'Sorry, but you must be over the age of 13 to ' \
                     'register at our site.',
             })
-    agree_tos = forms.BooleanField(required=True, 
+    agree_tos = forms.BooleanField(required=True,
        label='I agree to the Terms of Service',
         error_messages={
             'required': 'You have not agreed to our Terms of Service.',
@@ -96,7 +96,7 @@
         site = Site.objects.get_current()
         admin_email = settings.ADMINS[0][1]
 
-        activation_link = 'http://%s%s' % (site.domain, reverse('accounts.views.register_confirm', 
+        activation_link = 'http://%s%s' % (site.domain, reverse('accounts.views.register_confirm',
                 kwargs = {'username' : pending_user.username, 'key' : pending_user.key}))
 
         msg = render_to_string('accounts/registration_email.txt',
@@ -112,11 +112,11 @@
         subject = 'Registration Confirmation for ' + site.name
         send_mail(subject, msg, admin_email, [self.cleaned_data['email']],
                 expedite=True)
-        logging.info('Accounts/registration conf. email sent to %s for user %s; IP = %s' % \
-                (self.cleaned_data['email'], pending_user.username, self.ip))
+        logging.info('Accounts/registration conf. email sent to %s for user %s; IP = %s',
+                self.cleaned_data['email'], pending_user.username, self.ip)
 
         return pending_user
 
     def _validation_error(self, msg, param=None):
-        logging.error('Accounts/registration [%s]: %s (%s)' % (self.ip, msg, param))
+        logging.error('Accounts/registration [%s]: %s (%s)', self.ip, msg, param)
         raise forms.ValidationError(msg)
diff -r 36373d995611 -r 767cedc7d12a gpp/accounts/views.py
--- a/gpp/accounts/views.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/accounts/views.py	Sun Jan 30 20:02:32 2011 +0000
@@ -47,7 +47,7 @@
 def register_confirm(request, username, key):
     if request.user.is_authenticated():
         return HttpResponseRedirect(settings.LOGIN_REDIRECT_URL)
-    
+
     # purge expired users
 
     PendingUser.objects.purge_expired()
@@ -56,14 +56,14 @@
     try:
         pending_user = PendingUser.objects.get(username = username)
     except PendingUser.DoesNotExist:
-        logging.error('Accounts register_confirm [%s]: user does not exist: %s' % (ip, username))
+        logging.error('Accounts register_confirm [%s]: user does not exist: %s', ip, username)
         return render_to_response('accounts/register_failure.html', {
             'username': username,
             },
             context_instance = RequestContext(request))
 
     if pending_user.key != key:
-        logging.error('Accounts register_confirm [%s]: key error: %s' % (ip, username))
+        logging.error('Accounts register_confirm [%s]: key error: %s', ip, username)
         return render_to_response('accounts/register_failure.html', {
             'username': username,
             },
@@ -85,7 +85,7 @@
     new_user.save()
     pending_user.delete()
 
-    logging.info('Accounts register_confirm [%s]: success: %s' % (ip, username))
+    logging.info('Accounts register_confirm [%s]: success: %s', ip, username)
     return render_to_response('accounts/register_success.html', {
         'username': username,
         },
diff -r 36373d995611 -r 767cedc7d12a gpp/antispam/utils.py
--- a/gpp/antispam/utils.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/antispam/utils.py	Sun Jan 30 20:02:32 2011 +0000
@@ -61,7 +61,7 @@
     profile.status = STA_SUSPENDED
     profile.status_date = datetime.datetime.now()
     profile.save()
-    
+
 
 def _get_spam_phrases():
     """This function returns the current list of spam phrase strings.
diff -r 36373d995611 -r 767cedc7d12a gpp/bio/badges.py
--- a/gpp/bio/badges.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/bio/badges.py	Sun Jan 30 20:02:32 2011 +0000
@@ -1,4 +1,5 @@
 """This module contains user profile badge-related functionality."""
+import logging
 
 from bio.models import Badge
 from bio.models import BadgeOwnership
@@ -14,11 +15,10 @@
     to the given user. If the user already has the badge,
     the badge count is incremented by one.
     """
-    import logging
     try:
         badge = Badge.objects.get(numeric_id=badge_id)
     except Badge.DoesNotExist:
-        logging.error("Can't award badge with numeric_id = %d" % badge_id)
+        logging.error("Can't award badge with numeric_id = %d", badge_id)
         return
 
     profile = user.get_profile()
diff -r 36373d995611 -r 767cedc7d12a gpp/core/functions.py
--- a/gpp/core/functions.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/core/functions.py	Sun Jan 30 20:02:32 2011 +0000
@@ -1,6 +1,7 @@
 """This file houses various core utility functions for GPP"""
 import datetime
 import re
+import logging
 
 import django.core.mail
 from django.contrib.sites.models import Site
@@ -23,17 +24,16 @@
         django.core.mail.send_mail(subject, message, from_email, recipient_list,
                 fail_silently, auth_user, auth_password)
 
-    import logging
-    logging.debug('EMAIL:\nFrom: %s\nTo: %s\nSubject: %s\nMessage:\n%s' %
-            (from_email, str(recipient_list), subject, message))
+    logging.debug('EMAIL:\nFrom: %s\nTo: %s\nSubject: %s\nMessage:\n%s',
+        from_email, str(recipient_list), subject, message)
 
 
 def email_admins(subject, message):
     """Emails the site admins. Goes through the site send_mail function."""
     site = Site.objects.get_current()
     subject = '[%s] %s' % (site.name, subject)
-    send_mail(subject, 
-            message, 
+    send_mail(subject,
+            message,
             '%s@%s' % (settings.GPP_NO_REPLY_EMAIL, site.domain),
             [mail_tuple[1] for mail_tuple in settings.ADMINS])
 
@@ -42,8 +42,8 @@
     """Emails the site managers. Goes through the site send_mail function."""
     site = Site.objects.get_current()
     subject = '[%s] %s' % (site.name, subject)
-    send_mail(subject, 
-            msg, 
+    send_mail(subject,
+            msg,
             '%s@%s' % (settings.GPP_NO_REPLY_EMAIL, site.domain),
             [mail_tuple[1] for mail_tuple in settings.MANAGERS])
 
diff -r 36373d995611 -r 767cedc7d12a gpp/donations/tests.py
--- a/gpp/donations/tests.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/donations/tests.py	Sun Jan 30 20:02:32 2011 +0000
@@ -1,23 +1,110 @@
 """
-This file demonstrates two different styles of tests (one doctest and one
-unittest). These will both pass when you run "manage.py test".
+Tests for the donations application.
+"""
+import urlparse
+from decimal import Decimal
+import datetime
 
-Replace these with more appropriate tests for your application.
-"""
+from django.contrib.auth.models import User
+from django.test import TestCase
+from django.core.urlresolvers import reverse
 
-from django.test import TestCase
+from donations.models import Donation
+import bio.badges
 
-class SimpleTest(TestCase):
-    def test_basic_addition(self):
+
+# This data was copy/pasted from my actual Paypal IPN history. Some alterations
+# were made since this file is getting committed to version control and I
+# didn't want to store "real" data that could be used to trace a transaction or
+# real payer.
+
+# This data is for a non-anonymous donation:
+TEST_POST_DATA_1 = """\
+mc_gross=5.00&protection_eligibility=Ineligible&payer_id=FAKEPAYERID01&tax=0.00&payment_date=04:14:08 Jan 21, 2011 PST&payment_status=Completed&charset=windows-1252&first_name=John&option_selection1=No&mc_fee=0.50&notify_version=3.0&custom=test_user&payer_status=verified&business=brian@surfguitar101.com&quantity=1&verify_sign=Ai1PaTHIS-IS-FAKE-DATA-jB264AOjpiTa4vcsPCEavq-83oyIclHKI&payer_email=test_user@example.com&option_name1=List your name?&txn_id=TESTTXNID5815921V&payment_type=instant&last_name=Doe&receiver_email=brian@surfguitar101.com&payment_fee=0.50&receiver_id=FAKERECEIVERU&txn_type=web_accept&item_name=Donation for www.surfguitar101.com&mc_currency=USD&item_number=500&residence_country=AU&handling_amount=0.00&transaction_subject=test_user&payment_gross=5.00&shipping=0.00"""
+
+# Data from a user that wanted to remain anonymous
+TEST_POST_DATA_2 = """\
+mc_gross=100.00&protection_eligibility=Ineligible&payer_id=FAKEPAYERID02&tax=0.00&payment_date=05:40:33 Jan 16, 2011 PST&payment_status=Completed&charset=windows-1252&first_name=John&option_selection1=No&mc_fee=3.20&notify_version=3.0&custom=test_user&payer_status=unverified&business=brian@surfguitar101.com&quantity=1&verify_sign=AIkKNFAKE-DATA-NOT-REALpqCSxA-E7Tm4rMGlUpNy6ym0.exBzfiyI&payer_email=test_user@example.com&option_name1=List your name?&txn_id=TESTTXNIDK548343A&payment_type=instant&last_name=Doe&receiver_email=brian@surfguitar101.com&payment_fee=3.20&receiver_id=FAKERECEIVERU&txn_type=web_accept&item_name=Donation for www.surfguitar101.com&mc_currency=USD&item_number=501&residence_country=US&handling_amount=0.00&transaction_subject=test_user&payment_gross=100.00&shipping=0.00"""
+
+
+class DonationsTest(TestCase):
+    fixtures = ['badges']
+
+    def test_ipn_post_1(self):
         """
-        Tests that 1 + 1 always equals 2.
+        Test a simulated IPN post
         """
-        self.failUnlessEqual(1 + 1, 2)
+        user = User.objects.create_user('test_user', 'test_user@example.com',
+                'password')
+        user.save()
 
-__test__ = {"doctest": """
-Another way to test that 1 + 1 is equal to 2.
+        args = urlparse.parse_qs(TEST_POST_DATA_1)
+        response = self.client.post(reverse('donations-ipn'), args)
 
->>> 1 + 1 == 2
-True
-"""}
+        self.assertEqual(response.status_code, 200)
 
+        try:
+            d = Donation.objects.get(pk=1)
+        except Donation.DoesNotExist:
+            self.fail("Donation object was not created")
+        else:
+            self.assertEqual(d.user, user)
+            self.assertFalse(d.is_anonymous)
+            self.assertFalse(d.test_ipn)
+            self.assertEqual(d.txn_id, 'TESTTXNID5815921V')
+            self.assertEqual(d.txn_type, 'web_accept')
+            self.assertEqual(d.first_name, 'John')
+            self.assertEqual(d.last_name, 'Doe')
+            self.assertEqual(d.payer_email, 'test_user@example.com')
+            self.assertEqual(d.payer_id, 'FAKEPAYERID01')
+            self.assertEqual(d.mc_fee, Decimal('0.50'))
+            self.assertEqual(d.mc_gross, Decimal('5.00'))
+            self.assertEqual(d.memo, '')
+            self.assertEqual(d.payer_status, 'verified')
+            self.assertEqual(d.payment_date,
+                    datetime.datetime(2011, 1, 21, 4, 14, 8))
+
+            # user should have got a badge for donating
+            p = user.get_profile()
+            badges = list(p.badges.all())
+            self.assertEqual(len(badges), 1)
+            if len(badges) == 1:
+                self.assertEqual(badges[0].numeric_id, bio.badges.CONTRIBUTOR_PIN)
+
+    def test_ipn_post_2(self):
+        """
+        Test a simulated IPN post
+        """
+        user = User.objects.create_user('test_user', 'test_user@example.com',
+                'password')
+        user.save()
+
+        args = urlparse.parse_qs(TEST_POST_DATA_2)
+        response = self.client.post(reverse('donations-ipn'), args)
+
+        self.assertEqual(response.status_code, 200)
+
+        try:
+            d = Donation.objects.get(pk=1)
+        except Donation.DoesNotExist:
+            self.fail("Donation object was not created")
+        else:
+            self.assertEqual(d.user, user)
+            self.assertTrue(d.is_anonymous)
+            self.assertFalse(d.test_ipn)
+            self.assertEqual(d.txn_id, 'TESTTXNIDK548343A')
+            self.assertEqual(d.txn_type, 'web_accept')
+            self.assertEqual(d.first_name, 'John')
+            self.assertEqual(d.last_name, 'Doe')
+            self.assertEqual(d.payer_email, 'test_user@example.com')
+            self.assertEqual(d.payer_id, 'FAKEPAYERID02')
+            self.assertEqual(d.mc_fee, Decimal('3.20'))
+            self.assertEqual(d.mc_gross, Decimal('100.00'))
+            self.assertEqual(d.memo, '')
+            self.assertEqual(d.payer_status, 'verified')
+            self.assertEqual(d.payment_date,
+                    datetime.datetime(2011, 1, 16, 5, 40, 33))
+
+            # user should not have got a badge for donating
+            p = user.get_profile()
+            self.assertEqual(p.badges.count(), 0)
diff -r 36373d995611 -r 767cedc7d12a gpp/donations/views.py
--- a/gpp/donations/views.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/donations/views.py	Sun Jan 30 20:02:32 2011 +0000
@@ -4,6 +4,7 @@
 import urllib2
 import decimal
 import datetime
+import logging
 
 from django.shortcuts import render_to_response
 from django.template import RequestContext
@@ -35,6 +36,26 @@
     return form_action, business
 
 
+def verify_request(params):
+    """
+    Send the parameters back to Paypal and return the response string.
+    """
+    # If we are doing localhost-type unit tests, just return whatever
+    # the test wants us to...
+    if hasattr(settings, 'DONATIONS_DEBUG_VERIFY_RESPONSE'):
+        return settings.DONATIONS_DEBUG_VERIFY_RESPONSE
+
+    req = urllib2.Request(paypal_params()[0], params)
+    req.add_header("Content-type", "application/x-www-form-urlencoded")
+    try:
+        response = urllib2.urlopen(req)
+    except URLError, e:
+        logging.exception('IPN: exception verifying IPN: %s', e)
+        return None
+
+    return response.read()
+
+
 def index(request):
     gross, net, donations = Donation.objects.monthly_stats()
     current_site = Site.objects.get_current()
@@ -63,28 +84,23 @@
     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
-
     # 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()))
+    logging.info('IPN from %s; post data: %s', ip, parameters.urlencode())
 
     # 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'
 
-    # 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)
-
-    # Wait for the response from Paypal, which should be either VERIFIED or INVALID.
-    status = response.read()
+    # Post the request back to Paypal (either to the sandbox or the real deal),
+    # and read the response:
+    status = verify_request(parameters.urlencode())
     if status != 'VERIFIED':
-        logging.warning('IPN: Payapl did not verify; status was %s' % status)
+        logging.warning('IPN: Payapl did not verify; status was %s', status)
         return HttpResponse()
 
     # Response was VERIFIED; act on this if it is a Completed donation, 
@@ -93,13 +109,13 @@
 
     payment_status = parameters.get('payment_status')
     if payment_status != 'Completed':
-        logging.info('IPN: payment_status is %s; we are done.' % payment_status)
+        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:
+    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.')
@@ -110,11 +126,10 @@
 def process_donation(item_number, params):
     """
     A few validity and duplicate checks are made on the donation params.
-    If everything is ok, construct a donation object from the parameters and 
+    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?
     txn_id = params.get('txn_id')
     if txn_id is None:
@@ -132,15 +147,15 @@
     # Is the email address ours?
     business = params.get('business')
     if business != paypal_params()[1]:
-        logging.warning('IPN: invalid business: %s' % business)
+        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)
+        logging.warning('IPN: invalid txn_type: %s', txn_type)
         return
-    
+
     # Looks like a donation, save it to the database.
     # Determine which user this came from, if any.
     # The username is stored in the custom field if the user was logged in when
@@ -179,7 +194,7 @@
     try:
         payment_date = datetime.datetime.strptime(payment_date, PP_DATE_FMT)
     except ValueError:
-        logging.error('IPN: invalid payment_date "%s"' % params['payment_date'])
+        logging.error('IPN: invalid payment_date "%s"', params['payment_date'])
         return
 
     try:
diff -r 36373d995611 -r 767cedc7d12a gpp/forums/tools.py
--- a/gpp/forums/tools.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/forums/tools.py	Sun Jan 30 20:02:32 2011 +0000
@@ -91,7 +91,7 @@
     try:
         forum = Forum.objects.get(slug=forum_slug)
     except Forum.DoesNotExist:
-        logging.error('could not create_topic for forum_slug=%s' % forum_slug)
+        logging.error('could not create_topic for forum_slug=%s', forum_slug)
         raise
 
     topic = Topic(forum=forum,
diff -r 36373d995611 -r 767cedc7d12a gpp/forums/views/spam.py
--- a/gpp/forums/views/spam.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/forums/views/spam.py	Sun Jan 30 20:02:32 2011 +0000
@@ -69,7 +69,7 @@
     if request.method == "POST" and can_moderate and can_deactivate:
         deactivate_spammer(poster)
 
-        email_admins(SPAMMER_NAILED_SUBJECT % poster.username, 
+        email_admins(SPAMMER_NAILED_SUBJECT % poster.username,
             SPAMMER_NAILED_MSG_BODY % (
                 request.user.username, poster.username))
 
@@ -78,8 +78,8 @@
             IP: %s
             Message:
             %s
-            """ % (request.user.username, poster.username, post.user_ip,
-                post.body)))
+            """),
+            request.user.username, poster.username, post.user_ip, post.body)
 
         return HttpResponseRedirect(reverse('forums-spammer_nailed', args=[
             poster.id]))
@@ -126,8 +126,8 @@
     if request.method == "POST" and can_moderate and can_promote:
         promote_stranger(poster)
 
-        logging.info("STRANGER PROMOTED: %s promoted %s." % (
-            request.user.username, poster.username))
+        logging.info("STRANGER PROMOTED: %s promoted %s.",
+            request.user.username, poster.username)
 
         return HttpResponseRedirect(post.get_absolute_url())
 
diff -r 36373d995611 -r 767cedc7d12a gpp/mailer/__init__.py
--- a/gpp/mailer/__init__.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/mailer/__init__.py	Sun Jan 30 20:02:32 2011 +0000
@@ -1,6 +1,7 @@
 from socket import error as socket_error
 import smtplib
 import time
+import logging
 
 import django.core.mail
 
@@ -27,7 +28,6 @@
 
     sent, errors = 0, 0
 
-    import logging
     logging.debug("Sending queued mail...")
     start_time = time.time()
 
@@ -35,17 +35,17 @@
     for msg in msgs:
         try:
             django.core.mail.send_mail(
-                    msg.subject, 
-                    msg.body, 
-                    msg.from_address, 
+                    msg.subject,
+                    msg.body,
+                    msg.from_address,
                     [msg.to_address],
                     fail_silently=False)
         except (socket_error, smtplib.SMTPException), e:
             errors += 1
-            logging.error("Error sending queued mail: %s" % e)
+            logging.error("Error sending queued mail: %s", e)
         else:
-        	sent += 1
-        	msg.delete()
+            sent += 1
+            msg.delete()
 
     end_time = time.time()
     logging.debug("Sent queued mail: %d successful, %d error(s); elapsed time: %.2f" % (
diff -r 36373d995611 -r 767cedc7d12a gpp/settings.py
--- a/gpp/settings.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/settings.py	Sun Jan 30 20:02:32 2011 +0000
@@ -3,7 +3,6 @@
 import os
 import platform
 from decimal import Decimal
-import logging
 
 import local_settings
 
@@ -251,11 +250,7 @@
 # Configure Logging
 #######################################################################
 
-logging.basicConfig(
-        filename=os.path.join(project_path, 'logs', 'gpp.log'),
-        filemode='a',
-        format='%(asctime)s %(levelname)s %(message)s',
-        level=local_settings.LOG_LEVEL)
+LOGGING = local_settings.LOGGING
 
 #######################################################################
 # Django Debug Toolbar 
diff -r 36373d995611 -r 767cedc7d12a gpp/test_settings.py
--- a/gpp/test_settings.py	Sat Jan 29 20:39:55 2011 +0000
+++ b/gpp/test_settings.py	Sun Jan 30 20:02:32 2011 +0000
@@ -11,3 +11,7 @@
         'NAME': 'dev.db',
     },
 }
+
+# For unit-testing the Donations module w/o using the Paypal sandbox
+DONATIONS_DEBUG_VERIFY_RESPONSE = 'VERIFIED'
+DONATIONS_BUSINESS_DEBUG = 'brian@surfguitar101.com'