yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1799309] [NEW] Migration/Resize fails with Unexpected exception in API method: Circular reference detected

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Eric Miller <1799309@xxxxxxxxxxxxxxxxxx>
Date: Mon, 22 Oct 2018 22:20:25 -0000
Reply-to: Bug 1799309 <1799309@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Description
===========

Cold migration of a VM failed, so I tried resizing, and the same error
occurred.

Previous to this, I had disabled the compute service on one node, to see
if cold migrating VMs would avoid scheduling the VMs on the disabled
node.  This succeeded a few times, but then this error occurred and now
it happens on the two test VMs that I have running in this environment
(there are only two VMs total).


Steps to reproduce
==================

Run as "admin" on a test server created by a domain user in its respective domain project:
openstack server migrate <uuid>

It continues to be 100% repeatable.  VMs are still operational and can
be shut down and powered on without issue.


Expected result
===============

As with previous migrations, a graceful shut down, cold migrate, and
power on of the VM.


Actual result
=============

This is returned (note that this is from a different migration attempt
than the logs included below):

Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<type 'exceptions.ValueError'> (HTTP 500) (Request-ID: req-46ce0fd3-5579-48be-9486-499fdea085a1)


Environment
===========

stable/rocky deployed with Kolla-Ansible 7.0.0.0rc3devXX (as of October
15, 2018) with respective Kolla images

Hypervisor: Libvirt + KVM
Storage: iSCSI attached (Blockbridge)
Networking: DVR


Logs & Configs
==============

This is a filtered list of nova files from all nova containers running
on all controllers, concatenated and sorted, filtered by the request ID.

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.105 26 DEBUG nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] Action: 'action',
calling method: <bound method MigrateServerController._migrate of
<nova.api.openstack.compute.migrate_server.MigrateServerController
object at 0x7f46647a4590>>, body: {"migrate": null} _process_stack
/var/lib/kolla/venv/lib/python2.7/site-
packages/nova/api/openstack/wsgi.py:615

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.106 26 DEBUG nova.compute.api [req-8a41af8d-23ea-491e-be0a-
b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] [instance: 2fd8ff29
-f64a-4e5b-bfcd-97c52cf6d66d] Fetching instance by UUID get
/var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/api.py:2402

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.117 26 DEBUG oslo_concurrency.lockutils [req-8a41af8d-23ea-
491e-be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] Lock
"43894fde-4653-4499-9c83-0e963c974fae" acquired by
"nova.context.get_or_set_cached_cell_and_set_connections" :: waited
0.000s inner /var/lib/kolla/venv/lib/python2.7/site-
packages/oslo_concurrency/lockutils.py:273

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.118 26 DEBUG oslo_concurrency.lockutils [req-8a41af8d-23ea-
491e-be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] Lock
"43894fde-4653-4499-9c83-0e963c974fae" released by
"nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s
inner /var/lib/kolla/venv/lib/python2.7/site-
packages/oslo_concurrency/lockutils.py:285

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.174 26 DEBUG nova.objects.instance [req-8a41af8d-23ea-491e-
be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] Lazy-loading
'flavor' on Instance uuid 2fd8ff29-f64a-4e5b-bfcd-97c52cf6d66d
obj_load_attr /var/lib/kolla/venv/lib/python2.7/site-
packages/nova/objects/instance.py:1109

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.212 26 DEBUG nova.compute.api [req-8a41af8d-23ea-491e-be0a-
b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] [instance: 2fd8ff29
-f64a-4e5b-bfcd-97c52cf6d66d] flavor_id is None. Assuming migration.
resize /var/lib/kolla/venv/lib/python2.7/site-
packages/nova/compute/api.py:3448

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:07.213 26 DEBUG nova.compute.api [req-8a41af8d-23ea-491e-be0a-
b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] [instance: 2fd8ff29
-f64a-4e5b-bfcd-97c52cf6d66d] Old instance type c5.4xlarge, new instance
type c5.4xlarge resize /var/lib/kolla/venv/lib/python2.7/site-
packages/nova/compute/api.py:3469

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:09.999 26 ERROR nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] Unexpected exception
in API method: ValueError: Circular reference detected

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:10.005 26 INFO nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] HTTP exception
thrown: Unexpected API Error. Please report this at
http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:10.006 26 DEBUG nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default] Returning 500 to
user: Unexpected API Error. Please report this at
http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.

/var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
16:05:10.007 26 INFO nova.osapi_compute.wsgi.server [req-8a41af8d-23ea-
491e-be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
a87099d25afd4c599d34b2fae7689dec - default default]
104.36.108.132,192.168.4.1 "POST
/v2.1/a87099d25afd4c599d34b2fae7689dec/servers/2fd8ff29-f64a-4e5b-bfcd-
97c52cf6d66d/action HTTP/1.1" status: 500 len: 603 time: 2.9094801

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1799309

Title:
  Migration/Resize fails with Unexpected exception in API method:
  Circular reference detected

Status in OpenStack Compute (nova):
  New

Bug description:
  Description
  ===========

  Cold migration of a VM failed, so I tried resizing, and the same error
  occurred.

  Previous to this, I had disabled the compute service on one node, to
  see if cold migrating VMs would avoid scheduling the VMs on the
  disabled node.  This succeeded a few times, but then this error
  occurred and now it happens on the two test VMs that I have running in
  this environment (there are only two VMs total).

  
  Steps to reproduce
  ==================

  Run as "admin" on a test server created by a domain user in its respective domain project:
  openstack server migrate <uuid>

  It continues to be 100% repeatable.  VMs are still operational and can
  be shut down and powered on without issue.

  
  Expected result
  ===============

  As with previous migrations, a graceful shut down, cold migrate, and
  power on of the VM.

  
  Actual result
  =============

  This is returned (note that this is from a different migration attempt
  than the logs included below):

  Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <type 'exceptions.ValueError'> (HTTP 500) (Request-ID: req-46ce0fd3-5579-48be-9486-499fdea085a1)

  
  Environment
  ===========

  stable/rocky deployed with Kolla-Ansible 7.0.0.0rc3devXX (as of
  October 15, 2018) with respective Kolla images

  Hypervisor: Libvirt + KVM
  Storage: iSCSI attached (Blockbridge)
  Networking: DVR

  
  Logs & Configs
  ==============

  This is a filtered list of nova files from all nova containers running
  on all controllers, concatenated and sorted, filtered by the request
  ID.

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.105 26 DEBUG nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
  be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] Action: 'action',
  calling method: <bound method MigrateServerController._migrate of
  <nova.api.openstack.compute.migrate_server.MigrateServerController
  object at 0x7f46647a4590>>, body: {"migrate": null} _process_stack
  /var/lib/kolla/venv/lib/python2.7/site-
  packages/nova/api/openstack/wsgi.py:615

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.106 26 DEBUG nova.compute.api [req-8a41af8d-23ea-491e-be0a-
  b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] [instance:
  2fd8ff29-f64a-4e5b-bfcd-97c52cf6d66d] Fetching instance by UUID get
  /var/lib/kolla/venv/lib/python2.7/site-
  packages/nova/compute/api.py:2402

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.117 26 DEBUG oslo_concurrency.lockutils [req-8a41af8d-23ea-
  491e-be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] Lock
  "43894fde-4653-4499-9c83-0e963c974fae" acquired by
  "nova.context.get_or_set_cached_cell_and_set_connections" :: waited
  0.000s inner /var/lib/kolla/venv/lib/python2.7/site-
  packages/oslo_concurrency/lockutils.py:273

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.118 26 DEBUG oslo_concurrency.lockutils [req-8a41af8d-23ea-
  491e-be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] Lock
  "43894fde-4653-4499-9c83-0e963c974fae" released by
  "nova.context.get_or_set_cached_cell_and_set_connections" :: held
  0.000s inner /var/lib/kolla/venv/lib/python2.7/site-
  packages/oslo_concurrency/lockutils.py:285

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.174 26 DEBUG nova.objects.instance [req-8a41af8d-23ea-491e-
  be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] Lazy-loading
  'flavor' on Instance uuid 2fd8ff29-f64a-4e5b-bfcd-97c52cf6d66d
  obj_load_attr /var/lib/kolla/venv/lib/python2.7/site-
  packages/nova/objects/instance.py:1109

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.212 26 DEBUG nova.compute.api [req-8a41af8d-23ea-491e-be0a-
  b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] [instance:
  2fd8ff29-f64a-4e5b-bfcd-97c52cf6d66d] flavor_id is None. Assuming
  migration. resize /var/lib/kolla/venv/lib/python2.7/site-
  packages/nova/compute/api.py:3448

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:07.213 26 DEBUG nova.compute.api [req-8a41af8d-23ea-491e-be0a-
  b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] [instance:
  2fd8ff29-f64a-4e5b-bfcd-97c52cf6d66d] Old instance type c5.4xlarge,
  new instance type c5.4xlarge resize /var/lib/kolla/venv/lib/python2.7
  /site-packages/nova/compute/api.py:3469

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:09.999 26 ERROR nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
  be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] Unexpected
  exception in API method: ValueError: Circular reference detected

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:10.005 26 INFO nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
  be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] HTTP exception
  thrown: Unexpected API Error. Please report this at
  http://bugs.launchpad.net/nova/ and attach the Nova API log if
  possible.

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:10.006 26 DEBUG nova.api.openstack.wsgi [req-8a41af8d-23ea-491e-
  be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default] Returning 500 to
  user: Unexpected API Error. Please report this at
  http://bugs.launchpad.net/nova/ and attach the Nova API log if
  possible.

  /var/lib/docker/volumes/kolla_logs/_data/nova/nova-api.log:2018-10-22
  16:05:10.007 26 INFO nova.osapi_compute.wsgi.server [req-8a41af8d-
  23ea-491e-be0a-b0fbe98dd6a7 ebdf7b1025a6464ba150b8ea63bfacb5
  a87099d25afd4c599d34b2fae7689dec - default default]
  104.36.108.132,192.168.4.1 "POST
  /v2.1/a87099d25afd4c599d34b2fae7689dec/servers/2fd8ff29-f64a-4e5b-
  bfcd-97c52cf6d66d/action HTTP/1.1" status: 500 len: 603 time:
  2.9094801

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1799309/+subscriptions
Follow ups

[Bug 1799309] Re: Migration/Resize fails with Unexpected exception in API method: Circular reference detected
From: Balazs Gibizer, 2020-05-19