From 0bd0fb4c72b986ef92b02354bfb9484a5d05e37c Mon Sep 17 00:00:00 2001 From: Sam Hague Date: Sat, 20 Jan 2018 00:10:08 -0500 Subject: [PATCH] Add debug logging Change-Id: I27b2e74487dd6eaab57e859a8093df33e0314a07 Signed-off-by: Sam Hague --- tools/distchanges/changes.py | 139 +++++++++++++++++------- tools/distchanges/gerritquery.py | 83 ++++++++------ tools/distchanges/tests/test_changes.py | 9 +- 3 files changed, 156 insertions(+), 75 deletions(-) diff --git a/tools/distchanges/changes.py b/tools/distchanges/changes.py index 3fcafb88fa..608f3c520d 100644 --- a/tools/distchanges/changes.py +++ b/tools/distchanges/changes.py @@ -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)) diff --git a/tools/distchanges/gerritquery.py b/tools/distchanges/gerritquery.py index aa0ae59c2d..4e2c6cdd42 100644 --- a/tools/distchanges/gerritquery.py +++ b/tools/distchanges/gerritquery.py @@ -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 diff --git a/tools/distchanges/tests/test_changes.py b/tools/distchanges/tests/test_changes.py index a1cc8e5d2a..8628695f98 100644 --- a/tools/distchanges/tests/test_changes.py +++ b/tools/distchanges/tests/test_changes.py @@ -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 -- 2.36.6