Issue with SDB loader

[ggiesen]

Description
When creating an extension with an SDB module, it appears either due to an issue in salt-extension or salt itself, it doesn't load SDB modules from extensions properly.

Setup

Local machine

mkdir my_extension
cd my_extension
vagrant init almalinux/8
vagrant up
vagrant ssh

Vagrant machine

sudo dnf install -y git python38
sudo rpm --import https://repo.saltproject.io/salt/py3/redhat/8/x86_64/3005/SALTSTACK-GPG-KEY.pub
curl -fsSL https://repo.saltproject.io/salt/py3/redhat/8/x86_64/3005.repo | sudo tee /etc/yum.repos.d/salt.repo
sudo dnf install -y salt-minion
pip3 install --user pipx
pipx install salt-extension
mkdir ~/my_extension
cd ~/my_extension
create-salt-extension -A "John Example Doe" -E "[email protected]" -S "An example Salt Extension Module" -U https://example.com/my-saltext -L apache -l states -l module -l sdb my_extension
python3 -m venv .env --prompt 'my_extension'
source .env/bin/activate
git init .
python -m pip install -e .[dev,tests,docs]
pre-commit install
git config user.email "[email protected]"
git config user.name "John Example Doe"
git add .
git commit -a -m 'Initial extension layout'

Create get function in sdb

cat << EOF >> ~/my_extension/src/saltext/my_extension/sdbs/my_extension_mod.py


def get(key, profile=None):
    """
    This example function should be replaced

    CLI Example:

    .. code-block:: bash

        salt '*' sdb.get 'sdb://my_extension/foo'
    """
    return key
EOF

Add config file for extension

cat << EOF | sudo tee /etc/salt/minion.d/my_extension.conf
my_extension:
  driver: my_extension
EOF

Install extension

sudo salt-pip install ~/my_extension

Validate extension works for execution module

sudo salt-call --local my_extension.example_function foo
local:
    foo

Steps to Reproduce the behaviour

sudo salt-call --local sdb.get 'sdb://my_extension/foo' -l debug
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load saltext
[DEBUG   ] TiamatPipPathFinder.find_spec: /opt/saltstack/salt/pypath/lib/python3.9/site-packages/saltext is a directory
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load log4mongo
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load raven
[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/my_extension.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/my_extension.conf
[DEBUG   ] Using cached minion ID from /etc/salt/minion_id: 192.168.11.177
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load saltext
[DEBUG   ] TiamatPipPathFinder.find_spec: /opt/saltstack/salt/pypath/lib/python3.9/site-packages/saltext is a directory
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load log4mongo
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load raven
[DEBUG   ] Configuration file path: /etc/salt/minion
[DEBUG   ] Grains refresh requested. Refreshing grains.
[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/my_extension.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/my_extension.conf
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load pywintypes
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load dns
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load tldextract
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load tldextract
[DEBUG   ] The functions from module 'core' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'disks' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'extra' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'lvm' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'mdadm' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'minion_process' are being loaded by dir() on the loaded module
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load napalm
[DEBUG   ] The functions from module 'opts' are being loaded by dir() on the loaded module
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load pythoncom
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load win32com
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load win32api
[DEBUG   ] Override  __utils__: <module 'salt.loaded.int.grains.zfs' from '/opt/saltstack/salt/run/salt/grains/zfs.py'>
[DEBUG   ] The functions from module 'zfs' are being loaded by dir() on the loaded module
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] Elapsed time getting FQDNs: 0.026114702224731445 seconds
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load _bootlocale
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load lsb_release
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] The functions from module 'zfs' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded zfs.is_supported
[DEBUG   ] User provided environment variable 'LD_LIBRARY_PATH' with value '/opt/saltstack/salt/run' which is the value that PyInstaller set's. Removing it
[DEBUG   ] Setting environment variable 'LD_LIBRARY_PATH' to an empty string
[DEBUG   ] Determining pillar cache
[DEBUG   ] The functions from module 'jinja' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] The functions from module 'yaml' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] The functions from module 'jinja' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] The functions from module 'yaml' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] The functions from module 'sdb' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded sdb.get
[DEBUG   ] The functions from module 'direct_call' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded direct_call.execute
[DEBUG   ] The functions from module 'cache' are being loaded by dir() on the loaded module
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load confidant
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load consul
[DEBUG   ] The functions from module 'consul' are being loaded by dir() on the loaded module
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load couchdb
[DEBUG   ] The functions from module 'couchdb' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'env' are being loaded by dir() on the loaded module
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load etcd
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load etcd3
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load keyring
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load memcache
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load redis
[DEBUG   ] The functions from module 'rest' are being loaded by dir() on the loaded module
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load sqlite3
[DEBUG   ] TiamatPipPathFinder.find_spec: First time trying to load _sqlite3
[DEBUG   ] The functions from module 'sqlite3' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'tism' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'vault' are being loaded by dir() on the loaded module
[DEBUG   ] The functions from module 'yaml' are being loaded by dir() on the loaded module
[DEBUG   ] Could not LazyLoad my_extension.get: 'my_extension.get' is not available.
[DEBUG   ] Restoring sys.argv to: ['/opt/saltstack/salt/run/run', '--local', 'sdb.get', 'sdb://my_extension/foo', '-l', 'debug']
[ERROR   ] An un-handled exception was caught by Salt's global exception handler:
KeyError: 'my_extension.get'
Traceback (most recent call last):
  File "/root/.pyenv/versions/3.9.15/envs/tmp_76gn3tu/bin/salt", line 118, in <module>
  File "/root/.pyenv/versions/3.9.15/envs/tmp_76gn3tu/bin/salt", line 113, in redirect
  File "salt/scripts.py", line 441, in salt_call
    client.run()
  File "salt/cli/call.py", line 50, in run
    caller.run()
  File "salt/cli/caller.py", line 95, in run
    ret = self.call()
  File "salt/cli/caller.py", line 202, in call
    ret["return"] = self.minion.executors[fname](
  File "salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "salt/loader/lazy.py", line 1228, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "salt/loader/lazy.py", line 1243, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/run/salt/executors/direct_call.py", line 10, in execute
    return func(*args, **kwargs)
  File "salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "salt/loader/lazy.py", line 1228, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "salt/loader/lazy.py", line 1243, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/run/salt/modules/sdb.py", line 25, in get
    return salt.utils.sdb.sdb_get(uri, __opts__, __utils__, strict)
  File "salt/utils/sdb.py", line 57, in sdb_get
    return loaded_db[fun](query, profile=profile)
  File "salt/loader/lazy.py", line 336, in __getitem__
    super().__getitem__(item)  # try to get the item from the dictionary
  File "salt/utils/lazy.py", line 105, in __getitem__
    raise KeyError(key)
KeyError: 'my_extension.get'
Traceback (most recent call last):
  File "/root/.pyenv/versions/3.9.15/envs/tmp_76gn3tu/bin/salt", line 118, in <module>
  File "/root/.pyenv/versions/3.9.15/envs/tmp_76gn3tu/bin/salt", line 113, in redirect
  File "salt/scripts.py", line 441, in salt_call
  File "salt/cli/call.py", line 50, in run
  File "salt/cli/caller.py", line 95, in run
  File "salt/cli/caller.py", line 202, in call
  File "salt/loader/lazy.py", line 149, in __call__
  File "salt/loader/lazy.py", line 1228, in run
  File "salt/loader/lazy.py", line 1243, in _run_as
  File "/opt/saltstack/salt/run/salt/executors/direct_call.py", line 10, in execute
    return func(*args, **kwargs)
  File "salt/loader/lazy.py", line 149, in __call__
  File "salt/loader/lazy.py", line 1228, in run
  File "salt/loader/lazy.py", line 1243, in _run_as
  File "/opt/saltstack/salt/run/salt/modules/sdb.py", line 25, in get
    return salt.utils.sdb.sdb_get(uri, __opts__, __utils__, strict)
  File "salt/utils/sdb.py", line 57, in sdb_get
  File "salt/loader/lazy.py", line 336, in __getitem__
  File "salt/utils/lazy.py", line 105, in __getitem__
KeyError: 'my_extension.get'
[9921] Failed to execute script 'salt' due to unhandled exception!

Expected behaviour

local:
    foo

Versions Report

salt --versions-report

(Provided by running salt --versions-report. Please also mention any differences in master/minion versions.)

Salt Version:
                 Salt: 3005.1

Dependency Versions:
                 cffi: 1.14.6
             cherrypy: 18.6.1
             dateutil: 2.8.1
            docker-py: Not Installed
                gitdb: Not Installed
            gitpython: Not Installed
               Jinja2: 3.1.0
              libgit2: Not Installed
             M2Crypto: Not Installed
                 Mako: Not Installed
              msgpack: 1.0.2
         msgpack-pure: Not Installed
         mysql-python: Not Installed
            pycparser: 2.21
             pycrypto: Not Installed
         pycryptodome: 3.9.8
               pygit2: Not Installed
               Python: 3.9.15 (main, Nov  8 2022, 03:47:03)
         python-gnupg: 0.4.8
               PyYAML: 5.4.1
                PyZMQ: 23.2.0
                smmap: Not Installed
              timelib: 0.2.4
              Tornado: 4.5.3
                  ZMQ: 4.3.4

Salt Extensions:
 saltext.my-extension: 0.1.dev0+d20221113

System Versions:
                 dist: almalinux 8.7 Stone Smilodon
               locale: utf-8
              machine: x86_64
              release: 4.18.0-425.3.1.el8.x86_64
               system: Linux
              version: AlmaLinux 8.7 Stone Smilodon

[ggiesen]

Note, if I edit ~/my_extension/src/saltext/my_extension/loader.py to change:

return [str(PACKAGE_ROOT / "sdbs")]

to:

return [str(PACKAGE_ROOT / "sdb")]

and then rename ~/my_extension/src/saltext/my_extension/sdbs to ~/my_extension/src/saltext/my_extension/sdb and uninstall/reinstall, it works. Note, even if I change it back to sdbs and then uninstall/reinstall, it still works. Not sure if it's a caching issue with PIP, but /opt/saltstack/salt/pypath/lib/python3.9/site-packages/saltext/my_extension/sdb reappears, even if I change everything back and reinstall, and this is apparently how it's working.