{"id":4217,"date":"2017-01-11T00:00:00","date_gmt":"2017-01-11T00:00:00","guid":{"rendered":"https:\/\/azure.microsoft.com\/blog\/azure-virtual-machine-internals-part-1"},"modified":"2025-06-11T05:29:24","modified_gmt":"2025-06-11T12:29:24","slug":"azure-virtual-machine-internals-part-1","status":"publish","type":"post","link":"https:\/\/azure.microsoft.com\/en-us\/blog\/azure-virtual-machine-internals-part-1\/","title":{"rendered":"Azure Virtual Machine Internals \u2013 Part 1"},"content":{"rendered":"\n

Introduction<\/h2>\n\n\n\n

The Azure cloud services are composed of elements from Compute, Storage, and Networking. The compute building block is a Virtual Machine (VM), which is the subject of discussion in this post. Web search will yield large amounts of documentation regarding the commands, APIs and UX for creating and managing VMs. This is not a 101 or \u2018How to\u2019 and the reader is for the most part expected to already be familiar with the topics of VM creation and management. The goal of this series is to look at what is happening under the covers as a VM goes thru its various states.<\/p>\n\n\n\n

Azure provides IaaS and PaaS VMs; in this post when we refer to a VM we mean the IaaS VM. There are two control plane stacks in Azure, Azure Service Management (ASM) and Azure Resource Manager (ARM). We will be limiting ourselves to ARM since it is the forward looking control plane.<\/p>\n\n\n\n

ARM exposes resources like VM, NIC but in reality ARM is a thin frontend layer and the resources themselves are exposed by lower level resource providers like Compute Resource Provider (CRP), Network Resource Provider (NRP) and Storage Resource Provider (SRP). Portal calls ARM which in turn calls the resource providers.<\/p>\n\n\n\n

Getting Started<\/h2>\n\n\n\n

For most of the customers, their first experience creating a VM is in the Azure Portal<\/a>. I did the same and created a VM of size \u2018Standard DS1 v2\u2019 in the West US region. I mostly stayed with the defaults that the UI presented but chose to add a \u2018CustomScript\u2019 extension. When prompted I provided a local file \u2018Sample.ps\u2019 as the PowerShell script for the \u2018CustomScript\u2019 extension. The PS script itself is a single line Get-Process.<\/p>\n\n\n\n

The VM provisioned successfully but the overall ARM template deployment failed (bright red on my Portal dashboard). Couple clicks showed that the \u2018CustomScript\u2019 extension had failed and the Portal showed this message:<\/p>\n\n\n

\n{\n  \"status\": \"Failed\",\n  \"error\": {\n    \"code\": \"ResourceDeploymentFailure\",\n    \"message\": \"The resource operation completed with terminal provisioning state 'Failed'.\",\n    \"details\": [\n      {\n        \"code\": \"DeploymentFailed\",\n        \"message\": \"At least one resource deployment operation failed. Please list deployment operations for details. Please see https:\/\/aka.ms\/arm-debug for usage details.\",\n        \"details\": [\n          {\n            \"code\": \"Conflict\",\n            \"message\": \"{rn  \"status\": \"Failed\",rn  \"error\": {rn    \"code\": \"ResourceDeploymentFailure\",rn    \"message\": \"The resource operation completed with terminal provisioning state 'Failed'.\",rn    \"details\": [rn      {rn        \"code\": \"VMExtensionProvisioningError\",rn        \"message\": \"VM has reported a failure when processing extension 'CustomScriptExtension'. Error message: \"Finished executing command\".\"rn      }rn    ]rn  }rn}\"\n          }\n        ]\n      }\n    ]\n  }\n}\n<\/pre><\/div>\n\n\n
It wasn\u2019t immediately clear what had gone wrong. We can dig from here and as is often true, failures teach us more than successes.<\/p>\n\n\n\n
I RDPed to the just provisioned VM. The logs for the VM Agent are in C:WindowsAzureLogs. The VM Agent is a system agent that runs in all IaaS VMs (customers can opt out if they would like). The VM Agent is necessary to run extensions. Let\u2019s peek into the logs for the CustomScript Extension:<\/p>\n\n\n
\nC:WindowsAzureLogsPluginsMicrosoft.Compute.CustomScriptExtension1.8CustomScriptHandler\n\n[1732+00000001] [08\/14\/2016 06:19:17.77] [INFO] Command execution task started. Awaiting completion...\n\n[1732+00000001] [08\/14\/2016 06:19:18.80] [ERROR] Command execution finished. Command exited with code: -196608\n<\/pre><\/div>\n\n\n
The fact that the failure logs are cryptic hinted that something catastrophic had happened. So I re-looked at my input and realized that I had the file extension for the PS script wrong. I had it as Sample.ps when it should have been Sample.ps1. I updated the VM this time specifying the script file with the right extension. This succeeded as shown by more records appended to the log file mentioned above.
 <\/p>\n\n\n
\n[3732+00000001] [08\/14\/2016 08:42:24.04] [INFO] HandlerSettings = ProtectedSettingsCertThumbprint: , ProtectedSettings: {}, PublicSettings: {FileUris: [https:\/\/iaasv2tempstorewestus.blob.core.windows.net\/vmextensionstemporary-10033fff801becb5-20160814084130535\/simple.ps1?sv=2015-04-05&sr=c&sig=M3qa7lS%2BZwp%2B8Tytqf1VEew4YaAKvvYn1yzGrPfSwyw%3D&se=2016-08-15T08%3A41%3A30Z&sp=rw], CommandToExecute: powershell -ExecutionPolicy Unrestricted -File simple.ps1 }\n\n[3732+00000001] [08\/14\/2016 08:42:24.04] [INFO] Downloading files specified in configuration...\n\n[3732+00000001] [08\/14\/2016 08:42:24.05] [INFO] DownloadFiles: fileUri = https:\/\/iaasv2tempstorewestus.blob.core.windows.net\/vmextensionstemporary-10033fff801becb5-20160814084130535\/simple.ps1?sv=2015-04-05&sr=c&sig=M3qa7lS+Zwp+8Tytqf1VEew4YaAKvvYn1yzGrPfSwyw=&se=2016-08-15T08:41:30Z&sp=rw\n\n[3732+00000001] [08\/14\/2016 08:42:24.05] [INFO] DownloadFiles: Initializing CloudBlobClient with baseUri = https:\/\/iaasv2tempstorewestus.blob.core.windows.net\/\n\n[3732+00000001] [08\/14\/2016 08:42:24.22] [INFO] DownloadFiles: fileDownloadPath = Downloads\n\n[3732+00000001] [08\/14\/2016 08:42:24.22] [INFO] DownloadFiles: asynchronously downloading file to fileDownloadLocation = Downloadssimple.ps1\n\n[3732+00000001] [08\/14\/2016 08:42:24.24] [INFO] Waiting for all async file download tasks to complete...\n\n[3732+00000001] [08\/14\/2016 08:42:24.29] [INFO] Files downloaded. Asynchronously executing command: 'powershell -ExecutionPolicy Unrestricted -File simple.ps1 '\n\n[3732+00000001] [08\/14\/2016 08:42:24.29] [INFO] Command execution task started. Awaiting completion...\n\n[3732+00000001] [08\/14\/2016 08:42:25.29] [INFO] Command execution finished. Command exited with code: 0\n<\/pre><\/div>\n\n\n
The CustomScript extension takes a script file which can be provided as a file in a Storage blob. Portal offers a convenience where it accepts a file from the local machine. I had provided Simple.ps1 which was in my temp folder. Behind the scenes Portal uploads the file to a blob, generates a shared access signature (SAS) and passes it on to CRP. From the logs above you can see that URI<\/a>.<\/p>\n\n\n\n
This URI is worth understanding. It is a Storage blob SAS with the following attributes for an account in West US (which is the same region where my VM is deployed):<\/p>\n\n\n\n