diff --git a/runners/test_runner.c b/runners/test_runner.c index b187fcb3..4ce22ab6 100644 --- a/runners/test_runner.c +++ b/runners/test_runner.c @@ -1,4 +1,8 @@ +#ifndef _POSIX_C_SOURCE +#define _POSIX_C_SOURCE 199309L +#endif + #include "runners/test_runner.h" #include "bd/lfs_testbd.h" @@ -6,6 +10,10 @@ #include #include #include +#include +#include +#include +#include // test suites in a custom ld section @@ -219,10 +227,10 @@ static void run_powerloss_none( size_t perm, const lfs_testbd_powercycles_t *cycles, size_t cycle_count); -static const test_powerloss_t *test_powerlosses = (const test_powerloss_t[]){ +const test_powerloss_t *test_powerlosses = (const test_powerloss_t[]){ {'0', "none", run_powerloss_none, NULL, 0}, }; -static size_t test_powerloss_count = 1; +size_t test_powerloss_count = 1; typedef struct test_id { @@ -233,23 +241,70 @@ typedef struct test_id { size_t cycle_count; } test_id_t; -static const test_id_t *test_ids = (const test_id_t[]) { +const test_id_t *test_ids = (const test_id_t[]) { {NULL, NULL, -1, NULL, 0}, }; -static size_t test_id_count = 1; +size_t test_id_count = 1; -static const char *test_geometry = NULL; +const char *test_geometry = NULL; -static size_t test_start = 0; -static size_t test_stop = -1; -static size_t test_step = 1; +size_t test_start = 0; +size_t test_stop = -1; +size_t test_step = 1; -static const char *test_disk = NULL; -FILE *test_trace = NULL; -static lfs_testbd_delay_t test_read_delay = 0.0; -static lfs_testbd_delay_t test_prog_delay = 0.0; -static lfs_testbd_delay_t test_erase_delay = 0.0; +const char *test_disk_path = NULL; +const char *test_trace_path = NULL; +FILE *test_trace_file = NULL; +uint32_t test_trace_cycles = 0; +lfs_testbd_delay_t test_read_delay = 0.0; +lfs_testbd_delay_t test_prog_delay = 0.0; +lfs_testbd_delay_t test_erase_delay = 0.0; + + +// trace printing +void test_trace(const char *fmt, ...) { + if (test_trace_path) { + if (!test_trace_file) { + // Tracing output is heavy and trying to open every trace + // call is slow, so we only try to open the trace file every + // so often. Note this doesn't affect successfully opened files + if (test_trace_cycles % 128 != 0) { + test_trace_cycles += 1; + return; + } + test_trace_cycles += 1; + + int fd; + if (strcmp(test_trace_path, "-") == 0) { + fd = dup(1); + } else { + fd = open( + test_trace_path, + O_WRONLY | O_CREAT | O_APPEND | O_NONBLOCK, + 0666); + } + if (fd < 0) { + return; + } + + FILE *f = fdopen(fd, "a"); + assert(f); + int err = setvbuf(f, NULL, _IOLBF, BUFSIZ); + assert(!err); + test_trace_file = f; + } + + va_list va; + va_start(va, fmt); + int res = vfprintf(test_trace_file, fmt, va); + if (res < 0) { + fclose(test_trace_file); + test_trace_file = NULL; + } + va_end(va); + } +} // how many permutations are there actually in a test case @@ -613,13 +668,13 @@ static void run_powerloss_none( .erase_value = ERASE_VALUE, .erase_cycles = ERASE_CYCLES, .badblock_behavior = BADBLOCK_BEHAVIOR, - .disk_path = test_disk, + .disk_path = test_disk_path, .read_delay = test_read_delay, .prog_delay = test_prog_delay, .erase_delay = test_erase_delay, }; - int err = lfs_testbd_createcfg(&cfg, test_disk, &bdcfg); + int err = lfs_testbd_createcfg(&cfg, test_disk_path, &bdcfg); if (err) { fprintf(stderr, "error: could not create block device: %d\n", err); exit(-1); @@ -679,7 +734,7 @@ static void run_powerloss_linear( .erase_value = ERASE_VALUE, .erase_cycles = ERASE_CYCLES, .badblock_behavior = BADBLOCK_BEHAVIOR, - .disk_path = test_disk, + .disk_path = test_disk_path, .read_delay = test_read_delay, .prog_delay = test_prog_delay, .erase_delay = test_erase_delay, @@ -689,7 +744,7 @@ static void run_powerloss_linear( .powerloss_data = &powerloss_jmp, }; - int err = lfs_testbd_createcfg(&cfg, test_disk, &bdcfg); + int err = lfs_testbd_createcfg(&cfg, test_disk_path, &bdcfg); if (err) { fprintf(stderr, "error: could not create block device: %d\n", err); exit(-1); @@ -760,7 +815,7 @@ static void run_powerloss_exponential( .erase_value = ERASE_VALUE, .erase_cycles = ERASE_CYCLES, .badblock_behavior = BADBLOCK_BEHAVIOR, - .disk_path = test_disk, + .disk_path = test_disk_path, .read_delay = test_read_delay, .prog_delay = test_prog_delay, .erase_delay = test_erase_delay, @@ -770,7 +825,7 @@ static void run_powerloss_exponential( .powerloss_data = &powerloss_jmp, }; - int err = lfs_testbd_createcfg(&cfg, test_disk, &bdcfg); + int err = lfs_testbd_createcfg(&cfg, test_disk_path, &bdcfg); if (err) { fprintf(stderr, "error: could not create block device: %d\n", err); exit(-1); @@ -839,7 +894,7 @@ static void run_powerloss_cycles( .erase_value = ERASE_VALUE, .erase_cycles = ERASE_CYCLES, .badblock_behavior = BADBLOCK_BEHAVIOR, - .disk_path = test_disk, + .disk_path = test_disk_path, .read_delay = test_read_delay, .prog_delay = test_prog_delay, .erase_delay = test_erase_delay, @@ -849,7 +904,7 @@ static void run_powerloss_cycles( .powerloss_data = &powerloss_jmp, }; - int err = lfs_testbd_createcfg(&cfg, test_disk, &bdcfg); + int err = lfs_testbd_createcfg(&cfg, test_disk_path, &bdcfg); if (err) { fprintf(stderr, "error: could not create block device: %d\n", err); exit(-1); @@ -1025,7 +1080,7 @@ static void run_powerloss_exhaustive( .erase_value = ERASE_VALUE, .erase_cycles = ERASE_CYCLES, .badblock_behavior = BADBLOCK_BEHAVIOR, - .disk_path = test_disk, + .disk_path = test_disk_path, .read_delay = test_read_delay, .prog_delay = test_prog_delay, .erase_delay = test_erase_delay, @@ -1034,7 +1089,7 @@ static void run_powerloss_exhaustive( .powerloss_data = NULL, }; - int err = lfs_testbd_createcfg(&cfg, test_disk, &bdcfg); + int err = lfs_testbd_createcfg(&cfg, test_disk_path, &bdcfg); if (err) { fprintf(stderr, "error: could not create block device: %d\n", err); exit(-1); @@ -1153,6 +1208,9 @@ static void run_perms( } static void run(void) { + // ignore disconnected pipes + signal(SIGPIPE, SIG_IGN); + for (size_t t = 0; t < test_id_count; t++) { for (size_t i = 0; i < TEST_SUITE_COUNT; i++) { if (test_ids[t].suite && strcmp( @@ -1563,19 +1621,10 @@ powerloss_next: break; } case OPT_DISK: - test_disk = optarg; + test_disk_path = optarg; break; case OPT_TRACE: - if (strcmp(optarg, "-") == 0) { - test_trace = stdout; - } else { - test_trace = fopen(optarg, "w"); - if (!test_trace) { - fprintf(stderr, "error: could not open for trace: %d\n", - -errno); - exit(-1); - } - } + test_trace_path = optarg; break; case OPT_READ_DELAY: { char *parsed = NULL; diff --git a/runners/test_runner.h b/runners/test_runner.h index 27229ad3..4459a5c9 100644 --- a/runners/test_runner.h +++ b/runners/test_runner.h @@ -1,7 +1,26 @@ #ifndef TEST_RUNNER_H #define TEST_RUNNER_H -#include "lfs.h" + +// override LFS_TRACE +void test_trace(const char *fmt, ...); + +#define LFS_TRACE_(fmt, ...) \ + test_trace("%s:%d:trace: " fmt "%s\n", \ + __FILE__, \ + __LINE__, \ + __VA_ARGS__) +#define LFS_TRACE(...) LFS_TRACE_(__VA_ARGS__, "") +#define LFS_TESTBD_TRACE(...) LFS_TRACE_(__VA_ARGS__, "") + + +// note these are indirectly included in any generated files +#include "bd/lfs_testbd.h" +#include + +// give source a chance to define feature macros +#undef _FEATURES_H +#undef _STDIO_H // generated test configurations @@ -10,6 +29,8 @@ enum test_flags { }; typedef uint8_t test_flags_t; +struct lfs_config; + struct test_case { const char *id; const char *name; diff --git a/scripts/pretty_asserts.py b/scripts/pretty_asserts.py index 33c64c9b..8afa6545 100755 --- a/scripts/pretty_asserts.py +++ b/scripts/pretty_asserts.py @@ -422,7 +422,8 @@ if __name__ == "__main__": parser.add_argument('-p', '--pattern', action='append', help="Regex patterns to search for starting an assert statement. This" " implicitly includes \"assert\" and \"=>\".") - parser.add_argument('-l', '--limit', default=LIMIT, type=int, + parser.add_argument('-l', '--limit', + default=LIMIT, type=lambda x: int(x, 0), help="Maximum number of characters to display in strcmp and memcmp.") sys.exit(main(**{k: v for k, v in vars(parser.parse_args()).items() diff --git a/scripts/tailpipe.py b/scripts/tailpipe.py new file mode 100755 index 00000000..985f571c --- /dev/null +++ b/scripts/tailpipe.py @@ -0,0 +1,102 @@ +#!/usr/bin/env python3 + +import os +import sys +import threading as th +import time + + +def openio(path, mode='r'): + if path == '-': + if 'r' in mode: + return os.fdopen(os.dup(sys.stdin.fileno()), 'r') + else: + return os.fdopen(os.dup(sys.stdout.fileno()), 'w') + else: + return open(path, mode) + +def main(path, lines=1, keep_open=False): + ring = [None] * lines + i = 0 + count = 0 + lock = th.Lock() + event = th.Event() + done = False + + # do the actual reading in a background thread + def read(): + nonlocal i + nonlocal count + nonlocal done + while True: + with openio(path, 'r') as f: + for line in f: + with lock: + ring[i] = line + i = (i + 1) % lines + count = min(lines, count + 1) + event.set() + if not keep_open: + break + done = True + + th.Thread(target=read, daemon=True).start() + + try: + last_count = 1 + while not done: + time.sleep(0.01) + event.wait() + event.clear() + + # create a copy to avoid corrupt output + with lock: + ring_ = ring.copy() + i_ = i + count_ = count + + # first thing first, give ourself a canvas + while last_count < count_: + sys.stdout.write('\n') + last_count += 1 + + for j in range(count_): + # move cursor, clear line, disable/reenable line wrapping + sys.stdout.write('\r%s\x1b[K\x1b[?7l%s\x1b[?7h%s' % ( + '\x1b[%dA' % (count_-1-j) if count_-1-j > 0 else '', + ring_[(i_-count+j) % lines][:-1], + '\x1b[%dB' % (count_-1-j) if count_-1-j > 0 else '')) + + sys.stdout.flush() + + except KeyboardInterrupt: + pass + + sys.stdout.write('\n') + + +if __name__ == "__main__": + import sys + import argparse + parser = argparse.ArgumentParser( + description="Efficiently displays the last n lines of a file/pipe.") + parser.add_argument( + 'path', + nargs='?', + default='-', + help="Path to read from.") + parser.add_argument( + '-n', + '--lines', + type=lambda x: int(x, 0), + default=1, + help="Number of lines to show, defaults to 1.") + parser.add_argument( + '-k', + '--keep-open', + action='store_true', + help="Reopen the pipe on EOF, useful when multiple " + "processes are writing.") + sys.exit(main(**{k: v + for k, v in vars(parser.parse_args()).items() + if v is not None})) diff --git a/scripts/test.py b/scripts/test.py index 4aa0f116..a29423bb 100755 --- a/scripts/test.py +++ b/scripts/test.py @@ -22,16 +22,7 @@ import toml TEST_PATHS = ['tests'] RUNNER_PATH = './runners/test_runner' - -SUITE_PROLOGUE = """ -#include "runners/test_runner.h" -#include "bd/lfs_testbd.h" -#include -""" -CASE_PROLOGUE = """ -""" -CASE_EPILOGUE = """ -""" +HEADER_PATH = 'runners/test_runner.h' def testpath(path): @@ -49,14 +40,21 @@ def testcase(path): _, case, *_ = path.split('#', 2) return '%s#%s' % (testsuite(path), case) -def openio(path, mode='r'): +def openio(path, mode='r', buffering=-1, nb=False): if path == '-': if 'r' in mode: - return os.fdopen(os.dup(sys.stdin.fileno()), 'r') + return os.fdopen(os.dup(sys.stdin.fileno()), 'r', buffering) else: - return os.fdopen(os.dup(sys.stdout.fileno()), 'w') + return os.fdopen(os.dup(sys.stdout.fileno()), 'w', buffering) + elif nb and 'a' in mode: + return os.fdopen(os.open( + path, + os.O_WRONLY | os.O_CREAT | os.O_APPEND | os.O_NONBLOCK, + 0o666), + mode, + buffering) else: - return open(path, mode) + return open(path, mode, buffering) def color(**args): if args.get('color') == 'auto': @@ -252,19 +250,8 @@ def compile(**args): f.writeln("//") f.writeln() - # redirect littlefs tracing - f.writeln('#define LFS_TRACE_(fmt, ...) do { \\') - f.writeln(8*' '+'extern FILE *test_trace; \\') - f.writeln(8*' '+'if (test_trace) { \\') - f.writeln(12*' '+'fprintf(test_trace, ' - '"%s:%d:trace: " fmt "%s\\n", \\') - f.writeln(20*' '+'__FILE__, __LINE__, __VA_ARGS__); \\') - f.writeln(8*' '+'} \\') - f.writeln(4*' '+'} while (0)') - f.writeln('#define LFS_TRACE(...) LFS_TRACE_(__VA_ARGS__, "")') - f.writeln('#define LFS_TESTBD_TRACE(...) ' - 'LFS_TRACE_(__VA_ARGS__, "")') - f.writeln() + # include test_runner.h in every generated file + f.writeln("#include \"%s\"" % HEADER_PATH) # write out generated functions, this can end up in different # files depending on the "in" attribute @@ -316,10 +303,6 @@ def compile(**args): f.writeln('void __test__%s__%s__run(' '__attribute__((unused)) struct lfs_config *cfg) {' % (suite.name, case.name)) - if CASE_PROLOGUE.strip(): - f.writeln(4*' '+'%s' - % CASE_PROLOGUE.strip().replace('\n', '\n'+4*' ')) - f.writeln() f.writeln(4*' '+'// test case %s' % case.id()) if case.code_lineno is not None: f.writeln(4*' '+'#line %d "%s"' @@ -328,17 +311,10 @@ def compile(**args): if case.code_lineno is not None: f.writeln(4*' '+'#line %d "%s"' % (f.lineno+1, args['output'])) - if CASE_EPILOGUE.strip(): - f.writeln() - f.writeln(4*' '+'%s' - % CASE_EPILOGUE.strip().replace('\n', '\n'+4*' ')) f.writeln('}') f.writeln() if not args.get('source'): - # write test suite prologue - f.writeln('%s' % SUITE_PROLOGUE.strip()) - f.writeln() if suite.code is not None: if suite.code_lineno is not None: f.writeln('#line %d "%s"' @@ -427,9 +403,6 @@ def compile(**args): shutil.copyfileobj(sf, f) f.writeln() - f.write(SUITE_PROLOGUE) - f.writeln() - # write any internal tests for suite in suites: for case in suite.cases: @@ -638,6 +611,7 @@ def run_stage(name, runner_, **args): # run the tests! cmd = runner_.copy() + # TODO move all these to runner? if args.get('disk'): cmd.append('--disk=%s' % args['disk']) if args.get('trace'): @@ -656,8 +630,7 @@ def run_stage(name, runner_, **args): os.close(spty) children.add(proc) mpty = os.fdopen(mpty, 'r', 1) - if args.get('output'): - output = openio(args['output'], 'w') + output = None last_id = None last_output = [] @@ -675,8 +648,18 @@ def run_stage(name, runner_, **args): break last_output.append(line) if args.get('output'): - output.write(line) - elif args.get('verbose'): + try: + if not output: + output = openio(args['output'], 'a', 1, nb=True) + output.write(line) + except OSError as e: + if e.errno not in [ + errno.ENXIO, + errno.EPIPE, + errno.EAGAIN]: + raise + output = None + if args.get('verbose'): sys.stdout.write(line) m = pattern.match(line) @@ -709,8 +692,6 @@ def run_stage(name, runner_, **args): finally: children.remove(proc) mpty.close() - if args.get('output'): - output.close() proc.wait() if proc.returncode != 0: @@ -722,6 +703,7 @@ def run_stage(name, runner_, **args): def run_job(runner, start=None, step=None): nonlocal failures + nonlocal killed nonlocal locals start = start or 0 @@ -756,6 +738,7 @@ def run_stage(name, runner_, **args): continue else: # stop other tests + killed = True for child in children.copy(): child.kill() break @@ -766,10 +749,12 @@ def run_stage(name, runner_, **args): if 'jobs' in args: for job in range(args['jobs']): runners.append(th.Thread( - target=run_job, args=(runner_, job, args['jobs']))) + target=run_job, args=(runner_, job, args['jobs']), + daemon=True)) else: runners.append(th.Thread( - target=run_job, args=(runner_, None, None))) + target=run_job, args=(runner_, None, None), + daemon=True)) def print_update(done): if not args.get('verbose') and (color(**args) or done): @@ -830,8 +815,10 @@ def run_stage(name, runner_, **args): def run(**args): + # measure runtime start = time.time() + # query runner for tests runner_ = runner(**args) print('using runner: %s' % ' '.join(shlex.quote(c) for c in runner_)) @@ -844,6 +831,15 @@ def run(**args): total_perms)) print() + # truncate and open logs here so they aren't disconnected between tests + output = None + if args.get('output'): + output = openio(args['output'], 'w', 1) + trace = None + if args.get('trace'): + trace = openio(args['trace'], 'w', 1) + + # spawn runners expected = 0 passed = 0 powerlosses = 0 @@ -857,7 +853,9 @@ def run(**args): # spawn jobs for stage expected_, passed_, powerlosses_, failures_, killed = run_stage( - by or 'tests', stage_runner, **args) + by or 'tests', + stage_runner, + **args) expected += expected_ passed += passed_ powerlosses += powerlosses_ @@ -865,6 +863,11 @@ def run(**args): if (failures and not args.get('keep_going')) or killed: break + if output: + output.close() + if trace: + trace.close() + # show summary print() print('%sdone:%s %s' % ( @@ -974,9 +977,11 @@ def main(**args): if __name__ == "__main__": import argparse import sys + argparse.ArgumentParser._handle_conflict_ignore = lambda *_: None + argparse._ArgumentGroup._handle_conflict_ignore = lambda *_: None parser = argparse.ArgumentParser( description="Build and run tests.", - conflict_handler='resolve') + conflict_handler='ignore') parser.add_argument('test_ids', nargs='*', help="Description of testis to run. May be a directory, path, or \ test identifier. Test identifiers are of the form \ @@ -1013,11 +1018,11 @@ if __name__ == "__main__": help="Comma-separated list of power-loss scenarios to test. \ Defaults to 0,l.") test_parser.add_argument('-d', '--disk', - help="Redirect block device operations to this file.") + help="Direct block device operations to this file.") test_parser.add_argument('-t', '--trace', - help="Redirect trace output to this file.") + help="Direct trace output to this file.") test_parser.add_argument('-o', '--output', - help="Redirect stdout and stderr to this file.") + help="Direct stdout and stderr to this file.") test_parser.add_argument('--read-delay', help="Artificial read delay in seconds.") test_parser.add_argument('--prog-delay',