saltstack / saltstack/salt

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

Open
#60,568 5 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug
Dominant language
Python
Stars
15.7k
Forks
5.6k
Avg merge
2d 44m
Merged PRs (30d)
80

Description

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

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with salt/cloud/clouds/vultrpy.py, especially _query(), wait_for_hostname(), and wait_for_server_state(), then inspect salt/utils/cloud.py's wait_for_fun() using the reported traceback. Reproduce a Vultr deployment and follow the utils failure after server creation. Done means the deployment creates the VM successfully and failures provide a useful, non-repeating diagnostic.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
cloud
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.