Add better tracing and fix propagation of inDesiredState for PSAdapter

dsc_lib/src/dscresources/command_resource.rs

@@ -870,15 +870,15 @@ pub fn log_stderr_line<'a>(process_id: &u32, trace_line: &'a str) -> &'a str
             }
         }
         else if let Ok(json_obj) = serde_json::from_str::<Value>(trace_line) {
-            if let Some(msg) = json_obj.get("Error") {
+            if let Some(msg) = json_obj.get("error") {
                 error!("PID {process_id}: {}", msg.as_str().unwrap_or_default());
-            } else if let Some(msg) = json_obj.get("Warning") {
+            } else if let Some(msg) = json_obj.get("warn") {
                 warn!("PID {process_id}: {}", msg.as_str().unwrap_or_default());
-            } else if let Some(msg) = json_obj.get("Info") {
+            } else if let Some(msg) = json_obj.get("info") {
                 info!("PID {process_id}: {}", msg.as_str().unwrap_or_default());
-            } else if let Some(msg) = json_obj.get("Debug") {
+            } else if let Some(msg) = json_obj.get("debug") {
                 debug!("PID {process_id}: {}", msg.as_str().unwrap_or_default());
-            } else if let Some(msg) = json_obj.get("Trace") {
+            } else if let Some(msg) = json_obj.get("trace") {
                 trace!("PID {process_id}: {}", msg.as_str().unwrap_or_default());
             } else {
                 // the line is a valid json, but not one of standard trace lines - return it as filtered stderr_line

powershell-adapter/Tests/win_powershellgroup.tests.ps1

@@ -87,4 +87,41 @@ Describe 'WindowsPowerShell adapter resource tests - requires elevated permissio
             "$TestDrive/tracing.txt" | Should -Not -FileContentMatchExactly 'Constructing Get-DscResource cache'
         }
     }
+
+    It '_inDesiredState is returned correction: <Context>' -Skip:(!$IsWindows) -TestCases @(
+        @{ Context = 'Both running'; FirstState = 'Running'; SecondState = 'Running' }
+        @{ Context = 'Both stopped'; FirstState = 'Stopped'; SecondState = 'Stopped' }
+        @{ Context = 'First Stopped'; FirstState = 'Stopped'; SecondState = 'Running' }
+        @{ Context = 'First Running'; FirstState = 'Running'; SecondState = 'Stopped' }
+      ) {
+          param($Context, $FirstState, $SecondState)
+          $yaml = @"
+`$schema: https://aka.ms/dsc/schemas/v3/bundled/config/document.json
+resources:
+  - name: Use Windows PowerShell resources
+    type: Microsoft.Windows/WindowsPowerShell
+    properties:
+      resources:
+      - name: Check Spooler service 1
+        type: PsDesiredStateConfiguration/Service
+        properties:
+          Name: Spooler
+          State: $FirstState
+      - name: Check Spooler service 2
+        type: PsDesiredStateConfiguration/Service
+        properties:
+          Name: Spooler
+          State: $SecondState    
+"@
+
+        $inDesiredState = if ($FirstState -eq $SecondState) {
+          $FirstState -eq (Get-Service Spooler).Status
+        } else {
+          $false
+        }
+
+        $out = dsc config test -i $yaml | ConvertFrom-Json
+        $LASTEXITCODE | Should -Be 0
+        $out.results[0].result.inDesiredState | Should -Be $inDesiredState
+    }
 }

powershell-adapter/psDscAdapter/powershell.resource.ps1

@@ -46,9 +46,7 @@ if ($Operation -eq 'ClearCache') {
 }
 
 if ('Validate' -ne $Operation) {
-    # write $jsonInput to STDERR for debugging
-    $trace = @{'debug' = 'jsonInput=' + $jsonInput } | ConvertTo-Json -Compress
-    $host.ui.WriteErrorLine($trace)
+    Write-DscTrace -Operation Debug -Message "jsonInput=$jsonInput"
 
     # load private functions of psDscAdapter stub module
     if ($PSVersionTable.PSVersion.Major -le 5) {
@@ -135,16 +133,14 @@ switch ($Operation) {
     { @('Get','Set','Test','Export') -contains $_ } {
         $desiredState = $psDscAdapter.invoke(   { param($jsonInput) Get-DscResourceObject -jsonInput $jsonInput }, $jsonInput )
         if ($null -eq $desiredState) {
-            $trace = @{'debug' = 'ERROR: Failed to create configuration object from provided input JSON.' } | ConvertTo-Json -Compress
-            $host.ui.WriteErrorLine($trace)
+            Write-DscTrace -Operation Error -message 'Failed to create configuration object from provided input JSON.'
             exit 1
         }
 
         # only need to cache the resources that are used
         $dscResourceModules = $desiredState | ForEach-Object { $_.Type.Split('/')[0] }
         if ($null -eq $dscResourceModules) {
-            $trace = @{'debug' = 'ERROR: Could not get list of DSC resource types from provided JSON.' } | ConvertTo-Json -Compress
-            $host.ui.WriteErrorLine($trace)
+            Write-DscTrace -Operation Error -Message 'Could not get list of DSC resource types from provided JSON.'
             exit 1
         }
 
@@ -162,21 +158,28 @@ switch ($Operation) {
             }
         }
 
+        $inDesiredState = $true
         foreach ($ds in $desiredState) {
             # process the INPUT (desiredState) for each resource as dscresourceInfo and return the OUTPUT as actualState
             $actualState = $psDscAdapter.invoke( { param($op, $ds, $dscResourceCache) Invoke-DscOperation -Operation $op -DesiredState $ds -dscResourceCache $dscResourceCache }, $Operation, $ds, $dscResourceCache)
             if ($null -eq $actualState) {
-                $trace = @{'debug' = 'ERROR: Incomplete GET for resource ' + $ds.Name } | ConvertTo-Json -Compress
-                $host.ui.WriteErrorLine($trace)
+                Write-DscTrace -Operation Error -Message 'Incomplete GET for resource ' + $ds.Name
                 exit 1
             }
+            if ($null -ne $actualState.Properties -and $actualState.Properties.InDesiredState -eq $false) {
+                $inDesiredState = $false
+            }
             $result += $actualState
         }
 
         # OUTPUT json to stderr for debug, and to stdout
-        $result = @{ result = $result } | ConvertTo-Json -Depth 10 -Compress
-        $trace = @{'debug' = 'jsonOutput=' + $result } | ConvertTo-Json -Compress
-        $host.ui.WriteErrorLine($trace)
+        if ($Operation -eq 'Test') {
+            $result = @{ result = $result; _inDesiredState = $inDesiredState } | ConvertTo-Json -Depth 10 -Compress
+        }
+        else {
+            $result = @{ result = $result } | ConvertTo-Json -Depth 10 -Compress
+        }
+        Write-DscTrace -Operation Debug -Message "jsonOutput=$result"
         return $result
     }
     'Validate' {

powershell-adapter/psDscAdapter/psDscAdapter.psm1

@@ -13,7 +13,7 @@ function Write-DscTrace {
         [string]$Message
     )
 
-    $trace = @{$Operation = $Message } | ConvertTo-Json -Compress
+    $trace = @{$Operation.ToLower() = $Message } | ConvertTo-Json -Compress
     $host.ui.WriteErrorLine($trace)
 }
 
@@ -438,7 +438,7 @@ function Invoke-DscOperation {
     'PowerShell version: ' + $psVersion | Write-DscTrace
 
     # get details from cache about the DSC resource, if it exists
-    $cachedDscResourceInfo = $dscResourceCache | Where-Object Type -EQ $DesiredState.type | ForEach-Object DscResourceInfo
+    $cachedDscResourceInfo = $dscResourceCache | Where-Object Type -EQ $DesiredState.type | ForEach-Object DscResourceInfo | Select-Object -First 1
 
     # if the resource is found in the cache, get the actual state
     if ($cachedDscResourceInfo) {

powershell-adapter/psDscAdapter/win_psDscAdapter.psm1

@@ -13,7 +13,7 @@ function Write-DscTrace {
         [string]$Message
     )
 
-    $trace = @{$Operation = $Message } | ConvertTo-Json -Compress
+    $trace = @{$Operation.ToLower() = $Message } | ConvertTo-Json -Compress
     $host.ui.WriteErrorLine($trace)
 }
 
@@ -324,7 +324,7 @@ function Invoke-DscOperation {
     'PSDesiredStateConfiguration module version: ' + $moduleVersion | Write-DscTrace
 
     # get details from cache about the DSC resource, if it exists
-    $cachedDscResourceInfo = $dscResourceCache | Where-Object Type -EQ $DesiredState.type | ForEach-Object DscResourceInfo
+    $cachedDscResourceInfo = $dscResourceCache | Where-Object Type -EQ $DesiredState.type | ForEach-Object DscResourceInfo | Select-Object -First 1
 
     # if the resource is found in the cache, get the actual state
     if ($cachedDscResourceInfo) {
@@ -367,6 +367,7 @@ function Invoke-DscOperation {
 
                 # using the cmdlet the appropriate dsc module, and handle errors
                 try {
+                    Write-DscTrace -Operation Debug -Message "Module: $($cachedDscResourceInfo.ModuleName), Name: $($cachedDscResourceInfo.Name), Property: $($property)"
                     $invokeResult = Invoke-DscResource -Method $Operation -ModuleName $cachedDscResourceInfo.ModuleName -Name $cachedDscResourceInfo.Name -Property $property
 
                     if ($invokeResult.GetType().Name -eq 'Hashtable') {
@@ -381,6 +382,7 @@ function Invoke-DscOperation {
                     $addToActualState.properties = $ResultProperties
                 }
                 catch {
+                    $_.Exception | Format-List * -Force | Out-String | Write-DscTrace -Operation Debug
                     'Exception: ' + $_.Exception.Message | Write-DscTrace -Operation Error
                     exit 1
                 }