|
| 1 | +#!/usr/bin/env python3 |
| 2 | +# Licensed to the Apache Software Foundation (ASF) under one |
| 3 | +# or more contributor license agreements. See the NOTICE file |
| 4 | +# distributed with this work for additional information |
| 5 | +# regarding copyright ownership. The ASF licenses this file |
| 6 | +# to you under the Apache License, Version 2.0 (the |
| 7 | +# "License"); you may not use this file except in compliance |
| 8 | +# with the License. You may obtain a copy of the License at |
| 9 | +# |
| 10 | +# http://www.apache.org/licenses/LICENSE-2.0 |
| 11 | +# |
| 12 | +# Unless required by applicable law or agreed to in writing, software |
| 13 | +# distributed under the License is distributed on an "AS IS" BASIS, |
| 14 | +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 15 | +# See the License for the specific language governing permissions and |
| 16 | +# limitations under the License. |
| 17 | + |
| 18 | +"""How evenly each test target's splits divided, and which of them came near their deadline. |
| 19 | +
|
| 20 | +What makes a split long: `_split_tests` in ../run-tests.sh deals an alphabetically sorted class list |
| 21 | +round-robin with `split -n r/K/N`, which balances the count of classes and knows nothing of their duration. |
| 22 | +
|
| 23 | +Round-robin is required, so that which split holds a test is predictable and easy to find. |
| 24 | +
|
| 25 | +This report cannot tell a structurally long split from one that drew a |
| 26 | +slow agent, so change a split count only when consecutive builds agree. |
| 27 | +
|
| 28 | +Usage: |
| 29 | +
|
| 30 | + cell_balance.py [--input build/test] [--output build/ci_summary.html] [--budget-margin 15] |
| 31 | +
|
| 32 | +`--input` holds `cell-times/*.tsv`, one per cell from `recordCellTime` in the Jenkinsfile, and |
| 33 | +`output/<target>/` of decompressed JUnit XML. A cell records whether it ended ok, hit its deadline, or failed, |
| 34 | +so a target that never finishes still gets a row. With no records at all it says so and exits 0: this is not |
| 35 | +the check to fail a build on. |
| 36 | +""" |
| 37 | + |
| 38 | +import argparse |
| 39 | +import os |
| 40 | +import statistics |
| 41 | +import sys |
| 42 | +import xml.etree.ElementTree as ElementTree |
| 43 | + |
| 44 | +# Columns of a cell-times record, in order. test_seconds covers every class and not only the twelve .suites |
| 45 | +# lists, so the setup figure is exact rather than a residue. outcome is ok, timeout, or failed. Records from |
| 46 | +# before either column still read: a shorter record leaves the trailing keys unset. |
| 47 | +FIELDS = ("step", "arch", "jdk", "split", "splits", "timeout_hours", "duration_ms", "test_seconds", "outcome") |
| 48 | + |
| 49 | +# Enough of the worst cell's longest suites to show whether one class dominates or the whole split is heavy, |
| 50 | +# which is the distinction that decides what to do. More when over budget, that being the one to act on. |
| 51 | +LONGEST_SUITES = 6 |
| 52 | +LONGEST_SUITES_OVER_BUDGET = 12 |
| 53 | + |
| 54 | +# The floor keeps it quiet for cells with no setup worth reporting |
| 55 | +UNDER_RECORDED_TEST_SHARE = 0.25 |
| 56 | +UNDER_RECORDED_MINIMUM_MINUTES = 5.0 |
| 57 | + |
| 58 | +# Name the test classes only when the worst cell's longest reaches this |
| 59 | +NAME_CLASSES_ABOVE_MINUTES = 5.0 |
| 60 | + |
| 61 | + |
| 62 | +def read_records(cell_times_dir): |
| 63 | + """Every cell record, as a list of dicts. A malformed file is skipped rather than fatal.""" |
| 64 | + records = [] |
| 65 | + if not os.path.isdir(cell_times_dir): |
| 66 | + return records |
| 67 | + # The .suites files sit in this directory too, so only .tsv is a record. |
| 68 | + for name in sorted(n for n in os.listdir(cell_times_dir) if n.endswith(".tsv")): |
| 69 | + path = os.path.join(cell_times_dir, name) |
| 70 | + try: |
| 71 | + with open(path, encoding="utf-8") as handle: |
| 72 | + fields = handle.readline().rstrip("\n").split("\t") |
| 73 | + if not (len(FIELDS) - 2 <= len(fields) <= len(FIELDS)): |
| 74 | + continue |
| 75 | + record = dict(zip(FIELDS, fields)) |
| 76 | + record["minutes"] = int(record["duration_ms"]) / 60000.0 |
| 77 | + record["timed_out"] = record.get("outcome") == "timeout" |
| 78 | + record["failed"] = record.get("outcome") == "failed" |
| 79 | + |
| 80 | + record["test_minutes"] = (float(record["test_seconds"]) / 60.0 |
| 81 | + if record.get("test_seconds") else None) |
| 82 | + record["deadline_minutes"] = float(record["timeout_hours"]) * 60.0 |
| 83 | + record["label"] = f"{record['step']} jdk{record['jdk']} {record['split']}/{record['splits']}" |
| 84 | + record["suites"] = read_suites(path[: -len(".tsv")] + ".suites") |
| 85 | + records.append(record) |
| 86 | + except (OSError, ValueError): |
| 87 | + continue |
| 88 | + return records |
| 89 | + |
| 90 | + |
| 91 | +def read_suites(path): |
| 92 | + """(suite name, minutes) for one cell, longest first, or [] when the file is absent.""" |
| 93 | + try: |
| 94 | + with open(path, encoding="utf-8") as handle: |
| 95 | + fields = [line.rstrip("\n").partition("\t") for line in handle] |
| 96 | + return [(name, float(seconds) / 60.0) for seconds, _, name in fields if name] |
| 97 | + except (OSError, ValueError): |
| 98 | + return [] |
| 99 | + |
| 100 | + |
| 101 | +def summarise(records, budget_margin): |
| 102 | + """One row per target, worst first.""" |
| 103 | + by_step = {} |
| 104 | + for record in records: |
| 105 | + by_step.setdefault(record["step"], []).append(record) |
| 106 | + |
| 107 | + rows = [] |
| 108 | + for step, cells in by_step.items(): |
| 109 | + durations = sorted(cell["minutes"] for cell in cells) |
| 110 | + worst = max(cells, key=lambda cell: cell["minutes"]) |
| 111 | + median = statistics.median(durations) |
| 112 | + budget = max(cell["deadline_minutes"] for cell in cells) - budget_margin |
| 113 | + rows.append({ |
| 114 | + "step": step, |
| 115 | + "cells": len(cells), |
| 116 | + "min": durations[0], |
| 117 | + "median": median, |
| 118 | + "max": durations[-1], |
| 119 | + # Guarded, because a target whose median is zero is a target that ran nothing. |
| 120 | + "ratio": durations[-1] / median if median > 0 else 0.0, |
| 121 | + "budget": budget, |
| 122 | + "over_budget": durations[-1] > budget, |
| 123 | + # Counted because neither duration is a plain measurement: a killed cell's is its deadline, and a |
| 124 | + # failed cell's stops wherever the failure came. |
| 125 | + "timed_out_cells": sum(1 for cell in cells if cell["timed_out"]), |
| 126 | + "failed_cells": sum(1 for cell in cells if cell["failed"]), |
| 127 | + "worst_timed_out": worst["timed_out"], |
| 128 | + "worst_label": worst["label"], |
| 129 | + "worst_suites": worst["suites"], |
| 130 | + # The cell's own total where it recorded one, and the sum of what it listed otherwise. |
| 131 | + "worst_test_minutes": (worst["test_minutes"] if worst["test_minutes"] is not None |
| 132 | + else sum(minutes for _, minutes in worst["suites"])), |
| 133 | + "worst_test_minutes_exact": worst["test_minutes"] is not None, |
| 134 | + }) |
| 135 | + rows.sort(key=lambda row: -row["max"]) |
| 136 | + return rows |
| 137 | + |
| 138 | + |
| 139 | +def suite_times(target_output_dir): |
| 140 | + """(suite name, minutes) for every JUnit suite under one target, longest first.""" |
| 141 | + suites = [] |
| 142 | + for root, _, names in os.walk(target_output_dir): |
| 143 | + for name in names: |
| 144 | + if not name.endswith(".xml"): |
| 145 | + continue |
| 146 | + try: |
| 147 | + element = ElementTree.parse(os.path.join(root, name)).getroot() |
| 148 | + except (OSError, ElementTree.ParseError): |
| 149 | + continue |
| 150 | + # A file's root is <testsuite> from ant and <testsuites> from pytest, so both are searched. |
| 151 | + for suite in [element] if element.tag == "testsuite" else element.findall(".//testsuite"): |
| 152 | + try: |
| 153 | + suites.append((suite.get("name") or "?", float(suite.get("time") or 0) / 60.0)) |
| 154 | + except ValueError: |
| 155 | + continue |
| 156 | + suites.sort(key=lambda pair: -pair[1]) |
| 157 | + return suites |
| 158 | + |
| 159 | + |
| 160 | +def print_report(rows, output_root, budget_margin): |
| 161 | + if not rows: |
| 162 | + print("No cell-times records were found, so there is no split balance to report.") |
| 163 | + return |
| 164 | + |
| 165 | + print() |
| 166 | + print("Split balance, by test target. `worst` is one cell's whole duration, setup included, against a") |
| 167 | + print(f"`budget` of its deadline less {budget_margin} min. Splitting balances the count of classes and" |
| 168 | + " not their") |
| 169 | + print("duration, so a high w/med is a split that drew slow ones. Confirm against the previous build.") |
| 170 | + print() |
| 171 | + header = (f"{'target':34s} {'cells':>5s} {'min':>7s} {'median':>7s} {'worst':>7s}" |
| 172 | + f" {'w/med':>6s} {'budget':>7s} {'':4s} worst cell") |
| 173 | + print(header) |
| 174 | + print("-" * len(header)) |
| 175 | + for row in rows: |
| 176 | + flag = "KILL" if row["worst_timed_out"] else "OVER" if row["over_budget"] else "" |
| 177 | + print(f"{row['step']:34s} {row['cells']:5d} {row['min']:7.1f} {row['median']:7.1f}" |
| 178 | + f" {row['max']:7.1f} {row['ratio']:6.2f} {row['budget']:7.0f} {flag:4s}" |
| 179 | + f" {row['worst_label']}{cell_outcome_note(row)}") |
| 180 | + |
| 181 | + if not any(row["over_budget"] for row in rows): |
| 182 | + print() |
| 183 | + print("Every target's worst cell is inside its budget.") |
| 184 | + |
| 185 | + killed = sum(row["timed_out_cells"] for row in rows) |
| 186 | + failed = sum(row["failed_cells"] for row in rows) |
| 187 | + if killed or failed: |
| 188 | + print() |
| 189 | + print(f"Cells killed at their deadline (KILL): {killed}. Cells ended by a failure: {failed}. A killed" |
| 190 | + " cell's duration is that deadline, so read it as a lower bound; a failed cell's stops where the" |
| 191 | + " failure came, so it can pull min and median down.") |
| 192 | + |
| 193 | + print() |
| 194 | + print("What each worst cell ran. One class near the cell's whole duration cannot be split further;") |
| 195 | + print("several of comparable size can be. Classes are named only where the longest reaches" |
| 196 | + f" {NAME_CLASSES_ABOVE_MINUTES:.0f} min,") |
| 197 | + print("below which none of them is the reason.") |
| 198 | + for row in rows: |
| 199 | + print() |
| 200 | + print_worst_cell(row, output_root) |
| 201 | + |
| 202 | + |
| 203 | +def cell_outcome_note(row): |
| 204 | + """What to add after a worst cell's label, when it did not simply finish.""" |
| 205 | + if row["worst_timed_out"]: |
| 206 | + return " (killed at its deadline)" |
| 207 | + other = row["timed_out_cells"] + row["failed_cells"] |
| 208 | + return f" (+{other} killed or failed)" if other else "" |
| 209 | + |
| 210 | + |
| 211 | +def print_share(minutes, total, text): |
| 212 | + """One breakdown line: minutes, what share of the cell they are, and what spent them.""" |
| 213 | + print(f" {minutes:7.1f} min {100 * minutes / total if total else 0:4.0f}% {text}") |
| 214 | + |
| 215 | + |
| 216 | +def print_worst_cell(row, output_root): |
| 217 | + """The longest classes of one target's worst cell, and the time that was not test time.""" |
| 218 | + flag = " OVER BUDGET" if row["over_budget"] else "" |
| 219 | + print(f"{row['worst_label']}: {row['max']:.1f} min against a budget of {row['budget']:.0f}{flag}") |
| 220 | + if row["worst_timed_out"]: |
| 221 | + print(" killed at its deadline, so this duration is a lower bound and the classes below are only" |
| 222 | + " the ones that finished") |
| 223 | + |
| 224 | + suites, total, tests = row["worst_suites"], row["max"], row["worst_test_minutes"] |
| 225 | + if not suites: |
| 226 | + fallback = suite_times(os.path.join(output_root, row["step"]))[:LONGEST_SUITES] |
| 227 | + if not fallback: |
| 228 | + print(" no per-cell suite record, and no JUnit XML for this target either") |
| 229 | + return |
| 230 | + print(" no per-cell suite record, so these are the longest across the whole target:") |
| 231 | + for name, minutes in fallback: |
| 232 | + print(f" {minutes:7.1f} min {name}") |
| 233 | + return |
| 234 | + |
| 235 | + longest = max(minutes for _, minutes in suites) |
| 236 | + if longest < NAME_CLASSES_ABOVE_MINUTES: |
| 237 | + # No class is large enough to be the reason, so the whole test time is one line |
| 238 | + print_share(tests, total, f"every test class in this cell, the longest of them {longest:.1f} min") |
| 239 | + else: |
| 240 | + shown = suites[:LONGEST_SUITES_OVER_BUDGET if row["over_budget"] else LONGEST_SUITES] |
| 241 | + for name, minutes in shown: |
| 242 | + print_share(minutes, total, name) |
| 243 | + other = tests - sum(minutes for _, minutes in shown) |
| 244 | + if other > 0.05: |
| 245 | + print_share(other, total, "every other test class in this cell") |
| 246 | + |
| 247 | + setup = total - tests |
| 248 | + if setup <= 0: |
| 249 | + return |
| 250 | + share = tests / total if total else 1.0 |
| 251 | + if total >= UNDER_RECORDED_MINIMUM_MINUTES and share < UNDER_RECORDED_TEST_SHARE: |
| 252 | + print_share(setup, total, f"setup at most: only {tests:.1f} min of tests was recorded," |
| 253 | + f" {100 * share:.0f}% of the cell,") |
| 254 | + print(" so tests are missing from the JUnit XML and this is an upper bound") |
| 255 | + else: |
| 256 | + exact = "" if row["worst_test_minutes_exact"] else ", or a test class this cell did not record" |
| 257 | + print_share(setup, total, "not running tests: the node, the image pulls, the compile and the" |
| 258 | + f" virtualenv{exact}") |
| 259 | + |
| 260 | + |
| 261 | +def html_report(rows, budget_margin): |
| 262 | + parts = ["<h2>Split balance</h2>"] |
| 263 | + if not rows: |
| 264 | + parts.append("<p>No cell-times records were found.</p>") |
| 265 | + return "".join(parts) |
| 266 | + parts.append( |
| 267 | + "<p><code>worst</code> is one cell's whole duration, setup included, which is what the cell deadline" |
| 268 | + f" governs; <code>budget</code> is that deadline less {budget_margin} minutes of margin." |
| 269 | + " Round-robin splitting balances the number of classes in a split and not their duration, so a high" |
| 270 | + " <code>worst/median</code> is a split that drew slow classes. Confirm against the previous build" |
| 271 | + " before changing a split count.</p>") |
| 272 | + killed = sum(row["timed_out_cells"] for row in rows) |
| 273 | + failed = sum(row["failed_cells"] for row in rows) |
| 274 | + if killed or failed: |
| 275 | + parts.append( |
| 276 | + f"<p>Cells killed at their deadline: {killed}. Cells ended by a failure: {failed}. A killed cell's" |
| 277 | + " duration is that deadline, so read it as a lower bound; a failed cell's stops where the failure" |
| 278 | + " came, so it can pull <code>min</code> and <code>median</code> down.</p>") |
| 279 | + parts.append("<table border='1' cellpadding='4'><tr><th>target</th><th>cells</th><th>min</th>" |
| 280 | + "<th>median</th><th>worst</th><th>worst/median</th><th>budget</th><th>worst cell</th></tr>") |
| 281 | + for row in rows: |
| 282 | + style = " bgcolor='#ffdddd'" if row["over_budget"] else "" |
| 283 | + parts.append( |
| 284 | + f"<tr{style}><td>{row['step']}</td><td>{row['cells']}</td><td>{row['min']:.1f}</td>" |
| 285 | + f"<td>{row['median']:.1f}</td><td>{row['max']:.1f}</td><td>{row['ratio']:.2f}</td>" |
| 286 | + f"<td>{row['budget']:.0f}</td><td>{row['worst_label']}{cell_outcome_note(row)}</td></tr>") |
| 287 | + parts.append("</table>") |
| 288 | + return "".join(parts) |
| 289 | + |
| 290 | + |
| 291 | +def write_into_body(path, html): |
| 292 | + """Put the table inside the document's body, ci_parser.py having already closed it. |
| 293 | +
|
| 294 | + Insert before the last `</body>` instead, and append only when the file has no body to insert into. |
| 295 | + """ |
| 296 | + with open(path, encoding="utf-8") as handle: |
| 297 | + document = handle.read() |
| 298 | + head, tag, tail = document.rpartition("</body>") |
| 299 | + updated = head + html + tag + tail if tag else document + html |
| 300 | + with open(path, "w", encoding="utf-8") as handle: |
| 301 | + handle.write(updated) |
| 302 | + |
| 303 | + |
| 304 | +def main(): |
| 305 | + parser = argparse.ArgumentParser(description="Report how evenly each test target's splits divided.") |
| 306 | + parser.add_argument("--input", default="build/test", |
| 307 | + help="directory holding cell-times/ and output/, default build/test") |
| 308 | + parser.add_argument("--output", default=None, |
| 309 | + help="existing .html file to insert the table into; omitted prints only") |
| 310 | + parser.add_argument("--budget-margin", type=int, default=15, |
| 311 | + help="minutes of margin to keep under a cell's deadline, default 15") |
| 312 | + args = parser.parse_args() |
| 313 | + |
| 314 | + records = read_records(os.path.join(args.input, "cell-times")) |
| 315 | + rows = summarise(records, args.budget_margin) |
| 316 | + print_report(rows, os.path.join(args.input, "output"), args.budget_margin) |
| 317 | + |
| 318 | + if args.output and os.path.isfile(args.output): |
| 319 | + try: |
| 320 | + write_into_body(args.output, html_report(rows, args.budget_margin)) |
| 321 | + except OSError as error: |
| 322 | + print(f"could not write the table into {args.output}: {error}", file=sys.stderr) |
| 323 | + |
| 324 | + return 0 |
| 325 | + |
| 326 | + |
| 327 | +if __name__ == "__main__": |
| 328 | + sys.exit(main()) |
0 commit comments