diff --git a/src/app.py b/src/app.py index 0c134b4..ed46ba3 100644 --- a/src/app.py +++ b/src/app.py @@ -57,7 +57,7 @@ def process_workflow_job(): requestor = job.get("sender", {}).get("login") runner_name = job["workflow_job"]["runner_name"] runner_group_name = job["workflow_job"]["runner_group_name"] - runner_public = (runner_group_name == "GitHub Actions") + runner_public = runner_group_name == "GitHub Actions" context_details = { "action": action, @@ -73,24 +73,32 @@ def process_workflow_job(): elif action == "in_progress": job_requested = jobs.get(job_id) + time_to_start = None if not job_requested: - app.logger.warning(f"Job {job_id} is {action} but not stored!") - time_to_start = 0 + app.logger.error(f"Job {job_id} is {action} but not stored!") else: - time_to_start = (time_start - datetime.fromtimestamp(job_requested)).seconds + if time_start < datetime.fromtimestamp(job_requested): + app.logger.error(f"Job {job_id} was in progress before being queued") + del jobs[job_id] + else: + time_to_start = ( + time_start - datetime.fromtimestamp(job_requested) + ).seconds context_details = { **context_details, - "time_to_start": time_to_start, "runner_name": runner_name, "runner_public": runner_public, - "repository_private": repository_private + "repository_private": repository_private, } + if time_to_start: + context_details["time_to_start"] = time_to_start + elif action == "completed": job_requested = jobs.get(job_id) if not job_requested: - app.logger.warning(f"Job {job_id} is {action} but not stored!") + app.logger.error(f"Job {job_id} is {action} but not stored!") time_to_finish = 0 else: time_to_finish = ( @@ -102,7 +110,7 @@ def process_workflow_job(): context_details = { **context_details, "time_to_finish": time_to_finish, - "conclusion": conclusion + "conclusion": conclusion, } else: @@ -116,9 +124,7 @@ def process_workflow_job(): return True -allowed_events = { - "workflow_job": process_workflow_job -} +allowed_events = {"workflow_job": process_workflow_job} @app.route("/github-webhook", methods=["POST"]) diff --git a/tests/tests.py b/tests/tests.py index e4fc72c..aad826c 100644 --- a/tests/tests.py +++ b/tests/tests.py @@ -39,7 +39,7 @@ def test_headers_not_correct(client, caplog): response = client.post("/github-webhook") assert response.status_code == 401 assert caplog.messages == [ - "User-Agent is werkzeug/2.2.2", + "User-Agent is werkzeug/2.2.3", "Content is not JSON", "No GitHub Event received!", ] @@ -66,8 +66,8 @@ def test_started_job_not_stored(client, caplog): assert response.status_code == 200 assert caplog.messages == [ "Job 2 is in_progress but not stored!", - 'action=in_progress repository=foo/foo job_id=2 workflow=CI requestor=testerbot time_to_start=0 ' - 'runner_name= runner_public=false repository_private=false', + "action=in_progress repository=foo/foo job_id=2 workflow=CI requestor=testerbot " + "runner_name= runner_public=false repository_private=false", ] @@ -79,7 +79,7 @@ def test_finished_job_not_stored(client, caplog): assert response.status_code == 200 assert caplog.messages == [ "Job 3 is completed but not stored!", - 'action=completed repository=foo/foo job_id=3 workflow=CI requestor=testerbot time_to_finish=0 conclusion=', + "action=completed repository=foo/foo job_id=3 workflow=CI requestor=testerbot time_to_finish=0 conclusion=", ] @@ -93,7 +93,7 @@ def test_unknown_action(client, caplog): response = client.post("/github-webhook", headers=HEADERS, json=body_failed) assert response.status_code == 200 assert caplog.messages == [ - 'action=queued repository=foo/foo job_id=4 workflow=CI requestor=testerbot', + "action=queued repository=foo/foo job_id=4 workflow=CI requestor=testerbot", "Unknown action failed, removing from memory", ] @@ -105,7 +105,7 @@ def test_queued_job(client, caplog): response = client.post("/github-webhook", headers=HEADERS, json=body_queued) assert response.status_code == 200 assert caplog.messages == [ - 'action=queued repository=foo/foo job_id=1 workflow=CI requestor=testerbot' + "action=queued repository=foo/foo job_id=1 workflow=CI requestor=testerbot" ] @@ -117,7 +117,8 @@ def test_logging_flow(client, caplog): response = client.post("/github-webhook", headers=HEADERS, json=body_queued) assert response.status_code == 200 assert ( - caplog.messages[0] == 'action=queued repository=foo/foo job_id=5 workflow=CI requestor=testerbot' + caplog.messages[0] + == "action=queued repository=foo/foo job_id=5 workflow=CI requestor=testerbot" ) body_started = BODY.copy() @@ -127,9 +128,8 @@ def test_logging_flow(client, caplog): assert response.status_code == 200 assert ( caplog.messages[1] - == 'action=in_progress repository=foo/foo job_id=5 workflow=CI requestor=testerbot time_to_start=5 ' - 'runner_name= runner_public=false repository_private=false' - + == "action=in_progress repository=foo/foo job_id=5 workflow=CI requestor=testerbot " + "runner_name= runner_public=false repository_private=false time_to_start=5" ) body_completed = BODY.copy() @@ -140,6 +140,33 @@ def test_logging_flow(client, caplog): assert response.status_code == 200 assert ( caplog.messages[2] - == 'action=completed repository=foo/foo job_id=5 workflow=CI requestor=testerbot ' - 'time_to_finish=295 conclusion=success' + == "action=completed repository=foo/foo job_id=5 workflow=CI requestor=testerbot " + "time_to_finish=295 conclusion=success" + ) + + +def test_logging_flow_queued_after_in_progress(client, caplog): + body_queued = BODY.copy() + body_queued["action"] = "queued" + body_queued["workflow_job"]["id"] = 6 + body_queued["workflow_job"]["started_at"] = "2023-02-17T06:57:48Z" + + response = client.post("/github-webhook", headers=HEADERS, json=body_queued) + assert response.status_code == 200 + assert ( + caplog.messages[0] + == "action=queued repository=foo/foo job_id=6 workflow=CI requestor=testerbot" + ) + + body_started = BODY.copy() + body_started["action"] = "in_progress" + body_started["workflow_job"]["started_at"] = "2023-02-17T06:57:46Z" + response = client.post("/github-webhook", headers=HEADERS, json=body_started) + + assert response.status_code == 200 + assert caplog.messages[1] == "Job 6 was in progress before being queued" + assert ( + caplog.messages[2] + == "action=in_progress repository=foo/foo job_id=6 workflow=CI " + " requestor=testerbot runner_name= runner_public=false repository_private=false" )