Skip to content

Commit 8637904

Browse files
committed
Remove logger handlers in tests
1 parent 9b40dec commit 8637904

3 files changed

Lines changed: 104 additions & 91 deletions

File tree

tests/test_runtime.py

Lines changed: 74 additions & 65 deletions
Original file line numberDiff line numberDiff line change
@@ -80,8 +80,8 @@ async def test_runtime_log_forwarding():
8080
# Create logger with record capture
8181
log_queue: queue.Queue[logging.LogRecord] = queue.Queue()
8282
log_queue_list = cast(list[logging.LogRecord], log_queue.queue)
83+
handler = logging.handlers.QueueHandler(log_queue)
8384
logger = logging.getLogger(f"log-{uuid.uuid4()}")
84-
logger.addHandler(logging.handlers.QueueHandler(log_queue))
8585

8686
async def log_queue_len() -> int:
8787
return len(log_queue_list)
@@ -96,49 +96,53 @@ async def log_queue_len() -> int:
9696
)
9797
)
9898

99-
# Set capture only info logs
100-
logger.setLevel(logging.INFO)
101-
# Write some logs
102-
runtime._core_runtime.write_test_info_log("info1", "extra1")
103-
runtime._core_runtime.write_test_debug_log("debug2", "extra2")
104-
runtime._core_runtime.write_test_info_log("info3", "extra3")
105-
106-
# Check the expected records
107-
await assert_eq_eventually(2, log_queue_len)
108-
assert log_queue_list[0].levelno == logging.INFO
109-
assert log_queue_list[0].message.startswith(
110-
"[sdk_core::temporal_sdk_bridge::runtime] info1"
111-
)
112-
assert (
113-
log_queue_list[0].name
114-
== f"{logger.name}-sdk_core::temporal_sdk_bridge::runtime"
115-
)
116-
assert log_queue_list[0].created == log_queue_list[0].temporal_log.time # type: ignore
117-
assert log_queue_list[0].temporal_log.fields == {"extra_data": "extra1"} # type: ignore
118-
assert log_queue_list[1].levelno == logging.INFO
119-
assert log_queue_list[1].message.startswith(
120-
"[sdk_core::temporal_sdk_bridge::runtime] info3"
121-
)
99+
logger.addHandler(handler)
100+
try:
101+
# Set capture only info logs
102+
logger.setLevel(logging.INFO)
103+
# Write some logs
104+
runtime._core_runtime.write_test_info_log("info1", "extra1")
105+
runtime._core_runtime.write_test_debug_log("debug2", "extra2")
106+
runtime._core_runtime.write_test_info_log("info3", "extra3")
107+
108+
# Check the expected records
109+
await assert_eq_eventually(2, log_queue_len)
110+
assert log_queue_list[0].levelno == logging.INFO
111+
assert log_queue_list[0].message.startswith(
112+
"[sdk_core::temporal_sdk_bridge::runtime] info1"
113+
)
114+
assert (
115+
log_queue_list[0].name
116+
== f"{logger.name}-sdk_core::temporal_sdk_bridge::runtime"
117+
)
118+
assert log_queue_list[0].created == log_queue_list[0].temporal_log.time # type: ignore
119+
assert log_queue_list[0].temporal_log.fields == {"extra_data": "extra1"} # type: ignore
120+
assert log_queue_list[1].levelno == logging.INFO
121+
assert log_queue_list[1].message.startswith(
122+
"[sdk_core::temporal_sdk_bridge::runtime] info3"
123+
)
122124

123-
# Clear logs and enable debug and try again
124-
log_queue_list.clear()
125-
logger.setLevel(logging.DEBUG)
126-
runtime._core_runtime.write_test_info_log("info4", "extra4")
127-
runtime._core_runtime.write_test_debug_log("debug5", "extra5")
128-
runtime._core_runtime.write_test_info_log("info6", "extra6")
129-
await assert_eq_eventually(3, log_queue_len)
130-
assert log_queue_list[0].levelno == logging.INFO
131-
assert log_queue_list[0].message.startswith(
132-
"[sdk_core::temporal_sdk_bridge::runtime] info4"
133-
)
134-
assert log_queue_list[1].levelno == logging.DEBUG
135-
assert log_queue_list[1].message.startswith(
136-
"[sdk_core::temporal_sdk_bridge::runtime] debug5"
137-
)
138-
assert log_queue_list[2].levelno == logging.INFO
139-
assert log_queue_list[2].message.startswith(
140-
"[sdk_core::temporal_sdk_bridge::runtime] info6"
141-
)
125+
# Clear logs and enable debug and try again
126+
log_queue_list.clear()
127+
logger.setLevel(logging.DEBUG)
128+
runtime._core_runtime.write_test_info_log("info4", "extra4")
129+
runtime._core_runtime.write_test_debug_log("debug5", "extra5")
130+
runtime._core_runtime.write_test_info_log("info6", "extra6")
131+
await assert_eq_eventually(3, log_queue_len)
132+
assert log_queue_list[0].levelno == logging.INFO
133+
assert log_queue_list[0].message.startswith(
134+
"[sdk_core::temporal_sdk_bridge::runtime] info4"
135+
)
136+
assert log_queue_list[1].levelno == logging.DEBUG
137+
assert log_queue_list[1].message.startswith(
138+
"[sdk_core::temporal_sdk_bridge::runtime] debug5"
139+
)
140+
assert log_queue_list[2].levelno == logging.INFO
141+
assert log_queue_list[2].message.startswith(
142+
"[sdk_core::temporal_sdk_bridge::runtime] info6"
143+
)
144+
finally:
145+
logger.removeHandler(handler)
142146

143147

144148
@workflow.defn
@@ -152,8 +156,8 @@ async def test_runtime_task_fail_log_forwarding(client: Client):
152156
# Client with lo capturing runtime
153157
log_queue: queue.Queue[logging.LogRecord] = queue.Queue()
154158
log_queue_list = cast(list[logging.LogRecord], log_queue.queue)
159+
handler = logging.handlers.QueueHandler(log_queue)
155160
logger = logging.getLogger(f"log-{uuid.uuid4()}")
156-
logger.addHandler(logging.handlers.QueueHandler(log_queue))
157161
logger.setLevel(logging.WARN)
158162
client = await Client.connect(
159163
client.service_client.config.target_host,
@@ -168,30 +172,35 @@ async def test_runtime_task_fail_log_forwarding(client: Client):
168172
),
169173
)
170174

171-
# Start workflow
172-
task_queue = f"task-queue-{uuid.uuid4()}"
173-
async with Worker(client, task_queue=task_queue, workflows=[TaskFailWorkflow]):
174-
handle = await client.start_workflow(
175-
TaskFailWorkflow.run,
176-
id=f"workflow-{uuid.uuid4()}",
177-
task_queue=task_queue,
178-
)
179-
180-
# Wait for log to appear
181-
async def has_log() -> bool:
182-
return any(
183-
l for l in log_queue_list if "Failing workflow task" in l.message
175+
logger.addHandler(handler)
176+
try:
177+
# Start workflow
178+
task_queue = f"task-queue-{uuid.uuid4()}"
179+
async with Worker(client, task_queue=task_queue, workflows=[TaskFailWorkflow]):
180+
handle = await client.start_workflow(
181+
TaskFailWorkflow.run,
182+
id=f"workflow-{uuid.uuid4()}",
183+
task_queue=task_queue,
184184
)
185185

186-
await assert_eq_eventually(True, has_log)
186+
# Wait for log to appear
187+
async def has_log() -> bool:
188+
return any(
189+
l for l in log_queue_list if "Failing workflow task" in l.message
190+
)
187191

188-
# Check record
189-
record = next(l for l in log_queue_list if "Failing workflow task" in l.message)
190-
assert record.levelno == logging.WARNING
191-
assert (
192-
record.name == f"{logger.name}-sdk_core::temporalio_sdk_core::worker::workflow"
193-
)
194-
assert record.temporal_log.fields["run_id"] == handle.result_run_id # type: ignore
192+
await assert_eq_eventually(True, has_log)
193+
194+
# Check record
195+
record = next(l for l in log_queue_list if "Failing workflow task" in l.message)
196+
assert record.levelno == logging.WARNING
197+
assert (
198+
record.name
199+
== f"{logger.name}-sdk_core::temporalio_sdk_core::worker::workflow"
200+
)
201+
assert record.temporal_log.fields["run_id"] == handle.result_run_id # type: ignore
202+
finally:
203+
logger.removeHandler(handler)
195204

196205

197206
async def test_prometheus_histogram_bucket_overrides(client: Client):

tests/worker/test_activity.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1687,7 +1687,7 @@ async def raise_error():
16871687
assert handler._trace_identifiers == 1
16881688

16891689
finally:
1690-
activity.logger.base_logger.removeHandler(CustomLogHandler())
1690+
activity.logger.base_logger.removeHandler(handler)
16911691

16921692

16931693
async def test_activity_heartbeat_context(

tests/worker/test_workflow.py

Lines changed: 29 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -8445,41 +8445,45 @@ async def run(self):
84458445

84468446
class CustomLogHandler(logging.Handler):
84478447
def emit(self, record: logging.LogRecord) -> None:
8448-
import httpx # type: ignore[reportUnusedImport]
8448+
import httpx # type: ignore[reportUnusedImport] # noqa
84498449

84508450

84518451
async def test_disable_logger_sandbox(
84528452
client: Client,
84538453
):
84548454
logger = workflow.logger.logger
8455-
logger.addHandler(CustomLogHandler())
8456-
async with new_worker(
8457-
client,
8458-
DisableLoggerSandbox,
8459-
activities=[],
8460-
) as worker:
8461-
with pytest.raises(WorkflowFailureError):
8462-
await client.execute_workflow(
8463-
DisableLoggerSandbox.run,
8464-
id=f"workflow-{uuid.uuid4()}",
8465-
task_queue=worker.task_queue,
8466-
run_timeout=timedelta(seconds=1),
8467-
retry_policy=RetryPolicy(maximum_attempts=1),
8468-
)
8469-
workflow.logger.unsafe_disable_sandbox()
8470-
await client.execute_workflow(
8471-
DisableLoggerSandbox.run,
8472-
id=f"workflow-{uuid.uuid4()}",
8473-
task_queue=worker.task_queue,
8474-
run_timeout=timedelta(seconds=1),
8475-
retry_policy=RetryPolicy(maximum_attempts=1),
8476-
)
8477-
workflow.logger.unsafe_disable_sandbox(False)
8478-
with pytest.raises(WorkflowFailureError):
8455+
handler = CustomLogHandler()
8456+
logger.addHandler(handler)
8457+
try:
8458+
async with new_worker(
8459+
client,
8460+
DisableLoggerSandbox,
8461+
activities=[],
8462+
) as worker:
8463+
with pytest.raises(WorkflowFailureError):
8464+
await client.execute_workflow(
8465+
DisableLoggerSandbox.run,
8466+
id=f"workflow-{uuid.uuid4()}",
8467+
task_queue=worker.task_queue,
8468+
run_timeout=timedelta(seconds=1),
8469+
retry_policy=RetryPolicy(maximum_attempts=1),
8470+
)
8471+
workflow.logger.unsafe_disable_sandbox()
84798472
await client.execute_workflow(
84808473
DisableLoggerSandbox.run,
84818474
id=f"workflow-{uuid.uuid4()}",
84828475
task_queue=worker.task_queue,
84838476
run_timeout=timedelta(seconds=1),
84848477
retry_policy=RetryPolicy(maximum_attempts=1),
84858478
)
8479+
workflow.logger.unsafe_disable_sandbox(False)
8480+
with pytest.raises(WorkflowFailureError):
8481+
await client.execute_workflow(
8482+
DisableLoggerSandbox.run,
8483+
id=f"workflow-{uuid.uuid4()}",
8484+
task_queue=worker.task_queue,
8485+
run_timeout=timedelta(seconds=1),
8486+
retry_policy=RetryPolicy(maximum_attempts=1),
8487+
)
8488+
finally:
8489+
logger.removeHandler(handler)

0 commit comments

Comments
 (0)