Packer: Packer 1.5.2 "Error unquoting identity file: invalid syntax" in Vagrant/Virtualbox provider

Created on 13 Feb 2020  ยท  8Comments  ยท  Source: hashicorp/packer

Overview of the Issue

I upgraded packer to 1.5.2 this afternoon and started getting an error in my vagrant build related to "unquoting identity file".

I'm able to abort the cleanup and leave the box running. I'm able to successfully SSH to the box with vagrant ssh. I've tried wiping my ~/.vagrant.d folder and starting over with new keys, but to no avail. I'm going to try to step down my versions until I get back to what I had before and also to see where it started happening, but I'm fighting with homebrew trying to figure out how to do that. I'll update the issue if I can figure it out.

Reproduction Steps

Build a simple vagrant box using virtualbox provider. I'm not sure the source_path matters as the error seems to happen before it actually tries to SSH to the box.

Packer version

1.5.2

Simplified Packer Buildfile

{
  "builders": [
    {
      "box_name": "my-box-name",
      "type": "vagrant",
      "provider": "virtualbox",
      "source_path": "ubuntu/bionic64",
      "output_dir": "build/vagrant",
      "communicator": "ssh"
    }
  ]
}

Operating system and Environment details

Mac OS X (Catalina)
Vagrant 2.2.7
Virtualbox 6.1.2 r135662

Log Fragments and crash.log files

2020/02/13 14:32:32 packer-builder-vagrant plugin: Calling Vagrant CLI: []string{"ssh-config", "source"}
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout: Host source
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   HostName 127.0.0.1
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   User vagrant
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   Port 2200
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   UserKnownHostsFile /dev/null
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   StrictHostKeyChecking no
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   PasswordAuthentication no
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   IdentityFile /Users/joe/.vagrant.d/insecure_private_key
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   IdentitiesOnly yes
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:   LogLevel FATAL
2020/02/13 14:32:34 packer-builder-vagrant plugin: [vagrant driver] stdout:
2020/02/13 14:32:34 packer-builder-vagrant plugin: identity file is /Users/joe/.vagrant.d/insecure_private_key
2020/02/13 14:32:34 packer-builder-vagrant plugin: Removing quotes from identity file
2020/02/13 14:32:34 packer-builder-vagrant plugin: Error unquoting identity file: invalid syntax
==> vagrant: Using ssh communicator to connect: 127.0.0.1
2020/02/13 14:32:34 packer-builder-vagrant plugin: [INFO] Waiting for SSH, up to timeout: 10m0s
==> vagrant: Waiting for SSH to become available...
2020/02/13 14:32:34 packer-builder-vagrant plugin: [INFO] Attempting SSH connection to 127.0.0.1:2200...
2020/02/13 14:32:34 packer-builder-vagrant plugin: [DEBUG] reconnecting to TCP connection for SSH
2020/02/13 14:32:34 packer-builder-vagrant plugin: [DEBUG] handshaking with SSH
2020/02/13 14:32:34 packer-builder-vagrant plugin: [DEBUG] SSH handshake err: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none], no supported methods remain
2020/02/13 14:32:34 packer-builder-vagrant plugin: [DEBUG] Detected authentication error. Increasing handshake attempts.
==> vagrant: Error waiting for SSH: Packer experienced an authentication error when trying to connect via SSH. This can happen if your username/password are wrong. You may want to double-check your credentials as part of your debugging process. original error: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none], no supported methods remain
==> vagrant: Packer experienced an authentication error when trying to connect via SSH. This can happen if your username/password are wrong. You may want to double-check your credentials as part of your debugging process. original error: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none], no supported methods remain
==> vagrant: Step "StepConnect" failed

Thanks

bug buildevagrant regression

Most helpful comment

I think the problem is due to this change. When the code parses the line for IdentityFile in the SSH config (in the case of the Vagrant builder, the output of running vagrant ssh-config), the Packer code now filters the value through strconv.Unquote. However, the documentation for strconv.Unquote says that if its input isn't quoted, that results in an error (expand the "Example" section to see what I mean).

All 8 comments

I stepped down to 1.5.1 and confirmed that the error does not happen with that version. For fun, I removed homebrew out of the equation and downloaded 1.5.2 directly from the primary link and the issue was still present.

Thanks, I'll try to take a look at this when I get a chance.

I can confirm this is happening to me as well on 1.5.4.

2020/02/20 13:44:42 [INFO] Packer version: 1.5.4 [go1.13.8 darwin amd64]
2020/02/20 13:44:42 Checking 'PACKER_CONFIG' for a config file path
2020/02/20 13:44:42 'PACKER_CONFIG' not set; checking the default config file path
2020/02/20 13:44:42 Attempting to open config file: /Users/tj/.packerconfig
2020/02/20 13:44:42 [WARN] Config file doesn't exist: /Users/tj/.packerconfig
2020/02/20 13:44:42 Setting cache directory: /Users/tj/git/Work/LevelUp/build-ami/packer_cache
2020/02/20 13:44:42 Creating plugin client for path: /usr/local/bin/packer
2020/02/20 13:44:42 Starting plugin: /usr/local/bin/packer []string{"/usr/local/bin/packer", "plugin", "packer-builder-vagrant"}
2020/02/20 13:44:42 Waiting for RPC address for: /usr/local/bin/packer
2020/02/20 13:44:42 packer-builder-vagrant plugin: [INFO] Packer version: 1.5.4 [go1.13.8 darwin amd64]
2020/02/20 13:44:42 packer-builder-vagrant plugin: Checking 'PACKER_CONFIG' for a config file path
2020/02/20 13:44:42 packer-builder-vagrant plugin: 'PACKER_CONFIG' not set; checking the default config file path
2020/02/20 13:44:42 packer-builder-vagrant plugin: Attempting to open config file: /Users/tj/.packerconfig
2020/02/20 13:44:42 packer-builder-vagrant plugin: [WARN] Config file doesn't exist: /Users/tj/.packerconfig
2020/02/20 13:44:42 packer-builder-vagrant plugin: Setting cache directory: /Users/tj/git/Work/LevelUp/build-ami/packer_cache
2020/02/20 13:44:42 packer-builder-vagrant plugin: args: []string{"packer-builder-vagrant"}
2020/02/20 13:44:42 packer-builder-vagrant plugin: Plugin address: unix /var/folders/nn/n057j5q14qq7z40ct2v708zw0000gn/T/packer-plugin767268709
2020/02/20 13:44:42 packer-builder-vagrant plugin: Waiting for connection...
2020/02/20 13:44:42 Received unix RPC address for /usr/local/bin/packer: addr is /var/folders/nn/n057j5q14qq7z40ct2v708zw0000gn/T/packer-plugin767268709
2020/02/20 13:44:42 packer-builder-vagrant plugin: Serving a plugin connection...
2020/02/20 13:44:42 Creating plugin client for path: /usr/local/bin/packer
2020/02/20 13:44:42 Starting plugin: /usr/local/bin/packer []string{"/usr/local/bin/packer", "plugin", "packer-provisioner-ansible"}
2020/02/20 13:44:42 Waiting for RPC address for: /usr/local/bin/packer
2020/02/20 13:44:42 packer-provisioner-ansible plugin: [INFO] Packer version: 1.5.4 [go1.13.8 darwin amd64]
2020/02/20 13:44:42 packer-provisioner-ansible plugin: Checking 'PACKER_CONFIG' for a config file path
2020/02/20 13:44:42 packer-provisioner-ansible plugin: 'PACKER_CONFIG' not set; checking the default config file path
2020/02/20 13:44:42 packer-provisioner-ansible plugin: Attempting to open config file: /Users/tj/.packerconfig
2020/02/20 13:44:42 packer-provisioner-ansible plugin: [WARN] Config file doesn't exist: /Users/tj/.packerconfig
2020/02/20 13:44:42 packer-provisioner-ansible plugin: Setting cache directory: /Users/tj/git/Work/LevelUp/build-ami/packer_cache
2020/02/20 13:44:42 packer-provisioner-ansible plugin: args: []string{"packer-provisioner-ansible"}
2020/02/20 13:44:42 packer-provisioner-ansible plugin: Plugin address: unix /var/folders/nn/n057j5q14qq7z40ct2v708zw0000gn/T/packer-plugin847649441
2020/02/20 13:44:42 Received unix RPC address for /usr/local/bin/packer: addr is /var/folders/nn/n057j5q14qq7z40ct2v708zw0000gn/T/packer-plugin847649441
2020/02/20 13:44:42 packer-provisioner-ansible plugin: Waiting for connection...
2020/02/20 13:44:42 packer-provisioner-ansible plugin: Serving a plugin connection...
2020/02/20 13:44:42 Build debug mode: true
2020/02/20 13:44:42 Force build: true
2020/02/20 13:44:42 On error:
2020/02/20 13:44:42 Preparing build: vagrant
Debug mode enabled. Builds will not be parallelized.
vagrant: output will be in this color.

2020/02/20 13:44:42 packer-provisioner-ansible plugin: ansible-playbook version: 2.9.4
2020/02/20 13:44:42 Debug enabled, so waiting for build to finish: vagrant
2020/02/20 13:44:42 Starting build run: vagrant
2020/02/20 13:44:42 Running builder: vagrant
2020/02/20 13:44:42 [INFO] (telemetry) Starting builder vagrant
2020/02/20 13:44:42 packer-builder-vagrant plugin: Calling Vagrant CLI: []string{"--version"}
2020/02/20 13:44:42 packer-builder-vagrant plugin: [vagrant driver] stdout: Vagrant 2.2.7
==> vagrant: Pausing after run of step 'StepOutputDir'. Press enter to continue.
==> vagrant: Creating a Vagrantfile in the build directory...
2020/02/20 13:44:46 packer-builder-vagrant plugin: Created vagrantfile at /Users/tj/git/Work/LevelUp/build-ami/output-vagrant/Vagrantfile
==> vagrant: Pausing after run of step 'StepCreateVagrantfile'. Press enter to continue.
==> vagrant: skip_add was set so we assume the box is already in Vagrant...
==> vagrant: Pausing after run of step 'StepAddBox'. Press enter to continue.
==> vagrant: Calling Vagrant Up (this can take some time)...
2020/02/20 13:44:48 packer-builder-vagrant plugin: Calling Vagrant CLI: []string{"up", "source", "--provider=virtualbox"}
2020/02/20 13:44:50 packer-builder-vagrant plugin: [vagrant driver] stdout: Bringing machine 'source' up with 'virtualbox' provider...
2020/02/20 13:44:50 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Importing base box 'generic/rhel7'...
2020/02/20 13:44:52 packer-builder-vagrant plugin: [vagrant driver] stdout:
2020/02/20 13:44:52 packer-builder-vagrant plugin: [vagrant driver] stdout: Progress: 10%
2020/02/20 13:44:52 packer-builder-vagrant plugin: [vagrant driver] stdout: Progress: 20%
2020/02/20 13:44:54 packer-builder-vagrant plugin: [vagrant driver] stdout: Progress: 30%
2020/02/20 13:44:54 packer-builder-vagrant plugin: [vagrant driver] stdout: Progress: 50%
2020/02/20 13:44:55 packer-builder-vagrant plugin: [vagrant driver] stdout: Progress: 70%
2020/02/20 13:44:56 packer-builder-vagrant plugin: [vagrant driver] stdout: Progress: 90%
2020/02/20 13:44:56 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Matching MAC address for NAT networking...
2020/02/20 13:44:56 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Checking if box 'generic/rhel7' version '2.0.6' is up to date...
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Setting the name of the VM: output-vagrant_source_1582242297256_19588
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Fixed port collision for 22 => 2222. Now on port 2200.
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Clearing any previously set network interfaces...
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Preparing network interfaces based on configuration...
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: Adapter 1: nat
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Forwarding ports...
2020/02/20 13:44:57 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: 22 (guest) => 2200 (host) (adapter 1)
2020/02/20 13:44:58 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Running 'pre-boot' VM customizations...
2020/02/20 13:44:58 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Booting VM...
2020/02/20 13:44:58 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Waiting for machine to boot. This may take a few minutes...
2020/02/20 13:44:59 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: SSH address: 127.0.0.1:2200
2020/02/20 13:44:59 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: SSH username: vagrant
2020/02/20 13:44:59 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: SSH auth method: private key
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Machine booted and ready!
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout: ==> source: Checking for guest additions in VM...
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: The guest additions on this VM do not match the installed version of
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: VirtualBox! In most cases this is fine, but in rare cases it can
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: prevent things such as shared folders from working properly. If you see
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: shared folder errors, please make sure the guest additions within the
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: virtual machine match the version of VirtualBox you have installed on
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: your host and reload your VM.
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source:
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: Guest Additions Version: 5.2.34
2020/02/20 13:45:16 packer-builder-vagrant plugin: [vagrant driver] stdout:     source: VirtualBox Version: 6.1
==> vagrant: Pausing after run of step 'StepUp'. Press enter to continue.
2020/02/20 13:45:45 packer-builder-vagrant plugin: Calling Vagrant CLI: []string{"ssh-config", "source"}
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout: Host source
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   HostName 127.0.0.1
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   User vagrant
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   Port 2200
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   UserKnownHostsFile /dev/null
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   StrictHostKeyChecking no
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   PasswordAuthentication no
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   IdentityFile /Users/tj/.vagrant.d/insecure_private_key
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   IdentitiesOnly yes
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:   LogLevel FATAL
2020/02/20 13:45:47 packer-builder-vagrant plugin: [vagrant driver] stdout:
2020/02/20 13:45:47 packer-builder-vagrant plugin: identity file is /Users/tj/.vagrant.d/insecure_private_key
2020/02/20 13:45:47 packer-builder-vagrant plugin: Removing quotes from identity file
2020/02/20 13:45:47 packer-builder-vagrant plugin: Error unquoting identity file: invalid syntax

==> vagrant: Pausing after run of step 'StepSSHConfig'. Press enter to continue. ==> vagrant: Using ssh communicator to connect: 127.0.0.1
2020/02/20 13:45:47 packer-builder-vagrant plugin: [INFO] Waiting for SSH, up to timeout: 10m0s
==> vagrant: Waiting for SSH to become available...
2020/02/20 13:45:47 packer-builder-vagrant plugin: [INFO] Attempting SSH connection to 127.0.0.1:2200...
2020/02/20 13:45:47 packer-builder-vagrant plugin: [DEBUG] reconnecting to TCP connection for SSH
2020/02/20 13:45:47 packer-builder-vagrant plugin: [DEBUG] handshaking with SSH
2020/02/20 13:45:47 packer-builder-vagrant plugin: [DEBUG] SSH handshake err: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none], no supported methods remain
2020/02/20 13:45:47 packer-builder-vagrant plugin: [DEBUG] Detected authentication error. Increasing handshake attempts.

For those who want to downgrade, it appears that Brew only has the newest version available and Packer's website only lists a download link for the most current version. But the URL can be manually changed to grab the binary.

https://releases.hashicorp.com/packer/1.5.1/packer_1.5.1_darwin_amd64.zip

I think the problem is due to this change. When the code parses the line for IdentityFile in the SSH config (in the case of the Vagrant builder, the output of running vagrant ssh-config), the Packer code now filters the value through strconv.Unquote. However, the documentation for strconv.Unquote says that if its input isn't quoted, that results in an error (expand the "Example" section to see what I mean).

Thanks for tracking this down! Do you want to make a pull request to fix it, or would you rather I did?

I'm going to lock this issue because it has been closed for _30 days_ โณ. This helps our maintainers find and focus on the active issues.

If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

Was this page helpful?
0 / 5 - 0 ratings