Cannot boostrap from custom image-metadata-url or by specifying metadata-source

[Jorge Niedbalski]

[Environment]

Trusty 14.04.2
Juju core 1.23

[Reproduction]

This are the steps that I followed:

1) juju metadata generate-image -d simplestreams -i b6a1f124-85c9-48df-9811-50d06cad2305 -s utopic -r ctsstack -u http://10.230.19.65:5000/v2.0/ -a amd64

2) Upload the generated index to switft

swift post simplestreams
cd ~/simplestreams
swift upload simplestreams *
swift post simplestreams --read-acl .r:*

3) Just to make sure , I edited ~/.juju/environments.yaml, added the following lines to the openstack env:

    image-metadata-url: http://10.230.19.60:80:80/swift/v1/simplestreams
    ssl-hostname-verification: false

4) juju bootstrap -e openstack -v --metadata-source ~/simplestreams --series utopic --upload-tools

Then the bootstrap process fails with:

2015-05-06 19:01:13 INFO juju.mongo open.go:125 dialled mongo successfully on address "127.0.0.1:37017"
2015-05-06 19:01:13 INFO juju.replicaset replicaset.go:73 Initiating replicaset with config replicaset.Config{Name:"juju", Version:1, Members:[]replicaset.Member{replicaset.Member{Id:1, Address:"10.5.1.46:37017", Arbiter:(*bool)(nil), BuildIndexes:(*bool)(nil), Hidden:(*bool)(nil), Priority:(*float64)(nil), Tags:map[string]string{"juju-machine-id":"0"}, SlaveDelay:(*time.Duration)(nil), Votes:(*int)(nil)}}}
2015-05-06 19:01:13 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:13 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:14 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:14 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:15 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:15 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:16 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:16 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:17 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:17 INFO juju.mongo open.go:125 dialled mongo successfully on address "127.0.0.1:37017"
2015-05-06 19:01:17 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:18 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:18 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:19 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:19 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:20 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:20 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:21 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:21 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:22 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:22 WARNING juju.replicaset replicaset.go:93 Initiate: fetching replication status failed: cannot get replica set status: Received replSetInitiate - should come online shortly.
2015-05-06 19:01:23 INFO juju.worker.peergrouper initiate.go:70 replica set initiated
2015-05-06 19:01:23 INFO juju.worker.peergrouper initiate.go:81 finished MaybeInitiateMongoServer
2015-05-06 19:01:23 INFO juju.cmd.jujud bootstrap.go:179 started mongo
2015-05-06 19:01:23 INFO juju.mongo open.go:125 dialled mongo successfully on address "127.0.0.1:37017"
2015-05-06 19:01:25 INFO juju.state open.go:46 opening state, mongo addresses: ["127.0.0.1:37017"]; entity <nil>
2015-05-06 19:01:25 INFO juju.mongo open.go:125 dialled mongo successfully on address "127.0.0.1:37017"
2015-05-06 19:01:25 INFO juju.mongo open.go:125 dialled mongo successfully on address "127.0.0.1:37017"
2015-05-06 19:01:25 INFO juju.state open.go:83 initializing environment, owner: "admin@local"
2015-05-06 19:01:25 INFO juju.state open.go:84 info: &mongo.MongoInfo{Info:mongo.Info{Addrs:[]string{"127.0.0.1:37017"}, CACert:"-----BEGIN CERTIFICATE-----\nMIICWzCCAcagAwIBAgIBADALBgkqhkiG9w0BAQUwQzENMAsGA1UEChMEanVqdTEy\nMDAGA1UEAwwpanVqdS1nZW5lcmF0ZWQgQ0EgZm9yIGVudmlyb25tZW50ICJ0ZXV0\nbyIwHhcNMTUwNDI5MTg1NzMxWhcNMjUwNTA2MTg1NzMxWjBDMQ0wCwYDVQQKEwRq\ndWp1MTIwMAYDVQQDDClqdWp1LWdlbmVyYXRlZCBDQSBmb3IgZW52aXJvbm1lbnQg\nInRldXRvIjCBnzANBgkqhkiG9w0BAQEFAAOBjQAwgYkCgYEAnNjbpdEQlMaKtuAr\nYI5QIdHs2wvCjxnx3fGs3Lq79qo72VZ5XJ8Zwb0fiTZAgmpK24tvZNVnMyQBZ8UL\nDPbqS+VFZjdRrp2lY5Eb4CBy+vWOLMrfvUdTje+UWEyLD4J8gLsQBPLcPIaqJbwG\n4S7XVc1+0e4gu2tGI8hS9seYfakCAwEAAaNjMGEwDgYDVR0PAQH/BAQDAgCkMA8G\nA1UdEwEB/wQFMAMBAf8wHQYDVR0OBBYEFF73thBQgQiqYSZQ5a7uyM9+5NiLMB8G\nA1UdIwQYMBaAFF73thBQgQiqYSZQ5a7uyM9+5NiLMAsGCSqGSIb3DQEBBQOBgQAy\ncfrH1qQ/xyzWJVZZq2tfuaYtceOLkx+Xp5gD7V7uIiweYf97k1+P0lO6N8wRLa3K\nwJq9ablxME22RIRaGSqQRbUdImQBePj+APSUvJ7K4hvm2J1kO7uqo/HBFP5YATcO\nxXVuBfHxa7kSKHm/GcdkMhxIbLoktzIvJZUP6P2MyQ==\n-----END CERTIFICATE-----\n"}, Tag:names.Tag(nil), Password:"OVI/NfXhFqfKpxKr1LwJjGE4"}
2015-05-06 19:01:25 INFO juju.provider.openstack provider.go:249 opening environment "openstack"
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:67 hostname SSL verification disabled
2015-05-06 19:01:25 INFO juju.utils http.go:60 hostname SSL verification enabled
2015-05-06 19:01:25 INFO juju.utils http.go:60 hostname SSL verification enabled
2015-05-06 19:01:26 INFO juju.utils http.go:60 hostname SSL verification enabled
2015-05-06 19:01:26 INFO juju.utils http.go:60 hostname SSL verification enabled
2015-05-06 19:01:26 INFO juju.utils http.go:60 hostname SSL verification enabled
2015-05-06 19:01:26 INFO juju.utils http.go:60 hostname SSL verification enabled
2015-05-06 19:01:26 ERROR juju.cmd supercommand.go:430 cannot set initial environ constraints: index file has no data for cloud {ctsstack http://10.230.19.65:5000/v2.0} not found
ERROR failed to bootstrap environment: subprocess encountered error code 1

The index file:

{
    "index": {
        "com.ubuntu.cloud:custom": {
            "updated": "Wed, 06 May 2015 18:48:34 +0000",
            "format": "products:1.0",
            "datatype": "image-ids",
            "cloudname": "custom",
            "clouds": [
                {
                    "region": "ctsstack",
                    "endpoint": "http://10.230.19.65:5000/v2.0/"
                }
            ],
            "path": "streams/v1/com.ubuntu.cloud-released-imagemetadata.json",
            "products": [
                "com.ubuntu.cloud:server:14.10:amd64"
            ]
        }
    },
    "updated": "Wed, 06 May 2015 18:48:34 +0000",
    "format": "index:1.0"
}

The generated imagemetadata

images/streams/v1/com.ubuntu.cloud-released-imagemetadata.json
{
    "products": {
        "com.ubuntu.cloud:server:14.10:amd64": {
            "version": "14.10",
            "arch": "amd64",
            "versions": {
                "20150605": {
                    "items": {
                        "b6a1f124-85c9-48df-9811-50d06cad2305": {
                            "id": "b6a1f124-85c9-48df-9811-50d06cad2305",
                            "region": "ctsstack",
                            "endpoint": "http://10.230.19.65:5000/v2.0/"
                        }
                    }
                }
            }
        }
    },
    "updated": "Wed, 06 May 2015 18:48:34 +0000",
    "format": "products:1.0",
    "content_id": "com.ubuntu.cloud:custom"
}

[Curtis Hovey (sinzui)]

This may be a duplicate of bug 1435644. Maybe we can get more information about both the cloud and what juju is doing this time.

[Curtis Hovey (sinzui)]

Give the need for this to be solved by tomorrow. We need to explain where documentation is wrong or incomplete, or provide a work around.

[Jorge Niedbalski (niedbalski)]

http://paste.ubuntu.com/10999201/

[Martin Packman (gz)]

It looks like --metadata-source is unhappy, from the longer log it's (unsurprisingly) correctly used from your machine, but when the state server tries to open the environment, it checks for images using only "keystone catalog" and "default cloud images" obviously neither of which works.

What you can probably do is just *not* pass --metadata-source but instead use the image-metadata-url config, which in you example should be "http://10.230.19.60:80:80/swift/v1/simplestreams/images" - note the images on the end. With boostrap --debug you should see the "image-metadata-url" datasource being queried at each stage.

Last resort is add the swift location as a new endpoint named 'product-streams' in keystone, that always gets queried. Requires some poking of your keystone configuration though, and I can't find simple instructions for doing that.

[Jorge Niedbalski (niedbalski)]

This is a clean bootstrap, setting up image-metadata-url http://paste.ubuntu.com/10999422/

[Jorge Niedbalski (niedbalski)]

OK, i was able to successfully bootstrap without using the --metadata-source option , which is broken.

The trick is to set image-metadata-url to include "/images" , as @gz mentioned
http://10.230.19.60:80/swift/v1/simplestreams/images

ubuntu@niedbalski2-bastion:~$ juju status
environment: teuto
machines:
  "0":
    agent-state: started
    agent-version: 1.23.2.1
    dns-name: 10.5.1.53
    instance-id: 8a523624-7613-4d96-a27b-152a972bde06
    instance-state: ACTIVE
    series: utopic
    hardware: arch=amd64 cpu-cores=1 mem=1024M root-disk=20480M availability-zone=nova
    state-server-member-status: has-vote
services: {}

The log for this: http://paste.ubuntu.com/10999537/

[Ian Booth (wallyworld)]

In looking at the code, there's a couple of observations:

1. metadata source precedence
- environment sources like keystone are registered in init() functions and then later when bootstrap is used with --metadata-source, that is registered. This means that the keystone source is used in preference to --metadata-source which is wrong

2. As Martin says, unlike tools metadata, image metadata is not written into the state database, so is not available to machine agents. In the case referred to in this bug, the machine agent attempts to set up a constraints validator which in turns requires a list of image metadata records to determine the allowed architectures.

[John A Meinel (jameinel)]

Does it matter that the metadata has a trailing slash: "endpoint": "http://10.230.19.65:5000/v2.0/" but the error message does not? "ctsstack http://10.230.19.65:5000/v2.0"

We've had problems with having/missing a trailing slash before, we might at least look into adding/removing one and seeing if it changes the lookup.

[Mark Ramm (mark-ramm)]

This is a blocker for an important demo/customer and so I am triaging it up in priority.

[Ian Booth (wallyworld)]

@John, the trailing slash doesn't matter - the matching code knows how to deal with it either way

[Andrew Love (andrew-love)]

This bug is affecting my deployment of juju charms on a private Openstack cloud. I was following:
https://jujucharms.com/docs/devel/howto-privatecloud

The metadata-source parameter doesn't work as noted.

[Ian Booth (wallyworld)]

Looks like a gh issue has been raised also https://github.com/juju/juju/issues/1893

[Firl (celpa-firl)]

I accidentally changed a status, however I just repeated all these steps with the latest compiled version.
http://pastebin.com/KA4VDiq4