[JCLOUDS-1027] digitalocean2 request incorrect droplet

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.0.0
• Fix Version/s: 1.9.2, 2.0.0
• Component/s: jclouds-labs
• Environment: Java 1.7 under Linux
• Assignee: Unassigned
• Reporter: Ruben Rubio Rey
• Created: 26/Oct/15 08:25
• Updated: 21/Jan/16 03:03
• Resolved: 28/Oct/15 01:59

Description

When creating a new droplet using digitalocean2, it takes more than 5 minutes. The reason is that while the droplet is being created Jclouds is checking an incorrect dropletid and the droplet is not found. (Eventually it does check the proper dropletid, but it takes too long)

Test.java

    @Test
    public void newDebianJessie() throws Exception {
        final String POLL_PERIOD_TWENTY_SECONDS = String.valueOf(SECONDS.toMillis(20));

        Properties overrides = new Properties();
        overrides.setProperty(ComputeServiceProperties.POLL_INITIAL_PERIOD, POLL_PERIOD_TWENTY_SECONDS);
        overrides.setProperty(ComputeServiceProperties.POLL_MAX_PERIOD, POLL_PERIOD_TWENTY_SECONDS);

        Iterable<Module> modules = ImmutableSet.<Module> of(new SshjSshClientModule(), new SLF4JLoggingModule());
        //Iterable<Module> modules = ImmutableSet.<Module> of(new SshjSshClientModule());
        ComputeServiceContext context = ContextBuilder.newBuilder("digitalocean2")
                .credentials("manageacloud", "mycredentials")
                .modules(modules)
                .overrides(overrides)
                .buildView(ComputeServiceContext.class);

        ComputeService computeService = context.getComputeService();

        TemplateOptions opts = computeService.templateOptions();
        Template template = computeService.templateBuilder()
                .locationId("sfo1")
                .imageId("sfo1/debian-8-x64")
                .hardwareId("512mb")
                .options(opts.as(DigitalOcean2TemplateOptions.class).privateNetworking(true))
                .build();
        

        Set<? extends NodeMetadata> nodes = computeService.createNodesInGroup("unittest", 1, template);
        for (NodeMetadata nodeMetadata : nodes) {
            System.out.println("BuildNewServerTask Login: ssh " + nodeMetadata.getCredentials().getUser() +  "@" + nodeMetadata.getPublicAddresses());
            System.out.println("BuildNewServerTask Password: " + nodeMetadata.getCredentials().getPassword());
        }
        System.out.println("The end");
    }

If the logs are activated, you can see how JClouds is checking the incorrect dropletip

16:12:38.075 [user thread 0] DEBUG jclouds.headers - >> GET https://api.digitalocean.com/v2/droplets/69392077 HTTP/1.1
16:12:38.076 [user thread 0] DEBUG jclouds.headers - >> Accept: application/json
16:12:38.076 [user thread 0] DEBUG jclouds.headers - >> Authorization: Bearer mycr3d3nt14ls
16:12:39.453 [user thread 0] DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService - Receiving response -1100723561: HTTP/1.1 404 Not Found
16:12:39.454 [user thread 0] DEBUG jclouds.headers - << HTTP/1.1 404 Not Found
16:12:39.454 [user thread 0] DEBUG jclouds.headers - << RateLimit-Reset: 1445836354
16:12:39.454 [user thread 0] DEBUG jclouds.headers - << X-Runtime: 0.034042
16:12:39.454 [user thread 0] DEBUG jclouds.headers - << X-XSS-Protection: 1; mode=block
16:12:39.454 [user thread 0] DEBUG jclouds.headers - << Set-Cookie: __cfduid=d0bae9fcd693dc4bc109fa67a5ea6aad01445836358; expires=Tue, 25-Oct-16 05:12:38 GMT; path=/; domain=.digitalocean.com; HttpOnly
16:12:39.455 [user thread 0] DEBUG jclouds.headers - << X-Request-Id: e27e24fc-5b39-4bc5-82ef-02d26b424a0c
16:12:39.455 [user thread 0] DEBUG jclouds.headers - << Connection: keep-alive
16:12:39.455 [user thread 0] DEBUG jclouds.headers - << Server: cloudflare-nginx
16:12:39.456 [user thread 0] DEBUG jclouds.headers - << RateLimit-Limit: 5000
16:12:39.456 [user thread 0] DEBUG jclouds.headers - << Cache-Control: no-cache
16:12:39.456 [user thread 0] DEBUG jclouds.headers - << X-Content-Type-Options: nosniff
16:12:39.456 [user thread 0] DEBUG jclouds.headers - << Status: 404 Not Found
16:12:39.457 [user thread 0] DEBUG jclouds.headers - << X-Frame-Options: SAMEORIGIN
16:12:39.457 [user thread 0] DEBUG jclouds.headers - << RateLimit-Remaining: 4675
16:12:39.457 [user thread 0] DEBUG jclouds.headers - << Transfer-Encoding: chunked
16:12:39.458 [user thread 0] DEBUG jclouds.headers - << Date: Mon, 26 Oct 2015 05:12:39 GMT
16:12:39.458 [user thread 0] DEBUG jclouds.headers - << CF-RAY: 23b3aad7094f04bc-SYD
16:12:39.458 [user thread 0] DEBUG jclouds.headers - << Content-Type: application/json; charset=utf-8
16:12:39.459 [user thread 0] DEBUG jclouds.wire - << "{"id":"not_found","message":"The resource you were accessing could not be found."}"

However eventually the correct droplet id is checked and the configuration can move forward

16:12:50.395 [user thread 0] DEBUG jclouds.headers - >> GET https://api.digitalocean.com/v2/droplets/8409235 HTTP/1.1
16:12:50.395 [user thread 0] DEBUG jclouds.headers - >> Accept: application/json
16:12:50.395 [user thread 0] DEBUG jclouds.headers - >> Authorization: Bearer mycr3d3nt14ls
16:12:50.821 [user thread 0] DEBUG o.j.h.i.JavaUrlHttpCommandExecutorService - Receiving response -1048610249: HTTP/1.1 200 OK
16:12:50.821 [user thread 0] DEBUG jclouds.headers - << HTTP/1.1 200 OK
16:12:50.821 [user thread 0] DEBUG jclouds.headers - << RateLimit-Reset: 1445836394
16:12:50.821 [user thread 0] DEBUG jclouds.headers - << X-Runtime: 0.130968
16:12:50.821 [user thread 0] DEBUG jclouds.headers - << X-XSS-Protection: 1; mode=block
16:12:50.822 [user thread 0] DEBUG jclouds.headers - << Set-Cookie: __cfduid=d5a6ddc874ea2564b2d611da4fd9854f61445836370; expires=Tue, 25-Oct-16 05:12:50 GMT; path=/; domain=.digitalocean.com; HttpOnly
16:12:50.822 [user thread 0] DEBUG jclouds.headers - << X-Request-Id: 3a63ba1d-1f32-485a-812d-26623a0dfc84
16:12:50.822 [user thread 0] DEBUG jclouds.headers - << Connection: keep-alive
16:12:50.822 [user thread 0] DEBUG jclouds.headers - << Server: cloudflare-nginx
16:12:50.822 [user thread 0] DEBUG jclouds.headers - << RateLimit-Limit: 5000
16:12:50.822 [user thread 0] DEBUG jclouds.headers - << Cache-Control: max-age=0, private, must-revalidate
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << X-Content-Type-Options: nosniff
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << Status: 200 OK
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << X-Frame-Options: SAMEORIGIN
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << RateLimit-Remaining: 4673
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << Transfer-Encoding: chunked
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << Date: Mon, 26 Oct 2015 05:12:50 GMT
16:12:50.823 [user thread 0] DEBUG jclouds.headers - << CF-RAY: 23b3ab22fd6204bc-SYD
16:12:50.824 [user thread 0] DEBUG jclouds.headers - << Content-Type: application/json; charset=utf-8
16:12:50.824 [user thread 0] DEBUG jclouds.wire - << "{"droplet":{"id":8409235,"name":"unittest-698","memory":512,"vcpus":1,"disk":20,"locked":false,"status":"active","kernel":null,"created_at":"2015-10-26T05:07:49Z","features":["private_networking","virtio"],"backup_ids":[],"next_backup_window":null,"snapshot_ids":[],"image":{"id":12778278,"name":"8.1 x64","distribution":"Debian","slug":"debian-8-x64","public":true,"regions":["nyc1","ams1","sfo1","nyc2","ams2","sgp1","lon1","nyc3","ams3","fra1","tor1"],"created_at":"2015-07-16T18:49:14Z","min_disk_size":20,"type":"snapshot"},"size":{"slug":"512mb","memory":512,"vcpus":1,"disk":20,"transfer":1.0,"price_monthly":5.0,"price_hourly":0.00744,"regions":["nyc1","sgp1","sfo1","nyc2","lon1","nyc3","ams3","ams2","fra1","tor1"],"available":true},"size_slug":"512mb","networks":{"v4":[{"ip_address":"10.134.159.113","netmask":"255.255.0.0","gateway":"10.134.0.1","type":"private"},{"ip_address":"104.236.174.121","netmask":"255.255.192.0","gateway":"104.236.128.1","type":"public"}],"v6":[]},"region":{"name":"San Francisco 1","slug":"sfo1","sizes":["32gb","16gb","2gb","1gb","4gb","8gb","512mb","64gb","48gb"],"features":["private_networking","backups","ipv6","metadata"],"available":true}}}"
16:12:50.856 [user thread 0] DEBUG jclouds.compute - << RUNNING[ACTIVE] node(8409235)