Packer: SSH communicator does not properly connect to all image types via builder-digitalocean
Overview of the Issue
I am trying to use a builder with the mysql-18-04 digitalocean image, i.e. a marketplace image with other software installed after boot. Packer creates the droplet, waits for it to become active, uses the SSH communicator to determine SSH is available, and then fails when trying to SCP the first provision script. I am guessing this is because SSH is not actually available yet, or the image is still doing some on start work, and the retry logic is failing continuously afterwards.
The eventual error I get is Retryable error: Error uploading script: lease wait while we get your droplet ready...
The retry-er goes on indefinitely until packer times out.
The reason I believe this is a timing/SSH not ready issue is because if I run with the debug flag, and pause here:
==> digitalocean.mysql-base: Waiting for droplet to become active...
==> digitalocean.mysql-base: Pausing after run of step 'stepDropletInfo'. Press enter to continue.
for just a few seconds, right before the SSH communicator begins, the build works fine.
Is there a way to pause in between build steps, or some kind of mechanism to wait? pause_before_connecting happens after the SSH communicator starts doing it's thing, so it does not solve my problem.
Note that the exact same build with a different base image ubuntu-20-04-x64 or ubuntu-18-04-x64 works fine.
Reproduction Steps
try to build this file
source "digitalocean" "mysql-base" {
image = "mysql-18-04"
region = "sfo2"
size = "s-1vcpu-1gb"
ssh_username = "root"
snapshot_name = "mysql-base-{{timestamp}}"
}
build {
sources = [
"source.digitalocean.mysql-base"
]
provisioner "shell" {
inline = ["sleep 30"]
}
}
Packer version
Packer v1.6.0
Operating system and Environment details
ubuntu 18.04
Log Fragments and crash.log files
↪ tail -f packer-log248289182
2020/07/22 15:46:01 Running builder:
2020/07/22 15:46:01 [INFO] (telemetry) Starting builder
2020/07/22 15:46:01 ui: ==> digitalocean.mysql-base: Creating temporary ssh key for droplet...
2020/07/22 15:46:02 packer-builder-digitalocean plugin: temporary ssh key name: packer-5f18a58a-799f-509e-d06f-c2a7e9a3dae3
2020/07/22 15:46:02 ui: ==> digitalocean.mysql-base: Creating droplet...
2020/07/22 15:46:02 packer-builder-digitalocean plugin: [DEBUG] Droplet create paramaters: godo.DropletCreateRequest{Name:"packer-5f18a589-fe0f-0443-31a3-08649e4c8e86", Region:"sfo2", Size:"s-1vcpu-1gb",
Image:godo.DropletCreateImage{ID:0, Slug:"mysql-18-04"}, SSHKeys:[godo.DropletCreateSSHKey{ID:27988927, Fingerprint:""}], Backups:false, IPv6:false, PrivateNetworking:false, Monitoring:false, UserData:"",
Tags:[], VPCUUID:""}
2020/07/22 15:46:03 ui: ==> digitalocean.mysql-base: Waiting for droplet to become active...
2020/07/22 15:46:03 packer-builder-digitalocean plugin: Waiting for up to 360 seconds for droplet to become active
2020/07/22 15:46:03 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 1)
2020/07/22 15:46:06 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 2)
2020/07/22 15:46:10 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 3)
2020/07/22 15:46:13 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 4)
2020/07/22 15:46:16 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 5)
2020/07/22 15:46:20 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 6)
2020/07/22 15:46:23 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 7)
2020/07/22 15:46:26 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 8)
2020/07/22 15:46:30 packer-builder-digitalocean plugin: Checking droplet status... (attempt: 9)
2020/07/22 15:46:31 ui: ==> digitalocean.mysql-base: Using ssh communicator to connect: 167.71.121.182
2020/07/22 15:46:31 packer-builder-digitalocean plugin: [INFO] Waiting for SSH, up to timeout: 5m0s
2020/07/22 15:46:31 ui: ==> digitalocean.mysql-base: Waiting for SSH to become available...
2020/07/22 15:46:46 packer-builder-digitalocean plugin: [DEBUG] TCP connection to SSH ip/port failed: dial tcp 167.71.121.182:22: i/o timeout
2020/07/22 15:46:51 packer-builder-digitalocean plugin: [INFO] Attempting SSH connection to 167.71.121.182:22...
2020/07/22 15:46:51 packer-builder-digitalocean plugin: [DEBUG] reconnecting to TCP connection for SSH
2020/07/22 15:46:51 packer-builder-digitalocean plugin: [DEBUG] handshaking with SSH
2020/07/22 15:46:52 packer-builder-digitalocean plugin: [DEBUG] handshake complete!
2020/07/22 15:46:52 packer-builder-digitalocean plugin: [DEBUG] Opening new ssh session
2020/07/22 15:46:54 packer-builder-digitalocean plugin: [INFO] agent forwarding enabled
2020/07/22 15:46:54 ui: ==> digitalocean.mysql-base: Connected to SSH!
2020/07/22 15:46:54 packer-builder-digitalocean plugin: Running the provision hook
2020/07/22 15:46:54 [INFO] (telemetry) Starting provisioner shell
2020/07/22 15:46:54 ui: ==> digitalocean.mysql-base: Provisioning with shell script: /tmp/packer-shell232260377
2020/07/22 15:46:54 packer-provisioner-shell plugin: Opening /tmp/packer-shell232260377 for reading
2020/07/22 15:46:54 packer-provisioner-shell plugin: [INFO] 22 bytes written for 'uploadData'
2020/07/22 15:46:54 [INFO] 22 bytes written for 'uploadData'
2020/07/22 15:46:54 packer-builder-digitalocean plugin: [DEBUG] Opening new ssh session
2020/07/22 15:46:54 packer-builder-digitalocean plugin: [DEBUG] Starting remote scp process: scp -vt /tmp
2020/07/22 15:46:54 packer-builder-digitalocean plugin: [DEBUG] Started SCP session, beginning transfers...
2020/07/22 15:46:54 packer-builder-digitalocean plugin: [DEBUG] Copying input data into temporary file so we can read the length
2020/07/22 15:46:54 packer-builder-digitalocean plugin: [DEBUG] scp: Uploading script_5141.sh: perms=C0644 size=22
2020/07/22 15:46:54 packer-provisioner-shell plugin: Retryable error: Error uploading script: lease wait while we get your droplet ready...
2020/07/22 15:46:56 packer-provisioner-shell plugin: [INFO] 22 bytes written for 'uploadData'
2020/07/22 15:46:56 [INFO] 22 bytes written for 'uploadData'
2020/07/22 15:46:56 packer-builder-digitalocean plugin: [DEBUG] Opening new ssh session
2020/07/22 15:46:56 packer-builder-digitalocean plugin: [DEBUG] Starting remote scp process: scp -vt /tmp
2020/07/22 15:46:56 packer-builder-digitalocean plugin: [DEBUG] Started SCP session, beginning transfers...
2020/07/22 15:46:56 packer-builder-digitalocean plugin: [DEBUG] Copying input data into temporary file so we can read the length
2020/07/22 15:46:56 packer-builder-digitalocean plugin: [DEBUG] scp: Uploading script_5141.sh: perms=C0644 size=22
2020/07/22 15:46:56 packer-provisioner-shell plugin: Retryable error: Error uploading script: lease wait while we get your droplet ready...
whwright
All 10 comments
Hey @whwright thanks for opening; that's kinda weird, because first we see Waiting for Droplet to become active then please wait while we get your droplet ready; isn't it the same thing ? Anyways, here are a few pointers:
try setting
state_timeoutto10m( that's 10 minutes, the default is 6 )try waiting using a local shell:
provisioner "shell-local" {
inline = ["sleep 30"]
}
azr
on 23 Jul 2020
Thanks for the quick response!
Just to clarify, it appears that the droplet becomes available very soon after the provisioning attempts start. When pausing on that step in the debugger for just a few seconds, the build works fine. I was also able to SSH/SCP onto the host perfectly fine while the retryer was failing to do just that, so I don't think the state_timeout is going to help me, but I'll give these a try!
whwright
on 23 Jul 2020
So I changed this to use a local shell wait as suggested, and the next step in my real build is a file provisioner. This also fails, even though I can SSH/SCP onto the host fine in another terminal.
==> digitalocean.mysql-base: Upload failed: lease wait while we get your droplet ready...
maybe the SSH communicator is holding onto a bad connection? I'm going to try to debug this locally if I can find some time
whwright
on 23 Jul 2020
I think pause_before_connecting may actually solve your issue here -- did you try? It does connect, but then disconnects and reconnects so I think it would work in this situation.
SwampDragons
on 23 Jul 2020
I did try a few builds pause_before_connecting
whwright
on 24 Jul 2020
Okay I need to fix pause_before_connecting then because this is exactly the kind of situation it's intended to resolve. I probably won't have a chance until after the 1.6.1 release, but I'll self-assign and schedule for 1.6.2
SwampDragons
on 24 Jul 2020
Hi! I've pushed a small change that should force a reconnect after the pause; can you give it a try and let me know if it solves this issue for you? PR is #9772 and builds of that patch can be found on our CI server at https://circleci.com/gh/hashicorp/packer/74589#artifacts/containers/0
SwampDragons
on 14 Aug 2020
I added pause_before_connecting back to my build, and using the artifact from the link you provided has fixed my problem. Thank you!
whwright
on 17 Aug 2020
Wooooo! 🎉 Thanks for helping me get that fixed up.
SwampDragons
on 17 Aug 2020
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.
![hashibot[bot] picture](https://avatars2.githubusercontent.com/in/8332?v=4&s=40)
hashibot[bot]
on 13 Oct 2020
Related issues
brettswift
·
3Comments
sourav82
·
3Comments
craigsimon
·
3Comments
Nikoos
·
3Comments
znerd
·
3Comments
Most helpful comment
Wooooo! 🎉 Thanks for helping me get that fixed up.