From f0c9d2581afd03b41dfc304365890e5484843beb Mon Sep 17 00:00:00 2001 From: Clement Verna Date: Feb 02 2020 20:22:31 +0000 Subject: [PATCH 1/2] Skip tickets for specific composes. This commit uses the fedora-messaging configuration file to configure a list of composes to skip. This commit also add unit tests in order to test that feature. A brief description on how to run the tests was also added to the README file. Signed-off-by: Clement Verna --- diff --git a/Dockerfile b/Dockerfile index 22ec84f..14d87ec 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,4 +1,4 @@ -FROM registry.fedoraproject.org/fedora:30 +FROM registry.fedoraproject.org/fedora:31 # set PYTHONUNBUFFERED env var to non-empty string so that our # periods with no newline get printed immediately to the screen @@ -13,31 +13,21 @@ RUN dnf -y install python3-ogr fedora-messaging && dnf clean all RUN mkdir /work WORKDIR /work + +ADD compose-tracker.toml /work/my_config.toml # Copy the fedora config for fedora-messaging and also generate a random UUID # https://fedora-messaging.readthedocs.io/en/latest/fedora-broker.html#getting-connected # Note this will mean that if there is more than one container running # using this image they will be reading from the same queue. Generally # I expect this to only be running in one place. -RUN sed -e "s/[0-9a-f]\{8\}-[0-9a-f]\{4\}-[0-9a-f]\{4\}-[0-9a-f]\{4\}-[0-9a-f]\{12\}/$(uuidgen)/g" /etc/fedora-messaging/fedora.toml > /work/my_config.toml - -# Set the Application Name -RUN sed -i 's|Example Application|Compose Tracker: https://pagure.io/releng/compose-tracker|' /work/my_config.toml +RUN sed -i "s/[0-9a-f]\{8\}-[0-9a-f]\{4\}-[0-9a-f]\{4\}-[0-9a-f]\{4\}-[0-9a-f]\{12\}/$(uuidgen)/g" /work/my_config.toml # Lower log levels to WARNING level #RUN sed -i 's/INFO/WARNING/' /work/my_config.toml -# Set the log config of compose_tracker -RUN sed -i 's/\[log_config\]/\[log_config\]\nlevel = "DEBUG"/' /work/my_config.toml - -# Set the format for the log messages -RUN sed -i 's/format =.*$/format = "%(asctime)s %(levelname)s %(name)s - %(message)s"/' /work/my_config.toml - -# We only care about pungi.compose.status.change messages -RUN sed -i 's/^routing_keys.*$/routing_keys = ["org.fedoraproject.prod.pungi.compose.status.change"]/' /work/my_config.toml - # Put compose-tracker into a location that can be imported ADD compose_tracker.py /usr/lib/python3.7/site-packages/ # Call fedora-messaging CLI and tell it to use the ComposeTracker # class from the compose-tracker module. -CMD fedora-messaging --conf /work/my_config.toml consume --callback=compose_tracker:Consumer +CMD fedora-messaging --conf /work/my_config.toml consume diff --git a/README.md b/README.md index 3c32906..3135d4c 100644 --- a/README.md +++ b/README.md @@ -1,6 +1,6 @@ # compose-tracker -Source code that parses pungi logs and opens issues against +Source code that parses pungi logs and opens issues against https://pagure.io/releng/failed-composes # Deploying in Fedora @@ -33,7 +33,7 @@ oc new-project compose-tracker oc new-build --strategy=docker https://pagure.io/releng/compose-tracker --to compose-tracker-img ``` -Export pagure token to use as an env var and then use +Export pagure token to use as an env var and then use [kedge](https://github.com/kedgeproject/kedge) to get up and running in openshift: @@ -41,3 +41,25 @@ to get up and running in openshift: export PAGURE_TOKEN= kedge apply -f kedge.yaml ``` + +# Development Environment + +To run compose_tracker's tests on your local machine you need to create a virtual environment + +``` +$ python -m venv .venv +$ source .venv/bin/activate +(.venv) $ +``` + +Then you can install the dependencies using the requirements.txt file + +``` +(.venv) $ pip install -r requirements.txt +``` + +Finally you can run the tests + +``` +(.venv) $ py.test test_consumer.py -v +``` diff --git a/compose-tracker.toml b/compose-tracker.toml new file mode 100644 index 0000000..1f8b4ab --- /dev/null +++ b/compose-tracker.toml @@ -0,0 +1,78 @@ +# A basic configuration for Fedora's message broker +# +# This file is in the TOML format. +amqp_url = "amqps://fedora:@rabbitmq.fedoraproject.org/%2Fpublic_pubsub" +callback = "compose_tracker:Consumer" + +[tls] +ca_cert = "/etc/fedora-messaging/cacert.pem" +keyfile = "/etc/fedora-messaging/fedora-key.pem" +certfile = "/etc/fedora-messaging/fedora-cert.pem" + +[client_properties] +app = "compose_tracker" +app_url = "https://pagure.io/releng/compose-tracker" + +[exchanges."amq.topic"] +type = "topic" +durable = true +auto_delete = false +arguments = {} + +# Queue names *must* be in the normal UUID format: run "uuidgen" and use the +# output as your queue name. If your queue is not exclusive, anyone can connect +# and consume from it, causing you to miss messages, so do not share your queue +# name. Any queues that are not auto-deleted on disconnect are garbage-collected +# after approximately one hour. +# +# If you require a stronger guarantee about delivery, please talk to Fedora's +# Infrastructure team. +[queues.00000000-0000-0000-0000-000000000000] +durable = false +auto_delete = true +exclusive = true +arguments = {} + +[[bindings]] +queue = "00000000-0000-0000-0000-000000000000" +exchange = "amq.topic" +routing_keys = ["org.fedoraproject.prod.pungi.compose.status.change"] + +[consumer_config] +composes_to_skip = ["IoT"] + +[qos] +prefetch_size = 0 +prefetch_count = 25 + +[log_config] +level = "DEBUG" +version = 1 +disable_existing_loggers = true + +[log_config.formatters.simple] +format = "%(asctime)s %(levelname)s %(name)s - %(message)s" + +[log_config.handlers.console] +class = "logging.StreamHandler" +formatter = "simple" +stream = "ext://sys.stdout" + +[log_config.loggers.fedora_messaging] +level = "INFO" +propagate = false +handlers = ["console"] + +[log_config.loggers.twisted] +level = "INFO" +propagate = false +handlers = ["console"] + +[log_config.loggers.pika] +level = "WARNING" +propagate = false +handlers = ["console"] + +[log_config.root] +level = "ERROR" +handlers = ["console"] diff --git a/compose_tracker.py b/compose_tracker.py index af6cccd..a354526 100755 --- a/compose_tracker.py +++ b/compose_tracker.py @@ -6,17 +6,16 @@ # modify it under the terms of the GNU Lesser General Public # License as published by the Free Software Foundation; either # version 2 of the License, or (at your option) any later version. -# +# # This library is distributed in the hope that it will be useful, # but WITHOUT ANY WARRANTY; without even the implied warranty of # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU # Lesser General Public License for more details. -# +# # You should have received a copy of the GNU Lesser General Public # License along with this library. If not, see . import datetime -import fedora_messaging.api import json import logging import os @@ -25,9 +24,12 @@ import requests import sys import traceback +import fedora_messaging.api +import fedora_messaging.config from ogr import PagureService -# Set local logging + +# Set local logging logger = logging.getLogger(__name__) logger.setLevel(logging.INFO) @@ -42,7 +44,8 @@ KOJI_TASK_URL='https://koji.fedoraproject.org/koji/taskinfo?taskID=' # We are processing the org.fedoraproject.prod.pungi.compose.status.change topic # https://apps.fedoraproject.org/datagrepper/raw?topic=org.fedoraproject.prod.pungi.compose.status.change&delta=100000 -EXAMPLE_MESSAGE_BODY = json.loads(""" +EXAMPLE_MESSAGE_BODY = json.loads( + """ { "status": "DOOMED", "release_type": "ga", @@ -85,6 +88,7 @@ class Consumer(object): # Used for printing out a value when the day has changed self.date = datetime.date.today() + self.config = fedora_messaging.config.conf["consumer_config"] def get_supporting_text(self, lines): """ given a log file line determine if it has a koji task ID in it @@ -177,9 +181,10 @@ class Consumer(object): # It was requested that we not file issues for IoT composes # https://pagure.io/releng/failed-composes/issue/39#comment-591054 - if 'IoT' in msg['compose_id']: - logger.info("Skipping filing issues for IoT composes") - return + for compose in self.config["composes_to_skip"]: + if compose in msg["compose_id"]: + logger.info(f"Skipping filing issues for {compose} composes") + return # variable to hold description for issue content = "[pungi.global.log](%s)\n\n" % logfileurl diff --git a/requirements.txt b/requirements.txt index be59f7b..f42c790 100644 --- a/requirements.txt +++ b/requirements.txt @@ -1,4 +1,7 @@ -requests==2.21.0 -fedora_messaging>=1.7.1 -libpagure>=0.22 -PyYAML==5.1.2 +requests +fedora_messaging +ogr +PyYAML +# Development +pytest +pytest-mock diff --git a/test_consumer.py b/test_consumer.py new file mode 100644 index 0000000..445f0d7 --- /dev/null +++ b/test_consumer.py @@ -0,0 +1,98 @@ +import copy +import json + +import pytest +import fedora_messaging.api +import fedora_messaging.config + +from compose_tracker import Consumer + + +EXAMPLE_MESSAGE_BODY = json.loads( + """ +{ + "status": "DOOMED", + "release_type": "ga", + "compose_label": null, + "compose_respin": 0, + "compose_date": "20190619", + "release_version": "Rawhide", + "location": "https://kojipkgs.fedoraproject.org/compose/rawhide/Fedora-Rawhide-20190619.n.0/compose", + "compose_type": "nightly", + "release_is_layered": false, + "release_name": "Fedora", + "release_short": "Fedora", + "compose_id": "Fedora-Rawhide-20190619.n.0" +} +""" +) + + +def test_consumer_message_process(mocker, caplog): + "Test that we can successfully process a message" + mocker.patch("compose_tracker.PagureService") + mocker.patch("compose_tracker.requests") + mocker.patch( + "compose_tracker.fedora_messaging.config.conf", + fedora_messaging.config.conf.load_config("compose-tracker.toml"), + ) + con = Consumer() + msg = fedora_messaging.api.Message( + topic="org.fedoraproject.prod.pungi.compose.status.change", + body=EXAMPLE_MESSAGE_BODY, + ) + con.process(msg) + assert "Fedora-Rawhide-20190619.n.0 DOOMED" in caplog.text + + +def test_consumer_settings_ignore_compose(mocker, caplog): + "Test that we ignore the composes specified in the settings" + mocker.patch("compose_tracker.PagureService") + mocker.patch("compose_tracker.requests") + mocker.patch( + "compose_tracker.fedora_messaging.config.conf", + fedora_messaging.config.conf.load_config("compose-tracker.toml"), + ) + con = Consumer() + body = copy.copy(EXAMPLE_MESSAGE_BODY) + body["compose_id"] = "Fedora-IoT-20190619.n.0" + msg = fedora_messaging.api.Message( + topic="org.fedoraproject.prod.pungi.compose.status.change", body=body, + ) + con.process(msg) + assert "Skipping filing issues for IoT composes" in caplog.text + + +def test_consumer_settings_ignore_compose_2_values(mocker, caplog): + "Test that we ignore the composes specified in the settings with 2 values" + mocker.patch("compose_tracker.PagureService") + mocker.patch("compose_tracker.requests") + mocker.patch( + "compose_tracker.fedora_messaging.config.conf", + {"consumer_config": {"composes_to_skip": ["IoT", "Rawhide"]}}, + ) + con = Consumer() + msg = fedora_messaging.api.Message( + topic="org.fedoraproject.prod.pungi.compose.status.change", + body=EXAMPLE_MESSAGE_BODY, + ) + con.process(msg) + assert "Skipping filing issues for Rawhide composes" in caplog.text + + +def test_consumer_ignore_good_composes(mocker, caplog): + "Test that we ignore the composes that finished correctly" + mocker.patch("compose_tracker.PagureService") + mocker.patch("compose_tracker.requests") + mocker.patch( + "compose_tracker.fedora_messaging.config.conf", + fedora_messaging.config.conf.load_config("compose-tracker.toml"), + ) + con = Consumer() + body = copy.copy(EXAMPLE_MESSAGE_BODY) + body["status"] = "FINISHED" + msg = fedora_messaging.api.Message( + topic="org.fedoraproject.prod.pungi.compose.status.change", body=body, + ) + con.process(msg) + assert "Fedora-Rawhide-20190619.n.0" not in caplog.text From a70e7fb1f4d61f4e2ed17d27b47af88176cd623b Mon Sep 17 00:00:00 2001 From: Clement Verna Date: Feb 10 2020 08:03:03 +0000 Subject: [PATCH 2/2] Add the time it takes to make a compose to the tickets. This commits add the total time of a compose and the time for each phases of a compose in the ticket created. Fixes #18. Signed-off-by: Clement Verna --- diff --git a/compose_tracker.py b/compose_tracker.py index a354526..dce655b 100755 --- a/compose_tracker.py +++ b/compose_tracker.py @@ -15,7 +15,8 @@ # You should have received a copy of the GNU Lesser General Public # License along with this library. If not, see . -import datetime +import datetime as dt +import fedora_messaging.api import json import logging import os @@ -66,16 +67,16 @@ class Consumer(object): def __init__(self): self.token = os.getenv('PAGURE_TOKEN') pagure_domain = os.getenv('PAGURE_DOMAIN', DEFAULT_PAGURE_DOMAIN) - pagure_namespace = os.getenv('PAGURE_NAMESPACE', DEFAULT_PAGURE_NAMESPACE) - pagure_repo = os.getenv('PAGURE_REPO', DEFAULT_PAGURE_REPO) + pagure_namespace = os.getenv('PAGURE_NAMESPACE', DEFAULT_PAGURE_NAMESPACE) + pagure_repo = os.getenv('PAGURE_REPO', DEFAULT_PAGURE_REPO) if self.token: - logger.info("Using detected token to talk to pagure.") + logger.info("Using detected token to talk to pagure.") gitservice = PagureService( token=self.token, instance_url=pagure_domain) else: - logger.info("No pagure token was detected.") + logger.info("No pagure token was detected.") logger.info("This script will run but won't be able to create new issues.") gitservice = PagureService(instance_url=pagure_domain) @@ -87,7 +88,7 @@ class Consumer(object): namespace=pagure_namespace) # Used for printing out a value when the day has changed - self.date = datetime.date.today() + self.date = dt.date.today() self.config = fedora_messaging.config.conf["consumer_config"] def get_supporting_text(self, lines): @@ -156,7 +157,7 @@ class Consumer(object): status = msg['status'] # Print out a log statement if the day has changed - today = datetime.date.today() + today = dt.date.today() if today != self.date: self.date = today print('') # get to the next line @@ -199,9 +200,22 @@ class Consumer(object): lines = [] pass + phases = {} for x in range(1, len(lines)): - line = lines[x-1][20:] # trim date off log lines - nextline = lines[x][20:] # trim date off log lines + linedate = lines[x-1][:19] # keep only the date for each line + line = lines[x-1][20:] # trim date off log lines + nextline = lines[x][20:] # trim date off log lines + + r = re.search('.*\[BEGIN\] ---------- PHASE: (\w+) .*', line) + if r: + name = r.group(1) + phases[name] = [dt.datetime.fromisoformat(linedate)] + + r = re.search('.*\[DONE \] ---------- PHASE: (\w+) .*', line) + if r: + name = r.group(1) + phase = phases.get(name) + phase.append(dt.datetime.fromisoformat(linedate)) # If this is a [FAIL] line then we take it and the # next line and add them in markdown format. Also grab @@ -219,6 +233,16 @@ class Consumer(object): content+= f'- Compose run failed because: {text}\n' content+= "```\n%s\n```\n" % (line) + compose_start = dt.datetime.fromisoformat(lines[0][:19]) + compose_end = dt.datetime.fromisoformat(lines[-1][:19]) + content+= f"Compose Total time: {compose_end - compose_start}\n" + for p in phases: + if len(phases[p]) == 2: + phase_start = phases[p][0] + phase_end = phases[p][1] + content+= f"Compose phase {p} time: {phase_end - phase_start}.\n" + else: + content+= f"Compose phase {p}: FAILED.\n" logger.debug(content) # pull only part of the compose ID for the label to set diff --git a/test_consumer.py b/test_consumer.py index 445f0d7..4243c80 100644 --- a/test_consumer.py +++ b/test_consumer.py @@ -1,5 +1,6 @@ import copy import json +import logging import pytest import fedora_messaging.api @@ -27,19 +28,38 @@ EXAMPLE_MESSAGE_BODY = json.loads( """ ) +EXAMPLE_PUNGI_LOG_DOOMED = """2020-02-04 06:15:09 [INFO ] [BEGIN] ---------- PHASE: INIT ---------- +2020-02-04 06:15:19 [INFO ] [DONE ] ---------- PHASE: INIT ---------- +2020-02-04 06:15:20 [INFO ] [BEGIN] ---------- PHASE: WEAVER ---------- +2020-02-04 06:15:21 [INFO ] [DONE ] ---------- PHASE: WEAVER ---------- +2020-02-04 06:15:21 [INFO ] [BEGIN] ---------- PHASE: CREATEISO ---------- +2020-02-04 06:35:39 [ERROR ] Compose run failed: ImageBuild task failed: 41350838. See /mnt/koji/compose/cloud/Fedora-Cloud-30-20200204.0/logs/aarch64-ppc64le-s390x-x86_64/imagebuild-Cloud-Cloud_Base-qcow2-raw-xz.aarch64-ppc64le-s390x-x86_64.log for more details. +2020-02-04 06:35:39 [ERROR ] Extended traceback in: /mnt/koji/compose/cloud/Fedora-Cloud-30-20200204.0/logs/global/traceback.global.log +""" + +EXAMPLE_PUNGI_LOG_INCOMPLETE = """2020-02-04 05:59:24 [INFO ] [BEGIN] ---------- PHASE: OSTREE ---------- +2020-02-04 06:03:08 [ERROR ] [FAIL] Ostree (variant Silverblue, arch x86_64) failed, but going on anyway. +2020-02-04 06:03:08 [ERROR ] Runroot task failed: 41350821. See /mnt/koji/compose/rawhide/Fedora-Rawhide-20200204.n.0/logs/x86_64/Silverblue/ostree-1/runroot.log for more details. +2020-02-04 06:03:40 [ERROR ] [FAIL] Ostree (variant Silverblue, arch ppc64le) failed, but going on anyway. +2020-02-04 06:03:40 [ERROR ] Runroot task failed: 41350822. See /mnt/koji/compose/rawhide/Fedora-Rawhide-20200204.n.0/logs/ppc64le/Silverblue/ostree-2/runroot.log for more details. +2020-02-04 06:04:44 [INFO ] [DONE ] ---------- PHASE: OSTREE ---------- +""" + def test_consumer_message_process(mocker, caplog): "Test that we can successfully process a message" mocker.patch("compose_tracker.PagureService") - mocker.patch("compose_tracker.requests") + req = mocker.patch("compose_tracker.requests.get", autospec=True) + text_mock = mocker.MagicMock() + text_mock.text.splitlines.return_value = EXAMPLE_PUNGI_LOG_DOOMED.splitlines() + req.return_value = text_mock mocker.patch( "compose_tracker.fedora_messaging.config.conf", fedora_messaging.config.conf.load_config("compose-tracker.toml"), ) con = Consumer() msg = fedora_messaging.api.Message( - topic="org.fedoraproject.prod.pungi.compose.status.change", - body=EXAMPLE_MESSAGE_BODY, + topic="org.fedoraproject.prod.pungi.compose.status.change", body=EXAMPLE_MESSAGE_BODY, ) con.process(msg) assert "Fedora-Rawhide-20190619.n.0 DOOMED" in caplog.text @@ -51,7 +71,7 @@ def test_consumer_settings_ignore_compose(mocker, caplog): mocker.patch("compose_tracker.requests") mocker.patch( "compose_tracker.fedora_messaging.config.conf", - fedora_messaging.config.conf.load_config("compose-tracker.toml"), + {"consumer_config": {"composes_to_skip": ["IoT"]}}, ) con = Consumer() body = copy.copy(EXAMPLE_MESSAGE_BODY) @@ -73,8 +93,7 @@ def test_consumer_settings_ignore_compose_2_values(mocker, caplog): ) con = Consumer() msg = fedora_messaging.api.Message( - topic="org.fedoraproject.prod.pungi.compose.status.change", - body=EXAMPLE_MESSAGE_BODY, + topic="org.fedoraproject.prod.pungi.compose.status.change", body=EXAMPLE_MESSAGE_BODY, ) con.process(msg) assert "Skipping filing issues for Rawhide composes" in caplog.text @@ -96,3 +115,53 @@ def test_consumer_ignore_good_composes(mocker, caplog): ) con.process(msg) assert "Fedora-Rawhide-20190619.n.0" not in caplog.text + + +def test_consumer_logfile_time_parsing(mocker, caplog): + "Test that the consumer correctly parses the time a compose takes" + + mocker.patch("compose_tracker.PagureService") + + # set logs at DEBUG and capture this level + caplog.set_level(logging.DEBUG) + mocker.patch("compose_tracker.logger.level", logging.DEBUG) + + # mock the pungi.global.log file + req = mocker.patch("compose_tracker.requests.get", autospec=True) + text_mock = mocker.MagicMock() + text_mock.text.splitlines.return_value = EXAMPLE_PUNGI_LOG_DOOMED.splitlines() + req.return_value = text_mock + + con = Consumer() + msg = fedora_messaging.api.Message( + topic="org.fedoraproject.prod.pungi.compose.status.change", body=EXAMPLE_MESSAGE_BODY, + ) + con.process(msg) + assert "- Compose run failed because: - [41350838]" in caplog.text + assert "Compose Total time: 0:20:30" in caplog.text + assert "Compose phase INIT time: 0:00:10." in caplog.text + assert "Compose phase CREATEISO: FAILED." in caplog.text + + +def test_consumer_logfile_parsing_failures(mocker, caplog): + "Test that the consumer correctly parses the failures of a compose" + + mocker.patch("compose_tracker.PagureService") + + # set logs at DEBUG and capture this level + caplog.set_level(logging.DEBUG) + mocker.patch("compose_tracker.logger.level", logging.DEBUG) + + # mock the pungi.global.log file + req = mocker.patch("compose_tracker.requests.get", autospec=True) + text_mock = mocker.MagicMock() + text_mock.text.splitlines.return_value = EXAMPLE_PUNGI_LOG_INCOMPLETE.splitlines() + req.return_value = text_mock + + con = Consumer() + msg = fedora_messaging.api.Message( + topic="org.fedoraproject.prod.pungi.compose.status.change", body=EXAMPLE_MESSAGE_BODY, + ) + con.process(msg) + assert "Ostree (variant Silverblue, arch x86_64) failed, but going on anyway." in caplog.text + assert "Ostree (variant Silverblue, arch ppc64le) failed, but going on anyway." in caplog.text