20.05 regression: subprocess.CalledProcessError: Command '['pvscan']' died with <Signals.SIGPIPE: 13>

[Jason Hobbs]

We hit this failure on a number of runs, but at least one got past it, so it seems to be a race. We have never seen it on the stable charms.

2020-05-12 00:49:53 DEBUG juju-log Hardening function 'config_changed'
2020-05-12 00:49:54 DEBUG juju-log No hardening applied to 'config_changed'
2020-05-12 00:49:54 DEBUG config-changed Traceback (most recent call last):
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/hooks/config-changed", line 676, in <module>
2020-05-12 00:49:54 DEBUG config-changed hooks.execute(sys.argv)
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/charmhelpers/core/hookenv.py", line 934, in execute
2020-05-12 00:49:54 DEBUG config-changed self._hooks[hook_name]()
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/charmhelpers/contrib/openstack/utils.py", line 1696, in wrapped_f
2020-05-12 00:49:54 DEBUG config-changed stopstart, restart_functions)
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/charmhelpers/core/host.py", line 741, in restart_on_change_helper
2020-05-12 00:49:54 DEBUG config-changed r = lambda_f()
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/charmhelpers/contrib/openstack/utils.py", line 1695, in <lambda>
2020-05-12 00:49:54 DEBUG config-changed (lambda: f(*args, **kwargs)), __restart_map_cache['cache'],
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/charmhelpers/contrib/hardening/harden.py", line 93, in _harden_inner2
2020-05-12 00:49:54 DEBUG config-changed return f(*args, **kwargs)
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/hooks/config-changed", line 203, in config_changed
2020-05-12 00:49:54 DEBUG config-changed _configure_block_devices()
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/hooks/config-changed", line 277, in _configure_block_devices
2020-05-12 00:49:54 DEBUG config-changed conf['remove-missing-force'])
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/hooks/cinder_utils.py", line 530, in configure_lvm_storage
2020-05-12 00:49:54 DEBUG config-changed log_lvm_info()
2020-05-12 00:49:54 DEBUG config-changed File "/var/lib/juju/agents/unit-cinder-1/charm/hooks/cinder_utils.py", line 512, in log_lvm_info
2020-05-12 00:49:54 DEBUG config-changed pvscan_output = subprocess.check_output(['pvscan']).decode('UTF-8')
2020-05-12 00:49:54 DEBUG config-changed File "/usr/lib/python3.6/subprocess.py", line 356, in check_output
2020-05-12 00:49:54 DEBUG config-changed **kwargs).stdout
2020-05-12 00:49:54 DEBUG config-changed File "/usr/lib/python3.6/subprocess.py", line 438, in run
2020-05-12 00:49:54 DEBUG config-changed output=stdout, stderr=stderr)
2020-05-12 00:49:54 DEBUG config-changed subprocess.CalledProcessError: Command '['pvscan']' died with <Signals.SIGPIPE: 13>.
2020-05-12 00:49:54 ERROR juju.worker.uniter.operation runhook.go:132 hook "config-changed" failed: exit status 1

https://solutions.qa.canonical.com/#/qa/testRun/e49c670d-b0c8-4859-8c9a-a63d2320a4bb

[Liam Young (gnuoy)]

A quick git blame points to 7a98ea3da

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/727821
Committed: https://git.openstack.org/cgit/openstack/charm-cinder/commit/?id=fc8e95f8c712e8ec5f1d768a2ac3d5c7587421eb
Submitter: Zuul
Branch: master

commit fc8e95f8c712e8ec5f1d768a2ac3d5c7587421eb
Author: Alex Kavanagh <email address hidden>
Date: Wed May 13 17:07:34 2020 +0100

    Wrap lvm commands in try: except:

    Due to the additional of the cinder storage, it's possible that the
    log_lvm_info() commands gets called really early before lvm has been
    configured. This wraps the call to pvscan and logs if it doesn't
    complete -- the command is just to log the state of lvm at that point.

    Also, defensively wrap the reduce_lvm_volume_group_missing() calls for
    the same reason.

    Closes-Bug: #1878227
    Change-Id: I217f62d3f620992d1b18475ca5c3031da9428828