← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 2000318] [NEW] Metadata API server fails to provide VM data

 

Public bug reported:

Nova Metadata API server experiences an internal error when a cirros
image requests metadata.

This is how metadata are requested from a cirros VM, and the results I get:
$ curl http://169.254.169.254/latest/meta-data/placement/availability-zone/nova
<html>
 <head>
  <title>500 Internal Server Error</title>
 </head>
 <body>
  <h1>500 Internal Server Error</h1>
  Remote metadata server experienced an internal server error.<br /><br />


 </body>
</html>$

And here are the logs from openstack-nova-metadata-api service:

2022-12-22 14:19:57.854 675968 INFO nova.metadata.wsgi.server [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/eventlet/wsgi.py", line 569, in handle_one_response
    result = self.application(self.environ, start_response)
  File "/usr/lib/python3.9/site-packages/paste/urlmap.py", line 216, in __call__
    return app(environ, start_response)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
    response = req.get_response(self.application)
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
    status, headers, app_iter = self.call_application(
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
    response = req.get_response(self.application)
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
    status, headers, app_iter = self.call_application(
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/handler.py", line 129, in __call__
    data = meta_data.lookup(req.path_info)
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 576, in lookup
    data = self.get_ec2_item(path_tokens[1:])
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 308, in get_ec2_item
    return find_path_in_tree(data, path_tokens[1:])
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 746, in find_path_in_tree
    data = data[path_tokens[i]]
TypeError: string indices must be integers

2022-12-22 14:19:57.855 675968 INFO nova.metadata.wsgi.server [None
req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -]
10.18.85.3,172.20.119.1 "GET /latest/meta-data/placement/availability-
zone/nova HTTP/1.1" status: 500 len: 139 time: 0.2591183

To troubleshoot the error, I checked the code in
/usr/lib/python3.9/site-packages/nova/api/metadata/base.py, and I added
additional log output:

726 def find_path_in_tree(data, path_tokens):
727     # given a dict/list tree, and a path in that tree, return data found there.
728     LOG.warning("asdqwedasdqwed 1 data = \"{data}\"".format(data=data))
729     for i in range(0, len(path_tokens)):
730         LOG.warning("asdqwedasdqwed 1 i = \"{i}\"".format(i=i))
731         LOG.warning("asdqwedasdqwed 2 data = \"{data}\"".format(data=data))
732         if isinstance(data, dict) or isinstance(data, list):
733             LOG.warning("asdqwedasdqwed 3 data = \"{data}\"".format(data=data))
734             if path_tokens[i] in data:
735                 LOG.warning("asdqwedasdqwed 4 data = \"{data}\"".format(data=data))
736                 data = data[path_tokens[i]]
737                 LOG.warning("asdqwedasdqwed 5 data = \"{data}\"".format(data=data))
738             else:
739                 raise KeyError("/".join(path_tokens[0:i]))
740         else:
741             LOG.warning("asdqwedasdqwed path_tokens = \"{path_tokens}\"".format(path_tokens=path_tokens))
742             LOG.warning("asdqwedasdqwed 6 data = \"{data}\"".format(data=data))
743             LOG.warning("asdqwedasdqwed 2 i = \"{i}\"".format(i=i))
744             if i != len(path_tokens) - 1:
745                 raise KeyError("/".join(path_tokens[0:i]))
746             data = data[path_tokens[i]]
747     return data

After restarting openstack-nova-metadata-api service, Here is the trace I obtain:
2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 1 i = "2"
2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 2 data = "{'availability-zone': 'nova'}"
2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 3 data = "{'availability-zone': 'nova'}"
2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 4 data = "{'availability-zone': 'nova'}"
2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 5 data = "nova"
2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 1 i = "3"
2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 2 data = "nova"
2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed path_tokens = "['meta-data', 'placement', 'availability-zone', 'nova']"
2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 6 data = "nova"
2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 2 i = "3"

I see that data turns from a dictionary to a string as soon as the code
finds path_tokens[i] in data. The problem is the else branch tries to
look for path_tokens[i] in data. Since data is now a string, it can only
be indexed with an integer, as the logs indicate.

I commented out line 746 and restarted openstack-nova-metadata-api. Now
it seems my instance is sometime able to retrieve metadata:

2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 5 data = "{'availability-zone': 'nova'}"
2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 1 i = "2"
2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 2 data = "{'availability-zone': 'nova'}"
2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 3 data = "{'availability-zone': 'nova'}"
2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 4 data = "{'availability-zone': 'nova'}"
2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 5 data = "nova"
2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 1 i = "3"
2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 2 data = "nova"
2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed path_tokens = "['meta-data', 'placement', 'availability-zone', 'nova']"
2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 6 data = "nova"
2022-12-22 14:38:34.799 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 2 i = "3"
2022-12-22 14:38:34.799 679181 INFO nova.metadata.wsgi.server [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] 10.18.85.95,172.20.119.1 "GET /latest/meta-data/placement/availability-zone/nova HTTP/1.1" status: 200 len: 144 time: 0.1608348

sometimes it reports the remote metadata server experienced an internal
server error:

2022-12-22 14:39:10.644 21760 INFO nova.metadata.wsgi.server [None req-53d9a388-dfa9-4e29-bce2-745516a4270a - - - - - -] Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/eventlet/wsgi.py", line 569, in handle_one_response
    result = self.application(self.environ, start_response)
  File "/usr/lib/python3.9/site-packages/paste/urlmap.py", line 216, in __call__
    return app(environ, start_response)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
    response = req.get_response(self.application)
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
    status, headers, app_iter = self.call_application(
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
    response = req.get_response(self.application)
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
    status, headers, app_iter = self.call_application(
  File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/handler.py", line 129, in __call__
    data = meta_data.lookup(req.path_info)
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 576, in lookup
    data = self.get_ec2_item(path_tokens[1:])
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 308, in get_ec2_item
    return find_path_in_tree(data, path_tokens[1:])
  File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 737, in find_path_in_tree
    LOG.warning("asdqwedasdqwed 5 data = \"{data}\"".format(data=data))
TypeError: string indices must be integers

2022-12-22 14:39:10.644 21760 INFO nova.metadata.wsgi.server [None
req-53d9a388-dfa9-4e29-bce2-745516a4270a - - - - - -]
10.18.85.95,172.20.119.1 "GET /latest/meta-data/placement/availability-
zone/nova HTTP/1.1" status: 500 len: 139 time: 0.1553872

It looks like my "fix" is not sufficient to solve the issue. Regardless,
I am under the impression that this code cannot work as it is, whether
my "fix" is applied or not. This might be the sign I configured
something else very wrong, but I cannot find out what this could be.

I run Openstack Zed, freshly installed on Rocky Linux 9, also freshly
installed.

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/2000318

Title:
  Metadata API server fails to provide VM data

Status in OpenStack Compute (nova):
  New

Bug description:
  Nova Metadata API server experiences an internal error when a cirros
  image requests metadata.

  This is how metadata are requested from a cirros VM, and the results I get:
  $ curl http://169.254.169.254/latest/meta-data/placement/availability-zone/nova
  <html>
   <head>
    <title>500 Internal Server Error</title>
   </head>
   <body>
    <h1>500 Internal Server Error</h1>
    Remote metadata server experienced an internal server error.<br /><br />


   </body>
  </html>$

  And here are the logs from openstack-nova-metadata-api service:

  2022-12-22 14:19:57.854 675968 INFO nova.metadata.wsgi.server [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] Traceback (most recent call last):
    File "/usr/lib/python3.9/site-packages/eventlet/wsgi.py", line 569, in handle_one_response
      result = self.application(self.environ, start_response)
    File "/usr/lib/python3.9/site-packages/paste/urlmap.py", line 216, in __call__
      return app(environ, start_response)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
      resp = self.call_func(req, *args, **kw)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
      return self.func(req, *args, **kwargs)
    File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
      response = req.get_response(self.application)
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
      status, headers, app_iter = self.call_application(
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
      app_iter = application(self.environ, start_response)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
      resp = self.call_func(req, *args, **kw)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
      return self.func(req, *args, **kwargs)
    File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
      response = req.get_response(self.application)
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
      status, headers, app_iter = self.call_application(
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
      app_iter = application(self.environ, start_response)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
      resp = self.call_func(req, *args, **kw)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
      return self.func(req, *args, **kwargs)
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/handler.py", line 129, in __call__
      data = meta_data.lookup(req.path_info)
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 576, in lookup
      data = self.get_ec2_item(path_tokens[1:])
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 308, in get_ec2_item
      return find_path_in_tree(data, path_tokens[1:])
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 746, in find_path_in_tree
      data = data[path_tokens[i]]
  TypeError: string indices must be integers

  2022-12-22 14:19:57.855 675968 INFO nova.metadata.wsgi.server [None
  req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -]
  10.18.85.3,172.20.119.1 "GET /latest/meta-data/placement/availability-
  zone/nova HTTP/1.1" status: 500 len: 139 time: 0.2591183

  To troubleshoot the error, I checked the code in
  /usr/lib/python3.9/site-packages/nova/api/metadata/base.py, and I
  added additional log output:

  726 def find_path_in_tree(data, path_tokens):
  727     # given a dict/list tree, and a path in that tree, return data found there.
  728     LOG.warning("asdqwedasdqwed 1 data = \"{data}\"".format(data=data))
  729     for i in range(0, len(path_tokens)):
  730         LOG.warning("asdqwedasdqwed 1 i = \"{i}\"".format(i=i))
  731         LOG.warning("asdqwedasdqwed 2 data = \"{data}\"".format(data=data))
  732         if isinstance(data, dict) or isinstance(data, list):
  733             LOG.warning("asdqwedasdqwed 3 data = \"{data}\"".format(data=data))
  734             if path_tokens[i] in data:
  735                 LOG.warning("asdqwedasdqwed 4 data = \"{data}\"".format(data=data))
  736                 data = data[path_tokens[i]]
  737                 LOG.warning("asdqwedasdqwed 5 data = \"{data}\"".format(data=data))
  738             else:
  739                 raise KeyError("/".join(path_tokens[0:i]))
  740         else:
  741             LOG.warning("asdqwedasdqwed path_tokens = \"{path_tokens}\"".format(path_tokens=path_tokens))
  742             LOG.warning("asdqwedasdqwed 6 data = \"{data}\"".format(data=data))
  743             LOG.warning("asdqwedasdqwed 2 i = \"{i}\"".format(i=i))
  744             if i != len(path_tokens) - 1:
  745                 raise KeyError("/".join(path_tokens[0:i]))
  746             data = data[path_tokens[i]]
  747     return data

  After restarting openstack-nova-metadata-api service, Here is the trace I obtain:
  2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 1 i = "2"
  2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 2 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 3 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:19:57.852 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 4 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 5 data = "nova"
  2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 1 i = "3"
  2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 2 data = "nova"
  2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed path_tokens = "['meta-data', 'placement', 'availability-zone', 'nova']"
  2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 6 data = "nova"
  2022-12-22 14:19:57.853 675968 WARNING nova.api.metadata.base [None req-23bd0dbb-b50c-46ce-bd34-d399601bf697 - - - - - -] asdqwedasdqwed 2 i = "3"

  I see that data turns from a dictionary to a string as soon as the
  code finds path_tokens[i] in data. The problem is the else branch
  tries to look for path_tokens[i] in data. Since data is now a string,
  it can only be indexed with an integer, as the logs indicate.

  I commented out line 746 and restarted openstack-nova-metadata-api.
  Now it seems my instance is sometime able to retrieve metadata:

  2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 5 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 1 i = "2"
  2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 2 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:38:34.797 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 3 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 4 data = "{'availability-zone': 'nova'}"
  2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 5 data = "nova"
  2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 1 i = "3"
  2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 2 data = "nova"
  2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed path_tokens = "['meta-data', 'placement', 'availability-zone', 'nova']"
  2022-12-22 14:38:34.798 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 6 data = "nova"
  2022-12-22 14:38:34.799 679181 WARNING nova.api.metadata.base [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] asdqwedasdqwed 2 i = "3"
  2022-12-22 14:38:34.799 679181 INFO nova.metadata.wsgi.server [None req-d5e4cdf8-6fc5-4141-9c97-a5226cf5ef20 - - - - - -] 10.18.85.95,172.20.119.1 "GET /latest/meta-data/placement/availability-zone/nova HTTP/1.1" status: 200 len: 144 time: 0.1608348

  sometimes it reports the remote metadata server experienced an
  internal server error:

  2022-12-22 14:39:10.644 21760 INFO nova.metadata.wsgi.server [None req-53d9a388-dfa9-4e29-bce2-745516a4270a - - - - - -] Traceback (most recent call last):
    File "/usr/lib/python3.9/site-packages/eventlet/wsgi.py", line 569, in handle_one_response
      result = self.application(self.environ, start_response)
    File "/usr/lib/python3.9/site-packages/paste/urlmap.py", line 216, in __call__
      return app(environ, start_response)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
      resp = self.call_func(req, *args, **kw)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
      return self.func(req, *args, **kwargs)
    File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
      response = req.get_response(self.application)
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
      status, headers, app_iter = self.call_application(
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
      app_iter = application(self.environ, start_response)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
      resp = self.call_func(req, *args, **kw)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
      return self.func(req, *args, **kwargs)
    File "/usr/lib/python3.9/site-packages/oslo_middleware/base.py", line 124, in __call__
      response = req.get_response(self.application)
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1313, in send
      status, headers, app_iter = self.call_application(
    File "/usr/lib/python3.9/site-packages/webob/request.py", line 1278, in call_application
      app_iter = application(self.environ, start_response)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 129, in __call__
      resp = self.call_func(req, *args, **kw)
    File "/usr/lib/python3.9/site-packages/webob/dec.py", line 193, in call_func
      return self.func(req, *args, **kwargs)
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/handler.py", line 129, in __call__
      data = meta_data.lookup(req.path_info)
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 576, in lookup
      data = self.get_ec2_item(path_tokens[1:])
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 308, in get_ec2_item
      return find_path_in_tree(data, path_tokens[1:])
    File "/usr/lib/python3.9/site-packages/nova/api/metadata/base.py", line 737, in find_path_in_tree
      LOG.warning("asdqwedasdqwed 5 data = \"{data}\"".format(data=data))
  TypeError: string indices must be integers

  2022-12-22 14:39:10.644 21760 INFO nova.metadata.wsgi.server [None
  req-53d9a388-dfa9-4e29-bce2-745516a4270a - - - - - -]
  10.18.85.95,172.20.119.1 "GET /latest/meta-
  data/placement/availability-zone/nova HTTP/1.1" status: 500 len: 139
  time: 0.1553872

  It looks like my "fix" is not sufficient to solve the issue.
  Regardless, I am under the impression that this code cannot work as it
  is, whether my "fix" is applied or not. This might be the sign I
  configured something else very wrong, but I cannot find out what this
  could be.

  I run Openstack Zed, freshly installed on Rocky Linux 9, also freshly
  installed.

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/2000318/+subscriptions