Add debug logging 73/67373/3
authorSam Hague <shague@redhat.com>
Sat, 20 Jan 2018 05:10:08 +0000 (00:10 -0500)
committerSam Hague <shague@redhat.com>
Sat, 20 Jan 2018 05:30:38 +0000 (05:30 +0000)
Change-Id: I27b2e74487dd6eaab57e859a8093df33e0314a07
Signed-off-by: Sam Hague <shague@redhat.com>
tools/distchanges/changes.py
tools/distchanges/gerritquery.py
tools/distchanges/tests/test_changes.py

index 3fcafb88fa07f7d12c31b0a6363bc3e5093bbbb3..608f3c520dd3af4334415879817c0fc83f088808 100644 (file)
@@ -1,6 +1,7 @@
 #!/usr/bin/env python
 import argparse
 import gerritquery
+import logging
 import os
 import re
 import sys
@@ -39,6 +40,19 @@ See the License for the specific language governing permissions and
 limitations under the License."""
 
 
+logger = logging.getLogger("changes")
+logger.setLevel(logging.DEBUG)
+formatter = logging.Formatter('%(asctime)s - %(levelname).4s - %(name)s - %(lineno)04d - %(message)s')
+ch = logging.StreamHandler()
+ch.setLevel(logging.INFO)
+ch.setFormatter(formatter)
+logger.addHandler(ch)
+fh = logging.FileHandler("/tmp/changes.txt", "w")
+fh.setLevel(logging.DEBUG)
+fh.setFormatter(formatter)
+logger.addHandler(fh)
+
+
 class ChangeId(object):
     def __init__(self, changeid, merged):
         self.changeid = changeid
@@ -52,7 +66,7 @@ class Changes(object):
     NETVIRT_PROJECTS = ["netvirt", "controller", "dlux", "dluxapps", "genius", "infrautils", "mdsal", "netconf",
                         "neutron", "odlparent", "openflowplugin", "ovsdb", "sfc", "yangtools"]
     PROJECT_NAMES = NETVIRT_PROJECTS
-    VERBOSE = 0
+    VERBOSE = logging.INFO
     DISTRO_PATH = "/tmp/distribution-karaf"
     DISTRO_URL = None
     REMOTE_URL = gerritquery.GerritQuery.REMOTE_URL
@@ -70,6 +84,9 @@ class Changes(object):
     remote_url = REMOTE_URL
     verbose = VERBOSE
     projects = {}
+    regex_changeid = None
+    regex_shortmsg = None
+    regex_longmsg = None
 
     def __init__(self, branch=BRANCH, distro_path=DISTRO_PATH,
                  limit=LIMIT, qlimit=QUERY_LIMIT,
@@ -83,6 +100,17 @@ class Changes(object):
         self.remote_url = remote_url
         self.verbose = verbose
         self.projects = {}
+        self.set_log_level(verbose)
+        self.regex_changeid = re.compile(r'\bI([a-f0-9]{40})\b|\bI([a-f0-9]{8})\b')
+        # self.regex_shortmsg = re.compile(r'"([^"]*)"|(git.commit.message.short=(.*))')
+        self.regex_shortmsg1 = re.compile(r'(git.commit.message.short=.*"([^"]*)")')
+        self.regex_shortmsg2 = re.compile(r'(git.commit.message.short=(.*))')
+        self.regex_longmsg = re.compile(r'git.commit.message.full=(.*)')
+        self.regex_commitid = re.compile(r'(git.commit.id=(.*))')
+
+    @staticmethod
+    def set_log_level(level):
+        ch.setLevel(level)
 
     def epoch_to_utc(self, epoch):
         utc = time.gmtime(epoch)
@@ -120,9 +148,7 @@ class Changes(object):
         """
         Download the distribution from self.distro_url and extract it to self.distro_path
         """
-        if self.verbose >= 2:
-            print("attempting to download distribution from %s and extract to %s " %
-                  (self.distro_url, self.distro_path))
+        logger.info("attempting to download distribution from %s and extract to %s", self.distro_url, self.distro_path)
 
         tmp_distro_zip = '/tmp/distro.zip'
         tmp_unzipped_location = '/tmp/distro_unzipped'
@@ -148,9 +174,9 @@ class Changes(object):
         try:
             os.rename(tmp_unzipped_location + "/" + unzipped_distro_folder[0], self.distro_path)
         except OSError as e:
-            print(e)
-            print("Unable to move extracted files from %s to %s. Using whatever bits are already there" %
-                  (tmp_unzipped_location, self.distro_path))
+            logger.warn(e)
+            logger.warn("Unable to move extracted files from %s to %s. Using whatever bits are already there",
+                        tmp_unzipped_location, self.distro_path)
 
     def get_includes(self, project, changeid=None, msg=None, merged=True):
         """
@@ -167,7 +193,7 @@ class Changes(object):
         else:
             includes = self.gerritquery.get_gerrits(project, changeid, 1, None, None, True)
         if not includes:
-            print("Review %s in %s:%s was not found" % (changeid, project, self.gerritquery.branch))
+            logger.info("Review %s in %s:%s was not found", changeid, project, self.gerritquery.branch)
             return None
 
         gerrits = self.gerritquery.get_gerrits(project, changeid=None, limit=self.qlimit, msg=msg, status="merged")
@@ -185,7 +211,7 @@ class Changes(object):
                 break
 
         if len(includes) != self.limit + 1:
-            print("%s query limit was not large enough to capture %d gerrits" % (project, self.limit))
+            logger.info("%s query limit was not large enough to capture %d gerrits", project, self.limit)
 
         return includes
 
@@ -223,62 +249,102 @@ class Changes(object):
         :param str pfile: String containing the content of the git.properties file
         :return ChangeId: The Change-Id with a valid Change-Id or None if not found
         """
+        logger.info("trying Change-Id from git.properties in %s", project)
         # match a 40 or 8 char Change-Id hash. both start with I
-        regex = re.compile(r'\bI([a-f0-9]{40})\b|\bI([a-f0-9]{8})\b')
-        changeid = regex.search(pfile)
+        changeid = self.regex_changeid.search(pfile)
         if changeid:
-            if self.verbose >= 1:
-                print("trying Change-Id as merged in %s" % (project))
+            logger.info("trying Change-Id from git.properties as merged in %s: %s", project, changeid.group())
 
             gerrits = self.gerritquery.get_gerrits(project, changeid.group(), 1, None, status="merged")
             if gerrits:
+                logger.info("found Change-Id from git.properties as merged in %s", project)
                 return ChangeId(changeid.group(), True)
 
             # Maybe this is a patch that has not merged yet
-            if self.verbose >= 1:
-                print("did not find Change-Id as merged in %s, trying as unmerged" % project)
+            logger.info("did not find Change-Id from git.properties as merged in %s, trying as unmerged: %s",
+                        project, changeid.group())
 
             gerrits = self.gerritquery.get_gerrits(project, changeid.group(), 1, None, status=None, comments=True)
             if gerrits:
+                logger.info("found Change-Id from git.properties as unmerged in %s", project)
                 return ChangeId(gerrits[0]["id"], False)
 
+        logger.info("did not find Change-Id from git.properties in %s, trying commitid", project)
+
+        # match a 40 or 8 char Change-Id hash. both start with I
+        commitid = self.regex_commitid.search(pfile)
+        if commitid and commitid.group(2):
+            logger.info("trying commitid from git.properties in %s: %s", project, commitid.group(2))
+
+            gerrits = self.gerritquery.get_gerrits(project, commitid=commitid.group(2))
+            if gerrits:
+                logger.info("found Change-Id from git.properties as unmerged in %s", project)
+                return ChangeId(gerrits[0]["id"], True)
+
+        logger.info("did not find Change-Id from commitid from git.properties in %s, trying short commit message1",
+                    project)
+
         # Didn't find a Change-Id so try to get a commit message
         # match on "blah" but only keep the blah
-        regex_msg = re.compile(r'"([^"]*)"|^git.commit.message.short=(.*)$')
-        msg = regex_msg.search(pfile)
-        if msg:
-            if self.verbose >= 1:
-                print("did not find Change-Id in %s, trying with commit-msg: %s" % (project, msg.group()))
+        msg = self.regex_shortmsg1.search(pfile)
+        if msg and msg.group(2):
+            # logger.info("msg.groups 0: %s, 1: %s, 2: %s", msg.group(), msg.group(1), msg.group(2))
+            logger.info("trying with short commit-msg 1 from git.properties in %s: %s", project, msg.group(2))
 
-            gerrits = self.gerritquery.get_gerrits(project, None, 1, msg.group())
+            gerrits = self.gerritquery.get_gerrits(project, msg=msg.group(2))
             if gerrits:
+                logger.info("found Change-Id from git.properties short commit-msg 1 in %s", project)
                 return ChangeId(gerrits[0]["id"], True)
 
-            msg_no_spaces = msg.group().replace(" ", "+")
-            if self.verbose >= 1:
-                print("did not find Change-Id in %s, trying with commit-msg (no spaces): %s" % (project, msg_no_spaces))
+            msg_no_spaces = msg.group(2).replace(" ", "+")
+            logger.info("did not find Change-Id in %s, trying with commit-msg 1 (no spaces): %s",
+                        project, msg_no_spaces)
 
-            gerrits = self.gerritquery.get_gerrits(project, None, 1, msg_no_spaces)
+            gerrits = self.gerritquery.get_gerrits(project, msg=msg_no_spaces)
             if gerrits:
+                logger.info("found Change-Id from git.properties short commit-msg 1 (no spaces) in %s", project)
                 return ChangeId(gerrits[0]["id"], True)
 
+        logger.info("did not find Change-Id from short commit message1 from git.properties in %s", project)
+
+        # Didn't find a Change-Id so try to get a commit message
+        # match on "blah" but only keep the blah
+        msg = self.regex_shortmsg2.search(pfile)
+        if msg and msg.group(2):
+            logger.info("trying with short commit-msg 2 from git.properties in %s: %s", project, msg.group(2))
+
+            gerrits = self.gerritquery.get_gerrits(project, msg=msg.group(2))
+            if gerrits:
+                logger.info("found Change-Id from git.properties short commit-msg 2 in %s", project)
+                return ChangeId(gerrits[0]["id"], True)
+
+            msg_no_spaces = msg.group(2).replace(" ", "+")
+            logger.info("did not find Change-Id in %s, trying with commit-msg 2 (no spaces): %s",
+                        project, msg_no_spaces)
+
+            gerrits = self.gerritquery.get_gerrits(project, msg=msg_no_spaces)
+            if gerrits:
+                logger.info("found Change-Id from git.properties short commit-msg 2 (no spaces) in %s", project)
+                return ChangeId(gerrits[0]["id"], True)
+
+        logger.info("did not find Change-Id from short commit message2 from git.properties in %s", project)
+
         # Maybe one of the monster 'merge the world' gerrits
-        regex_msg = re.compile(r'git.commit.message.full=(.*)')
-        msg = regex_msg.search(pfile)
+        msg = self.regex_longmsg.search(pfile)
         first_msg = None
         if msg:
             lines = str(msg.group()).split("\\n")
             cli = next((i for i, line in enumerate(lines[:-1]) if '* changes\\:' in line), None)
             first_msg = lines[cli + 1] if cli else None
         if first_msg:
-            if self.verbose >= 1:
-                print("did not find Change-Id or commit-msg in %s, trying with merge commit-msg: %s"
-                      % (project, first_msg))
+            logger.info("did not find Change-Id or short commit-msg in %s, trying with merge commit-msg: %s",
+                        project, first_msg)
             gerrits = self.gerritquery.get_gerrits(project, None, 1, first_msg)
             if gerrits:
+                logger.info("found Change-Id from git.properties merge commit-msg in %s", project)
                 return ChangeId(gerrits[0]["id"], True)
 
-        print("did not find Change-Id for %s" % project)
+        logger.warn("did not find Change-Id for %s" % project)
 
         return ChangeId(None, False)
 
@@ -302,12 +368,12 @@ class Changes(object):
                         if changeid.changeid:
                             return changeid
                         else:
-                            print("Could not find %s Change-Id in git.properties" % project)
+                            logger.warn("Could not find %s Change-Id in git.properties", project)
                             break  # all jars will have the same git.properties
             if pfile is not None:
                 break  # all jars will have the same git.properties
         if pfile is None:
-            print("Could not find a git.properties file for %s" % project)
+            logger.warn("Could not find a git.properties file for %s", project)
         return ChangeId(None, False)
 
     def init(self):
@@ -341,8 +407,7 @@ class Changes(object):
             self.download_distro()
 
         for project in sorted(self.projects):
-            if self.verbose >= 1:
-                print("Processing %s" % project)
+            logger.info("Processing %s", project)
             changeid = self.find_distro_changeid(project)
             if changeid.changeid:
                 self.projects[project]['commit'] = changeid.changeid
@@ -411,9 +476,9 @@ def main():
             u = unicode(e)
         except NameError:
             # Python 3, we"re home free.
-            print(e)
+            logger.warn(e)
         else:
-            print(u.encode("utf-8"))
+            logger.warn(u.encode("utf-8"))
             raise
         sys.exit(getattr(e, "EXIT_CODE", -1))
 
index aa0ae59c2d9c0a070665dc1577713be5ebbef439..4e2c6cdd42cb00f687312931e174b5c3d524b4d2 100644 (file)
@@ -3,6 +3,7 @@ This module contains functions to manipulate gerrit queries.
 """
 import datetime
 import json
+import logging
 import os
 import re
 import shlex
@@ -29,6 +30,9 @@ else:
     do_input = input
 
 
+logger = logging.getLogger("changes.gerritquery")
+
+
 class GitReviewException(Exception):
     EXIT_CODE = 127
 
@@ -61,7 +65,6 @@ class GerritQuery:
     remote_url = REMOTE_URL
     branch = BRANCH
     query_limit = QUERY_LIMIT
-    verbose = 0
 
     def __init__(self, remote_url, branch, query_limit, verbose):
         self.remote_url = remote_url
@@ -69,21 +72,18 @@ class GerritQuery:
         self.query_limit = query_limit
         self.verbose = verbose
 
-    def set_verbose(self, verbose):
-        self.verbose = verbose
-
     @staticmethod
     def print_safe_encoding(string):
-        if sys.stdout.encoding is None:
-            # just print(string) could still throw a UnicodeEncodeError sometimes so casting string to unicode
-            print(unicode(string))
+        if type(string) == unicode:
+            encoding = 'utf-8'
+            if hasattr(sys.stdout, 'encoding') and sys.stdout.encoding:
+                encoding = sys.stdout.encoding
+            return string.encode(encoding or 'utf-8', 'replace')
         else:
-            print(string.encode(sys.stdout.encoding, 'replace'))
+            return str(string)
 
     def run_command_status(self, *argv, **kwargs):
-
-        if self.verbose >= 2:
-            print(datetime.datetime.now(), "Running:", " ".join(argv))
+        logger.debug("%s Running: %s", datetime.datetime.now(), " ".join(argv))
         if len(argv) == 1:
             # for python2 compatibility with shlex
             if sys.version_info < (3,) and isinstance(argv[0], unicode):
@@ -180,17 +180,13 @@ class GerritQuery:
         else:
             userhost = "%s@%s" % (username, hostname)
 
-        if self.verbose >= 2:
-            print("gerrit request %s %s" % (self.remote_url, request))
-        output = self.run_command_exc(
-            CommandFailed,
-            "ssh", "-x" + port_data, userhost,
-            request)
-        if self.verbose >= 3:
-            self.print_safe_encoding(output)
+        logger.debug("gerrit request %s %s" % (self.remote_url, request))
+        output = self.run_command_exc(CommandFailed, "ssh", "-x" + port_data, userhost, request)
+        if logger.isEnabledFor(logging.DEBUG):
+            logger.debug("%s", self.print_safe_encoding(output))
         return output
 
-    def make_gerrit_query(self, project, changeid=None, limit=1, msg=None, status=None, comments=False):
+    def make_gerrit_query(self, project, changeid=None, limit=1, msg=None, status=None, comments=False, commitid=None):
         """
         Make a gerrit query by combining the given options.
 
@@ -200,15 +196,24 @@ class GerritQuery:
         :param str msg or None: A commit-msg to search
         :param str status or None: The gerrit status, i.e. merged
         :param bool comments: If true include comments
+        :param commitid: A commit hash to search
         :return str: A gerrit query
         """
-        query = "gerrit query --format=json limit:%d " \
-                "project:%s branch:%s" \
-                % (limit, project, self.branch)
+
+        if project == "odlparent" or project == "yangtools":
+            query = "gerrit query --format=json limit:%d " \
+                    "project:%s" \
+                    % (limit, project)
+        else:
+            query = "gerrit query --format=json limit:%d " \
+                    "project:%s branch:%s" \
+                    % (limit, project, self.branch)
         if changeid:
             query += " change:%s" % changeid
         if msg:
-            query += " message:%s" % msg
+            query += " message:{%s}" % msg
+        if commitid:
+            query += " commit:%s" % commitid
         if status:
             query += " status:%s --all-approvals" % status
         if comments:
@@ -258,11 +263,11 @@ class GerritQuery:
                                     parsed['grantedOn'] = timestamp
                                     break
                 except Exception:
-                    if self.verbose:
-                        print("Failed to decode JSON: %s" % traceback.format_exc())
-                        self.print_safe_encoding(line)
+                    logger.warn("Failed to decode JSON: %s", traceback.format_exc())
+                    if logger.isEnabledFor(logging.DEBUG):
+                        logger.warn(self.print_safe_encoding(line))
         except Exception as err:
-            print("Exception: %s" % traceback.format_exc())
+            logger.warn("Exception: %s", traceback.format_exc())
             raise parse_exc(err)
         return parsed
 
@@ -278,15 +283,14 @@ class GerritQuery:
         lines = []
         for line in changes.split("\n"):
             if line.find('"type":"error","message"') != -1:
-                print("there was a query error")
+                logger.warn("there was a query error")
                 continue
             if line.find('stats') == -1:
                 lines.append(line)
-        if self.verbose >= 2:
-            print("get_gerrit_lines: found %d lines" % len(lines))
+        logger.debug("get_gerrit_lines: found %d lines", len(lines))
         return lines
 
-    def get_gerrits(self, project, changeid=None, limit=1, msg=None, status=None, comments=False):
+    def get_gerrits(self, project, changeid=None, limit=1, msg=None, status=None, comments=False, commitid=None):
         """
         Get a list of gerrits from gerrit query request.
 
@@ -302,15 +306,26 @@ class GerritQuery:
         :param str or None msg: A commit-msg to search
         :param str or None status: The gerrit status, i.e. merged
         :param bool comments: If true include comments
+        :param commitid: A commit hash to search
         :return str: List of gerrits sorted by merge time
         """
-        query = self.make_gerrit_query(project, changeid, limit, msg, status, comments)
+        logger.debug("get_gerrits: project: %s, changeid: %s, limit: %d, msg: %s, status: %s, comments: %s, " +
+                     "commitid: %s",
+                     project, changeid, limit, msg, status, comments, commitid)
+        query = self.make_gerrit_query(project, changeid, limit, msg, status, comments, commitid)
         changes = self.gerrit_request(query)
         lines = self.extract_lines_from_json(changes)
         gerrits = []
+        sorted_gerrits = []
         for line in lines:
             gerrits.append(self.parse_gerrit(line))
 
         from operator import itemgetter
-        sorted_gerrits = sorted(gerrits, key=itemgetter('grantedOn'), reverse=True)
+        if gerrits is None:
+            logger.warn("No gerrits were found for %s", project)
+            return gerrits
+        try:
+            sorted_gerrits = sorted(gerrits, key=itemgetter('grantedOn'), reverse=True)
+        except KeyError, e:
+            logger.warn("KeyError exception in %s, %s", project, str(e))
         return sorted_gerrits
index a1cc8e5d2a7337e315c08abe6064342ba0dda28a..8628695f98591220ef242978a885f480299f0ca0 100644 (file)
@@ -2,6 +2,7 @@
 
 # TODO: Add more tests here using all the tests/resources/* and automate those tests in a verify job
 
+import logging
 import unittest
 import distcompare
 from changes import Changes
@@ -11,7 +12,7 @@ NETVIRT_PROJECTS = ["controller", "dlux", "dluxapps", "genius", "infrautils", "m
                     "neutron", "odlparent", "openflowplugin", "ovsdb", "sfc", "yangtools"]
 PROJECT_NAMES = NETVIRT_PROJECTS
 DISTRO_PATH = "/tmp/distribution-karaf"
-BRANCH = 'master'
+BRANCH = 'stable/nitrogen'
 LIMIT = 10
 QLIMIT = 50
 
@@ -28,14 +29,14 @@ class TestChanges(unittest.TestCase):
         changes.pretty_print_projects(projects)
 
     def test_run_cmd_single(self):
-        project_names = ['neutron']
+        project_names = ['odlparent']
         branch = BRANCH
-        self.run_cmd(branch, DISTRO_PATH, LIMIT, QLIMIT, project_names, REMOTE_URL, 1)
+        self.run_cmd(branch, DISTRO_PATH, LIMIT, QLIMIT, project_names, REMOTE_URL, logging.INFO)
 
     def test_run_cmd_multiple(self):
         project_names = PROJECT_NAMES
         branch = BRANCH
-        self.run_cmd(branch, DISTRO_PATH, LIMIT, QLIMIT, project_names, REMOTE_URL, 1)
+        self.run_cmd(branch, DISTRO_PATH, LIMIT, QLIMIT, project_names, REMOTE_URL, logging.INFO)
 
     def test_pretty_print(self):
         project_names = PROJECT_NAMES