From e6ab4cf55fe7fda58a9c783c82fb6c62e3a0b565 Mon Sep 17 00:00:00 2001
From: Andreas Kloeckner <inform@tiker.net>
Date: Tue, 28 Jan 2014 18:15:40 -0600
Subject: [PATCH] Add more logging to auto_test

---
 loopy/auto_test.py | 21 +++++++++++++++++++--
 1 file changed, 19 insertions(+), 2 deletions(-)

diff --git a/loopy/auto_test.py b/loopy/auto_test.py
index 239a69d87..62797d00a 100644
--- a/loopy/auto_test.py
+++ b/loopy/auto_test.py
@@ -32,6 +32,10 @@ import pyopencl.array as cl_array
 
 AUTO_TEST_SKIP_RUN = False
 
+import logging
+logger = logging.getLogger(__name__)
+
+
 
 # {{{ create random argument arrays for testing
 
@@ -435,9 +439,12 @@ def auto_test_vs_ref(
             break
 
         ref_queue.finish()
-        ref_start = time()
 
-        print "using %s for the reference calculation" % dev
+        logger.info("%s (ref): using %s for the reference calculation" % (
+            ref_knl.name, dev))
+        logger.info("%s (ref): run" % ref_knl.name)
+
+        ref_start = time()
 
         if not AUTO_TEST_SKIP_RUN:
             ref_evt, _ = ref_compiled(ref_queue, **ref_args)
@@ -448,6 +455,8 @@ def auto_test_vs_ref(
         ref_stop = time()
         ref_elapsed_wall = ref_stop-ref_start
 
+        logger.info("%s (ref): run done" % ref_knl.name)
+
         ref_evt.wait()
         ref_elapsed = 1e-9*(ref_evt.profile.END-ref_evt.profile.SUBMIT)
 
@@ -507,6 +516,8 @@ def auto_test_vs_ref(
             print compiled.cl_program.binaries[0]
             print 75*"-"
 
+        logger.info("%s: run warmup" % (knl.name))
+
         for i in range(warmup_rounds):
             if not AUTO_TEST_SKIP_RUN:
                 compiled(queue, **args)
@@ -538,6 +549,10 @@ def auto_test_vs_ref(
         events = []
         queue.finish()
 
+        logger.info("%s: warmup done" % (knl.name))
+
+        logger.info("%s: timing run" % (knl.name))
+
         timing_rounds = warmup_rounds
 
         while True:
@@ -581,6 +596,8 @@ def auto_test_vs_ref(
             else:
                 break
 
+        logger.info("%s: timing run done" % (knl.name))
+
         rates = ""
         for cnt, lbl in zip(op_count, op_label):
             rates += " %g %s/s" % (cnt/elapsed_wall, lbl)
-- 
GitLab