'vgcreate cinder-volumes /dev/sdb' returned non-zero exit status 5 - A volume group called cinder-volumes already exists

[Larry Michel]

This happens on a server with and Adaptec ASR 8885Q controller. The /dev/sdb disk has its label successfully wiped but when disk is repartitioned, the cinder-volumes can not be created as it already exists. This seems to be an issue with the charm.

+ . ./pipeline_parameters
++ export OPENSTACK_RELEASE=icehouse
++ OPENSTACK_RELEASE=icehouse
++ export COMPUTE=nova-vmware
++ COMPUTE=nova-vmware
++ export BLOCK_STORAGE=cinder-iscsi
++ BLOCK_STORAGE=cinder-iscsi
++ export IMAGE_STORAGE=glance-swift
++ IMAGE_STORAGE=glance-swift
++ export PIPELINE_ID=55b065ca-5de5-408d-8317-53aecedf9ba1
++ PIPELINE_ID=55b065ca-5de5-408d-8317-53aecedf9ba1
++ export NETWORKING=nova-network-flatdhcp
++ NETWORKING=nova-network-flatdhcp
++ export UBUNTU_RELEASE=trusty
++ UBUNTU_RELEASE=trusty

From console.txt:

2015-03-31 09:59:57,461 [DEBUG] deployer.env: Delta machine: 5/lxc/1 change:started
2015-03-31 09:59:57,462 [DEBUG] deployer.env: Delta unit: rabbitmq-server/0 change:installing
2015-03-31 10:00:02,389 [DEBUG] deployer.env: Delta unit: rabbitmq-server/0 change:installing
2015-03-31 10:00:12,381 [DEBUG] deployer.env: Delta unit: cinder/0 change:error
2015-03-31 10:00:12,381 [ERROR] deployer.env: The following units had errors:
   unit: cinder/0: machine: 1 agent-state: error details: hook failed: "config-changed"
2015-03-31 10:00:12,548 [ERROR] oil_ci.deploy.oil_deployer: Deployment failed:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/oil_ci/deploy/oil_deployer.py", line 140, in deploy
    debug=True, verbose=True)
  File "/usr/lib/python2.7/dist-packages/oil_ci/juju/juju_deployer.py", line 85, in run_deployer
    importer.Importer(env, deploy, options=opts).run()
  File "/usr/lib/python2.7/dist-packages/deployer/action/importer.py", line 206, in run
    self.wait_for_units(ignore_errors=ignore_errors)
  File "/usr/lib/python2.7/dist-packages/deployer/action/importer.py", line 181, in wait_for_units
    services=self.deployment.get_service_names(), on_errors=on_errors)
  File "/usr/lib/python2.7/dist-packages/deployer/env/go.py", line 227, in wait_for_units
    services=services, on_errors=on_errors).run(callback)
  File "/usr/lib/python2.7/dist-packages/jujuclient.py", line 1923, in run
    if self.complete() is True:
  File "/usr/lib/python2.7/dist-packages/deployer/env/watchers.py", line 77, in complete
    on_errors(new_errors)
  File "/usr/lib/python2.7/dist-packages/deployer/env/watchers.py", line 98, in callback
    raise ErrorExit()
ErrorExit
2015-03-31 10:00:1

From unit-cinder-0.log:

2015-03-31 09:59:38 INFO unit.cinder/0.config-changed logger.go:40 Labels on physical volume "/dev/sdb" successfully wiped
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 Creating new GPT entries.
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 GPT data structures destroyed! You may now partition the disk using fdisk or
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 other utilities.
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 The operation has completed successfully.
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 1+0 records in
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 1+0 records out
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 1048576 bytes (1.0 MB) copied, 0.0180884 s, 58.0 MB/s
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 100+0 records in
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 100+0 records out
2015-03-31 10:00:02 INFO unit.cinder/0.config-changed logger.go:40 51200 bytes (51 kB) copied, 0.0133007 s, 3.8 MB/s
2015-03-31 10:00:03 INFO unit.cinder/0.config-changed logger.go:40 Physical volume "/dev/sdb" successfully created
2015-03-31 10:00:03 INFO unit.cinder/0.config-changed logger.go:40 No physical volume label read from /dev/loop0
2015-03-31 10:00:03 INFO unit.cinder/0.config-changed logger.go:40 Failed to read physical volume "/dev/loop0"
2015-03-31 10:00:03 INFO unit.cinder/0.config-changed logger.go:40 No physical volume label read from /dev/loop0
2015-03-31 10:00:03 INFO unit.cinder/0.config-changed logger.go:40 Failed to read physical volume "/dev/loop0"
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 Creating new GPT entries.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 Warning: The kernel is still using the old partition table.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 The new table will be used at the next reboot.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 GPT data structures destroyed! You may now partition the disk using fdisk or
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 other utilities.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 Warning: The kernel is still using the old partition table.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 The new table will be used at the next reboot.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 The operation has completed successfully.
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 1+0 records in
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 1+0 records out
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 1048576 bytes (1.0 MB) copied, 0.00287794 s, 364 MB/s
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 100+0 records in
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 100+0 records out
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 51200 bytes (51 kB) copied, 0.000713143 s, 71.8 MB/s
2015-03-31 10:00:06 INFO unit.cinder/0.config-changed logger.go:40 Physical volume "/dev/loop0" successfully created
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 A volume group called cinder-volumes already exists.
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 Traceback (most recent call last):
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/var/lib/juju/agents/unit-cinder-0/charm/hooks/config-changed", line 459, in <module>
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 hooks.execute(sys.argv)
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/var/lib/juju/agents/unit-cinder-0/charm/hooks/charmhelpers/core/hookenv.py", line 544, in execute
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 self._hooks[hook_name]()
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/var/lib/juju/agents/unit-cinder-0/charm/hooks/charmhelpers/core/host.py", line 312, in wrapped_f
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 f(*args)
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/var/lib/juju/agents/unit-cinder-0/charm/hooks/config-changed", line 118, in config_changed
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 conf['remove-missing'])
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/var/lib/juju/agents/unit-cinder-0/charm/hooks/cinder_utils.py", line 331, in configure_lvm_storage
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 create_lvm_volume_group(volume_group, new_devices[0])
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/var/lib/juju/agents/unit-cinder-0/charm/hooks/charmhelpers/contrib/storage/linux/lvm.py", line 105, in create_lvm_volume_group
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 check_call(['vgcreate', volume_group, block_device])
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 File "/usr/lib/python2.7/subprocess.py", line 540, in check_call
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 raise CalledProcessError(retcode, cmd)
2015-03-31 10:00:07 INFO unit.cinder/0.config-changed logger.go:40 subprocess.CalledProcessError: Command '['vgcreate', u'cinder-volumes', u'/dev/sdb']' returned non-zero exit status 5
2015-03-31 10:00:07 INFO juju.worker.uniter.context context.go:359 handling reboot
2015-03-31 10:00:07 ERROR juju.worker.uniter.operation runhook.go:86 hook "config-changed" failed: exit status 1
2015-03-31 10:00:07 DEBUG juju.worker.uniter modes.go:417 ModeConfigChanged exiting
2015-03-31 10:00:07 INFO juju.worker.uniter modes.go:415 ModeHookError starting

Setting the category-vendor tag for this one in case it's only re-creatable with storage from PMC-sierra system. This is disk info:

          - node:
            id: disk:1
            claimed: true
            class: disk
            handle: SCSI:00:01:01:00
            - description:
              ATA Disk
            - product:
              ST9500620NS
            - vendor:
              Seagate
            - physid:
              1.1.0
            - businfo:
              scsi@0:1.1.0
            - logicalname:
              /dev/sdb
            - dev:
              8:16
            - version:
              SN03
            - serial:
              9XF36RY5
            - size:
              units: bytes
              500107862016
            - configuration:
              - setting:
                id: ansiversion
                value: 6
              - setting:
                id: sectorsize
                value: 512

[Jason Hobbs (jason-hobbs)]

Larry - can you post the deployment yaml for this?

[Larry Michel (lmic)]

Deployment yaml file attached.

[Greg Lutostanski (lutostag)]

This is only happening on a particular type of hardware for now -- making note of it to see if it is vendor side or our side.

[Jason Hobbs (jason-hobbs)]

This has the same error message and likely same root cause as bug 1476418, marking this as a duplicate.