Improve messaging for resources

Open michaeltlombardi opened this issue 4 months ago • 0 comments

Summary of the new feature / enhancement

As a resource developer, integrating developer, and DSC user, I want to be able to have useful data about messages emitted from resources included in the message DSC emits, So that I can correctly correlate and investigate messages emitted when DSC invokes a resource.

Currently, DSC emits messages from resources with the following formats:

Console (info, warn, and error trace levels, default and plaintext formats):
```
2025-08-15T14:42:53.970726Z  WARN PID 29072: Message from resource
```

Console (trace and debug trace levels, default and plaintext formats):

2025-08-15T14:42:53.970726Z  WARN dsc_lib::dscresources::command_resource: 901: PID 34460: Message from resource

JSON (info, warn, and error trace levels, json format, pretty-printed for readability):

{
  "timestamp": "2025-08-15T14:42:53.970726Z",
  "level": "WARN",
  "fields": {
    "message": "PID 28644: Simple message"
  }
}

JSON (trace and debug trace levels, json format, pretty-printed for readability):

{
  "timestamp": "2025-08-15T14:42:53.970726Z",
  "level": "WARN",
  "fields": {
    "message": "PID 28644: Simple message"
  },
  "target": "dsc_lib::dscresources::command_resource",
  "line_number": 901
}

Proposal

In the current implementation, DSC munges the emitted message from the resource by inserting PID: <PID> before the emitted message, making the message syntax effectively PID: <PID> <Message>. Anyone processing the emitted message needs to make sense of the PID prefix and extract the message itself.

While the emitted message does indicate the PID for the process that raised the message, it doesn't indicate information about the resource that emitted it.

Ideally, the emitted trace should contain the following fields:

message - the message from the resource.
resource.process.pid - the PID for the resource invocation.
resource.type - the resource fully qualified type name
resource.name - the name of the resource instance when invoked in a configuration context (undefined or null when invoked with dsc resource * commands).
resource.operation - the operation the resource was invoked for.

While we can't effectively bubble up structured data from a resource at this time due to limitations in the tracing library, we can provide known-at-invocation metadata to help developers and users make sense of individual messages without requiring a user to read them in the broader context of emitted messages. Currently, to know which resource emitted a message, a user needs to evaluate prior messages from DSC - and those messages aren't necessarily available at trace levels warn or error.

This work would also ease the path towards collecting resource messages in the result output for configuration commands.

Proposed technical implementation details (optional)

In the current implementation, we use the invoke_command function to invoke operations for extensions and resources:

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L718-L729

invoke_command calls the run_process_async function, which calls log_stderr_line to process stderr from the resources:

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L663-L673

The log_stderr_line function is only called from run_process_async, which is only called from invoke_command, which is always used to invoke operations for resources (including adapters) and extensions.

Known call sites

The following callsites show where we use invoke_command in our code:

dsc_lib::dscresources::command_resource::invoke_get

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L41
dsc_lib::dscresources::command_resource::invoke_set

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L142

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L184
dsc_lib::dscresources::command_resource::invoke_test

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L276
dsc_lib::dscresources::command_resource::invoke_delete

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L411
dsc_lib::dscresources::command_resource::invoke_validate

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L442
dsc_lib::dscresources::command_resource::get_schema

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L463
dsc_lib::dscresources::command_resource::invoke_export

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L527
dsc_lib::dscresources::command_resource::invoke_resolve

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/dscresources/command_resource.rs#L573
dsc_lib::discovery::command_discovery::CommandDiscovery::discover_adapted_resources

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/discovery/command_discovery.rs#L390
dsc_lib::extensions::dscextension::DscExtension::discover

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/extensions/dscextension.rs#L114
dsc_lib::extensions::dscextension::DscExtension::import

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/extensions/dscextension.rs#L189
dsc_lib::extensions::dscextension::DscExtension::secret

https://github.com/PowerShell/DSC/blob/73c95ca37bec1df4208ef95dd6ab05f3ac0dc9a6/dsc_lib/src/extensions/dscextension.rs#L236

In every callsite, we know:

The type name for the resource or extension being invoked
The operation being invoked

In the current implementation, we can't get the name of the resource when invoked for a configuration operation. We would need to have a way to pass that context.

A minimally-disruptive implementation would be to extend invoke_command to take three additional parameters:

type_name - the fully qualified type name for the resource or extension.
command_type - either Extension or Resource
operation - String representation of the operation

Which we could then flow-down to the run_process_async and log_stderr_line functions.

More usefully/maintainably, we should consider extracting the process spawning code into a separate module (now that it's used by both resources and extensions) and define context structs we can use for bubbling up emitted messages from resource/extension commands:

pub enum CommandInvocationContext {
  Resource(ResourceCommandInvocationContext),
  Extension(ExtensionCommandInvocationContext),
}
pub struct ResourceCommandInvocationContext {
  // Ellided
}
pub struct ExtensionCommandInvocationContext {
  // Ellided
}

Aug 18 '25 19:08 michaeltlombardi