workflow Logs enhancements - Structured logging and right log levels

[rabollin]

Improve the debuggability of Dapr Workflows by (a) identifying gaps in logging and improving them, and (b) making the error reporting consistent across.

Explore structured logging like TIME LEVEL WORKFLOW_ID SOURCE MESSAGE where SOURCE can be Dapr Client or DTF (can have subcategories which we MAY consider including worker/client/task - mostly not required from Python SDK POV). Also requires setting up logger formatter in DTF Clients for each SDK.

Logs grouping for Starting the DTF worker, successful connection to gRPC server etc.. Currently it shows just this one statement.

== APP - WorkflowConsoleApp == INFO: Durable Task worker is connecting to sidecar at 127.0.0.1:61659.

Workflow Execution: The logs are capturing only very superficial as Workflow started, waiting for activity as shown here (logs from Python SDK). Capture Workflow Name, Workflow ID too in the messages below.

== APP - order-processor == 2023-10-20 18:24:48.276 durabletask-worker INFO: Starting gRPC worker that connects to 127.0.0.1:61723

== APP - order-processor == 2023-10-20 18:24:48.285 durabletask-worker INFO: Successfully connected to 127.0.0.1:61723. Waiting for work items...

== APP - order-processor == start_resp = daprClient.start_workflow(workflow_component=workflow_component,

== APP - order-processor == Starting order workflow, purchasing 10 of cars

Workflow Activity level logging: The logs below show as waiting for tasks and events, but nothing beyond that. Should capture Parent ID (Workflow ID), Task ID, Task name, Task status, event ID, event status as relevant in each log message.

== APP - order-processor == 2023-10-20 18:24:52.332 durabletask-worker INFO: 57044fb1-5f7b-4912-ad6e-f87595cb6ec2: Waiting for 1 task(s) and 0 event(s).

18:24:52.402 durabletask-worker INFO: 57044fb1-5f7b-4912-ad6e-f87595cb6ec2: Waiting for 1 task(s) and 1 event(s).

Categorization of log levels for Workflow logs for ease – Warning, Info & Debug

Debug logs to contain more finer details about activities: Make sure that SDKs support disabling Debug logs to not bombard app logs with too many logs

[shivamkm07]

Following are some of the logging enhancements which should improve Workflow debuggability, w.r.t python-sdk

1. Following log lines can be added to improve SDK logging:
   Workflow Authoring
   i. Scheduling activity: Scheduling activity {activity_name}
   ii. Creating timer: Creating timer to fire at {deadline}
   iii. Scheduling child workflow: Scheduling child-workflow {child_workflow_name}
   iv. Wait for external event: Waiting for the event {event_name} to be raised
   v. Continue-as-new: Continuing the execution as new instance
   Workflow Runtime:
   i. Register workflow: Registering workflow {workflow_name} with runtime
   ii. Register activity: Registering activity {activity_name} with workflow {workflow_name}
2. Add support for Logger in DaprClient: Currently there is no logger initialized while starting the Dapr Client. Also there is no support for multiple log levels like INFO, DEBUG etc. Enable support in DaprClient as well as DaprWorkflowClient and also pass the same log level to DTF-python to capture DTF debug logs
3. Standardization: The existing logs in DTF-python as well as the new logs to be added should be standardized to follow a standard schema. E.g. for the Workflow-Authoring logs, the format could be like TIME LEVEL WORKFLOW_ID SOURCE MESSAGE.

[shivamkm07]

Following are some of the logging enhancements which should improve Workflow debuggability, w.r.t python-sdk

1. Following log lines can be added to improve SDK logging:
   Workflow Authoring
   i. Scheduling activity: Scheduling activity {activity_name}
   ii. Creating timer: Creating timer to fire at {deadline}
   iii. Scheduling child workflow: Scheduling child-workflow {child_workflow_name}
   iv. Wait for external event: Waiting for the event {event_name} to be raised
   v. Continue-as-new: Continuing the execution as new instance
   Workflow Runtime:
   i. Register workflow: Registering workflow {workflow_name} with runtime
   ii. Register activity: Registering activity {activity_name} with workflow {workflow_name}
2. Add support for Logger in DaprClient: Currently there is no logger initialized while starting the Dapr Client. Also there is no support for multiple log levels like INFO, DEBUG etc. Enable support in DaprClient as well as DaprWorkflowClient and also pass the same log level to DTF-python to capture DTF debug logs
3. Standardization: The existing logs in DTF-python as well as the new logs to be added should be standardized to follow a standard schema. E.g. for the Workflow-Authoring logs, the format could be like TIME LEVEL WORKFLOW_ID SOURCE MESSAGE.

@DeepanshuA @RyanLettieri @cgillum thoughts?

[shivamkm07]

/assign

[berndverst]

Please use the correct issue template when opening an issue.

[dapr-bot]

This issue has been automatically marked as stale because it has not had activity in the last 60 days. It will be closed in the next 7 days unless it is tagged (pinned, good first issue, help wanted or triaged/resolved) or other activity occurs. Thank you for your contributions.

[mukundansundar]

closed via #645