Ansible WinRM provisioning hangs

373 views

Skip to first unread message

Gavin Williams

unread,

Apr 30, 2019, 4:57:33 AM4/30/19

to Packer

Hey there,

I'm trying to build some Windows Server GCP images using Packer and Ansible.

However whenever I try and build an image, Ansible hangs indefinitely on provisioning via WinRM.

For example:

2019-04-30 08:29:35 - INFO: 2019/04/30 08:29:35 [INFO] (telemetry) Starting provisioner ansible
2019-04-30 08:29:35 - INFO: ==> googlecompute: #< CLIXML
2019-04-30 08:29:35 - INFO:     googlecompute: WinRM connected.
2019-04-30 08:29:35 - INFO: ==> googlecompute: Connected to WinRM!
2019-04-30 08:29:35 - INFO: ==> googlecompute: <Objs Version="1.1.0.1" xmlns="http://schemas.microsoft.com/powershell/2004/04"><Obj S="progress" RefId="0"><TN RefId="0"><T>System.Management.Automation.PSCustomObject</T><T>System.Object</T></TN><MS><I64 N="SourceId">1</I64><PR N="Record"><AV>Preparing modules for first use.</AV><AI>0</AI><Nil /><PI>-1</PI><PC>-1</PC><T>Completed</T><SR>-1</SR><SD> </SD></PR></MS></Obj><Obj S="progress" RefId="1"><TNRef RefId="0" /><MS><I64 N="SourceId">1</I64><PR N="Record"><AV>Preparing modules for first use.</AV><AI>0</AI><Nil /><PI>-1</PI><PC>-1</PC><T>Completed</T><SR>-1</SR><SD> </SD></PR></MS></Obj></Objs>
2019-04-30 08:29:35 - INFO: ==> googlecompute: Provisioning with Ansible...
2019-04-30 08:29:35 - INFO: 2019/04/30 08:29:35 packer: 2019/04/30 08:29:35 SSH proxy: serving on 127.0.0.1:34087
2019-04-30 08:29:35 - INFO: ==> googlecompute: Executing Ansible: ansible-playbook --extra-vars packer_build_name=googlecompute packer_builder_type=googlecompute -o IdentitiesOnly=yes -i /tmp/packer-provisioner-ansible069289340 /infra/ansible/playbooks/scratchpad.yml -e ansible_ssh_private_key_file=/tmp/ansible-key547198033 -vvv --connection packer --extra-vars ansible_shell_type=powershell ansible_shell_executable=None ansible_ssh_executable=ssh skip_make_check=true
2019-04-30 08:29:36 - INFO:     googlecompute: ansible-playbook 2.5.15
2019-04-30 08:29:36 - INFO:     googlecompute:   config file = /infra/ansible/ansible.cfg
2019-04-30 08:29:36 - INFO:     googlecompute:   configured module search path = [u'/infra/ansible/library']
2019-04-30 08:29:36 - INFO:     googlecompute:   ansible python module location = /usr/local/lib/python2.7/site-packages/ansible
2019-04-30 08:29:36 - INFO:     googlecompute:   executable location = /usr/local/bin/ansible-playbook
2019-04-30 08:29:36 - INFO:     googlecompute:   python version = 2.7.15 (default, Feb  6 2019, 12:35:55) [GCC 6.3.0 20170516]
2019-04-30 08:29:36 - INFO:     googlecompute: Using /infra/ansible/ansible.cfg as config file
2019-04-30 08:29:36 - INFO:     googlecompute: Parsed /tmp/packer-provisioner-ansible069289340 inventory source with ini plugin
2019-04-30 08:29:37 - INFO:     googlecompute:
2019-04-30 08:29:37 - INFO:     googlecompute: PLAYBOOK: scratchpad.yml *******************************************************
2019-04-30 08:29:37 - INFO:     googlecompute: 1 plays in /infra/ansible/playbooks/scratchpad.yml
2019-04-30 08:29:37 - INFO:     googlecompute:
2019-04-30 08:29:37 - INFO:     googlecompute: PLAY [scratchpad playbook] *****************************************************
2019-04-30 08:29:37 - INFO:     googlecompute: META: ran handlers
2019-04-30 08:29:37 - INFO:     googlecompute:
2019-04-30 08:29:37 - INFO:     googlecompute: TASK [Create temporary file] ***************************************************
2019-04-30 08:29:37 - INFO:     googlecompute: task path: /infra/ansible/playbooks/scratchpad.yml:10
2019-04-30 08:29:37 - INFO:     googlecompute: Using module file /usr/local/lib/python2.7/site-packages/ansible/modules/windows/win_tempfile.ps1
2019-04-30 08:29:37 - INFO:     googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: packer
2019-04-30 08:29:37 - INFO:     googlecompute: <127.0.0.1> SSH: EXEC ssh -o ControlMaster=auto -o ControlPersist=30m -o ServerAliveInterval=60 -F ssh_config -o StrictHostKeyChecking=no -o Port=34087 -o 'IdentityFile="/tmp/ansible-key547198033"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=packer -o ConnectTimeout=10 -o ControlPath=/root/.ansible/cp/5f571a9699 127.0.0.1 'PowerShell -NoProfile -NonInteractive -ExecutionPolicy Unrestricted -EncodedCommand JgBjAGgAYwBwAC4AYwBvAG0AIAA2ADUAMAAwADEAIAA+ACAAJABuAHUAbABsAAoAJABlAHgAZQBjAF8AdwByAGEAcABwAGUAcgBfAHMAdAByACAAPQAgACQAaQBuAHAAdQB0ACAAfAAgAE8AdQB0AC0AUwB0AHIAaQBuAGcACgAkAHMAcABsAGkAdABfAHAAYQByAHQAcwAgAD0AIAAkAGUAeABlAGMAXwB3AHIAYQBwAHAAZQByAF8AcwB0AHIALgBTAHAAbABpAHQAKABAACgAIgBgADAAYAAwAGAAMABgADAAIgApACwAIAAyACwAIABbAFMAdAByAGkAbgBnAFMAcABsAGkAdABPAHAAdABpAG8AbgBzAF0AOgA6AFIAZQBtAG8AdgBlAEUAbQBwAHQAeQBFAG4AdAByAGkAZQBzACkACgBJAGYAIAAoAC0AbgBvAHQAIAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwAuAEwAZQBuAGcAdABoACAALQBlAHEAIAAyACkAIAB7ACAAdABoAHIAbwB3ACAAIgBpAG4AdgBhAGwAaQBkACAAcABhAHkAbABvAGEAZAAiACAAfQAKAFMAZQB0AC0AVgBhAHIAaQBhAGIAbABlACAALQBOAGEAbQBlACAAagBzAG8AbgBfAHIAYQB3ACAALQBWAGEAbAB1AGUAIAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwBbADEAXQAKACQAZQB4AGUAYwBfAHcAcgBhAHAAcABlAHIAIAA9ACAAWwBTAGMAcgBpAHAAdABCAGwAbwBjAGsAXQA6ADoAQwByAGUAYQB0AGUAKAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwBbADAAXQApAAoAJgAkAGUAeABlAGMAXwB3AHIAYQBwAHAAZQByAA=='
2019-04-30 08:29:37 - INFO: 2019/04/30 08:29:37 packer: 2019/04/30 08:29:37 SSH proxy: accepted connection
2019-04-30 08:29:37 - INFO: 2019/04/30 08:29:37 packer: 2019/04/30 08:29:37 authentication attempt from 127.0.0.1:44234 to 127.0.0.1:34087 as packer using none
2019-04-30 08:29:37 - INFO: 2019/04/30 08:29:37 packer: 2019/04/30 08:29:37 authentication attempt from 127.0.0.1:44234 to 127.0.0.1:34087 as packer using publickey
2019-04-30 08:29:37 - INFO: 2019/04/30 08:29:37 packer: 2019/04/30 08:29:37 new exec request: PowerShell -NoProfile -NonInteractive -ExecutionPolicy Unrestricted -EncodedCommand JgBjAGgAYwBwAC4AYwBvAG0AIAA2ADUAMAAwADEAIAA+ACAAJABuAHUAbABsAAoAJABlAHgAZQBjAF8AdwByAGEAcABwAGUAcgBfAHMAdAByACAAPQAgACQAaQBuAHAAdQB0ACAAfAAgAE8AdQB0AC0AUwB0AHIAaQBuAGcACgAkAHMAcABsAGkAdABfAHAAYQByAHQAcwAgAD0AIAAkAGUAeABlAGMAXwB3AHIAYQBwAHAAZQByAF8AcwB0AHIALgBTAHAAbABpAHQAKABAACgAIgBgADAAYAAwAGAAMABgADAAIgApACwAIAAyACwAIABbAFMAdAByAGkAbgBnAFMAcABsAGkAdABPAHAAdABpAG8AbgBzAF0AOgA6AFIAZQBtAG8AdgBlAEUAbQBwAHQAeQBFAG4AdAByAGkAZQBzACkACgBJAGYAIAAoAC0AbgBvAHQAIAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwAuAEwAZQBuAGcAdABoACAALQBlAHEAIAAyACkAIAB7ACAAdABoAHIAbwB3ACAAIgBpAG4AdgBhAGwAaQBkACAAcABhAHkAbABvAGEAZAAiACAAfQAKAFMAZQB0AC0AVgBhAHIAaQBhAGIAbABlACAALQBOAGEAbQBlACAAagBzAG8AbgBfAHIAYQB3ACAALQBWAGEAbAB1AGUAIAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwBbADEAXQAKACQAZQB4AGUAYwBfAHcAcgBhAHAAcABlAHIAIAA9ACAAWwBTAGMAcgBpAHAAdABCAGwAbwBjAGsAXQA6ADoAQwByAGUAYQB0AGUAKAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwBbADAAXQApAAoAJgAkAGUAeABlAGMAXwB3AHIAYQBwAHAAZQByAA==
2019-04-30 08:29:37 - INFO: 2019/04/30 08:29:37 packer: 2019/04/30 08:29:37 [INFO] 26711 bytes written for 'stdin'
2019-04-30 08:29:37 - INFO: 2019/04/30 08:29:37 [INFO] 26711 bytes written for 'stdin'
2019-04-30 08:29:38 - INFO: 2019/04/30 08:29:38 packer: 2019/04/30 08:29:38 [INFO] starting remote command: PowerShell -NoProfile -NonInteractive -ExecutionPolicy Unrestricted -EncodedCommand JgBjAGgAYwBwAC4AYwBvAG0AIAA2ADUAMAAwADEAIAA+ACAAJABuAHUAbABsAAoAJABlAHgAZQBjAF8AdwByAGEAcABwAGUAcgBfAHMAdAByACAAPQAgACQAaQBuAHAAdQB0ACAAfAAgAE8AdQB0AC0AUwB0AHIAaQBuAGcACgAkAHMAcABsAGkAdABfAHAAYQByAHQAcwAgAD0AIAAkAGUAeABlAGMAXwB3AHIAYQBwAHAAZQByAF8AcwB0AHIALgBTAHAAbABpAHQAKABAACgAIgBgADAAYAAwAGAAMABgADAAIgApACwAIAAyACwAIABbAFMAdAByAGkAbgBnAFMAcABsAGkAdABPAHAAdABpAG8AbgBzAF0AOgA6AFIAZQBtAG8AdgBlAEUAbQBwAHQAeQBFAG4AdAByAGkAZQBzACkACgBJAGYAIAAoAC0AbgBvAHQAIAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwAuAEwAZQBuAGcAdABoACAALQBlAHEAIAAyACkAIAB7ACAAdABoAHIAbwB3ACAAIgBpAG4AdgBhAGwAaQBkACAAcABhAHkAbABvAGEAZAAiACAAfQAKAFMAZQB0AC0AVgBhAHIAaQBhAGIAbABlACAALQBOAGEAbQBlACAAagBzAG8AbgBfAHIAYQB3ACAALQBWAGEAbAB1AGUAIAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwBbADEAXQAKACQAZQB4AGUAYwBfAHcAcgBhAHAAcABlAHIAIAA9ACAAWwBTAGMAcgBpAHAAdABCAGwAbwBjAGsAXQA6ADoAQwByAGUAYQB0AGUAKAAkAHMAcABsAGkAdABfAHAAYQByAHQAcwBbADAAXQApAAoAJgAkAGUAeABlAGMAXwB3AHIAYQBwAHAAZQByAA==

Versions:

* Packer: Tested 1.3.5 and 1.4.0

* Ansible: 2.5.15

* Windows OS: 2016 or 2019

I'm using the Packer Ansible connection plugin as defined here: https://github.com/hashicorp/packer/blob/master/examples/ansible/connection-plugin/2.5.x/packer.py

And my `packer-build.json` file looks like:

{
  "builders": [
    {
      "communicator": "winrm",
      "disk_size": 50,
      "image_family": "foundation-windows-2019",
      "image_labels": {
        "built_by": "packer_builder"
      },
      "image_name": "debug-foundation-windows-2019-{{isotime \"20060102150405\"}}",
      "machine_type": "n1-highcpu-4",
      "metadata": {
        "windows-startup-script-cmd": "winrm quickconfig -quiet & net user /add packer & net localgroup administrators packer /add & winrm set winrm/config/service/auth @{Basic=\"true\"}"
      },
      "preemptible": "false",
      "project_id": "{{user `target_project`}}",
      "source_image_family": "windows-2019-core",
      "source_image_project_id": "windows-cloud",
      "state_timeout": "10m",
      "tags": [
        "packer"
      ],
      "type": "googlecompute",
      "winrm_insecure": "true",
      "winrm_use_ssl": "true",
      "winrm_username": "packer",
      "zone": "us-central1-a"
    }
  ],
  "provisioners": [
    {
      "extra_arguments": [
        "-vvv",
        "--connection",
        "packer",
        "--extra-vars",
        "ansible_shell_type=powershell ansible_shell_executable=None ansible_ssh_executable=ssh skip_make_check=true"
      ],
      "groups": [
        "gce",
        "windows",
        "packer"
      ],
      "playbook_file": "./playbooks/scratchpad.yml",
      "type": "ansible",
      "user": "packer"
    }
  ],
  "variables": {
    "target_project": "images-qa"
  }
}

Any suggestions on what could be going wrong, or how I can debug further?

Thanks in advance for taking the time to respond.

Regards

Gavin

Reply all

Reply to author

Forward

0 new messages