| 1 | # Class for actually running tests. |
| 2 | # |
| 3 | # Copyright (c) 2020-2021 Virtuozzo International GmbH |
| 4 | # |
| 5 | # This program is free software; you can redistribute it and/or modify |
| 6 | # it under the terms of the GNU General Public License as published by |
| 7 | # the Free Software Foundation; either version 2 of the License, or |
| 8 | # (at your option) any later version. |
| 9 | # |
| 10 | # This program is distributed in the hope that it will be useful, |
| 11 | # but WITHOUT ANY WARRANTY; without even the implied warranty of |
| 12 | # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
| 13 | # GNU General Public License for more details. |
| 14 | # |
| 15 | # You should have received a copy of the GNU General Public License |
| 16 | # along with this program. If not, see <http://www.gnu.org/licenses/>. |
| 17 | # |
| 18 | |
| 19 | import os |
| 20 | from pathlib import Path |
| 21 | import datetime |
| 22 | import time |
| 23 | import difflib |
| 24 | import subprocess |
| 25 | import contextlib |
| 26 | import json |
| 27 | import shutil |
| 28 | import sys |
| 29 | from multiprocessing import get_context |
| 30 | from typing import List, Optional, Any, Sequence, Dict |
| 31 | from testenv import TestEnv |
| 32 | |
| 33 | |
| 34 | def silent_unlink(path: Path) -> None: |
| 35 | try: |
| 36 | path.unlink() |
| 37 | except OSError: |
| 38 | pass |
| 39 | |
| 40 | |
| 41 | def file_diff(file1: str, file2: str) -> List[str]: |
| 42 | with open(file1, encoding="utf-8") as f1, \ |
| 43 | open(file2, encoding="utf-8") as f2: |
| 44 | # We want to ignore spaces at line ends. There are a lot of mess about |
| 45 | # it in iotests. |
| 46 | # TODO: fix all tests to not produce extra spaces, fix all .out files |
| 47 | # and use strict diff here! |
| 48 | seq1 = [line.rstrip() for line in f1] |
| 49 | seq2 = [line.rstrip() for line in f2] |
| 50 | res = [line.rstrip() |
| 51 | for line in difflib.unified_diff(seq1, seq2, file1, file2)] |
| 52 | return res |
| 53 | |
| 54 | |
| 55 | class LastElapsedTime(contextlib.AbstractContextManager['LastElapsedTime']): |
| 56 | """ Cache for elapsed time for tests, to show it during new test run |
| 57 | |
| 58 | It is safe to use get() at any time. To use update(), you must either |
| 59 | use it inside with-block or use save() after update(). |
| 60 | """ |
| 61 | def __init__(self, cache_file: str, env: TestEnv) -> None: |
| 62 | self.env = env |
| 63 | self.cache_file = cache_file |
| 64 | self.cache: Dict[str, Dict[str, Dict[str, float]]] |
| 65 | |
| 66 | try: |
| 67 | with open(cache_file, encoding="utf-8") as f: |
| 68 | self.cache = json.load(f) |
| 69 | except (OSError, ValueError): |
| 70 | self.cache = {} |
| 71 | |
| 72 | def get(self, test: str, |
| 73 | default: Optional[float] = None) -> Optional[float]: |
| 74 | if test not in self.cache: |
| 75 | return default |
| 76 | |
| 77 | if self.env.imgproto not in self.cache[test]: |
| 78 | return default |
| 79 | |
| 80 | return self.cache[test][self.env.imgproto].get(self.env.imgfmt, |
| 81 | default) |
| 82 | |
| 83 | def update(self, test: str, elapsed: float) -> None: |
| 84 | d = self.cache.setdefault(test, {}) |
| 85 | d.setdefault(self.env.imgproto, {})[self.env.imgfmt] = elapsed |
| 86 | |
| 87 | def save(self) -> None: |
| 88 | with open(self.cache_file, 'w', encoding="utf-8") as f: |
| 89 | json.dump(self.cache, f) |
| 90 | |
| 91 | def __enter__(self) -> 'LastElapsedTime': |
| 92 | return self |
| 93 | |
| 94 | def __exit__(self, exc_type: Any, exc_value: Any, traceback: Any) -> None: |
| 95 | self.save() |
| 96 | |
| 97 | |
| 98 | class TestResult: |
| 99 | def __init__(self, status: str, description: str = '', |
| 100 | elapsed: Optional[float] = None, diff: Sequence[str] = (), |
| 101 | casenotrun: str = '', interrupted: bool = False) -> None: |
| 102 | self.status = status |
| 103 | self.description = description |
| 104 | self.elapsed = elapsed |
| 105 | self.diff = diff |
| 106 | self.casenotrun = casenotrun |
| 107 | self.interrupted = interrupted |
| 108 | |
| 109 | |
| 110 | class TestRunner(contextlib.AbstractContextManager['TestRunner']): |
| 111 | shared_self = None |
| 112 | |
| 113 | @staticmethod |
| 114 | def proc_run_test(test: str, test_field_width: int) -> TestResult: |
| 115 | # We are in a subprocess, we can't change the runner object! |
| 116 | runner = TestRunner.shared_self |
| 117 | assert runner is not None |
| 118 | return runner.run_test(test, test_field_width, mp=True) |
| 119 | |
| 120 | def run_tests_pool(self, tests: List[str], |
| 121 | test_field_width: int, jobs: int) -> List[TestResult]: |
| 122 | |
| 123 | # passing self directly to Pool.starmap() just doesn't work, because |
| 124 | # it's a context manager. |
| 125 | assert TestRunner.shared_self is None |
| 126 | TestRunner.shared_self = self |
| 127 | |
| 128 | with get_context('fork').Pool(jobs) as p: |
| 129 | results = p.starmap(self.proc_run_test, |
| 130 | zip(tests, [test_field_width] * len(tests))) |
| 131 | |
| 132 | TestRunner.shared_self = None |
| 133 | |
| 134 | return results |
| 135 | |
| 136 | def __init__(self, env: TestEnv, tap: bool = False, |
| 137 | color: str = 'auto') -> None: |
| 138 | self.env = env |
| 139 | self.tap = tap |
| 140 | self.last_elapsed = LastElapsedTime('.last-elapsed-cache', env) |
| 141 | |
| 142 | assert color in ('auto', 'on', 'off') |
| 143 | self.color = (color == 'on') or (color == 'auto' and |
| 144 | sys.stdout.isatty()) |
| 145 | |
| 146 | self._stack: contextlib.ExitStack |
| 147 | |
| 148 | def __enter__(self) -> 'TestRunner': |
| 149 | self._stack = contextlib.ExitStack() |
| 150 | self._stack.enter_context(self.env) |
| 151 | self._stack.enter_context(self.last_elapsed) |
| 152 | return self |
| 153 | |
| 154 | def __exit__(self, exc_type: Any, exc_value: Any, traceback: Any) -> None: |
| 155 | self._stack.close() |
| 156 | |
| 157 | def test_print_one_line(self, test: str, |
| 158 | test_field_width: int, |
| 159 | starttime: str, |
| 160 | endtime: Optional[str] = None, status: str = '...', |
| 161 | lasttime: Optional[float] = None, |
| 162 | thistime: Optional[float] = None, |
| 163 | description: str = '', |
| 164 | end: str = '\n') -> None: |
| 165 | """ Print short test info before/after test run """ |
| 166 | test = os.path.basename(test) |
| 167 | |
| 168 | if test_field_width is None: |
| 169 | test_field_width = 8 |
| 170 | |
| 171 | if self.tap: |
| 172 | if status == 'pass': |
| 173 | print(f'ok {self.env.imgfmt} {test}') |
| 174 | elif status == 'fail': |
| 175 | print(f'not ok {self.env.imgfmt} {test}') |
| 176 | elif status == 'not run': |
| 177 | print(f'ok {self.env.imgfmt} {test} # SKIP {description}') |
| 178 | return |
| 179 | |
| 180 | if lasttime: |
| 181 | lasttime_s = f' (last: {lasttime:.1f}s)' |
| 182 | else: |
| 183 | lasttime_s = '' |
| 184 | if thistime: |
| 185 | thistime_s = f'{thistime:.1f}s' |
| 186 | else: |
| 187 | thistime_s = '...' |
| 188 | |
| 189 | if endtime: |
| 190 | endtime = f'[{endtime}]' |
| 191 | else: |
| 192 | endtime = '' |
| 193 | |
| 194 | if self.color: |
| 195 | if status == 'pass': |
| 196 | col = '\033[32m' |
| 197 | elif status == 'fail': |
| 198 | col = '\033[1m\033[31m' |
| 199 | elif status == 'not run': |
| 200 | col = '\033[33m' |
| 201 | else: |
| 202 | col = '' |
| 203 | |
| 204 | col_end = '\033[0m' |
| 205 | else: |
| 206 | col = '' |
| 207 | col_end = '' |
| 208 | |
| 209 | print(f'{test:{test_field_width}} {col}{status:10}{col_end} ' |
| 210 | f'[{starttime}] {endtime:13}{thistime_s:5} {lasttime_s:14} ' |
| 211 | f'{description}', end=end) |
| 212 | |
| 213 | def find_reference(self, test: str) -> str: |
| 214 | if self.env.cachemode == 'none': |
| 215 | ref = f'{test}.out.nocache' |
| 216 | if os.path.isfile(ref): |
| 217 | return ref |
| 218 | |
| 219 | ref = f'{test}.out.{self.env.imgfmt}' |
| 220 | if os.path.isfile(ref): |
| 221 | return ref |
| 222 | |
| 223 | ref = f'{test}.{self.env.qemu_default_machine}.out' |
| 224 | if os.path.isfile(ref): |
| 225 | return ref |
| 226 | |
| 227 | return f'{test}.out' |
| 228 | |
| 229 | def do_run_test(self, test: str) -> TestResult: |
| 230 | """ |
| 231 | Run one test |
| 232 | |
| 233 | :param test: test file path |
| 234 | |
| 235 | Note: this method may be called from subprocess, so it does not |
| 236 | change ``self`` object in any way! |
| 237 | """ |
| 238 | |
| 239 | f_test = Path(test) |
| 240 | f_reference = Path(self.find_reference(test)) |
| 241 | |
| 242 | if not f_test.exists(): |
| 243 | return TestResult(status='fail', |
| 244 | description=f'No such test file: {f_test}') |
| 245 | |
| 246 | if not os.access(str(f_test), os.X_OK): |
| 247 | sys.exit(f'Not executable: {f_test}') |
| 248 | |
| 249 | if not f_reference.exists(): |
| 250 | return TestResult(status='not run', |
| 251 | description='No qualified output ' |
| 252 | f'(expected {f_reference})') |
| 253 | |
| 254 | args = [str(f_test.resolve())] |
| 255 | env = self.env.prepare_subprocess(args) |
| 256 | |
| 257 | # Split test directories, so that tests running in parallel don't |
| 258 | # break each other. |
| 259 | for d in ['TEST_DIR', 'SOCK_DIR']: |
| 260 | env[d] = os.path.join( |
| 261 | env[d], |
| 262 | f"{self.env.imgfmt}-{self.env.imgproto}-{f_test.name}") |
| 263 | Path(env[d]).mkdir(parents=True, exist_ok=True) |
| 264 | |
| 265 | test_dir = env['TEST_DIR'] |
| 266 | f_asan = Path(test_dir, f_test.name + '.out.asan') |
| 267 | f_bad = Path(test_dir, f_test.name + '.out.bad') |
| 268 | f_notrun = Path(test_dir, f_test.name + '.notrun') |
| 269 | f_casenotrun = Path(test_dir, f_test.name + '.casenotrun') |
| 270 | |
| 271 | env['ASAN_OPTIONS'] = f'detect_leaks=0:log_path={f_asan}' |
| 272 | |
| 273 | def unlink_asan(): |
| 274 | with os.scandir(test_dir) as it: |
| 275 | for entry in it: |
| 276 | if entry.name.startswith(f_asan.name): |
| 277 | os.unlink(entry) |
| 278 | |
| 279 | unlink_asan() |
| 280 | |
| 281 | for p in (f_notrun, f_casenotrun): |
| 282 | silent_unlink(p) |
| 283 | |
| 284 | t0 = time.time() |
| 285 | with f_bad.open('w', encoding="utf-8") as f: |
| 286 | with subprocess.Popen(args, cwd=str(f_test.parent), env=env, |
| 287 | stdin=subprocess.DEVNULL, |
| 288 | stdout=f, stderr=subprocess.STDOUT) as proc: |
| 289 | try: |
| 290 | proc.wait() |
| 291 | except KeyboardInterrupt: |
| 292 | proc.terminate() |
| 293 | proc.wait() |
| 294 | return TestResult(status='not run', |
| 295 | description='Interrupted by user', |
| 296 | interrupted=True) |
| 297 | ret = proc.returncode |
| 298 | |
| 299 | elapsed = round(time.time() - t0, 1) |
| 300 | |
| 301 | if ret != 0: |
| 302 | return TestResult(status='fail', elapsed=elapsed, |
| 303 | description=f'failed, exit status {ret}', |
| 304 | diff=file_diff(str(f_reference), str(f_bad))) |
| 305 | |
| 306 | if f_notrun.exists(): |
| 307 | return TestResult( |
| 308 | status='not run', |
| 309 | description=f_notrun.read_text(encoding='utf-8').strip()) |
| 310 | |
| 311 | casenotrun = '' |
| 312 | if f_casenotrun.exists(): |
| 313 | casenotrun = f_casenotrun.read_text(encoding='utf-8') |
| 314 | |
| 315 | diff = file_diff(str(f_reference), str(f_bad)) |
| 316 | if diff: |
| 317 | if os.environ.get("QEMU_IOTESTS_REGEN", None) is not None: |
| 318 | shutil.copyfile(str(f_bad), str(f_reference)) |
| 319 | print("########################################") |
| 320 | print("##### REFERENCE FILE UPDATED #####") |
| 321 | print("########################################") |
| 322 | return TestResult(status='fail', elapsed=elapsed, |
| 323 | description=f'output mismatch (see {f_bad})', |
| 324 | diff=diff, casenotrun=casenotrun) |
| 325 | else: |
| 326 | unlink_asan() |
| 327 | f_bad.unlink() |
| 328 | return TestResult(status='pass', elapsed=elapsed, |
| 329 | casenotrun=casenotrun) |
| 330 | |
| 331 | def run_test(self, test: str, |
| 332 | test_field_width: int, |
| 333 | mp: bool = False) -> TestResult: |
| 334 | """ |
| 335 | Run one test and print short status |
| 336 | |
| 337 | :param test: test file path |
| 338 | :param test_field_width: width for first field of status format |
| 339 | :param mp: if true, we are in a multiprocessing environment, don't try |
| 340 | to rewrite things in stdout |
| 341 | |
| 342 | Note: this method may be called from subprocess, so it does not |
| 343 | change ``self`` object in any way! |
| 344 | """ |
| 345 | |
| 346 | last_el = self.last_elapsed.get(test) |
| 347 | start = datetime.datetime.now().strftime('%H:%M:%S') |
| 348 | |
| 349 | if not self.tap: |
| 350 | self.test_print_one_line(test=test, |
| 351 | test_field_width=test_field_width, |
| 352 | status = 'started' if mp else '...', |
| 353 | starttime=start, |
| 354 | lasttime=last_el, |
| 355 | end = '\n' if mp else '\r') |
| 356 | else: |
| 357 | testname = os.path.basename(test) |
| 358 | print(f'# running {self.env.imgfmt} {testname}') |
| 359 | |
| 360 | res = self.do_run_test(test) |
| 361 | |
| 362 | end = datetime.datetime.now().strftime('%H:%M:%S') |
| 363 | self.test_print_one_line(test=test, |
| 364 | test_field_width=test_field_width, |
| 365 | status=res.status, |
| 366 | starttime=start, endtime=end, |
| 367 | lasttime=last_el, thistime=res.elapsed, |
| 368 | description=res.description) |
| 369 | |
| 370 | if res.casenotrun: |
| 371 | if self.tap: |
| 372 | print('#' + res.casenotrun.replace('\n', '\n#')) |
| 373 | else: |
| 374 | print(res.casenotrun) |
| 375 | |
| 376 | sys.stdout.flush() |
| 377 | return res |
| 378 | |
| 379 | def run_tests(self, tests: List[str], jobs: int = 1) -> bool: |
| 380 | n_run = 0 |
| 381 | failed = [] |
| 382 | notrun = [] |
| 383 | casenotrun = [] |
| 384 | |
| 385 | if self.tap: |
| 386 | print('TAP version 13') |
| 387 | self.env.print_env('# ') |
| 388 | print('1..%d' % len(tests)) |
| 389 | else: |
| 390 | self.env.print_env() |
| 391 | |
| 392 | test_field_width = max(len(os.path.basename(t)) for t in tests) + 2 |
| 393 | |
| 394 | if jobs > 1: |
| 395 | results = self.run_tests_pool(tests, test_field_width, jobs) |
| 396 | |
| 397 | for i, t in enumerate(tests): |
| 398 | name = os.path.basename(t) |
| 399 | |
| 400 | if jobs > 1: |
| 401 | res = results[i] |
| 402 | else: |
| 403 | res = self.run_test(t, test_field_width) |
| 404 | |
| 405 | assert res.status in ('pass', 'fail', 'not run') |
| 406 | |
| 407 | if res.casenotrun: |
| 408 | casenotrun.append(t) |
| 409 | |
| 410 | if res.status != 'not run': |
| 411 | n_run += 1 |
| 412 | |
| 413 | if res.status == 'fail': |
| 414 | failed.append(name) |
| 415 | if res.diff: |
| 416 | if self.tap: |
| 417 | print('\n'.join(res.diff), file=sys.stderr) |
| 418 | else: |
| 419 | print('\n'.join(res.diff)) |
| 420 | elif res.status == 'not run': |
| 421 | notrun.append(name) |
| 422 | elif res.status == 'pass': |
| 423 | assert res.elapsed is not None |
| 424 | self.last_elapsed.update(t, res.elapsed) |
| 425 | |
| 426 | sys.stdout.flush() |
| 427 | if res.interrupted: |
| 428 | break |
| 429 | |
| 430 | if not self.tap: |
| 431 | if notrun: |
| 432 | print('Not run:', ' '.join(notrun)) |
| 433 | |
| 434 | if casenotrun: |
| 435 | print('Some cases not run in:', ' '.join(casenotrun)) |
| 436 | |
| 437 | if failed: |
| 438 | print('Failures:', ' '.join(failed)) |
| 439 | print(f'Failed {len(failed)} of {n_run} iotests') |
| 440 | else: |
| 441 | print(f'Passed all {n_run} iotests') |
| 442 | return not failed |