Troubleshooting a Custom Script Extension as part of an ARM Template Deployment

I recently decided to test the use of a Custom Script Extension, as I wanted to deploy a VM with client software installed. I created a Powershell script that downloaded, extracted and installed the MSI tool Orca. If I could get this to deploy and run successfully it would give me a basis to install any software I needed, plus perform any other configuration I might need.

I added lots of error logging to the script so that I would have plenty of information when it came to troubleshooting. The script I used is located here.

Create ARM Template

I took an existing ARM template that I used to create a Windows 10 VM, renamed it and added the Custom Script Extension code. The template is here and the parameter file I used is here.

The Custom Script Extension code itself is shown here.

To deploy the template I used the following Powershell commands (after installing the Az module).

Connect-AzAccount
New-AzResourceGroupDeployment -Name TestDeployment -ResourceGroupName HiggCon -TemplateFile C:\Dev\VM\VMcse.template.json -TemplateParameterFile C:\Dev\VM\VM.parameters.json

And that is where the problems started…

There is a part of me that always hopes that something like this will work first time, but I have to be honest, it hardly ever does! So the error I got back is below.

The deployment failed

I looked back through my Custom Script Extension code (which I had got, and edited, from the Microsoft documentation), and found the following line that I hadn’t noticed.

"name": "virtualMachineName/config-app",

Hmm, that didn’t look right, so I changed it to this.

"name": "[Concat(parameters('virtualMachineName'),'/config-app')]",

Hurrah, the deployment was then successful…but.

Looking in Azure, I could see that the VM appeared to have been created successfully. Unfortunately, after logging into the VM, Orca wasn’t installed.

I looked in the Eventlog. There were no entries from my script so it looked like the script hadn’t run, but why?

First I looked in the C:\WindowsAzure\Logs\WaAppAgent.Log file. It looked like some Custom ScriptExtensions had run successfully, but they looked Azure specific, with no hint that my script had run. After some digging I managed to find the VMConfig.ps1 file, that was my script, in C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.10.8\Downloads\0. So that showed that the script had been copied down correctly. I tried running the script manually…and got the “Running Scripts is disabled” message. Doh!

I changed my command to execute to the following, deleted the VM and reran the deployment.

"commandToExecute": "powershell -ExecutionPolicy Unrestricted -File VMConfig.ps1"

Success! My Deployment worked AND my script worked. Orca was installed successfully. My script had also written successfully to the Event Viewer.

I looked in C:\WindowsAzure\Logs\WaAppAgent.Log and found these entries near the bottom.

Its not exactly clear, but I think it is related to my script as it wasn’t there previously. The middle line includes this “ExtensionName: ”’ seqNo ‘0’ reached terminal state”. My script was downloaded to a directory named 0, so my thinking is that they are related. The end of the last line stating “completed with status: RunToCompletion” sounds right too. Unfortunately it is difficult to know definitely.

Summary

So what have we learnt? Well first of all, I think that when writing a script to deploy using Custom Script Extension, it makes a lot of sense to include as much logging as possible, and to test if fully before trying to deploy, as it will be difficult to determine what is wrong otherwise.

The deployment can really be split into two sections, Deployment and Execution.

Deployment

It is easy to misconfigure the ARM template, as I found to my cost. I used Visual Studio Code to edit the template as it supports ARM templates and identifies error syntax. Make sure all errors are resolved before trying to deploy. The “New-AzResourceGroupDeployment” Powershell cmdlet will tell you if the deployment was successful or not. The error messages aren’t always easy to interpret though.

Execution

Once successfully deployed, if you don’t get the result you are expecting check the

C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.10.8\Downloads

directory for a subdirectory holding your script. That way you know that it is actually there. Then trying running the script and see what error messages you get.

I also looked in

C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.10.8\Status

and found a “0.status” file that gave me a little more information on my script, and a success status code.

In

C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.10.8\RuntimeSettings

I found a file named “0”, which contained, amongst other things, the URL the script was download from and the command to execute. So be aware if you are working in a secure environment, or are using a public repository.

Logging to the Windows Eventlog using Powershell

When automating tasks, such as software installation, using Powershell, it is useful to output to a logfile for fault finding purposes, but I have never liked the idea of creating log files, as these are not easily managed and can build up over time. Another problem is that no-one, other than yourself, is likely to know that the logs exist, or where it is located. Everyone, however, knows about the Windows Eventlog and how to access it, so it makes sense to log your information there.

Adding script output to the Windows Eventlog is reasonably straightforward, but has to be done in the correct way. To use the Eventlog you need to create two items, a new Eventlog and a Source for the log entries. Optionally you can then configure the log that you have created. The code for this is below.

New-EventLog -LogName Application -Source "Documentum_Webtop-AddIn_1.0_x86_R01"
Limit-EventLog -OverflowAction OverWriteAsNeeded -MaximumSize 64KB -LogName Application

The first line of code creates a log called Application, with a source called Documentum_Webtop-AddIn_1.0_x86_R01. The source is simply the packaged application that I am going to be installing. Using this name makes it easy to identify log entries from the application within the Eventlog.

The second line of code sets the maximum size of the log to 64Kb and configures the log to overwrite when it gets to the maximum size.

I can now write to the Eventlog by using the following command.

Write-EventLog -LogName "Application" -Source "Documentum_Webtop-AddIn_1.0_x86_R01" -EventID 25001  -EntryType Information -Message "Begining install of Application Documentum_Webtop-AddIn_1.0_x86_R01"

The EventID should be 25000 or greater, as this range is undocumented.

ErrorType can be Information, Warning or Error.

When writing install and uninstall scripts, I like to include the New-Eventlog and Limit-EventLog entries at the beginning of the Install script, and then remove the Source at the end of the Uninstall script. This keeps things tidy, especially if you have a large number of applications to install.

To remove the source use the following command.

Remove-EventLog -Source "Documentum_Webtop-AddIn_1.0_x86_R01"

Deploying Objects in Azure using ARM Templates

Object creation in Azure can be automated in many ways, one of which is by using ARM Templates. ARM Templates can either be authored from scratch, or can be based on manually deployed objects or Resource Groups.

In this post I simply want to detail the commands to use to deploy ARM Templates whether they are located locally, or in GitHub.

Start by connecting your Powershell session to Azure, using the command below (ensure that you have installed the Azure Powershell module previously).

Connect-AzAccount

This will prompt you for your Azure credentials and give you access to create objects in your Azure subscription.

Deploy Local ARM Templates

The command to deploy ARM templates that are stored locally is as follows.

New-AzResourceGroupDeployment -Name DeploymentName -ResourceGroupName <NameofResourceGroup> -TemplateFile "C:\DefaultVNETandNSG.json" -TemplateParameterFile "C:\DefaultVNETandNSG.parameters.json"

-Name is the name you wish to give this deployment.

-ResourceGroupName is the name of the Resource Group the objects will be created in.

-TemplateFile is the path to the template file you are using.

-TemplateParameterFile is the path to the parameter file that you are using (if any).

Deploying Templates stored in GitHub

The command to deploy templates store in GitHub is only slightly different.

New-AzResourceGroupDeployment -Name TestDeployment -ResourceGroupName <NameofResourceGroup> -TemplateUri "https://raw.githubusercontent.com/<NameofRepository>/Templates/master/DefaultVNETandNSG.json" -TemplateParameterUri "https://raw.githubusercontent.com/<NameofRepository>/Templates/master/DefaultVNETandNSG.parameters.json"

Only the following switches are different with this command.

-TemplateUri is the RAW URL for the template file.

-TemplateParameterUri is the RAW URL for the parameter file (if used).

*** Remember to only use the RAW URL for the paths for both files. Otherwise the deployment will fail. ***