rebaseline_server: add more timing and progress info to server-side log

gm/rebaseline_server/results.py

 #!/usr/bin/python
 

[epoger, 2013/12/18 18:24:12]

I suppose it would be good for the client side to also display the progress info
(and to speed up the result generation process!), but I think this is at least a
step in the right direction.

 """

[epoger, 2013/12/18 18:24:12]

The server-side log now looks like this:

epoger@wpgntat-ubiq141:~/src/skia/red/skia$ gm/rebaseline_server/server.py
--export --editable --port 9133
12/18/2013 13:20:16 WARNING Running with combination of "export" and "editable"
flags.  Users on other machines will be able to modify your GM expectations!
12/18/2013 13:20:16 INFO Updating actual GM results in .gm-actuals from SVN repo
http://skia-autogen.googlecode.com/svn/gm-actual ...
RunCommand: ['svn', 'update', '.']
12/18/2013 13:20:16 INFO Listening for requests on http://172.24.179.183:9133
12/18/2013 13:20:18 INFO Reading actual-results JSON files from .gm-actuals...
12/18/2013 13:20:18 INFO Reading expected-results JSON files from
/usr/local/google/home/epoger/src/skia/red/skia/expectations/gm...
12/18/2013 13:20:19 INFO Generating pixel diffs for builder #1 of 60,
"Test-Android-GalaxyNexus-SGX540-Arm7-Debug"...
12/18/2013 13:20:23 INFO Generating pixel diffs for builder #2 of 60,
"Test-Android-GalaxyNexus-SGX540-Arm7-Release"...
12/18/2013 13:20:23 INFO Generating pixel diffs for builder #3 of 60,
"Test-Android-IntelRhb-SGX544-x86-Debug"...
...
12/18/2013 13:21:46 INFO Generating pixel diffs for builder #60 of 60,
"Test-Win8-ShuttleA-HD7770-x86_64-Release"...
12/18/2013 13:21:46 INFO Results complete; took 88 seconds.
12/18/2013 13:21:46 INFO Initial results loaded. Ready for requests on
http://172.24.179.183:9133

 Copyright 2013 Google Inc.
 
 Use of this source code is governed by a BSD-style license that can be
 found in the LICENSE file.
 
 Repackage expected/actual GM results as needed by our HTML rebaseline viewer.
 """
 
 # System-level imports
 import fnmatch
@@ skipping 43 matching lines @@
   file contents, you will need to create a new Results object."""
 
   def __init__(self, actuals_root, expected_root, generated_images_root):
     """
     Args:
       actuals_root: root directory containing all actual-results.json files
       expected_root: root directory containing all expected-results.json files
       generated_images_root: directory within which to create all pixel diffs;
           if this directory does not yet exist, it will be created
     """
+    time_start = int(time.time())
     self._image_diff_db = imagediffdb.ImageDiffDB(generated_images_root)
     self._actuals_root = actuals_root
     self._expected_root = expected_root
     self._load_actual_and_expected()
     self._timestamp = int(time.time())
+    logging.info('Results complete; took %d seconds.' %
+                 (self._timestamp - time_start))
 
   def get_timestamp(self):
     """Return the time at which this object was created, in seconds past epoch
     (UTC).
     """
     return self._timestamp
 
   def edit_expectations(self, modifications):
     """Edit the expectations stored within this object and write them back
     to disk.
@@ skipping 199 matching lines @@
         expected_image_locator=expected_hashdigest,
         expected_image_url=expected_url,
         actual_image_locator=actual_hashdigest,
         actual_image_url=actual_url)
 
   def _load_actual_and_expected(self):
     """Loads the results of all tests, across all builders (based on the
     files within self._actuals_root and self._expected_root),
     and stores them in self._results.
     """
+    logging.info('Reading actual-results JSON files from %s...' %
+                 self._actuals_root)
     actual_builder_dicts = Results._read_dicts_from_root(self._actuals_root)
+    logging.info('Reading expected-results JSON files from %s...' %
+                 self._expected_root)
     expected_builder_dicts = Results._read_dicts_from_root(self._expected_root)
 
     categories_all = {}
     categories_failures = {}
 
     Results._ensure_included_in_category_dict(categories_all,
                                               'resultType', [
         gm_json.JSONKEY_ACTUALRESULTS_FAILED,
         gm_json.JSONKEY_ACTUALRESULTS_FAILUREIGNORED,
         gm_json.JSONKEY_ACTUALRESULTS_NOCOMPARISON,
         gm_json.JSONKEY_ACTUALRESULTS_SUCCEEDED,
         ])
     Results._ensure_included_in_category_dict(categories_failures,
                                               'resultType', [
         gm_json.JSONKEY_ACTUALRESULTS_FAILED,
         gm_json.JSONKEY_ACTUALRESULTS_FAILUREIGNORED,
         gm_json.JSONKEY_ACTUALRESULTS_NOCOMPARISON,
         ])
 
     data_all = []
     data_failures = []
-    for builder in sorted(actual_builder_dicts.keys()):
+    builders = sorted(actual_builder_dicts.keys())
+    num_builders = len(builders)
+    builder_num = 0
+    for builder in builders:
+      builder_num += 1
+      logging.info('Generating pixel diffs for builder #%d of %d, "%s"...' %
+                   (builder_num, num_builders, builder))
       actual_results_for_this_builder = (
           actual_builder_dicts[builder][gm_json.JSONKEY_ACTUALRESULTS])
       for result_type in sorted(actual_results_for_this_builder.keys()):
         results_of_this_type = actual_results_for_this_builder[result_type]
         if not results_of_this_type:
           continue
         for image_name in sorted(results_of_this_type.keys()):
           actual_image = results_of_this_type[image_name]
 
           # Default empty expectations; overwrite these if we find any real ones
@@ skipping 152 matching lines @@
       category_dict: category dict-of-dicts to modify
       category_name: category name, as a string
       category_values: list of values we want to make sure are represented
                        for this category
     """
     if not category_dict.get(category_name):
       category_dict[category_name] = {}
     for category_value in category_values:
       if not category_dict[category_name].get(category_value):
         category_dict[category_name][category_value] = 0