diff --git a/webhook_server/libs/check_run_handler.py b/webhook_server/libs/check_run_handler.py index 7212f555..011a638b 100644 --- a/webhook_server/libs/check_run_handler.py +++ b/webhook_server/libs/check_run_handler.py @@ -63,6 +63,7 @@ async def set_verify_check_success(self) -> None: async def set_run_tox_check_queued(self) -> None: if not self.github_webhook.tox: + self.logger.debug(f"{self.log_prefix} tox is not configured, skipping.") return return await self.set_check_run_status(check_run=TOX_STR, status=QUEUED_STR) @@ -78,6 +79,7 @@ async def set_run_tox_check_success(self, output: dict[str, Any]) -> None: async def set_run_pre_commit_check_queued(self) -> None: if not self.github_webhook.pre_commit: + self.logger.debug(f"{self.log_prefix} pre-commit is not configured, skipping.") return return await self.set_check_run_status(check_run=PRE_COMMIT_STR, status=QUEUED_STR) @@ -105,6 +107,7 @@ async def set_merge_check_failure(self, output: dict[str, Any]) -> None: async def set_container_build_queued(self) -> None: if not self.github_webhook.build_and_push_container: + self.logger.debug(f"{self.log_prefix} build_and_push_container is not configured, skipping.") return return await self.set_check_run_status(check_run=BUILD_CONTAINER_STR, status=QUEUED_STR) @@ -120,6 +123,7 @@ async def set_container_build_failure(self, output: dict[str, Any]) -> None: async def set_python_module_install_queued(self) -> None: if not self.github_webhook.pypi: + self.logger.debug(f"{self.log_prefix} pypi is not configured, skipping.") return return await self.set_check_run_status(check_run=PYTHON_MODULE_INSTALL_STR, status=QUEUED_STR) @@ -183,6 +187,7 @@ async def set_check_run_status( msg: str = f"{self.log_prefix} check run {check_run} status: {status or conclusion}" try: + self.logger.debug(f"{self.log_prefix} Set check run status with {kwargs}") await asyncio.to_thread(self.github_webhook.repository_by_github_app.create_check_run, **kwargs) if conclusion in (SUCCESS_STR, IN_PROGRESS_STR): self.logger.success(msg) # type: ignore @@ -221,14 +226,15 @@ async def is_check_run_in_progress(self, check_run: str) -> bool: if self.github_webhook.last_commit: for run in await asyncio.to_thread(self.github_webhook.last_commit.get_check_runs): if run.name == check_run and run.status == IN_PROGRESS_STR: + self.logger.debug(f"{self.log_prefix} Check run {check_run} is in progress.") return True return False async def required_check_failed_or_no_status( self, pull_request: PullRequest, last_commit_check_runs: list[CheckRun], check_runs_in_progress: list[str] ) -> str: - failed_check_runs = [] - no_status_check_runs = [] + failed_check_runs: list[str] = [] + no_status_check_runs: list[str] = [] for check_run in last_commit_check_runs: self.logger.debug(f"{self.log_prefix} Check if {check_run.name} failed or do not have status.") @@ -237,6 +243,7 @@ async def required_check_failed_or_no_status( or check_run.conclusion == SUCCESS_STR or check_run.name not in await self.all_required_status_checks(pull_request=pull_request) ): + self.logger.debug(f"{self.log_prefix} {check_run.name} is success or not required, skipping.") continue if check_run.conclusion is None: @@ -254,9 +261,11 @@ async def required_check_failed_or_no_status( if failed_check_run not in check_runs_in_progress ] msg += f"Some check runs failed: {', '.join(exclude_in_progress)}\n" + self.logger.debug(f"failed_check_runs: {failed_check_runs}") if no_status_check_runs: msg += f"Some check runs not started: {', '.join(no_status_check_runs)}\n" + self.logger.debug(f"no_status_check_runs: {no_status_check_runs}") return msg @@ -292,7 +301,9 @@ async def get_branch_required_status_checks(self, pull_request: PullRequest) -> pull_request_branch = await asyncio.to_thread(self.repository.get_branch, pull_request.base.ref) branch_protection = await asyncio.to_thread(pull_request_branch.get_protection) - return branch_protection.required_status_checks.contexts + branch_required_status_checks = branch_protection.required_status_checks.contexts + self.logger.debug(f"branch_required_status_checks: {branch_required_status_checks}") + return branch_required_status_checks async def required_check_in_progress( self, pull_request: PullRequest, last_commit_check_runs: list[CheckRun] diff --git a/webhook_server/libs/issue_comment_handler.py b/webhook_server/libs/issue_comment_handler.py index b0476d0b..abf5cb08 100644 --- a/webhook_server/libs/issue_comment_handler.py +++ b/webhook_server/libs/issue_comment_handler.py @@ -107,11 +107,20 @@ async def user_commands( return self.logger.info(f"{self.log_prefix} Processing label/user command {command} by user {reviewed_user}") + self.logger.debug(f"{self.log_prefix} Command {command} is supported.") if remove := len(command_and_args) > 1 and _args == "cancel": self.logger.debug(f"{self.log_prefix} User requested 'cancel' for command {_command}") - if _command in (COMMAND_RETEST_STR, COMMAND_ASSIGN_REVIEWER_STR, COMMAND_ADD_ALLOWED_USER_STR) and not _args: + if ( + _command + in ( + COMMAND_RETEST_STR, + COMMAND_ASSIGN_REVIEWER_STR, + COMMAND_ADD_ALLOWED_USER_STR, + ) + and not _args + ): missing_command_arg_comment_msg: str = f"{_command} requires an argument" error_msg: str = f"{self.log_prefix} {missing_command_arg_comment_msg}" self.logger.debug(error_msg) @@ -121,6 +130,7 @@ async def user_commands( await self.create_comment_reaction( pull_request=pull_request, issue_comment_id=issue_comment_id, reaction=REACTIONS.ok ) + self.logger.debug(f"{self.log_prefix} Added reaction to comment.") if _command == COMMAND_ASSIGN_REVIEWER_STR: await self._add_reviewer_by_user_comment(pull_request=pull_request, reviewer=_args) @@ -170,6 +180,9 @@ async def user_commands( elif _command == HOLD_LABEL_STR: if reviewed_user not in self.owners_file_handler.all_pull_request_approvers: + self.logger.debug( + f"{self.log_prefix} {reviewed_user} is not an approver, not adding {HOLD_LABEL_STR} label" + ) await asyncio.to_thread( pull_request.create_issue_comment, f"{reviewed_user} is not part of the approver, only approvers can mark pull request with hold", @@ -205,8 +218,10 @@ async def create_comment_reaction(self, pull_request: PullRequest, issue_comment async def _add_reviewer_by_user_comment(self, pull_request: PullRequest, reviewer: str) -> None: reviewer = reviewer.strip("@") self.logger.info(f"{self.log_prefix} Adding reviewer {reviewer} by user comment") + repo_contributors = list(await asyncio.to_thread(self.repository.get_contributors)) + self.logger.debug(f"Repo contributors are: {repo_contributors}") - for contributer in await asyncio.to_thread(self.repository.get_contributors): + for contributer in repo_contributors: if contributer.login == reviewer: await asyncio.to_thread(pull_request.create_review_request, [reviewer]) return @@ -221,6 +236,7 @@ async def process_cherry_pick_command( _target_branches: list[str] = command_args.split() _exits_target_branches: set[str] = set() _non_exits_target_branches_msg: str = "" + self.logger.debug(f"{self.log_prefix} Processing cherry pick for branches {_target_branches}") for _target_branch in _target_branches: try: @@ -228,6 +244,9 @@ async def process_cherry_pick_command( _exits_target_branches.add(_target_branch) except Exception: _non_exits_target_branches_msg += f"Target branch `{_target_branch}` does not exist\n" + self.logger.debug( + f"{self.log_prefix} Found target branches {_exits_target_branches} and not found {_non_exits_target_branches_msg}" + ) if _non_exits_target_branches_msg: self.logger.info(f"{self.log_prefix} {_non_exits_target_branches_msg}") @@ -254,13 +273,16 @@ async def process_cherry_pick_command( reviewed_user=reviewed_user, ) - async def process_retest_command(self, pull_request: PullRequest, command_args: str, reviewed_user: str) -> None: + async def process_retest_command( + self, pull_request: PullRequest, command_args: str, reviewed_user: str, automerge: bool = False + ) -> None: if not await self.owners_file_handler.is_user_valid_to_run_commands( pull_request=pull_request, reviewed_user=reviewed_user ): return _target_tests: list[str] = command_args.split() + self.logger.debug(f"{self.log_prefix} Target tests for re-test: {_target_tests}") _not_supported_retests: list[str] = [] _supported_retests: list[str] = [] _retests_to_func_map: dict[str, Callable] = { @@ -270,6 +292,7 @@ async def process_retest_command(self, pull_request: PullRequest, command_args: PYTHON_MODULE_INSTALL_STR: self.runner_handler.run_install_python_module, CONVENTIONAL_TITLE_STR: self.runner_handler.run_conventional_title_check, } + self.logger.debug(f"Retest map is {_retests_to_func_map}") if not _target_tests: msg = "No test defined to retest" @@ -288,6 +311,7 @@ async def process_retest_command(self, pull_request: PullRequest, command_args: else: _supported_retests = self.github_webhook.current_pull_request_supported_retest + self.logger.debug(f"{self.log_prefix} running all supported retests: {_supported_retests}") else: for _test in _target_tests: @@ -296,6 +320,8 @@ async def process_retest_command(self, pull_request: PullRequest, command_args: else: _not_supported_retests.append(_test) + self.logger.debug(f"Supported retests are {_supported_retests}") + self.logger.debug(f"Not supported retests are {_not_supported_retests}") if _not_supported_retests: msg = f"No {' '.join(_not_supported_retests)} configured for this repository" @@ -314,3 +340,6 @@ async def process_retest_command(self, pull_request: PullRequest, command_args: for result in results: if isinstance(result, Exception): self.logger.error(f"{self.log_prefix} Async task failed: {result}") + + if automerge: + await self.labels_handler._add_label(pull_request=pull_request, label="automerge") diff --git a/webhook_server/libs/labels_handler.py b/webhook_server/libs/labels_handler.py index ee47deb3..0e40f9b4 100644 --- a/webhook_server/libs/labels_handler.py +++ b/webhook_server/libs/labels_handler.py @@ -44,6 +44,7 @@ async def pull_request_labels_names(self, pull_request: PullRequest) -> list[str return [lb.name for lb in labels] async def _remove_label(self, pull_request: PullRequest, label: str) -> bool: + self.logger.debug(f"{self.log_prefix} Removing label {label}") try: if await self.label_exists_in_pull_request(pull_request=pull_request, label=label): self.logger.info(f"{self.log_prefix} Removing label {label}") @@ -58,6 +59,7 @@ async def _remove_label(self, pull_request: PullRequest, label: str) -> bool: async def _add_label(self, pull_request: PullRequest, label: str) -> None: label = label.strip() + self.logger.debug(f"{self.log_prefix} Adding label {label}") if len(label) > 49: self.logger.debug(f"{label} is too long, not adding.") return @@ -90,6 +92,7 @@ async def _add_label(self, pull_request: PullRequest, label: str) -> None: await self.wait_for_label(pull_request=pull_request, label=label, exists=True) async def wait_for_label(self, pull_request: PullRequest, label: str, exists: bool) -> bool: + self.logger.debug(f"{self.log_prefix} waiting for label {label} to {'exists' if exists else 'not exists'}") while TimeoutWatch(timeout=30).remaining_time() > 0: res = await self.label_exists_in_pull_request(pull_request=pull_request, label=label) if res == exists: @@ -107,6 +110,7 @@ def get_size(self, pull_request: PullRequest) -> str: additions = pull_request.additions if pull_request.additions is not None else 0 deletions = pull_request.deletions if pull_request.deletions is not None else 0 size = additions + deletions + self.logger.debug(f"{self.log_prefix} PR size is {size} (additions: {additions}, deletions: {deletions})") # Define label thresholds in a more readable way threshold_sizes = [20, 50, 100, 300, 500] @@ -122,6 +126,7 @@ def get_size(self, pull_request: PullRequest) -> str: async def add_size_label(self, pull_request: PullRequest) -> None: """Add a size label to the pull request based on its additions and deletions.""" size_label = self.get_size(pull_request=pull_request) + self.logger.debug(f"{self.log_prefix} size label is {size_label}") if not size_label: self.logger.debug(f"{self.log_prefix} Size label not found") return @@ -136,6 +141,7 @@ async def add_size_label(self, pull_request: PullRequest) -> None: ] if exists_size_label: + self.logger.debug(f"{self.log_prefix} Found existing size label {exists_size_label}, removing it.") await self._remove_label(pull_request=pull_request, label=exists_size_label[0]) await self._add_label(pull_request=pull_request, label=size_label) @@ -174,6 +180,7 @@ async def manage_reviewed_by_label( ) label_prefix: str = "" label_to_remove: str = "" + self.logger.debug(f"{self.log_prefix} label_prefix is {label_prefix}, label_to_remove is {label_to_remove}") if review_state == APPROVE_STR: if ( @@ -182,6 +189,10 @@ async def manage_reviewed_by_label( ): label_prefix = APPROVED_BY_LABEL_PREFIX label_to_remove = f"{CHANGED_REQUESTED_BY_LABEL_PREFIX}{reviewed_user}" + self.logger.debug( + f"{self.log_prefix} User {reviewed_user} is approver, setting label prefix to " + f"{label_prefix} and label to remove to {label_to_remove}" + ) else: self.logger.debug(f"{self.log_prefix} {reviewed_user} not in approvers list, will not {action} label.") @@ -197,23 +208,32 @@ async def manage_reviewed_by_label( _remove_label = f"{CHANGED_REQUESTED_BY_LABEL_PREFIX}{reviewed_user}" label_prefix = LGTM_BY_LABEL_PREFIX label_to_remove = _remove_label + self.logger.debug( + f"{self.log_prefix} Setting label prefix to {label_prefix} and label to remove to {label_to_remove}" + ) elif review_state == "changes_requested": label_prefix = CHANGED_REQUESTED_BY_LABEL_PREFIX _remove_label = LGTM_BY_LABEL_PREFIX label_to_remove = _remove_label + self.logger.debug( + f"{self.log_prefix} Setting label prefix to {label_prefix} and label to remove to {label_to_remove}" + ) elif review_state == "commented": label_prefix = COMMENTED_BY_LABEL_PREFIX + self.logger.debug(f"{self.log_prefix} Setting label prefix to {label_prefix}") if label_prefix: reviewer_label = f"{label_prefix}{reviewed_user}" if action == ADD_STR: + self.logger.debug(f"{self.log_prefix} Adding reviewer label {reviewer_label}") await self._add_label(pull_request=pull_request, label=reviewer_label) await self._remove_label(pull_request=pull_request, label=label_to_remove) if action == DELETE_STR: + self.logger.debug(f"{self.log_prefix} Removing reviewer label {reviewer_label}") await self._remove_label(pull_request=pull_request, label=reviewer_label) else: self.logger.warning( diff --git a/webhook_server/libs/owners_files_handler.py b/webhook_server/libs/owners_files_handler.py index ef30faa1..06e6889b 100644 --- a/webhook_server/libs/owners_files_handler.py +++ b/webhook_server/libs/owners_files_handler.py @@ -64,7 +64,9 @@ def allowed_users(self) -> list[str]: return _allowed_users async def list_changed_files(self, pull_request: PullRequest) -> list[str]: - return [_file.filename for _file in await asyncio.to_thread(pull_request.get_files)] + changed_files = [_file.filename for _file in await asyncio.to_thread(pull_request.get_files)] + self.logger.debug(f"{self.log_prefix} Changed files: {changed_files}") + return changed_files def _validate_owners_content(self, content: Any, path: str) -> bool: """Validate OWNERS file content structure.""" @@ -116,6 +118,7 @@ async def get_all_repository_approvers_and_reviewers(self, pull_request: PullReq break content_path = element.path + self.logger.debug(f"{self.log_prefix} Found OWNERS file: {content_path}") tasks.append(self._get_file_content(content_path, pull_request)) results = await asyncio.gather(*tasks) @@ -147,6 +150,7 @@ async def get_all_repository_approvers(self) -> list[str]: if key == "approvers": _approvers.extend(val) + self.logger.debug(f"{self.log_prefix} All repository approvers: {_approvers}") return _approvers async def get_all_repository_reviewers(self) -> list[str]: @@ -159,6 +163,7 @@ async def get_all_repository_reviewers(self) -> list[str]: if key == "reviewers": _reviewers.extend(val) + self.logger.debug(f"{self.log_prefix} All repository reviewers: {_reviewers}") return _reviewers async def get_all_pull_request_approvers(self) -> list[str]: @@ -170,6 +175,7 @@ async def get_all_pull_request_approvers(self) -> list[str]: _approvers.append(_approver) _approvers.sort() + self.logger.debug(f"{self.log_prefix} All pull request approvers: {_approvers}") return _approvers async def get_all_pull_request_reviewers(self) -> list[str]: @@ -181,6 +187,7 @@ async def get_all_pull_request_reviewers(self) -> list[str]: _reviewers.append(_reviewer) _reviewers.sort() + self.logger.debug(f"Pull request reviewers are: {_reviewers}") return _reviewers async def owners_data_for_changed_files(self) -> dict[str, dict[str, Any]]: @@ -189,6 +196,7 @@ async def owners_data_for_changed_files(self) -> dict[str, dict[str, Any]]: data: dict[str, dict[str, Any]] = {} changed_folders = {Path(cf).parent for cf in self.changed_files} + self.logger.debug(f"Changed folders: {changed_folders}") changed_folder_match: list[Path] = [] @@ -204,6 +212,9 @@ async def owners_data_for_changed_files(self) -> dict[str, dict[str, Any]]: if changed_folder == _owners_dir or _owners_dir in changed_folder.parents: data[owners_dir] = owners_data changed_folder_match.append(_owners_dir) + self.logger.debug( + f"{self.log_prefix} Matched changed folder: {changed_folder} with owners dir: {_owners_dir}" + ) if require_root_approvers is None: require_root_approvers = owners_data.get("root-approvers", True) @@ -217,9 +228,11 @@ async def owners_data_for_changed_files(self) -> dict[str, dict[str, Any]]: if _folder == _changed_path or _changed_path in _folder.parents: continue else: + self.logger.debug(f"Adding root approvers for {_folder}") data["."] = self.all_repository_approvers_and_reviewers.get(".", {}) break + self.logger.debug(f"Final owners data for changed files: {data}") return data async def assign_reviewers(self, pull_request: PullRequest) -> None: @@ -255,6 +268,7 @@ async def is_user_valid_to_run_commands(self, pull_request: PullRequest, reviewe - {"\n - @".join(allowed_user_to_approve)} """ valid_users = await self.valid_users_to_run_commands + self.logger.debug(f"Valid users to run commands: {valid_users}") if reviewed_user not in valid_users: for comment in [ @@ -301,10 +315,12 @@ async def get_all_repository_maintainers(self) -> list[str]: for user in await self.repository_collaborators: permissions = user.permissions + self.logger.debug(f"User {user.login} permissions: {permissions}") if permissions.admin or permissions.maintain: maintainers.append(user.login) + self.logger.debug(f"Maintainers: {maintainers}") return maintainers @functools.cached_property diff --git a/webhook_server/libs/pull_request_handler.py b/webhook_server/libs/pull_request_handler.py index 9e496a72..f5aa2a09 100644 --- a/webhook_server/libs/pull_request_handler.py +++ b/webhook_server/libs/pull_request_handler.py @@ -56,6 +56,7 @@ def __init__(self, github_webhook: "GithubWebhook", owners_file_handler: OwnersF async def process_pull_request_webhook_data(self, pull_request: PullRequest) -> None: hook_action: str = self.hook_data["action"] self.logger.info(f"{self.log_prefix} hook_action is: {hook_action}") + self.logger.debug(f"{self.log_prefix} pull_request: {pull_request.title} ({pull_request.number})") pull_request_data: dict[str, Any] = self.hook_data["pull_request"] @@ -126,6 +127,7 @@ async def process_pull_request_webhook_data(self, pull_request: PullRequest) -> return self.logger.info(f"{self.log_prefix} PR {pull_request.number} {hook_action} with {labeled}") + self.logger.debug(f"PR labels are {pull_request.labels}") _split_label = labeled.split(LABELS_SEPARATOR, 1) @@ -144,9 +146,11 @@ async def process_pull_request_webhook_data(self, pull_request: PullRequest) -> + self.owners_file_handler.root_approvers ): _check_for_merge = True + self.logger.debug(f"PR approved by label action, will check for merge. user: {_user}") if self.github_webhook.verified_job and labeled_lower == VERIFIED_LABEL_STR: _check_for_merge = True + self.logger.debug(f"PR verified label action, will check for merge. label: {labeled_lower}") if action_labeled: await self.check_run_handler.set_verify_check_success() @@ -155,6 +159,7 @@ async def process_pull_request_webhook_data(self, pull_request: PullRequest) -> if labeled_lower in (WIP_STR, HOLD_LABEL_STR): _check_for_merge = True + self.logger.debug(f"PR has {labeled_lower} label, will check for merge.") if _check_for_merge: await self.check_if_can_be_merged(pull_request=pull_request) @@ -328,6 +333,7 @@ async def label_all_opened_pull_requests_merge_state_after_merged(self) -> None: await self.label_pull_request_by_merge_state(pull_request=pull_request) async def delete_remote_tag_for_merged_or_closed_pr(self, pull_request: PullRequest) -> None: + self.logger.debug(f"{self.log_prefix} Checking if need to delete remote tag for {pull_request.number}") if not self.github_webhook.build_and_push_container: self.logger.info(f"{self.log_prefix} repository do not have container configured") return @@ -462,10 +468,17 @@ def _generate_issue_body(self, pull_request: PullRequest) -> str: return f"[Auto generated]\nNumber: [#{pull_request.number}]" async def set_pull_request_automerge(self, pull_request: PullRequest) -> None: - auto_merge = ( - pull_request.base.ref in self.github_webhook.set_auto_merge_prs - or self.github_webhook.parent_committer in self.github_webhook.auto_verified_and_merged_users + set_auto_merge_base_branch = pull_request.base.ref in self.github_webhook.set_auto_merge_prs + self.logger.debug(f"{self.log_prefix} set auto merge for base branch is {set_auto_merge_base_branch}") + parent_committer_in_auto_merge_users = ( + self.github_webhook.parent_committer in self.github_webhook.auto_verified_and_merged_users ) + self.logger.debug( + f"{self.log_prefix} parent committer {self.github_webhook.parent_committer} in auto merge users is " + f"{parent_committer_in_auto_merge_users}" + ) + + auto_merge = set_auto_merge_base_branch or parent_committer_in_auto_merge_users self.logger.debug(f"{self.log_prefix} auto_merge: {auto_merge}, branch: {pull_request.base.ref}") @@ -583,6 +596,7 @@ async def check_if_can_be_merged(self, pull_request: PullRequest) -> None: self.logger.debug(f"{self.log_prefix} check if can be merged. PR labels are: {_labels}") is_pr_mergable = pull_request.mergeable + self.logger.debug(f"{self.log_prefix} PR mergeable is {is_pr_mergable}") if not is_pr_mergable: failure_output += f"PR is not mergeable: {is_pr_mergable}\n" @@ -594,10 +608,12 @@ async def check_if_can_be_merged(self, pull_request: PullRequest) -> None: ) if required_check_in_progress_failure_output: failure_output += required_check_in_progress_failure_output + self.logger.debug(f"{self.log_prefix} required_check_in_progress_failure_output: {failure_output}") labels_failure_output = self.labels_handler.wip_or_hold_lables_exists(labels=_labels) if labels_failure_output: failure_output += labels_failure_output + self.logger.debug(f"{self.log_prefix} wip_or_hold_lables_exists: {failure_output}") required_check_failed_failure_output = await self.check_run_handler.required_check_failed_or_no_status( pull_request=pull_request, @@ -606,14 +622,17 @@ async def check_if_can_be_merged(self, pull_request: PullRequest) -> None: ) if required_check_failed_failure_output: failure_output += required_check_failed_failure_output + self.logger.debug(f"{self.log_prefix} required_check_failed_or_no_status: {failure_output}") labels_failure_output = self._check_labels_for_can_be_merged(labels=_labels) if labels_failure_output: failure_output += labels_failure_output + self.logger.debug(f"{self.log_prefix} _check_labels_for_can_be_merged: {failure_output}") pr_approvered_failure_output = await self._check_if_pr_approved(labels=_labels) if pr_approvered_failure_output: failure_output += pr_approvered_failure_output + self.logger.debug(f"{self.log_prefix} _check_if_pr_approved: {failure_output}") if not failure_output: await self.labels_handler._add_label(pull_request=pull_request, label=CAN_BE_MERGED_STR) @@ -638,6 +657,7 @@ async def check_if_can_be_merged(self, pull_request: PullRequest) -> None: async def _check_if_pr_approved(self, labels: list[str]) -> str: self.logger.info(f"{self.log_prefix} Check if pull request is approved by pull request labels.") + self.logger.debug(f"labels are {labels}") error: str = "" approved_by = [] @@ -648,9 +668,11 @@ async def _check_if_pr_approved(self, labels: list[str]) -> str: + self.owners_file_handler.root_approvers.copy() + self.owners_file_handler.root_reviewers.copy() ) + self.logger.debug(f"all_reviewers: {all_reviewers}") all_reviewers_without_pr_owner = { _reviewer for _reviewer in all_reviewers if _reviewer != self.github_webhook.parent_committer } + self.logger.debug(f"all_reviewers_without_pr_owner: {all_reviewers_without_pr_owner}") all_reviewers_without_pr_owner_and_lgtmed = all_reviewers_without_pr_owner.copy() @@ -660,13 +682,17 @@ async def _check_if_pr_approved(self, labels: list[str]) -> str: if LGTM_BY_LABEL_PREFIX.lower() in _label.lower() and reviewer in all_reviewers_without_pr_owner: lgtm_count += 1 all_reviewers_without_pr_owner_and_lgtmed.remove(reviewer) + self.logger.debug(f"lgtm_count: {lgtm_count}") for _label in labels: if APPROVED_BY_LABEL_PREFIX.lower() in _label.lower(): approved_by.append(_label.split(LABELS_SEPARATOR)[-1]) + self.logger.debug(f"approved_by: {approved_by}") missing_approvers = list(set(self.owners_file_handler.all_pull_request_approvers.copy())) + self.logger.debug(f"missing_approvers: {missing_approvers}") owners_data_changed_files = await self.owners_file_handler.owners_data_for_changed_files() + self.logger.debug(f"owners_data_changed_files: {owners_data_changed_files}") # If any of root approvers is in approved_by list, the pull request is approved for _approver in approved_by: @@ -688,6 +714,7 @@ async def _check_if_pr_approved(self, labels: list[str]) -> str: break missing_approvers = list(set(missing_approvers)) + self.logger.debug(f"missing_approvers after check: {missing_approvers}") if missing_approvers: error += f"Missing approved from approvers: {', '.join(missing_approvers)}\n" @@ -714,11 +741,13 @@ def _check_labels_for_can_be_merged(self, labels: list[str]) -> str: change_request_user = _label.split(LABELS_SEPARATOR)[-1] if change_request_user in self.owners_file_handler.all_pull_request_approvers: failure_output += "PR has changed requests from approvers\n" + self.logger.debug(f"Found changed request by {change_request_user}") missing_required_labels = [] for _req_label in self.github_webhook.can_be_merged_required_labels: if _req_label not in labels: missing_required_labels.append(_req_label) + self.logger.debug(f"Missing required label {_req_label}") if missing_required_labels: failure_output += f"Missing required labels: {', '.join(missing_required_labels)}\n" diff --git a/webhook_server/libs/pull_request_review_handler.py b/webhook_server/libs/pull_request_review_handler.py index e0bf563a..e9617c39 100644 --- a/webhook_server/libs/pull_request_review_handler.py +++ b/webhook_server/libs/pull_request_review_handler.py @@ -19,6 +19,7 @@ def __init__(self, github_webhook: "GithubWebhook", owners_file_handler: OwnersF self.labels_handler = LabelsHandler( github_webhook=self.github_webhook, owners_file_handler=self.owners_file_handler ) + self.github_webhook.logger.debug(f"{self.github_webhook.log_prefix} Initialized PullRequestReviewHandler") async def process_pull_request_review_webhook_data(self, pull_request: PullRequest) -> None: if self.hook_data["action"] == "submitted": @@ -29,8 +30,12 @@ async def process_pull_request_review_webhook_data(self, pull_request: PullReque changes_requested """ reviewed_user = self.hook_data["review"]["user"]["login"] - review_state = self.hook_data["review"]["state"] + self.github_webhook.logger.debug( + f"{self.github_webhook.log_prefix} " + f"Processing pull request review for user {reviewed_user} with state {review_state}" + ) + await self.labels_handler.manage_reviewed_by_label( pull_request=pull_request, review_state=review_state, @@ -39,6 +44,7 @@ async def process_pull_request_review_webhook_data(self, pull_request: PullReque ) if body := self.hook_data["review"]["body"]: + self.github_webhook.logger.debug(f"{self.github_webhook.log_prefix} Found review body: {body}") if f"/{APPROVE_STR}" in body: await self.labels_handler.label_by_user_comment( pull_request=pull_request, diff --git a/webhook_server/libs/push_handler.py b/webhook_server/libs/push_handler.py index 0616302f..641d4f73 100644 --- a/webhook_server/libs/push_handler.py +++ b/webhook_server/libs/push_handler.py @@ -26,6 +26,7 @@ async def process_push_webhook_data(self) -> None: if tag: tag_name = tag.group(1) self.logger.info(f"{self.log_prefix} Processing push for tag: {tag.group(1)}") + self.logger.debug(f"{self.log_prefix} Tag: {tag_name}") if self.github_webhook.pypi: self.logger.info(f"{self.log_prefix} Processing upload to pypi for tag: {tag_name}") await self.upload_to_pypi(tag_name=tag_name) @@ -46,6 +47,7 @@ def _issue_on_error(_error: str) -> None: clone_repo_dir = f"{self.github_webhook.clone_repo_dir}-{uuid4()}" uv_cmd_dir = f"--directory {clone_repo_dir}" self.logger.info(f"{self.log_prefix} Start uploading to pypi") + self.logger.debug(f"{self.log_prefix} Clone repo dir: {clone_repo_dir}") _dist_dir: str = f"{clone_repo_dir}/pypi-dist" async with self.runner_handler._prepare_cloned_repo_dir( @@ -73,6 +75,7 @@ def _issue_on_error(_error: str) -> None: f"uvx {uv_cmd_dir} twine check {_dist_dir}/{tar_gz_file}", f"uvx {uv_cmd_dir} twine upload --username __token__ --password {self.github_webhook.pypi['token']} {_dist_dir}/{tar_gz_file} --skip-existing", ] + self.logger.debug(f"Commands to run: {commands}") for cmd in commands: rc, out, err = await run_command(command=cmd, log_prefix=self.log_prefix) diff --git a/webhook_server/libs/runner_handler.py b/webhook_server/libs/runner_handler.py index 0e7e8896..dca1a513 100644 --- a/webhook_server/libs/runner_handler.py +++ b/webhook_server/libs/runner_handler.py @@ -45,6 +45,7 @@ async def _prepare_cloned_repo_dir( tag_name: str = "", ) -> AsyncGenerator[tuple[bool, Any, Any], None]: git_cmd = f"git --work-tree={clone_repo_dir} --git-dir={clone_repo_dir}/.git" + self.logger.debug(f"{self.log_prefix} Preparing cloned repo dir {clone_repo_dir} with git cmd: {git_cmd}") result: tuple[bool, str, str] = (True, "", "") success = True @@ -184,11 +185,15 @@ async def run_tox(self, pull_request: PullRequest) -> None: ) cmd = f"uvx {python_ver} {TOX_STR} --workdir {clone_repo_dir} --root {clone_repo_dir} -c {clone_repo_dir}" _tox_tests = self.github_webhook.tox.get(pull_request.base.ref, "") - if _tox_tests and _tox_tests != "all": - tests = _tox_tests.replace(" ", "") - cmd += f" -e {tests}" + if not _tox_tests: + tests = "" + else: + tests = f" -e {_tox_tests}" + + cmd += tests await self.check_run_handler.set_run_tox_check_in_progress() + self.logger.debug(f"{self.log_prefix} Tox command to run: {cmd}") async with self._prepare_cloned_repo_dir(clone_repo_dir=clone_repo_dir, pull_request=pull_request) as _res: output: dict[str, Any] = { "title": "Tox", @@ -285,6 +290,7 @@ async def run_build_container( build_cmd = f"{command_args} {build_cmd}" podman_build_cmd: str = f"podman build {build_cmd}" + self.logger.debug(f"{self.log_prefix} Podman build command to run: {podman_build_cmd}") async with self._prepare_cloned_repo_dir( pull_request=pull_request, is_merged=is_merged, @@ -395,6 +401,7 @@ async def run_conventional_title_check(self, pull_request: PullRequest) -> None: await self.check_run_handler.set_conventional_title_in_progress() allowed_names = self.github_webhook.conventional_title.split(",") title = pull_request.title + self.logger.debug(f"{self.log_prefix} Conventional title check for title: {title}, allowed: {allowed_names}") if any([title.startswith(f"{_name}:") for _name in allowed_names]): await self.check_run_handler.set_conventional_title_success(output=output) else: @@ -432,6 +439,7 @@ async def cherry_pick(self, pull_request: PullRequest, target_branch: str, revie f"{git_cmd} push origin {new_branch_name}", f"bash -c \"{hub_cmd} pull-request -b {target_branch} -h {new_branch_name} -l {CHERRY_PICKED_LABEL_PREFIX} -m '{CHERRY_PICKED_LABEL_PREFIX}: [{target_branch}] {commit_msg_striped}' -m 'cherry-pick {pull_request_url} into {target_branch}' -m 'requested-by {requested_by}'\"", ] + self.logger.debug(f"{self.log_prefix} Cherry pick commands to run: {commands}") rc, out, err = None, "", "" async with self._prepare_cloned_repo_dir(pull_request=pull_request, clone_repo_dir=clone_repo_dir) as _res: diff --git a/webhook_server/tests/test_check_run_handler.py b/webhook_server/tests/test_check_run_handler.py index a66c094e..aa485f69 100644 --- a/webhook_server/tests/test_check_run_handler.py +++ b/webhook_server/tests/test_check_run_handler.py @@ -439,7 +439,7 @@ def create_check_run_side_effect(*args: object, **kwargs: object) -> None: ) # Should be called twice - once for the original attempt, once for the fallback assert call_count["count"] == 2 - mock_debug.assert_called_once() + mock_debug.assert_called() def test_get_check_run_text_normal_length(self, check_run_handler: CheckRunHandler) -> None: """Test getting check run text with normal length."""