diff --git a/src/client/dfuse/il/int_posix.c b/src/client/dfuse/il/int_posix.c index 3609adcb5fc..027b938c869 100644 --- a/src/client/dfuse/il/int_posix.c +++ b/src/client/dfuse/il/int_posix.c @@ -359,8 +359,10 @@ ioil_init(void) static void ioil_show_summary() { - D_INFO("Performed %"PRIu64" reads and %"PRIu64" writes from %"PRIu64" files\n", - ioil_iog.iog_read_count, ioil_iog.iog_write_count, ioil_iog.iog_file_count); + D_INFO("Performed %" PRIu64 " reads, %" PRIu64 " writes and %" PRIu64 + " fstats from %" PRIu64 " files\n", + ioil_iog.iog_read_count, ioil_iog.iog_write_count, ioil_iog.iog_fstat_count, + ioil_iog.iog_file_count); if (ioil_iog.iog_file_count == 0 || !ioil_iog.iog_show_summary) return; diff --git a/utils/node_local_test.py b/utils/node_local_test.py index 6ace1015df3..c44695237b3 100755 --- a/utils/node_local_test.py +++ b/utils/node_local_test.py @@ -46,17 +46,27 @@ class NLTestFail(Exception): """Used to indicate test failure""" + def __repr__(self): + return "Test failure object for NLT" + class NLTestNoFi(NLTestFail): """Used to indicate Fault injection didn't work""" -class NLTestNoFunction(NLTestFail): +class NLTestIlZeroCall(NLTestFail): """Used to indicate a function did not log anything""" def __init__(self, function): super().__init__(self) self.function = function + self.command = [] + + def __str__(self): + if self.command: + cmd = ' '.join(self.command) + return f'Command "{cmd}" has zero stat count for {self.function}' + return f"Called program did not call {self.function}" class NLTestTimeout(NLTestFail): @@ -1507,8 +1517,11 @@ def il_cmd(self, cmd, check_read=True, check_write=True, check_fstat=True): would be freed in the _fini() function, and a lot of commands do not free all memory anyway. """ + if self.caching: + check_fstat = False + my_env = get_base_env() - prefix = f'dnt_dfuse_il_{get_inc_id()}_' + prefix = f'dnt_ioil_{cmd[0]}_{get_inc_id()}_' with tempfile.NamedTemporaryFile(prefix=prefix, suffix='.log', delete=False) as log_file: log_name = log_file.name my_env['D_LOG_FILE'] = log_name @@ -1517,21 +1530,27 @@ def il_cmd(self, cmd, check_read=True, check_write=True, check_fstat=True): my_env['D_IL_REPORT'] = '2' if self.conf.args.client_debug: my_env['D_LOG_MASK'] = self.conf.args.client_debug + + if check_fstat: + fsu = self.check_usage()['statistics'] + ret = subprocess.run(cmd, env=my_env, check=False) print(f'Logged il to {log_name}') print(ret) - if self.caching: - check_fstat = False + if check_fstat: + fsu2 = self.check_usage()['statistics'] + print(fsu) + print(fsu2) + delta = fsu2.get('getattr', 0) - fsu.get('getattr', 0) + print(f"Command caused {delta} stat calls") try: log_test(self.conf, log_name, check_read=check_read, check_write=check_write, check_fstat=check_fstat) - assert ret.returncode == 0 - except NLTestNoFunction as error: - command = ' '.join(cmd) - print(f"ERROR: command '{command}' did not log via {error.function}") - ret.returncode = 1 + except NLTestIlZeroCall as error: + error.command = cmd + raise assert ret.returncode == 0, ret return ret @@ -2712,11 +2731,7 @@ def test_il_cat(self): with open(fname, 'w'): pass - check_fstat = True - if self.dfuse.caching: - check_fstat = False - - self.dfuse.il_cmd(['cat', fname], check_write=False, check_fstat=check_fstat) + self.dfuse.il_cmd(['cat', fname], check_write=False) @needs_dfuse_with_opt(caching=False) def test_il(self): @@ -4654,7 +4669,6 @@ def run_tests(dfuse): assert_file_size(ofd, 21) print(os.fstat(ofd.fileno())) ofd.close() - dfuse.il_cmd(['cat', fname], check_write=False) ofd = os.open(fname, os.O_TRUNC) assert_file_size_fd(ofd, 0) os.close(ofd) @@ -4831,20 +4845,21 @@ def sizeof_fmt(num, suffix='B'): if not lto.fi_triggered: raise NLTestNoFi - functions = set() - if check_read or check_write or check_fstat: for line in log_iter.new_iter(): - functions.add(line.function) + if line.function != "ioil_show_summary": + continue + print(line.get_msg()) - if check_read and 'dfuse_read' not in functions: - raise NLTestNoFunction('dfuse_read') + # These numbers match the D_INFO log line in the ioil_show_summary function. + if check_read and int(line.get_field(3)) == 0: + raise NLTestIlZeroCall('read') - if check_write and 'dfuse_write' not in functions: - raise NLTestNoFunction('dfuse_write') + if check_write and int(line.get_field(5)) == 0: + raise NLTestIlZeroCall('write') - if check_fstat and 'dfuse___fxstat' not in functions: - raise NLTestNoFunction('dfuse___fxstat') + if check_fstat and int(line.get_field(8)) == 0: + raise NLTestIlZeroCall('fstat') if conf.max_log_size and fstat.st_size > conf.max_log_size: message = (f'Max log size exceeded, {sizeof_fmt(fstat.st_size)} > '