Skip to content

Log Slowest Tests To Stdout And Github Summary If Possible #249

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
kei-nan wants to merge 2 commits into
base: master
Choose a base branch
from
+38 −1
Open

Log Slowest Tests To Stdout And Github Summary If Possible #249

Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
d557997
initial commit
kei-nan May 11, 2026
6b3fc9e
Merge upstream/master: integrate slowest-tests timings with new singl…
kei-nan May 11, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
39 changes: 38 additions & 1 deletion RLTest/__main__.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -299,6 +299,11 @@ def do_normal_conn(self, line):
'--verbose-information-on-failure', action='store_const', const=True, default=False,
help='Print a verbose information on test failure')

parser.add_argument(
'--print-slowest', type=int, default=10, metavar='N',
help='At the end of the run, print the N slowest tests. Set to 0 to disable. '
'If $GITHUB_STEP_SUMMARY is set, the table is also appended there as markdown.')

parser.add_argument(
'--enable-debug-command', action='store_const', const=True, default=False,
help='On Redis 7, debug command need to be enabled in order to be used.')
Expand Down Expand Up @@ -559,6 +564,7 @@ def __init__(self):

self.tests = []
self.testsFailed = {}
self.testsTimings = []
self.currEnv = None
self.loader = TestLoader()

Expand Down Expand Up @@ -729,6 +735,7 @@ def _runTest(self, test, numberOfAssertionFailed=0, prefix='', before=lambda x=N
after_func = after

hasException = False
startTime = time.monotonic()
try:
before_func()
fn()
Expand All @@ -755,6 +762,8 @@ def _runTest(self, test, numberOfAssertionFailed=0, prefix='', before=lambda x=N
finally:
after_func()

self.testsTimings.append((testFullName, time.monotonic() - startTime))
Copy link
Copy Markdown
Contributor

@GuyAv46 GuyAv46 May 11, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should this timing include the before_func and after_func? Consider setting the start time in the try (right before calling fn()) and the end time in the finally before the after_func


numFailed = 0
if self.currEnv:
numFailed = self.currEnv.getNumberOfFailedAssertion()
Expand Down Expand Up @@ -868,6 +877,28 @@ def run_single_test(self, test, on_timeout_func):
lastEnv.debugPrint(json.dumps(verboseInfo, indent=2).replace('\\n', '\n'), force=True)
return done

def print_slowest_tests(self):
n = self.args.print_slowest
if n <= 0 or not self.testsTimings:
return
slowest = sorted(self.testsTimings, key=lambda x: x[1], reverse=True)[:n]
heading = 'Slowest %d tests:' % len(slowest)
print(Colors.Bold('\n' + heading))
for i, (name, duration) in enumerate(slowest, 1):
print(' %2d. %7.2fs %s' % (i, duration, name))

summary_path = os.environ.get('GITHUB_STEP_SUMMARY')
if summary_path:
try:
with open(summary_path, 'a') as f:
f.write('\n## %s\n\n' % heading)
f.write('| # | Duration | Test |\n')
f.write('|---|---|---|\n')
for i, (name, duration) in enumerate(slowest, 1):
f.write('| %d | %.2fs | %s |\n' % (i, duration, name))
except OSError as e:
print('Warning: failed to write to $GITHUB_STEP_SUMMARY: %s' % e)

def print_failures(self):
for group, failures in self.testsFailed.items():
print('\t' + Colors.Bold(group))
Expand Down Expand Up @@ -953,6 +984,7 @@ def run_jobs(jobs, results, port):
# dict, which is shipped as-is. The coordinator owns the
# cumulative testsFailed; the worker keeps no state across tests.
self.testsFailed = {}
self.testsTimings = []
output = io.StringIO()
with redirect_stdout(output):
def on_timeout():
Expand All @@ -971,9 +1003,10 @@ def on_timeout():
# join_thread() flushes both puts to the pipe first.
results.put({'test_name': test.name, 'output': output.getvalue(),
'done': 1, 'failures': self.testsFailed,
'timings': self.testsTimings,
'shutdown': False}, block=False)
results.put({'test_name': '<worker shutdown>', 'output': '',
'done': 0, 'failures': {},
'done': 0, 'failures': {}, 'timings': [],
'shutdown': True}, block=False)
results.close()
results.join_thread()
Expand All @@ -982,6 +1015,7 @@ def on_timeout():

results.put({'test_name': test.name, 'output': output.getvalue(),
'done': done_delta, 'failures': self.testsFailed,
'timings': self.testsTimings,
'shutdown': False}, block=False)

# Always ship one shutdown message per worker so the coordinator
Expand All @@ -992,6 +1026,7 @@ def on_timeout():
self.takeEnvDown(fullShutDown=True)
results.put({'test_name': '<worker shutdown>', 'output': '',
'done': 0, 'failures': self.testsFailed,
'timings': [],
'shutdown': True}, block=False)

results = Queue()
Expand Down Expand Up @@ -1030,6 +1065,7 @@ def _get_result():
print('%s' % res['output'], end="")
done += res['done']
self.testsFailed.update(res['failures'])
self.testsTimings.extend(res.get('timings', []))
if not res['shutdown']:
next(bar_iter, None)
next(bar_iter, None) # finalize bar.update(n_jobs)
Expand All @@ -1045,6 +1081,7 @@ def _get_result():
# Summary goes outside the group
print(Colors.Bold('\nTest Took: %d sec' % (endTime - startTime)))
print(Colors.Bold('Total Tests Run: %d, Total Tests Failed: %d, Total Tests Passed: %d' % (done, self.getFailedTestsCount(), done - self.getFailedTestsCount())))
self.print_slowest_tests()
if self.testsFailed:
if self.args.failed_tests_file:
with open(self.args.failed_tests_file, 'w') as file:
Expand Down
Loading