xref: /openbmc/qemu/tests/qemu-iotests/testrunner.py (revision c4fa97c7f216fc80b09a5d32be847ff8d502cba6)
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
19import os
20from pathlib import Path
21import datetime
22import time
23import difflib
24import subprocess
25import contextlib
26import json
27import shutil
28import sys
29from multiprocessing import Pool
30from typing import List, Optional, Any, Sequence, Dict
31from testenv import TestEnv
32
33
34def silent_unlink(path: Path) -> None:
35    try:
36        path.unlink()
37    except OSError:
38        pass
39
40
41def 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
55class 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
98class 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
110class 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 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')
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_bad = Path(test_dir, f_test.name + '.out.bad')
267        f_notrun = Path(test_dir, f_test.name + '.notrun')
268        f_casenotrun = Path(test_dir, f_test.name + '.casenotrun')
269
270        for p in (f_notrun, f_casenotrun):
271            silent_unlink(p)
272
273        t0 = time.time()
274        with f_bad.open('w', encoding="utf-8") as f:
275            with subprocess.Popen(args, cwd=str(f_test.parent), env=env,
276                                  stdin=subprocess.DEVNULL,
277                                  stdout=f, stderr=subprocess.STDOUT) as proc:
278                try:
279                    proc.wait()
280                except KeyboardInterrupt:
281                    proc.terminate()
282                    proc.wait()
283                    return TestResult(status='not run',
284                                      description='Interrupted by user',
285                                      interrupted=True)
286                ret = proc.returncode
287
288        elapsed = round(time.time() - t0, 1)
289
290        if ret != 0:
291            return TestResult(status='fail', elapsed=elapsed,
292                              description=f'failed, exit status {ret}',
293                              diff=file_diff(str(f_reference), str(f_bad)))
294
295        if f_notrun.exists():
296            return TestResult(
297                status='not run',
298                description=f_notrun.read_text(encoding='utf-8').strip())
299
300        casenotrun = ''
301        if f_casenotrun.exists():
302            casenotrun = f_casenotrun.read_text(encoding='utf-8')
303
304        diff = file_diff(str(f_reference), str(f_bad))
305        if diff:
306            if os.environ.get("QEMU_IOTESTS_REGEN", None) is not None:
307                shutil.copyfile(str(f_bad), str(f_reference))
308                print("########################################")
309                print("#####    REFERENCE FILE UPDATED    #####")
310                print("########################################")
311            return TestResult(status='fail', elapsed=elapsed,
312                              description=f'output mismatch (see {f_bad})',
313                              diff=diff, casenotrun=casenotrun)
314        else:
315            f_bad.unlink()
316            return TestResult(status='pass', elapsed=elapsed,
317                              casenotrun=casenotrun)
318
319    def run_test(self, test: str,
320                 test_field_width: int,
321                 mp: bool = False) -> TestResult:
322        """
323        Run one test and print short status
324
325        :param test: test file path
326        :param test_field_width: width for first field of status format
327        :param mp: if true, we are in a multiprocessing environment, don't try
328                   to rewrite things in stdout
329
330        Note: this method may be called from subprocess, so it does not
331        change ``self`` object in any way!
332        """
333
334        last_el = self.last_elapsed.get(test)
335        start = datetime.datetime.now().strftime('%H:%M:%S')
336
337        if not self.tap:
338            self.test_print_one_line(test=test,
339                                     test_field_width=test_field_width,
340                                     status = 'started' if mp else '...',
341                                     starttime=start,
342                                     lasttime=last_el,
343                                     end = '\n' if mp else '\r')
344        else:
345            testname = os.path.basename(test)
346            print(f'# running {self.env.imgfmt} {testname}')
347
348        res = self.do_run_test(test)
349
350        end = datetime.datetime.now().strftime('%H:%M:%S')
351        self.test_print_one_line(test=test,
352                                 test_field_width=test_field_width,
353                                 status=res.status,
354                                 starttime=start, endtime=end,
355                                 lasttime=last_el, thistime=res.elapsed,
356                                 description=res.description)
357
358        if res.casenotrun:
359            if self.tap:
360                print('#' + res.casenotrun.replace('\n', '\n#'))
361            else:
362                print(res.casenotrun)
363
364        sys.stdout.flush()
365        return res
366
367    def run_tests(self, tests: List[str], jobs: int = 1) -> bool:
368        n_run = 0
369        failed = []
370        notrun = []
371        casenotrun = []
372
373        if self.tap:
374            print('TAP version 13')
375            self.env.print_env('# ')
376            print('1..%d' % len(tests))
377        else:
378            self.env.print_env()
379
380        test_field_width = max(len(os.path.basename(t)) for t in tests) + 2
381
382        if jobs > 1:
383            results = self.run_tests_pool(tests, test_field_width, jobs)
384
385        for i, t in enumerate(tests):
386            name = os.path.basename(t)
387
388            if jobs > 1:
389                res = results[i]
390            else:
391                res = self.run_test(t, test_field_width)
392
393            assert res.status in ('pass', 'fail', 'not run')
394
395            if res.casenotrun:
396                casenotrun.append(t)
397
398            if res.status != 'not run':
399                n_run += 1
400
401            if res.status == 'fail':
402                failed.append(name)
403                if res.diff:
404                    if self.tap:
405                        print('\n'.join(res.diff), file=sys.stderr)
406                    else:
407                        print('\n'.join(res.diff))
408            elif res.status == 'not run':
409                notrun.append(name)
410            elif res.status == 'pass':
411                assert res.elapsed is not None
412                self.last_elapsed.update(t, res.elapsed)
413
414            sys.stdout.flush()
415            if res.interrupted:
416                break
417
418        if not self.tap:
419            if notrun:
420                print('Not run:', ' '.join(notrun))
421
422            if casenotrun:
423                print('Some cases not run in:', ' '.join(casenotrun))
424
425            if failed:
426                print('Failures:', ' '.join(failed))
427                print(f'Failed {len(failed)} of {n_run} iotests')
428            else:
429                print(f'Passed all {n_run} iotests')
430        return not failed
431