tags and not-tags cannot work properly

[Zhenyu Zheng]

When there is no tags in the system and user uses "nova list --not-tags xxx",
HTTP 500 will return:

root@SZX1000291918:/var/log/nova# nova list --not-tags 123
/usr/local/lib/python2.7/dist-packages/novaclient/client.py:278: UserWarning: The 'tenant_id' argument is deprecated in Ocata and its use may result in errors in future releases. As 'project_id' is provided, the 'tenant_id' argument will be ignored.
  warnings.warn(msg)
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<type 'exceptions.IndexError'> (HTTP 500) (Request-ID: req-225940e7-1976-4ec9-8970-a8c2b4b103ea)

nova-api Logs:
2017-04-14 09:34:29.952 111211 DEBUG oslo_db.sqlalchemy.engines [req-225940e7-1976-4ec9-8970-a8c2b4b103ea f9e4d94bbfbd4cf1b774108650faa855 d4fd94accf2a4718b2ec8100e4e2e5f1 - default default] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py:260
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions [req-225940e7-1976-4ec9-8970-a8c2b4b103ea f9e4d94bbfbd4cf1b774108650faa855 d4fd94accf2a4718b2ec8100e4e2e5f1 - default default] Unexpected exception in API method
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/extensions.py", line 336, in wrapped
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 181, in wrapper
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 181, in wrapper
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 167, in detail
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions servers = self._get_servers(req, is_detail=True)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 310, in _get_servers
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions sort_keys=sort_keys, sort_dirs=sort_dirs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/api.py", line 2572, in get_all
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions sort_dirs=sort_dirs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/api.py", line 2657, in _get_instances_by_filters_all_cells
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/api.py", line 2688, in _get_instances_by_filters
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions expected_attrs=fields, sort_keys=sort_keys, sort_dirs=sort_dirs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions result = fn(cls, context, *args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/objects/instance.py", line 1220, in get_by_filters
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions use_slave=use_slave, sort_keys=sort_keys, sort_dirs=sort_dirs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 236, in wrapper
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/objects/instance.py", line 1204, in _get_by_filters_impl
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions sort_keys=sort_keys, sort_dirs=sort_dirs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/api.py", line 763, in instance_get_all_by_filters_sort
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions sort_dirs=sort_dirs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 180, in wrapper
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 281, in wrapped
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions return f(context, *args, **kwargs)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 2211, in instance_get_all_by_filters_sort
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions first_tag = tags.pop(0)
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions IndexError: pop from empty list
2017-04-14 09:34:29.955 111211 ERROR nova.api.openstack.extensions
2017-04-14 09:34:29.958 111211 INFO nova.api.openstack.wsgi [req-225940e7-1976-4ec9-8970-a8c2b4b103ea f9e4d94bbfbd4cf1b774108650faa855 d4fd94accf2a4718b2ec8100e4e2e5f1 - 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.
<type 'exceptions.IndexError'>
2017-04-14 09:34:29.959 111211 DEBUG nova.api.openstack.wsgi [req-225940e7-1976-4ec9-8970-a8c2b4b103ea f9e4d94bbfbd4cf1b774108650faa855 d4fd94accf2a4718b2ec8100e4e2e5f1 - 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.
<type 'exceptions.IndexError'> __call__ /opt/stack/nova/nova/api/openstack/wsgi.py:1041
2017-04-14 09:34:29.960 111211 INFO nova.osapi_compute.wsgi.server [req-225940e7-1976-4ec9-8970-a8c2b4b103ea f9e4d94bbfbd4cf1b774108650faa855 d4fd94accf2a4718b2ec8100e4e2e5f1 - default default] 10.229.45.145 "GET /v2.1/servers/detail?not-tags=123 HTTP/1.1" status: 500 len: 563 time: 0.1029530

[Zhenyu Zheng (zhengzhenyu)]

In http://git.openstack.org/cgit/openstack/nova/tree/nova/db/sqlalchemy/api.py#n2150
we did copied the filters dict
in http://git.openstack.org/cgit/openstack/nova/tree/nova/db/sqlalchemy/api.py#n2188 and
http://git.openstack.org/cgit/openstack/nova/tree/nova/db/sqlalchemy/api.py#n2209
we pop the first tag in tags to do SQL query, as we didn't do deep copy, the
"tags" or "not-tags" key will be still in filters dict but the value has been removed,
as we loop through every cell, Error will happen, and also, the result is incorrect.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/457103

[Jay Pipes (jaypipes)]

Kevin, would it be possible to post the actual error message from the logs instead of the returned 500 error? Thanks!

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/ocata
Review: https://review.openstack.org/457335

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/ocata
Review: https://review.openstack.org/457336

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/457353

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/457103
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=01dd1a05a213c0cbd0097188418cabe915291c8d
Submitter: Jenkins
Branch: master

commit 01dd1a05a213c0cbd0097188418cabe915291c8d
Author: Matt Riedemann <email address hidden>
Date: Sun Apr 16 20:45:25 2017 -0400

    Add regression test for server filtering by tags bug 1682693

    There was a latent bug in the DB API code such that when we
    process filters when listing instances, the various tags
    filters have their values popped out of the filters dict and
    the values (which are lists) for the filter also have the
    first item in the list popped out to build the query.

    This latent bug was exposed in Newton when we started listing
    instances in the API from both cell0 and the main cell database,
    because the query to cell0 would pop an item and then it
    would not be in the 2nd query to the main cell database. If we
    only had one tag in the filter list, we get an IndexError on
    the 2nd pop() call.

    Note that we also use the build_requests table in the API to
    list instances, but there would not be any tagged servers in
    that table since a server has to be ACTIVE before you can tag it,
    and build_requests only exist until the instance is put into a
    cell and starts building there (so it won't be ACTIVE yet).

    Change-Id: I65bdfadd406368775c794ee4d8a16302a8a134bc
    Related-Bug: #1682693

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/456872
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=c4820305d2f9ee8d62bcc708baf3fa6dfe7ca960
Submitter: Jenkins
Branch: master

commit c4820305d2f9ee8d62bcc708baf3fa6dfe7ca960
Author: Kevin_Zheng <email address hidden>
Date: Fri Apr 14 11:57:59 2017 +0800

    Use deepcopy when process filters in db api

    In db API when we process filters, we didn't
    use deepcopy. In cases of "tags" and "not-tags"
    we used pop to get the first tag, filtered out
    results, and then joined with other tags for
    later filtering. When we did pop(), the original
    value was deleted, the key "tags"/"not-tags" remains.

    In the cell scenario, both single cell(we will
    query cell0 and the other cell) and multicell,
    as we have to query all the cells in a loop and
    the tags list in the filter will keep popping,
    this will lead to either a HTTP 500 error(popping
    from an empty list) or incorrect result(when
    number of tags in the list is larger than cell
    number, no HTTP 500 will show, but the filter
    results for each cell will be different as
    each loop will pop one tag).

    closes-bug: #1682693

    Change-Id: Ia2738dd0c7d1842b68c83d0a9e75e26b2f8d492a

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/457335
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=c9620d57c84378c6187485d571e60e9da3eb9737
Submitter: Jenkins
Branch: stable/ocata

commit c9620d57c84378c6187485d571e60e9da3eb9737
Author: Matt Riedemann <email address hidden>
Date: Sun Apr 16 20:45:25 2017 -0400

    Add regression test for server filtering by tags bug 1682693

    There was a latent bug in the DB API code such that when we
    process filters when listing instances, the various tags
    filters have their values popped out of the filters dict and
    the values (which are lists) for the filter also have the
    first item in the list popped out to build the query.

    This latent bug was exposed in Newton when we started listing
    instances in the API from both cell0 and the main cell database,
    because the query to cell0 would pop an item and then it
    would not be in the 2nd query to the main cell database. If we
    only had one tag in the filter list, we get an IndexError on
    the 2nd pop() call.

    Note that we also use the build_requests table in the API to
    list instances, but there would not be any tagged servers in
    that table since a server has to be ACTIVE before you can tag it,
    and build_requests only exist until the instance is put into a
    cell and starts building there (so it won't be ACTIVE yet).

    Change-Id: I65bdfadd406368775c794ee4d8a16302a8a134bc
    Related-Bug: #1682693
    (cherry picked from commit 01dd1a05a213c0cbd0097188418cabe915291c8d)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/457336
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=01ffbdf8be1cec567ccebb1d9dcb1b390cfaa31a
Submitter: Jenkins
Branch: stable/ocata

commit 01ffbdf8be1cec567ccebb1d9dcb1b390cfaa31a
Author: Kevin_Zheng <email address hidden>
Date: Fri Apr 14 11:57:59 2017 +0800

    Use deepcopy when process filters in db api

    In db API when we process filters, we didn't
    use deepcopy. In cases of "tags" and "not-tags"
    we used pop to get the first tag, filtered out
    results, and then joined with other tags for
    later filtering. When we did pop(), the original
    value was deleted, the key "tags"/"not-tags" remains.

    In the cell scenario, both single cell(we will
    query cell0 and the other cell) and multicell,
    as we have to query all the cells in a loop and
    the tags list in the filter will keep popping,
    this will lead to either a HTTP 500 error(popping
    from an empty list) or incorrect result(when
    number of tags in the list is larger than cell
    number, no HTTP 500 will show, but the filter
    results for each cell will be different as
    each loop will pop one tag).

    closes-bug: #1682693

    Change-Id: Ia2738dd0c7d1842b68c83d0a9e75e26b2f8d492a
    (cherry picked from commit c4820305d2f9ee8d62bcc708baf3fa6dfe7ca960)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/457353
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=6d1ce4cf5cfa9525dfde14bd55b94e86f5e548c1
Submitter: Jenkins
Branch: stable/newton

commit 6d1ce4cf5cfa9525dfde14bd55b94e86f5e548c1
Author: Kevin_Zheng <email address hidden>
Date: Fri Apr 14 11:57:59 2017 +0800

    Use deepcopy when process filters in db api

    In db API when we process filters, we didn't
    use deepcopy. In cases of "tags" and "not-tags"
    we used pop to get the first tag, filtered out
    results, and then joined with other tags for
    later filtering. When we did pop(), the original
    value was deleted, the key "tags"/"not-tags" remains.

    In the cell scenario, both single cell(we will
    query cell0 and the other cell) and multicell,
    as we have to query all the cells in a loop and
    the tags list in the filter will keep popping,
    this will lead to either a HTTP 500 error(popping
    from an empty list) or incorrect result(when
    number of tags in the list is larger than cell
    number, no HTTP 500 will show, but the filter
    results for each cell will be different as
    each loop will pop one tag).

    closes-bug: #1682693

    Conflicts:
          nova/tests/functional/regressions/test_bug_1682693.py

    NOTE(mriedem): The conflict on the functional regression test
    is due to I65bdfadd406368775c794ee4d8a16302a8a134bc not being
    backported to Newton. That was not backported simply because it
    relies on too many fixtures to stub out a real cells environment
    that trying to get it to work in Newton is not worth it. This
    fix is still unit tested which is sufficient.

    Change-Id: Ia2738dd0c7d1842b68c83d0a9e75e26b2f8d492a
    (cherry picked from commit c4820305d2f9ee8d62bcc708baf3fa6dfe7ca960)
    (cherry picked from commit 01ffbdf8be1cec567ccebb1d9dcb1b390cfaa31a)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 15.0.4 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 14.0.6 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 16.0.0.0b2 development milestone.