saltstack / salt

Software to automate the management and configuration of any infrastructure or application at scale. Install Salt from the Salt package repositories here:
https://docs.saltproject.io/salt/install-guide/en/latest/
Apache License 2.0
14.23k stars 5.49k forks source link

Salt cloud vultr integration is broken, and some of the cloud utilities function make it difficult to debug #60568

Open fake-name opened 3 years ago

fake-name commented 3 years ago

Description A clear and concise description of what the bug is.

Setup https://github.com/fake-name/AutoTriever/blob/master/marshaller/salt_runner.py

Steps to Reproduce the behavior Attempt to deploy a Vultr VM. Deploy fails.

Expected behavior I expect to actually create the VM.

Screenshots

Main.VpsHerder.MainThread - INFO - Creating instance...
Main.VpsHerder.MainThread - INFO -      Client name: 'test-1'
Main.VpsHerder.MainThread - INFO -      using provider: 'vultr'
Main.VpsHerder.MainThread - INFO -      kwargs: '{'image': 270, 'private_networking': False, 'size': '201', 'location': 22, 'script': '/home/client/AutoTriever/marshaller/bootstrap-salt-delay.sh'}'
salt.utils.entrypoints.MainThread - DEBUG - Using pkg_resources to load entry points
salt.utils.entrypoints.MainThread - DEBUG - Using pkg_resources to load entry points
salt.utils.lazy.MainThread - DEBUG - Could not LazyLoad parallels.avail_sizes: 'parallels' __virtual__ returned False
salt.utils.lazy.MainThread - DEBUG - LazyLoaded parallels.avail_locations
salt.utils.lazy.MainThread - DEBUG - LazyLoaded proxmox.avail_sizes
salt.cloud.MainThread - DEBUG - Generating minion keys for 'test-1'
salt.utils.lazy.MainThread - DEBUG - LazyLoaded cloud.fire_event
salt.utils.event.MainThread - DEBUG - MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
salt.utils.event.MainThread - DEBUG - MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
salt.utils.event.MainThread - DEBUG - Sending event: tag = salt/cloud/test-1/creating; data = {'provider': 'vultr:vultr', 'driver': 'vultr:vultr', 'name': 'test-1', 'profile': None, 'event': 'starting create', '_stamp': '2021-07-19T07:00:32.016509'}
salt.transport.ipc.MainThread - DEBUG - Closing IPCMessageClient instance
salt.utils.lazy.MainThread - DEBUG - LazyLoaded http.query
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/regions/list?api_key=XXXXXXXXXX using GET method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/os/list?api_key=XXXXXXXXXX using GET method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/plans/list?api_key=XXXXXXXXXX using GET method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
salt.loaded.int.clouds.vultrpy.MainThread - INFO - Creating Cloud VM test-1
salt.utils.event.MainThread - DEBUG - MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
salt.utils.event.MainThread - DEBUG - MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
salt.utils.event.MainThread - DEBUG - Sending event: tag = salt/cloud/test-1/requesting; data = {'kwargs': {'hostname': 'test-1', 'VPSPLANID': '201', 'enable_private_network': 'no', 'DCID': '22', 'OSID': 270, 'label': 'test-1'}, 'event': 'requesting instance', '_stamp': '2021-07-19T07:00:33.074577'}
salt.transport.ipc.MainThread - DEBUG - Closing IPCMessageClient instance
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/server/create?api_key=XXXXXXXXXX using POST method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
salt.loaded.int.utils.cloud.MainThread - DEBUG - Attempting function <function create.<locals>.wait_for_hostname at 0x7f998b660e50>
salt.loaded.int.utils.cloud.MainThread - DEBUG - Caught exception in wait_for_fun: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -     Traceback (most recent call last):
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 682, in wait_for_fun
salt.loaded.int.utils.cloud.MainThread - DEBUG -         response = fun(**kwargs)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 497, in wait_for_hostname
salt.loaded.int.utils.cloud.MainThread - DEBUG -         data = show_instance(vm_["name"], call="action")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 315, in show_instance
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = list_nodes_full()
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 246, in list_nodes_full
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = _query("server/list")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 617, in _query
salt.loaded.int.utils.cloud.MainThread - DEBUG -         result = __utils__["http.query"](
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 78, in __getitem__
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return self.value()[item]
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 72, in value
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return loader.pack[self.name]
salt.loaded.int.utils.cloud.MainThread - DEBUG -     KeyError: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -
salt.loaded.int.utils.cloud.MainThread - DEBUG - Retrying function <function create.<locals>.wait_for_hostname at 0x7f998b660e50> on  (try 1)
salt.loaded.int.utils.cloud.MainThread - DEBUG - Caught exception in wait_for_fun: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -     Traceback (most recent call last):
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 682, in wait_for_fun
salt.loaded.int.utils.cloud.MainThread - DEBUG -         response = fun(**kwargs)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 497, in wait_for_hostname
salt.loaded.int.utils.cloud.MainThread - DEBUG -         data = show_instance(vm_["name"], call="action")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 315, in show_instance
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = list_nodes_full()
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 246, in list_nodes_full
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = _query("server/list")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 617, in _query
salt.loaded.int.utils.cloud.MainThread - DEBUG -         result = __utils__["http.query"](
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 78, in __getitem__
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return self.value()[item]
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 72, in value
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return loader.pack[self.name]
salt.loaded.int.utils.cloud.MainThread - DEBUG -     KeyError: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -

<Repeat 900 (!) times>

Note that the above is with a patched wait_for_fun() implementation to actually output a useful traceback:


def wait_for_fun(fun, timeout=900, **kwargs):
    """
    Wait until a function finishes, or times out
    """
    start = time.time()
    log.debug("Attempting function %s", fun)
    trycount = 0
    while True:
        trycount += 1
        try:
            response = fun(**kwargs)
            if not isinstance(response, bool):
                return response
        except Exception as exc:  # pylint: disable=broad-except
            log.debug("Caught exception in wait_for_fun: %s", exc)
            for line in traceback.format_exc().split("\n"):
                log.debug("    %s", line)
            time.sleep(1)
            log.debug("Retrying function %s on  (try %s)", fun, trycount)
        if time.time() - start > timeout:
            log.error("Function timed out: %s", timeout)
            return False

I'm particulary confused by this exception, since vultrpy._query() is called successfully earlier in the deploy process. I suspect that something in the capture of wait_for_hostname() in wait_for_server_state() is breaking the reference to util somehow.

Versions Report

client@salt:~/AutoTriever/marshaller$ salt --versions-report
Salt Version:
          Salt: 3003.1

Dependency Versions:
          cffi: Not Installed
      cherrypy: Not Installed
      dateutil: 2.7.3
     docker-py: Not Installed
         gitdb: 2.0.6
     gitpython: 3.0.7
        Jinja2: 2.10.1
       libgit2: Not Installed
      M2Crypto: Not Installed
          Mako: Not Installed
       msgpack: 0.6.2
  msgpack-pure: Not Installed
  mysql-python: Not Installed
     pycparser: Not Installed
      pycrypto: 2.6.1
  pycryptodome: 3.6.1
        pygit2: Not Installed
        Python: 3.8.10 (default, Jun  2 2021, 10:49:15)
  python-gnupg: 0.4.5
        PyYAML: 5.3.1
         PyZMQ: 18.1.1
         smmap: 2.0.5
       timelib: Not Installed
       Tornado: 4.5.3
           ZMQ: 4.3.2

System Versions:
          dist: ubuntu 20.04 focal
        locale: utf-8
       machine: x86_64
       release: 5.4.0-77-generic
        system: Linux
       version: Ubuntu 20.04 focal

This is basically the current version from https://repo.saltproject.io/py3/ubuntu/20.04/amd64/latest

fake-name commented 3 years ago

Instrumenting loader_context():

Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.utils.event.MainThread - DEBUG - MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
salt.utils.event.MainThread - DEBUG - MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
salt.utils.event.MainThread - DEBUG - Sending event: tag = salt/cloud/test-1/creating; data = {'name': 'test-1', 'provider': 'vultr:vultr', 'profile': None, 'driver': 'vultr:vultr', 'event': 'starting create', '_stamp': '2021-07-19T07:21:10.760720'}
salt.transport.ipc.MainThread - DEBUG - Closing IPCMessageClient instance
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.utils.lazy.MainThread - DEBUG - LazyLoaded http.query
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/regions/list?api_key=XXXXXXXXXX using GET method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/os/list?api_key=XXXXXXXXXX using GET method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/plans/list?api_key=XXXXXXXXXX using GET method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
salt.loaded.int.clouds.vultrpy.MainThread - INFO - Creating Cloud VM test-1
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.utils.event.MainThread - DEBUG - MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
salt.utils.event.MainThread - DEBUG - MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
salt.utils.event.MainThread - DEBUG - Sending event: tag = salt/cloud/test-1/requesting; data = {'kwargs': {'DCID': '2', 'hostname': 'test-1', 'OSID': 270, 'VPSPLANID': '201', 'enable_private_network': 'no', 'label': 'test-1'}, 'event': 'requesting instance', '_stamp': '2021-07-19T07:21:11.772218'}
salt.transport.ipc.MainThread - DEBUG - Closing IPCMessageClient instance
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.loaded.int.utils.http.MainThread - DEBUG - Requesting URL https://api.vultr.com/v1/server/create?api_key=XXXXXXXXXX using POST method
salt.loaded.int.utils.http.MainThread - DEBUG - Using backend: tornado
salt.loaded.int.utils.http.MainThread - DEBUG - Response Status Code: 200
Loader name: __utils__
loader.pack {'__utils__': <salt.loader.LazyLoader object at 0x7f0e03077790>, '__active_provider_name__': {}, '__grains__': {}, '__pillar__': {}, '__context__': {}}
salt.loaded.int.utils.cloud.MainThread - DEBUG - Attempting function <function create.<locals>.wait_for_hostname at 0x7f0e02f4b940>
Loader name: __utils__
loader.pack {'__context__': {}, '__proxy__': <function proxy at 0x7f0e04405670>, '__grains__': {}, '__pillar__': {}}
salt.loaded.int.utils.cloud.MainThread - DEBUG - Caught exception in wait_for_fun: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -     Traceback (most recent call last):
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 682, in wait_for_fun
salt.loaded.int.utils.cloud.MainThread - DEBUG -         response = fun(**kwargs)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 497, in wait_for_hostname
salt.loaded.int.utils.cloud.MainThread - DEBUG -         data = show_instance(vm_["name"], call="action")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 315, in show_instance
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = list_nodes_full()
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 246, in list_nodes_full
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = _query("server/list")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 618, in _query
salt.loaded.int.utils.cloud.MainThread - DEBUG -         result = __utils__["http.query"](
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 81, in __getitem__
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return self.value()[item]
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 75, in value
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return loader.pack[self.name]
salt.loaded.int.utils.cloud.MainThread - DEBUG -     KeyError: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -
salt.loaded.int.utils.cloud.MainThread - DEBUG - Retrying function <function create.<locals>.wait_for_hostname at 0x7f0e02f4b940> on  (try 1)
Loader name: __utils__
loader.pack {'__context__': {}, '__proxy__': <function proxy at 0x7f0e04405670>, '__grains__': {}, '__pillar__': {}}
salt.loaded.int.utils.cloud.MainThread - DEBUG - Caught exception in wait_for_fun: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -     Traceback (most recent call last):
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 682, in wait_for_fun
salt.loaded.int.utils.cloud.MainThread - DEBUG -         response = fun(**kwargs)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 497, in wait_for_hostname
salt.loaded.int.utils.cloud.MainThread - DEBUG -         data = show_instance(vm_["name"], call="action")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 315, in show_instance
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = list_nodes_full()
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 246, in list_nodes_full
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = _query("server/list")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 618, in _query
salt.loaded.int.utils.cloud.MainThread - DEBUG -         result = __utils__["http.query"](
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 81, in __getitem__
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return self.value()[item]
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 75, in value
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return loader.pack[self.name]
salt.loaded.int.utils.cloud.MainThread - DEBUG -     KeyError: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -
salt.loaded.int.utils.cloud.MainThread - DEBUG - Retrying function <function create.<locals>.wait_for_hostname at 0x7f0e02f4b940> on  (try 2)
Loader name: __utils__
loader.pack {'__context__': {}, '__proxy__': <function proxy at 0x7f0e04405670>, '__grains__': {}, '__pillar__': {}}
salt.loaded.int.utils.cloud.MainThread - DEBUG - Caught exception in wait_for_fun: '__utils__'
salt.loaded.int.utils.cloud.MainThread - DEBUG -     Traceback (most recent call last):
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 682, in wait_for_fun
salt.loaded.int.utils.cloud.MainThread - DEBUG -         response = fun(**kwargs)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 497, in wait_for_hostname
salt.loaded.int.utils.cloud.MainThread - DEBUG -         data = show_instance(vm_["name"], call="action")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 315, in show_instance
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = list_nodes_full()
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 246, in list_nodes_full
salt.loaded.int.utils.cloud.MainThread - DEBUG -         nodes = _query("server/list")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 618, in _query
salt.loaded.int.utils.cloud.MainThread - DEBUG -         result = __utils__["http.query"](
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 81, in __getitem__
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return self.value()[item]
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/loader_context.py", line 75, in value
salt.loaded.int.utils.cloud.MainThread - DEBUG -         return loader.pack[self.name]
salt.loaded.int.utils.cloud.MainThread - DEBUG -     KeyError: '__utils__'

So somehow, __utils__ is missing from the relevant test function loader context.

Similarly, going through and making the imports that are pointed at by __utils__ explicit, it then explodes on a __opts__ access:

salt.loaded.int.utils.cloud.MainThread - DEBUG - Caught exception in wait_for_fun: name '__opts__' is not defined
salt.loaded.int.utils.cloud.MainThread - DEBUG -     Traceback (most recent call last):
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 682, in wait_for_fun
salt.loaded.int.utils.cloud.MainThread - DEBUG -         response = fun(**kwargs)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 503, in wait_for_hostname
salt.loaded.int.utils.cloud.MainThread - DEBUG -         data = show_instance(vm_["name"], call="action")
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/cloud/clouds/vultrpy.py", line 325, in show_instance
salt.loaded.int.utils.cloud.MainThread - DEBUG -         salt.utils.cloud.cache_node(nodes[name], _get_active_provider_name(), __opts__)
salt.loaded.int.utils.cloud.MainThread - DEBUG -       File "/usr/lib/python3/dist-packages/salt/utils/cloud.py", line 3073, in cache_node
salt.loaded.int.utils.cloud.MainThread - DEBUG -         __opts__.update(opts)
salt.loaded.int.utils.cloud.MainThread - DEBUG -     NameError: name '__opts__' is not defined
salt.loaded.int.utils.cloud.MainThread - DEBUG -
salt.loaded.int.utils.cloud.MainThread - DEBUG - Retrying function <function create.<locals>.wait_for_hostname at 0x7fccc7fbbc10> on  (try 5)

So all I can conclude is that something in some of the magic import stuff got changed, and no one tests the Vultr integrations at all.

fake-name commented 3 years ago

Possibly related to https://github.com/saltstack/salt/issues/58934 ? I don't think this is related.

yun14u commented 3 years ago

I encounter the similar issue. One interesting observation is that the server instance is created on the Vultr side and I can log on to that server instance using root password created by Vultr.

$ salt --versions-report Salt Version: Salt: 3003.2

yun14u commented 3 years ago

I'm not sure if my comment is relevant; however, Vultr is no longer supporting V1 API (v1). The entire vultrpy.py driver needs to be revamped for V2 API (v2) which requires a lot of code rewrite.

gizahNL commented 2 years ago

Can confirm this is hitting us as well. And agree with the diagnosis that it doesn't seem to be an API issue.

wait_for_hostname ends up calling list_nodes_full last, which is also called by calling "salt-cloud -F", and that seems to work fine, and from what I can see it's the last API call made.