nova-api is broken in postgresql jobs

Bug #1804271 reported by Slawek Kaplonski on 2018-11-20
18
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
High
Matt Riedemann
Rocky
Medium
Matt Riedemann

Bug Description

We noticed in neutron-tempest-postgres-full periodic job that since 14.11.2018 it's failing because of issue in nova-api.
Example of failure are on http://logs.openstack.org/periodic/git.openstack.org/openstack/neutron/master/neutron-tempest-postgres-full/1de7427/logs/screen-n-api.txt.gz?level=ERROR

Stacktrace:
Nov 20 06:34:20.578714 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi Traceback (most recent call last):
Nov 20 06:34:20.578885 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 655, in wrapped
Nov 20 06:34:20.579046 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return f(*args, **kwargs)
Nov 20 06:34:20.579218 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.579379 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.579537 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.579737 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.579899 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.580070 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.580236 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.580396 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.580616 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.581036 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.581205 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.581364 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.581523 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.581693 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.581852 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.582008 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.582170 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.582336 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.582505 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.582663 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.582835 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 110, in wrapper
Nov 20 06:34:20.582987 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Nov 20 06:34:20.583285 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 596, in create
Nov 20 06:34:20.583453 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi **create_kwargs)
Nov 20 06:34:20.583651 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/hooks.py", line 154, in inner
Nov 20 06:34:20.583805 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi rv = f(*args, **kwargs)
Nov 20 06:34:20.583957 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/compute/api.py", line 1737, in create
Nov 20 06:34:20.584136 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi trusted_certs=trusted_certs)
Nov 20 06:34:20.584298 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/compute/api.py", line 1195, in _create_instance
Nov 20 06:34:20.584459 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi supports_multiattach, network_metadata)
Nov 20 06:34:20.584623 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/compute/api.py", line 869, in _provision_instances
Nov 20 06:34:20.585034 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi context, instance_type, min_count, max_count)
Nov 20 06:34:20.585199 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/compute/utils.py", line 967, in check_num_instances_quota
Nov 20 06:34:20.585358 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi check_user_id=user_id)
Nov 20 06:34:20.585530 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
Nov 20 06:34:20.585708 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi result = fn(cls, context, *args, **kwargs)
Nov 20 06:34:20.585873 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/objects/quotas.py", line 339, in check_deltas
Nov 20 06:34:20.586037 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi **count_kwargs)
Nov 20 06:34:20.586195 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
Nov 20 06:34:20.586363 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi result = fn(cls, context, *args, **kwargs)
Nov 20 06:34:20.586520 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/objects/quotas.py", line 302, in count_as_dict
Nov 20 06:34:20.586677 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi context, resource, *args, **kwargs)
Nov 20 06:34:20.586834 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/quota.py", line 1002, in count_as_dict
Nov 20 06:34:20.587002 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return res.count_as_dict(context, *args, **kwargs)
Nov 20 06:34:20.587160 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/quota.py", line 1178, in _instances_cores_ram_count
Nov 20 06:34:20.587324 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi context, project_id)
Nov 20 06:34:20.587481 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/objects/cell_mapping.py", line 292, in get_by_project_id
Nov 20 06:34:20.587721 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi db_mappings = cls._get_by_project_id_from_db(context, project_id)
Nov 20 06:34:20.587984 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1012, in wrapper
Nov 20 06:34:20.588247 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return fn(*args, **kwargs)
Nov 20 06:34:20.588493 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/opt/stack/new/nova/nova/objects/cell_mapping.py", line 283, in _get_by_project_id_from_db
Nov 20 06:34:20.588745 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi options(joinedload('cell_mapping', innerjoin=True)).\
Nov 20 06:34:20.588998 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2843, in all
Nov 20 06:34:20.589248 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return list(self)
Nov 20 06:34:20.589509 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2995, in __iter__
Nov 20 06:34:20.589783 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return self._execute_and_instances(context)
Nov 20 06:34:20.590043 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 3018, in _execute_and_instances
Nov 20 06:34:20.590316 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi result = conn.execute(querycontext.statement, self._params)
Nov 20 06:34:20.590639 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 948, in execute
Nov 20 06:34:20.590932 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return meth(self, multiparams, params)
Nov 20 06:34:20.591199 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection
Nov 20 06:34:20.591459 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi return connection._execute_clauseelement(self, multiparams, params)
Nov 20 06:34:20.591746 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement
Nov 20 06:34:20.592005 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi compiled_sql, distilled_params
Nov 20 06:34:20.592273 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context
Nov 20 06:34:20.592540 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi context)
Nov 20 06:34:20.592806 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception
Nov 20 06:34:20.593101 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi util.raise_from_cause(newraise, exc_info)
Nov 20 06:34:20.593558 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause
Nov 20 06:34:20.593870 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi reraise(type(exception), exception, tb=exc_tb, cause=cause)
Nov 20 06:34:20.594130 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
Nov 20 06:34:20.594398 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi context)
Nov 20 06:34:20.594661 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 509, in do_execute
Nov 20 06:34:20.594937 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi cursor.execute(statement, parameters)
Nov 20 06:34:20.595226 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi DBError: (psycopg2.ProgrammingError) column "instance_mappings.created_at" must appear in the GROUP BY clause or be used in an aggregate function
Nov 20 06:34:20.595488 ubuntu-xenial-inap-mtl01-0000583998 <email address hidden>[24452]: ERROR nova.api.openstack.wsgi LINE 1: SELECT instance_mappings.created_at AS instance_mappings_cre...

Matt Riedemann (mriedem) on 2018-11-20
tags: added: postgresql
Changed in nova:
status: New → Confirmed
importance: Undecided → High
Matt Riedemann (mriedem) wrote :

The regression is from this change which merged on November 13:

https://review.openstack.org/#/c/569055/7/nova/quota.py

That uses this code:

cell_mappings = objects.CellMappingList.get_by_project_id(
        context, project_id)

Which is where the DB query error comes from. That query method was actually added awhile ago:

https://review.openstack.org/#/c/509002/

That was added for https://review.openstack.org/#/c/509003/ which, based on configuration, will pre-query the cells in which a tenant has instances before listing instances out of those cells, e.g. in the CERN case you can just list instances from 1-2 cells rather than all 70.

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

Changed in nova:
assignee: nobody → Matt Riedemann (mriedem)
status: Confirmed → In Progress

Reviewed: https://review.openstack.org/619061
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=248750578a938a1eaa2e49004302d14ab7318c5b
Submitter: Zuul
Branch: master

commit 248750578a938a1eaa2e49004302d14ab7318c5b
Author: Matt Riedemann <email address hidden>
Date: Tue Nov 20 13:55:55 2018 -0500

    Remove GROUP BY clause from CellMapping.get_by_project_id

    Under postgresql, the GROUP BY clause in this query fails with:

      DBError: (psycopg2.ProgrammingError) column "instance_mappings.created_at"
      must appear in the GROUP BY clause or be used in an aggregate function

    And we're getting lucky with using this under mysql because we don't
    have the ONLY_FULL_GROUP_BY mode set (but we probably should).

    This change removes the GROUP BY clause and re-writes the query
    to avoid the joinedload() from the instance_mappings table and
    simply do a subquery to get the cell_ids and then do a simple
    IN query with the cell_mappings table. This fixes the GROUP BY
    issue and should also make the query more efficient since we
    won't have to load InstanceMappings ORM objects.

    Change-Id: Idc9b5ad019205f447c82a702dd3391fa5dd20228
    Closes-Bug: #1804271

Changed in nova:
status: In Progress → Fix Released

Reviewed: https://review.openstack.org/625377
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=25dc6a467c641ccad5cc75f1003548af4f28b4fb
Submitter: Zuul
Branch: stable/rocky

commit 25dc6a467c641ccad5cc75f1003548af4f28b4fb
Author: Matt Riedemann <email address hidden>
Date: Tue Nov 20 13:55:55 2018 -0500

    Remove GROUP BY clause from CellMapping.get_by_project_id

    Under postgresql, the GROUP BY clause in this query fails with:

      DBError: (psycopg2.ProgrammingError) column "instance_mappings.created_at"
      must appear in the GROUP BY clause or be used in an aggregate function

    And we're getting lucky with using this under mysql because we don't
    have the ONLY_FULL_GROUP_BY mode set (but we probably should).

    This change removes the GROUP BY clause and re-writes the query
    to avoid the joinedload() from the instance_mappings table and
    simply do a subquery to get the cell_ids and then do a simple
    IN query with the cell_mappings table. This fixes the GROUP BY
    issue and should also make the query more efficient since we
    won't have to load InstanceMappings ORM objects.

    Change-Id: Idc9b5ad019205f447c82a702dd3391fa5dd20228
    Closes-Bug: #1804271
    (cherry picked from commit 248750578a938a1eaa2e49004302d14ab7318c5b)

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

This issue was fixed in the openstack/nova 19.0.0.0rc1 release candidate.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers