Add Functions host logging E2E coverage

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: ce0bfcf6-4e74-4a28-b802-45c98f3af2ef

Author: andystaples

tests/azure-functions-durable/e2e/_harness.py

@@ -411,6 +411,23 @@ def _read_log(self) -> str:
         except OSError:
             return "(no host log captured)"
 
+    def read_host_log(self) -> str:
+        """Return the Functions host output captured for this app."""
+        return self._read_log()
+
+    def wait_for_host_log(self, text: str, timeout: float = 30) -> str:
+        """Wait until captured Functions host output contains ``text``."""
+        deadline = time.time() + timeout
+        log = self._read_log()
+        while text not in log and time.time() < deadline:
+            time.sleep(0.1)
+            log = self._read_log()
+        if text not in log:
+            raise TimeoutError(
+                f"Functions host log did not contain {text!r} within {timeout}s.\n"
+                f"{log}")
+        return next(line for line in log.splitlines() if text in line)
+
     def stop(self) -> None:
         proc = self._process
         if proc is not None:

tests/azure-functions-durable/e2e/apps/dtask_style/client_routes.py

@@ -15,6 +15,7 @@
 
 import asyncio
 import json
+import logging
 from datetime import datetime, timedelta, timezone
 from typing import Any
 
@@ -32,6 +33,7 @@
 )
 
 bp = df.Blueprint()
+_LOGGER = logging.getLogger(__name__)
 
 
 def _sync_client(client: df.DurableFunctionsClient) -> TaskHubGrpcClient:
@@ -91,6 +93,19 @@ async def start_orchestration(
         json.dumps({"id": instance_id}), status_code=202, mimetype="application/json")
 
 
+@bp.route(route="start-logging-filtered/{name}", methods=["POST"])
+@bp.durable_client_input(client_name="client")
+async def start_logging_filtered(
+        req: func.HttpRequest, client: df.DurableFunctionsClient) -> func.HttpResponse:
+    name = req.route_params["name"]
+    body = req.get_json()
+    instance_id = await client.schedule_new_orchestration(name, input=body.get("input"))
+    _LOGGER.info("client-info-filter-anchor %s", instance_id)
+    _LOGGER.warning("client-filter-anchor %s", instance_id)
+    return func.HttpResponse(
+        json.dumps({"id": instance_id}), status_code=202, mimetype="application/json")
+
+
 @bp.route(route="status/{id}", methods=["GET"])
 @bp.durable_client_input(client_name="client")
 async def get_orchestration_status(

tests/azure-functions-durable/e2e/apps/dtask_style/host.json

@@ -2,7 +2,9 @@
   "version": "2.0",
   "logging": {
     "logLevel": {
-      "default": "Information"
+      "default": "Information",
+      "Function.start_logging_filtered.User": "Warning",
+      "Function.logging_filtered.User": "Warning"
     }
   },
   "extensionBundle": {

tests/azure-functions-durable/e2e/apps/dtask_style/orchestrators.py

@@ -13,12 +13,14 @@
 """
 
 from datetime import timedelta
+import logging
 from typing import Any
 
 import azure.durable_functions as df
 from durabletask import entities, task
 
 bp = df.Blueprint()
+_LOGGER = logging.getLogger(__name__)
 
 
 # ---------------------------------------------------------------------------
@@ -33,6 +35,13 @@ def activity_chain(ctx: task.OrchestrationContext, _: Any):
     return [first, second, third]
 
 
+@bp.orchestration_trigger(context_name="context")
+def logging_filtered(ctx: task.OrchestrationContext, _: Any):
+    _LOGGER.info("worker-info-filter-anchor %s", ctx.instance_id)
+    _LOGGER.warning("worker-filter-anchor %s", ctx.instance_id)
+    return "logged"
+
+
 @bp.orchestration_trigger(context_name="context")
 def fan_out_fan_in(ctx: task.OrchestrationContext, count: Any):
     count = count or 5

tests/azure-functions-durable/e2e/test_logging_e2e.py

@@ -0,0 +1,61 @@
+# Copyright (c) Microsoft Corporation.
+# Licensed under the MIT License.
+
+"""E2E validation for Durable Functions SDK logging."""
+
+import re
+
+import pytest
+
+from ._harness import http_request
+
+pytestmark = pytest.mark.functions_e2e
+
+
+def _assert_host_routed(line: str, message: str) -> None:
+    assert re.fullmatch(rf"\[[^\]]+Z\] {re.escape(message)}", line)
+
+
+def test_client_and_worker_logs_flow_through_host(dtask_app):
+    instance_id = dtask_app.start_orchestration("activity_chain")
+    status = dtask_app.wait_for_completion(instance_id)
+    assert status["runtimeStatus"] == "COMPLETED"
+
+    client_message = (
+        f"Starting new 'activity_chain' instance with ID = '{instance_id}'.")
+    worker_message = (
+        f"{instance_id}: Orchestration activity_chain completed with status: COMPLETED")
+    client_line = dtask_app.wait_for_host_log(client_message)
+    worker_line = dtask_app.wait_for_host_log(worker_message)
+
+    _assert_host_routed(client_line, client_message)
+    _assert_host_routed(worker_line, worker_message)
+
+
+def test_host_category_filter_applies_to_client_and_worker_logs(dtask_app):
+    result = http_request(
+        "POST",
+        f"{dtask_app.base_url}/api/start-logging-filtered/logging_filtered",
+        data={"input": None},
+    )
+    assert result.status == 202
+    instance_id = result.json()["id"]
+
+    status = dtask_app.wait_for_completion(instance_id)
+    assert status["runtimeStatus"] == "COMPLETED"
+    assert status["output"] == "logged"
+
+    dtask_app.wait_for_host_log(f"client-filter-anchor {instance_id}")
+    dtask_app.wait_for_host_log(f"worker-filter-anchor {instance_id}")
+    log = dtask_app.read_host_log()
+
+    assert f"client-info-filter-anchor {instance_id}" not in log
+    assert f"worker-info-filter-anchor {instance_id}" not in log
+    assert (
+        f"Starting new 'logging_filtered' instance with ID = '{instance_id}'."
+        not in log
+    )
+    assert (
+        f"{instance_id}: Orchestration logging_filtered completed with status: COMPLETED"
+        not in log
+    )