diff --git a/python/publish/github_action.py b/python/publish/github_action.py index d2f4bd78..b98d9e12 100644 --- a/python/publish/github_action.py +++ b/python/publish/github_action.py @@ -1,6 +1,7 @@ import logging import os import sys +import traceback from io import TextIOWrapper from typing import Mapping, Any, Optional @@ -62,11 +63,40 @@ def warning(self, message: str, file: Optional[str] = None, line: Optional[int] params.update(col=column) self._command(self._file, 'warning', message, params) + def _exception(self, te: traceback.TracebackException): + def exception_str(te: traceback.TracebackException) -> str: + # we take the last line, which ends with a newline, that we strip + return list(te.format_exception_only())[-1].split('\n')[0] + + self.error('{te}{caused}{context}'.format( + te=exception_str(te), + caused=f' caused by {exception_str(te.__cause__)}' if te.__cause__ else '', + context=f' while handling {exception_str(te.__context__)}' if te.__context__ else '' + ), exception=None) + + for lines in te.format(chain=False): + for line in lines.split('\n'): + if line: + logger.debug(line) + + cause = te.__cause__ + while cause: + self._exception(cause) + cause = cause.__cause__ + + context = te.__context__ + while context: + self._exception(context) + context = context.__context__ + def error(self, message: str, file: Optional[str] = None, line: Optional[int] = None, column: Optional[int] = None, exception: Optional[BaseException] = None): - logger.error(message, exc_info=exception) + if exception: + self._exception(traceback.TracebackException.from_exception(exception)) + else: + logger.error(message) params = {} if file is not None: @@ -79,6 +109,9 @@ def error(self, @staticmethod def _command(file: TextIOWrapper, command: str, value: str = '', params: Optional[Mapping[str, Any]] = None): + # take first line of value if multiline + value = value.split('\n', 1)[0] + if params is None: params = {} params = ','.join([f'{key}={str(value)}' diff --git a/python/publish_unit_test_results.py b/python/publish_unit_test_results.py index 5f678c09..f12539ea 100644 --- a/python/publish_unit_test_results.py +++ b/python/publish_unit_test_results.py @@ -16,13 +16,14 @@ import publish.github_action from publish import available_annotations, default_annotations, \ pull_request_build_modes, fail_on_modes, fail_on_mode_errors, fail_on_mode_failures, \ - comment_mode_off, comment_mode_always, comment_modes, punctuation_space + comment_mode_always, comment_modes, punctuation_space from publish.github_action import GithubAction from publish.junit import parse_junit_xml_files, process_junit_xml_elems from publish.progress import progress_logger from publish.publisher import Publisher, Settings from publish.retry import GitHubRetry -from publish.unittestresults import get_test_results, get_stats, ParsedUnitTestResults, ParsedUnitTestResultsWithCommit +from publish.unittestresults import get_test_results, get_stats, ParsedUnitTestResults, ParsedUnitTestResultsWithCommit, \ + ParseError logger = logging.getLogger('publish') @@ -123,6 +124,11 @@ def parse_files(settings: Settings, gha: GithubAction) -> ParsedUnitTestResultsW return process_junit_xml_elems(elems, settings.time_factor).with_commit(settings.commit) +def log_parse_errors(errors: List[ParseError], gha: GithubAction): + [gha.error(message=f'Error processing result file: {error.message}', file=error.file, line=error.line, column=error.column, exception=error.exception) + for error in errors] + + def main(settings: Settings, gha: GithubAction) -> None: # we cannot create a check run or pull request comment when running on pull_request event from a fork # when event_file is given we assume proper setup as in README.md#support-fork-repositories-and-dependabot-branches @@ -144,8 +150,7 @@ def main(settings: Settings, gha: GithubAction) -> None: # get the unit test results parsed = parse_files(settings, gha) - [gha.error(message=f'Error processing result file: {error.message}', file=error.file, line=error.line, column=error.column, exception=error.exception) - for error in parsed.errors] + log_parse_errors(parsed.errors, gha) # process the parsed results results = get_test_results(parsed, settings.dedup_classes_by_file_name) diff --git a/python/test/test_action_script.py b/python/test/test_action_script.py index a69bafa3..4227efbf 100644 --- a/python/test/test_action_script.py +++ b/python/test/test_action_script.py @@ -1,3 +1,5 @@ +import io +import re import json import logging import os @@ -6,15 +8,16 @@ import tempfile import unittest from typing import Optional, Union, List, Type + import mock from publish import pull_request_build_mode_merge, fail_on_mode_failures, fail_on_mode_errors, \ - fail_on_mode_nothing, comment_modes, comment_mode_off, comment_mode_always, \ + fail_on_mode_nothing, comment_modes, comment_mode_always, \ pull_request_build_modes, punctuation_space from publish.github_action import GithubAction from publish.unittestresults import ParsedUnitTestResults, ParseError from publish_unit_test_results import get_conclusion, get_commit_sha, get_var, \ - check_var, check_var_condition, deprecate_var, deprecate_val, \ + check_var, check_var_condition, deprecate_var, deprecate_val, log_parse_errors, \ get_settings, get_annotations_config, Settings, get_files, throttle_gh_request_raw, is_float, parse_files, main from test_utils import chdir @@ -803,8 +806,7 @@ def test_parse_files(self): trx_files_glob=str(test_files_path / 'trx' / '**' / '*.trx')) actual = parse_files(settings, gha) - gha.warning.assert_not_called() - gha.error.assert_not_called() + self.assertEqual([], gha.method_calls) self.assertEqual(65, actual.files) self.assertEqual(6, len(actual.errors)) @@ -817,6 +819,28 @@ def test_parse_files(self): self.assertEqual(1858, len(actual.cases)) self.assertEqual('commit', actual.commit) + with io.StringIO() as string: + gha = GithubAction(file=string) + with mock.patch('publish.github_action.logger') as m: + log_parse_errors(actual.errors, gha) + self.assertEqual( + sorted([ + "::error::lxml.etree.XMLSyntaxError: Start tag expected, '<' not found, line 1, column 1", + "::error file=non-xml.xml::Error processing result file: Start tag expected, '<' not found, line 1, column 1 (non-xml.xml, line 1)", + "::error::Exception: File is empty.", + "::error file=empty.xml::Error processing result file: File is empty.", + "::error::lxml.etree.XMLSyntaxError: Premature end of data in tag skipped line 9, line 11, column 22", + "::error file=corrupt-xml.xml::Error processing result file: Premature end of data in tag skipped line 9, line 11, column 22 (corrupt-xml.xml, line 11)", + "::error::junitparser.junitparser.JUnitXmlError: Invalid format.", + "::error file=non-junit.xml::Error processing result file: Invalid format.", + "::error::lxml.etree.XMLSyntaxError: Char 0x0 out of allowed range, line 33, column 16", + "::error file=NUnit-issue17521.xml::Error processing result file: Char 0x0 out of allowed range, line 33, column 16 (NUnit-issue17521.xml, line 33)", + "::error::lxml.etree.XMLSyntaxError: attributes construct error, line 5, column 109", + "::error file=NUnit-issue47367.xml::Error processing result file: attributes construct error, line 5, column 109 (NUnit-issue47367.xml, line 5)" + ]), sorted([re.sub(r'file=.*[/\\]', 'file=', re.sub(r'[(]file:.*/', '(', line)) for line in string.getvalue().split(os.linesep) if line]) + ) + # self.assertEqual([], m.method_calls) + def test_parse_files_no_matches(self): gha = mock.MagicMock() with tempfile.TemporaryDirectory() as path: diff --git a/python/test/test_github_action.py b/python/test/test_github_action.py index 1f511e3f..e41f88f2 100644 --- a/python/test/test_github_action.py +++ b/python/test/test_github_action.py @@ -1,5 +1,6 @@ import io import os +import re import tempfile import unittest from contextlib import contextmanager @@ -93,6 +94,93 @@ def test_error(self): with gh_action_command_test(self, '::error file=the file,line=1,col=2::the message') as gha: gha.error('the message', file='the file', line=1, column=2) + # log exception + with gh_action_command_test(self, f'::error::RuntimeError: failure{os.linesep}' + f'::error file=the file,line=1,col=2::the message') as gha: + try: + raise RuntimeError('failure') + except RuntimeError as e: + error = e + + with mock.patch('publish.github_action.logger') as m: + gha.error('the message', file='the file', line=1, column=2, exception=error) + + self.assertEqual( + [(call[0], re.sub(r'File ".*[/\\]', 'File "', re.sub(r'line \d+', 'line X', call.args[0]))) + for call in m.method_calls], + [ + ('error', 'RuntimeError: failure'), + ('debug', 'Traceback (most recent call last):'), + ('debug', ' File "test_github_action.py", line X, in test_error'), + ('debug', " raise RuntimeError('failure')"), + ('debug', 'RuntimeError: failure') + ] + ) + + # log exceptions related via cause + with gh_action_command_test(self, f'::error::RuntimeError: failed except caused by ValueError: invalid value{os.linesep}' + f'::error::ValueError: invalid value{os.linesep}' + f'::error file=the file,line=1,col=2::the message') as gha: + error = self.get_error_with_cause() + with mock.patch('publish.github_action.logger') as m: + gha.error('the message', file='the file', line=1, column=2, exception=error) + + self.assertEqual( + [(call[0], re.sub(r'File ".*[/\\]', 'File "', re.sub(r'line \d+', 'line X', call.args[0]))) + for call in m.method_calls], + [ + ('error', 'RuntimeError: failed except caused by ValueError: invalid value'), + ('debug', 'Traceback (most recent call last):'), + ('debug', ' File "test_github_action.py", line X, in get_error_with_cause'), + ('debug', " raise RuntimeError('failed except') from ValueError('invalid value')"), + ('debug', 'RuntimeError: failed except'), + ('error', 'ValueError: invalid value'), + ('debug', 'ValueError: invalid value') + ] + ) + + # log exceptions related via context + with gh_action_command_test(self, f'::error::RuntimeError: failed except while handling ValueError: invalid value{os.linesep}' + f'::error::ValueError: invalid value{os.linesep}' + f'::error file=the file,line=1,col=2::the message') as gha: + error = self.get_error_with_context() + with mock.patch('publish.github_action.logger') as m: + gha.error('the message', file='the file', line=1, column=2, exception=error) + + self.assertEqual( + [(call[0], re.sub(r'File ".*[/\\]', 'File "', re.sub(r'line \d+', 'line X', call.args[0]))) + for call in m.method_calls], + [ + ('error', 'RuntimeError: failed except while handling ValueError: invalid value'), + ('debug', 'Traceback (most recent call last):'), + ('debug', ' File "test_github_action.py", line X, in get_error_with_context'), + ('debug', " raise RuntimeError('failed except')"), + ('debug', 'RuntimeError: failed except'), + ('error', 'ValueError: invalid value'), + ('debug', 'Traceback (most recent call last):'), + ('debug', ' File "test_github_action.py", line X, in get_error_with_context'), + ('debug', " raise ValueError('invalid value')"), + ('debug', 'ValueError: invalid value') + ] + ) + + @staticmethod + def get_error_with_cause() -> RuntimeError: + try: + raise RuntimeError('failed except') from ValueError('invalid value') + except RuntimeError as re: + return re + + @staticmethod + def get_error_with_context() -> RuntimeError: + try: + raise ValueError('invalid value') + except ValueError: + try: + raise RuntimeError('failed except') + except RuntimeError as re: + return re + def test_add_env(self): with gh_action_env_file_test(self, GithubAction.ENV_FILE_VAR_NAME, 'var=val\n') as gha: gha.add_to_env('var', 'val') @@ -115,6 +203,11 @@ def test_add_job_summary(self): gha.add_to_job_summary('# title\ncontent\n') gha.add_to_job_summary('## subtitle\nmore content\n') + def test__command_with_multi_line_value(self): + with io.StringIO() as string: + GithubAction._command(string, 'command', 'multi\nline\nvalue') + self.assertEqual('::command::multi' + os.linesep, string.getvalue()) + def test__append_to_file_errors(self): # env variable does not exist with mock.patch.dict(os.environ, {}, clear=True):