Skip to content

Commit 151c50a

Browse files
committed
Refactor ReplaySafeLogger to use LoggerAdapter, add tests and docs
- Rewrite ReplaySafeLogger as a logging.LoggerAdapter subclass with a single isEnabledFor() override instead of manual method delegation - Add log() and isEnabledFor() methods with tests - Add replay-safe logging section to docs/features.md - Add usage example in examples/activity_sequence.py - Add cross-package compatibility section to copilot-instructions.md
1 parent 0cbcf48 commit 151c50a

5 files changed

Lines changed: 124 additions & 36 deletions

File tree

.github/copilot-instructions.md

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -107,3 +107,18 @@ python -m pytest
107107
- `examples/` — example orchestrations (see `examples/README.md`)
108108
- `tests/` — test suite
109109
- `dev-requirements.txt` — development dependencies
110+
111+
## Cross-Package Compatibility
112+
113+
The `durabletask-azuremanaged` package extends the core `durabletask`
114+
package (e.g. `DurableTaskSchedulerWorker` subclasses
115+
`TaskHubGrpcWorker`). When adding or changing features in
116+
`durabletask/`, always verify that `durabletask-azuremanaged` still
117+
works correctly:
118+
119+
- Check whether the azuremanaged worker, client, or tests override or
120+
depend on the code you changed.
121+
- Run the azuremanaged unit tests if they exist for the affected area.
122+
- If a new public API is added to the core SDK (e.g. a method on
123+
`OrchestrationContext`), confirm it is accessible through the
124+
azuremanaged package and add a test or example if appropriate.

docs/features.md

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -150,6 +150,47 @@ Orchestrations can be suspended using the `suspend_orchestration` client API and
150150

151151
Orchestrations can specify retry policies for activities and sub-orchestrations. These policies control how many times and how frequently an activity or sub-orchestration will be retried in the event of a transient error.
152152

153+
### Replay-safe logging
154+
155+
Orchestrator functions replay their history each time they are resumed,
156+
which can cause duplicate log messages. The `create_replay_safe_logger`
157+
method on `OrchestrationContext` returns a `ReplaySafeLogger` that wraps
158+
a standard `logging.Logger` and automatically suppresses output while
159+
the orchestrator is replaying. `ReplaySafeLogger` extends Python's
160+
`logging.LoggerAdapter`, which is the idiomatic way to add context or
161+
modify behavior on an existing logger.
162+
163+
```python
164+
import logging
165+
166+
logger = logging.getLogger("my_orchestrator")
167+
168+
def my_orchestrator(ctx: task.OrchestrationContext, input):
169+
replay_logger = ctx.create_replay_safe_logger(logger)
170+
replay_logger.info("Starting orchestration %s", ctx.instance_id)
171+
result = yield ctx.call_activity(my_activity, input=input)
172+
replay_logger.info("Activity returned: %s", result)
173+
return result
174+
```
175+
176+
> [!NOTE]
177+
> Unlike the .NET SDK, where `CreateReplaySafeLogger` accepts a
178+
> category name string and internally creates the logger via
179+
> `ILoggerFactory`, the Python SDK requires you to pass an existing
180+
> `logging.Logger` instance. This is because Python's
181+
> `logging.getLogger(name)` already serves as the global factory and
182+
> is the standard way to obtain loggers.
183+
184+
The replay-safe logger supports all standard log levels: `debug`,
185+
`info`, `warning`, `error`, `critical`, and `exception`, as well as
186+
the generic `log(level, msg)` method. It also exposes `isEnabledFor`
187+
which returns `False` during replay so callers can skip expensive
188+
message formatting.
189+
190+
> [!TIP]
191+
> Create the replay-safe logger once at the start of your orchestrator
192+
> and reuse it throughout the function.
193+
153194
### Large payload externalization
154195

155196
Orchestration inputs, outputs, and event data are transmitted through

durabletask/task.py

Lines changed: 13 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -300,10 +300,10 @@ def create_replay_safe_logger(self, logger: logging.Logger) -> ReplaySafeLogger:
300300
return ReplaySafeLogger(logger, lambda: self.is_replaying)
301301

302302

303-
class ReplaySafeLogger:
304-
"""A logger wrapper that suppresses log messages during orchestration replay.
303+
class ReplaySafeLogger(logging.LoggerAdapter):
304+
"""A logger adapter that suppresses log messages during orchestration replay.
305305
306-
This class wraps a standard :class:`logging.Logger` and only emits log
306+
This class extends :class:`logging.LoggerAdapter` and only emits log
307307
messages when the orchestrator is *not* replaying. Use this to avoid
308308
duplicate log entries that would otherwise appear every time the
309309
orchestrator replays its history.
@@ -312,41 +312,18 @@ class ReplaySafeLogger:
312312
"""
313313

314314
def __init__(self, logger: logging.Logger, is_replaying: Callable[[], bool]) -> None:
315-
self._logger = logger
315+
super().__init__(logger, {})
316316
self._is_replaying = is_replaying
317317

318-
def _should_log(self) -> bool:
319-
return not self._is_replaying()
320-
321-
def debug(self, msg: str, *args: Any, **kwargs: Any) -> None:
322-
"""Log a DEBUG-level message if the orchestrator is not replaying."""
323-
if self._should_log():
324-
self._logger.debug(msg, *args, **kwargs)
325-
326-
def info(self, msg: str, *args: Any, **kwargs: Any) -> None:
327-
"""Log an INFO-level message if the orchestrator is not replaying."""
328-
if self._should_log():
329-
self._logger.info(msg, *args, **kwargs)
330-
331-
def warning(self, msg: str, *args: Any, **kwargs: Any) -> None:
332-
"""Log a WARNING-level message if the orchestrator is not replaying."""
333-
if self._should_log():
334-
self._logger.warning(msg, *args, **kwargs)
335-
336-
def error(self, msg: str, *args: Any, **kwargs: Any) -> None:
337-
"""Log an ERROR-level message if the orchestrator is not replaying."""
338-
if self._should_log():
339-
self._logger.error(msg, *args, **kwargs)
340-
341-
def critical(self, msg: str, *args: Any, **kwargs: Any) -> None:
342-
"""Log a CRITICAL-level message if the orchestrator is not replaying."""
343-
if self._should_log():
344-
self._logger.critical(msg, *args, **kwargs)
345-
346-
def exception(self, msg: str, *args: Any, **kwargs: Any) -> None:
347-
"""Log an ERROR-level message with exception info if the orchestrator is not replaying."""
348-
if self._should_log():
349-
self._logger.exception(msg, *args, **kwargs)
318+
def isEnabledFor(self, level: int) -> bool:
319+
"""Return whether logging is enabled for the given level.
320+
321+
Returns ``False`` while the orchestrator is replaying so that callers
322+
can skip expensive message formatting during replay.
323+
"""
324+
if self._is_replaying():
325+
return False
326+
return self.logger.isEnabledFor(level)
350327

351328

352329
class FailureDetails:

examples/activity_sequence.py

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
"""End-to-end sample that demonstrates how to configure an orchestrator
22
that calls an activity function in a sequence and prints the outputs."""
3+
import logging
34
import os
45

56
from azure.identity import DefaultAzureCredential
@@ -8,6 +9,8 @@
89
from durabletask.azuremanaged.client import DurableTaskSchedulerClient
910
from durabletask.azuremanaged.worker import DurableTaskSchedulerWorker
1011

12+
logger = logging.getLogger("activity_sequence")
13+
1114

1215
def hello(ctx: task.ActivityContext, name: str) -> str:
1316
"""Activity function that returns a greeting"""
@@ -16,10 +19,15 @@ def hello(ctx: task.ActivityContext, name: str) -> str:
1619

1720
def sequence(ctx: task.OrchestrationContext, _):
1821
"""Orchestrator function that calls the 'hello' activity function in a sequence"""
22+
# Create a replay-safe logger to avoid duplicate log messages during replay
23+
replay_logger = ctx.create_replay_safe_logger(logger)
24+
25+
replay_logger.info("Starting activity sequence for instance %s", ctx.instance_id)
1926
# call "hello" activity function in a sequence
2027
result1 = yield ctx.call_activity(hello, input='Tokyo')
2128
result2 = yield ctx.call_activity(hello, input='Seattle')
2229
result3 = yield ctx.call_activity(hello, input='London')
30+
replay_logger.info("All activities completed")
2331

2432
# return an array of results
2533
return [result1, result2, result3]

tests/durabletask/test_orchestration_executor.py

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1269,6 +1269,53 @@ def emit(self, record: logging.LogRecord) -> None:
12691269
assert log_calls == ["should appear"]
12701270

12711271

1272+
def test_replay_safe_logger_log_method():
1273+
"""Validates the generic log() method respects the replay flag."""
1274+
log_calls: list[str] = []
1275+
1276+
class _RecordingHandler(logging.Handler):
1277+
def emit(self, record: logging.LogRecord) -> None:
1278+
log_calls.append(record.getMessage())
1279+
1280+
inner_logger = logging.getLogger("test_replay_safe_logger_log_method")
1281+
inner_logger.setLevel(logging.DEBUG)
1282+
inner_logger.addHandler(_RecordingHandler())
1283+
1284+
replaying = True
1285+
replay_logger = task.ReplaySafeLogger(inner_logger, lambda: replaying)
1286+
1287+
replay_logger.log(logging.WARNING, "suppressed warning")
1288+
assert log_calls == []
1289+
1290+
replaying = False
1291+
replay_logger.log(logging.WARNING, "visible warning")
1292+
assert log_calls == ["visible warning"]
1293+
1294+
1295+
def test_replay_safe_logger_is_enabled_for():
1296+
"""Validates isEnabledFor returns False during replay."""
1297+
inner_logger = logging.getLogger("test_replay_safe_logger_enabled")
1298+
inner_logger.setLevel(logging.DEBUG)
1299+
1300+
replaying = True
1301+
replay_logger = task.ReplaySafeLogger(inner_logger, lambda: replaying)
1302+
1303+
# During replay, isEnabledFor should always return False
1304+
assert replay_logger.isEnabledFor(logging.DEBUG) is False
1305+
assert replay_logger.isEnabledFor(logging.INFO) is False
1306+
assert replay_logger.isEnabledFor(logging.CRITICAL) is False
1307+
1308+
# After replay, delegates to the inner logger
1309+
replaying = False
1310+
assert replay_logger.isEnabledFor(logging.DEBUG) is True
1311+
assert replay_logger.isEnabledFor(logging.INFO) is True
1312+
1313+
# If a level is below the inner logger's level, should return False
1314+
inner_logger.setLevel(logging.WARNING)
1315+
assert replay_logger.isEnabledFor(logging.DEBUG) is False
1316+
assert replay_logger.isEnabledFor(logging.WARNING) is True
1317+
1318+
12721319
def test_when_any_with_retry():
12731320
"""Tests that a when_any pattern works correctly with retries"""
12741321
def dummy_activity(_, inp: str):

0 commit comments

Comments
 (0)