github-hashicorp-packer-6379.log

2018/06/13 10:10:05 [INFO] Packer version: 1.2.4
2018/06/13 10:10:05 Packer Target OS/Arch: darwin amd64
2018/06/13 10:10:05 Built with Go Version: go1.10.1
2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 Using internal plugin for parallels-iso
2018/06/13 10:10:05 Using internal plugin for amazon-chroot
2018/06/13 10:10:05 Using internal plugin for amazon-instance
2018/06/13 10:10:05 Using internal plugin for lxd
2018/06/13 10:10:05 Using internal plugin for null
2018/06/13 10:10:05 Using internal plugin for virtualbox-ovf
2018/06/13 10:10:05 Using internal plugin for amazon-ebsvolume
2018/06/13 10:10:05 Using internal plugin for cloudstack
2018/06/13 10:10:05 Using internal plugin for docker
2018/06/13 10:10:05 Using internal plugin for oneandone
2018/06/13 10:10:05 Using internal plugin for vmware-vmx
2018/06/13 10:10:05 Using internal plugin for amazon-ebssurrogate
2018/06/13 10:10:05 Using internal plugin for azure-arm
2018/06/13 10:10:05 Using internal plugin for parallels-pvm
2018/06/13 10:10:05 Using internal plugin for virtualbox-iso
2018/06/13 10:10:05 Using internal plugin for digitalocean
2018/06/13 10:10:05 Using internal plugin for googlecompute
2018/06/13 10:10:05 Using internal plugin for oracle-oci
2018/06/13 10:10:05 Using internal plugin for vmware-iso
2018/06/13 10:10:05 Using internal plugin for alicloud-ecs
2018/06/13 10:10:05 Using internal plugin for file
2018/06/13 10:10:05 Using internal plugin for hyperv-iso
2018/06/13 10:10:05 Using internal plugin for lxc
2018/06/13 10:10:05 Using internal plugin for profitbricks
2018/06/13 10:10:05 Using internal plugin for amazon-ebs
2018/06/13 10:10:05 Using internal plugin for ncloud
2018/06/13 10:10:05 Using internal plugin for oracle-classic
2018/06/13 10:10:05 Using internal plugin for hyperv-vmcx
2018/06/13 10:10:05 Using internal plugin for openstack
2018/06/13 10:10:05 Using internal plugin for qemu
2018/06/13 10:10:05 Using internal plugin for scaleway
2018/06/13 10:10:05 Using internal plugin for triton
2018/06/13 10:10:05 Using internal plugin for chef-solo
2018/06/13 10:10:05 Using internal plugin for converge
2018/06/13 10:10:05 Using internal plugin for puppet-server
2018/06/13 10:10:05 Using internal plugin for salt-masterless
2018/06/13 10:10:05 Using internal plugin for chef-client
2018/06/13 10:10:05 Using internal plugin for file
2018/06/13 10:10:05 Using internal plugin for ansible
2018/06/13 10:10:05 Using internal plugin for powershell
2018/06/13 10:10:05 Using internal plugin for puppet-masterless
2018/06/13 10:10:05 Using internal plugin for shell-local
2018/06/13 10:10:05 Using internal plugin for ansible-local
2018/06/13 10:10:05 Using internal plugin for windows-restart
2018/06/13 10:10:05 Using internal plugin for windows-shell
2018/06/13 10:10:05 Using internal plugin for shell
2018/06/13 10:10:05 Using internal plugin for shell-local
2018/06/13 10:10:05 Using internal plugin for vagrant
2018/06/13 10:10:05 Using internal plugin for vsphere
2018/06/13 10:10:05 Using internal plugin for artifice
2018/06/13 10:10:05 Using internal plugin for checksum
2018/06/13 10:10:05 Using internal plugin for docker-save
2018/06/13 10:10:05 Using internal plugin for docker-tag
2018/06/13 10:10:05 Using internal plugin for amazon-import
2018/06/13 10:10:05 Using internal plugin for compress
2018/06/13 10:10:05 Using internal plugin for atlas
2018/06/13 10:10:05 Using internal plugin for manifest
2018/06/13 10:10:05 Using internal plugin for vagrant-cloud
2018/06/13 10:10:05 Using internal plugin for vsphere-template
2018/06/13 10:10:05 Using internal plugin for alicloud-import
2018/06/13 10:10:05 Using internal plugin for docker-import
2018/06/13 10:10:05 Using internal plugin for docker-push
2018/06/13 10:10:05 Using internal plugin for googlecompute-export
2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 Attempting to open config file: /Users/matt/.packerconfig
2018/06/13 10:10:05 [WARN] Config file doesn't exist: /Users/matt/.packerconfig
2018/06/13 10:10:05 Packer config: &{DisableCheckpoint:false DisableCheckpointSignature:false PluginMinPort:10000 PluginMaxPort:25000 Builders:map[amazon-instance:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-amazon-instance amazon-ebsvolume:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-amazon-ebsvolume googlecompute:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-googlecompute amazon-chroot:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-amazon-chroot parallels-pvm:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-parallels-pvm alicloud-ecs:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-alicloud-ecs hyperv-iso:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-hyperv-iso oracle-classic:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-oracle-classic lxd:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-lxd docker:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-docker oneandone:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-oneandone amazon-ebssurrogate:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-amazon-ebssurrogate digitalocean:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-digitalocean vmware-iso:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-vmware-iso file:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-file lxc:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-lxc null:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-null virtualbox-ovf:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-virtualbox-ovf virtualbox-iso:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-virtualbox-iso oracle-oci:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-oracle-oci profitbricks:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-profitbricks parallels-iso:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-parallels-iso azure-arm:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-azure-arm amazon-ebs:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-amazon-ebs ncloud:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-ncloud openstack:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-openstack qemu:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-qemu vmware-vmx:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-vmware-vmx cloudstack:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-cloudstack scaleway:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-scaleway triton:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-triton hyperv-vmcx:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-builder-hyperv-vmcx] PostProcessors:map[vagrant-cloud:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-vagrant-cloud vsphere-template:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-vsphere-template docker-push:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-docker-push shell-local:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-shell-local vsphere:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-vsphere docker-save:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-docker-save amazon-import:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-amazon-import manifest:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-manifest artifice:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-artifice checksum:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-checksum atlas:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-atlas googlecompute-export:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-googlecompute-export compress:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-compress alicloud-import:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-alicloud-import vagrant:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-vagrant docker-tag:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-docker-tag docker-import:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-post-processor-docker-import] Provisioners:map[salt-masterless:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-salt-masterless chef-client:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-chef-client ansible:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-ansible shell-local:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-shell-local windows-shell:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-windows-shell shell:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-shell chef-solo:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-chef-solo puppet-masterless:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-puppet-masterless windows-restart:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-windows-restart powershell:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-powershell ansible-local:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-ansible-local converge:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-converge puppet-server:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-puppet-server file:/Users/matt/bin/packer-PACKERSPACE-plugin-PACKERSPACE-packer-provisioner-file]}
2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 Setting cache directory: /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/packer_cache
2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 Loading builder: googlecompute
2018/06/13 10:10:05 Plugin could not be found. Checking same directory as executable.
2018/06/13 10:10:05 Current exe path: /Users/matt/bin/packer
2018/06/13 10:10:05 Creating plugin client for path: /Users/matt/bin/packer
2018/06/13 10:10:05 Starting plugin: /Users/matt/bin/packer []string{"/Users/matt/bin/packer", "plugin", "packer-builder-googlecompute"}
2018/06/13 10:10:05 Waiting for RPC address for: /Users/matt/bin/packer
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 [INFO] Packer version: 1.2.4
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Packer Target OS/Arch: darwin amd64
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Built with Go Version: go1.10.1
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Attempting to open config file: /Users/matt/.packerconfig
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 [WARN] Config file doesn't exist: /Users/matt/.packerconfig
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Packer config: &{DisableCheckpoint:false DisableCheckpointSignature:false PluginMinPort:10000 PluginMaxPort:25000 Builders:map[] PostProcessors:map[] Provisioners:map[]}
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Setting cache directory: /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/packer_cache
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 args: []string{"packer-builder-googlecompute"}
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Plugin minimum port: 10000
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Plugin maximum port: 25000
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Plugin address: unix /tmp/packer-plugin341322442
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Waiting for connection...
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Serving a plugin connection...
2018/06/13 10:10:05 Loading provisioner: ansible
2018/06/13 10:10:05 Plugin could not be found. Checking same directory as executable.
2018/06/13 10:10:05 Current exe path: /Users/matt/bin/packer
2018/06/13 10:10:05 Creating plugin client for path: /Users/matt/bin/packer
2018/06/13 10:10:05 Starting plugin: /Users/matt/bin/packer []string{"/Users/matt/bin/packer", "plugin", "packer-provisioner-ansible"}
2018/06/13 10:10:05 Waiting for RPC address for: /Users/matt/bin/packer
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 [INFO] Packer version: 1.2.4
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Packer Target OS/Arch: darwin amd64
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Built with Go Version: go1.10.1
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Attempting to open config file: /Users/matt/.packerconfig
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 [WARN] Config file doesn't exist: /Users/matt/.packerconfig
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Packer config: &{DisableCheckpoint:false DisableCheckpointSignature:false PluginMinPort:10000 PluginMaxPort:25000 Builders:map[] PostProcessors:map[] Provisioners:map[]}
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Setting cache directory: /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/packer_cache
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Detected home directory from env var: /Users/matt
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 args: []string{"packer-provisioner-ansible"}
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Plugin minimum port: 10000
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Plugin maximum port: 25000
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Plugin address: unix /tmp/packer-plugin703994051
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Waiting for connection...
2018/06/13 10:10:05 packer: 2018/06/13 10:10:05 Serving a plugin connection...
2018/06/13 10:10:05 ui: googlecompute output will be in this color.
2018/06/13 10:10:05 ui:
googlecompute output will be in this color.

2018/06/13 10:10:05 Build debug mode: false
2018/06/13 10:10:05 Force build: false
2018/06/13 10:10:05 On error:
2018/06/13 10:10:05 Preparing build: googlecompute
2018/06/13 10:10:07 packer: 2018/06/13 10:10:07 ansible-playbook version: 2.7.0.
2018/06/13 10:10:07 Waiting on builds to complete...
2018/06/13 10:10:07 Starting build run: googlecompute
2018/06/13 10:10:07 Running builder: googlecompute
2018/06/13 10:10:07 [INFO] (telemetry) Starting builder googlecompute
2018/06/13 10:10:07 packer: 2018/06/13 10:10:07 [INFO] Requesting Google token via AccountFile...
2018/06/13 10:10:07 packer: 2018/06/13 10:10:07 [INFO]   -- Email: *****
2018/06/13 10:10:07 packer: 2018/06/13 10:10:07 [INFO]   -- Scopes: [https://www.googleapis.com/auth/compute https://www.googleapis.com/auth/devstorage.full_control]
2018/06/13 10:10:07 packer: 2018/06/13 10:10:07 [INFO]   -- Private Key Length: 1704
2018/06/13 10:10:07 packer: 2018/06/13 10:10:07 [INFO] Instantiating GCE client...
2018/06/13 10:10:07 ui: ==> googlecompute: Checking image does not exist...
==> googlecompute: Checking image does not exist...
==> googlecompute: Creating temporary SSH key for instance...
2018/06/13 10:10:07 ui: ==> googlecompute: Creating temporary SSH key for instance...
2018/06/13 10:10:09 ui: ==> googlecompute: Using image: ubuntu-1604-xenial-v20180522
==> googlecompute: Using image: ubuntu-1604-xenial-v20180522
2018/06/13 10:10:09 ui: ==> googlecompute: Creating instance...
==> googlecompute: Creating instance...
2018/06/13 10:10:09 ui:     googlecompute: Loading zone: us-central1-f
    googlecompute: Loading zone: us-central1-f
2018/06/13 10:10:09 ui:     googlecompute: Loading machine type: n1-standard-1
    googlecompute: Loading machine type: n1-standard-1
2018/06/13 10:10:09 ui:     googlecompute: Requesting instance creation...
    googlecompute: Requesting instance creation...
2018/06/13 10:10:11 ui:     googlecompute: Waiting for creation operation to complete...
    googlecompute: Waiting for creation operation to complete...
2018/06/13 10:10:15 ui:     googlecompute: Instance has been created!
    googlecompute: Instance has been created!
2018/06/13 10:10:15 ui: ==> googlecompute: Waiting for the instance to become running...
==> googlecompute: Waiting for the instance to become running...
2018/06/13 10:10:16 ui:     googlecompute: IP: 35.225.122.192
    googlecompute: IP: 35.225.122.192
2018/06/13 10:10:16 packer: 2018/06/13 10:10:16 [INFO] Waiting for SSH, up to timeout: 5m0s
2018/06/13 10:10:16 ui: ==> googlecompute: Waiting for SSH to become available...
==> googlecompute: Waiting for SSH to become available...
2018/06/13 10:10:31 packer: 2018/06/13 10:10:31 [DEBUG] TCP connection to SSH ip/port failed: dial tcp 35.225.122.192:22: i/o timeout
2018/06/13 10:10:51 packer: 2018/06/13 10:10:51 [DEBUG] TCP connection to SSH ip/port failed: dial tcp 35.225.122.192:22: i/o timeout
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 [INFO] Attempting SSH connection...
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 [DEBUG] reconnecting to TCP connection for SSH
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 [DEBUG] handshaking with SSH
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 [DEBUG] handshake complete!
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 [DEBUG] Opening new ssh session
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 [INFO] agent forwarding enabled
2018/06/13 10:10:56 ui: ==> googlecompute: Connected to SSH!
==> googlecompute: Connected to SSH!
2018/06/13 10:10:56 packer: 2018/06/13 10:10:56 Running the provision hook
2018/06/13 10:10:56 [INFO] (telemetry) Starting provisioner ansible
2018/06/13 10:10:56 ui: ==> googlecompute: Provisioning with Ansible...
==> googlecompute: Provisioning with Ansible...
2018/06/13 10:10:57 packer: 2018/06/13 10:10:57 SSH proxy: serving on 127.0.0.1:52587
2018/06/13 10:10:57 ui: ==> googlecompute: Executing Ansible: ansible-playbook --extra-vars packer_build_name=googlecompute packer_builder_type=googlecompute -i /tmp/packer-provisioner-ansible934131181 /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/repro-image-playbook.yml -e ansible_ssh_private_key_file=/tmp/ansible-key978442054 --ssh-extra-args -o IdentitiesOnly=yes -vvvv
==> googlecompute: Executing Ansible: ansible-playbook --extra-vars packer_build_name=googlecompute packer_builder_type=googlecompute -i /tmp/packer-provisioner-ansible934131181 /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/repro-image-playbook.yml -e ansible_ssh_private_key_file=/tmp/ansible-key978442054 --ssh-extra-args -o IdentitiesOnly=yes -vvvv
    googlecompute: ansible-playbook 2.7.0.dev0 (devel 5bdd91d75f) last updated 2018/06/12 09:50:36 (GMT -500)
2018/06/13 10:10:58 ui:     googlecompute: ansible-playbook 2.7.0.dev0 (devel 5bdd91d75f) last updated 2018/06/12 09:50:36 (GMT -500)
2018/06/13 10:10:58 ui:     googlecompute:   config file = None
    googlecompute:   config file = None
2018/06/13 10:10:58 ui:     googlecompute:   configured module search path = ['/Users/matt/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
    googlecompute:   configured module search path = ['/Users/matt/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
    googlecompute:   ansible python module location = /Users/matt/projects/ansibledev/ansible/lib/ansible
2018/06/13 10:10:58 ui:     googlecompute:   ansible python module location = /Users/matt/projects/ansibledev/ansible/lib/ansible
2018/06/13 10:10:58 ui:     googlecompute:   executable location = /Users/matt/projects/ansibledev/ansible/bin/ansible-playbook
    googlecompute:   executable location = /Users/matt/projects/ansibledev/ansible/bin/ansible-playbook
2018/06/13 10:10:58 ui:     googlecompute:   python version = 3.6.5 (default, Apr  6 2018, 10:24:13) [GCC 4.2.1 Compatible Apple LLVM 9.1.0 (clang-902.0.39.1)]
    googlecompute:   python version = 3.6.5 (default, Apr  6 2018, 10:24:13) [GCC 4.2.1 Compatible Apple LLVM 9.1.0 (clang-902.0.39.1)]
2018/06/13 10:10:58 ui:     googlecompute: No config file found; using defaults
    googlecompute: No config file found; using defaults
2018/06/13 10:10:58 ui:     googlecompute: setting up inventory plugins
    googlecompute: setting up inventory plugins
2018/06/13 10:10:58 ui:     googlecompute: Parsed /tmp/packer-provisioner-ansible934131181 inventory source with ini plugin
    googlecompute: Parsed /tmp/packer-provisioner-ansible934131181 inventory source with ini plugin
2018/06/13 10:10:58 ui:     googlecompute: Loading callback plugin default of type stdout, v2.0 from /Users/matt/projects/ansibledev/ansible/lib/ansible/plugins/callback/default.py
    googlecompute: Loading callback plugin default of type stdout, v2.0 from /Users/matt/projects/ansibledev/ansible/lib/ansible/plugins/callback/default.py
2018/06/13 10:10:58 ui:     googlecompute:
    googlecompute:
2018/06/13 10:10:58 ui:     googlecompute: PLAYBOOK: repro-image-playbook.yml *********************************************
    googlecompute: PLAYBOOK: repro-image-playbook.yml *********************************************
2018/06/13 10:10:58 ui:     googlecompute: 1 plays in /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/repro-image-playbook.yml
    googlecompute: 1 plays in /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/repro-image-playbook.yml
2018/06/13 10:10:58 ui:     googlecompute:
    googlecompute:
2018/06/13 10:10:58 ui:     googlecompute: PLAY [all] *********************************************************************
    googlecompute: PLAY [all] *********************************************************************
    googlecompute:
2018/06/13 10:10:59 ui:     googlecompute:
2018/06/13 10:10:59 ui:     googlecompute: TASK [Gathering Facts] *********************************************************
    googlecompute: TASK [Gathering Facts] *********************************************************
2018/06/13 10:10:59 ui:     googlecompute: task path: /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/repro-image-playbook.yml:2
    googlecompute: task path: /Users/matt/projects/ansibledev/playbooks/41377/ansible-template-validate-repro/repro-image-playbook.yml:2
2018/06/13 10:10:59 ui:     googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
    googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:10:59 ui:     googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'echo ~matt && sleep 0'"'"''
    googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'echo ~matt && sleep 0'"'"''
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 SSH proxy: accepted connection
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 authentication attempt from 127.0.0.1:52589 to 127.0.0.1:52587 as matt using none
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 authentication attempt from 127.0.0.1:52589 to 127.0.0.1:52587 as matt using publickey
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 rejecting auth-agent-req@openssh.com request
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 new env request: LC_ALL=en_US.UTF-8
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 new env request: LANG=en_US.UTF-8
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 new exec request: /bin/sh -c 'echo ~matt && sleep 0'
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [DEBUG] Opening new ssh session
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [DEBUG] starting remote command: /bin/sh -c 'echo ~matt && sleep 0'
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:10:59 [INFO] 6 bytes written for 'stdout'
2018/06/13 10:10:59 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:10:59 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:10:59 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:10:59 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [INFO] 6 bytes written for 'stdout'
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:10:59 packer: 2018/06/13 10:10:59 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:00 ui:     googlecompute: <127.0.0.1> (0, b'~matt\n', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug1: Control socket "/Users/matt/.ansible/cp/10aa3a24eb" does not exist\r\ndebug2: resolving "127.0.0.1" port 52587\r\ndebug2: ssh_connect_direct: needpriv 0\r\ndebug1: Connecting to 127.0.0.1 [127.0.0.1] port 52587.\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug1: fd 3 clearing O_NONBLOCK\r\ndebug1: Connection established.\r\ndebug3: timeout: 10000 ms remain after connect\r\ndebug1: key_load_public: No such file or directory\r\ndebug1: identity file /tmp/ansible-key978442054 type -1\r\ndebug1: key_load_public: No such file or directory\r\ndebug1: identity file /tmp/ansible-key978442054-cert type -1\r\ndebug1: Local version string SSH-2.0-OpenSSH_7.6\r\ndebug1: Remote protocol version 2.0, remote software version Go\r\ndebug1: no match: Go\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug1: Authenticating to 127.0.0.1:52587 as \'matt\'\r\ndebug3: put_host_port: [127.0.0.1]:52587\r\ndebug3: hostkeys_foreach: reading file "/Users/matt/.ssh/known_hosts"\r\ndebug3: send packet: type 20\r\ndebug1: SSH2_MSG_KEXINIT sent\r\ndebug3: receive packet: type 20\r\ndebug1: SSH2_MSG_KEXINIT received\r\ndebug2: local client KEXINIT proposal\r\ndebug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,ext-info-c\r\ndebug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa\r\ndebug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com\r\ndebug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com\r\ndebug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: compression ctos: zlib@openssh.com,zlib,none\r\ndebug2: compression stoc: zlib@openssh.com,zlib,none\r\ndebug2: languages ctos: \r\ndebug2: languages stoc: \r\ndebug2: first_kex_follows 0 \r\ndebug2: reserved 0 \r\ndebug2: peer server KEXINIT proposal\r\ndebug2: KEX algorithms: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\r\ndebug2: host key algorithms: ssh-rsa\r\ndebug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,arcfour256,arcfour128\r\ndebug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,arcfour256,arcfour128\r\ndebug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha1-96\r\ndebug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha1-96\r\ndebug2: compression ctos: none\r\ndebug2: compression stoc: none\r\ndebug2: languages ctos: \r\ndebug2: languages stoc: \r\ndebug2: first_kex_follows 0 \r\ndebug2: reserved 0 \r\ndebug1: kex: algorithm: curve25519-sha256@libssh.org\r\ndebug1: kex: host key algorithm: ssh-rsa\r\ndebug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none\r\ndebug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none\r\ndebug3: send packet: type 30\r\ndebug1: expecting SSH2_MSG_KEX_ECDH_REPLY\r\ndebug3: receive packet: type 31\r\ndebug1: Server host key: ssh-rsa SHA256:bnSPJlEjQ/9hOlGbqhft58MeIX0kqN9Y46e6LBppMzM\r\ndebug3: put_host_port: [127.0.0.1]:52587\r\ndebug3: put_host_port: [127.0.0.1]:52587\r\ndebug3: hostkeys_foreach: reading file "/Users/matt/.ssh/known_hosts"\r\ndebug1: checking without port identifier\r\ndebug3: hostkeys_foreach: reading file "/Users/matt/.ssh/known_hosts"\r\ndebug3: record_hostkey: found key type ECDSA in file /Users/matt/.ssh/known_hosts:16\r\ndebug3: load_hostkeys: loaded 1 keys from 127.0.0.1\r\nWarning: Permanently added \'[127.0.0.1]:52587\' (RSA) to the list of known hosts.\r\ndebug3: send packet: type 21\r\ndebug2: set_newkeys: mode 1\r\ndebug1: rekey after 4294967296 blocks\r\ndebug1: SSH2_MSG_NEWKEYS sent\r\ndebug1: expecting SSH2_MSG_NEWKEYS\r\ndebug3: receive packet: type 21\r\ndebug1: SSH2_MSG_NEWKEYS received\r\ndebug2: set_newkeys: mode 0\r\ndebug1: rekey after 4294967296 blocks\r\ndebug2: key: /tmp/ansible-key978442054 (0x0), explicit\r\ndebug3: send packet: type 5\r\ndebug3: receive packet: type 6\r\ndebug2: service_accept: ssh-userauth\r\ndebug1: SSH2_MSG_SERVICE_ACCEPT received\r\ndebug3: send packet: type 50\r\ndebug3: receive packet: type 51\r\ndebug1: Authentications that can continue: publickey\r\ndebug3: start over, passed a different list publickey\r\ndebug3: preferred gssapi-with-mic,gssapi-keyex,hostbased,publickey\r\ndebug3: authmethod_lookup publickey\r\ndebug3: remaining preferred: ,gssapi-keyex,hostbased,publickey\r\ndebug3: authmethod_is_enabled publickey\r\ndebug1: Next authentication method: publickey\r\ndebug1: Trying private key: /tmp/ansible-key978442054\r\ndebug3: sign_and_send_pubkey: RSA SHA256:ZsE8mR0gBcAZsZ0tRsvsKaonfUIDqtXxQsT9YG+s4aY\r\ndebug3: send packet: type 50\r\ndebug2: we sent a publickey packet, wait for reply\r\ndebug3: receive packet: type 52\r\ndebug1: Authentication succeeded (publickey).\r\nAuthenticated to 127.0.0.1 ([127.0.0.1]:52587).\r\ndebug1: setting up multiplex master socket\r\ndebug3: muxserver_listen: temporary control path /Users/matt/.ansible/cp/10aa3a24eb.KN099lGCjyYYGtli\r\ndebug2: fd 5 setting O_NONBLOCK\r\ndebug3: fd 5 is O_NONBLOCK\r\ndebug3: fd 5 is O_NONBLOCK\r\ndebug1: channel 0: new [/Users/matt/.ansible/cp/10aa3a24eb]\r\ndebug3: muxserver_listen: mux listener channel 0 fd 5\r\ndebug2: fd 3 setting TCP_NODELAY\r\ndebug3: ssh_packet_set_tos: set IP_TOS 0x08\r\ndebug1: control_persist_detach: backgrounding master process\r\ndebug2: control_persist_detach: background process is 13626\r\ndebug2: fd 5 setting O_NONBLOCK\r\ndebug1: forking to background\r\ndebug1: Entering interactive session.\r\ndebug1: pledge: id\r\ndebug2: set_control_persist_exit_time: schedule exit in 60 seconds\r\ndebug1: multiplexing control connection\r\ndebug3: fd 6 is O_NONBLOCK\r\ndebug3: fd 6 is O_NONBLOCK\r\ndebug1: channel 1: new [mux-control]\r\ndebug3: channel_post_mux_listener: new mux channel 1 fd 6\r\ndebug3: mux_master_read_cb: channel 1: hello sent\r\ndebug2: set_control_persist_exit_time: cancel scheduled exit\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x00000001 len 4\r\ndebug2: process_mux_master_hello: channel 1 slave version 4\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x10000004 len 4\r\ndebug2: process_mux_alive_check: channel 1: alive check\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x10000002 len 126\r\ndebug3: mux_client_request_session: session request sent\r\ndebug2: process_mux_new_session: channel 1: request tty 0, X 1, agent 1, subsys 0, term "xterm-256color", cmd "/bin/sh -c \'echo ~matt && sleep 0\'", env 2\r\ndebug3: process_mux_new_session: got fds stdin 7, stdout 8, stderr 9\r\ndebug2: fd 8 setting O_NONBLOCK\r\ndebug2: fd 9 setting O_NONBLOCK\r\ndebug1: channel 2: new [client-session]\r\ndebug2: process_mux_new_session: channel_new: 2 linked to control channel 1\r\ndebug2: channel 2: send open\r\ndebug3: send packet: type 90\r\ndebug3: receive packet: type 91\r\ndebug2: channel_input_open_confirmation: channel 2: callback start\r\ndebug1: Requesting authentication agent forwarding.\r\ndebug2: channel 2: request auth-agent-req@openssh.com confirm 0\r\ndebug3: send packet: type 98\r\ndebug2: client_session2_setup: id 2\r\ndebug1: Sending environment.\r\ndebug1: Sending env LC_ALL = en_US.UTF-8\r\ndebug2: channel 2: request env confirm 0\r\ndebug3: send packet: type 98\r\ndebug1: Sending env LANG = en_US.UTF-8\r\ndebug2: channel 2: request env confirm 0\r\ndebug3: send packet: type 98\r\ndebug1: Sending command: /bin/sh -c \'echo ~matt && sleep 0\'\r\ndebug2: channel 2: request exec confirm 1\r\ndebug3: send packet: type 98\r\ndebug3: mux_session_confirm: sending success reply\r\ndebug2: channel_input_open_confirmation: channel 2: callback done\r\ndebug2: channel 2: open confirm rwindow 2097152 rmax 32768\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: receive packet: type 99\r\ndebug2: channel_input_status_confirm: type 99 id 2\r\ndebug2: exec request accepted on channel 2\r\ndebug3: receive packet: type 98\r\ndebug1: client_input_channel_req: channel 2 rtype exit-status reply 0\r\ndebug3: mux_exit_message: channel 2: exit message, exitval 0\r\ndebug3: receive packet: type 97\r\ndebug2: channel 2: rcvd close\r\ndebug2: channel 2: output open -> drain\r\ndebug2: channel 2: close_read\r\ndebug2: channel 2: input open -> closed\r\ndebug3: channel 2: will not send data after close\r\ndebug2: channel 2: obuf empty\r\ndebug2: channel 2: close_write\r\ndebug2: channel 2: output drain -> closed\r\ndebug2: channel 2: send close\r\ndebug3: send packet: type 97\r\ndebug2: channel 2: is dead\r\ndebug2: channel 2: gc: notify user\r\ndebug3: mux_master_session_cleanup_cb: entering for channel 2\r\ndebug2: channel 1: rcvd close\r\ndebug2: channel 1: output open -> drain\r\ndebug2: channel 1: close_read\r\ndebug2: channel 1: input open -> closed\r\ndebug2: channel 2: gc: user detached\r\ndebug2: channel 2: is dead\r\ndebug2: channel 2: garbage collecting\r\ndebug1: channel 2: free: client-session, nchannels 3\r\ndebug3: channel 2: status: The following connections are open:\r\n  #1 mux-control (t16 nr0 i3/0 o1/16 fd 6/6 cc -1)\r\n  #2 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)\r\n\r\ndebug2: channel 1: obuf empty\r\ndebug2: channel 1: close_write\r\ndebug2: channel 1: output drain -> closed\r\ndebug2: channel 1: is dead (local)\r\ndebug2: channel 1: gc: notify user\r\ndebug3: mux_master_control_cleanup_cb: entering for channel 1\r\ndebug2: channel 1: gc: user detached\r\ndebug2: channel 1: is dead (local)\r\ndebug2: channel 1: garbage collecting\r\ndebug1: channel 1: free: mux-control, nchannels 2\r\ndebug3: channel 1: status: The following connections are open:\r\n  #1 mux-control (t16 nr0 i3/0 o3/0 fd 6/6 cc -1)\r\n\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\ndebug2: set_control_persist_exit_time: schedule exit in 60 seconds\r\n')
2018/06/13 10:11:00 ui:     googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:11:00 ui:     googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'( umask 77 && mkdir -p "` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" && echo ansible-tmp-1528902659.126792-183587805031127="` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" ) && sleep 0'"'"''
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 rejecting auth-agent-req@openssh.com request
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 new env request: LC_ALL=en_US.UTF-8
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 new env request: LANG=en_US.UTF-8
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 new exec request: /bin/sh -c '( umask 77 && mkdir -p "` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" && echo ansible-tmp-1528902659.126792-183587805031127="` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" ) && sleep 0'
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [DEBUG] Opening new ssh session
    googlecompute: <127.0.0.1> (0, b'~matt\n', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug1: Control socket "/Users/matt/.ansible/cp/10aa3a24eb" does not exist\r\ndebug2: resolving "127.0.0.1" port 52587\r\ndebug2: ssh_connect_direct: needpriv 0\r\ndebug1: Connecting to 127.0.0.1 [127.0.0.1] port 52587.\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug1: fd 3 clearing O_NONBLOCK\r\ndebug1: Connection established.\r\ndebug3: timeout: 10000 ms remain after connect\r\ndebug1: key_load_public: No such file or directory\r\ndebug1: identity file /tmp/ansible-key978442054 type -1\r\ndebug1: key_load_public: No such file or directory\r\ndebug1: identity file /tmp/ansible-key978442054-cert type -1\r\ndebug1: Local version string SSH-2.0-OpenSSH_7.6\r\ndebug1: Remote protocol version 2.0, remote software version Go\r\ndebug1: no match: Go\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug1: Authenticating to 127.0.0.1:52587 as \'matt\'\r\ndebug3: put_host_port: [127.0.0.1]:52587\r\ndebug3: hostkeys_foreach: reading file "/Users/matt/.ssh/known_hosts"\r\ndebug3: send packet: type 20\r\ndebug1: SSH2_MSG_KEXINIT sent\r\ndebug3: receive packet: type 20\r\ndebug1: SSH2_MSG_KEXINIT received\r\ndebug2: local client KEXINIT proposal\r\ndebug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,ext-info-c\r\ndebug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa\r\ndebug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com\r\ndebug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com\r\ndebug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: compression ctos: zlib@openssh.com,zlib,none\r\ndebug2: compression stoc: zlib@openssh.com,zlib,none\r\ndebug2: languages ctos: \r\ndebug2: languages stoc: \r\ndebug2: first_kex_follows 0 \r\ndebug2: reserved 0 \r\ndebug2: peer server KEXINIT proposal\r\ndebug2: KEX algorithms: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\r\ndebug2: host key algorithms: ssh-rsa\r\ndebug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,arcfour256,arcfour128\r\ndebug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,arcfour256,arcfour128\r\ndebug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha1-96\r\ndebug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha1-96\r\ndebug2: compression ctos: none\r\ndebug2: compression stoc: none\r\ndebug2: languages ctos: \r\ndebug2: languages stoc: \r\ndebug2: first_kex_follows 0 \r\ndebug2: reserved 0 \r\ndebug1: kex: algorithm: curve25519-sha256@libssh.org\r\ndebug1: kex: host key algorithm: ssh-rsa\r\ndebug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none\r\ndebug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: none\r\ndebug3: send packet: type 30\r\ndebug1: expecting SSH2_MSG_KEX_ECDH_REPLY\r\ndebug3: receive packet: type 31\r\ndebug1: Server host key: ssh-rsa SHA256:bnSPJlEjQ/9hOlGbqhft58MeIX0kqN9Y46e6LBppMzM\r\ndebug3: put_host_port: [127.0.0.1]:52587\r\ndebug3: put_host_port: [127.0.0.1]:52587\r\ndebug3: hostkeys_foreach: reading file "/Users/matt/.ssh/known_hosts"\r\ndebug1: checking without port identifier\r\ndebug3: hostkeys_foreach: reading file "/Users/matt/.ssh/known_hosts"\r\ndebug3: record_hostkey: found key type ECDSA in file /Users/matt/.ssh/known_hosts:16\r\ndebug3: load_hostkeys: loaded 1 keys from 127.0.0.1\r\nWarning: Permanently added \'[127.0.0.1]:52587\' (RSA) to the list of known hosts.\r\ndebug3: send packet: type 21\r\ndebug2: set_newkeys: mode 1\r\ndebug1: rekey after 4294967296 blocks\r\ndebug1: SSH2_MSG_NEWKEYS sent\r\ndebug1: expecting SSH2_MSG_NEWKEYS\r\ndebug3: receive packet: type 21\r\ndebug1: SSH2_MSG_NEWKEYS received\r\ndebug2: set_newkeys: mode 0\r\ndebug1: rekey after 4294967296 blocks\r\ndebug2: key: /tmp/ansible-key978442054 (0x0), explicit\r\ndebug3: send packet: type 5\r\ndebug3: receive packet: type 6\r\ndebug2: service_accept: ssh-userauth\r\ndebug1: SSH2_MSG_SERVICE_ACCEPT received\r\ndebug3: send packet: type 50\r\ndebug3: receive packet: type 51\r\ndebug1: Authentications that can continue: publickey\r\ndebug3: start over, passed a different list publickey\r\ndebug3: preferred gssapi-with-mic,gssapi-keyex,hostbased,publickey\r\ndebug3: authmethod_lookup publickey\r\ndebug3: remaining preferred: ,gssapi-keyex,hostbased,publickey\r\ndebug3: authmethod_is_enabled publickey\r\ndebug1: Next authentication method: publickey\r\ndebug1: Trying private key: /tmp/ansible-key978442054\r\ndebug3: sign_and_send_pubkey: RSA SHA256:ZsE8mR0gBcAZsZ0tRsvsKaonfUIDqtXxQsT9YG+s4aY\r\ndebug3: send packet: type 50\r\ndebug2: we sent a publickey packet, wait for reply\r\ndebug3: receive packet: type 52\r\ndebug1: Authentication succeeded (publickey).\r\nAuthenticated to 127.0.0.1 ([127.0.0.1]:52587).\r\ndebug1: setting up multiplex master socket\r\ndebug3: muxserver_listen: temporary control path /Users/matt/.ansible/cp/10aa3a24eb.KN099lGCjyYYGtli\r\ndebug2: fd 5 setting O_NONBLOCK\r\ndebug3: fd 5 is O_NONBLOCK\r\ndebug3: fd 5 is O_NONBLOCK\r\ndebug1: channel 0: new [/Users/matt/.ansible/cp/10aa3a24eb]\r\ndebug3: muxserver_listen: mux listener channel 0 fd 5\r\ndebug2: fd 3 setting TCP_NODELAY\r\ndebug3: ssh_packet_set_tos: set IP_TOS 0x08\r\ndebug1: control_persist_detach: backgrounding master process\r\ndebug2: control_persist_detach: background process is 13626\r\ndebug2: fd 5 setting O_NONBLOCK\r\ndebug1: forking to background\r\ndebug1: Entering interactive session.\r\ndebug1: pledge: id\r\ndebug2: set_control_persist_exit_time: schedule exit in 60 seconds\r\ndebug1: multiplexing control connection\r\ndebug3: fd 6 is O_NONBLOCK\r\ndebug3: fd 6 is O_NONBLOCK\r\ndebug1: channel 1: new [mux-control]\r\ndebug3: channel_post_mux_listener: new mux channel 1 fd 6\r\ndebug3: mux_master_read_cb: channel 1: hello sent\r\ndebug2: set_control_persist_exit_time: cancel scheduled exit\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x00000001 len 4\r\ndebug2: process_mux_master_hello: channel 1 slave version 4\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x10000004 len 4\r\ndebug2: process_mux_alive_check: channel 1: alive check\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x10000002 len 126\r\ndebug3: mux_client_request_session: session request sent\r\ndebug2: process_mux_new_session: channel 1: request tty 0, X 1, agent 1, subsys 0, term "xterm-256color", cmd "/bin/sh -c \'echo ~matt && sleep 0\'", env 2\r\ndebug3: process_mux_new_session: got fds stdin 7, stdout 8, stderr 9\r\ndebug2: fd 8 setting O_NONBLOCK\r\ndebug2: fd 9 setting O_NONBLOCK\r\ndebug1: channel 2: new [client-session]\r\ndebug2: process_mux_new_session: channel_new: 2 linked to control channel 1\r\ndebug2: channel 2: send open\r\ndebug3: send packet: type 90\r\ndebug3: receive packet: type 91\r\ndebug2: channel_input_open_confirmation: channel 2: callback start\r\ndebug1: Requesting authentication agent forwarding.\r\ndebug2: channel 2: request auth-agent-req@openssh.com confirm 0\r\ndebug3: send packet: type 98\r\ndebug2: client_session2_setup: id 2\r\ndebug1: Sending environment.\r\ndebug1: Sending env LC_ALL = en_US.UTF-8\r\ndebug2: channel 2: request env confirm 0\r\ndebug3: send packet: type 98\r\ndebug1: Sending env LANG = en_US.UTF-8\r\ndebug2: channel 2: request env confirm 0\r\ndebug3: send packet: type 98\r\ndebug1: Sending command: /bin/sh -c \'echo ~matt && sleep 0\'\r\ndebug2: channel 2: request exec confirm 1\r\ndebug3: send packet: type 98\r\ndebug3: mux_session_confirm: sending success reply\r\ndebug2: channel_input_open_confirmation: channel 2: callback done\r\ndebug2: channel 2: open confirm rwindow 2097152 rmax 32768\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: receive packet: type 99\r\ndebug2: channel_input_status_confirm: type 99 id 2\r\ndebug2: exec request accepted on channel 2\r\ndebug3: receive packet: type 98\r\ndebug1: client_input_channel_req: channel 2 rtype exit-status reply 0\r\ndebug3: mux_exit_message: channel 2: exit message, exitval 0\r\ndebug3: receive packet: type 97\r\ndebug2: channel 2: rcvd close\r\ndebug2: channel 2: output open -> drain\r\ndebug2: channel 2: close_read\r\ndebug2: channel 2: input open -> closed\r\ndebug3: channel 2: will not send data after close\r\ndebug2: channel 2: obuf empty\r\ndebug2: channel 2: close_write\r\ndebug2: channel 2: output drain -> closed\r\ndebug2: channel 2: send close\r\ndebug3: send packet: type 97\r\ndebug2: channel 2: is dead\r\ndebug2: channel 2: gc: notify user\r\ndebug3: mux_master_session_cleanup_cb: entering for channel 2\r\ndebug2: channel 1: rcvd close\r\ndebug2: channel 1: output open -> drain\r\ndebug2: channel 1: close_read\r\ndebug2: channel 1: input open -> closed\r\ndebug2: channel 2: gc: user detached\r\ndebug2: channel 2: is dead\r\ndebug2: channel 2: garbage collecting\r\ndebug1: channel 2: free: client-session, nchannels 3\r\ndebug3: channel 2: status: The following connections are open:\r\n  #1 mux-control (t16 nr0 i3/0 o1/16 fd 6/6 cc -1)\r\n  #2 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)\r\n\r\ndebug2: channel 1: obuf empty\r\ndebug2: channel 1: close_write\r\ndebug2: channel 1: output drain -> closed\r\ndebug2: channel 1: is dead (local)\r\ndebug2: channel 1: gc: notify user\r\ndebug3: mux_master_control_cleanup_cb: entering for channel 1\r\ndebug2: channel 1: gc: user detached\r\ndebug2: channel 1: is dead (local)\r\ndebug2: channel 1: garbage collecting\r\ndebug1: channel 1: free: mux-control, nchannels 2\r\ndebug3: channel 1: status: The following connections are open:\r\n  #1 mux-control (t16 nr0 i3/0 o3/0 fd 6/6 cc -1)\r\n\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\ndebug2: set_control_persist_exit_time: schedule exit in 60 seconds\r\n')
    googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
    googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'( umask 77 && mkdir -p "` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" && echo ansible-tmp-1528902659.126792-183587805031127="` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" ) && sleep 0'"'"''
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [DEBUG] starting remote command: /bin/sh -c '( umask 77 && mkdir -p "` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" && echo ansible-tmp-1528902659.126792-183587805031127="` echo ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127 `" ) && sleep 0'
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:00 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:00 [INFO] 111 bytes written for 'stdout'
2018/06/13 10:11:00 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:00 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:00 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [INFO] 111 bytes written for 'stdout'
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:00 packer: 2018/06/13 10:11:00 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:00 ui:     googlecompute: <127.0.0.1> (0, b'ansible-tmp-1528902659.126792-183587805031127=~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127\n', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
    googlecompute: <127.0.0.1> (0, b'ansible-tmp-1528902659.126792-183587805031127=~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127\n', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
2018/06/13 10:11:01 ui:     googlecompute: Using module file /Users/matt/projects/ansibledev/ansible/lib/ansible/modules/system/setup.py
    googlecompute: Using module file /Users/matt/projects/ansibledev/ansible/lib/ansible/modules/system/setup.py
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> PUT /Users/matt/.ansible/tmp/ansible-local-13619knl8e6ug/tmp9efcvect TO ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py
    googlecompute: <127.0.0.1> PUT /Users/matt/.ansible/tmp/ansible-local-13619knl8e6ug/tmp9efcvect TO ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> SSH: EXEC scp -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb /Users/matt/.ansible/tmp/ansible-local-13619knl8e6ug/tmp9efcvect '[127.0.0.1]:'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"''
    googlecompute: <127.0.0.1> SSH: EXEC scp -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb /Users/matt/.ansible/tmp/ansible-local-13619knl8e6ug/tmp9efcvect '[127.0.0.1]:'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"''
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new env request: LC_ALL=en_US.UTF-8
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new env request: LANG=en_US.UTF-8
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new exec request: scp -v -t '~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] Opening new ssh session
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [INFO] 209290 bytes written for 'uploadData'
2018/06/13 10:11:01 [INFO] 209290 bytes written for 'uploadData'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] Starting remote scp process:  scp -vt ~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] Started SCP session, beginning transfers...
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] scp: Uploading setup.py: perms=C0600 size=209290
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] SCP session complete, closing stdin pipe.
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] Waiting for SSH session to complete.
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] scp stderr (length 28): Sink: C0600 209290 setup.py
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> (0, b'', b"Executing: program /usr/bin/ssh host 127.0.0.1, user (unspecified), command scp -v -t '~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'\nOpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\nSending file modes: C0600 209290 tmp9efcvect\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n")
    googlecompute: <127.0.0.1> (0, b'', b"Executing: program /usr/bin/ssh host 127.0.0.1, user (unspecified), command scp -v -t '~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'\nOpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\nSending file modes: C0600 209290 tmp9efcvect\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n")
    googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'chmod u+x '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"'"'"'"'"'"'"' '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"'"'"'"'"'"'"' && sleep 0'"'"''
    googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'chmod u+x '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"'"'"'"'"'"'"' '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"'"'"'"'"'"'"' && sleep 0'"'"''
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 rejecting auth-agent-req@openssh.com request
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new env request: LC_ALL=en_US.UTF-8
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new env request: LANG=en_US.UTF-8
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new exec request: /bin/sh -c 'chmod u+x '"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"' '"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"' && sleep 0'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] Opening new ssh session
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] starting remote command: /bin/sh -c 'chmod u+x '"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"' '"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"' && sleep 0'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:01 [INFO] 0 bytes written for 'stdout'
2018/06/13 10:11:01 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:01 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:01 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:01 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [INFO] 0 bytes written for 'stdout'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> (0, b'', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
    googlecompute: <127.0.0.1> (0, b'', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:11:01 ui:     googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb -tt 127.0.0.1 '/bin/sh -c '"'"'sudo -H -S -n -u root /bin/sh -c '"'"'"'"'"'"'"'"'echo BECOME-SUCCESS-xqvuwtglmwjckgwlsuizpemcmmzvmxyt; /usr/bin/python '"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"''"'"'"'"'"'"'"'"' && sleep 0'"'"''
    googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
    googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb -tt 127.0.0.1 '/bin/sh -c '"'"'sudo -H -S -n -u root /bin/sh -c '"'"'"'"'"'"'"'"'echo BECOME-SUCCESS-xqvuwtglmwjckgwlsuizpemcmmzvmxyt; /usr/bin/python '"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"'"''"'"'"'"'"'"'"'"' && sleep 0'"'"''
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 rejecting auth-agent-req@openssh.com request
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 ansible provisioner pty-req request
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new env request: LC_ALL=en_US.UTF-8
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new env request: LANG=en_US.UTF-8
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 new exec request: /bin/sh -c 'sudo -H -S -n -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-xqvuwtglmwjckgwlsuizpemcmmzvmxyt; /usr/bin/python '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"'"'"'"'"'"'"''"'"' && sleep 0'
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] Opening new ssh session
2018/06/13 10:11:01 packer: 2018/06/13 10:11:01 [DEBUG] starting remote command: /bin/sh -c 'sudo -H -S -n -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-xqvuwtglmwjckgwlsuizpemcmmzvmxyt; /usr/bin/python '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py'"'"'"'"'"'"'"'"''"'"' && sleep 0'
2018/06/13 10:11:01 ui:     googlecompute: Escalation succeeded
    googlecompute: Escalation succeeded
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:02 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:02 [INFO] 15727 bytes written for 'stdout'
2018/06/13 10:11:02 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:02 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:02 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] 15727 bytes written for 'stdout'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:02 ui:     googlecompute: <127.0.0.1> (0, b'\n{"invocation": {"module_args": {"filter": "*", "gather_subset": ["all"], "fact_path": "/etc/ansible/facts.d", "gather_timeout": 10}}, "ansible_facts": {"ansible_product_serial": "GoogleCloud-C8B4A6F25CF45D31F44FD2AE3846C6FF", "ansible_form_factor": "Other", "ansible_real_group_id": 0, "ansible_user_gecos": "root", "ansible_distribution_file_parsed": true, "ansible_fips": false, "ansible_service_mgr": "systemd", "ansible_user_id": "root", "ansible_selinux_python_present": false, "ansible_userspace_bits": "64", "ansible_ssh_host_key_rsa_public": "AAAAB3NzaC1yc2EAAAADAQABAAABAQDIARUpxxHcK4COc3PhkhycHRzhRT7YLBJpcjCC4wn0m4NscmVnVd3aZkqNkCxufQvDgnoz2yJ3MZqPANUcslbCWPuCjQEPrQOM5Jzx2I5MsKaxl/7gK6A3snugiorzx26cqOfmG7EvkiPqSAOgsWE5SPEgUxyyeKeFpG1fxvddqG1Te5SXUp5ecajPOPGi6W/DYyhNZaxGQoq4hjq33BzEsn+r9JglFbwcq26u67dBpymjrEf/b2qNZ4o693DkdPpzSM0EdsqnQjDRyLi7t9Rk5Y1XPAUtIQCshWRX2kh2Gr94Cz4ht7ZDAG1EFPf6yFpW53fANKTLt9y20y4RH1qd", "gather_subset": ["all"], "ansible_architecture": "x86_64", "ansible_local": {}, "ansible_distribution_version": "16.04", "ansible_domain": "*****", "ansible_distribution_file_path": "/etc/os-release", "ansible_user_shell": "/bin/bash", "ansible_virtualization_type": "NA", "ansible_real_user_id": 0, "ansible_processor_cores": 1, "ansible_virtualization_role": "NA", "ansible_distribution_file_variety": "Debian", "ansible_dns": {"nameservers": ["169.254.169.254"], "search": ["*****", "google.internal"]}, "ansible_effective_group_id": 0, "ansible_bios_version": "Google", "ansible_processor": ["0", "GenuineIntel", "Intel(R) Xeon(R) CPU @ 2.50GHz"], "ansible_date_time": {"weekday_number": "3", "iso8601_basic_short": "20180613T151101", "tz": "UTC", "weeknumber": "24", "hour": "15", "year": "2018", "minute": "11", "tz_offset": "+0000", "month": "06", "epoch": "1528902661", "iso8601_micro": "2018-06-13T15:11:01.961403Z", "weekday": "Wednesday", "time": "15:11:01", "date": "2018-06-13", "iso8601": "2018-06-13T15:11:01Z", "day": "13", "iso8601_basic": "20180613T151101961283", "second": "01"}, "ansible_lo": {"features": {"tx_checksum_ipv4": "off [fixed]", "generic_receive_offload": "on", "tx_checksum_ipv6": "off [fixed]", "tx_scatter_gather_fraglist": "on [fixed]", "rx_all": "off [fixed]", "highdma": "on [fixed]", "rx_fcs": "off [fixed]", "tx_lockless": "on [fixed]", "tx_tcp_ecn_segmentation": "on", "esp_hw_offload": "off [fixed]", "tx_gso_robust": "off [fixed]", "tx_tcp_mangleid_segmentation": "on", "tx_ipxip4_segmentation": "off [fixed]", "tx_checksumming": "on", "vlan_challenged": "on [fixed]", "loopback": "on [fixed]", "tx_ipxip6_segmentation": "off [fixed]", "fcoe_mtu": "off [fixed]", "scatter_gather": "on", "tx_checksum_sctp": "on [fixed]", "tx_vlan_stag_hw_insert": "off [fixed]", "rx_vlan_stag_hw_parse": "off [fixed]", "tx_gso_partial": "off [fixed]", "rx_vlan_stag_filter": "off [fixed]", "large_receive_offload": "off [fixed]", "tx_scatter_gather": "on [fixed]", "rx_checksumming": "on [fixed]", "tx_tcp_segmentation": "on", "netns_local": "on [fixed]", "tx_esp_segmentation": "off [fixed]", "generic_segmentation_offload": "on", "tx_udp_tnl_segmentation": "off [fixed]", "tcp_segmentation_offload": "on", "l2_fwd_offload": "off [fixed]", "rx_vlan_offload": "off [fixed]", "ntuple_filters": "off [fixed]", "tx_gre_csum_segmentation": "off [fixed]", "esp_tx_csum_hw_offload": "off [fixed]", "tx_tcp6_segmentation": "on", "tx_udp_tnl_csum_segmentation": "off [fixed]", "udp_fragmentation_offload": "on", "tx_sctp_segmentation": "on", "tx_checksum_fcoe_crc": "off [fixed]", "hw_tc_offload": "off [fixed]", "tx_checksum_ip_generic": "on [fixed]", "tx_fcoe_segmentation": "off [fixed]", "tx_nocache_copy": "off [fixed]", "rx_vlan_filter": "off [fixed]", "tx_vlan_offload": "off [fixed]", "receive_hashing": "off [fixed]", "tx_gre_segmentation": "off [fixed]"}, "hw_timestamp_filters": [], "mtu": 65536, "device": "lo", "promisc": false, "timestamping": ["tx_software", "rx_software", "software"], "ipv4": {"broadcast": "host", "netmask": "255.0.0.0", "network": "127.0.0.0", "address": "127.0.0.1"}, "ipv6": [{"scope": "host", "prefix": "128", "address": "::1"}], "active": true, "type": "loopback"}, "ansible_memtotal_mb": 3693, "ansible_ssh_host_key_ecdsa_public": "AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBIi6/IcZG9d8RBPW8VC7nU9mHwFZ85X/6hfDwHpR7+v2KD0NGUxsLk0YPbsAUJ2Auuw1yecr1c1nEB90fM221sA=", "ansible_device_links": {"masters": {}, "labels": {"sda1": ["cloudimg-rootfs"]}, "ids": {"sda": ["google-persistent-disk-0", "scsi-0Google_PersistentDisk_persistent-disk-0"], "sda1": ["google-persistent-disk-0-part1", "scsi-0Google_PersistentDisk_persistent-disk-0-part1"]}, "uuids": {"sda1": ["84ce5b56-30b1-4479-a864-7296bb549cec"]}}, "ansible_default_ipv4": {"macaddress": "42:01:0a:80:00:02", "network": "10.128.0.2", "mtu": 1460, "broadcast": "10.128.0.2", "alias": "ens4", "netmask": "255.255.255.255", "address": "10.128.0.2", "interface": "ens4", "type": "ether", "gateway": "10.128.0.1"}, "ansible_swapfree_mb": 0, "ansible_default_ipv6": {}, "ansible_distribution_release": "xenial", "ansible_system_vendor": "Google", "ansible_os_family": "Debian", "ansible_cmdline": {"BOOT_IMAGE": "/boot/vmlinuz-4.13.0-1017-gcp", "scsi_mod.use_blk_mq": "Y", "ro": true, "root": "LABEL=cloudimg-rootfs", "console": "ttyS0"}, "ansible_effective_user_id": 0, "ansible_user_gid": 0, "ansible_selinux": {"status": "Missing selinux Python library"}, "ansible_product_version": "NA", "ansible_apparmor": {"status": "enabled"}, "ansible_userspace_architecture": "x86_64", "ansible_product_uuid": "C8B4A6F2-5CF4-5D31-F44F-D2AE3846C6FF", "ansible_fqdn": "packer-5b2133cd-fa5b-3c07-2929-fa22d53c444d.c.*****", "ansible_system": "Linux", "ansible_pkg_mgr": "apt", "ansible_memfree_mb": 3331, "ansible_devices": {"sda": {"scheduler_mode": "none", "rotational": "0", "vendor": "Google", "sectors": "20971520", "links": {"masters": [], "labels": [], "ids": ["google-persistent-disk-0", "scsi-0Google_PersistentDisk_persistent-disk-0"], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "Non-VGA unclassified device: Red Hat, Inc Virtio SCSI", "sectorsize": "512", "removable": "0", "support_discard": "4096", "model": "PersistentDisk", "partitions": {"sda1": {"sectorsize": 512, "uuid": "84ce5b56-30b1-4479-a864-7296bb549cec", "links": {"masters": [], "labels": ["cloudimg-rootfs"], "ids": ["google-persistent-disk-0-part1", "scsi-0Google_PersistentDisk_persistent-disk-0-part1"], "uuids": ["84ce5b56-30b1-4479-a864-7296bb549cec"]}, "sectors": "20969439", "start": "2048", "holders": [], "size": "10.00 GB"}}, "holders": [], "size": "10.00 GB"}, "loop3": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop2": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop1": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop0": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop7": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop6": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop5": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop4": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}}, "ansible_user_uid": 0, "ansible_lvm": {"pvs": {}, "lvs": {}, "vgs": {}}, "ansible_distribution": "Ubuntu", "ansible_user_dir": "/root", "ansible_env": {"USERNAME": "root", "LANG": "en_US.UTF-8", "SUDO_GID": "1002", "SHELL": "/bin/bash", "SUDO_COMMAND": "/bin/sh -c echo BECOME-SUCCESS-xqvuwtglmwjckgwlsuizpemcmmzvmxyt; /usr/bin/python \'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py\'", "SUDO_UID": "1001", "TERM": "unknown", "MAIL": "/var/mail/root", "PWD": "/home/packer", "LOGNAME": "root", "USER": "root", "HOME": "/root", "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin", "SUDO_USER": "packer"}, "ansible_distribution_major_version": "16", "module_setup": true, "ansible_processor_count": 1, "ansible_hostname": "packer-5b2133cd-fa5b-3c07-2929-fa22d53c444d", "ansible_processor_vcpus": 1, "ansible_swaptotal_mb": 0, "ansible_lsb": {"release": "16.04", "major_release": "16", "codename": "xenial", "id": "Ubuntu", "description": "Ubuntu 16.04.4 LTS"}, "ansible_ssh_host_key_ed25519_public": "AAAAC3NzaC1lZDI1NTE5AAAAIDqHPmURIPmTKNa4cmNiiQ2jjqmAmWoicLkRAwRT1mJR", "ansible_bios_date": "01/01/2011", "ansible_all_ipv6_addresses": ["fe80::4001:aff:fe80:2"], "ansible_interfaces": ["ens4", "lo"], "ansible_uptime_seconds": 35, "ansible_machine_id": "c8b4a6f25cf45d31f44fd2ae3846c6ff", "ansible_kernel": "4.13.0-1017-gcp", "ansible_iscsi_iqn": "iqn.1993-08.org.debian:01:70facc643553", "ansible_system_capabilities_enforced": "True", "ansible_python": {"executable": "/usr/bin/python", "version": {"micro": 12, "major": 2, "releaselevel": "final", "serial": 0, "minor": 7}, "type": "CPython", "has_sslcontext": true, "version_info": [2, 7, 12, "final", 0]}, "ansible_processor_threads_per_core": 1, "ansible_is_chroot": false, "ansible_mounts": [{"block_used": 290344, "uuid": "84ce5b56-30b1-4479-a864-7296bb549cec", "size_total": 10340831232, "block_total": 2524617, "mount": "/", "block_available": 2234273, "size_available": 9151582208, "fstype": "ext4", "inode_total": 1280000, "options": "rw,relatime,data=ordered", "device": "/dev/sda1", "inode_used": 81923, "block_size": 4096, "inode_available": 1198077}], "ansible_memory_mb": {"real": {"total": 3693, "used": 362, "free": 3331}, "swap": {"cached": 0, "total": 0, "free": 0, "used": 0}, "nocache": {"used": 157, "free": 3536}}, "ansible_nodename": "packer-5b2133cd-fa5b-3c07-2929-fa22d53c444d", "ansible_product_name": "Google Compute Engine", "ansible_machine": "x86_64", "ansible_system_capabilities": ["cap_chown", "cap_dac_override", "cap_dac_read_search", "cap_fowner", "cap_fsetid", "cap_kill", "cap_setgid", "cap_setuid", "cap_setpcap", "cap_linux_immutable", "cap_net_bind_service", "cap_net_broadcast", "cap_net_admin", "cap_net_raw", "cap_ipc_lock", "cap_ipc_owner", "cap_sys_module", "cap_sys_rawio", "cap_sys_chroot", "cap_sys_ptrace", "cap_sys_pacct", "cap_sys_admin", "cap_sys_boot", "cap_sys_nice", "cap_sys_resource", "cap_sys_time", "cap_sys_tty_config", "cap_mknod", "cap_lease", "cap_audit_write", "cap_audit_control", "cap_setfcap", "cap_mac_override", "cap_mac_admin", "cap_syslog", "cap_wake_alarm", "cap_block_suspend", "37+ep"], "ansible_ssh_host_key_dsa_public": "AAAAB3NzaC1kc3MAAACBAP9Wl7GtPPssSbmUn27ZWlDY/rnyGV89aKBJyptNVTeUj0opoccV8bl07kjH6Lx40KXthabE88OrmJsRkS0Sz8m/hEDWpW/L0BmuglG64pKon25nLIejvk63OFGcQP8pGYOvDXt0O5w34XyuyS++L+89v8DcEf7fu2Z27IDmRRjZAAAAFQCKkzJBvAZ5ErVuqt9ae5K3AsygTwAAAIEA44hfi3zh5AqxJxIEnTIW8jZHUW5PQOARy/eM73goi8/dmf1a6A/mNFqNuYH4nwKD5mxAGVDtXuk5UP0/KclMS/UspfLCBNuzuzutLktYkMeplg1lHTpRgA9FS8Hlfy4jWphEsNAER8hRWH9pYHJmQlJ++6ijour0qBn13OfgFwUAAACBAOotWePY5eHeXNSUlaKtBRB68z1Jr9/iyT0QLEbV+cyqGh4xYKMBVRBy44f8VDeTpwhZON/s8vzJINOEkNzgCA7qBWLWEzTWKLO+TVMfDsCH0Svu5jeEtwVwz9rOWcuGdLXyb9J+9mL28DVe1aB+TXyphebzNYk5/aybTi7+ytyP", "ansible_all_ipv4_addresses": ["10.128.0.2"], "ansible_python_version": "2.7.12", "ansible_ens4": {"macaddress": "42:01:0a:80:00:02", "features": {"tx_checksum_ipv4": "off [fixed]", "generic_receive_offload": "on", "tx_checksum_ipv6": "off [fixed]", "tx_scatter_gather_fraglist": "off [fixed]", "rx_all": "off [fixed]", "highdma": "on [fixed]", "rx_fcs": "off [fixed]", "tx_lockless": "off [fixed]", "tx_tcp_ecn_segmentation": "off [fixed]", "esp_hw_offload": "off [fixed]", "tx_gso_robust": "on [fixed]", "tx_tcp_mangleid_segmentation": "off", "tx_ipxip4_segmentation": "off [fixed]", "tx_checksumming": "on", "vlan_challenged": "off [fixed]", "loopback": "off [fixed]", "tx_ipxip6_segmentation": "off [fixed]", "fcoe_mtu": "off [fixed]", "scatter_gather": "on", "tx_checksum_sctp": "off [fixed]", "tx_vlan_stag_hw_insert": "off [fixed]", "rx_vlan_stag_hw_parse": "off [fixed]", "tx_gso_partial": "off [fixed]", "rx_vlan_stag_filter": "off [fixed]", "large_receive_offload": "off [fixed]", "tx_scatter_gather": "on", "rx_checksumming": "on [fixed]", "tx_tcp_segmentation": "on", "netns_local": "off [fixed]", "tx_esp_segmentation": "off [fixed]", "generic_segmentation_offload": "on", "tx_udp_tnl_segmentation": "off [fixed]", "tcp_segmentation_offload": "on", "l2_fwd_offload": "off [fixed]", "rx_vlan_offload": "off [fixed]", "ntuple_filters": "off [fixed]", "tx_gre_csum_segmentation": "off [fixed]", "esp_tx_csum_hw_offload": "off [fixed]", "tx_tcp6_segmentation": "on", "tx_udp_tnl_csum_segmentation": "off [fixed]", "udp_fragmentation_offload": "off [fixed]", "tx_sctp_segmentation": "off [fixed]", "tx_checksum_fcoe_crc": "off [fixed]", "hw_tc_offload": "off [fixed]", "tx_checksum_ip_generic": "on", "tx_fcoe_segmentation": "off [fixed]", "tx_nocache_copy": "off", "rx_vlan_filter": "off [fixed]", "tx_vlan_offload": "off [fixed]", "receive_hashing": "off [fixed]", "tx_gre_segmentation": "off [fixed]"}, "type": "ether", "pciid": "virtio1", "module": "virtio_net", "mtu": 1460, "device": "ens4", "promisc": false, "timestamping": ["tx_software", "rx_software", "software"], "ipv4": {"broadcast": "10.128.0.2", "netmask": "255.255.255.255", "network": "10.128.0.2", "address": "10.128.0.2"}, "ipv6": [{"scope": "link", "prefix": "64", "address": "fe80::4001:aff:fe80:2"}], "active": true, "speed": -1, "hw_timestamp_filters": []}}}\n', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\nShared connection to 127.0.0.1 closed.\r\n')
2018/06/13 10:11:02 ui:     googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:11:02 ui:     googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'rm -f -r '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"'"'"'"'"'"'"' > /dev/null 2>&1 && sleep 0'"'"''
    googlecompute: <127.0.0.1> (0, b'\n{"invocation": {"module_args": {"filter": "*", "gather_subset": ["all"], "fact_path": "/etc/ansible/facts.d", "gather_timeout": 10}}, "ansible_facts": {"ansible_product_serial": "GoogleCloud-C8B4A6F25CF45D31F44FD2AE3846C6FF", "ansible_form_factor": "Other", "ansible_real_group_id": 0, "ansible_user_gecos": "root", "ansible_distribution_file_parsed": true, "ansible_fips": false, "ansible_service_mgr": "systemd", "ansible_user_id": "root", "ansible_selinux_python_present": false, "ansible_userspace_bits": "64", "ansible_ssh_host_key_rsa_public": "AAAAB3NzaC1yc2EAAAADAQABAAABAQDIARUpxxHcK4COc3PhkhycHRzhRT7YLBJpcjCC4wn0m4NscmVnVd3aZkqNkCxufQvDgnoz2yJ3MZqPANUcslbCWPuCjQEPrQOM5Jzx2I5MsKaxl/7gK6A3snugiorzx26cqOfmG7EvkiPqSAOgsWE5SPEgUxyyeKeFpG1fxvddqG1Te5SXUp5ecajPOPGi6W/DYyhNZaxGQoq4hjq33BzEsn+r9JglFbwcq26u67dBpymjrEf/b2qNZ4o693DkdPpzSM0EdsqnQjDRyLi7t9Rk5Y1XPAUtIQCshWRX2kh2Gr94Cz4ht7ZDAG1EFPf6yFpW53fANKTLt9y20y4RH1qd", "gather_subset": ["all"], "ansible_architecture": "x86_64", "ansible_local": {}, "ansible_distribution_version": "16.04", "ansible_domain": "*****", "ansible_distribution_file_path": "/etc/os-release", "ansible_user_shell": "/bin/bash", "ansible_virtualization_type": "NA", "ansible_real_user_id": 0, "ansible_processor_cores": 1, "ansible_virtualization_role": "NA", "ansible_distribution_file_variety": "Debian", "ansible_dns": {"nameservers": ["169.254.169.254"], "search": ["*****", "google.internal"]}, "ansible_effective_group_id": 0, "ansible_bios_version": "Google", "ansible_processor": ["0", "GenuineIntel", "Intel(R) Xeon(R) CPU @ 2.50GHz"], "ansible_date_time": {"weekday_number": "3", "iso8601_basic_short": "20180613T151101", "tz": "UTC", "weeknumber": "24", "hour": "15", "year": "2018", "minute": "11", "tz_offset": "+0000", "month": "06", "epoch": "1528902661", "iso8601_micro": "2018-06-13T15:11:01.961403Z", "weekday": "Wednesday", "time": "15:11:01", "date": "2018-06-13", "iso8601": "2018-06-13T15:11:01Z", "day": "13", "iso8601_basic": "20180613T151101961283", "second": "01"}, "ansible_lo": {"features": {"tx_checksum_ipv4": "off [fixed]", "generic_receive_offload": "on", "tx_checksum_ipv6": "off [fixed]", "tx_scatter_gather_fraglist": "on [fixed]", "rx_all": "off [fixed]", "highdma": "on [fixed]", "rx_fcs": "off [fixed]", "tx_lockless": "on [fixed]", "tx_tcp_ecn_segmentation": "on", "esp_hw_offload": "off [fixed]", "tx_gso_robust": "off [fixed]", "tx_tcp_mangleid_segmentation": "on", "tx_ipxip4_segmentation": "off [fixed]", "tx_checksumming": "on", "vlan_challenged": "on [fixed]", "loopback": "on [fixed]", "tx_ipxip6_segmentation": "off [fixed]", "fcoe_mtu": "off [fixed]", "scatter_gather": "on", "tx_checksum_sctp": "on [fixed]", "tx_vlan_stag_hw_insert": "off [fixed]", "rx_vlan_stag_hw_parse": "off [fixed]", "tx_gso_partial": "off [fixed]", "rx_vlan_stag_filter": "off [fixed]", "large_receive_offload": "off [fixed]", "tx_scatter_gather": "on [fixed]", "rx_checksumming": "on [fixed]", "tx_tcp_segmentation": "on", "netns_local": "on [fixed]", "tx_esp_segmentation": "off [fixed]", "generic_segmentation_offload": "on", "tx_udp_tnl_segmentation": "off [fixed]", "tcp_segmentation_offload": "on", "l2_fwd_offload": "off [fixed]", "rx_vlan_offload": "off [fixed]", "ntuple_filters": "off [fixed]", "tx_gre_csum_segmentation": "off [fixed]", "esp_tx_csum_hw_offload": "off [fixed]", "tx_tcp6_segmentation": "on", "tx_udp_tnl_csum_segmentation": "off [fixed]", "udp_fragmentation_offload": "on", "tx_sctp_segmentation": "on", "tx_checksum_fcoe_crc": "off [fixed]", "hw_tc_offload": "off [fixed]", "tx_checksum_ip_generic": "on [fixed]", "tx_fcoe_segmentation": "off [fixed]", "tx_nocache_copy": "off [fixed]", "rx_vlan_filter": "off [fixed]", "tx_vlan_offload": "off [fixed]", "receive_hashing": "off [fixed]", "tx_gre_segmentation": "off [fixed]"}, "hw_timestamp_filters": [], "mtu": 65536, "device": "lo", "promisc": false, "timestamping": ["tx_software", "rx_software", "software"], "ipv4": {"broadcast": "host", "netmask": "255.0.0.0", "network": "127.0.0.0", "address": "127.0.0.1"}, "ipv6": [{"scope": "host", "prefix": "128", "address": "::1"}], "active": true, "type": "loopback"}, "ansible_memtotal_mb": 3693, "ansible_ssh_host_key_ecdsa_public": "AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBIi6/IcZG9d8RBPW8VC7nU9mHwFZ85X/6hfDwHpR7+v2KD0NGUxsLk0YPbsAUJ2Auuw1yecr1c1nEB90fM221sA=", "ansible_device_links": {"masters": {}, "labels": {"sda1": ["cloudimg-rootfs"]}, "ids": {"sda": ["google-persistent-disk-0", "scsi-0Google_PersistentDisk_persistent-disk-0"], "sda1": ["google-persistent-disk-0-part1", "scsi-0Google_PersistentDisk_persistent-disk-0-part1"]}, "uuids": {"sda1": ["84ce5b56-30b1-4479-a864-7296bb549cec"]}}, "ansible_default_ipv4": {"macaddress": "42:01:0a:80:00:02", "network": "10.128.0.2", "mtu": 1460, "broadcast": "10.128.0.2", "alias": "ens4", "netmask": "255.255.255.255", "address": "10.128.0.2", "interface": "ens4", "type": "ether", "gateway": "10.128.0.1"}, "ansible_swapfree_mb": 0, "ansible_default_ipv6": {}, "ansible_distribution_release": "xenial", "ansible_system_vendor": "Google", "ansible_os_family": "Debian", "ansible_cmdline": {"BOOT_IMAGE": "/boot/vmlinuz-4.13.0-1017-gcp", "scsi_mod.use_blk_mq": "Y", "ro": true, "root": "LABEL=cloudimg-rootfs", "console": "ttyS0"}, "ansible_effective_user_id": 0, "ansible_user_gid": 0, "ansible_selinux": {"status": "Missing selinux Python library"}, "ansible_product_version": "NA", "ansible_apparmor": {"status": "enabled"}, "ansible_userspace_architecture": "x86_64", "ansible_product_uuid": "C8B4A6F2-5CF4-5D31-F44F-D2AE3846C6FF", "ansible_fqdn": "packer-5b2133cd-fa5b-3c07-2929-fa22d53c444d.*****", "ansible_system": "Linux", "ansible_pkg_mgr": "apt", "ansible_memfree_mb": 3331, "ansible_devices": {"sda": {"scheduler_mode": "none", "rotational": "0", "vendor": "Google", "sectors": "20971520", "links": {"masters": [], "labels": [], "ids": ["google-persistent-disk-0", "scsi-0Google_PersistentDisk_persistent-disk-0"], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "Non-VGA unclassified device: Red Hat, Inc Virtio SCSI", "sectorsize": "512", "removable": "0", "support_discard": "4096", "model": "PersistentDisk", "partitions": {"sda1": {"sectorsize": 512, "uuid": "84ce5b56-30b1-4479-a864-7296bb549cec", "links": {"masters": [], "labels": ["cloudimg-rootfs"], "ids": ["google-persistent-disk-0-part1", "scsi-0Google_PersistentDisk_persistent-disk-0-part1"], "uuids": ["84ce5b56-30b1-4479-a864-7296bb549cec"]}, "sectors": "20969439", "start": "2048", "holders": [], "size": "10.00 GB"}}, "holders": [], "size": "10.00 GB"}, "loop3": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop2": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop1": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop0": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop7": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop6": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop5": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}, "loop4": {"scheduler_mode": "none", "rotational": "1", "vendor": null, "sectors": "0", "links": {"masters": [], "labels": [], "ids": [], "uuids": []}, "sas_device_handle": null, "sas_address": null, "virtual": 1, "host": "", "sectorsize": "512", "removable": "0", "support_discard": "0", "model": null, "partitions": {}, "holders": [], "size": "0.00 Bytes"}}, "ansible_user_uid": 0, "ansible_lvm": {"pvs": {}, "lvs": {}, "vgs": {}}, "ansible_distribution": "Ubuntu", "ansible_user_dir": "/root", "ansible_env": {"USERNAME": "root", "LANG": "en_US.UTF-8", "SUDO_GID": "1002", "SHELL": "/bin/bash", "SUDO_COMMAND": "/bin/sh -c echo BECOME-SUCCESS-xqvuwtglmwjckgwlsuizpemcmmzvmxyt; /usr/bin/python \'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/setup.py\'", "SUDO_UID": "1001", "TERM": "unknown", "MAIL": "/var/mail/root", "PWD": "/home/packer", "LOGNAME": "root", "USER": "root", "HOME": "/root", "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin", "SUDO_USER": "packer"}, "ansible_distribution_major_version": "16", "module_setup": true, "ansible_processor_count": 1, "ansible_hostname": "packer-5b2133cd-fa5b-3c07-2929-fa22d53c444d", "ansible_processor_vcpus": 1, "ansible_swaptotal_mb": 0, "ansible_lsb": {"release": "16.04", "major_release": "16", "codename": "xenial", "id": "Ubuntu", "description": "Ubuntu 16.04.4 LTS"}, "ansible_ssh_host_key_ed25519_public": "AAAAC3NzaC1lZDI1NTE5AAAAIDqHPmURIPmTKNa4cmNiiQ2jjqmAmWoicLkRAwRT1mJR", "ansible_bios_date": "01/01/2011", "ansible_all_ipv6_addresses": ["fe80::4001:aff:fe80:2"], "ansible_interfaces": ["ens4", "lo"], "ansible_uptime_seconds": 35, "ansible_machine_id": "c8b4a6f25cf45d31f44fd2ae3846c6ff", "ansible_kernel": "4.13.0-1017-gcp", "ansible_iscsi_iqn": "iqn.1993-08.org.debian:01:70facc643553", "ansible_system_capabilities_enforced": "True", "ansible_python": {"executable": "/usr/bin/python", "version": {"micro": 12, "major": 2, "releaselevel": "final", "serial": 0, "minor": 7}, "type": "CPython", "has_sslcontext": true, "version_info": [2, 7, 12, "final", 0]}, "ansible_processor_threads_per_core": 1, "ansible_is_chroot": false, "ansible_mounts": [{"block_used": 290344, "uuid": "84ce5b56-30b1-4479-a864-7296bb549cec", "size_total": 10340831232, "block_total": 2524617, "mount": "/", "block_available": 2234273, "size_available": 9151582208, "fstype": "ext4", "inode_total": 1280000, "options": "rw,relatime,data=ordered", "device": "/dev/sda1", "inode_used": 81923, "block_size": 4096, "inode_available": 1198077}], "ansible_memory_mb": {"real": {"total": 3693, "used": 362, "free": 3331}, "swap": {"cached": 0, "total": 0, "free": 0, "used": 0}, "nocache": {"used": 157, "free": 3536}}, "ansible_nodename": "packer-5b2133cd-fa5b-3c07-2929-fa22d53c444d", "ansible_product_name": "Google Compute Engine", "ansible_machine": "x86_64", "ansible_system_capabilities": ["cap_chown", "cap_dac_override", "cap_dac_read_search", "cap_fowner", "cap_fsetid", "cap_kill", "cap_setgid", "cap_setuid", "cap_setpcap", "cap_linux_immutable", "cap_net_bind_service", "cap_net_broadcast", "cap_net_admin", "cap_net_raw", "cap_ipc_lock", "cap_ipc_owner", "cap_sys_module", "cap_sys_rawio", "cap_sys_chroot", "cap_sys_ptrace", "cap_sys_pacct", "cap_sys_admin", "cap_sys_boot", "cap_sys_nice", "cap_sys_resource", "cap_sys_time", "cap_sys_tty_config", "cap_mknod", "cap_lease", "cap_audit_write", "cap_audit_control", "cap_setfcap", "cap_mac_override", "cap_mac_admin", "cap_syslog", "cap_wake_alarm", "cap_block_suspend", "37+ep"], "ansible_ssh_host_key_dsa_public": "AAAAB3NzaC1kc3MAAACBAP9Wl7GtPPssSbmUn27ZWlDY/rnyGV89aKBJyptNVTeUj0opoccV8bl07kjH6Lx40KXthabE88OrmJsRkS0Sz8m/hEDWpW/L0BmuglG64pKon25nLIejvk63OFGcQP8pGYOvDXt0O5w34XyuyS++L+89v8DcEf7fu2Z27IDmRRjZAAAAFQCKkzJBvAZ5ErVuqt9ae5K3AsygTwAAAIEA44hfi3zh5AqxJxIEnTIW8jZHUW5PQOARy/eM73goi8/dmf1a6A/mNFqNuYH4nwKD5mxAGVDtXuk5UP0/KclMS/UspfLCBNuzuzutLktYkMeplg1lHTpRgA9FS8Hlfy4jWphEsNAER8hRWH9pYHJmQlJ++6ijour0qBn13OfgFwUAAACBAOotWePY5eHeXNSUlaKtBRB68z1Jr9/iyT0QLEbV+cyqGh4xYKMBVRBy44f8VDeTpwhZON/s8vzJINOEkNzgCA7qBWLWEzTWKLO+TVMfDsCH0Svu5jeEtwVwz9rOWcuGdLXyb9J+9mL28DVe1aB+TXyphebzNYk5/aybTi7+ytyP", "ansible_all_ipv4_addresses": ["10.128.0.2"], "ansible_python_version": "2.7.12", "ansible_ens4": {"macaddress": "42:01:0a:80:00:02", "features": {"tx_checksum_ipv4": "off [fixed]", "generic_receive_offload": "on", "tx_checksum_ipv6": "off [fixed]", "tx_scatter_gather_fraglist": "off [fixed]", "rx_all": "off [fixed]", "highdma": "on [fixed]", "rx_fcs": "off [fixed]", "tx_lockless": "off [fixed]", "tx_tcp_ecn_segmentation": "off [fixed]", "esp_hw_offload": "off [fixed]", "tx_gso_robust": "on [fixed]", "tx_tcp_mangleid_segmentation": "off", "tx_ipxip4_segmentation": "off [fixed]", "tx_checksumming": "on", "vlan_challenged": "off [fixed]", "loopback": "off [fixed]", "tx_ipxip6_segmentation": "off [fixed]", "fcoe_mtu": "off [fixed]", "scatter_gather": "on", "tx_checksum_sctp": "off [fixed]", "tx_vlan_stag_hw_insert": "off [fixed]", "rx_vlan_stag_hw_parse": "off [fixed]", "tx_gso_partial": "off [fixed]", "rx_vlan_stag_filter": "off [fixed]", "large_receive_offload": "off [fixed]", "tx_scatter_gather": "on", "rx_checksumming": "on [fixed]", "tx_tcp_segmentation": "on", "netns_local": "off [fixed]", "tx_esp_segmentation": "off [fixed]", "generic_segmentation_offload": "on", "tx_udp_tnl_segmentation": "off [fixed]", "tcp_segmentation_offload": "on", "l2_fwd_offload": "off [fixed]", "rx_vlan_offload": "off [fixed]", "ntuple_filters": "off [fixed]", "tx_gre_csum_segmentation": "off [fixed]", "esp_tx_csum_hw_offload": "off [fixed]", "tx_tcp6_segmentation": "on", "tx_udp_tnl_csum_segmentation": "off [fixed]", "udp_fragmentation_offload": "off [fixed]", "tx_sctp_segmentation": "off [fixed]", "tx_checksum_fcoe_crc": "off [fixed]", "hw_tc_offload": "off [fixed]", "tx_checksum_ip_generic": "on", "tx_fcoe_segmentation": "off [fixed]", "tx_nocache_copy": "off", "rx_vlan_filter": "off [fixed]", "tx_vlan_offload": "off [fixed]", "receive_hashing": "off [fixed]", "tx_gre_segmentation": "off [fixed]"}, "type": "ether", "pciid": "virtio1", "module": "virtio_net", "mtu": 1460, "device": "ens4", "promisc": false, "timestamping": ["tx_software", "rx_software", "software"], "ipv4": {"broadcast": "10.128.0.2", "netmask": "255.255.255.255", "network": "10.128.0.2", "address": "10.128.0.2"}, "ipv6": [{"scope": "link", "prefix": "64", "address": "fe80::4001:aff:fe80:2"}], "active": true, "speed": -1, "hw_timestamp_filters": []}}}\n', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\nShared connection to 127.0.0.1 closed.\r\n')
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 rejecting auth-agent-req@openssh.com request
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 new env request: LC_ALL=en_US.UTF-8
    googlecompute: <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: matt
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 new env request: LANG=en_US.UTF-8
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 new exec request: /bin/sh -c 'rm -f -r '"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"' > /dev/null 2>&1 && sleep 0'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [DEBUG] Opening new ssh session
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [DEBUG] starting remote command: /bin/sh -c 'rm -f -r '"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"' > /dev/null 2>&1 && sleep 0'
    googlecompute: <127.0.0.1> SSH: EXEC ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=52587 -o 'IdentityFile="/tmp/ansible-key978442054"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=matt -o ConnectTimeout=10 -o IdentitiesOnly=yes -o ControlPath=/Users/matt/.ansible/cp/10aa3a24eb 127.0.0.1 '/bin/sh -c '"'"'rm -f -r '"'"'"'"'"'"'"'"'~matt/.ansible/tmp/ansible-tmp-1528902659.126792-183587805031127/'"'"'"'"'"'"'"'"' > /dev/null 2>&1 && sleep 0'"'"''
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:02 [INFO] 0 bytes written for 'stdout'
2018/06/13 10:11:02 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:02 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:02 [INFO] RPC endpoint: Communicator ended with: 0
2018/06/13 10:11:02 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] 0 bytes written for 'stdout'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] 0 bytes written for 'stderr'
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] RPC client: Communicator ended with: 0
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 [INFO] 0 bytes written for 'stdin'
2018/06/13 10:11:02 ui:     googlecompute: <127.0.0.1> (0, b'', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
    googlecompute: <127.0.0.1> (0, b'', b'OpenSSH_7.6p1, LibreSSL 2.6.2\r\ndebug1: Reading configuration data /Users/matt/.ssh/config\r\ndebug1: /Users/matt/.ssh/config line 56: Applying options for *\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 48: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 13628\r\ndebug3: mux_client_request_session: session request sent\r\ndebug1: mux_client_request_session: master session id: 2\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
2018/06/13 10:11:02 ui:     googlecompute: ok: [default]
    googlecompute: ok: [default]
2018/06/13 10:11:02 ui:     googlecompute: META: ran handlers
    googlecompute: META: ran handlers
    googlecompute: META: ran handlers
2018/06/13 10:11:02 ui:     googlecompute: META: ran handlers
    googlecompute: META: ran handlers
2018/06/13 10:11:02 ui:     googlecompute: META: ran handlers
2018/06/13 10:11:02 ui:     googlecompute:
    googlecompute:
2018/06/13 10:11:02 ui:     googlecompute: PLAY RECAP *********************************************************************
    googlecompute: PLAY RECAP *********************************************************************
    googlecompute: default                    : ok=1    changed=0    unreachable=0    failed=0
2018/06/13 10:11:02 ui:     googlecompute: default                    : ok=1    changed=0    unreachable=0    failed=0
2018/06/13 10:11:02 ui:     googlecompute:
    googlecompute:
2018/06/13 10:11:02 packer: 2018/06/13 10:11:02 shutting down the SSH proxy
2018/06/13 10:11:02 [INFO] (telemetry) ending ansible
2018/06/13 10:11:02 ui: ==> googlecompute: Deleting instance...
==> googlecompute: Deleting instance...
    googlecompute: Instance has been deleted!
==> googlecompute: Creating image...
2018/06/13 10:12:36 ui:     googlecompute: Instance has been deleted!
2018/06/13 10:12:36 ui: ==> googlecompute: Creating image...
==> googlecompute: Deleting disk...
2018/06/13 10:13:02 ui: ==> googlecompute: Deleting disk...
2018/06/13 10:13:05 ui:     googlecompute: Disk has been deleted!
    googlecompute: Disk has been deleted!
2018/06/13 10:13:05 [INFO] (telemetry) ending googlecompute
2018/06/13 10:13:05 ui: Build 'googlecompute' finished.
2018/06/13 10:13:05 Builds completed. Waiting on interrupt barrier...
2018/06/13 10:13:05 ui:
==> Builds finished. The artifacts of successful builds are:
Build 'googlecompute' finished.

==> Builds finished. The artifacts of successful builds are:
2018/06/13 10:13:05 machine readable: googlecompute,artifact-count []string{"1"}
2018/06/13 10:13:05 machine readable: googlecompute,artifact []string{"0", "builder-id", "packer.googlecompute"}
2018/06/13 10:13:05 machine readable: googlecompute,artifact []string{"0", "id", "repro-bug-2018-06-13t15-10-05z"}
2018/06/13 10:13:05 machine readable: googlecompute,artifact []string{"0", "string", "A disk image was created: repro-bug-2018-06-13t15-10-05z"}
2018/06/13 10:13:05 machine readable: googlecompute,artifact []string{"0", "files-count", "0"}
2018/06/13 10:13:05 machine readable: googlecompute,artifact []string{"0", "end"}
2018/06/13 10:13:05 ui: --> googlecompute: A disk image was created: repro-bug-2018-06-13t15-10-05z
--> googlecompute: A disk image was created: repro-bug-2018-06-13t15-10-05z
2018/06/13 10:13:05 [INFO] (telemetry) Finalizing.
2018/06/13 10:13:06 waiting for all plugin processes to complete...
2018/06/13 10:13:06 /Users/matt/bin/packer: plugin process exited
2018/06/13 10:13:06 /Users/matt/bin/packer: plugin process exited