Search code examples
jsonazuretemplatesdsc

Azure ARM Templates - DSC (new schema) not running scripts and not returning an error?


I've just converted a ARM template (DC deployment) to use the newer 2016 DSC schema. I thought I had formatted my JSON properly and when I deploy the template it provisions successfully, happy days! However it's not, although the template is deploying successfully the DSC configuration files aren't being run, the DSC extension is installed though. The configuration files are held on an Azure blob and in the old schema I constructed the URL using parameters for the URL and SAS token. The new schema splits all this up and I think the issue is that the SAS token isn't being added to the URL.

For info the configuration file provisions the ADDS feature and sets up the forest.

As a test I removed the configuration files from the blob storage and ran the template again, and again it provisioned properly....it appears to be skipping the configuration part complete...very odd.

This is the DSC extension snippet, can anyone spot any typos or incorrectly placed brackets? I've been staring at this for about 5 hours now so to me it's just one big blur.

            "resources": [
                {
                    "type": "Microsoft.Compute/virtualMachines/extensions",
                    "name": "[concat(variables('dc2name'), '/CreateADBDC')]",
                    "apiVersion": "2019-03-01",
                    "location": "[resourceGroup().location]",
                    "dependsOn": [
                        "[resourceId('Microsoft.Compute/virtualMachines', variables('dc2name'))]",
                        "[resourceId('Microsoft.Compute/virtualMachines/extensions', variables('dc1name'), 'CreateADForest')]"
                    ],
                    "properties": {
                        "publisher": "Microsoft.Powershell",
                        "type": "DSC",
                        "typeHandlerVersion": "2.77",
                        "autoUpgradeMinorVersion": true,
                        "settings": {
                            "WMFVersion": "latest",
                            "configuraton": {
                            "url": "[concat(parameters('Artifacts Location'), '/dsc/CreateADBDC.zip')]",
                            "script": "CreateADBDC.ps1",
                            "function": "CreateADBDC"
                            },
                            "configurationArguments": {
                                "DomainName": "[parameters('Domain Name')]",
                                "DNSServer": "[variables('dc1ipaddress')]"
                            }
                        },
                        "protectedSettings": {
                            "configurationArguments": {
                              "adminCreds": {
                                    "UserName": "[parameters('Administrator User')]",
                                    "Password": "[parameters('Administrator Password')]"
                                    }
                                },
                            "configurationUrlSasToken": "[parameters('Artifacts Location SAS Token')]"
                        }
                    }
                }
            ]

Below is the deployment_operations output, (I've removed the sensitive info). What I don't understand is the difference between the "Request" section verses the "Response", there appears anything in the "protectedsettings" is missing, is that normal?

      "request": {
        "content": {
          "location": "uksouth",
          "properties": {
            "publisher": "Microsoft.Powershell",
            "type": "DSC",
            "typeHandlerVersion": "2.77",
            "autoUpgradeMinorVersion": true,
            "settings": {
              "WMFVersion": "latest",
              "configuraton": {
                "url": "https://xxxxx.blob.core.windows.net/dsc/CreateADBDC.zip",
                "script": "CreateADBDC.ps1",
                "function": "CreateADBDC"
              },
              "configurationArguments": {
                "DomainName": "domain.co.uk",
                "DNSServer": "10.x.x.250"
              }
            },
            "protectedSettings": {
              "configurationArguments": {
                "adminCreds": {
                  "UserName": "admin",
                  "Password": "password"
                }
              },
              "configurationUrlSasToken": "stuffhere"
            }
          }
        }
      },
      "response": {
        "content": {
          "properties": {
            "autoUpgradeMinorVersion": true,
            "settings": {
              "WMFVersion": "latest",
              "configuraton": {
                "url": "https://xxxxxx.blob.core.windows.net/dsc/CreateADBDC.zip",
                "script": "CreateADBDC.ps1",
                "function": "CreateADBDC"
              },
              "configurationArguments": {
                "DomainName": "domain.co.uk",
                "DNSServer": "10.x.x.250"
              }
            },
            "provisioningState": "Succeeded",
            "instanceView": {
              "name": "CreateADBDC",
              "type": "Microsoft.Powershell.DSC",
              "typeHandlerVersion": "2.77.0.0",
              "substatuses": [
                {
                  "code": "ComponentStatus/DscConfigurationLog/succeeded",
                  "level": "Info",
                  "displayStatus": "Provisioning succeeded",
                  "message": ""
                },
                {
                  "code": "ComponentStatus/DscExtensionLog/succeeded",
                  "level": "Info",
                  "displayStatus": "Provisioning succeeded",
                  "message": "[2019-03-14 20:06:49Z] Getting handler execution status HKLM:\\SOFTWARE\\Microsoft\\Azure\\DSC\\2.77.0.0\\Status ..
                },
                {
                  "code": "ComponentStatus/Metadata/succeeded",
                  "level": "Info",
                  "displayStatus": "Provisioning succeeded",
                  "message": "VMUUId=5CE28735-xxxx-xxxx-xxxx-53AA96F3A520;AgentId=BAFCAC0D-xxxx-xxxx-xxxx-0022480775AE;"
                }
              ],
              "statuses": [
                {
                  "code": "ProvisioningState/succeeded",
                  "level": "Info",
                  "displayStatus": "Provisioning succeeded",
                  "message": "PowerShell DSC has been enabled.",
                  "time": "2019-03-14T20:07:03+00:00"
                }
              ]
            },
            "publisher": "Microsoft.Powershell",
            "type": "DSC",
            "typeHandlerVersion": "2.77"
          },
          "type": "Microsoft.Compute/virtualMachines/extensions",
          "location": "uksouth",
          "id": "/subscriptions/xxxxx/resourceGroups/RG/providers/Microsoft.Compute/virtualMachines/DC2/extensions/CreateADBDC",
          "name": "CreateADBDC"
        }
      }
    }
  },

Update:

Searching the DSC extension logs I see this error:

[ERROR] occurred while invoking events for telemetry The property 'Configuration' 
cannot be found on this object. Verify that the property exists.

And a bit further down the log this:

A DSC configuration was not provided. PowerShell DSC has been enabled on the VM, will exit now.

So that explains why it's not running the scripts but the configuration property is in the template....very baffled now!

Update 2

PowerShell command executed by DSC

configuration CreateADBDC {
    Param (
        # Get deployment details
        [Parameter(Mandatory)]
        [String]$DNSServer,
        [Parameter(Mandatory)]
        [String]$DomainName,

        # Credentials
        [Parameter(Mandatory)]
        [System.Management.Automation.PSCredential]$Admincreds,

        [Int]$RetryCount = 500,
        [Int]$RetryIntervalSec = 3
    )

    Import-DscResource -ModuleName PSDesiredStateConfiguration, xStorage, xNetworking, xActiveDirectory, xPendingReboot
    $Interface = Get-NetAdapter | Where-Object { $_.Name -Like "Ethernet*" } | Select-Object -First 1
    [System.Management.Automation.PSCredential]$DomainCreds = New-Object System.Management.Automation.PSCredential ("${DomainName}\$($Admincreds.UserName)", $Admincreds.Password)
    $features = @("AD-Domain-Services", "RSAT-ADDS-Tools", "RSAT-AD-AdminCenter")

    Node localhost {
        LocalConfigurationManager {
            RebootNodeIfNeeded = $true
        }

        xWaitforDisk Disk2 {
            DiskNumber       = 2
            RetryIntervalSec = $RetryIntervalSec
            RetryCount       = $RetryCount
        }

        xDisk ADDataDisk {
            DiskNumber  = 2
            DriveLetter = "F"
            DependsOn   = "[xWaitForDisk]Disk2"
        }

        WindowsFeatureSet Prereqs {
            Name                 = $features
            Ensure               = "Present"
            IncludeAllSubFeature = $true
        } 

        xDnsServerAddress DnsServerAddress {
            Address        = $DNSServer
            InterfaceAlias = $Interface.Name
            AddressFamily  = "IPv4"
            DependsOn      = "[WindowsFeatureSet]Prereqs"
        }

        xWaitForADDomain DscForestWait {
            DomainName           = $DomainName
            DomainUserCredential = $DomainCreds
            RetryCount           = $RetryCount
            RetryIntervalSec     = $RetryIntervalSec
        }

        xADDomainController BDC {
            DomainName                    = $DomainName
            DomainAdministratorCredential = $DomainCreds
            SafemodeAdministratorPassword = $DomainCreds
            DatabasePath                  = "F:\NTDS"
            LogPath                       = "F:\NTDS"
            SysvolPath                    = "F:\SYSVOL"
            DependsOn                     = "[xWaitForADDomain]DscForestWait"
        }

        xPendingReboot RebootAfterPromotion {
            Name      = "RebootAfterDCPromotion"
            DependsOn = "[xADDomainController]BDC"
        }
    }
}

Update 3

Complete DSC log:

VERBOSE: [2019-03-15 09:54:33Z] Extension request for sequence number 0 attempting to create lock.0 mutex
VERBOSE: [2019-03-15 09:54:33Z] Attempting to grab mutex DscExtensionHandler_Lock for sequence number 0
VERBOSE: [2019-03-15 09:54:33Z] Acquired lock for extension instance for sequence number 0
VERBOSE: [2019-03-15 09:54:33Z] Attempting to acquire extension lock
VERBOSE: [2019-03-15 09:54:33Z] Attempting to grab mutex DscExtensionHandler_Lock
VERBOSE: [2019-03-15 09:54:33Z] Acquired lock for extension
VERBOSE: [2019-03-15 09:54:33Z] lock does not exist: begin processing
VERBOSE: [2019-03-15 09:54:33Z] Starting DSC Extension ...
VERBOSE: [2019-03-15 09:54:33Z] Getting handler execution status HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status 
...
VERBOSE: [2019-03-15 09:54:33Z] Updating execution status (HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status)
VERBOSE: [2019-03-15 09:54:33Z] Transitioning to DataValidation state ...
VERBOSE: [2019-03-15 09:54:33Z] Settings handler status to 'transitioning' 
(C:\Packages\Plugins\Microsoft.Powershell.DSC\2.77.0.0\Status\0.status)
VERBOSE: [2019-03-15 09:54:33Z] Retrieving system information ...
VERBOSE: [2019-03-15 09:54:37Z]     OS Version : 10.0
VERBOSE: [2019-03-15 09:54:37Z]     Server OS  : True
VERBOSE: [2019-03-15 09:54:37Z]     64-bit OS  : True
VERBOSE: [2019-03-15 09:54:37Z]     PS Version : 5.1.17763.316
VERBOSE: [2019-03-15 09:54:37Z] Validating user provided settings for the DSC Extension Handler ...
VERBOSE: [2019-03-15 09:54:37Z] Reading handler settings from 
C:\Packages\Plugins\Microsoft.Powershell.DSC\2.77.0.0\RuntimeSettings\0.settings
VERBOSE: [2019-03-15 09:54:37Z] Found protected settings on Azure VM. Decrypting.
VERBOSE: [2019-03-15 09:54:40Z] Updating user preference for Data Collection ......
VERBOSE: [2019-03-15 09:54:40Z] Get DSC Extension Handler install status  ...
VERBOSE: [2019-03-15 09:54:40Z]  Status: NotInstalled
VERBOSE: [2019-03-15 09:54:40Z] Updating execution status (HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status)
VERBOSE: [2019-03-15 09:54:40Z] Transitioning to DownloadHotfixes state ...
VERBOSE: [2019-03-15 09:54:40Z] Getting handler execution status HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status 
...
VERBOSE: [2019-03-15 09:54:40Z] Settings handler status to 'transitioning' 
(C:\Packages\Plugins\Microsoft.Powershell.DSC\2.77.0.0\Status\0.status)
VERBOSE: [2019-03-15 09:54:40Z] Downloading wmf hotfixes (if any) required for the DSC Extension install ...
VERBOSE: [2019-03-15 09:54:42Z] Retrieving WMF download information (WMF_5.1-Windows_10.0-x64)...
VERBOSE: [2019-03-15 09:54:42Z] Updating execution status (HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status)
VERBOSE: [2019-03-15 09:54:42Z] Transitioning to InstallExtension state ...
VERBOSE: [2019-03-15 09:54:42Z] Getting handler execution status HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status 
...
VERBOSE: [2019-03-15 09:54:42Z] Settings handler status to 'transitioning' 
(C:\Packages\Plugins\Microsoft.Powershell.DSC\2.77.0.0\Status\0.status)
VERBOSE: [2019-03-15 09:54:43Z] DSC Extension Install Status: NotInstalled
VERBOSE: [2019-03-15 09:54:43Z] Installing the DSC Extension...
VERBOSE: [2019-03-15 09:54:43Z] Setting install status to 'InProgress' 
(HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\InstallStatus)
VERBOSE: [2019-03-15 09:54:43Z] Settings handler status to 'transitioning' 
(C:\Packages\Plugins\Microsoft.Powershell.DSC\2.77.0.0\Status\0.status)
VERBOSE: [2019-03-15 09:54:43Z] Test if WMF 5PP is installed on the machine ...
VERBOSE: [2019-03-15 09:54:45Z] Retrieving WMF download information (WMF_5.0PP-Windows_10.0-x64)...
VERBOSE: [2019-03-15 09:54:48Z] Retrieving WMF download information (WMF_5.1-Windows_10.0-x64)...
VERBOSE: [2019-03-15 09:54:48Z] Enabling WINRM listeners...
VERBOSE: [2019-03-15 09:54:50Z] Configured LocalAccountTokenFilterPolicy to grant administrative rights remotely to 
local users. 

VERBOSE: [2019-03-15 09:54:51Z] The DSC Extension was installed successfully
VERBOSE: [2019-03-15 09:54:51Z] Setting install status to 'Installed' 
(HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\InstallStatus)
VERBOSE: [2019-03-15 09:54:51Z] Initializing handler metadata ...
VERBOSE: [2019-03-15 09:54:53Z] AgentID is 6111F68C-4708-11E9-ACF3-000D3AXX0539 ...
VERBOSE: [2019-03-15 09:54:53Z] VMUUId is D077C845-7564-47F4-B76B-C9FAXXEA7A61 ...
VERBOSE: [2019-03-15 09:54:53Z] Azure Resource ID is  ...
VERBOSE: [2019-03-15 09:54:53Z] Loading VM agent telemetry assemblies ...
VERBOSE: [2019-03-15 09:54:54Z] [ERROR] occurred while invoking events for telemetry The property 'Configuration' 
cannot be found on this object. Verify that the property exists.
VERBOSE: [2019-03-15 09:54:54Z] Updating execution status (HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status)
VERBOSE: [2019-03-15 09:54:54Z] Transitioning to ProcessConfiguration state ...
VERBOSE: [2019-03-15 09:54:54Z] Getting handler execution status HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status 
...
VERBOSE: [2019-03-15 09:54:54Z] A DSC configuration was not provided. PowerShell DSC has been enabled on the VM, will 
exit now.
VERBOSE: [2019-03-15 09:54:54Z] Settings handler status to 'success' 
(C:\Packages\Plugins\Microsoft.Powershell.DSC\2.77.0.0\Status\0.status)
VERBOSE: [2019-03-15 09:54:54Z] Updating execution status (HKLM:\SOFTWARE\Microsoft\Azure\DSC\2.77.0.0\Status)
VERBOSE: [2019-03-15 09:54:54Z] Transitioning to Completed state ...
VERBOSE: [2019-03-15 09:54:54Z] Releasing SameSeq mutex
VERBOSE: [2019-03-15 09:54:54Z] Releasing mutex DscExtensionHandler_Lock

Solution

  • in this case the error was due to a typo in the template: configuraon, instead of configuration