Speeding up the process of parsing gcovr xml (#163)

* Speeding up the process of parsing gcovr xml

* A bit of cleanup

* Improving logs

bugzoo/mgr/coverage.py

@@ -1,3 +1,4 @@
+from timeit import default_timer as timer
 from typing import List, Dict, Optional, Set
 import tempfile
 import os
@@ -53,12 +54,14 @@ def _from_gcovr_xml_string(self,
         logger = self.__logger.getChild(container.id)
         mgr_ctr = self.__installation.containers
         dir_source = container.bug.source_dir # TODO port
+        # getting a list of all files in source directory to later use for resolving path
+        resp = mgr_ctr.command(container, "find {} -type f".format(dir_source))
+        all_files = resp.output.split('\n')
+
 
         def has_file(fn_rel: str) -> bool:
             fn_abs = os.path.join(dir_source, fn_rel)
-            cmd = 'test -f "{}"'.format(fn_abs)
-            resp = mgr_ctr.command(container, cmd)
-            return resp.code == 0
+            return (fn_abs in all_files)
 
         # FIXME is this a general solution?
         def resolve_path(fn_rel: str) -> str:
@@ -77,6 +80,8 @@ def resolve_path(fn_rel: str) -> str:
         files_to_lines = {}
         packages = root.find('packages')
 
+        t_start = timer()
+        logger.debug("Starting to traverse all files reported by gcovr.")
         for package in packages.findall('package'):
             for cls in package.find('classes').findall('class'):
                 try:
@@ -91,6 +96,7 @@ def resolve_path(fn_rel: str) -> str:
                 if lines != []:
                     files_to_lines[path] = lines
 
+        logger.debug("Traversing all files finished. Seconds passed: %.2f", timer() - t_start)
         # modify coverage information for all of the instrumented files
         num_instrumentation_lines = CoverageManager.INSTRUMENTATION.count('\n')
         lines_to_remove = set(range(1, num_instrumentation_lines))
@@ -225,20 +231,29 @@ def extract(self,
         code files within the project. Destroys '.gcda' files upon computing
         coverage.
         """
+        logger = self.__logger.getChild(container.id)
         mgr_ctr = self.__installation.containers
+        logger.debug("Starting to extract coverage info")
 
         if not instrumented_files:
             instrumented_files = set()
         else:
             instrumented_files = set(instrumented_files)
 
         dir_source = container.bug.source_dir # TODO port
+        t_start = timer()
+        logger.debug("Running gcovr.")
         response = mgr_ctr.command(container,
                                    'gcovr -x -d -r .',
                                    context=dir_source)
+        logger.debug("gcovr returned. Seconds passed: %.2f", timer() - t_start)
         assert response.code == 0
         response = response.output
 
-        return self._from_gcovr_xml_string(response,
+        t_start = timer()
+        logger.debug("Parsing gcovr xml.")
+        res = self._from_gcovr_xml_string(response,
                                            instrumented_files,
                                            container)
+        logger.debug("Finished parsing gcovr xml. Seconds passed: %.2f", timer() - t_start)
+        return res