After running Tempest (full suite), 3 volumes still active/not cleaned up

Bug #992640 reported by Jay Pipes
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
tempest
Fix Released
High
Jay Pipes

Bug Description

There are volumes not being cleaned up properly in Tempest test runs (see attached screenshot of directly after a completed test run)

The volume in error state is from the setUpClass method in test_volumes_list.VolumesTest:

======================================================================
ERROR: test suite for <class 'tempest.tests.test_volumes_list.VolumesTest'>
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/nose/suite.py", line 208, in run
    self.setUp()
  File "/usr/lib/pymodules/python2.7/nose/suite.py", line 291, in setUp
    self.setupContext(ancestor)
  File "/usr/lib/pymodules/python2.7/nose/suite.py", line 314, in setupContext
    try_run(context, names)
  File "/usr/lib/pymodules/python2.7/nose/util.py", line 478, in try_run
    return func()
  File "/home/jpipes/repos/tempest/tempest/tests/test_volumes_list.py", line 23, in setUpClass
    'available')
  File "/home/jpipes/repos/tempest/tempest/services/nova/json/volumes_client.py", line 86, in wait_for_volume_status
    raise exceptions.BuildErrorException(volume_id=volume_id)
BuildErrorException: Server %(server_id)s failed to build and is in ERROR status

Not sure which test is producing the orphaned 2 other volumes... will investigate

Revision history for this message
Jay Pipes (jaypipes) wrote :
Changed in tempest:
assignee: nobody → Jay Pipes (jaypipes)
Revision history for this message
Jay Pipes (jaypipes) wrote :

Verified all three leftover volumes are from test_volumes_list.

Changed in tempest:
status: Confirmed → In Progress
Revision history for this message
Jay Pipes (jaypipes) wrote :

OK, so logging into the volume worker, I see this after 2 volumes get created successfully:

2012-05-01 13:22:11 DEBUG nova.utils [req-b590c146-714b-4075-a6f8-13b4ae278f02 5cf785318d7145d8bed991d20878824c b16ec725817a4dd0a5671f167436705a] Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap lvcreate -L 1G -n volume-00000013 nova-volumes from (pid=31198) execute /opt/stack/nova/nova/utils.py:220
2012-05-01 13:22:12 DEBUG nova.utils [req-b590c146-714b-4075-a6f8-13b4ae278f02 5cf785318d7145d8bed991d20878824c b16ec725817a4dd0a5671f167436705a] Result was 5 from (pid=31198) execute /opt/stack/nova/nova/utils.py:236
2012-05-01 13:22:12 ERROR nova.rpc.amqp [req-b590c146-714b-4075-a6f8-13b4ae278f02 5cf785318d7145d8bed991d20878824c b16ec725817a4dd0a5671f167436705a] Exception during message handling
2012-05-01 13:22:12 TRACE nova.rpc.amqp Traceback (most recent call last):
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/rpc/amqp.py", line 262, in _process_data
2012-05-01 13:22:12 TRACE nova.rpc.amqp rval = node_func(context=ctxt, **node_args)
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/volume/manager.py", line 138, in create_volume
2012-05-01 13:22:12 TRACE nova.rpc.amqp volume_ref['id'], {'status': 'error'})
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-05-01 13:22:12 TRACE nova.rpc.amqp self.gen.next()
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/volume/manager.py", line 122, in create_volume
2012-05-01 13:22:12 TRACE nova.rpc.amqp model_update = self.driver.create_volume(volume_ref)
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/volume/driver.py", line 152, in create_volume
2012-05-01 13:22:12 TRACE nova.rpc.amqp self._create_volume(volume['name'], self._sizestr(volume['size']))
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/volume/driver.py", line 111, in _create_volume
2012-05-01 13:22:12 TRACE nova.rpc.amqp volume_name, FLAGS.volume_group, run_as_root=True)
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/volume/driver.py", line 90, in _try_execute
2012-05-01 13:22:12 TRACE nova.rpc.amqp self._execute(*command, **kwargs)
2012-05-01 13:22:12 TRACE nova.rpc.amqp File "/opt/stack/nova/nova/utils.py", line 243, in execute
2012-05-01 13:22:12 TRACE nova.rpc.amqp cmd=' '.join(cmd))
2012-05-01 13:22:12 TRACE nova.rpc.amqp ProcessExecutionError: Unexpected error while running command.
2012-05-01 13:22:12 TRACE nova.rpc.amqp Command: sudo /usr/local/bin/nova-rootwrap lvcreate -L 1G -n volume-00000013 nova-volumes
2012-05-01 13:22:12 TRACE nova.rpc.amqp Exit code: 5
2012-05-01 13:22:12 TRACE nova.rpc.amqp Stdout: ''
2012-05-01 13:22:12 TRACE nova.rpc.amqp Stderr: ' Insufficient free extents (0) in volume group nova-volumes: 256 required\n'

Revision history for this message
Jay Pipes (jaypipes) wrote :

Here is what the volume group shows:

jpipes@librebox:~/repos/devstack$ sudo vgdisplay
  --- Volume group ---
  VG Name nova-volumes
  System ID
  Format lvm2
  Metadata Areas 1
  Metadata Sequence No 27
  VG Access read/write
  VG Status resizable
  MAX LV 0
  Cur LV 2
  Open LV 2
  Max PV 0
  Cur PV 1
  Act PV 1
  VG Size 2.00 GiB
  PE Size 4.00 MiB
  Total PE 512
  Alloc PE / Size 512 / 2.00 GiB
  Free PE / Size 0 / 0
  VG UUID NO4W2i-jze0-8ZE9-ufp3-kGl2-sXsJ-zk3ghT

Revision history for this message
Jay Pipes (jaypipes) wrote :

And the pvdisplay:

jpipes@librebox:~/repos/devstack$ sudo pvdisplay
  --- Physical volume ---
  PV Name /dev/loop0
  VG Name nova-volumes
  PV Size 2.00 GiB / not usable 4.00 MiB
  Allocatable yes (but full)
  PE Size 4.00 MiB
  Total PE 512
  Free PE 0
  Allocated PE 512
  PV UUID p3tkcS-gyBE-Lxcu-71fB-ZMF0-80uQ-ocxWFq

Revision history for this message
Jay Pipes (jaypipes) wrote :

Doh. So this is due to devstack creating the nova-volumes volume group with a size of 2G:

if is_service_enabled n-vol; then
    #
    # Configure a default volume group called 'nova-volumes' for the nova-volume
    # service if it does not yet exist. If you don't wish to use a file backed
    # volume group, create your own volume group called 'nova-volumes' before
    # invoking stack.sh.
    #
    # By default, the backing file is 2G in size, and is stored in /opt/stack.

    if ! sudo vgs $VOLUME_GROUP; then
        VOLUME_BACKING_FILE=${VOLUME_BACKING_FILE:-$DEST/nova-volumes-backing-file}
        VOLUME_BACKING_FILE_SIZE=${VOLUME_BACKING_FILE_SIZE:-2052M}
        # Only create if the file doesn't already exists
        [[ -f $VOLUME_BACKING_FILE ]] || truncate -s $VOLUME_BACKING_FILE_SIZE $VOLUME_BACKING_FILE
        DEV=`sudo losetup -f --show $VOLUME_BACKING_FILE`
        # Only create if the loopback device doesn't contain $VOLUME_GROUP
        if ! sudo vgs $VOLUME_GROUP; then sudo vgcreate $VOLUME_GROUP $DEV; fi
    fi

So, in tempest, we need to do a little magic in the volume list test to determine how many volumes we can create...

Revision history for this message
Jay Pipes (jaypipes) wrote :

Easiest fix at this point is to modify devstack's tools/configure_tempest.sh script to set up a volume group with a backing file size of 4GB and then put in the setUpClass() some scripting to determine the backing file size and skip certain tests if smaller than 4G

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

Fix proposed to branch: master
Review: https://review.openstack.org/7067

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to tempest (master)

Reviewed: https://review.openstack.org/7067
Committed: http://github.com/openstack/tempest/commit/4759ac6412adc67a57eab294e9f6fd9ff2d414e4
Submitter: Jenkins
Branch: master

commit 4759ac6412adc67a57eab294e9f6fd9ff2d414e4
Author: Jay Pipes <email address hidden>
Date: Thu May 3 12:52:42 2012 -0400

    Fixes LP #992640 - Volumes sometimes not cleaned

    * Adds some error handling to the volume list test case
      that properly handles the (fairly common) case for when
      Nova's volume group backing file size is too small to create
      the needed 3 1G volumes for the test

    Change-Id: Ice367b73303d74c529351d7bd4d9a4e9b1348e07

Changed in tempest:
status: In Progress → Fix Committed
Jay Pipes (jaypipes)
Changed in tempest:
status: Fix Committed → Fix Released
Sean Dague (sdague)
Changed in tempest:
milestone: none → havana-3
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.