failed configuring a static IP for container "1/lxc/0": cannot allocate addresses: instId not supported

[James Tunnicliffe]

On amazon I get the following error in the Juju logs:

machine-1[5563]: 2015-09-23 15:33:21 INFO juju.worker runner.go:269 start "lxc-provisioner"
machine-1[5563]: 2015-09-23 15:33:21 INFO juju.worker runner.go:275 stopped "1-container-watcher", err: <nil>
machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner provisioner_task.go:138 Starting up provisioner task machine-1
machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner provisioner_task.go:408 found machine pending provisioning id:1/lxc/0, details:1/lxc/0
machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner provisioner_task.go:253 provisioner-harvest-mode is set to destroyed; unknown instances not stopped []
machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner.lxc lxc-broker.go:88 starting lxc container for machineId: 1/lxc/0
machine-1[5563]: 2015-09-23 15:33:22 WARNING juju.provisioner lxc-broker.go:532 failed configuring a static IP for container "1/lxc/0": cannot allocate addresses: instId not supported
machine-1[5563]: 2015-09-23 15:33:22 INFO juju.provisioner lxc-broker.go:114 not allocating static IP for container "1/lxc/0": cannot allocate addresses: instId not supported

It looks like this is to do with the interaction with the recent subnets and spaces code changes and the older container logic. I don't get the error on MAAS.

Currently rewinding through commits to see if/when the error goes away.

[James Tunnicliffe (dooferlad)]

Default VPC with addressable containers on, earlier revision (before the changes that the above error is created from):

machine-1[9862]: 2015-09-23 16:47:50 INFO juju.provisioner.lxc lxc-broker.go:87 starting lxc container for machineId: 1/lxc/0
machine-1[9862]: 2015-09-23 16:47:50 DEBUG juju.provisioner lxc-broker.go:101 trying to allocate static IP for container "1/lxc/0"
machine-1[9862]: 2015-09-23 16:47:50 DEBUG juju.provisioner lxc-broker.go:546 trying to allocate a static IP for container "1/lxc/0"
machine-1[9862]: 2015-09-23 16:47:55 WARNING juju.provisioner lxc-broker.go:529 failed configuring a static IP for container "1/lxc/0": cannot allocate addresses: no interfaces available
machine-1[9862]: 2015-09-23 16:47:55 INFO juju.provisioner lxc-broker.go:113 not allocating static IP for container "1/lxc/0": cannot allocate addresses: no interfaces available
machine-1[9862]: 2015-09-23 16:47:55 DEBUG juju.service discovery.go:65 discovered init system "upstart" from series "trusty"
machine-1[9862]: 2015-09-23 16:47:55 DEBUG juju.container.lxc lxc.go:421 creating lxc container "juju-machine-1-lxc-0"

I think this is the same as the log when we don't have a default VPC. Will need to check that next.

[James Tunnicliffe (dooferlad)]

machine-0: 2015-09-24 11:29:44 INFO juju.provisioner.lxc lxc-broker.go:88 starting lxc container for machineId: 0/lxc/1
machine-0: 2015-09-24 11:29:44 DEBUG juju.provisioner lxc-broker.go:102 trying to allocate static IP for container "0/lxc/1"
machine-0: 2015-09-24 11:29:44 TRACE juju.provisioner lxc-broker.go:477 trying to discover primary network interface
machine-0: 2015-09-24 11:29:44 TRACE juju.provisioner lxc-broker.go:481 not using loopback interface "lo"
machine-0: 2015-09-24 11:29:44 TRACE juju.provisioner lxc-broker.go:487 verifying interface "eth0" has addresses
machine-0: 2015-09-24 11:29:44 TRACE juju.provisioner lxc-broker.go:506 primary network interface is "eth0", address "172.31.20.211"
machine-0: 2015-09-24 11:29:44 DEBUG juju.provisioner lxc-broker.go:549 trying to allocate a static IP for container "0/lxc/1"
machine-0: 2015-09-24 11:29:44 TRACE juju.apiserver apiserver.go:259 <- [2] machine-0 {"RequestId":560,"Type":"Provisioner","Version":1,"Request":"PrepareContainerInterfaceInfo","Params":{"Entities":[{"Tag":"machine-0-lxc-1"}]}}
machine-0: 2015-09-24 11:29:44 INFO juju.provider.ec2 provider.go:49 opening environment "tmpamz"
machine-0: 2015-09-24 11:29:44 TRACE juju.provider.ec2 environ.go:977 retrieving NICs for instance "i-9942b758"
machine-0: 2015-09-24 11:29:44 TRACE juju.provider.ec2 environ.go:981 instance "i-9942b758" NICs: &ec2.NetworkInterfacesResp{RequestId:"fefc34f8-1185-4a46-a1d6-95a38a98e515", Interfaces:[]ec2.NetworkInterface{ec2.NetworkInterface{Id:"eni-9414e8fc", SubnetId:"subnet-0fb97566", VPCId:"vpc-f8ea1191", AvailZone:"eu-central-1a", Description:"", OwnerId:"251147536467", RequesterId:"", RequesterManaged:false, Status:"in-use", MACAddress:"02:33:f8:06:29:8d", PrivateIPAddress:"172.31.20.211", PrivateDNSName:"ip-172-31-20-211.eu-central-1.compute.internal", SourceDestCheck:true, Groups:[]ec2.SecurityGroup{ec2.SecurityGroup{Id:"sg-aba13dc2", Name:"juju-tmpamz-0"}, ec2.SecurityGroup{Id:"sg-a8a13dc1", Name:"juju-tmpamz"}}, Attachment:ec2.NetworkInterfaceAttachment{Id:"eni-attach-f13670e4", InstanceId:"i-9942b758", InstanceOwnerId:"251147536467", DeviceIndex:0, Status:"attached", AttachTime:"2015-09-24T11:07:14.000Z", DeleteOnTermination:true}, Tags:[]ec2.Tag(nil), PrivateIPs:[]ec2.PrivateIP{ec2.PrivateIP{Address:"172.31.20.211", DNSName:"ip-172-31-20-211.eu-central-1.compute.internal", IsPrimary:true}}}}} (err: <nil>)
machine-0: 2015-09-24 11:29:44 TRACE juju.provider.ec2 environ.go:990 found instance "i-9942b758" NICS: []ec2.NetworkInterface{ec2.NetworkInterface{Id:"eni-9414e8fc", SubnetId:"subnet-0fb97566", VPCId:"vpc-f8ea1191", AvailZone:"eu-central-1a", Description:"", OwnerId:"251147536467", RequesterId:"", RequesterManaged:false, Status:"in-use", MACAddress:"02:33:f8:06:29:8d", PrivateIPAddress:"172.31.20.211", PrivateDNSName:"ip-172-31-20-211.eu-central-1.compute.internal", SourceDestCheck:true, Groups:[]ec2.SecurityGroup{ec2.SecurityGroup{Id:"sg-aba13dc2", Name:"juju-tmpamz-0"}, ec2.SecurityGroup{Id:"sg-a8a13dc1", Name:"juju-tmpamz"}}, Attachment:ec2.NetworkInterfaceAttachment{Id:"eni-attach-f13670e4", InstanceId:"i-9942b758", InstanceOwnerId:"251147536467", DeviceIndex:0, Status:"attached", ...

[James Tunnicliffe (dooferlad)]

Eugh, like breaks where they don't belong. The fragment as it should be is here: http://pastebin.ubuntu.com/12541155/

[Michael Foord (mfoord)]

apiserver/provisioner/provsioner.go:1139 - inside ProvisionerAPI.prepareAllocationNetwork calls environ.Subnets with an instance Id. For ec2 calling Subnets with anything other than instance.UnknownId is an error. provider/ec2/environ.go:1002 returns the "instId not supported" error.

So this code has never actually been tried with ec2. :-(

[Michael Foord (mfoord)]

On a separate note, that error you see in your second log "cannot allocate addresses: no interfaces available" is also worrying. Provisioning the container may have succeeded, but it looks to me like it didn't successfully get an IP address.

[James Tunnicliffe (dooferlad)]

The second note was an EC2 account without a default VPC, which we don't
support, right?

On Thu, Sep 24, 2015 at 4:30 PM, Michael Foord <email address hidden>
wrote:

> ** Changed in: juju-core
> Assignee: (unassigned) => Michael Foord (mfoord)
>
> ** Changed in: juju-core
> Importance: Undecided => Critical
>
> ** Changed in: juju-core
> Milestone: None => 1.25-beta2
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1498982
>
> Title:
> failed configuring a static IP for container "1/lxc/0": cannot
> allocate addresses: instId not supported
>
> Status in juju-core:
> New
>
> Bug description:
> On amazon I get the following error in the Juju logs:
>
> machine-1[5563]: 2015-09-23 15:33:21 INFO juju.worker runner.go:269
> start "lxc-provisioner"
> machine-1[5563]: 2015-09-23 15:33:21 INFO juju.worker runner.go:275
> stopped "1-container-watcher", err: <nil>
> machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner
> provisioner_task.go:138 Starting up provisioner task machine-1
> machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner
> provisioner_task.go:408 found machine pending provisioning id:1/lxc/0,
> details:1/lxc/0
> machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner
> provisioner_task.go:253 provisioner-harvest-mode is set to destroyed;
> unknown instances not stopped []
> machine-1[5563]: 2015-09-23 15:33:21 INFO juju.provisioner.lxc
> lxc-broker.go:88 starting lxc container for machineId: 1/lxc/0
> machine-1[5563]: 2015-09-23 15:33:22 WARNING juju.provisioner
> lxc-broker.go:532 failed configuring a static IP for container "1/lxc/0":
> cannot allocate addresses: instId not supported
> machine-1[5563]: 2015-09-23 15:33:22 INFO juju.provisioner
> lxc-broker.go:114 not allocating static IP for container "1/lxc/0": cannot
> allocate addresses: instId not supported
>
> It looks like this is to do with the interaction with the recent
> subnets and spaces code changes and the older container logic. I don't
> get the error on MAAS.
>
> Currently rewinding through commits to see if/when the error goes
> away.
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/juju-core/+bug/1498982/+subscriptions
>

[Michael Foord (mfoord)]

Fix here, manually confirmed to work:
https://github.com/juju/juju/compare/1.25...voidspace:ec2-subnets-1498982-1.25

Needs some tests and I'll propose it and forward port to master.