Logger: started logging SQL

4 files changed, 27 insertions, 26 deletions

diff --git a/wqflask/dbFunction/webqtlDatabaseFunction.py b/wqflask/dbFunction/webqtlDatabaseFunction.py
index 299114b4..1bc67992 100644
--- a/wqflask/dbFunction/webqtlDatabaseFunction.py
+++ b/wqflask/dbFunction/webqtlDatabaseFunction.py
@@ -20,13 +20,15 @@
 #
 # This module is used by GeneNetwork project (www.genenetwork.org)
 
-
 from flask import Flask, g
 
 import MySQLdb
 import string
 from base import webqtlConfig
 
+from utility.logger import getLogger
+logger = getLogger(__name__ )
+
 ###########################################################################
 #output: cursor instance
 #function: connect to database and return cursor instance
@@ -76,33 +78,23 @@ def getAllSpecies(cursor=None):
     allSpecies = cursor.fetchall()
     return allSpecies
 
-###########################################################################
-#input: cursor, RISet (string)
-#output: specie's name (string), value will be None or else
-#function: retrieve specie's name info based on RISet
-###########################################################################
-
 def retrieve_species(group):
-    return g.db.execute("""select Species.Name
-                           from Species, InbredSet
-                           where InbredSet.Name = %s and
-                           InbredSet.SpeciesId = Species.Id""", (group)).fetchone()[0]
+    logger.debug("retrieve_species",group)
+    logger.sql(""""select Species.Name from Species, InbredSet where InbredSet.Name = %s and InbredSet.SpeciesId = Species.Id""", (group))
+
+    return g.db.execute("""select Species.Name from Species, InbredSet where InbredSet.Name =
+%s and InbredSet.SpeciesId = Species.Id""", (group)).fetchone()[0]
 
 def retrieve_species_id(group):
     return g.db.execute("select SpeciesId from InbredSet where Name = %s", (group)).fetchone()[0]
 
 
-###########################################################################
-# input: cursor
-# output: tissProbeSetFreezeIdList (list),
-#         nameList (list),
-#         fullNameList (list)
-# function: retrieve all TissueProbeSetFreezeId,Name,FullName info
-#           from TissueProbeSetFreeze table.
-#           These data will listed in the dropdown menu in the first page of Tissue Correlation
-###########################################################################
-
 def getTissueDataSet(cursor=None):
+    """Retrieve all TissueProbeSetFreezeId,Name,FullName info from
+TissueProbeSetFreeze table.  These data will listed in the dropdown
+menu in the first page of Tissue Correlation
+
+    """
     tissProbeSetFreezeIdList=[]
     nameList =[]
     fullNameList = []
diff --git a/wqflask/utility/logger.py b/wqflask/utility/logger.py
index 81202b05..bc0578c9 100644
--- a/wqflask/utility/logger.py
+++ b/wqflask/utility/logger.py
@@ -28,6 +28,7 @@
 
 import logging
 import string
+from inspect import isfunction
 from utility.tools import LOG_LEVEL
 
 class GNLogger:
@@ -62,8 +63,10 @@ class GNLogger:
         self.collect(self.logger.error,*args)
 
     def debugf(self,*args):
-        """Call logging.debug for multiple args"""
-        self.collect(self.logger.debug,*args)
+        """Call logging.debug for multiple args lazily"""
+        if self.logger.getEffectiveLevel() <= 10:
+            self.debug("Calling debug function!")
+            self.collectf(self.logger.debug,*args)
 
     def sql(self, sqlcommand, fun = None):
         """Log SQL command, optionally invoking a timed fun"""
@@ -73,6 +76,14 @@ class GNLogger:
         for a in args:
             fun(a)
 
+    def collectf(self,fun,*args):
+        """Collect arguments and use fun to output one by one"""
+        for a in args:
+            if isfunction(a):
+                fun(a())
+            else:
+                fun(a)
+
 # Get the module logger. You can override log levels at the
 # module level
 def getLogger(name, level = None):
diff --git a/wqflask/wqflask/search_results.py b/wqflask/wqflask/search_results.py
index 30b65e80..494e1047 100644
--- a/wqflask/wqflask/search_results.py
+++ b/wqflask/wqflask/search_results.py
@@ -100,7 +100,6 @@ class SearchResultPage(object):
         self.trait_list = []
 
         species = webqtlDatabaseFunction.retrieve_species(self.dataset.group.name)
-
         # result_set represents the results for each search term; a search of
         # "shh grin2b" would have two sets of results, one for each term
         logger.debug("self.results is:", pf(self.results))
diff --git a/wqflask/wqflask/views.py b/wqflask/wqflask/views.py
index 88cce263..f486a8b5 100644
--- a/wqflask/wqflask/views.py
+++ b/wqflask/wqflask/views.py
@@ -119,11 +119,11 @@ def search_page():
         else:
             return render_template("data_sharing.html", **template_vars.__dict__)
     else:
-        logger.debug("key is:", pf(key))
         result = None
         if USE_REDIS:
             with Bench("Trying Redis cache"):
                 key = "search_results:v1:" + json.dumps(request.args, sort_keys=True)
+                logger.debug("key is:", pf(key))
                 result = Redis.get(key)
                 if result:
                     logger.info("Redis cache hit on search results!")
@@ -131,7 +131,6 @@ def search_page():
         else:
             logger.info("Skipping Redis cache (USE_REDIS=False)")
 
-        logger.info("calling search_results.SearchResultPage")
         logger.info("request.args is", request.args)
         the_search = search_results.SearchResultPage(request.args)
         result = the_search.__dict__