From 5ef2b12dca45b5ca396cf55de747c5ad4b27fe65 Mon Sep 17 00:00:00 2001 From: evanchia-ly-sdets <80914607+evanchia-ly-sdets@users.noreply.github.com> Date: Wed, 9 Feb 2022 18:13:01 -0800 Subject: [PATCH] Collects failed assets on LyTestTools test failures (#7368) * Collects failed assets on LyTestTools test failures Signed-off-by: evanchia * Changed query to all lines because of current asset logging bug Signed-off-by: evanchia * fixes per pr feedback Signed-off-by: evanchia * testing removing change for AR failure Signed-off-by: evanchia * Moved asset log artifact collection to after the results have been collected Signed-off-by: evanchia * Adding debug line to help debug AR failure Signed-off-by: evanchia * Made asset log collection non failing Signed-off-by: evanchia * moved asset log collection after test result collection Signed-off-by: evanchia * changed asset saving to non failing Signed-off-by: evanchia * improved logging and comments Signed-off-by: evanchia --- .../managers/abstract_resource_locator.py | 9 ++- .../ly_test_tools/o3de/editor_test.py | 24 +++++++- .../ly_test_tools/o3de/editor_test_utils.py | 39 +++++++++++++ .../tests/unit/test_editor_test_utils.py | 56 +++++++++++++++++++ .../tests/unit/test_o3de_editor_test.py | 7 +++ 5 files changed, 132 insertions(+), 3 deletions(-) diff --git a/Tools/LyTestTools/ly_test_tools/_internal/managers/abstract_resource_locator.py b/Tools/LyTestTools/ly_test_tools/_internal/managers/abstract_resource_locator.py index 4514e5d812..6e0923b916 100755 --- a/Tools/LyTestTools/ly_test_tools/_internal/managers/abstract_resource_locator.py +++ b/Tools/LyTestTools/ly_test_tools/_internal/managers/abstract_resource_locator.py @@ -175,13 +175,20 @@ class AbstractResourceLocator(object): return os.path.join(self.build_directory(), 'AssetProcessor') def asset_processor_batch(self): - """" + """ Return path for the AssetProcessorBatch compatible with this build platform and configuration ex. engine_root/dev/mac/bin/profile/AssetProcessorBatch :return: path to AssetProcessorBatch """ return os.path.join(self.build_directory(), 'AssetProcessorBatch') + def ap_job_logs(self): + """ + Return path to the Asset Processor JobLogs directory. + :return: path to /user/log/JobLogs + """ + return os.path.join(self.project_log(), 'JobLogs') + def editor(self): """ Return path to the editor executable compatible with the current build. diff --git a/Tools/LyTestTools/ly_test_tools/o3de/editor_test.py b/Tools/LyTestTools/ly_test_tools/o3de/editor_test.py index f363689066..3c4e2b49a4 100644 --- a/Tools/LyTestTools/ly_test_tools/o3de/editor_test.py +++ b/Tools/LyTestTools/ly_test_tools/o3de/editor_test.py @@ -851,11 +851,11 @@ class EditorTestSuite(): workspace.artifact_manager.save_artifact(os.path.join(editor_utils.retrieve_log_path(run_id, workspace), log_name), f'({run_id}){log_name}') if return_code == 0: - # No need to scrap the output, as all the tests have passed + # No need to scrape the output, as all the tests have passed for test_spec in test_spec_list: results[test_spec.__name__] = Result.Pass.create(test_spec, output, editor_log_content) else: - # Scrap the output to attempt to find out which tests failed. + # Scrape the output to attempt to find out which tests failed. # This function should always populate the result list, if it didn't find it, it will have "Unknown" type of result results = self._get_results_using_output(test_spec_list, output, editor_log_content) assert len(results) == len(test_spec_list), "bug in _get_results_using_output(), the number of results don't match the tests ran" @@ -940,6 +940,9 @@ class EditorTestSuite(): editor_test_data.results.update(results) test_name, test_result = next(iter(results.items())) self._report_result(test_name, test_result) + # If test did not pass, save assets with errors and warnings + if not isinstance(test_result, Result.Pass): + editor_utils.save_failed_asset_joblogs(workspace) def _run_batched_tests(self, request: Request, workspace: AbstractWorkspace, editor: Editor, editor_test_data: TestData, test_spec_list: list[EditorSharedTest], extra_cmdline_args: list[str] = []) -> None: @@ -961,6 +964,11 @@ class EditorTestSuite(): extra_cmdline_args) assert results is not None editor_test_data.results.update(results) + # If at least one test did not pass, save assets with errors and warnings + for result in results: + if not isinstance(result, Result.Pass): + editor_utils.save_failed_asset_joblogs(workspace) + return def _run_parallel_tests(self, request: Request, workspace: AbstractWorkspace, editor: Editor, editor_test_data: TestData, test_spec_list: list[EditorSharedTest], extra_cmdline_args: list[str] = []) -> None: @@ -1007,8 +1015,14 @@ class EditorTestSuite(): for t in threads: t.join() + save_asset_logs = False for result in results_per_thread: editor_test_data.results.update(result) + if not isinstance(result, Result.Pass): + save_asset_logs = True + # If at least one test did not pass, save assets with errors and warnings + if save_asset_logs: + editor_utils.save_failed_asset_joblogs(workspace) def _run_parallel_batched_tests(self, request: Request, workspace: AbstractWorkspace, editor: Editor, editor_test_data: TestData, test_spec_list: list[EditorSharedTest], extra_cmdline_args: list[str] = []) -> None: @@ -1056,8 +1070,14 @@ class EditorTestSuite(): for t in threads: t.join() + save_asset_logs = False for result in results_per_thread: editor_test_data.results.update(result) + if not isinstance(result, Result.Pass): + save_asset_logs = True + # If at least one test did not pass, save assets with errors and warnings + if save_asset_logs: + editor_utils.save_failed_asset_joblogs(workspace) def _get_number_parallel_editors(self, request: Request) -> int: """ diff --git a/Tools/LyTestTools/ly_test_tools/o3de/editor_test_utils.py b/Tools/LyTestTools/ly_test_tools/o3de/editor_test_utils.py index 7b36a82c07..4e678151bd 100644 --- a/Tools/LyTestTools/ly_test_tools/o3de/editor_test_utils.py +++ b/Tools/LyTestTools/ly_test_tools/o3de/editor_test_utils.py @@ -10,6 +10,7 @@ from __future__ import annotations import os import time import logging +import re import ly_test_tools.environment.process_utils as process_utils import ly_test_tools.environment.waiter as waiter @@ -151,3 +152,41 @@ def retrieve_last_run_test_index_from_output(test_spec_list: list[EditorTestBase else: index += 1 return index + +def save_failed_asset_joblogs(workspace: AbstractWorkspace) -> None: + """ + Checks all asset logs in the JobLogs directory to see if the asset has any warnings or errors. If so, the asset is + saved via ArtifactManager. + + :param workspace: The AbstractWorkspace to access the JobLogs path + :return: None + """ + for walk_tuple in os.walk(workspace.paths.ap_job_logs()): + for log_file in walk_tuple[2]: + full_log_path = os.path.join(walk_tuple[0], log_file) + # Only save asset logs that contain errors or warnings + if _check_log_errors_warnings(full_log_path): + try: + workspace.artifact_manager.save_artifact(full_log_path) + except Exception as e: # Purposefully broad + logger.warning(f"Error when saving log at path:{full_log_path}\n{e}") + +def _check_log_errors_warnings(log_path: str) -> bool: + """ + Checks to see if the asset log contains any errors or warnings. Also returns True is no regex is found because + something probably went wrong. + Example log lines: ~~1643759303647~~1~~00000000000009E0~~AssetBuilder~~S: 0 errors, 1 warnings + + :param log_path: The full path to the asset log file to read + :return: True if the regex finds an error or warning, else False + """ + log_regex = "(\\d+) errors, (\\d+) warnings" + with open(log_path, 'r') as opened_asset_log: + for log_line in opened_asset_log: + regex_match = re.search(log_regex, log_line) + if regex_match is not None: + break + # If we match any non zero numbers in: n error, n warnings + if regex_match is None or (int)(regex_match.group(1)) != 0 or (int)(regex_match.group(2)) != 0: + return True + return False diff --git a/Tools/LyTestTools/tests/unit/test_editor_test_utils.py b/Tools/LyTestTools/tests/unit/test_editor_test_utils.py index f81d2fd8e6..cca9a161c8 100644 --- a/Tools/LyTestTools/tests/unit/test_editor_test_utils.py +++ b/Tools/LyTestTools/tests/unit/test_editor_test_utils.py @@ -170,3 +170,59 @@ class TestEditorTestUtils(unittest.TestCase): mock_test_list.append(mock_test) assert 0 == editor_test_utils.retrieve_last_run_test_index_from_output(mock_test_list, mock_editor_output) + + @mock.patch('ly_test_tools.o3de.editor_test_utils._check_log_errors_warnings') + @mock.patch('os.walk') + def test_SaveFailedAssetJoblogs_ManyValidLogs_SavesCorrectly(self, mock_walk, mock_check_log): + mock_workspace = mock.MagicMock() + mock_walk.return_value = [['MockDirectory', None, ['mock_log.log']], + ['MockDirectory2', None, ['mock_log2.log']]] + mock_check_log.return_value = True + + editor_test_utils.save_failed_asset_joblogs(mock_workspace) + + assert mock_workspace.artifact_manager.save_artifact.call_count == 2 + + @mock.patch('ly_test_tools.o3de.editor_test_utils._check_log_errors_warnings') + @mock.patch('os.walk') + def test_SaveFailedAssetJoblogs_ManyInvalidLogs_NoSaves(self, mock_walk, mock_check_log): + mock_workspace = mock.MagicMock() + mock_walk.return_value = [['MockDirectory', None, ['mock_log.log']], + ['MockDirectory2', None, ['mock_log2.log']]] + mock_check_log.return_value = False + + editor_test_utils.save_failed_asset_joblogs(mock_workspace) + + assert mock_workspace.artifact_manager.save_artifact.call_count == 0 + + def test_CheckLogErrorWarnings_ValidLine_ReturnsTrue(self): + mock_log = '~~1643759303647~~1~~00000000000009E0~~AssetBuilder~~S: 0 errors, 1 warnings' + mock_log_path = mock.MagicMock() + + with mock.patch('builtins.open', mock.mock_open(read_data=mock_log)) as mock_file: + expected = editor_test_utils._check_log_errors_warnings(mock_log_path) + assert expected + + def test_CheckLogErrorWarnings_MultipleValidLine_ReturnsTrue(self): + mock_log = 'foo\nfoo\n~~1643759303647~~1~~00000000000009E0~~AssetBuilder~~S: 1 errors, 1 warnings' + mock_log_path = mock.MagicMock() + + with mock.patch('builtins.open', mock.mock_open(read_data=mock_log)) as mock_file: + expected = editor_test_utils._check_log_errors_warnings(mock_log_path) + assert expected + + def test_CheckLogErrorWarnings_InvalidLine_ReturnsFalse(self): + mock_log = 'foo\n~~1643759303647~~1~~00000000000009E0~~AssetBuilder~~S: 0 errors, 0 warnings' + mock_log_path = mock.MagicMock() + + with mock.patch('builtins.open', mock.mock_open(read_data=mock_log)) as mock_file: + expected = editor_test_utils._check_log_errors_warnings(mock_log_path) + assert not expected + + def test_CheckLogErrorWarnings_InvalidRegex_ReturnsTrue(self): + mock_log = 'Invalid last line' + mock_log_path = mock.MagicMock() + + with mock.patch('builtins.open', mock.mock_open(read_data=mock_log)) as mock_file: + expected = editor_test_utils._check_log_errors_warnings(mock_log_path) + assert expected diff --git a/Tools/LyTestTools/tests/unit/test_o3de_editor_test.py b/Tools/LyTestTools/tests/unit/test_o3de_editor_test.py index 973366aa94..f63ec315eb 100644 --- a/Tools/LyTestTools/tests/unit/test_o3de_editor_test.py +++ b/Tools/LyTestTools/tests/unit/test_o3de_editor_test.py @@ -871,6 +871,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._report_result') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._exec_editor_test') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunSingleTest_ValidTest_ReportsResults(self, mock_setup_test, mock_exec_editor_test, mock_report_result): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite() mock_test_data = mock.MagicMock() @@ -903,6 +904,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('threading.Thread') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._get_number_parallel_editors') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunParallelTests_TwoTestsAndEditors_TwoThreads(self, mock_setup_test, mock_get_num_editors, mock_thread): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite() mock_get_num_editors.return_value = 2 @@ -919,6 +921,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('threading.Thread') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._get_number_parallel_editors') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunParallelTests_TenTestsAndTwoEditors_TenThreads(self, mock_setup_test, mock_get_num_editors, mock_thread): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite() mock_get_num_editors.return_value = 2 @@ -937,6 +940,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('threading.Thread') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._get_number_parallel_editors') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunParallelTests_TenTestsAndThreeEditors_TenThreads(self, mock_setup_test, mock_get_num_editors, mock_thread): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite() @@ -956,6 +960,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('threading.Thread') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._get_number_parallel_editors') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunParallelBatchedTests_TwoTestsAndEditors_TwoThreads(self, mock_setup_test, mock_get_num_editors, mock_thread): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite() @@ -973,6 +978,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('threading.Thread') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._get_number_parallel_editors') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunParallelBatchedTests_TenTestsAndTwoEditors_2Threads(self, mock_setup_test, mock_get_num_editors, mock_thread): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite() @@ -992,6 +998,7 @@ class TestRunningTests(unittest.TestCase): @mock.patch('threading.Thread') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._get_number_parallel_editors') @mock.patch('ly_test_tools.o3de.editor_test.EditorTestSuite._setup_editor_test') + @mock.patch('ly_test_tools.o3de.editor_test_utils.save_failed_asset_joblogs', mock.MagicMock()) def test_RunParallelBatchedTests_TenTestsAndThreeEditors_ThreeThreads(self, mock_setup_test, mock_get_num_editors, mock_thread): mock_test_suite = ly_test_tools.o3de.editor_test.EditorTestSuite()