Quickly list the slowest targets that may have caused a timeout

find-slow-targets.py

#!/usr/bin/env python3


import argparse
from datetime import datetime
import requests
import re


class TimedOut(Exception):
    pass


def list_builds(buildset_id):
    r = requests.get(
        f"https://ansible.softwarefactory-project.io/zuul/api/buildset/{buildset_id}"
    )

    def _acceptable(build):
        # return build["final"] and build["result"] != "ABORTED" and "integration" in build["job_name"]
        return build["result"] == "TIMED_OUT"

    return [build for build in r.json()["builds"] if _acceptable(build)]


def list_scheduled_targets(log_output):
    for l in r.text.split("\n"):
        if m := re.match(
            ".*About to run: ansible-test integration.*-v+(\s(?P<targets>.*))", l
        ):
            return m.group("targets").split(" ")


def find_target_startup_time(log_output, target):
    for l in log_output.split("\n"):
        if m := re.match(
            "(?P<timestamp>\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}.\d+).*Running "
            + target
            + " integration test role",
            l,
        ):
            return datetime.fromisoformat(m.group("timestamp"))


def find_target_end_time(log_output, target):
    inside = False
    for l in log_output.split("\n"):
        if m := re.match(".*Running " + target + " integration test role", l):
            inside = True
            continue

        if not inside:
            continue
        elif m := re.match(
            "(?P<timestamp>\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}.\d+).*Running \S+ integration test role",
            l,
        ):
            return datetime.fromisoformat(m.group("timestamp"))
        elif m := re.match(
            "(?P<timestamp>\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}.\d+).*RESULT_TIMED_OUT.*",
            l,
        ):
            return datetime.fromisoformat(m.group("timestamp"))
        elif m := re.match(
            "(?P<timestamp>\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}.\d+).*unregister the node",
            l,
        ):
            return datetime.fromisoformat(m.group("timestamp"))


parser = argparse.ArgumentParser(
    description="Find the slowest targets in an ansible-test output."
)
parser.add_argument("buildset_id", type=str, help="Buildset ID to investigate")
args = parser.parse_args()

for build in list_builds(args.buildset_id):
    print(f"** {build['job_name']} - {build['result']}")
    r = requests.get(f"{build['log_url']}/job-output.txt")
    log_output = r.text
    scheduled_targets = list_scheduled_targets(log_output)
    startup_times = []

    targets = []
    for target in scheduled_targets:
        startup_time = find_target_startup_time(log_output, target)
        end_time = find_target_end_time(log_output, target)
        if not startup_time:
            continue
        targets.append(
            (
                target,
                end_time - startup_time,
            )
        )

    for target, duration in sorted(targets, key=lambda x: x[1], reverse=True):
        print(f"{target}: {duration}")