Skip to content
This repository has been archived by the owner on Apr 27, 2022. It is now read-only.

OSProfiler is not getting traces from every service #6

Closed
EmreAtes opened this issue Jun 27, 2018 · 9 comments
Closed

OSProfiler is not getting traces from every service #6

EmreAtes opened this issue Jun 27, 2018 · 9 comments

Comments

@EmreAtes
Copy link
Contributor

This is mostly up to me to fix, but I'm writing some progress here. Any help is most welcome.

Steps to reproduce

  1. Install devstack according to the instructions
  2. Source openrc with parameters admin admin
  3. Run an openstack command - I used openstack --os-profile Devstack1 server create --flavor m1.tiny --image cirros-0.3.5-x86_64-disk test_server_1
  4. Retrieve the trace using osprofiler trace show --json --connection-string redis://localhost:6379 $TRACE_ID

Result

The trace only contains traces from glance after these operations. I've also checked redis using redis-cli and then KEYS osprofiler* and the traces match - there are only 8 entries for the VM create command, all from glance.

Additional Info

After devstack is running, every service can be restarted using sudo systemctl restart devstack@*, which fixes something in keystone. After this, I can get keystone traces as well, but still nothing from nova.
@HuzefaMandvi
Copy link
Contributor

Is the VM creation issue fixed now? i.e. is the VM in active state or nostate?

@EmreAtes
Copy link
Contributor Author

Applying these patches enables getting traces from neuron and nova:

https://review.openstack.org/#/c/273951/16/etc/api-paste.ini

https://review.openstack.org/#/c/519664/3/nova/api/openstack/wsgi_app.py

@EmreAtes
Copy link
Contributor Author

EmreAtes commented Jun 28, 2018 •
edited
Loading

I applied the patches to the corresponding services under /opt/stack, and then ran sudo pip install --no-deps --force-reinstall -U . inside /opt/stack/nova and /opt/stack/neutron. After this I ran sudo systemctl restart devstack@*, and then I could get traces, but I also get a 500 error when I try to create VMs.

@EmreAtes
Copy link
Contributor Author

There's an error when creating VMs after applying the patches. This is the debug output:

START with options: [u'--debug', u'--os-profile', u'Devstack1', u'server', u'create', u'--image', u'cirros-0.3.5-x86_64-disk', u'--flavor', u'm1.tiny', u'test_server_3']
options: Namespace(access_key='', access_secret='***', access_token='***', access_token_endpoint='', access_token_type='', auth_type='password', auth_url='http://192.168.0.10/identity', cacert=None, cert='', client_id='', client_secret='***', cloud='', code='', consumer_key='', consumer_secret='***', debug=True, default_domain='default', default_domain_id='', default_domain_name='', deferred_help=False, discovery_endpoint='', domain_id='', domain_name='', endpoint='', glare_url='', identity_provider='', identity_provider_url='', insecure=None, interface='', key='', log_file=None, murano_packages_service='murano', murano_url='', openid_scope='', os_application_catalog_api_version='1', os_baremetal_api_version='1.9', os_beta_command=False, os_clustering_api_version='1', os_compute_api_version='', os_container_infra_api_version='1', os_data_processing_api_version='1.1', os_data_processing_url='', os_database_api_version='1', os_dns_api_version='2', os_event_api_version='2', os_identity_api_version='3', os_image_api_version='', os_infra_optim_api_version='1', os_key_manager_api_version='1', os_metrics_api_version='1', os_network_api_version='', os_object_api_version='', os_orchestration_api_version='1', os_project_id=None, os_project_name=None, os_queues_api_version='2', os_volume_api_version='2', os_workflow_api_version='2', passcode='', password='***', profile=u'Devstack1', project_domain_id='default', project_domain_name='', project_id='', project_name='admin', protocol='', redirect_uri='', region_name='RegionOne', roles='', service_provider_endpoint='', service_provider_entity_id='', timing=False, token='***', trust_id='', url='', user='', user_domain_id='default', user_domain_name='', user_id='', username='admin', verbose_level=3, verify=None)
Auth plugin password selected
auth_config_hook(): {'auth_type': 'password', 'beta_command': False, u'compute_api_version': u'2', 'key': None, u'database_api_version': '1', 'metrics_api_version': '1', 'data_processing_api_version': '1.1', 'auth_url': 'http://192.168.0.10/identity', u'network_api_version': u'2', u'message': u'', u'image_format': u'qcow2', 'networks': [], 'queues_api_version': '2', 'clustering_api_version': '1', 'verify': True, 'event_api_version': '2', u'dns_api_version': '2', u'object_store_api_version': u'1', 'username': 'admin', u'container_infra_api_version': '1', 'verbose_level': 3, 'region_name': 'RegionOne', 'api_timeout': None, u'baremetal_api_version': '1.9', u'image_api_version': u'2', 'auth': {'project_name': 'admin', 'user_domain_id': 'default', 'project_domain_id': 'default'}, 'default_domain': 'default', u'container_api_version': u'1', u'image_api_use_tasks': False, 'profile': u'Devstack1', u'orchestration_api_version': '1', 'timing': False, 'password': '***', u'application_catalog_api_version': '1', 'murano_packages_service': 'murano', 'cacert': None, u'key_manager_api_version': '1', u'metering_api_version': u'2', 'deferred_help': False, u'identity_api_version': '3', u'workflow_api_version': '2', u'volume_api_version': '2', 'infra_optim_api_version': '1', 'cert': None, u'secgroup_source': u'neutron', u'status': u'active', 'debug': True, u'floating_ip_source': u'neutron', u'interface': None, u'disable_vendor_agent': {}}
defaults: {u'auth_type': 'password', u'status': u'active', u'compute_api_version': u'2', 'key': None, u'database_api_version': u'1.0', 'api_timeout': None, u'baremetal_api_version': u'1', u'image_api_version': u'2', u'container_infra_api_version': u'1', u'metering_api_version': u'2', u'image_api_use_tasks': False, u'floating_ip_source': u'neutron', u'orchestration_api_version': u'1', 'cacert': None, u'network_api_version': u'2', u'message': u'', u'image_format': u'qcow2', u'application_catalog_api_version': u'1', u'key_manager_api_version': u'v1', u'workflow_api_version': u'2', 'verify': True, u'identity_api_version': u'2.0', u'volume_api_version': u'2', 'cert': None, u'secgroup_source': u'neutron', u'container_api_version': u'1', u'dns_api_version': u'2', u'object_store_api_version': u'1', u'interface': None, u'disable_vendor_agent': {}}
cloud cfg: {'auth_type': 'password', 'beta_command': False, u'compute_api_version': u'2', 'key': None, u'database_api_version': '1', 'metrics_api_version': '1', 'data_processing_api_version': '1.1', 'auth_url': 'http://192.168.0.10/identity', u'network_api_version': u'2', u'message': u'', u'image_format': u'qcow2', 'networks': [], 'queues_api_version': '2', 'clustering_api_version': '1', 'verify': True, 'event_api_version': '2', u'dns_api_version': '2', u'object_store_api_version': u'1', 'username': 'admin', u'container_infra_api_version': '1', 'verbose_level': 3, 'region_name': 'RegionOne', 'api_timeout': None, u'baremetal_api_version': '1.9', u'image_api_version': u'2', 'auth': {'project_name': 'admin', 'user_domain_id': 'default', 'project_domain_id': 'default'}, 'default_domain': 'default', u'container_api_version': u'1', u'image_api_use_tasks': False, 'profile': u'Devstack1', u'orchestration_api_version': '1', 'timing': False, 'password': '***', u'application_catalog_api_version': '1', 'murano_packages_service': 'murano', 'cacert': None, u'key_manager_api_version': '1', u'metering_api_version': u'2', 'deferred_help': False, u'identity_api_version': '3', u'workflow_api_version': '2', u'volume_api_version': '2', 'infra_optim_api_version': '1', 'cert': None, u'secgroup_source': u'neutron', u'status': u'active', 'debug': True, u'floating_ip_source': u'neutron', u'interface': None, u'disable_vendor_agent': {}}
compute API version 2, cmd group openstack.compute.v2
network API version 2, cmd group openstack.network.v2
image API version 2, cmd group openstack.image.v2
volume API version 2, cmd group openstack.volume.v2
identity API version 3, cmd group openstack.identity.v3
object_store API version 1, cmd group openstack.object_store.v1
messaging API version 2, cmd group openstack.messaging.v2
infra-optim API version 1, cmd group openstack.infra_optim.v1
database API version 1, cmd group openstack.database.v1
clustering API version 1, cmd group openstack.clustering.v1
data_processing API version 1.1, cmd group openstack.data_processing.v1
neutronclient API version 2, cmd group openstack.neutronclient.v2
application_catalog API version 1, cmd group openstack.application_catalog.v1
workflow_engine API version 2, cmd group openstack.workflow_engine.v2
container_infra API version 1, cmd group openstack.container_infra.v1
baremetal API version 1.9, cmd group openstack.baremetal.v1
orchestration API version 1, cmd group openstack.orchestration.v1
dns API version 2, cmd group openstack.dns.v2
key_manager API version 1, cmd group openstack.key_manager.v1
event API version 2, cmd group openstack.event.v2
metric API version 1, cmd group openstack.metric.v1
Auth plugin password selected
auth_config_hook(): {'auth_type': 'password', 'beta_command': False, u'compute_api_version': u'2', 'key': None, u'database_api_version': '1', 'metrics_api_version': '1', 'data_processing_api_version': '1.1', 'auth_url': 'http://192.168.0.10/identity', u'network_api_version': u'2', u'message': u'', u'image_format': u'qcow2', 'networks': [], 'queues_api_version': '2', 'clustering_api_version': '1', 'verify': True, 'event_api_version': '2', u'dns_api_version': '2', u'object_store_api_version': u'1', 'username': 'admin', u'container_infra_api_version': '1', 'verbose_level': 3, 'region_name': 'RegionOne', 'api_timeout': None, u'baremetal_api_version': '1.9', u'image_api_version': u'2', 'auth': {'project_name': 'admin', 'user_domain_id': 'default', 'project_domain_id': 'default'}, 'default_domain': 'default', u'container_api_version': u'1', u'image_api_use_tasks': False, 'profile': u'Devstack1', u'orchestration_api_version': '1', 'timing': False, 'password': '***', u'application_catalog_api_version': '1', 'murano_packages_service': 'murano', 'cacert': None, u'key_manager_api_version': '1', u'metering_api_version': u'2', 'deferred_help': False, u'identity_api_version': '3', u'workflow_api_version': '2', u'volume_api_version': '2', 'infra_optim_api_version': '1', 'cert': None, u'secgroup_source': u'neutron', u'status': u'active', 'debug': True, u'floating_ip_source': u'neutron', u'interface': None, u'disable_vendor_agent': {}}
Auth plugin password selected
auth_config_hook(): {'auth_type': 'password', 'beta_command': False, u'compute_api_version': u'2', 'key': None, u'database_api_version': '1', 'metrics_api_version': '1', 'data_processing_api_version': '1.1', 'auth_url': 'http://192.168.0.10/identity', u'network_api_version': u'2', u'message': u'', u'image_format': u'qcow2', 'networks': [], 'queues_api_version': '2', 'clustering_api_version': '1', 'verify': True, 'event_api_version': '2', u'dns_api_version': '2', u'object_store_api_version': u'1', 'username': 'admin', u'container_infra_api_version': '1', 'verbose_level': 3, 'region_name': 'RegionOne', 'api_timeout': None, u'baremetal_api_version': '1.9', u'image_api_version': u'2', 'auth': {'project_name': 'admin', 'user_domain_id': 'default', 'project_domain_id': 'default'}, 'default_domain': 'default', u'container_api_version': u'1', u'image_api_use_tasks': False, 'profile': u'Devstack1', u'orchestration_api_version': '1', 'timing': False, 'password': '***', u'application_catalog_api_version': '1', 'murano_packages_service': 'murano', 'cacert': None, u'key_manager_api_version': '1', u'metering_api_version': u'2', 'deferred_help': False, u'identity_api_version': '3', u'workflow_api_version': '2', u'volume_api_version': '2', 'infra_optim_api_version': '1', 'cert': None, u'secgroup_source': u'neutron', u'status': u'active', 'debug': True, u'floating_ip_source': u'neutron', u'interface': None, u'disable_vendor_agent': {}}
command: server create -> openstackclient.compute.v2.server.CreateServer (auth=True)
Auth plugin password selected
auth_config_hook(): {'auth_type': 'password', 'beta_command': False, u'compute_api_version': u'2', 'key': None, u'database_api_version': '1', 'metrics_api_version': '1', 'data_processing_api_version': '1.1', 'auth_url': 'http://192.168.0.10/identity', u'network_api_version': u'2', u'message': u'', u'image_format': u'qcow2', 'networks': [], 'queues_api_version': '2', 'clustering_api_version': '1', 'verify': True, 'event_api_version': '2', u'dns_api_version': '2', u'object_store_api_version': u'1', 'username': 'admin', u'container_infra_api_version': '1', 'verbose_level': 3, 'region_name': 'RegionOne', 'api_timeout': None, u'baremetal_api_version': '1.9', u'image_api_version': u'2', 'auth': {'project_name': 'admin', 'user_domain_id': 'default', 'project_domain_id': 'default'}, 'default_domain': 'default', u'container_api_version': u'1', u'image_api_use_tasks': False, 'profile': u'Devstack1', u'orchestration_api_version': '1', 'timing': False, 'password': '***', u'application_catalog_api_version': '1', 'murano_packages_service': 'murano', 'cacert': None, u'key_manager_api_version': '1', u'metering_api_version': u'2', 'deferred_help': False, u'identity_api_version': '3', u'workflow_api_version': '2', u'volume_api_version': '2', 'infra_optim_api_version': '1', 'cert': None, u'secgroup_source': u'neutron', u'status': u'active', 'debug': True, u'floating_ip_source': u'neutron', u'interface': None, u'disable_vendor_agent': {}}
Using auth plugin: password
Using parameters {'username': 'admin', 'project_name': 'admin', 'user_domain_id': 'default', 'auth_url': 'http://192.168.0.10/identity', 'password': '***', 'project_domain_id': 'default'}
Get auth_ref
REQ: curl -g -i -X GET http://192.168.0.10/identity -H "X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5" -H "X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=" -H "Accept: application/json" -H "User-Agent: osc-lib/1.7.0 keystoneauth1/3.1.0 python-requests/2.18.2 CPython/2.7.5"
Starting new HTTP connection (1): 192.168.0.10
http://192.168.0.10:80 "GET /identity HTTP/1.1" 300 606
RESP: [300] Date: Thu, 28 Jun 2018 19:48:10 GMT Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5 Vary: X-Auth-Token Content-Type: application/json Content-Length: 606 Connection: close 
RESP BODY: {"versions": {"values": [{"status": "stable", "updated": "2017-02-22T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.8", "links": [{"href": "http://192.168.0.10/identity/v3/", "rel": "self"}]}, {"status": "deprecated", "updated": "2016-08-04T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v2.0+json"}], "id": "v2.0", "links": [{"href": "http://192.168.0.10/identity/v2.0/", "rel": "self"}, {"href": "https://docs.openstack.org/", "type": "text/html", "rel": "describedby"}]}]}}

Making authentication request to http://192.168.0.10/identity/v3/auth/tokens
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "POST /identity/v3/auth/tokens HTTP/1.1" 201 3655
{"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "15831ea5b53d46d2b513539230fe7714", "name": "admin"}], "expires_at": "2018-06-28T20:48:10.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "d8dedd2a11d5447aa69f2cc2461de6d8", "name": "admin"}, "catalog": [{"endpoints": [{"url": "http://192.168.0.10/volume/v1/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "7c2e90686f644d1d8731a6a940c85c35"}], "type": "volume", "id": "4b9218689c22475d87ab298f2676d39a", "name": "cinder"}, {"endpoints": [{"url": "http://192.168.0.10/compute/v2/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "2aa2aea7d0ae45ce8f3399aabd67f1c5"}], "type": "compute_legacy", "id": "884cea0d9a2b428794c0641cac1dff71", "name": "nova_legacy"}, {"endpoints": [{"url": "http://192.168.0.10/volume/v2/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "f0cf7df6b18646a0bf395e518f8e756e"}], "type": "volumev2", "id": "89fff24856b749da9a74d72ed825d802", "name": "cinderv2"}, {"endpoints": [{"url": "http://192.168.0.10:8977", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "0720c175408144438cc380297b65778f"}, {"url": "http://192.168.0.10:8977", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "81d01ce087244362b11f9153fce8ff96"}, {"url": "http://192.168.0.10:8977", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "beb290ce49bf48b18358ea8b7cec54ce"}], "type": "event", "id": "94dae295102546a5acf23ef4bb9a0874", "name": "panko"}, {"endpoints": [{"url": "http://192.168.0.10:9696/", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "d2332705f9c540c29c2f8319924735c3"}], "type": "network", "id": "9b7be4ae6d464369939c1fa4675f16ec", "name": "neutron"}, {"endpoints": [{"url": "http://192.168.0.10/placement", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "ba304f668dbd40bab5de0d31c7ae29ee"}], "type": "placement", "id": "ae34c57217504790aaf012a7ed26ee95", "name": "placement"}, {"endpoints": [{"url": "http://192.168.0.10/image", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "924ac061e2cb4707b7af2185d98a53c7"}], "type": "image", "id": "bcc875169958449f839858c97a5a1201", "name": "glance"}, {"endpoints": [{"url": "http://192.168.0.10/identity", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "0c9b1c08cc10428a952ba0534f5eb3f6"}, {"url": "http://192.168.0.10/identity", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "8502da6061b94809a2fc4b168cbb8309"}], "type": "identity", "id": "d3632663dfc843ee96768a54c5a2f70b", "name": "keystone"}, {"endpoints": [{"url": "http://192.168.0.10/compute/v2.1", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "2d4bc5abe8134801b01d041c117cd7f3"}], "type": "compute", "id": "e285fed8789540fc900133efa232c5c5", "name": "nova"}, {"endpoints": [{"url": "http://192.168.0.10/volume/v3/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "9abf7f3a72434112989f888b0684fd05"}], "type": "volumev3", "id": "ff17b52aafa146019d7b0157b19f9881", "name": "cinderv3"}], "user": {"domain": {"id": "default", "name": "Default"}, "password_expires_at": null, "name": "admin", "id": "32fdf588e1be4fe5b59bc9ca10e2a3d3"}, "audit_ids": ["O9On1ay6RPKhvy4oDEA0dw"], "issued_at": "2018-06-28T19:48:10.000000Z"}}
run(Namespace(availability_zone=None, block_device_mapping={}, columns=[], config_drive=False, file=[], fit_width=False, flavor=u'm1.tiny', formatter='table', hint=[], image=u'cirros-0.3.5-x86_64-disk', key_name=None, max=1, max_width=0, min=1, nic=None, noindent=False, prefix='', print_empty=False, property=None, security_group=[], server_name=u'test_server_3', user_data=None, variables=[], volume=None, wait=False))
Instantiating compute client for API Version Major: 2, Minor: 0
Instantiating compute api: <class 'openstackclient.api.compute_v2.APIv2'>
Instantiating volume client: <class 'cinderclient.v2.client.Client'>
Instantiating image client: <class 'glanceclient.v2.client.Client'>
Making authentication request to http://192.168.0.10/identity/v3/auth/tokens
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "POST /identity/v3/auth/tokens HTTP/1.1" 201 3655
{"token": {"is_domain": false, "methods": ["password"], "roles": [{"id": "15831ea5b53d46d2b513539230fe7714", "name": "admin"}], "expires_at": "2018-06-28T20:48:11.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "d8dedd2a11d5447aa69f2cc2461de6d8", "name": "admin"}, "catalog": [{"endpoints": [{"url": "http://192.168.0.10/volume/v1/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "7c2e90686f644d1d8731a6a940c85c35"}], "type": "volume", "id": "4b9218689c22475d87ab298f2676d39a", "name": "cinder"}, {"endpoints": [{"url": "http://192.168.0.10/compute/v2/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "2aa2aea7d0ae45ce8f3399aabd67f1c5"}], "type": "compute_legacy", "id": "884cea0d9a2b428794c0641cac1dff71", "name": "nova_legacy"}, {"endpoints": [{"url": "http://192.168.0.10/volume/v2/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "f0cf7df6b18646a0bf395e518f8e756e"}], "type": "volumev2", "id": "89fff24856b749da9a74d72ed825d802", "name": "cinderv2"}, {"endpoints": [{"url": "http://192.168.0.10:8977", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "0720c175408144438cc380297b65778f"}, {"url": "http://192.168.0.10:8977", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "81d01ce087244362b11f9153fce8ff96"}, {"url": "http://192.168.0.10:8977", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "beb290ce49bf48b18358ea8b7cec54ce"}], "type": "event", "id": "94dae295102546a5acf23ef4bb9a0874", "name": "panko"}, {"endpoints": [{"url": "http://192.168.0.10:9696/", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "d2332705f9c540c29c2f8319924735c3"}], "type": "network", "id": "9b7be4ae6d464369939c1fa4675f16ec", "name": "neutron"}, {"endpoints": [{"url": "http://192.168.0.10/placement", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "ba304f668dbd40bab5de0d31c7ae29ee"}], "type": "placement", "id": "ae34c57217504790aaf012a7ed26ee95", "name": "placement"}, {"endpoints": [{"url": "http://192.168.0.10/image", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "924ac061e2cb4707b7af2185d98a53c7"}], "type": "image", "id": "bcc875169958449f839858c97a5a1201", "name": "glance"}, {"endpoints": [{"url": "http://192.168.0.10/identity", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "0c9b1c08cc10428a952ba0534f5eb3f6"}, {"url": "http://192.168.0.10/identity", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "8502da6061b94809a2fc4b168cbb8309"}], "type": "identity", "id": "d3632663dfc843ee96768a54c5a2f70b", "name": "keystone"}, {"endpoints": [{"url": "http://192.168.0.10/compute/v2.1", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "2d4bc5abe8134801b01d041c117cd7f3"}], "type": "compute", "id": "e285fed8789540fc900133efa232c5c5", "name": "nova"}, {"endpoints": [{"url": "http://192.168.0.10/volume/v3/d8dedd2a11d5447aa69f2cc2461de6d8", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "9abf7f3a72434112989f888b0684fd05"}], "type": "volumev3", "id": "ff17b52aafa146019d7b0157b19f9881", "name": "cinderv3"}], "user": {"domain": {"id": "default", "name": "Default"}, "password_expires_at": null, "name": "admin", "id": "32fdf588e1be4fe5b59bc9ca10e2a3d3"}, "audit_ids": ["92dHxXS3QzOklAAb4ApLXw"], "issued_at": "2018-06-28T19:48:11.000000Z"}}
Instantiating image api: <class 'openstackclient.api.image_v2.APIv2'>
curl -g -i -X GET -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521' -H 'X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5' -H 'X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=' -H 'Connection: keep-alive' -H 'User-Agent: python-glanceclient' -H 'Content-Type: application/octet-stream' http://192.168.0.10/image/v2/images/cirros-0.3.5-x86_64-disk
Starting new HTTP connection (1): 192.168.0.10
http://192.168.0.10:80 "GET /image/v2/images/cirros-0.3.5-x86_64-disk HTTP/1.1" 404 169
GET call to image for http://192.168.0.10/image/v2/images/cirros-0.3.5-x86_64-disk used request id req-36d96fda-6361-4907-93e6-9322c6d3234b
Request returned failure status 404.
curl -g -i -X GET -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521' -H 'X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5' -H 'X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=' -H 'Connection: keep-alive' -H 'User-Agent: python-glanceclient' -H 'Content-Type: application/octet-stream' http://192.168.0.10/image/v2/images?limit=20
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "GET /image/v2/images?limit=20 HTTP/1.1" 200 680
GET call to image for http://192.168.0.10/image/v2/images?limit=20 used request id req-dcbf0cc6-7291-4734-9aec-6024b8d1fcd7

HTTP/1.1 200 OK
Date: Thu, 28 Jun 2018 19:48:11 GMT
Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5
Content-Length: 680
Content-Type: application/json
x-openstack-request-id: req-dcbf0cc6-7291-4734-9aec-6024b8d1fcd7
Connection: close

{"images": [{"status": "active", "name": "cirros-0.3.5-x86_64-disk", "tags": [], "container_format": "bare", "created_at": "2018-06-28T19:13:38Z", "size": 13267968, "disk_format": "qcow2", "updated_at": "2018-06-28T19:13:38Z", "visibility": "public", "self": "/v2/images/35d14d2b-629b-43dd-8329-176bf4e462f3", "min_disk": 0, "protected": false, "id": "35d14d2b-629b-43dd-8329-176bf4e462f3", "file": "/v2/images/35d14d2b-629b-43dd-8329-176bf4e462f3/file", "checksum": "f8ab98ff5e73ebab884d80c9dc9c7290", "owner": "d8dedd2a11d5447aa69f2cc2461de6d8", "virtual_size": null, "min_ram": 0, "schema": "/v2/schemas/image"}], "schema": "/v2/schemas/images", "first": "/v2/images?limit=20"}

curl -g -i -X GET -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521' -H 'X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5' -H 'X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=' -H 'Connection: keep-alive' -H 'User-Agent: python-glanceclient' -H 'Content-Type: application/octet-stream' http://192.168.0.10/image/v2/schemas/image
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "GET /image/v2/schemas/image HTTP/1.1" 200 4157
GET call to image for http://192.168.0.10/image/v2/schemas/image used request id req-9ac10f72-a8e3-4a96-8f35-c6c011188b4a

HTTP/1.1 200 OK
Date: Thu, 28 Jun 2018 19:48:11 GMT
Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5
Content-Type: application/json
Content-Length: 4157
x-openstack-request-id: req-9ac10f72-a8e3-4a96-8f35-c6c011188b4a
Connection: close

{"additionalProperties": {"type": "string"}, "name": "image", "links": [{"href": "{self}", "rel": "self"}, {"href": "{file}", "rel": "enclosure"}, {"href": "{schema}", "rel": "describedby"}], "properties": {"status": {"readOnly": true, "enum": ["queued", "saving", "active", "killed", "deleted", "pending_delete", "deactivated"], "type": "string", "description": "Status of the image"}, "tags": {"items": {"type": "string", "maxLength": 255}, "type": "array", "description": "List of strings related to the image"}, "kernel_id": {"pattern": "^([0-9a-fA-F]){8}-([0-9a-fA-F]){4}-([0-9a-fA-F]){4}-([0-9a-fA-F]){4}-([0-9a-fA-F]){12}$", "type": ["null", "string"], "description": "ID of image stored in Glance that should be used as the kernel when booting an AMI-style image.", "is_base": false}, "container_format": {"enum": [null, "ami", "ari", "aki", "bare", "ovf", "ova", "docker"], "type": ["null", "string"], "description": "Format of the container"}, "min_ram": {"type": "integer", "description": "Amount of ram (in MB) required to boot image."}, "ramdisk_id": {"pattern": "^([0-9a-fA-F]){8}-([0-9a-fA-F]){4}-([0-9a-fA-F]){4}-([0-9a-fA-F]){4}-([0-9a-fA-F]){12}$", "type": ["null", "string"], "description": "ID of image stored in Glance that should be used as the ramdisk when booting an AMI-style image.", "is_base": false}, "locations": {"items": {"required": ["url", "metadata"], "type": "object", "properties": {"url": {"type": "string", "maxLength": 255}, "metadata": {"type": "object"}}}, "type": "array", "description": "A set of URLs to access the image file kept in external store"}, "visibility": {"enum": ["community", "public", "private", "shared"], "type": "string", "description": "Scope of image accessibility"}, "updated_at": {"readOnly": true, "type": "string", "description": "Date and time of the last image modification"}, "owner": {"type": ["null", "string"], "description": "Owner of the image", "maxLength": 255}, "file": {"readOnly": true, "type": "string", "description": "An image file url"}, "min_disk": {"type": "integer", "description": "Amount of disk space (in GB) required to boot image."}, "virtual_size": {"readOnly": true, "type": ["null", "integer"], "description": "Virtual size of image in bytes"}, "id": {"pattern": "^([0-9a-fA-F]){8}-([0-9a-fA-F]){4}-([0-9a-fA-F]){4}-([0-9a-fA-F]){4}-([0-9a-fA-F]){12}$", "type": "string", "description": "An identifier for the image"}, "size": {"readOnly": true, "type": ["null", "integer"], "description": "Size of image file in bytes"}, "instance_uuid": {"type": "string", "description": "Metadata which can be used to record which instance this image is associated with. (Informational only, does not create an instance snapshot.)", "is_base": false}, "os_distro": {"type": "string", "description": "Common name of operating system distribution as specified in https://docs.openstack.org/python-glanceclient/latest/cli/property-keys.html", "is_base": false}, "name": {"type": ["null", "string"], "description": "Descriptive name for the image", "maxLength": 255}, "checksum": {"readOnly": true, "type": ["null", "string"], "description": "md5 hash of image contents.", "maxLength": 32}, "created_at": {"readOnly": true, "type": "string", "description": "Date and time of image registration"}, "disk_format": {"enum": [null, "ami", "ari", "aki", "vhd", "vhdx", "vmdk", "raw", "qcow2", "vdi", "iso", "ploop"], "type": ["null", "string"], "description": "Format of the disk"}, "os_version": {"type": "string", "description": "Operating system version as specified by the distributor", "is_base": false}, "protected": {"type": "boolean", "description": "If true, image will not be deletable."}, "architecture": {"type": "string", "description": "Operating system architecture as specified in https://docs.openstack.org/python-glanceclient/latest/cli/property-keys.html", "is_base": false}, "direct_url": {"readOnly": true, "type": "string", "description": "URL to access the image file kept in external store"}, "self": {"readOnly": true, "type": "string", "description": "An image self url"}, "schema": {"readOnly": true, "type": "string", "description": "An image schema url"}}}

REQ: curl -g -i -X GET http://192.168.0.10/compute/v2.1/flavors/m1.tiny -H "X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5" -H "X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=" -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521"
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "GET /compute/v2.1/flavors/m1.tiny HTTP/1.1" 404 80
RESP: [404] Date: Thu, 28 Jun 2018 19:48:11 GMT Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5 OpenStack-API-Version: compute 2.1 X-OpenStack-Nova-API-Version: 2.1 Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version Content-Type: application/json; charset=UTF-8 Content-Length: 80 x-openstack-request-id: req-3de0e24f-9e60-4f8a-a0e2-ac12ce63540e x-compute-request-id: req-3de0e24f-9e60-4f8a-a0e2-ac12ce63540e Connection: close 
RESP BODY: {"itemNotFound": {"message": "Flavor m1.tiny could not be found.", "code": 404}}

GET call to compute for http://192.168.0.10/compute/v2.1/flavors/m1.tiny used request id req-3de0e24f-9e60-4f8a-a0e2-ac12ce63540e
REQ: curl -g -i -X GET http://192.168.0.10/compute/v2.1/flavors -H "X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5" -H "X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=" -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521"
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "GET /compute/v2.1/flavors HTTP/1.1" 200 2241
RESP: [200] Date: Thu, 28 Jun 2018 19:48:11 GMT Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5 Content-Length: 2241 Content-Type: application/json OpenStack-API-Version: compute 2.1 X-OpenStack-Nova-API-Version: 2.1 Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version x-openstack-request-id: req-59c1cac3-0f34-4cfc-9beb-5fe53511741c x-compute-request-id: req-59c1cac3-0f34-4cfc-9beb-5fe53511741c Connection: close 
RESP BODY: {"flavors": [{"id": "1", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/1", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/1", "rel": "bookmark"}], "name": "m1.tiny"}, {"id": "2", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/2", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/2", "rel": "bookmark"}], "name": "m1.small"}, {"id": "3", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/3", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/3", "rel": "bookmark"}], "name": "m1.medium"}, {"id": "4", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/4", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/4", "rel": "bookmark"}], "name": "m1.large"}, {"id": "42", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/42", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/42", "rel": "bookmark"}], "name": "m1.nano"}, {"id": "5", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/5", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/5", "rel": "bookmark"}], "name": "m1.xlarge"}, {"id": "84", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/84", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/84", "rel": "bookmark"}], "name": "m1.micro"}, {"id": "c1", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/c1", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/c1", "rel": "bookmark"}], "name": "cirros256"}, {"id": "d1", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/d1", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/d1", "rel": "bookmark"}], "name": "ds512M"}, {"id": "d2", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/d2", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/d2", "rel": "bookmark"}], "name": "ds1G"}, {"id": "d3", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/d3", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/d3", "rel": "bookmark"}], "name": "ds2G"}, {"id": "d4", "links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/d4", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/d4", "rel": "bookmark"}], "name": "ds4G"}]}

GET call to compute for http://192.168.0.10/compute/v2.1/flavors used request id req-59c1cac3-0f34-4cfc-9beb-5fe53511741c
REQ: curl -g -i -X GET http://192.168.0.10/compute/v2.1/flavors/1 -H "X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5" -H "X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=" -H "User-Agent: python-novaclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521"
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "GET /compute/v2.1/flavors/1 HTTP/1.1" 200 364
RESP: [200] Date: Thu, 28 Jun 2018 19:48:11 GMT Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5 Content-Length: 364 Content-Type: application/json OpenStack-API-Version: compute 2.1 X-OpenStack-Nova-API-Version: 2.1 Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version x-openstack-request-id: req-ea975d24-77c2-4311-ad0c-bf1c16936f2e x-compute-request-id: req-ea975d24-77c2-4311-ad0c-bf1c16936f2e Connection: close 
RESP BODY: {"flavor": {"links": [{"href": "http://192.168.0.10/compute/v2.1/flavors/1", "rel": "self"}, {"href": "http://192.168.0.10/compute/flavors/1", "rel": "bookmark"}], "ram": 512, "OS-FLV-DISABLED:disabled": false, "os-flavor-access:is_public": true, "rxtx_factor": 1.0, "disk": 1, "id": "1", "name": "m1.tiny", "vcpus": 1, "swap": "", "OS-FLV-EXT-DATA:ephemeral": 0}}

GET call to compute for http://192.168.0.10/compute/v2.1/flavors/1 used request id req-ea975d24-77c2-4311-ad0c-bf1c16936f2e
network endpoint in service catalog
Connection: <openstack.connection.Connection object at 0x7effa163ce50>
Network client initialized using OpenStack SDK: <openstack.network.v2._proxy.Proxy object at 0x7effa14f4510>
boot_args: [u'test_server_3', {u'status': u'active', u'tags': [], u'container_format': u'bare', u'min_ram': 0, u'updated_at': u'2018-06-28T19:13:38Z', u'visibility': u'public', u'owner': u'd8dedd2a11d5447aa69f2cc2461de6d8', u'file': u'/v2/images/35d14d2b-629b-43dd-8329-176bf4e462f3/file', u'min_disk': 0, u'virtual_size': None, u'id': u'35d14d2b-629b-43dd-8329-176bf4e462f3', u'size': 13267968, u'name': u'cirros-0.3.5-x86_64-disk', u'checksum': u'f8ab98ff5e73ebab884d80c9dc9c7290', u'created_at': u'2018-06-28T19:13:38Z', u'disk_format': u'qcow2', u'protected': False, u'schema': u'/v2/schemas/image'}, <Flavor: m1.tiny>]
boot_kwargs: {'files': {}, 'userdata': None, 'key_name': None, 'availability_zone': None, 'nics': [], 'max_count': 1, 'meta': None, 'block_device_mapping_v2': [], 'min_count': 1, 'scheduler_hints': {}, 'reservation_id': None, 'security_groups': [], 'config_drive': None}
REQ: curl -g -i -X POST http://192.168.0.10/compute/v2.1/servers -H "X-Trace-HMAC: 0c5c1bd6d4e55876026e98930edff2fa3ee12de5" -H "X-Trace-Info: eyJwYXJlbnRfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIiwgImJhc2VfaWQiOiAiMWJkN2M1M2EtZGIzYy00N2ExLWIyNTAtYjMzNWI1OGYzNjZiIn0=" -H "User-Agent: python-novaclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}9bebb917a22d694aaf85330befe32758046a4521" -d '{"server": {"min_count": 1, "flavorRef": "1", "name": "test_server_3", "imageRef": "35d14d2b-629b-43dd-8329-176bf4e462f3", "max_count": 1}}'
Resetting dropped connection: 192.168.0.10
http://192.168.0.10:80 "POST /compute/v2.1/servers HTTP/1.1" 500 128
RESP: [500] Date: Thu, 28 Jun 2018 19:48:11 GMT Server: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_wsgi/3.4 Python/2.7.5 OpenStack-API-Version: compute 2.1 X-OpenStack-Nova-API-Version: 2.1 Vary: OpenStack-API-Version,X-OpenStack-Nova-API-Version Content-Type: application/json; charset=UTF-8 Content-Length: 128 x-openstack-request-id: req-5a86126d-45a3-42cc-aeae-a7704ccd8162 x-compute-request-id: req-5a86126d-45a3-42cc-aeae-a7704ccd8162 Connection: close 
RESP BODY: {"computeFault": {"message": "The server has either erred or is incapable of performing the requested operation.", "code": 500}}

POST call to compute for http://192.168.0.10/compute/v2.1/servers used request id req-5a86126d-45a3-42cc-aeae-a7704ccd8162
The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-5a86126d-45a3-42cc-aeae-a7704ccd8162)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/cliff/app.py", line 400, in run_subcommand
    result = cmd.run(parsed_args)
  File "/usr/lib/python2.7/site-packages/osc_lib/command/command.py", line 41, in run
    return super(Command, self).run(parsed_args)
  File "/usr/lib/python2.7/site-packages/cliff/display.py", line 113, in run
    column_names, data = self.take_action(parsed_args)
  File "/usr/lib/python2.7/site-packages/openstackclient/compute/v2/server.py", line 769, in take_action
    server = compute_client.servers.create(*boot_args, **boot_kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/v2/servers.py", line 1403, in create
    **boot_kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/v2/servers.py", line 802, in _boot
    return_raw=return_raw, **kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/base.py", line 361, in _create
    resp, body = self.api.client.post(url, body=body)
  File "/usr/lib/python2.7/site-packages/keystoneauth1/adapter.py", line 294, in post
    return self.request(url, 'POST', **kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 83, in request
    raise exceptions.from_response(resp, body, url, method)
ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-5a86126d-45a3-42cc-aeae-a7704ccd8162)
clean_up CreateServer: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-5a86126d-45a3-42cc-aeae-a7704ccd8162)
Trace ID: 1bd7c53a-db3c-47a1-b250-b335b58f366b
Display trace with command:
osprofiler trace show --html 1bd7c53a-db3c-47a1-b250-b335b58f366b 
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/osc_lib/shell.py", line 134, in run
    ret_val = super(OpenStackShell, self).run(argv)
  File "/usr/lib/python2.7/site-packages/cliff/app.py", line 279, in run
    result = self.run_subcommand(remainder)
  File "/usr/lib/python2.7/site-packages/osc_lib/shell.py", line 169, in run_subcommand
    ret_value = super(OpenStackShell, self).run_subcommand(argv)
  File "/usr/lib/python2.7/site-packages/cliff/app.py", line 400, in run_subcommand
    result = cmd.run(parsed_args)
  File "/usr/lib/python2.7/site-packages/osc_lib/command/command.py", line 41, in run
    return super(Command, self).run(parsed_args)
  File "/usr/lib/python2.7/site-packages/cliff/display.py", line 113, in run
    column_names, data = self.take_action(parsed_args)
  File "/usr/lib/python2.7/site-packages/openstackclient/compute/v2/server.py", line 769, in take_action
    server = compute_client.servers.create(*boot_args, **boot_kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/v2/servers.py", line 1403, in create
    **boot_kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/v2/servers.py", line 802, in _boot
    return_raw=return_raw, **kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/base.py", line 361, in _create
    resp, body = self.api.client.post(url, body=body)
  File "/usr/lib/python2.7/site-packages/keystoneauth1/adapter.py", line 294, in post
    return self.request(url, 'POST', **kwargs)
  File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 83, in request
    raise exceptions.from_response(resp, body, url, method)
ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-5a86126d-45a3-42cc-aeae-a7704ccd8162)

END return value: 1

@EmreAtes
Copy link
Contributor Author

This one looks like it might solve our problem
https://bugzilla.redhat.com/show_bug.cgi?id=1412661
https://ask.openstack.org/en/question/53943/nova-instance-creation-500-error/

However, there is no /var/lib/cinder in our VM

@HuzefaMandvi
Copy link
Contributor

It looks like the VM is being created successfully? I wonder if this error message is a false flag that we're getting. Also, interestingly, creating a VM without osprofiler raises no error message.

That said..uninstalling the second patch [1] gives no error but only keystone/glance in the trace. Hmm...

[1] https://review.openstack.org/#/c/519664/3/nova/api/openstack/wsgi_app.py

@EmreAtes
Copy link
Contributor Author

Whenever I create a VM, I get this following in the logs (sudo journalctl --since '22:00:26' -p 5):

Jun 29 22:02:02 ore-1.moclocal nova-api-wsgi[4642]: ERROR nova.api.openstack [None req-e3a35247-ef45-4bd1-952d-1271d75785a6 admin admin] Caught error: pop from an empty deque: IndexError: pop from an empty deque
                                                    ERROR nova.api.openstack Traceback (most recent call last):
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 84, in __call__
                                                    ERROR nova.api.openstack     return req.get_response(self.application)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1316, in send
                                                    ERROR nova.api.openstack     application, catch_exc_info=False)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1280, in call_application
                                                    ERROR nova.api.openstack     app_iter = application(self.environ, start_response)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 131, in __call__
                                                    ERROR nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 196, in call_func
                                                    ERROR nova.api.openstack     return self.func(req, *args, **kwargs)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/requestlog.py", line 92, in __call__
                                                    ERROR nova.api.openstack     self._log_req(req, res, start)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
                                                    ERROR nova.api.openstack     self.force_reraise()
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
                                                    ERROR nova.api.openstack     six.reraise(self.type_, self.value, self.tb)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/requestlog.py", line 87, in __call__
                                                    ERROR nova.api.openstack     res = req.get_response(self.application)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1316, in send
                                                    ERROR nova.api.openstack     application, catch_exc_info=False)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1280, in call_application
                                                    ERROR nova.api.openstack     app_iter = application(self.environ, start_response)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 145, in __call__
                                                    ERROR nova.api.openstack     return resp(environ, start_response)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 131, in __call__
                                                    ERROR nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 196, in call_func
                                                    ERROR nova.api.openstack     return self.func(req, *args, **kwargs)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/osprofiler/web.py", line 128, in __call__
                                                    ERROR nova.api.openstack     return request.get_response(self.application)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 327, in __exit__
                                                    ERROR nova.api.openstack     stop()
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 94, in stop
                                                    ERROR nova.api.openstack     profiler.stop(info=info)
                                                    ERROR nova.api.openstack   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 393, in stop
                                                    ERROR nova.api.openstack     self._notify("%s-stop" % self._name.pop(), info)
                                                    ERROR nova.api.openstack IndexError: pop from an empty deque
                                                    ERROR nova.api.openstack

It looks like profiler.stop() is being called multiple times, or the number of start() and stop()s do not match, hence the IndexError. However, most of these methods are just generic methods and I couldn't find which one of these is being traced by osprofiler.

@EmreAtes
Copy link
Contributor Author

Also, during ./stack.sh I get this problem:

Jun 29 20:08:13 ore-1.moclocal neutron-openvswitch-agent[11729]: CRITICAL neutron [None req-808e11b6-d3af-4e88-913b-2af278d8a20b None None] Unhandled error: AsyncProcessException: Process is not running.
                                                                 ERROR neutron Traceback (most recent call last):
                                                                 ERROR neutron   File "/usr/bin/neutron-openvswitch-agent", line 10, in <module>
                                                                 ERROR neutron     sys.exit(main())
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/neutron/cmd/eventlet/plugins/ovs_neutron_agent.py", line 20, in main
                                                                 ERROR neutron     agent_main.main()
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/main.py", line 49, in main
                                                                 ERROR neutron     mod.main()
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/main.py", line 35, in main
                                                                 ERROR neutron     'neutron.plugins.ml2.drivers.openvswitch.agent.'
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/ryu/base/app_manager.py", line 375, in run_apps
                                                                 ERROR neutron     hub.joinall(services)
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/ryu/lib/hub.py", line 103, in joinall
                                                                 ERROR neutron     t.wait()
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 175, in wait
                                                                 ERROR neutron     return self._exit_event.wait()
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 125, in wait
                                                                 ERROR neutron     current.throw(*self._exc)
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/eventlet/greenthread.py", line 214, in main
                                                                 ERROR neutron     result = function(*args, **kwargs)
                                                                 ERROR neutron   File "/usr/lib/python2.7/site-packages/ryu/lib/hub.py", line 65, in _launch
                                                                 ERROR neutron     raise e
                                                                 ERROR neutron AsyncProcessException: Process is not running.
                                                                 ERROR neutron

@HuzefaMandvi
Copy link
Contributor

HuzefaMandvi commented Jul 2, 2018 •
edited
Loading

So I'm pretty sure the 500 error is unrelated to not getting traces from every service (EDIT: you had already noticed this, sorry for my redundancy). I found this bug, which looks relevant to the output from your journalctl output:

https://bugs.launchpad.net/osprofiler/+bug/1743586

The bug results from Nova executing some parallelized code. At the end of the thread, we see that this is patched in osprofiler 1.15.2 - however, ORE was using stable/pike version of osprofiler which was 1.11.2.
I upgraded osprofiler to stable/queens (1.15.2) and did a pip reinstall. No longer getting the 500 error message.

That said, trace is still only getting keystone and glance.

EDIT: Just kidding - I had uninstalled one of the patches during my testing. With the 2 patches installed and the stable/queens version of osprofiler, I have no errors and a trace with neutron, nova, glance, and keystone!!!

This was referenced Jul 2, 2018
Closed
Merged
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@HuzefaMandvi @EmreAtes