Delete subnet fails with "ObjectDeletedError: Instance '<IPAllocation at 0x7f6abc3abe50>' has been deleted, or its row is otherwise not present."

[Matt Riedemann]

Seen here:

http://logs.openstack.org/91/327191/15/check/gate-tempest-dsvm-neutron-dvr/ed57c36/logs/screen-q-svc.txt.gz?level=TRACE#_2016-06-20_02_06_12_987

2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource [req-3870a7f4-ae6c-4710-b55f-7f2179c3d48a tempest-NetworksTestDHCPv6-2051920777 -] delete failed
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource Traceback (most recent call last):
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/api/v2/resource.py", line 78, in resource
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource result = method(request=request, **args)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 549, in delete
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource return self._delete(request, id, **kwargs)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource ectxt.value = e.inner_exc
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource self.force_reraise()
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/api/v2/base.py", line 571, in _delete
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource obj_deleter(request.context, id, **kwargs)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/common/utils.py", line 600, in inner
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource return f(self, context, *args, **kwargs)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 1058, in delete_subnet
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource LOG.debug("Port %s deleted concurrently", a.port_id)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/attributes.py", line 237, in __get__
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource return self.impl.get(instance_state(instance), dict_)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/attributes.py", line 578, in get
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource value = state._load_expired(state, passive)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/state.py", line 474, in _load_expired
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource self.manager.deferred_scalar_loader(self, toload)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/loading.py", line 669, in load_scalar_attributes
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource raise orm_exc.ObjectDeletedError(state)
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource ObjectDeletedError: Instance '<IPAllocation at 0x7f6abc3abe50>' has been deleted, or its row is otherwise not present.
2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource

Looks like it's mostly failure but not 100%, might depend on the job.

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22ObjectDeletedError%3A%20Instance%20'%3CIPAllocation%5C%22%20AND%20message%3A%5C%22has%20been%20deleted%2C%20or%20its%20row%20is%20otherwise%20not%20present.%5C%22%20AND%20message%3A%5C%22delete_subnet%5C%22%20AND%20tags%3A%5C%22screen-q-svc.txt%5C%22%20AND%20voting%3A1&from=7d

[Matt Riedemann (mriedem)]

A better query that's 100% failure:

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22ObjectDeletedError%3A%20Instance%20'%3CIPAllocation%5C%22%20AND%20message%3A%5C%22has%20been%20deleted%2C%20or%20its%20row%20is%20otherwise%20not%20present.%5C%22%20AND%20message%3A%5C%22delete_subnet%5C%22%20AND%20tags%3A%5C%22screen-q-svc.txt%5C%22%20AND%20voting%3A1%20AND%20NOT%20build_name%3A%5C%22gate-rally-dsvm-neutron-rally%5C%22%20AND%20NOT%20build_queue%3A%5C%22post%5C%22&from=7d

[Manjeet Singh Bhatia (manjeet-s-bhatia)]

I am giving it a shot since this is important if someone finds a solution before me just go ahead with patch and change assignee

[Carl Baldwin (carl-baldwin)]

So, I notice in the stack trace that the code has already figured out that the port was deleted concurrently. See this from the stack trace:

2016-06-20 02:06:12.987 18923 ERROR neutron.api.v2.resource LOG.debug("Port %s deleted concurrently", a.port_id)

The problem is that -- in reporting the problem -- it is trying to extract the port_id from the db object that has been deleted and that is causing the issue. If we can just get the port_id from something else then I think we'll be fine.

[Carl Baldwin (carl-baldwin)]

A prettier stack trace that should stick around: http://paste.openstack.org/show/521746/

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/333601
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=dfbe1fb7c510d556095a926fec6bfe6f4c153b47
Submitter: Jenkins
Branch: master

commit dfbe1fb7c510d556095a926fec6bfe6f4c153b47
Author: Carl Baldwin <email address hidden>
Date: Thu Jun 23 15:39:47 2016 -0600

    Fix code that's trying to read from a stale DB object

    Change-Id: Ib601235b56c553c29618a4dfdf0608a7b2784c6f
    Closes-Bug: #1594376

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/neutron 9.0.0.0b2 development milestone.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/354444

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/354445

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/354445
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=a587dec08cefb88c448d8cdbe741f363430c01b5
Submitter: Jenkins
Branch: stable/liberty

commit a587dec08cefb88c448d8cdbe741f363430c01b5
Author: Carl Baldwin <email address hidden>
Date: Thu Jun 23 15:39:47 2016 -0600

    Fix code that's trying to read from a stale DB object

    Change-Id: Ib601235b56c553c29618a4dfdf0608a7b2784c6f
    Closes-Bug: #1594376
    (cherry picked from commit dfbe1fb7c510d556095a926fec6bfe6f4c153b47)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/354444
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=1845a1ed020b52af01c9b5ea7af4c74d0ea72df6
Submitter: Jenkins
Branch: stable/mitaka

commit 1845a1ed020b52af01c9b5ea7af4c74d0ea72df6
Author: Carl Baldwin <email address hidden>
Date: Thu Jun 23 15:39:47 2016 -0600

    Fix code that's trying to read from a stale DB object

    Change-Id: Ib601235b56c553c29618a4dfdf0608a7b2784c6f
    Closes-Bug: #1594376
    (cherry picked from commit dfbe1fb7c510d556095a926fec6bfe6f4c153b47)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 7.2.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 8.3.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 7.2.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 8.3.0 release.