dsccommunity / xPSDesiredStateConfiguration

DSC resources for configuring common operating systems features, files and settings.
https://dsccommunity.org
MIT License
211 stars 134 forks source link

xPackage crashes with NullReferenceException #634

Closed reznet closed 5 years ago

reznet commented 5 years ago

Details of the scenario you tried and the problem that is occurring

I am trying to install an exe installer using the xPackage resource. I'm pretty sure it once worked on my machine (and we have been using xPackage successfully in our automation), but something broke and I've been unable to explain what. I extracted Test-TargetResource from the module and ran it manually and it did not fail, so it seems something between DSC and the module is introducing the error. I've tried debugging in PowerShell ISE but am able to step through my configuration script but not into the module. I've already tried rebooting, reinstalling the module, but nothing has helped. I've also verified that the module isn't completely broken by successfully testing the xEnvironment resource.

I've set the DscDebug mode to BreakAll, but it doesn't seem to have any effect. Even though the output says it is waiting for a debugger, the script continues to run, displays the error, and exits. I've tried this in both the console and in PowerShell ISE.

What can I try next to troubleshoot this issue?

Verbose logs showing the problem

` PS C:\WINDOWS\system32> C:\Users\wieva\source\xPackageDebugging\config.ps1

[DBG]: PS C:\WINDOWS\system32>> 
DEBUG:    MSFT_xPackageResource: RESOURCE PROCESSING STARTED [KeywordName='xPackage'] Function='xPSDesiredStateConfiguration\xPackage']
DEBUG:    MSFT_xPackageResource: ResourceID = [xPackage]NetFramework461
DEBUG:    MSFT_xPackageResource: Processing property 'DependsOn' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'DependsOn' ]
DEBUG:    MSFT_xPackageResource: Processing property 'PsDscRunAsCredential' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'PsDscRunAsCredential' ]
DEBUG:    MSFT_xPackageResource: Processing property 'Ensure' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'Ensure' ]
DEBUG:    MSFT_xPackageResource: Processing property 'Name' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'Name' = 'dotNETFramework461'
DEBUG:    MSFT_xPackageResource:    Processing completed 'Name' ]
DEBUG:    MSFT_xPackageResource: Processing property 'Path' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'Path' = 'C:\installers\NDP461-KB3102436-x86-x64-AllOS-ENU.exe'
DEBUG:    MSFT_xPackageResource:    Processing completed 'Path' ]
DEBUG:    MSFT_xPackageResource: Processing property 'ProductId' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'ProductId' = ''
DEBUG:    MSFT_xPackageResource:    Processing completed 'ProductId' ]
DEBUG:    MSFT_xPackageResource: Processing property 'Arguments' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'Arguments' = '/q'
DEBUG:    MSFT_xPackageResource:    Processing completed 'Arguments' ]
DEBUG:    MSFT_xPackageResource: Processing property 'Credential' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'Credential' ]
DEBUG:    MSFT_xPackageResource: Processing property 'ReturnCode' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'ReturnCode' ]
DEBUG:    MSFT_xPackageResource: Processing property 'LogPath' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'LogPath' ]
DEBUG:    MSFT_xPackageResource: Processing property 'FileHash' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'FileHash' ]
DEBUG:    MSFT_xPackageResource: Processing property 'HashAlgorithm' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'HashAlgorithm' ]
DEBUG:    MSFT_xPackageResource: Processing property 'SignerSubject' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'SignerSubject' ]
DEBUG:    MSFT_xPackageResource: Processing property 'SignerThumbprint' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'SignerThumbprint' ]
DEBUG:    MSFT_xPackageResource: Processing property 'ServerCertificateValidationCallback' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'ServerCertificateValidationCallback' ]
DEBUG:    MSFT_xPackageResource: Processing property 'InstalledCheckRegHive' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'InstalledCheckRegHive' ]
DEBUG:    MSFT_xPackageResource: Processing property 'InstalledCheckRegKey' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'InstalledCheckRegKey' = 'SOFTWARE\Microsoft\NET Framework Setup\NDP\v4\Full'
DEBUG:    MSFT_xPackageResource:    Processing completed 'InstalledCheckRegKey' ]
DEBUG:    MSFT_xPackageResource: Processing property 'InstalledCheckRegValueName' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'InstalledCheckRegValueName' = 'Release'
DEBUG:    MSFT_xPackageResource:    Processing completed 'InstalledCheckRegValueName' ]
DEBUG:    MSFT_xPackageResource: Processing property 'InstalledCheckRegValueData' [
DEBUG:    MSFT_xPackageResource:        Canonicalized property 'InstalledCheckRegValueData' = '394271'
DEBUG:    MSFT_xPackageResource:    Processing completed 'InstalledCheckRegValueData' ]
DEBUG:    MSFT_xPackageResource: Processing property 'CreateCheckRegValue' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'CreateCheckRegValue' ]
DEBUG:    MSFT_xPackageResource: Processing property 'IgnoreReboot' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'IgnoreReboot' ]
DEBUG:    MSFT_xPackageResource: Processing property 'RunAsCredential' [
DEBUG:    MSFT_xPackageResource:    Processing completed 'RunAsCredential' ]
DEBUG:    MSFT_xPackageResource: MOF alias for this resource is '$MSFT_xPackageResource1ref'
DEBUG:    MSFT_xPackageResource: RESOURCE PROCESSING COMPLETED. TOTAL ERROR COUNT: 0

    Directory: C:\WINDOWS\system32\DotNET461ConfigurationDefinition

Mode                LastWriteTime         Length Name                                                                                                                                                       
----                -------------         ------ ----                                                                                                                                                       
-a----        7/21/2019   4:16 PM           2586 localhost.mof                                                                                                                                              

[DBG]: PS C:\WINDOWS\system32>> 
VERBOSE: Perform operation 'Invoke CimMethod' with following parameters, ''methodName' = SendConfigurationApply,'className' = MSFT_DSCLocalConfigurationManager,'namespaceName' = root/Microsoft/Windows/Desi
redStateConfiguration'.
VERBOSE: An LCM method call arrived from computer JEFFELAPTOP with user sid S-1-5-21-2127521184-1604012920-1887927527-32692574.
VERBOSE: [JEFFELAPTOP]: LCM:  [ Start  Set      ]
WARNING: [JEFFELAPTOP]:                            [DSCEngine] Warning LCM is in Debug 'ResourceScriptBreakAll' mode.  Resource script processing will be stopped to wait for PowerShell script debugger to a
ttach.
VERBOSE: [JEFFELAPTOP]:                            [DSCEngine] Importing the module C:\Program Files\WindowsPowerShell\Modules\xPSDesiredStateConfiguration\8.8.0.0\DscResources\MSFT_xPackageResource\MSFT_x
PackageResource.psm1 in force mode.
VERBOSE: [JEFFELAPTOP]: LCM:  [ Start  Resource ]  [[xPackage]NetFramework461]
VERBOSE: [JEFFELAPTOP]: LCM:  [ Start  Test     ]  [[xPackage]NetFramework461]
VERBOSE: [JEFFELAPTOP]:                            [[xPackage]NetFramework461] Importing the module MSFT_xPackageResource in force mode.
WARNING: [JEFFELAPTOP]:                            [[xPackage]NetFramework461] Resource is waiting for PowerShell script debugger to attach.  Use the following commands to begin debugging this resource scr
ipt:
Enter-PSSession -ComputerName JEFFELAPTOP -Credential <credentials>
Enter-PSHostProcess -Id 8704 -AppDomainName DscPsPluginWkr_AppDomain
Debug-Runspace -Id 3
VERBOSE: [JEFFELAPTOP]: LCM:  [ End    Test     ]  [[xPackage]NetFramework461]  in 0.3180 seconds.
PowerShell DSC resource MSFT_xPackageResource  failed to execute Test-TargetResource functionality with error message: Object reference not set to an instance of an object. 
    + CategoryInfo          : InvalidOperation: (:) [], CimException
    + FullyQualifiedErrorId : ProviderOperationExecutionFailure
    + PSComputerName        : localhost

VERBOSE: [JEFFELAPTOP]: LCM:  [ End    Set      ]
The SendConfigurationApply function did not succeed.
    + CategoryInfo          : NotSpecified: (root/Microsoft/...gurationManager:String) [], CimException
    + FullyQualifiedErrorId : MI RESULT 1
    + PSComputerName        : localhost

VERBOSE: Operation 'Invoke CimMethod' complete.
VERBOSE: Time taken for configuration job to complete is 1.042 seconds

`

Suggested solution to the issue

The DSC configuration that is used to reproduce the issue (as detailed as possible)

config.ps1
`

    configuration DotNET461ConfigurationDefinition
    {
        $ErrorActionPreference = "Stop"
        $VerbosePreference = "Continue"
        $InformationPreference  = "Continue"
        $DebugPreference  = "Continue"
        Import-DSCResource -ModuleName xPSDesiredStateConfiguration -ModuleVersion "8.8.0.0";

        Node localhost
        {
            # The .NET 4.6.1 Framework installation. For more information about checking the installation of .NET frameworks see:
            # MSDN How to: Determine Which .NET Framework Versions Are Installed
            # https://msdn.microsoft.com/en-us/library/hh925568(v=vs.110).aspx
            xPackage NetFramework461
            {
                Name = "dotNETFramework461"
                ProductId = ""
                Path = "C:\installers\NDP461-KB3102436-x86-x64-AllOS-ENU.exe"
                InstalledCheckRegKey = "SOFTWARE\Microsoft\NET Framework Setup\NDP\v4\Full"
                InstalledCheckRegValueName = "Release"
                InstalledCheckRegValueData = "394271"
                Arguments = "/q"
            }
        }
    }

    Enable-DSCDebug -BreakAll
    Wait-Debugger
    DotNET461ConfigurationDefinition -output "." 
    #Test-DscConfiguration -Path .\DotNET461ConfigurationDefinition -Verbose
    Start-DscConfiguration -Path .\DotNET461ConfigurationDefinition -Wait -Verbose 

`

The operating system the target node is running

OsName : Microsoft Windows 10 Enterprise OsOperatingSystemSKU : EnterpriseEdition OsArchitecture : 64-bit WindowsVersion : 1903 WindowsBuildLabEx : 18362.1.amd64fre.19h1_release.190318-1202 OsLanguage : en-US OsMuiLanguages : {en-US}

Version and build of PowerShell the target node is running

Name Value


PSVersion 5.1.18362.145
PSEdition Desktop
PSCompatibleVersions {1.0, 2.0, 3.0, 4.0...}
BuildVersion 10.0.18362.145
CLRVersion 4.0.30319.42000
WSManStackVersion 3.0
PSRemotingProtocolVersion 2.3
SerializationVersion 1.1.0.1

Version of the DSC module that was used ('dev' if using current dev branch)

8.8.0.0

reznet commented 5 years ago

It looks like the problem is related to the LCM. I tried running Invoke-DscResource and it also failed:

PS C:\Users\wieva\source\xPackageDebugging> Invoke-DscResource -Name xPackage -ModuleName xPSDesiredStateConfiguration -Method Test -Property @{Path="C:\installers\NDP461-KB3102436-x86-x64-AllOS-ENU.exe"; Name="";ProductId=""}
WARNING: [JEFFELAPTOP]:                            [DSCEngine] Warning LCM is in Debug 'ResourceScriptBreakAll' mode.
Resource script processing will be stopped to wait for PowerShell script debugger to attach.
WARNING: [JEFFELAPTOP]:                            [[xPackage]DirectResourceAccess] Resource is waiting for PowerShell
script debugger to attach.  Use the following commands to begin debugging this resource script:
Enter-PSSession -ComputerName JEFFELAPTOP -Credential <credentials>
Enter-PSHostProcess -Id 3424 -AppDomainName DscPsPluginWkr_AppDomain
Debug-Runspace -Id 4
PowerShell DSC resource MSFT_xPackageResource  failed to execute Test-TargetResource functionality with error message:
Object reference not set to an instance of an object.
    + CategoryInfo          : InvalidOperation: (root/Microsoft/...gurationManager:String) [], CimException
    + FullyQualifiedErrorId : ProviderOperationExecutionFailure
    + PSComputerName        : localhost

but when I applied an LCM configuration that set Refresh to Disabled:

[DSCLocalConfigurationManager()]
configuration LCMConfig
{
    Node localhost
    {
        Settings
        {
            RefreshMode = 'Disabled'
        }
    }
}

I was able to successfully use Invoke-DscResource:

PS C:\Users\wieva\source\xPackageDebugging> Invoke-DscResource -Name xPackage -ModuleName xPSDesiredStateConfiguration -Method Test -Property @{Path="C:\installers\NDP461-KB3102436-x86-x64-AllOS-ENU.exe"; Name="";ProductId=""}

InDesiredState
--------------
False

It's not clear yet how this issue is specific to the xPackage resource, since it did not happen with xEnvironment.

reznet commented 5 years ago

Well, looks like the issue is fixed for now. When I tried to apply my DSC configuration, it complained that Start-DscConfiguration was not allowed when the LCM Refresh mode is Disabled, so I created a new configuration to set Refresh mode to Push:

[DSCLocalConfigurationManager()]
configuration LCMConfigPush
{
    Node localhost
    {
        Settings
        {
            RefreshMode = 'Push'
        }
    }
}

I then applied that to the LCM and tried Start-DscConfiguration again, and it worked!

So if anyone else has trouble with this, Disable refresh on the LCM and then set it back to Push and see if that helps. Seems that the LCM somehow got confused or stuck and needed to be reset.

Hope this investigation helps someone else!

JustinGrote commented 5 years ago

@reznet I had the same problem. I killed the process, manually ran an invoke-dsc test, and then it started working again. Ghost in the machine somewhere...

EDIT: Also noticed it would fail when running DSC debug (enable-dscdebug -breakall) but work fine when disabled. This is reproducible consistently.

mhendric commented 5 years ago

Hey Guys, if this happens again, can someone run with -Verbose? That may help track down exactly where in Test-TargetResource the NullReferenceException is occurring so that we can add a proper check for null objects.

JustinGrote commented 5 years ago

@mhendric, I can regularly reproduce it if debug is on, happens every time, turn debug off, it doesn't.

Specifically using the Path and Name parameters, but not ProductID, after the software is already installed (doesn't happen if software isn't installed yet). Server 2012R2 (Azure Smalldisk Image) as the target.

mhendric commented 5 years ago

@JustinGrote, can you reproduce with Debug and Verbose? There's a bunch of Verbose statements in Test-TargetResource, so I'd like to see how many fire before the NullReferenceException occurs. Thanks.