diff --git a/Procfile b/Procfile index 0ceb9f1f..58b9a3ef 100644 --- a/Procfile +++ b/Procfile @@ -1,2 +1,2 @@ web: python3 -m miss_islington -worker: celery --app miss_islington.tasks.app worker --concurrency=1 +worker: celery --app miss_islington.tasks.app worker --concurrency=1 --loglevel=INFO diff --git a/miss_islington/__main__.py b/miss_islington/__main__.py index bc321571..e458e669 100644 --- a/miss_islington/__main__.py +++ b/miss_islington/__main__.py @@ -1,7 +1,6 @@ import asyncio +import logging import os -import sys -import traceback import aiohttp import cachetools @@ -16,6 +15,9 @@ from . import backport_pr, delete_branch +logging.basicConfig(level=logging.INFO) +logger = logging.getLogger(__name__) + router = routing.Router( backport_pr.router, delete_branch.router ) @@ -29,7 +31,10 @@ async def main(request): secret = os.environ.get("GH_SECRET") event = sansio.Event.from_http(request.headers, body, secret=secret) - print("GH delivery ID", event.delivery_id, file=sys.stderr) + logger.info( + "received GitHub webhook", + extra={"delivery_id": event.delivery_id, "event": event.event}, + ) if event.event == "ping": return web.Response(status=200) async with aiohttp.ClientSession() as session: @@ -50,25 +55,32 @@ async def main(request): await asyncio.sleep(1) await router.dispatch(event, gh) try: - print( - f"""\ -GH requests remaining: {gh.rate_limit.remaining}/{gh.rate_limit.limit}, \ -reset time: {gh.rate_limit.reset_datetime:%b-%d-%Y %H:%M:%S %Z}, \ -GH delivery ID {event.delivery_id} \ -""" + logger.info( + "GitHub rate limit", + extra={ + "remaining": gh.rate_limit.remaining, + "limit": gh.rate_limit.limit, + "reset": gh.rate_limit.reset_datetime.isoformat(), + "delivery_id": event.delivery_id, + }, ) except AttributeError: pass return web.Response(status=200) - except Exception as exc: - traceback.print_exc(file=sys.stderr) + except Exception: + logger.exception("webhook handler crashed") return web.Response(status=500) @router.register("installation", action="created") async def repo_installation_added(event, gh, *args, **kwargs): - # installation_id = event.data["installation"]["id"] - print(f"App installed by {event.data['installation']['account']['login']}, installation_id: {event.data['installation']['id']}") + logger.info( + "app installed", + extra={ + "account": event.data["installation"]["account"]["login"], + "installation_id": event.data["installation"]["id"], + }, + ) sentry_sdk.init(dsn=os.environ.get("SENTRY_DSN"), integrations=[AioHttpIntegration()]) diff --git a/miss_islington/tasks.py b/miss_islington/tasks.py index 89d1d6d9..80859efa 100644 --- a/miss_islington/tasks.py +++ b/miss_islington/tasks.py @@ -44,7 +44,7 @@ @app.task() def setup_cpython_repo(): - print("Setting up CPython repository") # pragma: nocover + logger.info("setting up CPython repository") # pragma: nocover if "cpython" not in os.listdir("."): subprocess.check_output( f"git clone https://{os.environ.get('GH_AUTH')}:x-oauth-basic@github.com/miss-islington/cpython.git".split() @@ -59,9 +59,9 @@ def setup_cpython_repo(): subprocess.check_output( f"git remote add upstream https://{os.environ.get('GH_AUTH')}:x-oauth-basic@github.com/python/cpython.git".split() ) - print("Finished setting up CPython Repo") + logger.info("finished setting up CPython repository") else: - print("cpython directory already exists") + logger.info("cpython directory already exists") @app.task() @@ -100,7 +100,16 @@ async def backport_task_asyncio( if "cpython" in os.listdir("."): os.chdir("./cpython") else: - print(f"pwd: {os.getcwd()}, listdir: {os.listdir('.')}") + logger.warning( + "cpython directory not found", + extra={ + "pwd": os.getcwd(), + "listdir": os.listdir("."), + "branch": branch, + "commit_hash": commit_hash, + "issue_number": issue_number, + }, + ) await util.comment_on_pr( gh, @@ -150,7 +159,14 @@ async def backport_task_asyncio( """, ) await util.assign_pr_to_core_dev(gh, issue_number, merged_by) - logger.exception("InvalidRepoException while backporting to %s", branch) + logger.exception( + "backport failed: invalid repo state", + extra={ + "branch": branch, + "commit_hash": commit_hash, + "issue_number": issue_number, + }, + ) except cherry_picker.BranchCheckoutException as bce: await util.comment_on_pr( gh, @@ -166,7 +182,15 @@ async def backport_task_asyncio( ) await util.assign_pr_to_core_dev(gh, issue_number, merged_by) bce_state = cp.get_state_and_verify() - print(bce_state, bce) + logger.exception( + "backport failed: branch checkout error", + extra={ + "branch": branch, + "commit_hash": commit_hash, + "issue_number": issue_number, + "state": bce_state.name, + }, + ) cp.abort_cherry_pick() except cherry_picker.CherryPickException as cpe: await util.comment_on_pr( @@ -182,7 +206,15 @@ async def backport_task_asyncio( ) await util.assign_pr_to_core_dev(gh, issue_number, merged_by) cpe_state = cp.get_state_and_verify() - print(cpe_state, cpe) + logger.exception( + "backport failed: cherry-pick conflict", + extra={ + "branch": branch, + "commit_hash": commit_hash, + "issue_number": issue_number, + "state": cpe_state.name, + }, + ) cp.abort_cherry_pick() except cherry_picker.GitHubException as ghe: await util.comment_on_pr( @@ -199,7 +231,15 @@ async def backport_task_asyncio( ) await util.assign_pr_to_core_dev(gh, issue_number, merged_by) ghe_state = cp.get_state_and_verify() - print(ghe_state, ghe) + logger.exception( + "backport failed: github error", + extra={ + "branch": branch, + "commit_hash": commit_hash, + "issue_number": issue_number, + "state": ghe_state.name, + }, + ) cp.abort_cherry_pick() @@ -220,8 +260,14 @@ async def _delete_branch_task_asyncio(branch_name, pr_url, merged, *, installati if "cpython" in os.listdir("."): os.chdir("./cpython") else: - print(f"Cannot delete branch: cpython repo not found. " - f"pwd: {os.getcwd()}, listdir: {os.listdir('.')}") + logger.warning( + "cannot delete branch: cpython repo not found", + extra={ + "branch": branch_name, + "pwd": os.getcwd(), + "listdir": os.listdir("."), + }, + ) return if merged: @@ -249,15 +295,18 @@ def _git_delete_branch(branch_name): ["git", "push", "origin", "--delete", branch_name], stderr=subprocess.STDOUT ) - print(f"Deleted branch {branch_name}") + logger.info("deleted branch", extra={"branch": branch_name}) except subprocess.CalledProcessError as e: - print(f"Failed to delete branch {branch_name}: {e.output.decode()}") + logger.exception( + "failed to delete branch", + extra={"branch": branch_name, "output": e.output.decode()}, + ) raise class InitRepoStep(bootsteps.StartStopStep): def start(self, c): - print("Initialize the repository.") + logger.info("initializing the repository") setup_cpython_repo() diff --git a/miss_islington/util.py b/miss_islington/util.py index ab28d4ee..d296b3dd 100644 --- a/miss_islington/util.py +++ b/miss_islington/util.py @@ -1,6 +1,9 @@ +import logging import subprocess import textwrap +logger = logging.getLogger(__name__) + async def comment_on_pr(gh, issue_number, message): """ @@ -10,7 +13,10 @@ async def comment_on_pr(gh, issue_number, message): message = textwrap.dedent(message) data = {"body": message} response = await gh.post(issue_comment_url, data=data) - print(f"Commented at {response['html_url']}, message: {message}") + logger.info( + "commented on PR", + extra={"issue_number": issue_number, "url": response["html_url"]}, + ) return response