OpenStack Compute (nova)

Comment 3 for bug 1778305

Revision history for this message

Trygve Vea (trygve-vea-gmail) wrote on 2018-06-25:

We're running Pike (nova 16.1.4), on Centos 7.5 with the RDO packages.

This error message didn't come with a stack trace, it was just logged in nova-api.log

Running nova-api in debug mode yielded the following logs when making the call:

2018-06-22 23:26:50.348 22073 DEBUG nova.api.openstack.wsgi [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Calling method '<bound method ServersController.detail of <nova.api.openstack.compute.servers.ServersController object at 0x7f92cdf14d90>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-06-22 23:26:50.353 22073 DEBUG nova.compute.api [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Searching by: {'deleted': False, 'project_id': u'2b633b0b2ca84e748e37b0b12bbb81fc'} get_all /usr/lib/python2.7/site-packages/nova/compute/api.py:2356
2018-06-22 23:26:50.376 22073 DEBUG oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] 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/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-06-22 23:26:50.400 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-06-22 23:26:50.402 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-06-22 23:26:50.404 22073 WARNING oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] URL mysql://nova:***@ctrl.acme.org/nova_cell0 does not contain a '+drivername' portion, and will make use of a default driver. A full dbname+drivername:// protocol is recommended. For MySQL, it is strongly recommended that mysql+pymysql:// be specified for maximum service compatibility
2018-06-22 23:26:50.428 22073 DEBUG oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] 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/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-06-22 23:26:50.487 22073 DEBUG nova.compute.api [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Found 3 cells: e4e9275c-58e0-4f5a-8b6e-796170ed4be2(default),00000000-0000-0000-0000-000000000000(cell0),64d8fd40-3b4b-4d12-b177-4b767821073c(default) load_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:236
2018-06-22 23:26:50.487 22073 DEBUG nova.compute.api [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Listing 1000 instances in cell e4e9275c-58e0-4f5a-8b6e-796170ed4be2(default) _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2559
2018-06-22 23:26:50.488 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "e4e9275c-58e0-4f5a-8b6e-796170ed4be2" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-06-22 23:26:50.490 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "e4e9275c-58e0-4f5a-8b6e-796170ed4be2" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-06-22 23:26:50.490 22073 WARNING oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] URL mysql://nova:***@ctrl.acme.org/nova does not contain a '+drivername' portion, and will make use of a default driver. A full dbname+drivername:// protocol is recommended. For MySQL, it is strongly recommended that mysql+pymysql:// be specified for maximum service compatibility
2018-06-22 23:26:50.512 22073 DEBUG oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] 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/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-06-22 23:26:50.590 22073 DEBUG nova.objects.service [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de8
9c349fdaf8] Generated UUID 2dd86bf1-a805-42ef-9fb8-c94c9c3408fe for service 104 _from_db_object /usr/lib/python2.7/site-packages/nova/objects/service.py:245
2018-06-22 23:26:50.596 22073 INFO nova.api.openstack.wsgi [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] HTTP exception thrown: This service is older (v9) than the minimum (v16) version of the rest of the deployment. Unable to continue.
2018-06-22 23:26:50.596 22073 DEBUG nova.api.openstack.wsgi [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Returning 400 to user: This service is older (v9) than the minimum (v16) version of the rest of the deployment. Unable to continue. __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:1029
2018-06-22 23:26:50.597 22073 INFO nova.osapi_compute.wsgi.server [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] IPV6_ADDRESS_OF_CALLER "GET /v2/2b633b0b2ca84e748e37b0b12bbb81fc/servers/detail HTTP/1.1" status: 400 len: 439 time: 0.4044061
2018-06-22 23:59:31.592 22073 DEBUG nova.osapi_compute.wsgi.server [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] (22073) accepted ('IPV6_ADDRESS_OF_CALLER', 59370, 0, 0) server /usr/lib/python2.7/site-packages/eventlet/wsgi.py:883

We're running Pike (nova 16.1.4), on Centos 7.5 with the RDO packages.

This error message didn't come with a stack trace, it was just logged in nova-api.log

Running nova-api in debug mode yielded the following logs when making the call:

2018-06-22 23:26:50.348 22073 DEBUG nova.api.openstack.wsgi [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Calling method '<bound method ServersController.detail of <nova.api.openstack.compute.servers.ServersController object at 0x7f92cdf14d90>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-06-22 23:26:50.353 22073 DEBUG nova.compute.api [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Searching by: {'deleted': False, 'project_id': u'2b633b0b2ca84e748e37b0b12bbb81fc'} get_all /usr/lib/python2.7/site-packages/nova/compute/api.py:2356
2018-06-22 23:26:50.376 22073 DEBUG oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] 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/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-06-22 23:26:50.400 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-06-22 23:26:50.402 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-06-22 23:26:50.404 22073 WARNING oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] URL mysql://nova:***@ctrl.acme.org/nova_cell0 does not contain a '+drivername' portion, and will make use of a default driver.  A full dbname+drivername:// protocol is recommended. For MySQL, it is strongly recommended that mysql+pymysql:// be specified for maximum service compatibility
2018-06-22 23:26:50.428 22073 DEBUG oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] 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/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-06-22 23:26:50.487 22073 DEBUG nova.compute.api [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Found 3 cells: e4e9275c-58e0-4f5a-8b6e-796170ed4be2(default),00000000-0000-0000-0000-000000000000(cell0),64d8fd40-3b4b-4d12-b177-4b767821073c(default) load_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:236
2018-06-22 23:26:50.487 22073 DEBUG nova.compute.api [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Listing 1000 instances in cell e4e9275c-58e0-4f5a-8b6e-796170ed4be2(default) _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2559
2018-06-22 23:26:50.488 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "e4e9275c-58e0-4f5a-8b6e-796170ed4be2" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-06-22 23:26:50.490 22073 DEBUG oslo_concurrency.lockutils [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Lock "e4e9275c-58e0-4f5a-8b6e-796170ed4be2" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-06-22 23:26:50.490 22073 WARNING oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] URL mysql://nova:***@ctrl.acme.org/nova does not contain a '+drivername' portion, and will make use of a default driver.  A full dbname+drivername:// protocol is recommended. For MySQL, it is strongly recommended that mysql+pymysql:// be specified for maximum service compatibility
2018-06-22 23:26:50.512 22073 DEBUG oslo_db.sqlalchemy.engines [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] 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/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-06-22 23:26:50.590 22073 DEBUG nova.objects.service [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de8
9c349fdaf8] Generated UUID 2dd86bf1-a805-42ef-9fb8-c94c9c3408fe for service 104 _from_db_object /usr/lib/python2.7/site-packages/nova/objects/service.py:245
2018-06-22 23:26:50.596 22073 INFO nova.api.openstack.wsgi [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] HTTP exception thrown: This service is older (v9) than the minimum (v16) version of the rest of the deployment. Unable to continue.
2018-06-22 23:26:50.596 22073 DEBUG nova.api.openstack.wsgi [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] Returning 400 to user: This service is older (v9) than the minimum (v16) version of the rest of the deployment. Unable to continue. __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:1029
2018-06-22 23:26:50.597 22073 INFO nova.osapi_compute.wsgi.server [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] IPV6_ADDRESS_OF_CALLER "GET /v2/2b633b0b2ca84e748e37b0b12bbb81fc/servers/detail HTTP/1.1" status: 400 len: 439 time: 0.4044061
2018-06-22 23:59:31.592 22073 DEBUG nova.osapi_compute.wsgi.server [req-3e0ababe-e09b-4ef8-ba3a-43060bc1f807 f5aa981c393d716b7a4d6d4407a5e29445732b73c062edab167017160a65b680 2b633b0b2ca84e748e37b0b12bbb81fc - 5039e916e83448099a0de89c349fdaf8 5039e916e83448099a0de89c349fdaf8] (22073) accepted ('IPV6_ADDRESS_OF_CALLER', 59370, 0, 0) server /usr/lib/python2.7/site-packages/eventlet/wsgi.py:883