Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

NXOS_API Proxy Minions Error KeyError: 'proxy.post_master_init' after upgrading to 2019.2.1 #54751

Closed
jnmatlock opened this issue Sep 25, 2019 · 8 comments

Comments

@jnmatlock
Copy link

commented Sep 25, 2019

Description of Issue

Proxy Minions unable to come up after upgrading from 2019.2.0 to 2019.2.1.

Setup

NXOS_API Pillar Config

proxy:
  host: 10.0.0.10
  username: myusername
  password: mypassword
  proxytype: nxos_api
  transport: https
  port: 8443
  verify: False

(Please provide relevant configs and/or SLS files (Be sure to remove sensitive info).)

Steps to Reproduce Issue

All NXOS_API proxys have the same issue. Including some custom proxys as well.

[salt.minion      :1049][CRITICAL][1452] Unexpected error while connecting to localhost
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 1026, in _connect_minion
    yield minion.connect_master(failed=failed)
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/usr/local/lib/python3.6/dist-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 1063, in run
    yielded = self.gen.throw(*exc_info)
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 1225, in connect_master
    yield self._post_master_init(master)
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/usr/local/lib/python3.6/dist-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 292, in wrapper
    result = func(*args, **kwargs)
  File "/usr/lib/python3.6/types.py", line 248, in wrapped
    coro = func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 3343, in _post_master_init
    mp_call = _metaproxy_call(self.opts, 'post_master_init')
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 3318, in _metaproxy_call
    return metaproxy[metaproxy_fn]
  File "/usr/lib/python3/dist-packages/salt/loader.py", line 1208, in __getitem__
    func = super(LazyLoader, self).__getitem__(item)
  File "/usr/lib/python3/dist-packages/salt/utils/lazy.py", line 108, in __getitem__
    raise KeyError(key)
KeyError: 'proxy.post_master_init'

Debug from a NXOS_API Proxy Minion

salt-proxy --proxyid my_nxos_api -l debug
[DEBUG   ] Reading configuration from /etc/salt/proxy
[DEBUG   ] Configuration file path: /etc/salt/proxy
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[INFO    ] Setting up "my_nxos_api" the Salt ProxyMinion
[DEBUG   ] Marking 'base64_encode' as a jinja filter
[DEBUG   ] Marking 'base64_decode' as a jinja filter
[DEBUG   ] Marking 'md5' as a jinja filter
[DEBUG   ] Marking 'sha256' as a jinja filter
[DEBUG   ] Marking 'sha512' as a jinja filter
[DEBUG   ] Marking 'hmac' as a jinja filter
[DEBUG   ] Marking 'random_hash' as a jinja filter
[DEBUG   ] Marking 'rand_str' as a jinja filter
[DEBUG   ] Marking 'file_hashsum' as a jinja filter
[DEBUG   ] Marking 'http_query' as a jinja filter
[DEBUG   ] Marking 'strftime' as a jinja filter
[DEBUG   ] Marking 'date_format' as a jinja filter
[DEBUG   ] Marking 'yaml_dquote' as a jinja filter
[DEBUG   ] Marking 'yaml_squote' as a jinja filter
[DEBUG   ] Marking 'yaml_encode' as a jinja filter
[DEBUG   ] Marking 'raise' as a jinja global
[DEBUG   ] Marking 'match' as a jinja test
[DEBUG   ] Marking 'equalto' as a jinja test
[DEBUG   ] Marking 'skip' as a jinja filter
[DEBUG   ] Marking 'sequence' as a jinja filter
[DEBUG   ] Marking 'to_bool' as a jinja filter
[DEBUG   ] Marking 'tojson' as a jinja filter
[DEBUG   ] Marking 'quote' as a jinja filter
[DEBUG   ] Marking 'regex_escape' as a jinja filter
[DEBUG   ] Marking 'regex_search' as a jinja filter
[DEBUG   ] Marking 'regex_match' as a jinja filter
[DEBUG   ] Marking 'regex_replace' as a jinja filter
[DEBUG   ] Marking 'uuid' as a jinja filter
[DEBUG   ] Marking 'unique' as a jinja filter
[DEBUG   ] Marking 'min' as a jinja filter
[DEBUG   ] Marking 'max' as a jinja filter
[DEBUG   ] Marking 'avg' as a jinja filter
[DEBUG   ] Marking 'union' as a jinja filter
[DEBUG   ] Marking 'intersect' as a jinja filter
[DEBUG   ] Marking 'difference' as a jinja filter
[DEBUG   ] Marking 'symmetric_difference' as a jinja filter
[DEBUG   ] Created pidfile: /var/run/salt/my_nxos_api/salt-minion.pid
[INFO    ] The Proxy Minion is starting up the Salt ProxyMinion
[DEBUG   ] AsyncEventPublisher PUB socket URI: /var/run/salt/proxy/minion_event_84a5fd23d3_pub.ipc
[DEBUG   ] AsyncEventPublisher PULL socket URI: /var/run/salt/proxy/minion_event_84a5fd23d3_pull.ipc
[INFO    ] Starting pull socket on /var/run/salt/proxy/minion_event_84a5fd23d3_pull.ipc
[DEBUG   ] SaltEvent PUB socket URI: /var/run/salt/proxy/minion_event_84a5fd23d3_pub.ipc
[DEBUG   ] SaltEvent PULL socket URI: /var/run/salt/proxy/minion_event_84a5fd23d3_pull.ipc
[INFO    ] Creating minion process manager
[DEBUG   ] Process Manager starting!
[DEBUG   ] Process Manager starting!
[DEBUG   ] Connecting to master. Attempt 1 of 1
[DEBUG   ] "localhost" Not an IP address? Assuming it is a hostname.
[DEBUG   ] Master URI: tcp://127.0.0.1:4506
[DEBUG   ] Popen(['git', 'version'], cwd=/, universal_newlines=False, shell=None)
[DEBUG   ] Popen(['git', 'version'], cwd=/, universal_newlines=False, shell=None)
[DEBUG   ] Initializing new AsyncAuth for ('/etc/salt/pki/proxy', 'my_nxos_api', 'tcp://127.0.0.1:4506')
[DEBUG   ] Generated random reconnect delay between '1000ms' and '11000ms' (10877)
[DEBUG   ] Setting zmq_reconnect_ivl to '10877ms'
[DEBUG   ] Setting zmq_reconnect_ivl_max to '11000ms'
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/proxy', 'my_nxos_api', 'tcp://127.0.0.1:4506', 'clear')
[DEBUG   ] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
[DEBUG   ] Trying to connect to: tcp://127.0.0.1:4506
[DEBUG   ] salt.crypt.get_rsa_pub_key: Loading public key
[DEBUG   ] Decrypting the current master AES key
[DEBUG   ] salt.crypt.get_rsa_key: Loading private key
[DEBUG   ] salt.crypt._get_key_with_evict: Loading private key
[DEBUG   ] Loaded minion key: /etc/salt/pki/proxy/minion.pem
[DEBUG   ] salt.crypt.get_rsa_pub_key: Loading public key
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] Connecting the Minion to the Master publish port, using the URI: tcp://127.0.0.1:4505
[DEBUG   ] salt.crypt.get_rsa_key: Loading private key
[DEBUG   ] Loaded minion key: /etc/salt/pki/proxy/minion.pem
[DEBUG   ] Could not LazyLoad proxy.post_master_init: 'proxy.post_master_init' is not available.
[CRITICAL] Unexpected error while connecting to localhost
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 1026, in _connect_minion
    yield minion.connect_master(failed=failed)
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/usr/local/lib/python3.6/dist-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 1063, in run
    yielded = self.gen.throw(*exc_info)
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 1225, in connect_master
    yield self._post_master_init(master)
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/usr/local/lib/python3.6/dist-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/usr/local/lib/python3.6/dist-packages/tornado/gen.py", line 292, in wrapper
    result = func(*args, **kwargs)
  File "/usr/lib/python3.6/types.py", line 248, in wrapped
    coro = func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 3343, in _post_master_init
    mp_call = _metaproxy_call(self.opts, 'post_master_init')
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 3318, in _metaproxy_call
    return metaproxy[metaproxy_fn]
  File "/usr/lib/python3/dist-packages/salt/loader.py", line 1208, in __getitem__
    func = super(LazyLoader, self).__getitem__(item)
  File "/usr/lib/python3/dist-packages/salt/utils/lazy.py", line 108, in __getitem__
    raise KeyError(key)
KeyError: 'proxy.post_master_init'

Versions Report

Salt Version:
           Salt: 2019.2.1
 
Dependency Versions:
           cffi: 1.12.2
       cherrypy: 8.9.1
       dateutil: 2.8.0
      docker-py: Not Installed
          gitdb: 2.0.3
      gitpython: 2.1.8
          ioflo: Not Installed
         Jinja2: 2.10
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: 0.31.0
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.5.6
   mysql-python: Not Installed
      pycparser: 2.19
       pycrypto: 2.6.1
   pycryptodome: 3.8.2
         pygit2: Not Installed
         Python: 3.6.8 (default, Aug 20 2019, 17:12:48)
   python-gnupg: 0.4.1
         PyYAML: 5.1
          PyZMQ: 17.1.2
           RAET: Not Installed
          smmap: 2.0.3
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.2.5
 
System Versions:
           dist: Ubuntu 18.04 bionic
         locale: UTF-8
        machine: x86_64
        release: 4.15.0-64-generic
         system: Linux
        version: Ubuntu 18.04 bionic
@garethgreenaway

This comment has been minimized.

Copy link
Member

commented Sep 26, 2019

@jnmatlock Thanks for the report. Quick question, did you upgrade your Salt master and restart it, or just the proxy minion?

@max-arnold

This comment has been minimized.

Copy link
Contributor

commented Sep 26, 2019

I observed the same issue on Neon branch (didn't report it because it is not yet stabilized). It seems to be related to the metaproxy PR backport #54001.

Now I reproduced it on a fresh 2019.2.1 Vagrant install (both master and minion):

# salt-proxy --proxyid proxy1

[CRITICAL] Unexpected error while connecting to 192.168.10.10
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 1026, in _connect_minion
    yield minion.connect_master(failed=failed)
  File "/usr/lib/python3/dist-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/usr/lib/python3/dist-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/usr/lib/python3/dist-packages/tornado/gen.py", line 1063, in run
    yielded = self.gen.throw(*exc_info)
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 1225, in connect_master
    yield self._post_master_init(master)
  File "/usr/lib/python3/dist-packages/tornado/gen.py", line 1055, in run
    value = future.result()
  File "/usr/lib/python3/dist-packages/tornado/concurrent.py", line 238, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/usr/lib/python3/dist-packages/tornado/gen.py", line 292, in wrapper
    result = func(*args, **kwargs)
  File "/usr/lib/python3.6/types.py", line 248, in wrapped
    coro = func(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 3343, in _post_master_init
    mp_call = _metaproxy_call(self.opts, 'post_master_init')
  File "/usr/lib/python3/dist-packages/salt/minion.py", line 3318, in _metaproxy_call
    return metaproxy[metaproxy_fn]
  File "/usr/lib/python3/dist-packages/salt/loader.py", line 1208, in __getitem__
    func = super(LazyLoader, self).__getitem__(item)
  File "/usr/lib/python3/dist-packages/salt/utils/lazy.py", line 108, in __getitem__
    raise KeyError(key)
KeyError: 'proxy.post_master_init'

Maybe it is actually a good idea to follow your own development policy and avoid merging new features into stable branches? Doing some QA would be also useful.

@jnmatlock

This comment has been minimized.

Copy link
Author

commented Sep 26, 2019

@garethgreenaway After upgrading to 2019.2.1, the SALT Master and Proxy were restarted.

@garethgreenaway

This comment has been minimized.

Copy link
Member

commented Sep 26, 2019

@jnmatlock @max-arnold Thanks for the updates. We've identified the issue and the fix will be available in a 2019.2.2 release, which we hope to release next week.

@mattp-

This comment has been minimized.

Copy link
Contributor

commented Oct 3, 2019

shouldn't this have broken all proxy tests?

@garethgreenaway

This comment has been minimized.

Copy link
Member

commented Oct 3, 2019

@mattp- Unfortunately no. This issue was a packaging one. The new metaproxy directory didn't get included in the package while it was available in the source that was checked out during tests. We have plans to add additional tests to test the packages using the testing suite.

@mattp-

This comment has been minimized.

Copy link
Contributor

commented Oct 3, 2019

ah gotcha. thanks

@cachedout

This comment has been minimized.

Copy link
Collaborator

commented Oct 21, 2019

Shouldn't this be closed now that #54783 is merged?

@jnmatlock jnmatlock closed this Oct 21, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
5 participants
You can’t perform that action at this time.