Machine: docker-machine very slow and timing out with ec2

Created on 18 Dec 2016  路  22Comments  路  Source: docker/machine

Using docker-machine 0.9.0-rc2 with the amazonec2 driver is very slow and docker-machine ls always times out for that host. Commands like docker-machine env ... are generally taking around 25 seconds.

I think this could be related to using the eu-west-1 region? But I haven't tried creating a host in another region.

This is consistently the case and slow enough to make docker-machine fairly annoying to use.

Once I've configured my shell to connect to that host everything is nice and quick.

I had to move to the rc version of docker-machine as the stable version failed to connect to hosts on ec2, i think related to #3930.

~ || time docker-machine ls
NAME             ACTIVE   DRIVER       STATE     URL   SWARM   DOCKER    ERRORS
docker-postfix            amazonec2    Timeout                           
foobar           -        virtualbox   Stopped                 Unknown   

real    0m10.043s
user    0m0.020s
sys 0m0.000s
~ || time docker-machine status docker-postfix
Running

real    0m12.216s
user    0m0.012s
sys 0m0.008s
~ || time docker-machine env docker-postfix
export DOCKER_TLS_VERIFY="1"
export DOCKER_HOST="tcp://***:2376"
export DOCKER_CERT_PATH="/home/samuel/.docker/machine/machines/docker-postfix"
export DOCKER_MACHINE_NAME="docker-postfix"
export DOCKER_API_VERSION="1.24"
# Run this command to configure your shell: 
# eval $(docker-machine env docker-postfix)

real    0m24.370s
user    0m0.064s
sys 0m0.012s
~ || time docker-machine ssh docker-postfix whoami
ubuntu

real    0m24.985s
user    0m0.020s
sys 0m0.016s
~ || docker-machine inspect docker-postfix
{
    "ConfigVersion": 3,
    "Driver": {
        "IPAddress": "***",
        "MachineName": "docker-postfix",
        "SSHUser": "ubuntu",
        "SSHPort": 22,
        "SSHKeyPath": "/home/samuel/.docker/machine/machines/docker-postfix/id_rsa",
        "StorePath": "/home/samuel/.docker/machine",
        "SwarmMaster": false,
        "SwarmHost": "tcp://0.0.0.0:3376",
        "SwarmDiscovery": "",
        "Id": "***",
        "AccessKey": "***",
        "SecretKey": "***",
        "SessionToken": "",
        "Region": "eu-west-1",
        "AMI": "ami-c593deb6",
        "SSHKeyID": 0,
        "ExistingKey": false,
        "KeyName": "docker-postfix",
        "InstanceId": "i-***",
        "InstanceType": "t2.nano",
        "PrivateIPAddress": "***",
        "SecurityGroupId": "",
        "SecurityGroupIds": [
            "sg-***"
        ],
        "SecurityGroupName": "",
        "SecurityGroupNames": [
            "docker-machine"
        ],
        "OpenPorts": null,
        "Tags": "",
        "ReservationId": "",
        "DeviceName": "/dev/sda1",
        "RootSize": 8,
        "VolumeType": "gp2",
        "IamInstanceProfile": "docker-postfix-profile",
        "VpcId": "vpc-***",
        "SubnetId": "subnet-***",
        "Zone": "a",
        "RequestSpotInstance": false,
        "SpotPrice": "0.50",
        "BlockDurationMinutes": 0,
        "PrivateIPOnly": false,
        "UsePrivateIP": false,
        "UseEbsOptimizedInstance": false,
        "Monitoring": false,
        "SSHPrivateKeyPath": "",
        "RetryCount": 5,
        "Endpoint": "",
        "DisableSSL": false,
        "UserDataFile": ""
    },
    "DriverName": "amazonec2",
    "HostOptions": {
        "Driver": "",
        "Memory": 0,
        "Disk": 0,
        "EngineOptions": {
            "ArbitraryFlags": [],
            "Dns": null,
            "GraphDir": "",
            "Env": [],
            "Ipv6": false,
            "InsecureRegistry": [],
            "Labels": [],
            "LogLevel": "",
            "StorageDriver": "",
            "SelinuxEnabled": false,
            "TlsVerify": true,
            "RegistryMirror": [],
            "InstallURL": "https://get.docker.com"
        },
        "SwarmOptions": {
            "IsSwarm": false,
            "Address": "",
            "Discovery": "",
            "Agent": false,
            "Master": false,
            "Host": "tcp://0.0.0.0:3376",
            "Image": "swarm:latest",
            "Strategy": "spread",
            "Heartbeat": 0,
            "Overcommit": 0,
            "ArbitraryFlags": [],
            "ArbitraryJoinFlags": [],
            "Env": null,
            "IsExperimental": false
        },
        "AuthOptions": {
            "CertDir": "/home/samuel/.docker/machine/certs",
            "CaCertPath": "/home/samuel/.docker/machine/certs/ca.pem",
            "CaPrivateKeyPath": "/home/samuel/.docker/machine/certs/ca-key.pem",
            "CaCertRemotePath": "",
            "ServerCertPath": "/home/samuel/.docker/machine/machines/docker-postfix/server.pem",
            "ServerKeyPath": "/home/samuel/.docker/machine/machines/docker-postfix/server-key.pem",
            "ClientKeyPath": "/home/samuel/.docker/machine/certs/key.pem",
            "ServerCertRemotePath": "",
            "ServerKeyRemotePath": "",
            "ClientCertPath": "/home/samuel/.docker/machine/certs/cert.pem",
            "ServerCertSANs": [],
            "StorePath": "/home/samuel/.docker/machine/machines/docker-postfix"
        }
    },
    "Name": "docker-postfix"
}
~ || docker-machine -v
docker-machine version 0.9.0-rc2, build 7b19591

The host was created with this script.

picture samuelcolvin
👍4

Most helpful comment

Ok, I've at last got somewhere with this problem.

It was because I didn't have the aws credential env variables exported and ~/.aws/credentials had two profiles personal and work, eg. no default profile.

I was able to stop the slowness and timeouts by renaming the "personal" profile to "default".

Still not sure what's going on to cause the delay rather than just a failure, but at least for me this problem is avoided. Is this a problem with machine or with the aws-go library?

picture samuelcolvin on 20 Aug 2017
👍3

All 22 comments

answering here to follow up with @dberchtold ... I did not experience slowness/timeouts yet.

fredbt picture fredbt on 19 Dec 2016

Ok tried now and this seems to be an intermittent problem. Sometimes ls doesn't timeout and env takes 0.5s, sometimes I get the 25s delay and ls shows timeout.

Right now it's working, half an hour ago it was timing out, an hour before that it was working....

samuelcolvin picture samuelcolvin on 20 Dec 2016

I'm facing similar issue with ec2 in us-east-1 zone d.

huntrahul picture huntrahul on 31 Dec 2016
👍1

Now I'm having this issue:

eval $(docker-machine env machinename)
Error checking TLS connection: Error checking and/or regenerating the certs: There was an error validating certificates for host "54.242.235.171:2376": dial tcp 54.242.235.171:2376: i/o timeout
You can attempt to regenerate them using 'docker-machine regenerate-certs [name]'.
Be advised that this will trigger a Docker daemon restart which might stop running containers.

The issue persists even if I regenerate the certs.

docker-machine regenerate-certs machinename

Regenerate TLS machine certs? Warning: this is irreversible. (y/n): y
Regenerating TLS certificates
Waiting for SSH to be available...
Detecting the provisioner...
Installing Docker...
Copying certs to the local machine directory...
Copying certs to the remote machine...
Setting Docker configuration on the remote daemon...

eval $(docker-machine env prodbt)
Error checking TLS connection: Error checking and/or regenerating the certs: There was an error validating certificates for host "54.242.235.171:2376": dial tcp 54.242.235.171:2376: i/o timeout
You can attempt to regenerate them using 'docker-machine regenerate-certs [name]'.
Be advised that this will trigger a Docker daemon restart which might stop running containers.

fredbt picture fredbt on 2 Jan 2017

My bad. In my case, it was a misconfiguration in the inbond rules of our security group for 2376 (I'm working from home during the holidays!).

fredbt picture fredbt on 2 Jan 2017

+1 on this, it's painfully slow (10+ min to launch a single m4.xlarge instance). DigitalOcean instances are ready within 2 minutes, even small ones.

jloisel picture jloisel on 5 Jan 2017

Perhaps this is document somewhere and I haven't seen it, but could someone explain what machine is doing for 25 seconds?

(not being negative, just some explanation would be interesting)

samuelcolvin picture samuelcolvin on 5 Jan 2017

Waiting for the AWS instance to be running and for SSH to be available.

Edit: Oops, mis-read. Hard to say what would be causing a timeout but usually it's due to something (e.g., SSH on the machine or Docker port, which might happen if Docker itself crashes) not responding in time -- docker-machine --debug output would be helpful here

nathanleclaire picture nathanleclaire on 5 Jan 2017

it can't be, in my examples above the instance is already running with ssh enabled.

samuelcolvin picture samuelcolvin on 5 Jan 2017

Yup, I mis-read the thread context -- see above

nathanleclaire picture nathanleclaire on 5 Jan 2017

See below, it looks like some requests to AWS are taking 12 seconds.

Surely there must be something specific to this situation? AWS can't aways be that slow for these types of request.

~ || time machine --debug env docker-postfix 2>&1 | ts '[%H:%M:%S]'
[20:20:06] Docker Machine Version:  0.9.0-rc2, build 7b19591
[20:20:06] Found binary path at /usr/local/bin/docker-machine
[20:20:06] Launching plugin server for driver amazonec2
[20:20:06] Plugin server listening at address 127.0.0.1:37652
[20:20:06] () Calling .GetVersion
[20:20:06] Using API Version  1
[20:20:06] () Calling .SetConfigRaw
[20:20:06] () Calling .GetMachineName
[20:20:06] (docker-postfix) Calling .GetURL
[20:20:18] (docker-postfix) DBG | 2017/01/05 20:20:18 DEBUG: Request ec2/DescribeInstances Details:
[20:20:18] (docker-postfix) DBG | ---[ REQUEST POST-SIGN ]-----------------------------
[20:20:18] (docker-postfix) DBG | POST / HTTP/1.1
[20:20:18] (docker-postfix) DBG | Host: ec2.eu-west-1.amazonaws.com
[20:20:18] (docker-postfix) DBG | User-Agent: aws-sdk-go/1.4.10 (go1.7.3; linux; amd64)
[20:20:18] (docker-postfix) DBG | Content-Length: 67
[20:20:18] (docker-postfix) DBG | Authorization: AWS4-HMAC-SHA256 Credential=XXX
[20:20:18] (docker-postfix) DBG | Content-Type: application/x-www-form-urlencoded; charset=utf-8
[20:20:18] (docker-postfix) DBG | X-Amz-Date: 20170105T202018Z
[20:20:18] (docker-postfix) DBG | Accept-Encoding: gzip
[20:20:18] (docker-postfix) DBG |
[20:20:18] (docker-postfix) DBG | Action=DescribeInstances&InstanceId.1=i-ed9da705&Version=2016-04-01
[20:20:18] (docker-postfix) DBG | -----------------------------------------------------
[20:20:18] (docker-postfix) DBG | 2017/01/05 20:20:18 DEBUG: Response ec2/DescribeInstances Details:
[20:20:18] (docker-postfix) DBG | ---[ RESPONSE ]--------------------------------------
[20:20:18] (docker-postfix) DBG | HTTP/1.1 200 OK
[20:20:18] (docker-postfix) DBG | Transfer-Encoding: chunked
[20:20:18] (docker-postfix) DBG | Content-Type: text/xml;charset=UTF-8
[20:20:18] (docker-postfix) DBG | Date: Thu, 05 Jan 2017 20:20:17 GMT
[20:20:18] (docker-postfix) DBG | Server: AmazonEC2
[20:20:18] (docker-postfix) DBG | Vary: Accept-Encoding
[20:20:18] (docker-postfix) DBG |
[20:20:18] (docker-postfix) DBG | 186a
[20:20:18] (docker-postfix) DBG | <?xml version="1.0" encoding="UTF-8"?>
[20:20:18] (docker-postfix) DBG | <DescribeInstancesResponse xmlns="http://ec2.amazonaws.com/doc/2016-04-01/">
[20:20:18] (docker-postfix) DBG |     <requestId>2f10b482-9e2a-42d6-8274-ade6ecc45995</requestId>
[20:20:18] (docker-postfix) DBG |     <reservationSet>
[20:20:18] (docker-postfix) DBG |         <item>
[20:20:18] (docker-postfix) DBG |             <reservationId>r-0160a889</reservationId>
[20:20:18] (docker-postfix) DBG |             <ownerId>768427182047</ownerId>
[20:20:18] (docker-postfix) DBG |             <groupSet/>
[20:20:18] (docker-postfix) DBG |             <instancesSet>
[20:20:18] (docker-postfix) DBG |                 <item>
[20:20:18] (docker-postfix) DBG |                     <instanceId>i-ed9da705</instanceId>
[20:20:18] (docker-postfix) DBG |                     <imageId>ami-c593deb6</imageId>
[20:20:18] (docker-postfix) DBG |                     <instanceState>
[20:20:18] (docker-postfix) DBG |                         <code>16</code>
[20:20:18] (docker-postfix) DBG |                         <name>running</name>
[20:20:18] (docker-postfix) DBG |                     </instanceState>
[20:20:18] (docker-postfix) DBG |                     <privateDnsName>ip-XXX.eu-west-1.compute.internal</privateDnsName>
[20:20:18] (docker-postfix) DBG |                     <dnsName>ec2-XXX.eu-west-1.compute.amazonaws.com</dnsName>
[20:20:18] (docker-postfix) DBG |                     <reason/>
[20:20:18] (docker-postfix) DBG |                     <keyName>docker-postfix</keyName>
[20:20:18] (docker-postfix) DBG |                     <amiLaunchIndex>0</amiLaunchIndex>
[20:20:18] (docker-postfix) DBG |                     <productCodes/>
[20:20:18] (docker-postfix) DBG |                     <instanceType>t2.nano</instanceType>
[20:20:18] (docker-postfix) DBG |                     <launchTime>2016-12-12T11:42:25.000Z</launchTime>
[20:20:18] (docker-postfix) DBG |                     <placement>
[20:20:18] (docker-postfix) DBG |                         <availabilityZone>eu-west-1a</availabilityZone>
[20:20:18] (docker-postfix) DBG |                         <groupName/>
[20:20:18] (docker-postfix) DBG |                         <tenancy>default</tenancy>
[20:20:18] (docker-postfix) DBG |                     </placement>
[20:20:18] (docker-postfix) DBG |                     <monitoring>
[20:20:18] (docker-postfix) DBG |                         <state>disabled</state>
[20:20:18] (docker-postfix) DBG |                     </monitoring>
[20:20:18] (docker-postfix) DBG |                     <subnetId>subnet-40349424</subnetId>
[20:20:18] (docker-postfix) DBG |                     <vpcId>vpc-71d92315</vpcId>
[20:20:18] (docker-postfix) DBG |                     <privateIpAddress>XXX</privateIpAddress>
[20:20:18] (docker-postfix) DBG |                     <ipAddress>XXX</ipAddress>
[20:20:18] (docker-postfix) DBG |                     <sourceDestCheck>true</sourceDestCheck>
[20:20:18] (docker-postfix) DBG |                     <groupSet>
[20:20:18] (docker-postfix) DBG |                         <item>
[20:20:18] (docker-postfix) DBG |                             <groupId>sg-37af3d51</groupId>
[20:20:18] (docker-postfix) DBG |                             <groupName>docker-machine</groupName>
[20:20:18] (docker-postfix) DBG |                         </item>
[20:20:18] (docker-postfix) DBG |                     </groupSet>
[20:20:18] (docker-postfix) DBG |                     <architecture>x86_64</architecture>
[20:20:18] (docker-postfix) DBG |                     <rootDeviceType>ebs</rootDeviceType>
[20:20:18] (docker-postfix) DBG |                     <rootDeviceName>/dev/sda1</rootDeviceName>
[20:20:18] (docker-postfix) DBG |                     <blockDeviceMapping>
[20:20:18] (docker-postfix) DBG |                         <item>
[20:20:18] (docker-postfix) DBG |                             <deviceName>/dev/sda1</deviceName>
[20:20:18] (docker-postfix) DBG |                             <ebs>
[20:20:18] (docker-postfix) DBG |                                 <volumeId>vol-30a2ddb2</volumeId>
[20:20:18] (docker-postfix) DBG |                                 <status>attached</status>
[20:20:18] (docker-postfix) DBG |                                 <attachTime>2016-12-12T11:42:26.000Z</attachTime>
[20:20:18] (docker-postfix) DBG |                                 <deleteOnTermination>true</deleteOnTermination>
[20:20:18] (docker-postfix) DBG |                             </ebs>
[20:20:18] (docker-postfix) DBG |                         </item>
[20:20:18] (docker-postfix) DBG |                     </blockDeviceMapping>
[20:20:18] (docker-postfix) DBG |                     <virtualizationType>hvm</virtualizationType>
[20:20:18] (docker-postfix) DBG |                     <clientToken/>
[20:20:18] (docker-postfix) DBG |                     <tagSet>
[20:20:18] (docker-postfix) DBG |                         <item>
[20:20:18] (docker-postfix) DBG |                             <key>Name</key>
[20:20:18] (docker-postfix) DBG |                             <value>docker-postfix</value>
[20:20:18] (docker-postfix) DBG |                         </item>
[20:20:18] (docker-postfix) DBG |                     </tagSet>
[20:20:18] (docker-postfix) DBG |                     <hypervisor>xen</hypervisor>
[20:20:18] (docker-postfix) DBG |                     <networkInterfaceSet>
[20:20:18] (docker-postfix) DBG |                         <item>
[20:20:18] (docker-postfix) DBG |                             <networkInterfaceId>eni-dbb2efa6</networkInterfaceId>
[20:20:18] (docker-postfix) DBG |                             <subnetId>subnet-40349424</subnetId>
[20:20:18] (docker-postfix) DBG |                             <vpcId>vpc-71d92315</vpcId>
[20:20:18] (docker-postfix) DBG |                             <description/>
[20:20:18] (docker-postfix) DBG |                             <ownerId>768427182047</ownerId>
[20:20:18] (docker-postfix) DBG |                             <status>in-use</status>
[20:20:18] (docker-postfix) DBG |                             <macAddress>02:bd:95:64:50:0f</macAddress>
[20:20:18] (docker-postfix) DBG |                             <privateIpAddress>XXX</privateIpAddress>
[20:20:18] (docker-postfix) DBG |                             <privateDnsName>ip-XXX.eu-west-1.compute.internal</privateDnsName>
[20:20:18] (docker-postfix) DBG |                             <sourceDestCheck>true</sourceDestCheck>
[20:20:18] (docker-postfix) DBG |                             <groupSet>
[20:20:18] (docker-postfix) DBG |                                 <item>
[20:20:18] (docker-postfix) DBG |                                     <groupId>sg-37af3d51</groupId>
[20:20:18] (docker-postfix) DBG |                                     <groupName>docker-machine</groupName>
[20:20:18] (docker-postfix) DBG |                                 </item>
[20:20:18] (docker-postfix) DBG |                             </groupSet>
[20:20:18] (docker-postfix) DBG |                             <attachment>
[20:20:18] (docker-postfix) DBG |                                 <attachmentId>eni-attach-69bfe8e6</attachmentId>
[20:20:18] (docker-postfix) DBG |                                 <deviceIndex>0</deviceIndex>
[20:20:18] (docker-postfix) DBG |                                 <status>attached</status>
[20:20:18] (docker-postfix) DBG |                                 <attachTime>2016-12-12T11:42:25.000Z</attachTime>
[20:20:18] (docker-postfix) DBG |                                 <deleteOnTermination>true</deleteOnTermination>
[20:20:18] (docker-postfix) DBG |                             </attachment>
[20:20:18] (docker-postfix) DBG |                             <association>
[20:20:18] (docker-postfix) DBG |                                 <publicIp>XXX</publicIp>
[20:20:18] (docker-postfix) DBG |                                 <publicDnsName>ec2-XXX.eu-west-1.compute.amazonaws.com</publicDnsName>
[20:20:18] (docker-postfix) DBG |                                 <ipOwnerId>768427182047</ipOwnerId>
[20:20:18] (docker-postfix) DBG |                             </association>
[20:20:18] (docker-postfix) DBG |                             <privateIpAddressesSet>
[20:20:18] (docker-postfix) DBG |                                 <item>
[20:20:18] (docker-postfix) DBG |                                     <privateIpAddress>XXX</privateIpAddress>
[20:20:18] (docker-postfix) DBG |                                     <privateDnsName>ip-XXX.eu-west-1.compute.internal</privateDnsName>
[20:20:18] (docker-postfix) DBG |                                     <primary>true</primary>
[20:20:18] (docker-postfix) DBG |                                     <association>
[20:20:18] (docker-postfix) DBG |                                     <publicIp>XXX</publicIp>
[20:20:18] (docker-postfix) DBG |                                     <publicDnsName>ec2-XXX.eu-west-1.compute.amazonaws.com</publicDnsName>
[20:20:18] (docker-postfix) DBG |                                     <ipOwnerId>768427182047</ipOwnerId>
[20:20:18] (docker-postfix) DBG |                                     </association>
[20:20:18] (docker-postfix) DBG |                                 </item>
[20:20:18] (docker-postfix) DBG |                             </privateIpAddressesSet>
[20:20:18] (docker-postfix) DBG |                         </item>
[20:20:18] (docker-postfix) DBG |                     </networkInterfaceSet>
[20:20:18] (docker-postfix) DBG |                     <iamInstanceProfile>
[20:20:18] (docker-postfix) DBG |                         <arn>arn:aws:iam::768427182047:instance-profile/docker-postfix-profile</arn>
[20:20:18] (docker-postfix) DBG |                         <id>XXX</id>
[20:20:18] (docker-postfix) DBG |                     </iamInstanceProfile>
[20:20:18] (docker-postfix) DBG |                     <ebsOptimized>false</ebsOptimized>
[20:20:18] (docker-postfix) DBG |                 </item>
[20:20:18] (docker-postfix) DBG |             </instancesSet>
[20:20:18] (docker-postfix) DBG |         </item>
[20:20:18] (docker-postfix) DBG |     </reservationSet>
[20:20:18] (docker-postfix) DBG | </DescribeInstancesResponse>
[20:20:18] (docker-postfix) DBG | 0
[20:20:18] (docker-postfix) DBG |
[20:20:18] (docker-postfix) DBG |
[20:20:18] (docker-postfix) DBG | -----------------------------------------------------
[20:20:30] (docker-postfix) DBG | 2017/01/05 20:20:30 DEBUG: Request ec2/DescribeInstances Details:
[20:20:30] (docker-postfix) DBG | ---[ REQUEST POST-SIGN ]-----------------------------
[20:20:30] (docker-postfix) DBG | POST / HTTP/1.1
[20:20:30] (docker-postfix) DBG | Host: ec2.eu-west-1.amazonaws.com
[20:20:30] (docker-postfix) DBG | User-Agent: aws-sdk-go/1.4.10 (go1.7.3; linux; amd64)
[20:20:30] (docker-postfix) DBG | Content-Length: 67
[20:20:30] (docker-postfix) DBG | Authorization: AWS4-HMAC-SHA256 Credential=AKIAIAFT5RNHDOGXQIJA/20170105/eu-west-1/ec2/aws4_request, SignedHeaders=content-length;content-type;host;x-amz-date, Signature=b81b76a2d686fbe6dbf0f44ef44b3b9456a9262111b4feb1ea5d4681799fc044
[20:20:30] (docker-postfix) DBG | Content-Type: application/x-www-form-urlencoded; charset=utf-8
[20:20:30] (docker-postfix) DBG | X-Amz-Date: 20170105T202030Z
[20:20:30] (docker-postfix) DBG | Accept-Encoding: gzip
[20:20:30] (docker-postfix) DBG |
[20:20:30] (docker-postfix) DBG | Action=DescribeInstances&InstanceId.1=i-ed9da705&Version=2016-04-01
[20:20:30] (docker-postfix) DBG | -----------------------------------------------------
[20:20:30] (docker-postfix) DBG | 2017/01/05 20:20:30 DEBUG: Response ec2/DescribeInstances Details:
[20:20:30] (docker-postfix) DBG | ---[ RESPONSE ]--------------------------------------
[20:20:30] (docker-postfix) DBG | HTTP/1.1 200 OK
[20:20:30] (docker-postfix) DBG | Transfer-Encoding: chunked
[20:20:30] (docker-postfix) DBG | Content-Type: text/xml;charset=UTF-8
[20:20:30] (docker-postfix) DBG | Date: Thu, 05 Jan 2017 20:20:30 GMT
[20:20:30] (docker-postfix) DBG | Server: AmazonEC2
[20:20:30] (docker-postfix) DBG | Vary: Accept-Encoding
[20:20:30] (docker-postfix) DBG |
[20:20:30] (docker-postfix) DBG | 186a
[20:20:30] (docker-postfix) DBG | <?xml version="1.0" encoding="UTF-8"?>
[20:20:30] (docker-postfix) DBG | <DescribeInstancesResponse xmlns="http://ec2.amazonaws.com/doc/2016-04-01/">
[20:20:30] (docker-postfix) DBG |     <requestId>4cb02c56-33ef-42f0-90b2-ebad06bd5fa8</requestId>
[20:20:30] (docker-postfix) DBG |     <reservationSet>
[20:20:30] (docker-postfix) DBG |         <item>
[20:20:30] (docker-postfix) DBG |             <reservationId>r-0160a889</reservationId>
[20:20:30] (docker-postfix) DBG |             <ownerId>768427182047</ownerId>
[20:20:30] (docker-postfix) DBG |             <groupSet/>
[20:20:30] (docker-postfix) DBG |             <instancesSet>
[20:20:30] (docker-postfix) DBG |                 <item>
[20:20:30] (docker-postfix) DBG |                     <instanceId>i-ed9da705</instanceId>
[20:20:30] (docker-postfix) DBG |                     <imageId>ami-c593deb6</imageId>
[20:20:30] (docker-postfix) DBG |                     <instanceState>
[20:20:30] (docker-postfix) DBG |                         <code>16</code>
[20:20:30] (docker-postfix) DBG |                         <name>running</name>
[20:20:30] (docker-postfix) DBG |                     </instanceState>
[20:20:30] (docker-postfix) DBG |                     <privateDnsName>ip-XXX.eu-west-1.compute.internal</privateDnsName>
[20:20:30] (docker-postfix) DBG |                     <dnsName>ec2-XXX.eu-west-1.compute.amazonaws.com</dnsName>
[20:20:30] (docker-postfix) DBG |                     <reason/>
[20:20:30] (docker-postfix) DBG |                     <keyName>docker-postfix</keyName>
[20:20:30] (docker-postfix) DBG |                     <amiLaunchIndex>0</amiLaunchIndex>
[20:20:30] (docker-postfix) DBG |                     <productCodes/>
[20:20:30] (docker-postfix) DBG |                     <instanceType>t2.nano</instanceType>
[20:20:30] (docker-postfix) DBG |                     <launchTime>2016-12-12T11:42:25.000Z</launchTime>
[20:20:30] (docker-postfix) DBG |                     <placement>
[20:20:30] (docker-postfix) DBG |                         <availabilityZone>eu-west-1a</availabilityZone>
[20:20:30] (docker-postfix) DBG |                         <groupName/>
[20:20:30] (docker-postfix) DBG |                         <tenancy>default</tenancy>
[20:20:30] (docker-postfix) DBG |                     </placement>
[20:20:30] (docker-postfix) DBG |                     <monitoring>
[20:20:30] (docker-postfix) DBG |                         <state>disabled</state>
[20:20:30] (docker-postfix) DBG |                     </monitoring>
[20:20:30] (docker-postfix) DBG |                     <subnetId>subnet-40349424</subnetId>
[20:20:30] (docker-postfix) DBG |                     <vpcId>vpc-71d92315</vpcId>
[20:20:30] (docker-postfix) DBG |                     <privateIpAddress>XXX</privateIpAddress>
[20:20:30] (docker-postfix) DBG |                     <ipAddress>XXX</ipAddress>
[20:20:30] (docker-postfix) DBG |                     <sourceDestCheck>true</sourceDestCheck>
[20:20:30] (docker-postfix) DBG |                     <groupSet>
[20:20:30] (docker-postfix) DBG |                         <item>
[20:20:30] (docker-postfix) DBG |                             <groupId>sg-37af3d51</groupId>
[20:20:30] (docker-postfix) DBG |                             <groupName>docker-machine</groupName>
[20:20:30] (docker-postfix) DBG |                         </item>
[20:20:30] (docker-postfix) DBG |                     </groupSet>
[20:20:30] (docker-postfix) DBG |                     <architecture>x86_64</architecture>
[20:20:30] (docker-postfix) DBG |                     <rootDeviceType>ebs</rootDeviceType>
[20:20:30] (docker-postfix) DBG |                     <rootDeviceName>/dev/sda1</rootDeviceName>
[20:20:30] (docker-postfix) DBG |                     <blockDeviceMapping>
[20:20:30] (docker-postfix) DBG |                         <item>
[20:20:30] (docker-postfix) DBG |                             <deviceName>/dev/sda1</deviceName>
[20:20:30] (docker-postfix) DBG |                             <ebs>
[20:20:30] (docker-postfix) DBG |                                 <volumeId>vol-30a2ddb2</volumeId>
[20:20:30] (docker-postfix) DBG |                                 <status>attached</status>
[20:20:30] (docker-postfix) DBG |                                 <attachTime>2016-12-12T11:42:26.000Z</attachTime>
[20:20:30] (docker-postfix) DBG |                                 <deleteOnTermination>true</deleteOnTermination>
[20:20:30] (docker-postfix) DBG |                             </ebs>
[20:20:30] (docker-postfix) DBG |                         </item>
[20:20:30] (docker-postfix) DBG |                     </blockDeviceMapping>
[20:20:30] (docker-postfix) DBG |                     <virtualizationType>hvm</virtualizationType>
[20:20:30] (docker-postfix) DBG |                     <clientToken/>
[20:20:30] (docker-postfix) DBG |                     <tagSet>
[20:20:30] (docker-postfix) DBG |                         <item>
[20:20:30] (docker-postfix) DBG |                             <key>Name</key>
[20:20:30] (docker-postfix) DBG |                             <value>docker-postfix</value>
[20:20:30] (docker-postfix) DBG |                         </item>
[20:20:30] (docker-postfix) DBG |                     </tagSet>
[20:20:30] (docker-postfix) DBG |                     <hypervisor>xen</hypervisor>
[20:20:30] (docker-postfix) DBG |                     <networkInterfaceSet>
[20:20:30] (docker-postfix) DBG |                         <item>
[20:20:30] (docker-postfix) DBG |                             <networkInterfaceId>eni-dbb2efa6</networkInterfaceId>
[20:20:30] (docker-postfix) DBG |                             <subnetId>subnet-40349424</subnetId>
[20:20:30] (docker-postfix) DBG |                             <vpcId>vpc-71d92315</vpcId>
[20:20:30] (docker-postfix) DBG |                             <description/>
[20:20:30] (docker-postfix) DBG |                             <ownerId>768427182047</ownerId>
[20:20:30] (docker-postfix) DBG |                             <status>in-use</status>
[20:20:30] (docker-postfix) DBG |                             <macAddress>02:bd:95:64:50:0f</macAddress>
[20:20:30] (docker-postfix) DBG |                             <privateIpAddress>XXX</privateIpAddress>
[20:20:30] (docker-postfix) DBG |                             <privateDnsName>ip-XXX.eu-west-1.compute.internal</privateDnsName>
[20:20:30] (docker-postfix) DBG |                             <sourceDestCheck>true</sourceDestCheck>
[20:20:30] (docker-postfix) DBG |                             <groupSet>
[20:20:30] (docker-postfix) DBG |                                 <item>
[20:20:30] (docker-postfix) DBG |                                     <groupId>sg-37af3d51</groupId>
[20:20:30] (docker-postfix) DBG |                                     <groupName>docker-machine</groupName>
[20:20:30] (docker-postfix) DBG |                                 </item>
[20:20:30] (docker-postfix) DBG |                             </groupSet>
[20:20:30] (docker-postfix) DBG |                             <attachment>
[20:20:30] (docker-postfix) DBG |                                 <attachmentId>eni-attach-69bfe8e6</attachmentId>
[20:20:30] (docker-postfix) DBG |                                 <deviceIndex>0</deviceIndex>
[20:20:30] (docker-postfix) DBG |                                 <status>attached</status>
[20:20:30] (docker-postfix) DBG |                                 <attachTime>2016-12-12T11:42:25.000Z</attachTime>
[20:20:30] (docker-postfix) DBG |                                 <deleteOnTermination>true</deleteOnTermination>
[20:20:30] (docker-postfix) DBG |                             </attachment>
[20:20:30] (docker-postfix) DBG |                             <association>
[20:20:30] (docker-postfix) DBG |                                 <publicIp>XXX</publicIp>
[20:20:30] (docker-postfix) DBG |                                 <publicDnsName>ec2-XXX.eu-west-1.compute.amazonaws.com</publicDnsName>
[20:20:30] (docker-postfix) DBG |                                 <ipOwnerId>768427182047</ipOwnerId>
[20:20:30] (docker-postfix) DBG |                             </association>
[20:20:30] (docker-postfix) DBG |                             <privateIpAddressesSet>
[20:20:30] (docker-postfix) DBG |                                 <item>
[20:20:30] (docker-postfix) DBG |                                     <privateIpAddress>XXX</privateIpAddress>
[20:20:30] (docker-postfix) DBG |                                     <privateDnsName>ip-XXX.eu-west-1.compute.internal</privateDnsName>
[20:20:30] (docker-postfix) DBG |                                     <primary>true</primary>
[20:20:30] (docker-postfix) DBG |                                     <association>
[20:20:30] (docker-postfix) DBG |                                     <publicIp>XXX</publicIp>
[20:20:30] (docker-postfix) DBG |                                     <publicDnsName>ec2-XXX.eu-west-1.compute.amazonaws.com</publicDnsName>
[20:20:30] (docker-postfix) DBG |                                     <ipOwnerId>768427182047</ipOwnerId>
[20:20:30] (docker-postfix) DBG |                                     </association>
[20:20:30] (docker-postfix) DBG |                                 </item>
[20:20:30] (docker-postfix) DBG |                             </privateIpAddressesSet>
[20:20:30] (docker-postfix) DBG |                         </item>
[20:20:30] (docker-postfix) DBG |                     </networkInterfaceSet>
[20:20:30] (docker-postfix) DBG |                     <iamInstanceProfile>
[20:20:30] (docker-postfix) DBG |                         <arn>arn:aws:iam::768427182047:instance-profile/docker-postfix-profile</arn>
[20:20:30] (docker-postfix) DBG |                         <id>XXX</id>
[20:20:30] (docker-postfix) DBG |                     </iamInstanceProfile>
[20:20:30] (docker-postfix) DBG |                     <ebsOptimized>false</ebsOptimized>
[20:20:30] (docker-postfix) DBG |                 </item>
[20:20:30] (docker-postfix) DBG |             </instancesSet>
[20:20:30] (docker-postfix) DBG |         </item>
[20:20:30] (docker-postfix) DBG |     </reservationSet>
[20:20:30] (docker-postfix) DBG | </DescribeInstancesResponse>
[20:20:30] (docker-postfix) DBG | 0
[20:20:30] (docker-postfix) DBG |
[20:20:30] (docker-postfix) DBG |
[20:20:30] (docker-postfix) DBG | -----------------------------------------------------
[20:20:30] Reading CA certificate from /home/samuel/.docker/machine/certs/ca.pem
[20:20:30] Reading client certificate from /home/samuel/.docker/machine/certs/cert.pem
[20:20:30] Reading client key from /home/samuel/.docker/machine/certs/key.pem
[20:20:30] Reading CA certificate from /home/samuel/.docker/machine/certs/ca.pem
[20:20:30] Reading client certificate from /home/samuel/.docker/machine/certs/cert.pem
[20:20:30] Reading client key from /home/samuel/.docker/machine/certs/key.pem
[20:20:30] export DOCKER_TLS_VERIFY="1"
[20:20:30] export DOCKER_HOST="tcp://XXX:2376"
[20:20:30] export DOCKER_CERT_PATH="/home/samuel/.docker/machine/machines/docker-postfix"
[20:20:30] export DOCKER_MACHINE_NAME="docker-postfix"
[20:20:30] export DOCKER_API_VERSION="1.24"
[20:20:30] # Run this command to configure your shell:
[20:20:30] # eval $(docker-machine --debug env docker-postfix)
[20:20:30] Making call to close driver server
[20:20:30] (docker-postfix) Calling .Close
[20:20:30] Successfully made call to close driver server
[20:20:30] Making call to close connection to plugin binary
[20:20:30] (docker-postfix) DBG | Closing plugin on server side

real    0m24.348s
user    0m0.080s
sys 0m0.008s
~ ||
samuelcolvin picture samuelcolvin on 5 Jan 2017

How long do Docker API request to that node take? (e.g., eval $(docker-machine env node); time docker ps

nathanleclaire picture nathanleclaire on 5 Jan 2017

In my case, i'm using docker-machine through Rancher which makes it difficult to debug anything. But, have noticed it takes almost a minute between the create call and the moment docker-machine effectively launches the instance on Amazon.

jloisel picture jloisel on 6 Jan 2017

Tested with docker-machine directly, instead of going through rancher and things are way better: it takes 2min to launch an instance. I've opened a bug on their side:
https://github.com/rancher/rancher/issues/7292

For me, it seems like it's not a docker-machine issue, but a Rancher issue.

jloisel picture jloisel on 17 Jan 2017

sorry @nathanleclaire, forgot to reply to this.

time docker ps takes 0.25s real. Looks like that's not suffering from the problem.

samuelcolvin picture samuelcolvin on 17 Jan 2017

I have this with the generic (ssh) driver too.
It become unresponsive, getting worse over days.
I left it alone some weeks, because I got a second server with better hardware.

Now docker ps didn't respond in a day (22 hours, left running in a screen)

It is still running, the containers are still up
(I can browse the urls, and top on the server shows many good looking process names)
I just can't use any docker related command any more.
Neither via docker-compose on my laptop, nor on the host itself via ssh.

Anything I can check, or help you guys debug this?

$ uname -a

Linux cloudsdale 4.4.0-31-generic #50-Ubuntu SMP Wed Jul 13 00:07:12 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

$ docker --version

Docker version 1.12.1, build 23cf638

**$ docker version

Client:
 Version:      1.12.1
 API version:  1.24
 Go version:   go1.6.3
 Git commit:   23cf638
 Built:        Thu Aug 18 05:33:38 2016
 OS/Arch:      linux/amd64

Server:
 Version:      1.12.1
 API version:  1.24
 Go version:   go1.6.3
 Git commit:   23cf638
 Built:        Thu Aug 18 05:33:38 2016
 OS/Arch:      linux/amd64
luckydonald picture luckydonald on 3 Mar 2017

I read somewhere it could be related to VPN or stuff, I don't have such stuff on my root server.
However here a some outputs, not sure if helpful at all. If it contains data which should not be on the internet, kindly tell me.

$ docker network ls

NETWORK ID          NAME                      DRIVER              SCOPE
c6b8d715e52b        bridge                    bridge              local
66647f0a259e        dockertgbot_default       bridge              local
51a6bdea97ae        elasticnet                bridge              local
3ed0ccf2b4a4        host                      host                local
dfc43ab777c1        none                      null                local
5ad5c3bfd660        reddit2telegram_default   bridge              local
8c39e64fa9db        rss_default               bridge              local
22233a69bce1        teamproject16_default     bridge              local
55098aef1e65        tgdl_default              bridge              local

$ netstat -i

Kernel Interface table
Iface   MTU Met   RX-OK RX-ERR RX-DRP RX-OVR    TX-OK TX-ERR TX-DRP TX-OVR Flg
br-22233a69bce1  1500 0   1245963      0      0 0       1262602      0      0      0 BMRU
br-51a6bdea97ae  1500 0     45506      0      0 0         49829      0      0      0 BMRU
br-55098aef1e65  1500 0  27417856      0      0 0      29177684      0      0      0 BMRU
br-5ad5c3bfd660  1500 0         0      0      0 0             0      0      0      0 BMU
br-66647f0a259e  1500 0  83870876      0      0 0      75144496      0      0      0 BMRU
br-8c39e64fa9db  1500 0        61      0      0 0            71      0      0      0 BMU
docker0    1500 0    198839      0      0 0        412463      0      0      0 BMU
eth0       1500 0  234719861      0      0 0      169336118      0      0      0 BMRU
lo        65536 0        14      0      0 0            14      0      0      0 LRU
veth0071488  1500 0      5242      0      0 0        203479      0      0      0 BMRU
veth0085c28  1500 0  624862391      0      0 0      543946194      0      0      0 BMRU
veth07aabf6  1500 0    435458      0      0 0        624380      0      0      0 BMRU
veth0d213e2  1500 0    187318      0      0 0        378231      0      0      0 BMRU
veth10681cf  1500 0    235966      0      0 0        410286      0      0      0 BMRU
veth14cf2cf  1500 0     49835      0      0 0        229919      0      0      0 BMRU
veth1650ea9  1500 0   2276208      0      0 0       2183235      0      0      0 BMRU
veth1c3a393  1500 0   2267546      0      0 0       2177188      0      0      0 BMRU
veth1e7ca3d  1500 0   8227873      0      0 0      12272048      0      0      0 BMRU
veth25d6359  1500 0    829325      0      0 0        915176      0      0      0 BMRU
veth377cd2c  1500 0     20309      0      0 0        218961      0      0      0 BMRU
veth417d15d  1500 0   6537558      0      0 0       3642135      0      0      0 BMRU
veth4621d4f  1500 0      1718      0      0 0        199950      0      0      0 BMRU
veth4bfdd0f  1500 0     17947      0      0 0        213016      0      0      0 BMRU
veth4ccacc5  1500 0  1044728396      0      0 0      1186870106      0      0      0 BMRU
veth4faaef8  1500 0  16199815      0      0 0      15175986      0      0      0 BMRU
veth554f556  1500 0   2261846      0      0 0       2170038      0      0      0 BMRU
veth5ed2979  1500 0       997      0      0 0        199279      0      0      0 BMRU
veth679c51a  1500 0   2264953      0      0 0       2172014      0      0      0 BMRU
veth686d724  1500 0      6032      0      0 0        148254      0      0      0 BMRU
veth7585a3a  1500 0    165936      0      0 0        245870      0      0      0 BMRU
veth76558cd  1500 0     13043      0      0 0        194378      0      0      0 BMRU
veth7d9a8d0  1500 0     29058      0      0 0        219316      0      0      0 BMRU
veth8690bb1  1500 0  139336515      0      0 0      99626461      0      0      0 BMRU
veth893a589  1500 0     20254      0      0 0        218738      0      0      0 BMRU
veth8bc3783  1500 0     73944      0      0 0         84518      0      0      0 BMRU
veth91972fd  1500 0     17042      0      0 0        211272      0      0      0 BMRU
veth946af0d  1500 0     20051      0      0 0        218673      0      0      0 BMRU
veth9757cd9  1500 0     12683      0      0 0        194139      0      0      0 BMRU
veth9bf73f4  1500 0   5926261      0      0 0       6665886      0      0      0 BMRU
veth9f20fe8  1500 0     13812      0      0 0        195295      0      0      0 BMRU
vetha730ba9  1500 0   2074173      0      0 0       2581642      0      0      0 BMRU
vethab15d5c  1500 0  20735507      0      0 0      21581890      0      2      0 BMRU
vethb2bf19a  1500 0     18595      0      0 0        217369      0      0      0 BMRU
vethb7d831b  1500 0  735117323      0      0 0      852692112      0      0      0 BMRU
vethbc96183  1500 0     20042      0      0 0        214768      0      0      0 BMRU
vethbdc1b1a  1500 0    832454      0      0 0        917818      0      0      0 BMRU
vethc0dd9ed  1500 0      2276      0      0 0        200640      0      0      0 BMRU
vethce92bf3  1500 0     13809      0      0 0        195290      0      0      0 BMRU
vethd1ff44f  1500 0       573      0      0 0        198358      0      0      0 BMRU
vethd75034c  1500 0     19814      0      0 0        218348      0      0      0 BMRU
vethdc122f9  1500 0  93585831      0      0 0      95738336      0      0      0 BMRU
vethde88ffc  1500 0  1347766923      0      0 0      1203023429      0      0      0 BMRU
vethe31aa63  1500 0    782283      0      0 0        834003      0      0      0 BMRU
vetheec5622  1500 0     30211      0      0 0         37154      0      0      0 BMRU
vethf50ddad  1500 0     13179      0      0 0        194639      0      0      0 BMRU
vethf6105b2  1500 0       975      0      0 0          1827      0      0      0 BMRU
vethf8a0f86  1500 0    367966      0      0 0        435620      0      0      0 BMRU
vethfa273cf  1500 0   1982850      0      0 0       1932690      0      0      0 BMRU
vethfcfa4ee  1500 0    281611      0      0 0        448501      0      0      0 BMRU
luckydonald picture luckydonald on 3 Mar 2017

Oh, wrong place to report indeed.
In my case that could be https://github.com/docker/docker/issues/31487

luckydonald picture luckydonald on 3 Mar 2017

@samuelcolvin did you manage to find the source of the problem?
I'm experiencing the same problem:
When I ssh to a machine (as well as getting info with docker-machine ls) on AWS the api requests take at least 10 seconds to complete-
"Calling .GetSSHHostname", "Calling .GetState", "Calling .GetURL", etc.

Making similar api requests with AWS-CLI takes only 0.5 sec.

OmerZfira picture OmerZfira on 16 Apr 2017

Sorry for the slow reply @OmerZfira, I'm still getting the same problem.

I created a new machine today again in eu-west with docker machine version 0.12.2, build 9371605 and docker 17.06.1-ce and I'm getting the exact same problem.

I'm assuming this must be related to the region otherwise surely others more people would be having the problem???

samuelcolvin picture samuelcolvin on 19 Aug 2017

Ok, I've at last got somewhere with this problem.

It was because I didn't have the aws credential env variables exported and ~/.aws/credentials had two profiles personal and work, eg. no default profile.

I was able to stop the slowness and timeouts by renaming the "personal" profile to "default".

Still not sure what's going on to cause the delay rather than just a failure, but at least for me this problem is avoided. Is this a problem with machine or with the aws-go library?

samuelcolvin picture samuelcolvin on 20 Aug 2017
👍3

UPDATE A combination of two things were necessary to solve my issues:

  1. Let PowerShell launch a bash process that calls docker-machine commands that depend on ssh, such as docker-machine create and docker-machine ssh.
  2. I asked my network administrator to open Docker port 2376 on the company firewall.

ORIGINAL

I have the same problem, that is, all docker-machine commands are slow or they timeout, when working with machines that use the amazonec2 driver. I don't use ~/.aws/credentials file. Instead I use the environment variables AWS_ACCESS_KEY_ID, AWS_SECRET_ACCESS_KEY and MACHINE_STORAGE_PATH.

I am using docker-machine inside a PowerShell prompt, and PowerShell scripts.

The commands tested:
docker-machine env aws-docker-machine
docker-machine ls
docker-machine kill aws-docker-machine
docker-machine start aws-docker-machine
docker-machine regenerate-certs --force aws-docker-machine

I have one VirtualBox docker machine, and one AWS docker machine.

An example error for docker-machine env aws-docker-machine:

Error checking TLS connection: Error checking and/or regenerating the certs: There was an error validating certificates for host "18.209.16.213:2376": dial tcp 18.209.16.213:2376: i/o timeout
You can attempt to regenerate them using 'docker-machine regenerate-certs [name]'.
Be advised that this will trigger a Docker daemon restart which might stop running containers.

I am using Docker Toolbox for Windows.

I don't have the Amazon AWS CLI installed.

$> docker-machine version

docker-machine.exe version 0.14.0, build 89b8332

$> docker version

Client:
Version: 18.03.0-ce
API version: 1.37
Go version: go1.9.4
Git commit: 0520e24302
Built: Fri Mar 23 08:31:36 2018
OS/Arch: windows/amd64
Experimental: false
Orchestrator: swarm

Server:
Engine:
Version: 18.05.0-ce
API version: 1.37 (minimum version 1.12)
Go version: go1.10.1
Git commit: f150324
Built: Wed May 9 22:20:42 2018
OS/Arch: linux/amd64
Experimental: false

W1M0R picture W1M0R on 26 Jun 2018
👍1
Was this page helpful?
0 / 5 - 0 ratings

Related issues

pschultz picture pschultz  路  3Comments
iongion picture iongion  路  4Comments
diver-sity picture diver-sity  路  4Comments
masaeedu picture masaeedu  路  4Comments
m-amr picture m-amr  路  5Comments