Prometheus Charm

charm install can fail due to configure_storage not being gated on install hook completion

Bug #1714546 reported by Tom Haddon
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Prometheus Charm
Triaged
High
Unassigned

Bug Description

We're seeing the following in CI:

....
2017-09-01 15:36:57 DEBUG metrics-filesystem-storage-attached Collecting pip
2017-09-01 15:36:57 DEBUG metrics-filesystem-storage-attached Building wheels for collected packages: pip
2017-09-01 15:36:57 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for pip: started
2017-09-01 15:36:58 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for pip: finished with status 'done'
2017-09-01 15:36:58 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/8f/99/55/2748f62b4bb1760281b0483d5eb27ee0a9397e317d15f3dbbe
2017-09-01 15:36:58 DEBUG metrics-filesystem-storage-attached Successfully built pip
2017-09-01 15:36:58 DEBUG metrics-filesystem-storage-attached Installing collected packages: pip
2017-09-01 15:36:58 DEBUG metrics-filesystem-storage-attached Found existing installation: pip 8.1.1
2017-09-01 15:36:58 DEBUG metrics-filesystem-storage-attached Not uninstalling pip at /usr/lib/python3/dist-packages, outside environment /usr
2017-09-01 15:36:59 DEBUG metrics-filesystem-storage-attached Successfully installed pip-8.1.2
2017-09-01 15:36:59 DEBUG metrics-filesystem-storage-attached Ignoring indexes: https://pypi.python.org/simple
2017-09-01 15:36:59 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/Jinja2-2.9.6.tar.gz
2017-09-01 15:36:59 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/PyYAML-3.12.tar.gz
2017-09-01 15:37:00 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/MarkupSafe-1.0.tar.gz
2017-09-01 15:37:00 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/pip-8.1.2.tar.gz
2017-09-01 15:37:00 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/six-1.10.0.tar.gz
2017-09-01 15:37:00 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/Tempita-0.5.2.tar.gz
2017-09-01 15:37:01 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/charms.reactive-0.4.7.tar.gz
2017-09-01 15:37:01 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/charmhelpers-0.17.0.tar.gz
2017-09-01 15:37:01 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/netaddr-0.7.19.tar.gz
2017-09-01 15:37:02 DEBUG metrics-filesystem-storage-attached Processing ./wheelhouse/pyaml-16.12.2.tar.gz
2017-09-01 15:37:02 DEBUG metrics-filesystem-storage-attached Collecting MarkupSafe>=0.23 (from Jinja2==2.9.6)
2017-09-01 15:37:02 DEBUG metrics-filesystem-storage-attached Collecting pyaml (from charms.reactive==0.4.7)
2017-09-01 15:37:02 DEBUG metrics-filesystem-storage-attached Collecting charmhelpers>=0.5.0 (from charms.reactive==0.4.7)
2017-09-01 15:37:03 DEBUG metrics-filesystem-storage-attached Collecting netaddr (from charmhelpers==0.17.0)
2017-09-01 15:37:03 DEBUG metrics-filesystem-storage-attached Building wheels for collected packages: Jinja2, MarkupSafe, PyYAML, pip, six, Tempita, charms.reactive, pyaml, charmhelpers, netaddr
2017-09-01 15:37:03 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for Jinja2: started
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for Jinja2: finished with status 'done'
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/52/3d/13/4a245579846212c27bf7edec0079c05e2afaf1a29f14b30cfb
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for MarkupSafe: started
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for MarkupSafe: finished with status 'done'
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/ad/d4/49/3e7561c91a648e8b017ea1d1b99fd6abb09ef44f8f563a7458
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for PyYAML: started
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for PyYAML: finished with status 'done'
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/78/b9/7b/20138ca3b0c997b7aa8a66e7b0ca720d50553456901a79c427
2017-09-01 15:37:04 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for pip: started
2017-09-01 15:37:05 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for pip: finished with status 'done'
2017-09-01 15:37:05 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/8f/99/55/2748f62b4bb1760281b0483d5eb27ee0a9397e317d15f3dbbe
2017-09-01 15:37:05 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for six: started
2017-09-01 15:37:05 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for six: finished with status 'done'
2017-09-01 15:37:05 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/d4/36/51/4b796a3ac29bddbe7ed05bd57b8007b3e862447d708f8da8f9
2017-09-01 15:37:05 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for Tempita: started
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for Tempita: finished with status 'done'
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/5a/83/2c/0d61af6310bbb498e2ccc58d73f95f76115aebbecf413396e2
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for charms.reactive: started
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for charms.reactive: finished with status 'done'
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/79/3a/7c/db2b7f13be86476eef2dffd7d26e26e3cd7fbd9ac6f100b4be
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for pyaml: started
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for pyaml: finished with status 'done'
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/ad/fa/91/1ec75f40256a7ee08eaa20e58e8e6db4a63d4c44f073a5818f
2017-09-01 15:37:07 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for charmhelpers: started
2017-09-01 15:37:08 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for charmhelpers: finished with status 'done'
2017-09-01 15:37:08 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/50/42/e0/a303ee0cb37788cf2715adb6057b54f62d3cefbf702ebebe31
2017-09-01 15:37:08 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for netaddr: started
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Running setup.py bdist_wheel for netaddr: finished with status 'done'
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Stored in directory: /root/.cache/pip/wheels/35/dc/dd/8db94be2372798cea3a3c619b0a29bf8e428504a1731979adb
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Successfully built Jinja2 MarkupSafe PyYAML pip six Tempita charms.reactive pyaml charmhelpers netaddr
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Installing collected packages: MarkupSafe, Jinja2, PyYAML, pip, six, Tempita, pyaml, netaddr, charmhelpers, charms.reactive
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Found existing installation: MarkupSafe 0.23
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Uninstalling MarkupSafe-0.23:
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Successfully uninstalled MarkupSafe-0.23
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Found existing installation: Jinja2 2.8
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Uninstalling Jinja2-2.8:
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Successfully uninstalled Jinja2-2.8
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Found existing installation: PyYAML 3.11
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached DEPRECATION: Uninstalling a distutils installed project (PyYAML) has been deprecated and will be removed in a future version. This is due to the fact that uninstalling a distutils project will only partially uninstall the project.
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Uninstalling PyYAML-3.11:
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Successfully uninstalled PyYAML-3.11
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Found existing installation: pip 8.1.2
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Uninstalling pip-8.1.2:
2017-09-01 15:37:09 DEBUG metrics-filesystem-storage-attached Successfully uninstalled pip-8.1.2
2017-09-01 15:37:10 DEBUG metrics-filesystem-storage-attached Found existing installation: six 1.10.0
2017-09-01 15:37:10 DEBUG metrics-filesystem-storage-attached Uninstalling six-1.10.0:
2017-09-01 15:37:10 DEBUG metrics-filesystem-storage-attached Successfully uninstalled six-1.10.0
2017-09-01 15:37:10 DEBUG metrics-filesystem-storage-attached Successfully installed Jinja2-2.9.6 MarkupSafe-1.0 PyYAML-3.12 Tempita-0.5.2 charmhelpers-0.17.0 charms.reactive-0.4.7 netaddr-0.7.19 pip-8.1.2 pyaml-16.12.2 six-1.10.0
2017-09-01 15:37:11 INFO juju-log Reactive main running for hook metrics-filesystem-storage-attached
2017-09-01 15:37:11 INFO juju-log Initializing Snap Layer
2017-09-01 15:37:11 DEBUG metrics-filesystem-storage-attached none
2017-09-01 15:37:11 INFO juju-log Making dir /etc/systemd/system/snapd.service.d root:root 555
2017-09-01 15:37:11 INFO juju-log Writing file /etc/systemd/system/snapd.service.d/snap_layer_proxy.conf root:root 444
2017-09-01 15:37:13 INFO juju-log Invoking reactive handler: reactive/prometheus.py:141:configure_storage
2017-09-01 15:37:13 DEBUG juju-log No daemon args in config
2017-09-01 15:37:13 INFO juju-log Invoking reactive handler: reactive/prometheus.py:414:check_reconfig_prometheus
2017-09-01 15:37:13 DEBUG juju-log No daemon args in config
2017-09-01 15:37:13 INFO juju-log One of options affecting daemon args has changed, scheduling reconfiguration
2017-09-01 15:37:13 INFO juju-log CLI flags have change, scheduling reconfiguration
2017-09-01 15:37:13 INFO juju-log Daemon flags template changed, scheduling reconfiguration
2017-09-01 15:37:13 INFO juju-log Invoking reactive handler: reactive/prometheus.py:397:setup_prometheus
2017-09-01 15:37:13 INFO juju-log Invoking reactive handler: reactive/prometheus.py:285:write_prometheus_config_yml
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached Traceback (most recent call last):
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/var/lib/juju/agents/unit-prometheus-0/charm/hooks/metrics-filesystem-storage-attached", line 19, in <module>
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached main()
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/local/lib/python3.5/dist-packages/charms/reactive/__init__.py", line 78, in main
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached bus.dispatch()
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/local/lib/python3.5/dist-packages/charms/reactive/bus.py", line 423, in dispatch
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached _invoke(other_handlers)
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/local/lib/python3.5/dist-packages/charms/reactive/bus.py", line 406, in _invoke
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached handler.invoke()
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/local/lib/python3.5/dist-packages/charms/reactive/bus.py", line 280, in invoke
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached self._action(*args)
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/var/lib/juju/agents/unit-prometheus-0/charm/reactive/prometheus.py", line 290, in write_prometheus_config_yml
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached ver_major, ver_minor, ver_patch = get_version()
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/var/lib/juju/agents/unit-prometheus-0/charm/reactive/prometheus.py", line 262, in get_version
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached output = subprocess.check_output([get_paths()['promtool'], 'version']).split(b'\n')[0]
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/lib/python3.5/subprocess.py", line 626, in check_output
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached **kwargs).stdout
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/lib/python3.5/subprocess.py", line 693, in run
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached with Popen(*popenargs, **kwargs) as process:
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/lib/python3.5/subprocess.py", line 947, in __init__
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached restore_signals, start_new_session)
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached File "/usr/lib/python3.5/subprocess.py", line 1551, in _execute_child
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached raise child_exception_type(errno_num, err_msg)
2017-09-01 15:37:13 DEBUG metrics-filesystem-storage-attached FileNotFoundError: [Errno 2] No such file or directory: '/snap/bin/prometheus.promtool'
2017-09-01 15:37:13 ERROR juju.worker.uniter.operation runhook.go:107 hook "metrics-filesystem-storage-attached" failed: exit status 1

This is because configure_storage is not gated on install hook completion.

Revision history for this message
Jacek Nykis (jacekn) wrote :

Storage hooks run before install so we will always hit this when using juju storage.

It is a bit tricky because we set "prometheus.do-install" state when "install" hooks is triggered but we also gate "check_reconfig_prometheus" on @when_not('prometheus.do-install')

So what I think is happening is that storage hooks run, set prometheus.do-check-reconfig state which then triggers check_reconfig_prometheus function _before_ install hook has time to set "prometheus.do-install".

I _think_ the fix is to simply remove "set_state('prometheus.do-check-reconfig')" from the "configure_storage()" function but please double check my logic.

Changed in prometheus-charm:
status: New → Triaged
importance: Undecided → High
Revision history for this message
Stuart Bishop (stub) wrote :

Recommended fix would be to not use the @hook('install') decorator, and instead use normal states.

Instead of:

@when('prometheus.do-install')
def install_packages():
   [...]
   reactive.remove_state('prometheus.do-install')

Have instead:

@when_not('prometheus.installed')
def install_packages():
    [...]
    reactive.set_state('prometheus.installed')

You can then remove the @hook('install') handler entirely, and the install_packages handler will run in the first hook (even if it is a storage hook).

Revision history for this message
Jacek Nykis (jacekn) wrote :

Yeah that works too. It's much more involved because it means rewriting reactive logic in quite a few places but we should benefit in the long term.

Thomas Cuthbert (tcuthbert)
Changed in prometheus-charm:
assignee: nobody → Thomas Cuthbert (tcuthbert)
Thomas Cuthbert (tcuthbert)
Changed in prometheus-charm:
assignee: Thomas Cuthbert (tcuthbert) → nobody
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

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