Azure / nxtools

Azure Automanage Machine Configuration Linux DSC resources
Other
13 stars 13 forks source link

nxPackage - on system that uses dpkg (i.e. Ubuntu), crashes when package is not installed on the system #45

Closed eehret closed 10 months ago

eehret commented 1 year ago

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

I have an Ubuntu system on which I am trying to ensure that a number of packages are either present or not present. This operation crashes when the package in question isn't present. This happens both when I am trying to Ensure='Present' and when Ensure='Absent'.

It crashes in such a way that no compliance results for the entire configuration run are available to see. I would consider this to be a severe defect.

Verbose logs showing the problem

Here is an example involving the ldap-utils package (see comments below for another example when Ensure=Present, for appamor-utils package)

First, during the test operation this appears:

[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Displaying messages from the engine:
         WMI channel 1
         ResourceID: [nxPackage]ldap_client_not_installed
         Message : [vm-azam-ubuntu20]: LCM:  [ Start  Resource ]  [[nxPackage]ldap_client_not_installed]
[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Getting a registration instance for nxPackage
[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Moving the resource [nxPackage]ldap_client_not_instal>[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Getting Metaconfiguration details.
[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Executing operations for PS DSC resource nxPackage wi>[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Method Exec_PSProvider started with parameters
         Class name: nxPackage
         Resource ID: [nxPackage]ldap_client_not_installed
         Flags: 134217728
         Execution Mode: 12582912
         DSC resource Namespace: null
[2023-09-25 13:12:11.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Displaying messages from the engine:
         WMI channel 1
         ResourceID: [nxPackage]ldap_client_not_installed
         Message : [vm-azam-ubuntu20]: LCM:  [ Start  Test     ]  [[nxPackage]ldap_client_not_installed]
[2023-09-25 13:12:11.258] [PID 1453535] [TID 1453537] [PSPROVIDER] [INFO] [00000000-0000-0000-0000-000000000000] getPSModulePath(). psModulePath:/var/lib/GuestConfig/Configuration/Ubuntu20-CISv201-section2-0_>[2023-09-25 13:12:11.356] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Activity Loading default keywords
CurrentOperation [vm-azam-ubuntu20] Get-DscResource
StatusDescription Processing
 PercentComplete 0
 SecondsRemaining 0
[2023-09-25 13:12:12.356] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Activity Getting module list
CurrentOperation [vm-azam-ubuntu20] Get-DscResource
StatusDescription Processing
 PercentComplete 0
 SecondsRemaining 0
[2023-09-25 13:12:14.261] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Activity Creating resource list
CurrentOperation [vm-azam-ubuntu20] Get-DscResource
StatusDescription Processing
 PercentComplete 0
 SecondsRemaining 0
[2023-09-25 13:12:14.659] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Activity Loading default keywords
CurrentOperation [vm-azam-ubuntu20] Get-DscResource
StatusDescription Processing
 PercentComplete 0
 SecondsRemaining 0
[2023-09-25 13:12:14.754] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Activity Getting module list
CurrentOperation [vm-azam-ubuntu20] Get-DscResource
StatusDescription Processing
 PercentComplete 0
 SecondsRemaining 0
[2023-09-25 13:12:18.257] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Activity Creating resource list
CurrentOperation [vm-azam-ubuntu20] Get-DscResource
StatusDescription Processing
 PercentComplete 0
[2023-09-25 13:12:21.354] [PID 1453535] [TID 1453537] [DSCEngine] [ERROR] [00000000-0000-0000-0000-000000000000] [/__w/1/s/src/dsc/gc_diagnostics/dsc_logger.cpp:157] [/__w/1/s/src/dsc/engine/ConfigurationMana>Error Message: dpkg-query: package 'ldap-utils' is not installed and no information is available
Message ID: OMI:MI_Result:1
Error Category: 0
Error Code: 1
Error Type:
[2023-09-25 13:12:21.356] [PID 1453535] [TID 1453537] [DSCEngine] [ERROR] [00000000-0000-0000-0000-000000000000] [/__w/1/s/src/dsc/gc_diagnostics/dsc_logger.cpp:157] [/__w/1/s/src/dsc/engine/ConfigurationMana>Error Message: Use dpkg --info (= dpkg-deb --info) to examine archive files.
Message ID: OMI:MI_Result:1
Error Category: 0
Error Code: 1
Error Type:
[2023-09-25 13:12:21.360] [PID 1453535] [TID 1453537] [DSCEngine] [ERROR] [00000000-0000-0000-0000-000000000000] [/__w/1/s/src/dsc/gc_diagnostics/dsc_logger.cpp:157] [/__w/1/s/src/dsc/engine/ConfigurationMana>Error Message: InvokeDscResource() failed. errorMessage:The PowerShell DSC resource with className:nxPackage moduleName:nxtools moduleVersion:1.2.0 threw one or more non-terminating errors, while running the >Message ID: OMI:MI_Result:1
Error Category: 0
Error Code: 1
Error Type:
[2023-09-25 13:12:21.360] [PID 1453535] [TID 1453537] [DSCEngine] [INFO] [00000000-0000-0000-0000-000000000000] Job 819771db-e0b1-451f-8513-00f34ede692d : Displaying messages from the engine:
         WMI channel 1
         ResourceID: [nxPackage]ldap_client_not_installed
         Message : [vm-azam-ubuntu20]: LCM:  [ End    Test     ]  [[nxPackage]ldap_client_not_installed]  in 0.4732 seconds.
[2023-09-25 13:12:21.360] [PID 1453535] [TID 1453537] [DSCEngine] [ERROR] [00000000-0000-0000-0000-000000000000] [/__w/1/s/src/dsc/gc_diagnostics/dsc_logger.cpp:157] [/__w/1/s/src/dsc/engine/ca/CAInfrastructu>[2023-09-25 13:12:21.360] [PID 1453535] [TID 1453537] [DSCEngine] [ERROR] [00000000-0000-0000-0000-000000000000] [/__w/1/s/src/dsc/gc_diagnostics/dsc_logger.cpp:157] [/__w/1/s/src/dsc/engine/ConfigurationMana>Error Message: The PowerShell DSC resource with className:nxPackage moduleName:nxtools moduleVersion:1.2.0 threw one or more non-terminating errors, while running the Get-DscResource functionality
Message ID: OMI:MI_Result:1
Error Category: 0
Error Code: 1
Error Type:

Then a few lines later in the log at the end of the configuration run, we see this:

InvokeDscResource() failed. errorMessage:The PowerShell DSC resource with className:nxPackage moduleName:nxtools moduleVersion:1.2.0 threw one or more non-terminating errors, while running the Get-DscResource>The PowerShell DSC resource with className:nxPackage moduleName:nxtools moduleVersion:1.2.0 threw one or more non-terminating errors, while running the Get-DscResource functionality
dpkg-query: package 'ldap-utils' is not installed and no information is available
Use dpkg --info (= dpkg-deb --info) to examine archive files.
InvokeDscResource() failed. errorMessage:The PowerShell DSC resource with className:nxPackage moduleName:nxtools moduleVersion:1.2.0 threw one or more non-terminating errors, while running the Get-DscResource>The PowerShell DSC resource with className:nxPackage moduleName:nxtools moduleVersion:1.2.0 threw one or more non-terminating errors, while running the Get-DscResource functionality
The SendConfigurationApply function did not succeed. LCM failed to start desired state configuration manually.
' reasoncode 'DscConfigurationDeployment'.

Suggested solution to the issue

I traced the calls to pinpoint where the issue appears to be. At a high level, focusing in on just the calls involving queries to the package manager, the calls flow like this nxPackage -> Get-nxPackage -> Get-nxDpkgPackage -> Get-nxDpkgPackageInstalled

The problem seems to be originating from the following line: https://github.com/Azure/nxtools/blob/b4db4c002bd90c9905a38e7f2b7491a5aff9f92f/source/Public/Packages/dpkg/Get-nxDpkgPackage.ps1#L49C11-L49C11

That call results in an error being thrown, which is not being handled correctly. I verified this by invoking the same command manually; I can see that internally dkpg must be making a call to dpkg-query, which is throwing the error. Here's what that looks like:

PS /home/azops.eric.ehret> Invoke-NativeCommand -Executable 'dpkg' -Parameters  @('--status', "ldap-utils")
dpkg-query: package 'ldap-utils' is not installed and no information is available
Use dpkg --info (= dpkg-deb --info) to examine archive files,
and dpkg --contents (= dpkg-deb --contents) to list their contents.

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

    nxPackage ldap_client_not_installed
    {
      Name = "ldap-utils"
      Ensure = "Absent"
    }

The operating system the target node is running

Ubuntu 20.04 LTS

Version and build of PowerShell the target node is running

7.3.6

Version of the DSC module that was used

1.2.0

eehret commented 1 year ago

Note that I'm getting an identical error with Ensure=Present for the apparmor-utils package.

    nxPackage apparmor_utils_installed
    {
      Name = "apparmor-utils"
      Ensure = "Present"
    }

So the scope of the failure seems to extend beyond what I originally stated.

MutemwaRMasheke commented 1 year ago

Thank you for raising this with us @eehret! We are actively investigating this.

eehret commented 1 year ago

@MutemwaRMasheke Hi. How's it going with this? nxPackage is pretty key to our overall automanage machine configuration deployment, so we're eager to see progress on this, as well as the other nxPackage issues I've raised. Thanks :)

MutemwaRMasheke commented 10 months ago

Hello @eerhet! We just closed on fixing this so you should be good to go! Thanks for reaching out.

eehret commented 10 months ago

@MutemwaRMasheke Hi. Thanks, that sounds promising. Unfortunately we are still waiting for Microsoft to publish the updated module to PowerShell Gallery. When can we expect that? I will not be able to test and confirm how well this fix resolves our problem until that is done.

MutemwaRMasheke commented 9 months ago

Just published a new nxtools release with fixes for this and other Github issues. https://www.powershellgallery.com/packages/nxtools/1.4.0

Thank you for your feedback!