juju-deployer reports that config specifies num units for subordinate when it doesn't

[Alex Iannicelli]

I am deploying openstack over and over to a large scale system setup and I keep seeing this message:

Config specifies num units for subordinate: <some subordinate unit>

The message is not a big deal, but what is more important is that it seems to delay the deploy of the unit by about 30 seconds. This massively affects the time it takes to deploy a large scale setup and has affected the ability to test other deployment tests.

Here is an example of what I see (keep in mind that for each of these messages I see a 30-60 second pause before the message is displayed.

2015-09-24 14:45:14 Connecting to environment...
2015-09-24 14:45:15 Connected to environment
2015-09-24 14:45:15 Deploying services...
2015-09-24 14:45:15 <deployer.env.go.GoEnvironment object at 0x7f5f470d7b90>
2015-09-24 14:45:15 Service 'ceilometer-agent' already deployed. Skipping
2015-09-24 14:45:15 Service 'ceph-osd' already deployed. Skipping
2015-09-24 14:45:15 Service 'cinder-ceph' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-ceilometer' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-cinder' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-glance' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-horizon' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-keystone' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-neutron' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-nova' already deployed. Skipping
2015-09-24 14:45:15 Service 'hacluster-pxc' already deployed. Skipping
2015-09-24 14:45:15 Service 'neutron-gateway' already deployed. Skipping
2015-09-24 14:45:15 Service 'neutron-openvswitch' already deployed. Skipping
2015-09-24 14:45:15 Service 'nodes-api' already deployed. Skipping
2015-09-24 14:45:15 Service 'nova-compute' already deployed. Skipping
2015-09-24 14:45:15 Service 'ntp' already deployed. Skipping
2015-09-24 14:45:15 Service 'rsyslog-forwarder' already deployed. Skipping
2015-09-24 14:45:15 Service 'ceilometer' already deployed. Skipping
2015-09-24 14:45:15 Service 'ceph' already deployed. Skipping
2015-09-24 14:45:15 Service 'cinder' already deployed. Skipping
2015-09-24 14:45:15 Service 'glance' already deployed. Skipping
2015-09-24 14:45:15 Service 'keystone' already deployed. Skipping
2015-09-24 14:45:15 Service 'keystone-percona' already deployed. Skipping
2015-09-24 14:45:15 Service 'memcached' already deployed. Skipping
2015-09-24 14:45:15 Service 'mongodb' already deployed. Skipping
2015-09-24 14:45:15 Service 'neutron-api' already deployed. Skipping
2015-09-24 14:45:15 Service 'nova-cloud-controller' already deployed. Skipping
2015-09-24 14:45:15 Service 'openstack-dashboard' already deployed. Skipping
2015-09-24 14:45:15 Service 'percona-cluster' already deployed. Skipping
2015-09-24 14:45:15 Service 'rabbitmq-server' already deployed. Skipping
2015-09-24 14:45:15 Service 'rsyslog' already deployed. Skipping
2015-09-24 14:45:20 Adding units...
2015-09-24 14:46:22 Service: ceilometer-agent has neither charm url or branch specified
2015-09-24 14:46:22 Config specifies num units for subordinate: ceilometer-agent
2015-09-24 14:46:22 Service 'ceph-osd' does not need any more units added.
2015-09-24 14:47:24 Service: cinder-ceph has neither charm url or branch specified
2015-09-24 14:47:24 Config specifies num units for subordinate: cinder-ceph
2015-09-24 14:48:26 Service: hacluster has neither charm url or branch specified
2015-09-24 14:48:26 Config specifies num units for subordinate: hacluster-ceilometer
2015-09-24 14:49:28 Service: hacluster has neither charm url or branch specified
2015-09-24 14:49:28 Config specifies num units for subordinate: hacluster-cinder
2015-09-24 14:50:30 Service: hacluster has neither charm url or branch specified
2015-09-24 14:50:30 Config specifies num units for subordinate: hacluster-glance
2015-09-24 14:51:32 Service: hacluster has neither charm url or branch specified
2015-09-24 14:51:32 Config specifies num units for subordinate: hacluster-horizon
2015-09-24 14:52:34 Service: hacluster has neither charm url or branch specified
2015-09-24 14:52:34 Config specifies num units for subordinate: hacluster-keystone
2015-09-24 14:53:36 Service: hacluster has neither charm url or branch specified
2015-09-24 14:53:36 Config specifies num units for subordinate: hacluster-neutron
2015-09-24 14:54:38 Service: hacluster has neither charm url or branch specified
2015-09-24 14:54:38 Config specifies num units for subordinate: hacluster-nova
2015-09-24 14:55:40 Service: hacluster has neither charm url or branch specified
2015-09-24 14:55:40 Config specifies num units for subordinate: hacluster-pxc
2015-09-24 14:55:40 Service 'neutron-gateway' does not need any more units added.
2015-09-24 14:56:42 Service: neutron-openvswitch has neither charm url or branch specified
2015-09-24 14:56:42 Config specifies num units for subordinate: neutron-openvswitch
2015-09-24 14:56:42 Service: ubuntu has neither charm url or branch specified

here is an example of one of the subordinate unit's yaml description:

   "ceilometer-agent":
      charm: "local:trusty/ceilometer-agent"

and here are my overrides just in case that has some affect:

  overrides:
    "openstack-origin": "cloud:trusty-juno"
    source: "cloud:trusty-juno"
    use-syslog: "true"
    corosync_transport: "unicast"
    cluster_count: 3
    data-port: eth1
    network-device-mtu: 2500

juju-deployer version: 0.5.2-1
juju version: 1.24.5-trusty-amd64

[Jorge Niedbalski (niedbalski)]

This bug seems to be related to https://bugs.launchpad.net/juju-deployer/+bug/1421315

Particularly, this code

        # Workaround an issue where watch output doesn't include subordinate
        # services right away, and add_unit would fail while attempting to add
        # units to a non-existant service. See lp:1421315 for details.
        cur_units = 0
        for svc in self.deployment.get_services():
            delay = time.time() + 60
            while delay > time.time():
                if svc.name in env_status['services']:
                    cur_units = len(
                        env_status['services'][svc.name].get('units', ())
                    )
                    if cur_units > 0:
                        break
                time.sleep(5)
                env_status = self.env.status()

Was added as a workaround, so can you point on the bug description which Juju versions are you using?

[Alex Iannicelli (atiannicelli)]

Upgraded juju to 1.24.6 and I don't see the message anymore. I still see a 1 minute pause in between each unit getting added (when the units are already there.... Notice times below:

2015-09-25 09:17:31 Adding units...
2015-09-25 09:17:31 Service 'ceilometer-agent' does not need any more units added.
2015-09-25 09:17:31 Service 'ceph-osd' does not need any more units added.
2015-09-25 09:18:33 Service: cinder-ceph has neither charm url or branch specified
2015-09-25 09:18:33 Config specifies num units for subordinate: cinder-ceph
2015-09-25 09:19:36 Service: hacluster has neither charm url or branch specified
2015-09-25 09:19:36 Config specifies num units for subordinate: hacluster-ceilometer

Any idea what the 1 minute and 3 seconds is caused by?

[Alex Iannicelli (atiannicelli)]

Obviously I'm not awake yet. The comment above shows that I am still seeing the "Config specifies num units for subordinate" message and seeing the delay even after upgrading to 1.24.6

[Alvaro Uria (aluria)]

Hi,

FWIW, it still happens in:

ii juju-core 1.25.0-0ubuntu1~14.04.1~juju1 amd64 Juju is devops distilled - client
ii juju-deployer 0.6.0-1 all Deploy complex stacks of services using Juju

Cheers,
-Alvaro.