CODEWITHSUNDEEP
azureterraformterraform-provider-azure
maltman
maltman

Reputation: 454

Terraform Azure Extension Issue

Receiving this error when running Terraform apply on a module that I created to spin up an Azure Windows VM.

Error: Error applying plan:

1 error occurred:
        * module.vm-windows.azurerm_virtual_machine_extension.test: 1 error occurred:
        * azurerm_virtual_machine_extension.test: Code="VMExtensionProvisioningError" Message="VM has reported a failure when processing extension 'hostname'. Error message: \"Finished executing command\"."

Here is my code for VM creation and extension

resource "azurerm_virtual_machine" "vm" {
  count                            = "${length(var.vm_name_suffix)}"
  name                             = "${var.vm_name_prefix}${element(var.vm_name_suffix, count.index)}"
  location                         = "${var.location}"
  resource_group_name              = "${var.rg_name}"
  network_interface_ids            = ["${element(azurerm_network_interface.nic.*.id, count.index)}"]
  vm_size                          = "${var.vm_size}"
  delete_os_disk_on_termination    = "true"
  delete_data_disks_on_termination = "true"
  license_type                     = "Windows_Server"
  zones                            = ["${element(local.azs, count.index)}"] 

  storage_image_reference {
    publisher = "MicrosoftWindowsServer"
    offer     = "WindowsServer"
    sku       = "${var.win_os[var.os_name]}"
    version   = "latest"
  }

  storage_os_disk {
    name              = "${var.vm_name_prefix}${element(var.vm_name_suffix, count.index)}-OSDisk"
    caching           = "ReadWrite"
    create_option     = "FromImage"
    managed_disk_type = "${var.os_disk_type}"
  }

  os_profile {
    computer_name  = "${var.vm_name_prefix}${element(var.vm_name_suffix, count.index)}"
    admin_username = "admin"
    admin_password = "${random_string.adminpassword.result}"
  }

  os_profile_windows_config {
    provision_vm_agent = true
  }
}

resource "azurerm_virtual_machine_extension" "test" {
  name                 = "hostname"
  location             = "${var.location}"
  resource_group_name  = "${var.rg_name}"
  virtual_machine_name = "${azurerm_virtual_machine.vm.name}"
  publisher            = "Microsoft.Compute"
  type                 = "CustomScriptExtension"
  type_handler_version = "1.9"

  settings = <<SETTINGS
    {
        "commandToExecute": "powershell -ExecutionPolicy Unrestricted -File C:\\FOLDER\\WinFirewall.ps1\""
    }
  SETTINGS

  depends_on = ["azurerm_virtual_machine.vm"]
}

It looks like it is trying to run the extension before the machine has been created, which is why I added the depends on. Not sure though as the error doesn't tell me much. Any help would be greatly appreciated.

EDIT: Here are the logs from VM

Command Execution Log

[05/31/2019 20:09:24.31] Executing: C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\enable.cmd 
[05/31/2019 20:09:24.34] Execution Complete.
######
Execution Output:
C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3>if not exist RuntimeSettings\*.settings exit /b -2 
C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3>start cmd /C bin\CustomScriptHandler.exe "enable" 


Execution Error:

######
 Number of Tries:
 1Command C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\enable.cmd of Microsoft.Compute.CustomScriptExtension has exited with Exit code: 0
Plugin (name: Microsoft.Compute.CustomScriptExtension, version: 1.9.3) completed successfully.

Custom Script Handler Log

[2140+00000001] [05/31/2019 19:15:06.60] [INFO] Starting IaaS ScriptHandler Extension v1
[2140+00000001] [05/31/2019 19:15:06.63] [INFO] HandlerEnvironment = Version: 1, HandlerEnvironment: [LogFolder: "C:\WindowsAzure\Logs\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3", ConfigFolder: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\RuntimeSettings", StatusFolder: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\Status", HeartbeatFile: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\Status\HeartBeat.Json"]
[2140+00000001] [05/31/2019 19:15:06.63] [INFO] Installing Handler
[2140+00000001] [05/31/2019 19:15:06.63] [INFO] Handler successfully installed
[2140+00000001] [05/31/2019 19:15:06.64] [INFO] Removing user-level access rules for 2 directories
[2140+00000001] [05/31/2019 19:15:06.64] [INFO] Removing Users access rules from directory 'C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3'
[2140+00000001] [05/31/2019 19:15:06.67] [INFO] Removing Users access rules from directory 'C:\WindowsAzure\Logs\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3'
[2140+00000001] [05/31/2019 19:15:06.69] [INFO] Finished removing user-level access rules
[588+00000001] [05/31/2019 19:15:10.19] [INFO] Starting IaaS ScriptHandler Extension v1
[588+00000001] [05/31/2019 19:15:10.21] [INFO] HandlerEnvironment = Version: 1, HandlerEnvironment: [LogFolder: "C:\WindowsAzure\Logs\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3", ConfigFolder: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\RuntimeSettings", StatusFolder: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\Status", HeartbeatFile: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\Status\HeartBeat.Json"]
[588+00000001] [05/31/2019 19:15:10.21] [INFO] Enabling Handler
[588+00000001] [05/31/2019 19:15:10.22] [INFO] Successfully enabled TLS.
[588+00000001] [05/31/2019 19:15:10.22] [INFO] Handler successfully enabled
[588+00000001] [05/31/2019 19:15:10.24] [INFO] Loading configuration for sequence number 0
[588+00000001] [05/31/2019 19:15:10.27] [INFO] HandlerSettings = ProtectedSettingsCertThumbprint: , ProtectedSettings: {}, PublicSettings: {FileUris: [], CommandToExecute: powershell -ExecutionPolicy Unrestricted -File C:\FOLDER\WinFirewall.ps1"}
[588+00000001] [05/31/2019 19:15:10.27] [INFO] Downloading files specified in configuration...
[588+00000001] [05/31/2019 19:15:10.35] [INFO] No files to download.
[588+00000001] [05/31/2019 19:15:10.36] [INFO] Files downloaded. Asynchronously executing command: 'powershell -ExecutionPolicy Unrestricted -File C:\FOLDER\WinFirewall.ps1"'
[588+00000001] [05/31/2019 19:15:10.38] [INFO] Command execution task started. Awaiting completion...
[588+00000001] [05/31/2019 19:15:13.55] [ERROR] Command execution finished. Command exited with code: -196608
[1944+00000001] [05/31/2019 20:09:24.64] [INFO] Starting IaaS ScriptHandler Extension v1
[1944+00000001] [05/31/2019 20:09:24.65] [INFO] HandlerEnvironment = Version: 1, HandlerEnvironment: [LogFolder: "C:\WindowsAzure\Logs\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3", ConfigFolder: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\RuntimeSettings", StatusFolder: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\Status", HeartbeatFile: "C:\Packages\Plugins\Microsoft.Compute.CustomScriptExtension\1.9.3\Status\HeartBeat.Json"]
[1944+00000001] [05/31/2019 20:09:24.65] [INFO] Enabling Handler
[1944+00000001] [05/31/2019 20:09:24.67] [INFO] Successfully enabled TLS.
[1944+00000001] [05/31/2019 20:09:24.67] [INFO] Handler successfully enabled
[1944+00000001] [05/31/2019 20:09:24.69] [INFO] Loading configuration for sequence number 0
[1944+00000001] [05/31/2019 20:09:24.70] [INFO] HandlerSettings = ProtectedSettingsCertThumbprint: , ProtectedSettings: {}, PublicSettings: {FileUris: [], CommandToExecute: powershell -ExecutionPolicy Unrestricted -File C:\WS\CloudTemplates\Terraform\Azure\Deployments\_Testing\ANSIBLE_TEST\Module\WinFirewall.ps1"}
[1944+00000001] [05/31/2019 20:09:24.70] [WARN] Current sequence number, 0, is not greater than the sequence number of the most recently executed configuration. Exiting...

Upvotes: 1

Views: 1700

Answers (1)

4c74356b41
4c74356b41

Reputation: 72191

why do you think ordering is the problem. when you are using "${azurerm_virtual_machine.vm.name}" you are creating an implicit dependency, so extension runs after the vm is created. also, the error suggests that the extension failed to execute the script (or rather it was executed by returned an error or something like this).

To figure out whats going on - check extension logs on the vm

https://learn.hashicorp.com/terraform/azure/dependencies_az

Upvotes: 1

Related Questions