Bug 1045515

Summary:

Re-size of an ACTIVE Nova instance returns success (albeit, bogus)

Product:

[Community] RDO

Reporter:

Kashyap Chamarthy <kchamart>

Component:

openstack-nova

Assignee:

Nikola Dipanov <ndipanov>

Status:

CLOSED CURRENTRELEASE

QA Contact:

Ami Jeain <ajeain>

Severity:

unspecified

Docs Contact:

Priority:

unspecified

Version:

unspecified

CC:

eglynn, ndipanov, rbryant, yeylon

Target Milestone:

---

Keywords:

Triaged

Target Release:

---

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

Fixed In Version:

Doc Type:

Bug Fix

Doc Text:

Story Points:

---

Clone Of:

Environment:

Last Closed:

2015-02-18 10:26:20 UTC

Type:

Bug

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

---

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Embargoed:

Attachments:

Description	Flags
nova.conf of Controller node	none
nova.conf of Compute node	none
nova.conf with IceHouse setup	none

Description Kashyap Chamarthy 2013-12-20 15:55:08 UTC

Description of problem
----------------------

Re-sizing an ACTIVE Nova instance returns success (albeit, bogus):
resize returns success when the command is invoked  to target flavor
size, but doesn't reflect in reality

    $ nova resize --poll cirr-guest2 m1.small
    Instance resizing... 100% complete
    Finished
    $ echo $?
    0


Version
-------

    $ rpm -q openstack-nova python-nova
    openstack-nova-2013.2-4.fc20.noarch
    python-nova-2013.2-4.fc20.noarch


Test environment:
-----------------
Two node, Havana RDO setup on F20:

  - Controller node: Nova, Keystone, Cinder, Glance, Neutron (using Open
    vSwitch plugin and GRE tunneling).

  - Compute node: Nova (nova-compute), Neutron (openvswitch-agent)


How reproducible: Consistently.


Steps to Reproduce
------------------

1. List an active instance:

    $ nova list | grep cirr-guest2
    | e93916df-8d99-4c5e-9c9a-fdff59623677 | cirr-guest2     | ACTIVE | None       | Running     | int=12.0.0.4, 192.169.142.12 |

2. Find out its flavor:

    $ nova show cirr-guest2 | grep flavor
    | flavor                               | m1.tiny (1)                                              |
    $ 

3. Re-size it to m1.small flavor (from medium):

    $ nova resize --poll cirr-guest2 m1.small
    Instance resizing... 100% complete
    Finished
    $ echo $?
    0

4. List the instance again, the (status of it should be VERIFY_RESIZE):

    $ nova list | grep cirr-guest2
    | e93916df-8d99-4c5e-9c9a-fdff59623677 | cirr-guest2     | ACTIVE | None       | Running     | int=12.0.0.4, 192.169.142.12 |

5. List the instance actions (you can notice the 'resize' action):

    $ nova instance-action-list cirr-guest2
    +--------+------------------------------------------+---------+----------------------------+
    | Action | Request_ID                               | Message | Start_Time                 |
    +--------+------------------------------------------+---------+----------------------------+
    | create | req-b738f225-c11c-4f0b-a2e6-5a67d91ba20d | None    | 2013-12-11T10:25:30.000000 |
    | resize | req-c531f0f4-6cb7-4fe1-a0b7-da8343575cae | None    | 2013-12-20T13:19:51.000000 |
    | reboot | req-ef8505d3-6778-4aef-8303-609c0f1a26cd | None    | 2013-12-20T13:28:37.000000 |
    +--------+------------------------------------------+---------+----------------------------+

6. Perform a reboot (not necessary, but I included here for completeness'
   sake of what I did):

    $ nova reboot cirr-guest2

7. On Compute node, let's check the information of this disk (memory is
   sake 512 MB):

    $ virsh dominfo instance-00000003
    Id:             12
    Name:           instance-00000003
    UUID:           e93916df-8d99-4c5e-9c9a-fdff59623677
    OS Type:        hvm
    State:          running
    CPU(s):         1
    CPU time:       109.9s
    Max memory:     524288 KiB
    Used memory:    524288 KiB
    Persistent:     yes
    Autostart:      disable
    Managed save:   no
    Security model: selinux
    Security DOI:   0
    Security label: system_u:system_r:svirt_tcg_t:s0:c316,c397 (permissive)

8. And, check the size of the disk:

    $ ls -lash /var/lib/nova/instances/e93916df-8d99-4c5e-9c9a-fdff59623677/disk 
    12M -rw-r--r--. 1 qemu qemu 12M Dec 20 08:31 /var/lib/nova/instances/e93916df-8d99-4c5e-9c9a-fdff59623677/disk


Two things: 

 - Why hasn't the instance state turned to VERIFY_RESIZE at step-4? so
   that we could confirm the re-size:

     $ nova resize-confirm cirr-guest2

     (Ref: http://docs.openstack.org/user-guide/content/nova_cli_resize.html)

 - From steps 7 & 8 the instance has not resized at all: prior to
   resize, the instance was tiny, after the resize too, the instance is
   tiny. If successfully resized to 'small' flavor, the instance should
   have 2048 MB of memory & 20GB of disk.


Actual results 
--------------

Resize of an ACTIVE nova instance returns a bogus success.


Expected results
----------------

Resize of an ACTIVE nova instance should return a failure


Additional info/Questions:
--------------------------

 - Question: Should Re-size on a SHUTOFF instance work successfully? If
   so, when I tried & polled, it just hung at 0%

 - When I tried on LIVE instance, I could reach the instance on Compute
   node just fine.

    $ ping  -c1 192.169.142.12
    PING 192.169.142.12 (192.169.142.12) 56(84) bytes of data.
    64 bytes from 192.169.142.12: icmp_seq=1 ttl=63 time=1.38 ms

    $ ip netns exec qrouter-f2df2518-78cb-4ad2-917c-3c1b0e994de7 ping -c1
    12.0.0.4
    PING 12.0.0.4 (12.0.0.4) 56(84) bytes of data.
    64 bytes from 12.0.0.4: icmp_seq=1 ttl=64 time=3.26 ms

Comment 1 Kashyap Chamarthy 2013-12-20 16:00:16 UTC

Created attachment 839642 [details]
nova.conf of Controller node

Comment 2 Kashyap Chamarthy 2013-12-20 16:01:28 UTC

Created attachment 839644 [details]
nova.conf  of Compute node

Comment 3 Kashyap Chamarthy 2013-12-20 16:21:22 UTC

I re-tested by enabling Debug and Verbose logs:

    $ egrep -i 'verbose|debug' /etc/nova/nova.conf 
    debug = True
    verbose = True

    $ openstack-service restart nova  # On Controller & Compute nodes


Nothing interesting in logs:

    $ egrep 'ERROR|TRACE' /var/log/nova/*.log
    $ echo $?
    1
    $ grep 'ERROR|TRACE' /var/log/nova/compute.log
    $ echo $?
    1


=> Searching for 'resize' in logs:

Just these uninteresting bits:

$ grep -i resize /var/log/nova/compute.log 
2013-12-20 11:08:46.813 8163 DEBUG nova.openstack.common.periodic_task [req-b26e47f7-7a46-476b-9219-56c39a3ea9c3 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py:176
2013-12-20 11:09:53.211 8163 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py:176
2013-12-20 11:10:56.916 8163 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py:176
2013-12-20 11:12:02.006 8163 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /usr/lib/python2.7/site-packages/nova/openstack/common/periodic_task.py:176


=> Or in Controller logs:

I see uninteresting things like this in scheduler.log & conductor.log:
-----
$ grep resize /var/log/nova/*.log
.
.
.
ame': u'm1.tiny', u'instance_type_id': u'2', u'instance_type_ephemeral_gb': u'0', u'instance_type_rxtx_factor': u'1', u'image_disk_format': u'qcow2', u'instance_type_flavorid': u'1', u'instance_type_vcpus': u'1', u'image_container_format': u'bare', u'image_min_ram': 0, u'image_min_disk': 1, u'image$base_image_ref': u'4cb747d5-e211-4320-a11d-68a977e8dfcb'}, u'task_state': u'resize_prep', u'shutdown_terminate': False, u'cell_name': None, u'root_gb$: 1, u'locked': False, u'name': u'instance-00000003', u'created_at': u'2013-12-11T10:25:30.000000', u'locked_by': None, u'launch_index': 0, u'memory_$b': 512, u'vcpus': 1, u'image_ref': u'4cb747d5-e211-4320-a11d-68a977e8dfcb', u'architecture': None, u'auto_disk_config': False, u'os_type': None, u'm$tadata': {}}, u'instance_type': {u'disabled': False, u'root_gb': 20, u'name': u'm1.small', u'flavorid': u'2', u'deleted': 0, u'created_at': None, u'e$hemeral_gb': 0, u'updated_at': None, u'memory_mb': 2048, u'vcpus': 1, u'e
-----

Comment 4 Kashyap Chamarthy 2014-05-20 13:08:18 UTC

I can still see the same behavior from the Description of this bug w/ a 2-node IceHouse + Neutron+ML2+OVS+GRE setup w/ these versions:

    $ rpm -q openstack-nova-compute qemu-system-x86 libvirt
    openstack-nova-compute-2014.1-2.fc21.noarch
    qemu-system-x86-1.6.2-4.fc20.x86_64
    libvirt-1.1.3.5-1.fc20.x86_64

Test
----
    $ nova list | grep cvm2
    | ff3e4a5a-5415-40db-94c9-72eaf766bb4e | cvm2 | ACTIVE  | -          | Running     | int=30.0.0.26, 192.169.142.12 |

    $ nova show cvm2 | grep -i flavor
    | flavor                               | m1.tiny (1)

    $ ls -lash /var/lib/nova/instances/ff3e4a5a-5415-40db-94c9-72eaf766bb4e/disk
    8.4M -rw-r--r--. 1 qemu qemu 8.5M May 20 10:01 /var/lib/nova/instances/ff3e4a5a-5415-40db-94c9-72eaf766bb4e/disk


    $ nova resize --poll cvm2 m1.small                                                                                
    Server resizing... 100% complete
    Finished

    $ echo $?
    0

Check the flavor type and size again (remains unchanged):

    $ nova show cvm2 | grep -i flavor
    | flavor                               | m1.tiny (1)

    $ nova list | grep cvm2
    | ff3e4a5a-5415-40db-94c9-72eaf766bb4e | cvm2 | ACTIVE  | -          | Running     | int=30.0.0.26, 192.169.142.12 |


    $ ls -lash /var/lib/nova/instances/ff3e4a5a-5415-40db-94c9-72eaf766bb4e/disk
    8.4M -rw-r--r--. 1 qemu qemu 8.5M May 20 10:01 /var/lib/nova/instances/ff3e4a5a-5415-40db-94c9-72eaf766bb4e/disk


Contextual DEBUG logs from nova-api.log (from Controller node)
--------------------------------------------------------------

[. . .]
2014-05-20 13:56:39.568 20931 DEBUG nova.api.openstack.wsgi [req-67d1de3b-34e8-4c91-b48f-a6dbfbc0fed0 cb68d099e78d490ab0adf4030881153b 0a6eb2259ca142e7a80541db10835e71] Calling method '<bound method Controller._action_resize of <nova.api.openstack.compute.contrib.keypairs.Controller object at 0x494e910>>' (Content-type='application/json', Accept='application/json') _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:945
2014-05-20 13:56:39.668 20931 DEBUG nova.compute.api [req-67d1de3b-34e8-4c91-b48f-a6dbfbc0fed0 cb68d099e78d490ab0adf4030881153b 0a6eb2259ca142e7a80541db10835e71] [instance: ff3e4a5a-5415-40db-94c9-72eaf766bb4e] Old instance type m1.tiny,  new instance type m1.small resize /usr/lib/python2.7/site-packages/nova/compute/api.py:2388
2014-05-20 13:56:39.744 20931 DEBUG nova.quota [req-67d1de3b-34e8-4c91-b48f-a6dbfbc0fed0 cb68d099e78d490ab0adf4030881153b 0a6eb2259ca142e7a80541db1083
5e71] Created reservations ['1bc9768f-121d-4f01-9381-a53a635407c5'] reserve /usr/lib/python2.7/site-packages/nova/quota.py:1272
2014-05-20 13:56:42.865 20931 INFO nova.osapi_compute.wsgi.server [req-67d1de3b-34e8-4c91-b48f-a6dbfbc0fed0 cb68d099e78d490ab0adf4030881153b 0a6eb2259
ca142e7a80541db10835e71] 192.169.142.168 "POST /v2/0a6eb2259ca142e7a80541db10835e71/servers/ff3e4a5a-5415-40db-94c9-72eaf766bb4e/action HTTP/1.1" stat
us: 202 len: 185 time: 3.3071191
2014-05-20 13:56:42.932 20931 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keyst
oneclient/middleware/auth_token.py:602
2014-05-20 13:56:42.934 20931 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,
X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,
X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/aut
h_token.py:661
2014-05-20 13:56:42.937 20931 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keysto
neclient/middleware/auth_token.py:1010
2014-05-20 13:56:42.939 20931 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: cb68d099e78d490ab0adf4030881153b with project
_id : 0a6eb2259ca142e7a80541db10835e71 and roles: user  _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:9
09
2014-05-20 13:56:42.946 20931 DEBUG routes.middleware [-] Matched GET /0a6eb2259ca142e7a80541db10835e71/servers/ff3e4a5a-5415-40db-94c9-72eaf766bb4e _
_call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-05-20 13:56:42.947 20931 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova
.api.openstack.wsgi.Resource object at 0x40872d0>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-05-20 13:56:42.949 20931 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x
40872d0>, 'project_id': u'0a6eb2259ca142e7a80541db10835e71', 'id': u'ff3e4a5a-5415-40db-94c9-72eaf766bb4e'} __call__ /usr/lib/python2.7/site-packages/
routes/middleware.py:103
2014-05-20 13:56:42.951 20931 DEBUG nova.api.openstack.wsgi [req-8bb5e7b6-c855-4dcd-ada7-c5c2b3dc2ba9 cb68d099e78d490ab0adf4030881153b 0a6eb2259ca142e
7a80541db10835e71] Calling method '<bound method Controller.show of <nova.api.openstack.compute.servers.Controller object at 0x40848d0>>' (Content-typ
e='None', Accept='application/json') _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:945
2014-05-20 13:56:43.117 20931 DEBUG neutronclient.client [-] 
REQ: curl -i http://192.169.142.97:9696/v2.0/ports.json?device_id=ff3e4a5a-5415-40db-94c9-72eaf766bb4e -X GET -H "X-Auth-Token: MIIIWQYJKoZIhvcNAQcCoI
[. . .]

Comment 5 Kashyap Chamarthy 2014-05-20 13:12:03 UTC

Created attachment 897571 [details]
nova.conf with IceHouse setup

Comment 6 Kashyap Chamarthy 2015-02-17 17:28:48 UTC

Just tested with current Nova from git with DevStack, resize works just
fine. Successful test below.


I was at these commits
-----------------------

  DevStack:
  commit 13c7ccc9d5d7ee8b88c2ee7d4af8990a075440a2
  Nova:
  commit 69f4b44691ddabc2cfa8c08539a51d255646e173
  Glance:
  commit cd60a24a7d32d4ca0be36f7afa4d082193958989
  Keystone:
  commit c06591dd470aaa595206100d0176ccc0575d58b7
  Neutron:
  commit 12b0d4d9792d83fd559de59f2dd7b9f532f89398
  requirements:
  commit ec1c788c2bfac3ef964396b92f8a090b60dbb4ef


Test
----


(1) Boot a Nova instance, successfully:

  $ nova boot --image cirros-0.3.1-x86_64-disk --flavor m1.tiny cirrvm1
  $ nova list
  +--------------------------------------+---------+--------+------------+-------------+-------------------+
  | ID                                   | Name    | Status | Task State | Power State | Networks          |
  +--------------------------------------+---------+--------+------------+-------------+-------------------+
  | 75674781-7403-4e84-9fa1-43fe363fe14a | cirrvm1 | ACTIVE | -          | Running     | public=172.24.4.3 |
  +--------------------------------------+---------+--------+------------+-------------+-------------------+


(2) Enumerate the flavor of the instance:

  $ nova show cirrvm1 | grep flavor
  | flavor                               | m1.tiny (1)          


(3) Find the disk associated with the Nova instance

  $ sudo virsh list
   Id    Name                           State
  ----------------------------------------------------
   3     instance-00000001              running
  
  $ sudo virsh domblklist instance-00000001
  Target     Source
  ------------------------------------------------
  vda        /home/kashyapc/src/cloud/data/nova/instances/75674781-7403-4e84-9fa1-43fe363fe14a/disk
  hdd        /home/kashyapc/src/cloud/data/nova/instances/75674781-7403-4e84-9fa1-43fe363fe14a/disk.config


(4) Check the size of the disk:

  $ ls -lash /home/kashyapc/src/cloud/data/nova/instances/75674781-7403-4e84-9fa1-43fe363fe14a/disk
  3.6M -rw-r--r--. 1 qemu qemu 3.6M Feb 17 11:30 /home/kashyapc/src/cloud/data/nova/instances/75674781-7403-4e84-9fa1-43fe363fe14a/disk


(5) Resize the instance to 'm1.small' (from 'm1.tiny'):

  $ nova resize --poll cirrvm2 m1.small
  
  Server resizing... 100% complete
  Finished
  
  $ echo $?
  0


(6) List the instances (you can notice that now it is in 'VERIFY_RESIZE'
    state:

  $ nova list
  +--------------------------------------+---------+---------------+------------+-------------+-------------------+
  | ID                                   | Name    | Status        | Task State | Power State | Networks          |
  +--------------------------------------+---------+---------------+------------+-------------+-------------------+
  | 75674781-7403-4e84-9fa1-43fe363fe14a | cirrvm1 | VERIFY_RESIZE | -          | Running     | public=172.24.4.4 |
  +--------------------------------------+---------+---------------+------------+-------------+-------------------+


(7) Confirm the resize:

  $ nova resize-confirm cirrvm1

  $ echo $?
  0


(8) List the Nova instances, now the 'Status' is ACTIVE:

  $ nova list
  +--------------------------------------+---------+--------+------------+-------------+-------------------+
  | ID                                   | Name    | Status | Task State | Power State | Networks          |
  +--------------------------------------+---------+--------+------------+-------------+-------------------+
  | 75674781-7403-4e84-9fa1-43fe363fe14a | cirrvm1 | ACTIVE | -          | Running     | public=172.24.4.4 |
  +--------------------------------------+---------+--------+------------+-------------+-------------------+


(9) Check the (new) size of the disk associated with the Nova instance:

  $ ls -lash /home/kashyapc/src/cloud/data/nova/instances/75674781-7403-4e84-9fa1-43fe363fe14a/disk
  19M -rw-r--r--. 1 qemu qemu 19M Feb 17 11:38 /home/kashyapc/src/cloud/data/nova/instances/75674781-7403-4e84-9fa1-43fe363fe14a/disk

Comment 7 Kashyap Chamarthy 2015-02-18 10:26:20 UTC

I repeated the exact test from comment #6 on Juno stable branch, and resize works just as expected.

For the record, these are the commits at Juno Stable branch, that I was at:

  DevStack:
  commit cb247b60bae17571dcedad2c1ef28237a30a8806
  Glance:
  commit 25a722e614eacc47e4658f0bca6343fa52f7d03f
  Keystone:
  commit 1a772b616a27df156f67f98253e121ccd812a633
  Neutron:
  commit da0641eedbb281f1e9f01498dc8cc137a3e7fa3d
  Nova:
  commit b8b9369fb39c13ec2f69be6cd87ef14fb737a54e
  requirements:
  commit df4ffd96084b6e3f144d3ecaacb4aca190903b83

Closing the bug as per this detail.