search

openstack-k8s-operators / nova-operator

Apache License 2.0
8 stars 44 forks source link

The nova-api service runs with partial oslo.config due to config validation error #434

Open gibizer opened 1 year ago

gibizer commented 1 year ago

We set metadata_workers to 0 for the nova-api and the nova-api starts but fails to load the full oslo configuration as the config validation fails with:

$ oc logs nova-api-0 -f -c nova-api-api
[snip]
+ exec /usr/sbin/httpd -DFOREGROUND
mod_wsgi (pid=12): Attach interpreter ''.
mod_wsgi (pid=12): Imported 'mod_wsgi'.
mod_wsgi (pid=12): Started thread 0 in daemon process 'nova-api'.
AH01628: authorization result: granted (no directives)
AH01628: authorization result: granted (no directives)
mod_wsgi (pid=12, process='nova-api', application=''): Loading Python script file '/usr/bin/nova-api-wsgi'.
Modules with known eventlet monkey patching issues were imported prior to eventlet monkey patching: urllib3. This warning can usually be ignored if the caller is only importing and not executing nova code.
mod_wsgi (pid=12): Callback registration for signal 12 ignored.
  File "/usr/bin/nova-api-wsgi", line 52, in <module>
    application = init_application()
  File "/usr/lib/python3.9/site-packages/nova/api/openstack/compute/wsgi.py", line 20, in init_application
    return wsgi_app.init_application(NAME)
  File "/usr/lib/python3.9/site-packages/nova/api/openstack/wsgi_app.py", line 128, in init_application
    init_global_data(conf_files, name)
  File "/usr/lib/python3.9/site-packages/nova/utils.py", line 1122, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3.9/site-packages/nova/api/openstack/wsgi_app.py", line 105, in init_global_data
    gmr.TextGuruMeditation.setup_autorun(
  File "/usr/lib/python3.9/site-packages/oslo_reports/guru_meditation_report.py", line 152, in setup_autorun
    cls._setup_signal(signal.SIGUSR2,
  File "/usr/lib/python3.9/site-packages/oslo_reports/guru_meditation_report.py", line 185, in _setup_signal
    signal.signal(signum,
mod_wsgi (pid=12): Failed to exec Python script file '/usr/bin/nova-api-wsgi'.
mod_wsgi (pid=12): Exception occurred processing WSGI script '/usr/bin/nova-api-wsgi'.
Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2716, in _do_get
    return (convert(val), alt_loc)
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2685, in convert
    return self._convert_value(
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2813, in _convert_value
    return opt.type(value)
  File "/usr/lib/python3.9/site-packages/oslo_config/types.py", line 315, in __call__
    raise ValueError('Should be greater than or equal to %g' %
ValueError: Should be greater than or equal to 1
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/bin/nova-api-wsgi", line 52, in <module>
    application = init_application()
  File "/usr/lib/python3.9/site-packages/nova/api/openstack/compute/wsgi.py", line 20, in init_application
    return wsgi_app.init_application(NAME)
  File "/usr/lib/python3.9/site-packages/nova/api/openstack/wsgi_app.py", line 128, in init_application
    init_global_data(conf_files, name)
  File "/usr/lib/python3.9/site-packages/nova/utils.py", line 1122, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python3.9/site-packages/nova/api/openstack/wsgi_app.py", line 114, in init_global_data
    CONF.log_opt_values(
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2603, in log_opt_values
    _sanitize(opt, getattr(self, opt_name)))
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2219, in __getattr__
    return self._get(name)
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2653, in _get
    value, loc = self._do_get(name, group, namespace)
  File "/usr/lib/python3.9/site-packages/oslo_config/cfg.py", line 2732, in _do_get
    raise ConfigFileValueError(message)
oslo_config.cfg.ConfigFileValueError: Value for option metadata_workers from LocationInfo(location=<Locations.user: (4, True)>, detail='/etc/nova/nova.conf.d/01-nova.conf') is not valid: Should be greater than or equal to 1

Then the nova-api only logs a subset of the oslo.config parameters so it actually runs with a partial config:

2023-07-05 08:33:50.247 12 DEBUG nova.api.openstack.wsgi_app [-] ******************************************************************************** log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2589
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] Configuration options gathered from: log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2590
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] command line args: [] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2591
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] config files: ['/etc/nova/api-paste.ini', '/etc/nova/nova.conf'] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2592
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] ================================================================================ log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2594
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] allow_resize_to_same_host      = True log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] arq_binding_timeout            = 300 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] block_device_allocate_retries  = 60 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] block_device_allocate_retries_interval = 3 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] cert                           = self.pem log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] compute_driver                 = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.248 12 DEBUG nova.api.openstack.wsgi_app [-] compute_monitors               = [] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] config_dir                     = ['/etc/nova/nova.conf.d'] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] config_drive_format            = iso9660 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] config_file                    = ['/etc/nova/api-paste.ini', '/etc/nova/nova.conf'] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] config_source                  = [] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] console_host                   = nova-api-0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] control_exchange               = nova log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] cpu_allocation_ratio           = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] daemon                         = False log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] debug                          = True log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] default_access_ip_network_name = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] default_availability_zone      = nova log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] default_ephemeral_format       = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.249 12 DEBUG nova.api.openstack.wsgi_app [-] default_log_levels             = ['amqp=WARN', 'amqplib=WARN', 'boto=WARN', 'qpid=WARN', 'sqlalchemy=WARN', 'suds=INFO', 'oslo.messaging=INFO', 'oslo_messaging=INFO', 'iso8601=WARN', 'requests.packages.urllib3.connectionpool=WARN', 'urllib3.connectionpool=WARN', 'websocket=WARN', 'requests.packages.urllib3.util.retry=WARN', 'urllib3.util.retry=WARN', 'keystonemiddleware=WARN', 'routes.middleware=WARN', 'stevedore=WARN', 'taskflow=WARN', 'keystoneauth=WARN', 'oslo.cache=INFO', 'oslo_policy=INFO', 'dogpile.core.dogpile=INFO', 'glanceclient=WARN', 'oslo.privsep.daemon=INFO'] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] default_schedule_zone          = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] disk_allocation_ratio          = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] enable_new_services            = True log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] enabled_apis                   = ['osapi_compute', 'metadata'] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] enabled_ssl_apis               = [] log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] flat_injected                  = False log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] force_config_drive             = True log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] force_raw_images               = True log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] graceful_shutdown_timeout      = 60 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] heal_instance_info_cache_interval = 60 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] host                           = nova-api-0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] initial_cpu_allocation_ratio   = 4.0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] initial_disk_allocation_ratio  = 1.0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] initial_ram_allocation_ratio   = 1.0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.250 12 DEBUG nova.api.openstack.wsgi_app [-] injected_network_template      = /usr/lib/python3.9/site-packages/nova/virt/interfaces.template log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_build_timeout         = 0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_delete_interval       = 300 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_format                = [instance: %(uuid)s]  log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_name_template         = instance-%08x log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_usage_audit           = False log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_usage_audit_period    = month log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instance_uuid_format           = [instance: %(uuid)s]  log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] instances_path                 = /var/lib/nova/instances log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] internal_service_availability_zone = internal log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] key                            = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] live_migration_retry_count     = 30 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_config_append              = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_date_format                = %Y-%m-%d %H:%M:%S log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_dir                        = None log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_file                       = /var/log/nova/nova-api.log log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_options                    = True log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_rotate_interval            = 1 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.251 12 DEBUG nova.api.openstack.wsgi_app [-] log_rotate_interval_type       = days log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] log_rotation_type              = size log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] logging_context_format_string  = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(user_identity)s] %(instance)s%(message)s log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] logging_debug_format_suffix    = %(funcName)s %(pathname)s:%(lineno)d log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] logging_default_format_string  = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(instance)s%(message)s log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] logging_exception_prefix       = %(asctime)s.%(msecs)03d %(process)d ERROR %(name)s %(instance)s log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] logging_user_identity_format   = %(user)s %(project)s %(domain)s %(system_scope)s %(user_domain)s %(project_domain)s log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] long_rpc_timeout               = 1800 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] max_concurrent_builds          = 10 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] max_concurrent_live_migrations = 1 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] max_concurrent_snapshots       = 5 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] max_local_block_devices        = 3 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] max_logfile_count              = 5 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] max_logfile_size_mb            = 50 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] maximum_instance_delete_attempts = 5 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] metadata_listen                = 0.0.0.0 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.252 12 DEBUG nova.api.openstack.wsgi_app [-] metadata_listen_port           = 8775 log_opt_values /usr/lib/python3.9/site-packages/oslo_config/cfg.py:2602
2023-07-05 08:33:50.254 12 INFO nova.api.openstack.wsgi_app [-] Global data already initialized, not re-initializing.

If the metadata_workers is set to 1 the nova-api dumps the full oslo.config as expected see full.txt

gibizer commented 1 year ago

full.txt

gibizer commented 1 year ago

I tried in devstack where we use uwsgi instead of mod_wsgi. There the nova-api process exists if the config is invalid.

Jul 05 08:20:08 gibi-devstack-aio devstack@n-api.service[3619164]: ERROR nova oslo_config.cfg.ConfigFileValueError: Value for option metadata_workers from LocationInfo(location=<Locations.user: (4, True)>, detai>
Jul 05 08:20:08 gibi-devstack-aio devstack@n-api.service[3619164]: ERROR nova 
Jul 05 08:20:08 gibi-devstack-aio devstack@n-api.service[3619164]: unable to load app 0 (mountpoint='') (callable not found or import error)
Jul 05 08:20:08 gibi-devstack-aio devstack@n-api.service[3619164]: *** no app loaded. going in full dynamic mode ***
Jul 05 08:20:33 gibi-devstack-aio devstack@n-api.service[3619163]: --- no python application found, check your startup logs for errors ---
gibizer commented 1 year ago

So there are two issues actually: 1) nova-operator generates a wrong config 2) the nova-api and nova-metadata detects the invalid config but it does not fail but instead starts with an incomplete config

gibizer commented 1 year ago
  1. is fixed by https://github.com/openstack-k8s-operators/nova-operator/pull/436