From df8d1d9506cc60cb4ff932e52b9ab1665d09be5b Mon Sep 17 00:00:00 2001
From: Raymond Yee <raymond.yee@gmail.com>
Date: Thu, 10 Nov 2011 07:36:17 -0800
Subject: [PATCH] Put more logging into Goodreads handling to try to debug why
 shelf loading not working in some cases.

---
 core/goodreads.py | 8 +++++++-
 frontend/views.py | 6 ++++--
 2 files changed, 11 insertions(+), 3 deletions(-)

diff --git a/core/goodreads.py b/core/goodreads.py
index f7db35a8..96003c4a 100644
--- a/core/goodreads.py
+++ b/core/goodreads.py
@@ -216,6 +216,9 @@ def load_goodreads_shelf_into_wishlist(user, shelf_name='all', goodreads_user_id
     Load a specified Goodreads shelf (by default:  all the books from the Goodreads account associated with user)
     """
     
+    logger.info('Entering load_goodreads_shelf_into_wishlist.  user: %s, shelf_name: %s, goodreads_user_id: %s, max_books: %s',
+                user, shelf_name, goodreads_user_id, max_books)
+    
     gc = GoodreadsClient(key=settings.GOODREADS_API_KEY, secret=settings.GOODREADS_API_SECRET, user=user)
         
     if goodreads_user_id is None:
@@ -224,6 +227,8 @@ def load_goodreads_shelf_into_wishlist(user, shelf_name='all', goodreads_user_id
       else:
         raise Exception("No Goodreads user_id is associated with user.")
         
+    logger.info('computed goodreads_user_id: %s ', goodreads_user_id)
+    
     for (i, review) in enumerate(islice(gc.review_list(goodreads_user_id,shelf=shelf_name),max_books)):
         isbn = review["book"]["isbn10"] if review["book"]["isbn10"] is not None else review["book"]["isbn13"]
         logger.info("%d %s %s %s ", i, review["book"]["title"], isbn, review["book"]["small_image_url"])
@@ -234,5 +239,6 @@ def load_goodreads_shelf_into_wishlist(user, shelf_name='all', goodreads_user_id
             user.wishlist.works.add(edition.work)
             logger.info("Work with isbn %s added to wishlist.", isbn)
         except Exception, e:
-            logger.info ("error adding ISBN %s: %s", isbn, e) 
+            logger.info ("Exception adding ISBN %s: %s", isbn, e) 
 
+    logger.info('Leaving load_goodreads_shelf_into_wishlist.  Length of wishlist for user %s is %s', user, len(user.wishlist.works.all()))
diff --git a/frontend/views.py b/frontend/views.py
index 11fb4e38..2e695f94 100755
--- a/frontend/views.py
+++ b/frontend/views.py
@@ -327,6 +327,7 @@ def goodreads_flush_assoc(request):
         profile.goodreads_auth_token = None
         profile.goodreads_auth_secret = None
         profile.save()
+        logger.info('Goodreads association flushed for user %s', user)
     return HttpResponseRedirect(reverse('goodreads_display'))
       
 @require_POST
@@ -345,7 +346,7 @@ def goodreads_load_shelf(request):
         return HttpResponse("Shelf loading placed on task queue.")
     except Exception,e:
         return HttpResponse("Error in loading shelf: %s " % (e))
-        logger.info("Error in loading shelf: %s ", e)
+        logger.info("Error in loading shelf for user %s: %s ", user, e)
 
 @require_POST
 @login_required      
@@ -353,10 +354,11 @@ def goodreads_load_shelf(request):
 def clear_wishlist(request):
     try:
         request.user.wishlist.works.clear()
+        logger.info("Wishlist for user %s cleared", request.user)
         return HttpResponse('wishlist cleared')
     except Exception, e:
         return HttpResponse("Error in clearing wishlist: %s " % (e))
-        logger.info("Error in clearing wishlist: %s ", e)
+        logger.info("Error in clearing wishlist for user %s: %s ", request.user, e)
     
 
 def celery_test(request):