DSC icon indicating copy to clipboard operation
DSC copied to clipboard

PS Adapter doesn't exit if background runspace is busy

Open ThomasNieto opened this issue 7 months ago • 0 comments

Prerequisites

  • [x] Write a descriptive title.
  • [x] Make sure you are able to repro it on the latest version
  • [x] Search the existing issues.

Summary

PS Adapter running a class-based resource may work or it will just run forever.

Update

Did some more investigation on this and found the root cause.

TLDR: A background runspace was busy preventing pwsh from closing

  1. AnyPackageDsc module depends on AnyPackage
  2. AnyPackage supports feedback and command predictors
  3. When the AnyPackage provider (AnyPackage.PSResourceGet) module gets imported, AnyPackage will start a runspace to cache predictions
  4. When the runspace is caching the runspace is busy for ~30 seconds
  5. During this time if the main runspace is completed and closes; the pwsh process stays open
  6. Even if the provider runspace goes from busy to available pwsh never exits
  7. I used Enter-PSHostProcess and ran Get-Runspace and noticed runspace 1 was closed but the provider runspace was available. Once I closed the provider runspace pwsh exited and dsc returned data. Feedback/Predictor subsystem is updated to not call registered providers when pwsh is non-interactive. cc: @daxian-dbw

Steps to reproduce

  1. Install AnyPackage.PSResourceGet, AnyPackageDsc modules
$schema: https://raw.githubusercontent.com/PowerShell/DSC/main/schemas/v3/config/document.json
resources:
  - name: SNMP
    type: AnyPackageDsc/Package
    properties:
      Name: SNMP
      Version: "*"
      Provider: AnyPackage.PSResourceGet\PSResourceGet
      Ensure: Present
  1. Run dsc config get -f c:\temp\config.yml multiple times. It is very inconsistent if it just hangs or returns immediately

Expected behavior

Runs to completion every time within expected timeframe.

Actual behavior

PS C:\Users\Thomas> dsc config get -f c:\temp\config.yml
metadata:
  Microsoft.DSC:
    version: 3.0.0
    operation: get
    executionType: actual
    startDatetime: 2025-05-08T20:01:13.940991700-05:00
    endDatetime: 2025-05-08T20:01:15.765426800-05:00
    duration: PT1.8244351S
    securityContext: restricted
results:
- metadata:
    Microsoft.DSC:
      duration: PT1.1756815S
  name: SNMP
  type: AnyPackageDsc/Package
  result:
    actualState:
      Latest: false
      Ensure: 1
      Reasons: null
      Provider: AnyPackage.PSResourceGet\PSResourceGet
      Prerelease: false
      Version: 1.0.0.1
      Source: PSGallery
      AdditionalParameters: {}
      Name: SNMP
messages: []
hadErrors: false
PS C:\Users\Thomas> dsc config get -f c:\temp\config.yml
2025-05-09T01:04:23.345212Z  WARN Ctrl-C received
2025-05-09T01:04:23.499002Z ERROR Command: Resource 'pwsh' [exit code 1] manifest description: Error
PS C:\Users\Thomas> dsc config get -f c:\temp\config.yml
⠒ [00:00:38] [░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░]       0/1       Get 'SNMP'

Trace when it works

2025-05-09T01:12:10.509185Z TRACE dsc_lib::dscresources::command_resource: 904: PID 13564: Output: {"name":"AnyPackageDsc/Package","type":"AnyPackageDsc/Package","properties":{"InDesiredState":true}}
2025-05-09T01:12:10.514297Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 13564: jsonOutput={"result":[{"name":"AnyPackageDsc/Package","type":"AnyPackageDsc/Package","properties":{"InDesiredState":true}}],"_inDesiredState":true}
2025-05-09T01:12:10.573316Z DEBUG dsc_lib::dscresources::command_resource: 660: Process 'pwsh' id 13564 exited with code 0
2025-05-09T01:12:10.575789Z  INFO dsc_lib::dscresources::dscresource: 539: diff: key 'resources' missing
2025-05-09T01:12:10.576022Z  INFO dsc_lib::dscresources::dscresource: 543: diff: key 'context' is not an object
2025-05-09T01:12:10.576225Z  INFO dsc_lib::dscresources::dscresource: 543: diff: key '_exist' is not an object
2025-05-09T01:12:10.576417Z DEBUG dsc_lib::dscresources::dscresource: 513: diff: sub diff for 'Microsoft.DSC'
2025-05-09T01:12:10.576606Z  INFO dsc_lib::dscresources::dscresource: 543: diff: key '_exist' is not an object
2025-05-09T01:12:10.576797Z DEBUG dsc_lib::dscresources::dscresource: 513: diff: sub diff for 'metadata'
2025-05-09T01:12:10.577058Z  INFO dsc_lib::dscresources::dscresource: 539: diff: key 'Name' missing
2025-05-09T01:12:10.577265Z  INFO dsc_lib::dscresources::dscresource: 539: diff: key 'Version' missing
2025-05-09T01:12:10.577455Z  INFO dsc_lib::dscresources::dscresource: 539: diff: key 'Provider' missing
2025-05-09T01:12:10.577645Z  INFO dsc_lib::dscresources::dscresource: 539: diff: key 'Ensure' missing
metadata:
  Microsoft.DSC:
    version: 3.0.0
    operation: test
    executionType: actual
    startDatetime: 2025-05-08T20:12:08.648107200-05:00
    endDatetime: 2025-05-08T20:12:10.577857600-05:00
    duration: PT1.9297504S
    securityContext: restricted
results:
- metadata:
    Microsoft.DSC:
      duration: PT1.2516759S
  name: SNMP
  type: AnyPackageDsc/Package
  result:
    desiredState:
      Name: SNMP
      Version: '*'
      Provider: AnyPackage.PSResourceGet\PSResourceGet
      Ensure: Present
    actualState:
      InDesiredState: true
    inDesiredState: true
    differingProperties:
    - Name
    - Version
    - Provider
    - Ensure
messages: []
hadErrors: false

Error details

2025-05-09T01:10:34.369292Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: Reading from Get-DscResource cache file C:\Users\Thomas\AppData\Local\dsc\PSAdapterCache.json
2025-05-09T01:10:34.377500Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: Checking cache for stale entries
2025-05-09T01:10:34.397882Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: Checking cache for stale PSModulePath
2025-05-09T01:10:34.424932Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: PSModulePath diff ''
2025-05-09T01:10:34.432600Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: OS version: Microsoft Windows NT 10.0.26100.0
2025-05-09T01:10:34.433159Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: PowerShell version: 7.6.0-preview.4
2025-05-09T01:10:34.525678Z TRACE dsc_lib::dscresources::command_resource: 904: PID 8252: [
  "Name",
  "Version",
  "Provider",
  "Prerelease",
  "Source",
  "AdditionalParameters",
  "Latest",
  "Ensure",
  "Reasons"
]
2025-05-09T01:10:34.738497Z TRACE dsc_lib::dscresources::command_resource: 904: PID 8252: Output: {"name":"AnyPackageDsc/Package","type":"AnyPackageDsc/Package","properties":{"InDesiredState":true}}
2025-05-09T01:10:34.741328Z DEBUG dsc_lib::dscresources::command_resource: 902: PID 8252: jsonOutput={"_inDesiredState":true,"result":[{"name":"AnyPackageDsc/Package","type":"AnyPackageDsc/Package","properties":{"InDesiredState":true}}]}

Environment data

7.6-preview4

Version

3.1.0-preview.5

Visuals

No response

ThomasNieto avatar May 09 '25 01:05 ThomasNieto