octavia super slow install in focal

Bug #1884449 reported by Marian Gasparovic
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Octavia Charm
Fix Released
Undecided
Alex Kavanagh

Bug Description

When I install focal-ussuri, octavia takes over 4 hours to install, just charm install part, before joining relations. It happens every single time, not just one time event.

Here is the sample bundle to demonstrate.

applications:
  ceph-osd:
    bindings: {? '' : oam-space, cluster: ceph-replica-space, mon: ceph-access-space,
      public: ceph-access-space, secrets-storage: internal-space}
    charm: cs:ceph-osd
    num_units: 1
    options: {aa-profile-mode: complain, autotune: false, bluestore: true, customize-failure-domain: true,
      osd-devices: /dev/disk/by-dname/bcache1, osd-encrypt: true, osd-encrypt-keymanager: vault,
      source: distro}
    to: ['1003']
  hacluster-octavia:
    charm: cs:hacluster
    options: {cluster_count: 1}
  octavia:
    bindings: {? '' : oam-space, admin: internal-space, internal: internal-space,
      public: public-space}
    charm: cs:octavia
    num_units: 1
    options: {lb-mgmt-controller-cacert: 'include-base64://../ssl/octavia/controller_ca.pem',
      lb-mgmt-controller-cert: 'include-base64://../ssl/octavia/controller_cert_bundle.pem',
      lb-mgmt-issuing-ca-key-passphrase: foobar, lb-mgmt-issuing-ca-private-key: 'include-base64://../ssl/octavia/controller_ca_key.pem',
      lb-mgmt-issuing-cacert: 'include-base64://../ssl/octavia/controller_ca.pem',
      loadbalancer-topology: ACTIVE_STANDBY, openstack-origin: distro, spare-pool-size: 2,
      vip: 10.244.8.94 192.168.33.17}
    to: ['lxd:1003']
machines:
  '1003': {constraints: tags=foundation-nodes zones=zone1}
relations:
- [octavia, hacluster-octavia]
series: focal
variables: {}

2020-06-21 09:34:37 DEBUG juju-log Running the apt-get install command as .is-git-installed not set
2020-06-21 09:34:37 DEBUG install Reading package lists...
2020-06-21 09:34:37 DEBUG install Building dependency tree...
2020-06-21 09:34:37 DEBUG install Reading state information...
...
2020-06-21 14:02:26 DEBUG install Successfully installed Babel-2.8.0 Jinja2-2.11.2 Mako-1.1.2 MarkupSafe-1.1.1 Paste-3.4.0 PasteDeploy-2.1.0 PyYAML-5.3.1 Routes-2.4.1 SQLAlchemy-1.3.17 Tempita-0.5.2 WebOb-1.8.6 WebTest-2.0.35 alembic-1.4.2 amqp-2.5.2 appdirs-1.4.4 argparse-1.4.0 beautifulsoup4-4.9.1 cachetools-4.1.0 certifi-2020.4.5.1 cffi-1.14.0 chardet-3.0.4 charmhelpers-0.20.14 charms.openstack-0.0.1.dev1 charms.reactive-1.3.0 cliff-3.1.0 cmd2-0.8.9 cryptography-2.9.2 debtcollector-1.22.0 decorator-4.4.2 dnspython-1.16.0 dogpile.cache-0.9.2 eventlet-0.25.2 extras-1.0.0 fasteners-0.15 fixtures-3.0.0 futurist-1.10.0 greenlet-0.4.15 idna-2.9 importlib-metadata-1.6.0 iso8601-0.1.12 jmespath-0.10.0 jsonpatch-1.25 jsonpointer-2.0 keystoneauth1-4.0.0 kombu-4.6.8 linecache2-1.0.0 logutils-0.3.5 monotonic-1.5 msgpack-1.0.0 munch-2.5.0 netaddr-0.7.19 netifaces-0.10.9 neutron-lib-1.31.0 openstacksdk-0.46.0 os-client-config-2.1.0 os-ken-0.4.1 os-service-types-1.7.0 os-traits-2.2.0 osc-lib-2.0.0 oslo.concurrency-3.31.0 oslo.config-7.0.0 oslo.context-2.23.0 oslo.db-6.0.0 oslo.i18n-3.25.1 oslo.log-3.45.2 oslo.messaging-10.5.0 oslo.middleware-3.38.1 oslo.policy-2.4.1 oslo.serialization-2.29.2 oslo.service-1.41.1 oslo.utils-3.42.1 oslo.versionedobjects-1.37.0 osprofiler-2.9.0 ovs-2.13.0 pbr-5.4.5 pecan-1.3.3 prettytable-0.7.2 psutil-5.7.0 pyaml-20.4.0 pycparser-2.20 pyinotify-0.9.6 pyparsing-2.4.2 pyperclip-1.8.0 pytest-runner-5.2 python-dateutil-2.8.1 python-editor-1.0.4 python-keystoneclient-3.22.0 python-mimeparse-1.6.0 python-neutronclient-7.1.0 python-novaclient-16.0.0 pytz-2020.1 repoze.lru-0.7 requests-2.23.0 requestsexceptions-1.4.0 rfc3986-1.4.0 setproctitle-1.1.10 simplejson-3.17.0 six-1.15.0 sortedcontainers-2.1.0 soupsieve-2.0.1 sqlalchemy-migrate-0.13.0 sqlparse-0.3.1 statsd-3.3.0 stevedore-1.32.0 testresources-2.0.1 testscenarios-0.5.0 testtools-2.4.0 tinyrpc-1.0.4 traceback2-1.4.0 unittest2-1.1.0 urllib3-1.25.9 vine-1.3.0 waitress-1.4.3 wcwidth-0.1.9 wheel-0.33.6 wrapt-1.12.1 yappi-1.2.5 zipp-1.2.0
2020-06-21 14:02:27 INFO juju-log Reactive main running for hook install
2020-06-21 14:02:29 INFO juju-log Initializing Leadership Layer (is leader)
2020-06-21 14:02:29 DEBUG juju-log tracer: set flag leadership.is_leader
2020-06-21 14:02:29 DEBUG juju-log tracer>
tracer: starting handler dispatch, 93 flags set
tracer: set flag charms.openstack.do-default-amqp.connected
tracer: set flag charms.openstack.do-default-certificates.available
tracer: set flag charms.openstack.do-default-charm.installed

Timestamps show 4.5 hours passed.

Same bundle with bionic-ussuri

applications:
  ceph-osd:
    bindings: {? '' : oam-space, cluster: ceph-replica-space, mon: ceph-access-space,
      public: ceph-access-space, secrets-storage: internal-space}
    charm: cs:ceph-osd
    num_units: 1
    options: {aa-profile-mode: complain, autotune: false, bluestore: true, customize-failure-domain: true,
      osd-devices: /dev/disk/by-dname/bcache1, osd-encrypt: true, osd-encrypt-keymanager: vault,
      source: distro}
    to: ['1003']
  hacluster-octavia:
    charm: cs:hacluster
    options: {cluster_count: 1}
  octavia:
    bindings: {? '' : oam-space, admin: internal-space, internal: internal-space,
      public: public-space}
    charm: cs:octavia
    num_units: 1
    options: {lb-mgmt-controller-cacert: 'include-base64://../ssl/octavia/controller_ca.pem',
      lb-mgmt-controller-cert: 'include-base64://../ssl/octavia/controller_cert_bundle.pem',
      lb-mgmt-issuing-ca-key-passphrase: foobar, lb-mgmt-issuing-ca-private-key: 'include-base64://../ssl/octavia/controller_ca_key.pem',
      lb-mgmt-issuing-cacert: 'include-base64://../ssl/octavia/controller_ca.pem',
      loadbalancer-topology: ACTIVE_STANDBY, openstack-origin: "cloud:bionic-ussuri", spare-pool-size: 2,
      vip: 10.244.8.94 192.168.33.17}
    to: ['lxd:1003']
machines:
  '1003': {constraints: tags=foundation-nodes zones=zone1}
relations:
- [octavia, hacluster-octavia]
series: bionic
variables: {}

takes 5 minutes

2020-06-21 14:59:18 DEBUG juju-log Running the apt-get install command as .is-git-installed not set
2020-06-21 14:59:18 DEBUG install Reading package lists...
2020-06-21 14:59:18 DEBUG install Building dependency tree...
2020-06-21 14:59:18 DEBUG install Reading state information...
2020-06-21 14:59:18 DEBUG install git is already the newest version (1:2.17.1-1ubuntu0.7).
2020-06-21 14:59:18 DEBUG install git set to manually installed.
...
2020-06-21 15:03:58 INFO juju-log Reactive main running for hook install
2020-06-21 15:04:00 INFO juju-log Initializing Leadership Layer (is leader)
2020-06-21 15:04:00 DEBUG juju-log tracer: set flag leadership.is_leader
2020-06-21 15:04:00 DEBUG juju-log tracer>
tracer: starting handler dispatch, 92 flags set

Revision history for this message
Marian Gasparovic (marosg) wrote :
Revision history for this message
Marian Gasparovic (marosg) wrote :

just to be clear, I see this only in octavia charm, all other charms install in reasonable time frames

Revision history for this message
Marian Gasparovic (marosg) wrote :

Look at Processing ./wheelhouse/oslo.*
It always takes 6 minutes and 9-11 seconds, always.

2020-06-22 09:00:39 DEBUG install Successfully built setuptools-scm
2020-06-22 09:00:39 DEBUG install Installing collected packages: setuptools-scm
2020-06-22 09:00:39 DEBUG install Successfully installed setuptools-scm-1.17.0
2020-06-22 09:00:40 DEBUG install Looking in links: wheelhouse
2020-06-22 09:00:40 DEBUG install Processing ./wheelhouse/importlib_metadata-1.6.1.tar.gz
2020-06-22 09:00:40 DEBUG install Installing build dependencies: started
2020-06-22 09:00:44 DEBUG install Installing build dependencies: finished with status 'done'
2020-06-22 09:00:44 DEBUG install Getting requirements to build wheel: started
2020-06-22 09:00:44 DEBUG install Getting requirements to build wheel: finished with status 'done'
2020-06-22 09:00:44 DEBUG install Preparing wheel metadata: started
2020-06-22 09:00:44 DEBUG install Preparing wheel metadata: finished with status 'done'
2020-06-22 09:00:44 DEBUG install Processing ./wheelhouse/oslo.policy-2.4.1.tar.gz
2020-06-22 09:06:55 DEBUG install Processing ./wheelhouse/ovs-2.13.0.tar.gz
2020-06-22 09:06:56 DEBUG install Processing ./wheelhouse/oslo.config-7.0.0.tar.gz
2020-06-22 09:13:05 DEBUG install Processing ./wheelhouse/waitress-1.4.4.tar.gz
2020-06-22 09:13:05 DEBUG install Installing build dependencies: started
2020-06-22 09:13:07 DEBUG install Installing build dependencies: finished with status 'done'
2020-06-22 09:13:07 DEBUG install Getting requirements to build wheel: started
2020-06-22 09:13:07 DEBUG install Getting requirements to build wheel: finished with status 'done'
2020-06-22 09:13:07 DEBUG install Installing backend dependencies: started
2020-06-22 09:13:08 DEBUG install Installing backend dependencies: finished with status 'done'
2020-06-22 09:13:08 DEBUG install Preparing wheel metadata: started
2020-06-22 09:13:09 DEBUG install Preparing wheel metadata: finished with status 'done'
2020-06-22 09:13:09 DEBUG install Processing ./wheelhouse/oslo.middleware-3.38.1.tar.gz
2020-06-22 09:19:18 DEBUG install Processing ./wheelhouse/oslo.utils-3.42.1.tar.gz
2020-06-22 09:25:28 DEBUG install Processing ./wheelhouse/cffi-1.14.0.tar.gz
2020-06-22 09:25:28 DEBUG install Processing ./wheelhouse/oslo.messaging-10.5.0.tar.gz

Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :
Download full text (4.8 KiB)

After a quick initial look at the logs, it stalled during the unpacking of the wheelhouse; it seems that the extract/install of the wheelhouse items took a LONG time (some 5-10 minutes each). Octavia was being installed in a LXD container.

It looks like each ceph-osd "update-status" hook 'stalled' the octavia install:

unit-octavia-0: 09:54:02 DEBUG unit.octavia/0.install Processing ./wheelhouse/python-neutronclient-7.1.0.tar.gz
unit-ceph-osd-0: 09:56:40 DEBUG unit.ceph-osd/0.juju-log Hardening function 'update_status'
unit-ceph-osd-0: 09:56:41 DEBUG unit.ceph-osd/0.juju-log No hardening applied to 'update_status'
unit-ceph-osd-0: 09:56:41 INFO unit.ceph-osd/0.juju-log Updating status.
unit-ceph-osd-0: 09:56:41 INFO juju.worker.uniter.operation ran "update-status" hook
unit-octavia-0: 10:00:11 DEBUG unit.octavia/0.install Processing ./wheelhouse/netifaces-0.10.9.tar.gz
unit-octavia-0: 10:00:12 DEBUG unit.octavia/0.install Processing ./wheelhouse/oslo.config-7.0.0.tar.gz
unit-ceph-osd-0: 10:02:34 DEBUG unit.ceph-osd/0.juju-log Hardening function 'update_status'
unit-ceph-osd-0: 10:02:34 DEBUG unit.ceph-osd/0.juju-log No hardening applied to 'update_status'
unit-ceph-osd-0: 10:02:34 INFO unit.ceph-osd/0.juju-log Updating status.
unit-ceph-osd-0: 10:02:35 INFO juju.worker.uniter.operation ran "update-status" hook
unit-octavia-0: 10:06:21 DEBUG unit.octavia/0.install Processing ./wheelhouse/pecan-1.3.3.tar.gz
unit-octavia-0: 10:06:21 DEBUG unit.octavia/0.install Processing ./wheelhouse/charms.reactive-1.3.0.tar.gz
unit-octavia-0: 10:06:22 DEBUG unit.octavia/0.install Processing ./wheelhouse/cffi-1.14.0.tar.gz
unit-octavia-0: 10:06:22 DEBUG unit.octavia/0.install Processing ./wheelhouse/osc-lib-2.0.0.tar.gz
unit-ceph-osd-0: 10:07:37 DEBUG unit.ceph-osd/0.juju-log Hardening function 'update_status'
unit-ceph-osd-0: 10:07:37 DEBUG unit.ceph-osd/0.juju-log No hardening applied to 'update_status'
unit-ceph-osd-0: 10:07:37 INFO unit.ceph-osd/0.juju-log Updating status.
unit-ceph-osd-0: 10:07:38 INFO juju.worker.uniter.operation ran "update-status" hook
unit-octavia-0: 10:12:31 DEBUG unit.octavia/0.install Processing ./wheelhouse/monotonic-1.5.tar.gz
unit-octavia-0: 10:12:31 DEBUG unit.octavia/0.install Processing ./wheelhouse/jmespath-0.10.0.tar.gz
unit-octavia-0: 10:12:32 DEBUG unit.octavia/0.install Processing ./wheelhouse/os-service-types-1.7.0.tar.gz
unit-ceph-osd-0: 10:13:02 DEBUG unit.ceph-osd/0.juju-log Hardening function 'update_status'
unit-ceph-osd-0: 10:13:02 DEBUG unit.ceph-osd/0.juju-log No hardening applied to 'update_status'
unit-ceph-osd-0: 10:13:03 INFO unit.ceph-osd/0.juju-log Updating status.
unit-ceph-osd-0: 10:13:03 INFO juju.worker.uniter.operation ran "update-status" hook
unit-ceph-osd-0: 10:18:33 DEBUG unit.ceph-osd/0.juju-log Hardening function 'update_status'
unit-ceph-osd-0: 10:18:33 DEBUG unit.ceph-osd/0.juju-log No hardening applied to 'update_status'
unit-ceph-osd-0: 10:18:33 INFO unit.ceph-osd/0.juju-log Updating status.
unit-ceph-osd-0: 10:18:34 INFO juju.worker.uniter.operation ran "update-status" hook
unit-octavia-0: 10:18:41 DEBUG unit.octavia/0.install Processing ./wheelhouse/PasteDeploy-2.1.0.tar.gz
unit-octavia-0...

Read more...

Changed in charm-octavia:
status: New → Incomplete
Revision history for this message
Marian Gasparovic (marosg) wrote :

Alex, both bundles are provided in the report.
Juju is 2.7.6 from 2.7/stable snap

Michael Skalka (mskalka)
Changed in charm-octavia:
status: Incomplete → New
Revision history for this message
Marian Gasparovic (marosg) wrote :

As suggested by OpenStack team, this was caused by an issue with layer:basic which causes packages being installed from a wheel to occasionally reach out to pypi even if all the data is in the wheel. When firewall allowed to access pypi, installation took just couple of minutes.

Revision history for this message
Michael Skalka (mskalka) wrote :

Subbing field High. While the suggested workaround worked, this will block deployment in our production lab and 95% of customer sites.

Michael Skalka (mskalka)
tags: added: cdo-release-blocker
Changed in charm-octavia:
assignee: nobody → Alex Kavanagh (ajkavanagh)
Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

Fix is in layer basic: https://github.com/juju-solutions/layer-basic/pull/184 -- just waiting for it to be merged, and then octavia can be rebuilt.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to charm-octavia (master)

Fix proposed to branch: master
Review: https://review.opendev.org/743987

Changed in charm-octavia:
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on charm-octavia (master)

Change abandoned by Alex Kavanagh (tinwood) (<email address hidden>) on branch: master
Review: https://review.opendev.org/743987
Reason: Abandoning in favour of https://review.opendev.org/#/c/744099 which will do the rebuild anyway.

Revision history for this message
Alex Kavanagh (ajkavanagh) wrote :

This https://review.opendev.org/#/c/744099 will cause the rebuild and fix this bug.

Changed in charm-octavia:
status: In Progress → Fix Committed
James Page (james-page)
Changed in charm-octavia:
milestone: none → 20.08
Changed in charm-octavia:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.