some more expressive logging during data inserts

git-svn-id: svn://svn.open-ils.org/ILS-Contrib/constrictor/trunk@855 6d9bc8c9-1ec2-4278-b937-99fde70a366f

diff --git a/constrictor/data.py b/constrictor/data.py
index ea55007..ec463ec 100644 (file)
--- a/constrictor/data.py
+++ b/constrictor/data.py
@@ -78,7 +78,6 @@ class Data(object):
     def store_data(self):
 
         end_time = time.time()
-        log.log_info("Inserting data into data store...")
 
         # close out the task set
         self.engine.execute(
@@ -91,11 +90,19 @@ class Data(object):
         ).close()
 
         task_times = 0
+        total_tasks = len(self.runtime_data)
+        counter = 0
+
+        log.log_info("Inserting %d rows of data into data store..." % total_tasks)
 
         # insert all of the task data
+        # TODO: Create a batch insert SQL string to insert, since
+        # one row at a time is pretty slow
         for task in self.runtime_data:
+
             task_times += task['duration']
             log.log_debug("Storing " + task['name'])
+
             self.engine.execute(
                 self.task_table.insert().values(
                     task_name = task['name'],
@@ -107,10 +114,14 @@ class Data(object):
                 )
             ).close()
 
+            counter += 1
+            if counter %100 == 0:
+                log.log_info("Inserted %d rows" % counter)
+
         # log some basic stats
         task_set_time = end_time - self.task_set_start_time
         log.log_info("Total Tasks        -> %d" % len(self.runtime_data))
         log.log_info("Total time         -> %0.3f seconds" % task_set_time)
-        log.log_info("Average task time  -> %0.3f seconds" % (task_times / len(self.runtime_data)))
-        log.log_info("Time / Total Tasks -> %0.3f seconds/task" % (task_set_time / len(self.runtime_data)))
+        log.log_info("Average task time  -> %0.3f seconds" % (task_times / total_tasks))
+        log.log_info("Real Time / Total Tasks -> %0.3f seconds/task" % (task_set_time / total_tasks))