[tracker/sam/functional-tests-shared: 3/7] functional-tests: Remove log() helper function

[Sam Thursfield <sthursfield src gnome org>]

commit 59225f7aad49e5611b200e65547ff6f3f6026c81
Author: Sam Thursfield <sam afuera me uk>
Date:   Wed Aug 7 15:00:33 2019 +0200

    functional-tests: Remove log() helper function
    
    Let's use Python's actual 'logging' module instead.

 tests/functional-tests/17-ontology-changes.py      |  8 +++--
 .../functional-tests/common/utils/configuration.py | 10 ++++++-
 tests/functional-tests/common/utils/dconf.py       |  5 ++--
 tests/functional-tests/common/utils/helpers.py     | 34 +++++++++++-----------
 4 files changed, 34 insertions(+), 23 deletions(-)
---
diff --git a/tests/functional-tests/17-ontology-changes.py b/tests/functional-tests/17-ontology-changes.py
index 687757fe1..45817038c 100755
--- a/tests/functional-tests/17-ontology-changes.py
+++ b/tests/functional-tests/17-ontology-changes.py
@@ -25,6 +25,7 @@ changes and checking if the data is still there.
 
 from gi.repository import GLib
 
+import logging
 import os
 import shutil
 import re
@@ -49,6 +50,8 @@ TEST_ENV_VARS = {"LC_COLLATE": "en_GB.utf8"}
 
 REASONABLE_TIMEOUT = 5
 
+log = logging.getLogger()
+
 
 class UnableToBootException (Exception):
     pass
@@ -88,12 +91,11 @@ class TrackerSystemAbstraction (object):
             os.environ[var] = directory
 
         if ontodir:
-            helpers.log("export %s=%s" %
-                        ("TRACKER_DB_ONTOLOGIES_DIR", ontodir))
+            log.debug("export %s=%s", "TRACKER_DB_ONTOLOGIES_DIR", ontodir)
             os.environ["TRACKER_DB_ONTOLOGIES_DIR"] = ontodir
 
         for var, value in TEST_ENV_VARS.items():
-            helpers.log("export %s=%s" % (var, value))
+            log.debug("export %s=%s", var, value)
             os.environ[var] = value
 
         # Previous loop should have set DCONF_PROFILE to the test location
diff --git a/tests/functional-tests/common/utils/configuration.py 
b/tests/functional-tests/common/utils/configuration.py
index 9fd8c1c64..f90d76d13 100644
--- a/tests/functional-tests/common/utils/configuration.py
+++ b/tests/functional-tests/common/utils/configuration.py
@@ -18,10 +18,14 @@
 # 02110-1301, USA.
 #
 
-"Constants describing Tracker D-Bus services"
 
 import json
+import logging
 import os
+import sys
+
+from . import options
+
 
 if 'TRACKER_FUNCTIONAL_TEST_CONFIG' not in os.environ:
     raise RuntimeError("The TRACKER_FUNCTIONAL_TEST_CONFIG environment "
@@ -96,3 +100,7 @@ def generated_ttl_dir():
         return os.path.join(TOP_BUILDDIR, 'tests', 'functional-tests', 'ttl')
     else:
         return 'ttl'
+
+
+if options.get_environment_boolean('TRACKER_TESTS_VERBOSE'):
+    logging.basicConfig(stream=sys.stderr, level=logging.DEBUG)
diff --git a/tests/functional-tests/common/utils/dconf.py b/tests/functional-tests/common/utils/dconf.py
index d4b42dfe9..328f9b845 100644
--- a/tests/functional-tests/common/utils/dconf.py
+++ b/tests/functional-tests/common/utils/dconf.py
@@ -1,9 +1,10 @@
 from gi.repository import GLib
 from gi.repository import Gio
 
+import logging
 import os
 
-from common.utils.helpers import log
+log = logging.getLogger(__name__)
 
 
 class DConfClient(object):
@@ -75,5 +76,5 @@ class DConfClient(object):
                                 "dconf",
                                 "trackertest")
         if os.path.exists(dconf_db):
-            log("[Conf] Removing dconf database: " + dconf_db)
+            log.debug("[Conf] Removing dconf database: %s", dconf_db)
             os.remove(dconf_db)
diff --git a/tests/functional-tests/common/utils/helpers.py b/tests/functional-tests/common/utils/helpers.py
index 6e5c26c40..b19d72c08 100644
--- a/tests/functional-tests/common/utils/helpers.py
+++ b/tests/functional-tests/common/utils/helpers.py
@@ -17,13 +17,16 @@
 # Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
 # 02110-1301, USA.
 #
+
 from gi.repository import Gio
 from gi.repository import GLib
+
+import logging
 import os
+import re
 import sys
 import subprocess
 import time
-import re
 
 from common.utils import configuration as cfg
 from common.utils import options as options
@@ -34,10 +37,7 @@ class NoMetadataException (Exception):
 
 REASONABLE_TIMEOUT = 30
 
-
-def log(message):
-    if options.is_verbose():
-        print(message)
+log = logging.getLogger(__name__)
 
 
 class Helper:
@@ -94,19 +94,19 @@ class Helper:
             kws['env'] = env
 
         command = [path] + flags
-        log("Starting %s" % ' '.join(command))
+        log.debug("Starting %s", ' '.join(command))
         try:
             return subprocess.Popen([path] + flags, **kws)
         except OSError as e:
             raise RuntimeError("Error starting %s: %s" % (path, e))
 
     def _bus_name_appeared(self, name, owner, data):
-        log("[%s] appeared in the bus as %s" % (self.PROCESS_NAME, owner))
+        log.debug("[%s] appeared in the bus as %s", self.PROCESS_NAME, owner)
         self.available = True
         self.loop.quit()
 
     def _bus_name_vanished(self, name, data):
-        log("[%s] disappeared from the bus" % self.PROCESS_NAME)
+        log.debug("[%s] disappeared from the bus", self.PROCESS_NAME)
         self.available = False
         self.loop.quit()
 
@@ -132,7 +132,7 @@ class Helper:
                                (self.PROCESS_NAME, status, error))
 
     def _timeout_on_idle_cb(self):
-        log("[%s] Timeout waiting... asumming idle." % self.PROCESS_NAME)
+        log.debug("[%s] Timeout waiting... asumming idle.", self.PROCESS_NAME)
         self.loop.quit()
         self.timeout_id = None
         return False
@@ -159,8 +159,8 @@ class Helper:
                                 "already running " % self.PROCESS_NAME)
 
             self.process = self._start_process(env=env)
-            log('[%s] Started process %i' %
-                (self.PROCESS_NAME, self.process.pid))
+            log.debug('[%s] Started process %i',
+                self.PROCESS_NAME, self.process.pid)
             self.process_watch_timeout = GLib.timeout_add(
                 200, self._process_watch_cb)
 
@@ -187,12 +187,12 @@ class Helper:
                 time.sleep(0.1)
 
                 if time.time() > (start + REASONABLE_TIMEOUT):
-                    log("[%s] Failed to terminate, sending kill!" %
+                    log.debug("[%s] Failed to terminate, sending kill!",
                         self.PROCESS_NAME)
                     self.process.kill()
                     self.process.wait()
 
-        log("[%s] stopped." % self.PROCESS_NAME)
+        log.debug("[%s] stopped.", self.PROCESS_NAME)
 
         # Run the loop until the bus name appears, or the process dies.
         self.loop.run()
@@ -202,7 +202,7 @@ class Helper:
 
     def kill(self):
         if options.is_manual_start():
-            log("kill(): ignoring, because process was started manually.")
+            log.debug("kill(): ignoring, because process was started manually.")
             return
 
         if self.process_watch_timeout != 0:
@@ -217,7 +217,7 @@ class Helper:
 
         self.process = None
 
-        log("[%s] killed." % self.PROCESS_NAME)
+        log.debug("[%s] killed.", self.PROCESS_NAME)
 
 
 class StoreHelper (Helper):
@@ -251,9 +251,9 @@ class StoreHelper (Helper):
             self.bus, Gio.DBusProxyFlags.DO_NOT_AUTO_START, None,
             cfg.TRACKER_BUSNAME, cfg.TRACKER_STATUS_OBJ_PATH, cfg.STATUS_IFACE)
 
-        log("[%s] booting..." % self.PROCESS_NAME)
+        log.debug("[%s] booting...", self.PROCESS_NAME)
         self.status_iface.Wait()
-        log("[%s] ready." % self.PROCESS_NAME)
+        log.debug("[%s] ready.", self.PROCESS_NAME)
 
     def stop(self):
         Helper.stop(self)