ansible-inventory gives extra error text from openstack plugin, making it non-parsable

[AlanCoding]

SUMMARY

Cannot properly use ansible-inventory with inventory files that use the openstack inventory plugin.

ISSUE TYPE

• Bug Report

COMPONENT NAME

lib/ansible/cli/inventory.py
lib/ansible/plugins/inventory/openstack.py

ANSIBLE VERSION

ansible --version
ansible 2.8.0.dev0
  config file = None
  configured module search path = [u'/Users/alancoding/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible
  executable location = /Users/alancoding/.virtualenvs/ansible/bin/ansible
  python version = 2.7.11 (default, Oct 17 2016, 14:59:40) [GCC 4.2.1 Compatible Apple LLVM 7.0.2 (clang-700.1.81)]

CONFIGURATION

(no changes)

OS / ENVIRONMENT

Mac, in inventory loading. Dependency for plugin:

openstacksdk==0.19.0

STEPS TO REPRODUCE

Create an openstack.yml file and a clouds.yaml file that gives auth information for a real OpenStack server. Documented at:

https://docs.ansible.com/ansible/2.7/plugins/inventory/openstack.html

My own, more detailed, personal example:

https://github.com/AlanCoding/Ansible-inventory-file-examples/tree/master/plugins/example_openstack

Then run

ansible-inventory -i private/openstack/openstack.yml --list --export

EXPECTED RESULTS

JSON outputed to stdout

Other information going to stderr is okay with me.

ACTUAL RESULTS

I have extra messages, which go to stdout

Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
Keystone catalog entry not found (service_type=network,service_name=Noneinterface=public,region_name=)
{
    "_meta": {
        "hostvars": {
...rest of content...
    }
}

The ultimate culprit is at:

https://github.com/openstack/openstacksdk/blob/9675c1fb0b065017a0fadf75f52d8193cce7dd24/openstack/config/cloud_region.py#L583-L604

Here is the call stack and traceback:

  File "/Users/alancoding/.virtualenvs/ansible/bin/ansible-inventory", line 4, in <module>
    __import__('pkg_resources').run_script('ansible==2.8.0.dev0', 'ansible-inventory')
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/pkg_resources/__init__.py", line 661, in run_script
    self.require(requires)[0].run_script(script_name, ns)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/pkg_resources/__init__.py", line 1441, in run_script
    exec(code, namespace, namespace)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/EGG-INFO/scripts/ansible-inventory", line 110, in <module>
    exit_code = cli.run()
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/cli/inventory.py", line 136, in run
    self.loader, self.inventory, self.vm = self._play_prereqs(self.options)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/cli/__init__.py", line 787, in _play_prereqs
    inventory = InventoryManager(loader=loader, sources=options.inventory)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/inventory/manager.py", line 145, in __init__
    self.parse_sources(cache=True)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/inventory/manager.py", line 205, in parse_sources
    parse = self.parse_source(source, cache=cache)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/inventory/manager.py", line 270, in parse_source
    plugin.parse(self._inventory, self._loader, source, cache=cache)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/plugins/inventory/auto.py", line 55, in parse
    plugin.parse(inventory, loader, path, cache=cache)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/plugins/inventory/openstack.py", line 197, in parse
    expand=expand_hostvars, fail_on_cloud_config=fail_on_errors)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/inventory.py", line 66, in list_hosts
    for server in cloud.list_servers(detailed=expand):
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 2123, in list_servers
    filters=filters)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 2146, in _list_servers
    for server in servers
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 3138, in _expand_server
    return meta.get_hostvars_from_server(self, server)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/meta.py", line 482, in get_hostvars_from_server
    server_vars = add_server_interfaces(cloud, server)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/meta.py", line 447, in add_server_interfaces
    server['addresses'] = _get_supplemental_addresses(cloud, server)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/meta.py", line 407, in _get_supplemental_addresses
    if (cloud.has_service('network') and cloud._has_floating_ips() and
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 1419, in has_service
    endpoint = self.get_session_endpoint(service_key)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 1389, in get_session_endpoint
    return self.config.get_session_endpoint(service_key)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/config/cloud_region.py", line 596, in get_session_endpoint
    traceback.print_stack()
Traceback (most recent call last):
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/config/cloud_region.py", line 592, in get_session_endpoint
    **version_kwargs
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/keystoneauth1/session.py", line 1113, in get_endpoint
    return auth.get_endpoint(self, **kwargs)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/keystoneauth1/identity/base.py", line 380, in get_endpoint
    allow_version_hack=allow_version_hack, **kwargs)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/keystoneauth1/identity/base.py", line 279, in get_endpoint_data
    service_name=service_name)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/keystoneauth1/access/service_catalog.py", line 462, in endpoint_data_for
    raise exceptions.EndpointNotFound(msg)
EndpointNotFound: public endpoint for network service not found

This problem could be addressed by the client library, but this is hideously complicated to dive into that. We could somehow turn down the log level, but it's a high custom implementation and there's a lot of class instantiations it gets passed around to. Or, something could have the smarts to not call this method if it's not applicable given the input data. That would be on the client library side, and not the code inside the openstack inventory plugin.

Alternatively (and I think this is most reasonable solution), either the inventory plugin or ansible-inventory itself should redirect stdout while a 3rd party library is being called, because we can't trust that library to not write to stdout.

Having this content in stdout means that we can't parse the output from ansible-inventory with the stock python JSON library.

[bcoca]

Or you can filter out 'non-json' output https://github.com/ansible/ansible/blob/devel/lib/ansible/module_utils/json_utils.py#L32

[ansibot]

cc @Shrews @cloudnull @dagnello @emonty @evrardjp @juliakreger @mnaser @odyssey4me @rcarrillocruz
click here for bot help

[AlanCoding]

That method will still not give valid JSON in all cases because it appends a warning to the end. I put up a proposed workaround in AWX. If that is accepted, then we won't need any changes here.

[AlanCoding]

Also, in the method you linked to...

    # Filter trailing junk
    lines = lines[start:]

I think this is filtering the leading junk. The trailing junk is dealt with in latter code.

[AlanCoding]

This is still quite a problem, because spitting on our side seems unlikely to be accepted. I have argued that we need some form of splitting to use the verbosity flag as well (absolutely necessary for plugin use), but there is no clear plan for that right now.

We could consider a workaround specific to this problem. Here is the stack trace getting to that warning.

  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/inventory/manager.py", line 272, in parse_source
    plugin.parse(self._inventory, self._loader, source, cache=cache)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/plugins/inventory/auto.py", line 55, in parse
    plugin.parse(inventory, loader, path, cache=cache)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/ansible-2.8.0.dev0-py2.7.egg/ansible/plugins/inventory/openstack.py", line 197, in parse
    expand=expand_hostvars, fail_on_cloud_config=fail_on_errors)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/inventory.py", line 66, in list_hosts
    for server in cloud.list_servers(detailed=expand):
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 2123, in list_servers
    filters=filters)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 2146, in _list_servers
    for server in servers
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 3140, in _expand_server
    return meta.add_server_interfaces(self, server)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/meta.py", line 448, in add_server_interfaces
    server['public_v4'] = get_server_external_ipv4(cloud, server) or ''
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/meta.py", line 186, in get_server_external_ipv4
    ext_nets = cloud.get_external_ipv4_networks()
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 2640, in get_external_ipv4_networks
    self._find_interesting_networks()
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 2578, in _find_interesting_networks
    if not self.has_service('network'):
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 1419, in has_service
    endpoint = self.get_session_endpoint(service_key)
  File "/Users/alancoding/.virtualenvs/ansible/lib/python2.7/site-packages/openstack/cloud/openstackcloud.py", line 1403, in get_session_endpoint
    error=str(e)))

Code bits in question:

ansible/lib/ansible/plugins/inventory/openstack.py

Lines 196 to 197 in bafc1f8

	source_data = cloud_inventory.list_hosts(
	expand=expand_hostvars, fail_on_cloud_config=fail_on_errors)

This suggests that using fail_on_errors: true config option might force error, instead of being successful but giving warning messages. I tried it and this does not work. It still imports.

Looking at this, I'm was not optimistic that it can be resolved in the inventory plugin code. The error logs seem to be an implementation detail within the library. The plugin could try to adjust the python logging configuration. That is somewhat complicated by the fact that they use their own logging utilities, from openstack import _log.

However, once I got pdb shell and looked, I saw a big honking StreamHandler attached to the "openstack" logger. It didn't appear that the library set this... so that brought me to the culprit...

[ansibot]

@AlanCoding: Greetings! Thanks for taking the time to open this issue. In order for the community to handle your issue effectively, we need a bit more information.

Here are the items we could not find in your description:

• issue type
• ansible version
• component name

Please set the description of this issue with this template:
https://raw.githubusercontent.com/ansible/ansible/devel/.github/ISSUE_TEMPLATE.md

click here for bot help