Skip to content

(REPRO) Trace messaging issues repro #1048

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

michaeltlombardi
Copy link
Collaborator

PR Summary

This change creates a repro resource, tests, and example configuration to enumerate issues with the current model for bubbling up trace messages from resources.

The resources/repro.trace folder contains the relevant files:

  • repro.trace.dsc.resource.json - resource manifest
  • repro.trace.resource.ps1 - resource script
  • repro.trace.tests.ps1 - failing tests for behavior
  • repro.config.dsc.yaml - config file with every repro case
  • repro.config.result.yaml - snapshot of output from config

The repro covers several test cases to show how DSC behaves when a resource emits trace messages as compressed JSON to stderr:

  • simpleMessaging shows the behavior for emitting a string for a given trace level, like {"warn":"my warning"}.
  • minimalStruct shows the behavior for emitting a struct that defines the level, timestamp, and fields.message properties.
  • structWithMetadata also defines the target and lineNumber properties to bubble up for the resource.
  • structWithAdditionalFields defines fields.extraString and fieldsextraInteger` to bubble up related context.
  • structWithMetadataAndAdditionalFields includes defines target, lineNumber, fields.extraString, and fields.extraInteger.

The resource itself returns the name of the test case and uses the emittedData read-only property to return the data that it emitted to stderr for DSC to interpret as a trace message.

Findings:

  • For the structured representation, DSC only retains the trace level and message contents. The timestamp, target, lineNumber, and additional fields are all ignored or dropped.
  • Regardless of emitted JSON, DSC munges the message to insert the process ID like PID 1234: <message>.
  • For structured representation, DSC bubbles up the message in the trace_message field instead of message.
  • For dsc config get, DSC doesn't seem to capture the emitted messages in the result object, only emitting them to stderr.

This repro shows that we have some unexpected behaviors for resource messaging that may guide a review and update of the implementation.

PR Context

While working on the resource authoring design guide, I started to write up how and when a resource author should implement trace messaging for the resource. To accurately advise authors, I needed a better understanding of how to implement tracing and how it would behave when invoked through DSC.

This change creates a repro resource, tests, and example
configuration to enumerate issues with the current model
for bubbling up trace messages from resources.

The `resources/repro.trace` folder contains the relevant
files:

- `repro.trace.dsc.resource.json` - resource manifest
- `repro.trace.resource.ps1` - resource script
- `repro.trace.tests.ps1` - failing tests for behavior
- `repro.config.dsc.yaml` - config file with every repro case
- `repro.config.result.yaml` - snapshot of output from config

The repro covers several test cases to show how DSC behaves
when a resource emits trace messages as compressed JSON to
stderr:

- `simpleMessaging` shows the behavior for emitting a string
  for a given trace level, like `{"warn":"my warning"}`.
- `minimalStruct` shows the behavior for emitting a struct
  that defines the `level`, `timestamp`, and `fields.message`
  properties.
- `structWithMetadata` also defines the `target` and `lineNumber`
  properties to bubble up for the resource.
- `structWithAdditionalFields` defines fields.`extraString` and
  `fields`extraInteger` to bubble up related context.
- `structWithMetadataAndAdditionalFields` includes defines
  `target`, `lineNumber`, `fields.extraString`, and `fields.extraInteger`.

The resource itself returns the name of the test case and uses the `emittedData`
read-only property to return the data that it emitted to stderr for DSC to
interpret as a trace message.

Findings:

- For the structured representation, DSC only retains the trace level and
  message contents. The `timestamp`, `target`, `lineNumber`, and additional
  fields are all ignored or dropped.
- Regardless of emitted JSON, DSC munges the message to insert the process
  ID like `PID 1234: <message>`.
- For structured representation, DSC bubbles up the message in the `trace_message`
  field instead of `message`.
- For `dsc config get`, DSC doesn't seem to capture the emitted messages in the
  result object, only emitting them to stderr.

This repro shows that we have some unexpected behaviors for resource messaging
that may guide a review and update of the implementation.
@SteveL-MSFT
Copy link
Member

Discussed with @michaeltlombardi, conclusions:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants