From 9090d469b79b14d7b23d0af7e2728cd3146e0370 Mon Sep 17 00:00:00 2001 From: Forge Date: Thu, 16 Jul 2026 12:26:55 +0000 Subject: [PATCH 1/4] [AISOS-2201] Add structured start log to implement_task function Added an INFO-level structured log message at the beginning of task implementation in src/forge/workflow/nodes/implementation.py. Changes: - Added logger.info() call after fetching Jira task issue details - Log includes structured extra fields: event, task_name, feature_id, task_id - Handles empty task summary by defaulting to empty string - Special characters in task summary are logged as-is Closes: AISOS-2201 --- src/forge/workflow/nodes/implementation.py | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/forge/workflow/nodes/implementation.py b/src/forge/workflow/nodes/implementation.py index 6bf02cd6..9dd3765c 100644 --- a/src/forge/workflow/nodes/implementation.py +++ b/src/forge/workflow/nodes/implementation.py @@ -114,6 +114,16 @@ async def implement_task(state: WorkflowState) -> WorkflowState: task_description = task_issue.description or "" task_summary = task_issue.summary + logger.info( + f"Implementation started for task {current_task}", + extra={ + "event": "implementation_started", + "task_name": task_summary or "", + "feature_id": ticket_key, + "task_id": current_task, + }, + ) + # Post status comment at task implementation start await post_status_comment( jira, From cf59f0c92bd494eafa8b46a53bf5fc4a6ad8ea3d Mon Sep 17 00:00:00 2001 From: Forge Date: Thu, 16 Jul 2026 12:28:00 +0000 Subject: [PATCH 2/4] [AISOS-2202] Add structured end log on successful implementation Added INFO-level structured log message when implementation completes successfully: - Log is emitted after container completion, before status comment is posted - Uses logger.info() with structured extra dict containing: - event="implementation_completed" - task_name=task_summary - feature_id=ticket_key - task_id=current_task - success=True Closes: AISOS-2202 --- src/forge/workflow/nodes/implementation.py | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/src/forge/workflow/nodes/implementation.py b/src/forge/workflow/nodes/implementation.py index 9dd3765c..919ee1be 100644 --- a/src/forge/workflow/nodes/implementation.py +++ b/src/forge/workflow/nodes/implementation.py @@ -165,6 +165,18 @@ async def implement_task(state: WorkflowState) -> WorkflowState: if result.success: logger.info(f"Container completed successfully for {current_task}") + # Emit structured log for successful implementation + logger.info( + f"Implementation completed for task {current_task}", + extra={ + "event": "implementation_completed", + "task_name": task_summary, + "feature_id": ticket_key, + "task_id": current_task, + "success": True, + }, + ) + # Post status comment at task implementation completion await post_status_comment( jira, From 6064335ad500497d3469b9576f9fe610f3fa8a60 Mon Sep 17 00:00:00 2001 From: Forge Date: Thu, 16 Jul 2026 12:30:25 +0000 Subject: [PATCH 3/4] [AISOS-2203] Add structured end log on failed implementation Add INFO-level structured log when implementation fails: - Initialize task_summary to 'unknown' before Jira fetch for early failures (BR-003) - Add structured log in exception handler with event='implementation_ended' - Include task_name, feature_id, task_id, success=False in extra dict - Handle None current_task with 'unknown' placeholder Closes: AISOS-2203 --- src/forge/workflow/nodes/implementation.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/src/forge/workflow/nodes/implementation.py b/src/forge/workflow/nodes/implementation.py index 919ee1be..1d005f0e 100644 --- a/src/forge/workflow/nodes/implementation.py +++ b/src/forge/workflow/nodes/implementation.py @@ -108,6 +108,9 @@ async def implement_task(state: WorkflowState) -> WorkflowState: settings = get_settings() jira = JiraClient(settings) + # Initialize placeholder for early failure logging (BR-003) + task_summary = "unknown" + try: # Get Task details from Jira task_issue = await jira.get_issue(current_task) @@ -208,6 +211,17 @@ async def implement_task(state: WorkflowState) -> WorkflowState: except Exception as e: logger.error(f"Implementation failed for {current_task}: {e}") + # Emit structured end log for failed implementation + logger.info( + f"Implementation ended for task {current_task or 'unknown'}", + extra={ + "event": "implementation_ended", + "task_name": task_summary, + "feature_id": ticket_key, + "task_id": current_task or "unknown", + "success": False, + }, + ) return { **state, "last_error": str(e), From abced54e886c27fa7ee17dc68e1ece3e910d1422 Mon Sep 17 00:00:00 2001 From: Forge Date: Thu, 16 Jul 2026 12:33:47 +0000 Subject: [PATCH 4/4] [AISOS-2204] Add unit tests for structured logging in implement_task Added TestImplementTaskStructuredLogging test class with 7 test methods: - test_logs_implementation_started_with_structured_fields (TS-001) - test_logs_implementation_completed_on_success (TS-002) - test_logs_implementation_ended_on_failure (TS-003) - test_logs_implementation_ended_on_exception (TS-004) - test_logs_unknown_task_name_when_jira_fails_early (TS-005) - test_logs_empty_task_summary_as_empty_string (TS-006) - test_logs_special_characters_in_task_summary (TS-007) Tests use caplog fixture to capture log records and verify: - Log level is INFO - Presence of event, task_name, feature_id, task_id fields - success field on end logs (True/False) - Correct placeholder handling for early failures Closes: AISOS-2204 --- .../workflow/nodes/test_implementation.py | 252 +++++++++++++++++- 1 file changed, 250 insertions(+), 2 deletions(-) diff --git a/tests/unit/workflow/nodes/test_implementation.py b/tests/unit/workflow/nodes/test_implementation.py index 64aeac11..036e7cc0 100644 --- a/tests/unit/workflow/nodes/test_implementation.py +++ b/tests/unit/workflow/nodes/test_implementation.py @@ -56,7 +56,6 @@ def _make_successful_runner(): class TestImplementTaskStartedComment: - @pytest.mark.asyncio async def test_posts_comment_on_task_ticket_before_container(self): """A comment is posted on the task ticket (not parent) when implementation starts.""" @@ -184,7 +183,6 @@ async def test_passes_trace_context_to_container_runner(self): class TestImplementationNodeRouting: - @pytest.mark.asyncio async def test_feature_missing_workspace_uses_feature_implementation_node(self): """Feature implementation failures must resume at implement_task.""" @@ -270,3 +268,253 @@ async def test_bug_container_failure_keeps_bug_implementation_node(self): assert result["current_node"] == "implement_bug_fix" assert result["last_error"] == "container failed" assert result["retry_count"] == 1 + + +class TestImplementTaskStructuredLogging: + """Tests for structured logging in implement_task (TS-001 through TS-007).""" + + @pytest.mark.asyncio + async def test_logs_implementation_started_with_structured_fields(self, caplog): + """TS-001: Start log has correct extra fields.""" + from forge.workflow.nodes.implementation import implement_task + + mock_jira = _make_mock_jira(summary="Add new API endpoint") + runner = _make_successful_runner() + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch( + "forge.workflow.nodes.implementation.ContainerRunner", + return_value=runner, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the start log record + start_logs = [ + r for r in caplog.records if "implementation_started" in str(getattr(r, "event", "")) + ] + assert len(start_logs) == 1 + record = start_logs[0] + + assert record.levelname == "INFO" + assert record.event == "implementation_started" + assert record.task_name == "Add new API endpoint" + assert record.feature_id == "FEAT-100" + assert record.task_id == "TASK-200" + + @pytest.mark.asyncio + async def test_logs_implementation_completed_on_success(self, caplog): + """TS-002: Success end log has success=True.""" + from forge.workflow.nodes.implementation import implement_task + + mock_jira = _make_mock_jira(summary="Fix login bug") + runner = _make_successful_runner() + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch( + "forge.workflow.nodes.implementation.ContainerRunner", + return_value=runner, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the completion log record + end_logs = [ + r for r in caplog.records if "implementation_completed" in str(getattr(r, "event", "")) + ] + assert len(end_logs) == 1 + record = end_logs[0] + + assert record.levelname == "INFO" + assert record.event == "implementation_completed" + assert record.task_name == "Fix login bug" + assert record.feature_id == "FEAT-100" + assert record.task_id == "TASK-200" + assert record.success is True + + @pytest.mark.asyncio + async def test_logs_implementation_ended_on_failure(self, caplog): + """TS-003: Failure end log has success=False.""" + from forge.workflow.nodes.implementation import implement_task + + mock_jira = _make_mock_jira(summary="Refactor database") + runner = MagicMock() + result = MagicMock() + result.success = False + result.error_message = "Container crashed" + runner.run = AsyncMock(return_value=result) + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch( + "forge.workflow.nodes.implementation.ContainerRunner", + return_value=runner, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the end log record + end_logs = [ + r for r in caplog.records if "implementation_ended" in str(getattr(r, "event", "")) + ] + assert len(end_logs) == 1 + record = end_logs[0] + + assert record.levelname == "INFO" + assert record.event == "implementation_ended" + assert record.task_name == "Refactor database" + assert record.feature_id == "FEAT-100" + assert record.task_id == "TASK-200" + assert record.success is False + + @pytest.mark.asyncio + async def test_logs_implementation_ended_on_exception(self, caplog): + """TS-004: Exception path emits end log with success=False.""" + from forge.workflow.nodes.implementation import implement_task + + mock_jira = _make_mock_jira(summary="Add feature X") + runner = MagicMock() + runner.run = AsyncMock(side_effect=RuntimeError("Network timeout")) + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch( + "forge.workflow.nodes.implementation.ContainerRunner", + return_value=runner, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the end log record + end_logs = [ + r for r in caplog.records if "implementation_ended" in str(getattr(r, "event", "")) + ] + assert len(end_logs) == 1 + record = end_logs[0] + + assert record.levelname == "INFO" + assert record.event == "implementation_ended" + assert record.task_name == "Add feature X" + assert record.feature_id == "FEAT-100" + assert record.task_id == "TASK-200" + assert record.success is False + + @pytest.mark.asyncio + async def test_logs_unknown_task_name_when_jira_fails_early(self, caplog): + """TS-005: Placeholder handling when Jira fails before getting summary.""" + from forge.workflow.nodes.implementation import implement_task + + mock_jira = AsyncMock() + mock_jira.get_issue = AsyncMock(side_effect=Exception("Jira unavailable")) + mock_jira.close = AsyncMock() + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the end log record + end_logs = [ + r for r in caplog.records if "implementation_ended" in str(getattr(r, "event", "")) + ] + assert len(end_logs) == 1 + record = end_logs[0] + + assert record.levelname == "INFO" + assert record.event == "implementation_ended" + assert record.task_name == "unknown" + assert record.feature_id == "FEAT-100" + assert record.task_id == "TASK-200" + assert record.success is False + + @pytest.mark.asyncio + async def test_logs_empty_task_summary_as_empty_string(self, caplog): + """TS-006: Empty summary handling.""" + from forge.workflow.nodes.implementation import implement_task + + mock_jira = _make_mock_jira(summary="") + runner = _make_successful_runner() + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch( + "forge.workflow.nodes.implementation.ContainerRunner", + return_value=runner, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the start log record + start_logs = [ + r for r in caplog.records if "implementation_started" in str(getattr(r, "event", "")) + ] + assert len(start_logs) == 1 + record = start_logs[0] + + assert record.levelname == "INFO" + assert record.task_name == "" + + @pytest.mark.asyncio + async def test_logs_special_characters_in_task_summary(self, caplog): + """TS-007: Special characters not escaped in task_name.""" + from forge.workflow.nodes.implementation import implement_task + + special_summary = 'Fix "quotes" & and newline\nhere' + mock_jira = _make_mock_jira(summary=special_summary) + runner = _make_successful_runner() + + with ( + caplog.at_level("INFO", logger="forge.workflow.nodes.implementation"), + patch( + "forge.workflow.nodes.implementation.JiraClient", + return_value=mock_jira, + ), + patch( + "forge.workflow.nodes.implementation.ContainerRunner", + return_value=runner, + ), + patch("forge.workflow.nodes.implementation.get_settings"), + ): + await implement_task(_make_state(ticket_key="FEAT-100", current_task_key="TASK-200")) + + # Find the start log record + start_logs = [ + r for r in caplog.records if "implementation_started" in str(getattr(r, "event", "")) + ] + assert len(start_logs) == 1 + record = start_logs[0] + + # Special characters should be preserved exactly as-is + assert record.task_name == special_summary