From 3a8a9121de9cf0d1d8b12c019f2f997338ead1a0 Mon Sep 17 00:00:00 2001 From: Mason Egger Date: Mon, 17 Mar 2025 17:48:04 -0500 Subject: [PATCH 1/4] Fixing indent issue with kwargs["extra"] --- temporalio/workflow.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/temporalio/workflow.py b/temporalio/workflow.py index 0a298a032..a3127e623 100644 --- a/temporalio/workflow.py +++ b/temporalio/workflow.py @@ -1175,9 +1175,9 @@ async def sleep( This can be in single-line Temporal markdown format. """ await _Runtime.current().workflow_sleep( - duration=duration.total_seconds() - if isinstance(duration, timedelta) - else duration, + duration=( + duration.total_seconds() if isinstance(duration, timedelta) else duration + ), summary=summary, ) @@ -1361,7 +1361,7 @@ def process( if self.workflow_info_on_extra: extra.setdefault("temporal_workflow", {}).update(update_details) - kwargs["extra"] = {**extra, **(kwargs.get("extra") or {})} + kwargs["extra"] = {**extra, **(kwargs.get("extra") or {})} if msg_extra: msg = f"{msg} ({msg_extra})" return (msg, kwargs) From 3c92a2eb992b69fc796c3d1bd97ab12e95d20ac7 Mon Sep 17 00:00:00 2001 From: Mason Egger Date: Mon, 17 Mar 2025 17:52:04 -0500 Subject: [PATCH 2/4] undoing something my autoformatter tried to fix --- temporalio/workflow.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/temporalio/workflow.py b/temporalio/workflow.py index a3127e623..0a7091d67 100644 --- a/temporalio/workflow.py +++ b/temporalio/workflow.py @@ -1175,9 +1175,9 @@ async def sleep( This can be in single-line Temporal markdown format. """ await _Runtime.current().workflow_sleep( - duration=( - duration.total_seconds() if isinstance(duration, timedelta) else duration - ), + duration=duration.total_seconds() + if isinstance(duration, timedelta) + else duration, summary=summary, ) From 052abb7446865c32a8950ce71624d48dd1e073b4 Mon Sep 17 00:00:00 2001 From: Mason Egger Date: Mon, 17 Mar 2025 17:54:58 -0500 Subject: [PATCH 3/4] indent other two lines --- temporalio/workflow.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/temporalio/workflow.py b/temporalio/workflow.py index 0a7091d67..0b741a927 100644 --- a/temporalio/workflow.py +++ b/temporalio/workflow.py @@ -1362,8 +1362,8 @@ def process( extra.setdefault("temporal_workflow", {}).update(update_details) kwargs["extra"] = {**extra, **(kwargs.get("extra") or {})} - if msg_extra: - msg = f"{msg} ({msg_extra})" + if msg_extra: + msg = f"{msg} ({msg_extra})" return (msg, kwargs) def isEnabledFor(self, level: int) -> bool: From c1756c69e2c1e6323d4b58174c444d568bc1a3c7 Mon Sep 17 00:00:00 2001 From: Dan Davison Date: Mon, 17 Mar 2025 21:16:24 -0400 Subject: [PATCH 4/4] Extend logging tests to cover no-info branch with bug --- tests/worker/test_workflow.py | 77 +++++++++++++++++++++++++---------- 1 file changed, 55 insertions(+), 22 deletions(-) diff --git a/tests/worker/test_workflow.py b/tests/worker/test_workflow.py index 665a5393e..86acca464 100644 --- a/tests/worker/test_workflow.py +++ b/tests/worker/test_workflow.py @@ -1948,8 +1948,29 @@ def find_log(self, starts_with: str) -> Optional[logging.LogRecord]: return None -async def test_workflow_logging(client: Client, env: WorkflowEnvironment): - workflow.logger.full_workflow_info_on_extra = True +@pytest.mark.parametrize( + "with_workflow_info", + [True, False], +) +async def test_workflow_logging( + client: Client, env: WorkflowEnvironment, with_workflow_info: bool +): + orig_on_message = workflow.logger.workflow_info_on_message + orig_on_extra = workflow.logger.workflow_info_on_extra + orig_full_on_extra = workflow.logger.full_workflow_info_on_extra + + try: + workflow.logger.workflow_info_on_message = with_workflow_info + workflow.logger.workflow_info_on_extra = with_workflow_info + workflow.logger.full_workflow_info_on_extra = with_workflow_info + await _do_workflow_logging_test(client, with_workflow_info) + finally: + workflow.logger.workflow_info_on_message = orig_on_message + workflow.logger.workflow_info_on_extra = orig_on_extra + workflow.logger.full_workflow_info_on_extra = orig_full_on_extra + + +async def _do_workflow_logging_test(client: Client, with_workflow_info: bool): with LogCapturer().logs_captured( workflow.logger.base_logger, activity.logger.base_logger ) as capturer: @@ -1976,30 +1997,42 @@ async def test_workflow_logging(client: Client, env: WorkflowEnvironment): assert "signal 2" == await handle.query(LoggingWorkflow.last_signal) # Confirm logs were produced - assert capturer.find_log("Signal: signal 1 ({'attempt':") + assert capturer.find_log("Signal: signal 1") assert capturer.find_log("Signal: signal 2") assert capturer.find_log("Update: update 1") assert capturer.find_log("Update: update 2") assert not capturer.find_log("Signal: signal 3") - # Also make sure it has some workflow info and correct funcName - record = capturer.find_log("Signal: signal 1") - assert ( - record - and record.__dict__["temporal_workflow"]["workflow_type"] - == "LoggingWorkflow" - and record.funcName == "my_signal" - ) - # Since we enabled full info, make sure it's there - assert isinstance(record.__dict__["workflow_info"], workflow.Info) - # Check the log emitted by the update execution. - record = capturer.find_log("Update: update 1") - assert ( - record - and record.__dict__["temporal_workflow"]["update_id"] == "update-1" - and record.__dict__["temporal_workflow"]["update_name"] == "my_update" - and "'update_id': 'update-1'" in record.message - and "'update_name': 'my_update'" in record.message - ) + + if with_workflow_info: + record = capturer.find_log("Signal: signal 1 ({'attempt':") + assert ( + record + and record.__dict__["temporal_workflow"]["workflow_type"] + == "LoggingWorkflow" + and record.funcName == "my_signal" + ) + # Since we enabled full info, make sure it's there + assert isinstance(record.__dict__["workflow_info"], workflow.Info) + + # Check the log emitted by the update execution. + record = capturer.find_log("Update: update 1") + assert ( + record + and record.__dict__["temporal_workflow"]["update_id"] == "update-1" + and record.__dict__["temporal_workflow"]["update_name"] == "my_update" + and "'update_id': 'update-1'" in record.message + and "'update_name': 'my_update'" in record.message + ) + else: + record = capturer.find_log("Signal: signal 1") + assert record and "temporal_workflow" not in record.__dict__ + assert record and "workflow_info" not in record.__dict__ + + record = capturer.find_log("Update: update 1") + assert record and "temporal_workflow" not in record.__dict__ + assert record and "workflow_info" not in record.__dict__ + assert "'update_id': 'update-1'" not in record.message + assert "'update_name': 'my_update'" not in record.message # Clear queue and start a new one with more signals capturer.log_queue.queue.clear()