From: Yuanfang Chen Date: Sun, 24 Apr 2022 02:30:00 +0000 (-0700) Subject: [lit] Keep stdout/stderr when using GoogleTest format X-Git-Tag: upstream/15.0.7~9460 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=d3efa577f549760a42ba68bda95d1e576c2adda1;p=platform%2Fupstream%2Fllvm.git [lit] Keep stdout/stderr when using GoogleTest format When a unit test crashes or timeout, print the shard's stdout and stderr. When a unit test fails, attaches the test's output to the LIT output to help debugging. While at it, concatenating shard's environment variables using space instead of newline to make the reproducer script user friendly. Based on D123797. (Thanks to @lenary) --- diff --git a/llvm/utils/lit/lit/formats/googletest.py b/llvm/utils/lit/lit/formats/googletest.py index 1e6da6d..603e04d 100644 --- a/llvm/utils/lit/lit/formats/googletest.py +++ b/llvm/utils/lit/lit/formats/googletest.py @@ -110,11 +110,10 @@ class GoogleTest(TestFormat): from lit.cl_arguments import TestOrder use_shuffle = TestOrder(litConfig.order) == TestOrder.RANDOM shard_env = { - 'GTEST_COLOR': 'no', + 'GTEST_OUTPUT': 'json:' + test.gtest_json_file, 'GTEST_SHUFFLE': '1' if use_shuffle else '0', 'GTEST_TOTAL_SHARDS': total_shards, - 'GTEST_SHARD_INDEX': shard_idx, - 'GTEST_OUTPUT': 'json:' + test.gtest_json_file + 'GTEST_SHARD_INDEX': shard_idx } test.config.environment.update(shard_env) @@ -127,27 +126,43 @@ class GoogleTest(TestFormat): return lit.Test.PASS, '' def get_shard_header(shard_env): - shard_envs = '\n'.join([k + '=' + v for k, v in shard_env.items()]) - return f"Script(shard):\n--\n%s\n%s\n--\n" % (shard_envs, ' '.join(cmd)) + shard_envs = ' '.join([k + '=' + v for k, v in shard_env.items()]) + return f"Script(shard):\n--\n%s %s\n--\n" % (shard_envs, ' '.join(cmd)) shard_header = get_shard_header(shard_env) try: - _, _, exitCode = lit.util.executeCommand( + out, _, exitCode = lit.util.executeCommand( cmd, env=test.config.environment, - timeout=litConfig.maxIndividualTestTime) - except lit.util.ExecuteCommandTimeoutException: - return (lit.Test.TIMEOUT, f'{shard_header}Reached timeout of ' - f'{litConfig.maxIndividualTestTime} seconds') + timeout=litConfig.maxIndividualTestTime, redirect_stderr=True) + except lit.util.ExecuteCommandTimeoutException as e: + stream_msg = f"\n{e.out}\n--\nexit: {e.exitCode}\n--\n" + return (lit.Test.TIMEOUT, f'{shard_header}{stream_msg}Reached ' + f'timeout of {litConfig.maxIndividualTestTime} seconds') if not os.path.exists(test.gtest_json_file): errmsg = f"shard JSON output does not exist: %s" % ( test.gtest_json_file) - return lit.Test.FAIL, shard_header + errmsg + stream_msg = f"\n{out}\n--\nexit: {exitCode}\n--\n" + return lit.Test.FAIL, shard_header + stream_msg + errmsg if exitCode == 0: return lit.Test.PASS, '' + def get_test_stdout(test_name): + res = [] + header = f'[ RUN ] ' + test_name + footer = f'[ FAILED ] ' + test_name + in_range = False + for l in out.splitlines(): + if l.startswith(header): + in_range = True + elif l.startswith(footer): + return f'' if len(res) == 0 else '\n'.join(res) + elif in_range: + res.append(l) + assert False, f'gtest did not report the result for ' + test_name + with open(test.gtest_json_file, encoding='utf-8') as f: jf = json.load(f) @@ -165,6 +180,9 @@ class GoogleTest(TestFormat): ' '.join(cmd), testname) if 'failures' in testinfo: output += header + test_out = get_test_stdout(testname) + if test_out: + output += test_out + '\n\n' for fail in testinfo['failures']: output += fail['failure'] + '\n' output += '\n' diff --git a/llvm/utils/lit/lit/util.py b/llvm/utils/lit/lit/util.py index 41bf89d..11112d8 100644 --- a/llvm/utils/lit/lit/util.py +++ b/llvm/utils/lit/lit/util.py @@ -314,7 +314,8 @@ class ExecuteCommandTimeoutException(Exception): kUseCloseFDs = not (platform.system() == 'Windows') -def executeCommand(command, cwd=None, env=None, input=None, timeout=0): +def executeCommand(command, cwd=None, env=None, input=None, timeout=0, + redirect_stderr=False): """Execute command ``command`` (list of arguments or string) with. * working directory ``cwd`` (str), use None to use the current @@ -323,6 +324,7 @@ def executeCommand(command, cwd=None, env=None, input=None, timeout=0): * Input to the command ``input`` (str), use string to pass no input. * Max execution time ``timeout`` (int) seconds. Use 0 for no timeout. + * ``redirect_stderr`` (bool), use True if redirect stderr to stdout Returns a tuple (out, err, exitCode) where * ``out`` (str) is the standard output of running the command @@ -335,10 +337,11 @@ def executeCommand(command, cwd=None, env=None, input=None, timeout=0): """ if input is not None: input = to_bytes(input) + err_out = subprocess.STDOUT if redirect_stderr else subprocess.PIPE p = subprocess.Popen(command, cwd=cwd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, - stderr=subprocess.PIPE, + stderr=err_out, env=env, close_fds=kUseCloseFDs) timerObject = None # FIXME: Because of the way nested function scopes work in Python 2.x we @@ -365,7 +368,7 @@ def executeCommand(command, cwd=None, env=None, input=None, timeout=0): # Ensure the resulting output is always of string type. out = to_string(out) - err = to_string(err) + err = '' if redirect_stderr else to_string(err) if hitTimeOut[0]: raise ExecuteCommandTimeoutException( diff --git a/llvm/utils/lit/tests/Inputs/googletest-crash/DummySubDir/OneTest.py b/llvm/utils/lit/tests/Inputs/googletest-crash/DummySubDir/OneTest.py index bebedb6..1ff9f02 100644 --- a/llvm/utils/lit/tests/Inputs/googletest-crash/DummySubDir/OneTest.py +++ b/llvm/utils/lit/tests/Inputs/googletest-crash/DummySubDir/OneTest.py @@ -35,6 +35,12 @@ dummy_output = """\ }""" if os.environ['GTEST_SHARD_INDEX'] == '0': + print("""\ +[----------] 4 test from FirstTest +[ RUN ] FirstTest.subTestA +[ OK ] FirstTest.subTestA (18 ms) +[ RUN ] FirstTest.subTestB""", flush=True) + print('I am about to crash', file=sys.stderr, flush=True) exit_code = 1 else: json_filename = os.environ['GTEST_OUTPUT'].split(':', 1)[1] diff --git a/llvm/utils/lit/tests/Inputs/googletest-format/DummySubDir/OneTest.py b/llvm/utils/lit/tests/Inputs/googletest-format/DummySubDir/OneTest.py index 5ab7339..32859c7e 100644 --- a/llvm/utils/lit/tests/Inputs/googletest-format/DummySubDir/OneTest.py +++ b/llvm/utils/lit/tests/Inputs/googletest-format/DummySubDir/OneTest.py @@ -95,6 +95,10 @@ dummy_output = """\ json_filename = os.environ['GTEST_OUTPUT'].split(':', 1)[1] with open(json_filename, 'w') as f: if os.environ['GTEST_SHARD_INDEX'] == '0': + print('[ RUN ] FirstTest.subTestB', flush=True) + print('I am subTest B output', file=sys.stderr, flush=True) + print('[ FAILED ] FirstTest.subTestB (8 ms)', flush=True) + f.write(output) exit_code = 1 else: diff --git a/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest.py b/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest.py index 3747232..d64d1dc 100644 --- a/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest.py +++ b/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest.py @@ -54,6 +54,8 @@ if os.environ['GTEST_SHARD_INDEX'] == '0': f.write(output) exit_code = 0 elif test_name == 'InfiniteLoopSubTest': + print('[ RUN ] T.InfiniteLoopSubTest', flush=True) + print('some in progess output', file=sys.stderr, flush=True) while True: pass else: diff --git a/llvm/utils/lit/tests/googletest-crash.py b/llvm/utils/lit/tests/googletest-crash.py index 74682b6..d647d44 100644 --- a/llvm/utils/lit/tests/googletest-crash.py +++ b/llvm/utils/lit/tests/googletest-crash.py @@ -7,12 +7,17 @@ # CHECK: *** TEST 'googletest-crash :: [[PATH]][[FILE]]/0{{.*}} FAILED *** # CHECK-NEXT: Script(shard): # CHECK-NEXT: -- -# CHECK-NEXT: GTEST_COLOR=no -# CHECK-NEXT: GTEST_SHUFFLE=0 -# CHECK-NEXT: GTEST_TOTAL_SHARDS=6 -# CHECK-NEXT: GTEST_SHARD_INDEX=0 -# CHECK-NEXT: GTEST_OUTPUT=json:[[JSON:.*\.json]] -# CHECK-NEXT: [[FILE]] +# CHECK-NEXT: GTEST_OUTPUT=json:[[JSON:[^[:space:]]*\.json]] GTEST_SHUFFLE=0 GTEST_TOTAL_SHARDS=6 GTEST_SHARD_INDEX=0 {{.*}}[[FILE]] +# CHECK-NEXT: -- +# CHECK-EMPTY: +# CHECK-NEXT: [----------] 4 test from FirstTest +# CHECK-NEXT: [ RUN ] FirstTest.subTestA +# CHECK-NEXT: [ OK ] FirstTest.subTestA (18 ms) +# CHECK-NEXT: [ RUN ] FirstTest.subTestB +# CHECK-NEXT: I am about to crash +# CHECK-EMPTY: +# CHECK-NEXT: -- +# CHECK-NEXT: exit: # CHECK-NEXT: -- # CHECK-NEXT: shard JSON output does not exist: [[JSON]] # CHECK-NEXT: *** diff --git a/llvm/utils/lit/tests/googletest-format.py b/llvm/utils/lit/tests/googletest-format.py index 842a333..2dedaa5 100644 --- a/llvm/utils/lit/tests/googletest-format.py +++ b/llvm/utils/lit/tests/googletest-format.py @@ -13,19 +13,15 @@ # CHECK: *** TEST 'googletest-format :: [[PATH]][[FILE]]/0{{.*}} FAILED *** # CHECK-NEXT: Script(shard): # CHECK-NEXT: -- -# CHECK-NEXT: GTEST_COLOR=no -# CHECK-NEXT: GTEST_SHUFFLE=1 -# CHECK-NEXT: GTEST_TOTAL_SHARDS=6 -# CHECK-NEXT: GTEST_SHARD_INDEX=0 -# CHECK-NEXT: GTEST_OUTPUT=json:{{.*\.json}} -# CHECK-NEXT: GTEST_RANDOM_SEED=123 -# CHECK-NEXT: [[FILE]] +# CHECK-NEXT: GTEST_OUTPUT=json:{{[^[:space:]]*}} GTEST_SHUFFLE=1 GTEST_TOTAL_SHARDS=6 GTEST_SHARD_INDEX=0 GTEST_RANDOM_SEED=123 {{.*}}[[FILE]] # CHECK-NEXT: -- # CHECK-EMPTY: # CHECK-NEXT: Script: # CHECK-NEXT: -- # CHECK-NEXT: [[FILE]] --gtest_filter=FirstTest.subTestB # CHECK-NEXT: -- +# CHECK-NEXT: I am subTest B output +# CHECK-EMPTY: # CHECK-NEXT: I am subTest B, I FAIL # CHECK-NEXT: And I have two lines of output # CHECK-EMPTY: diff --git a/llvm/utils/lit/tests/googletest-timeout.py b/llvm/utils/lit/tests/googletest-timeout.py index 2e33f70..a32759f 100644 --- a/llvm/utils/lit/tests/googletest-timeout.py +++ b/llvm/utils/lit/tests/googletest-timeout.py @@ -19,16 +19,18 @@ # RUN: FileCheck --check-prefix=CHECK-INF < %t.cfgset.out %s # CHECK-INF: -- Testing: -# CHECK-INF: TIMEOUT: googletest-timeout :: [[PATH:[Dd]ummy[Ss]ub[Dd]ir/]][[FILE:OneTest\.py]]/0/2 +# CHECK-INF: TIMEOUT: googletest-timeout :: [[PATH:[Dd]ummy[Ss]ub[Dd]ir/]][[FILE:OneTest.py]]/0/2 # CHECK-INF-NEXT: ******************** TEST 'googletest-timeout :: [[PATH]][[FILE]]/0/2' FAILED ******************** # CHECK-INF-NEXT: Script(shard): # CHECK-INF-NEXT: -- -# CHECK-INF-NEXT: GTEST_COLOR=no -# CHECK-INF-NEXT: GTEST_SHUFFLE=0 -# CHECK-INF-NEXT: GTEST_TOTAL_SHARDS=2 -# CHECK-INF-NEXT: GTEST_SHARD_INDEX=0 -# CHECK-INF-NEXT: GTEST_OUTPUT=json:{{.*\.json}} -# CHECK-INF-NEXT: [[FILE]] +# CHECK-INF-NEXT: GTEST_OUTPUT=json:{{[^[:space:]]*}} GTEST_SHUFFLE=0 GTEST_TOTAL_SHARDS=2 GTEST_SHARD_INDEX=0 {{.*}}[[FILE]] +# CHECK-INF-NEXT: -- +# CHECK-INF-EMPTY: +# CHECK-INF-NEXT: [ RUN ] T.InfiniteLoopSubTest +# CHECK-INF-NEXT: some in progess output +# CHECK-INF-EMPTY: +# CHECK-INF-NEXT: -- +# CHECK-INF-NEXT: exit: # CHECK-INF-NEXT: -- # CHECK-INF-NEXT: Reached timeout of 1 seconds # CHECK-INF: Timed Out: 1