minion authentication issues

[David Bottger]

Hi, 

I'm seeing some odd minion authentication issues.

minions are not responding to test.ping

minions are logging:

2014-09-11 15:00:12,367 [salt.minion                                 ][CRITICAL] An exception occurred while polling the minion

Traceback (most recent call last):

  File "/usr/lib/python2.6/site-packages/salt/minion.py", line 1473, in tune_in_no_block

    self._handle_payload(payload)

  File "/usr/lib/python2.6/site-packages/salt/minion.py", line 660, in _handle_payload

    payload['sig'] if 'sig' in payload else None)

  File "/usr/lib/python2.6/site-packages/salt/minion.py", line 685, in _handle_aes

    data = self.crypticle.loads(load)

  File "/usr/lib/python2.6/site-packages/salt/crypt.py", line 505, in loads

    data = self.decrypt(data)

  File "/usr/lib/python2.6/site-packages/salt/crypt.py", line 488, in decrypt

    raise AuthenticationError('message authentication failed')

AuthenticationError: message authentication failed

while master logs

2014-09-11 15:00:12,367 [salt.master                                 ][INFO    ] Authentication request from server1.xyz.com

2014-09-11 15:00:12,367 [salt.master                                 ][INFO    ] Authentication accepted from server1.xyz.com

 

minion restart clears it up, but within 24 hours the minions drop off line (meaning test.ping no longer works).

both are running 2014.1.10

minions are configured for syn flood:

recon_default: 1000

recon_max: 59000

recon_randomize: True

acceptance_wait_time: 10

random_reauth_delay: 60

auth_timeout: 60

I do not yet have minion debug info for when it stops responding, currently working on that.

db

[dbott]

OK, got debug info for both master and minion for when the minion stops responding

Looks like the master restarted?  (shows loading of conf files)

master:

2014-09-11 15:10:24,649 [salt.utils.event                         ][DEBUG   ] LocalClientEvent PUB socket URI: ipc:///var/run/salt/master/master_event_pub.ipc

2014-09-11 15:10:24,650 [salt.utils.event                         ][DEBUG   ] LocalClientEvent PULL socket URI: ipc:///var/run/salt/master/master_event_pull.ipc

2014-09-11 15:10:24,653 [salt.master                                 ][INFO    ] Clear payload received with command publish

2014-09-11 15:10:24,654 [salt.master                                 ][DEBUG   ] Minion tokenized user = "usera"

2014-09-11 15:10:24,655 [salt.master                                 ][INFO    ] User usera Published command util.factInfo with jid 20140911151024654332

2014-09-11 15:10:24,656 [salt.master                                 ][DEBUG   ] Published command details {'tgt_type': 'list', 'jid': '20140911151024654332', 'tgt': ['server2.xyz.com', 'server1.xyz.com'], 'ret': '', 'user': 'usera', 'arg': [], 'fun': 'util.factInfo'}

2014-09-11 15:10:24,710 [cherrypy.access.28142032                 ][INFO    ] 10.196.45.23 - - [11/Sep/2014:15:10:24] "POST / HTTP/1.1" 200 138 "" "Python-urllib/2.6"

2014-09-11 15:10:24,781 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/halite.conf'

2014-09-11 15:10:24,783 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/halite.conf

2014-09-11 15:10:24,795 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/ldap.conf'

2014-09-11 15:10:24,797 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/ldap.conf

2014-09-11 15:10:24,817 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/logging.conf'

2014-09-11 15:10:24,819 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/logging.conf

2014-09-11 15:10:24,825 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master

2014-09-11 15:10:24,851 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/halite.conf'

2014-09-11 15:10:24,865 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/halite.conf

2014-09-11 15:10:24,874 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/master.conf'

2014-09-11 15:10:24,876 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/master.conf

2014-09-11 15:10:24,879 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/ldap.conf'

2014-09-11 15:10:24,883 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/ldap.conf

2014-09-11 15:10:24,888 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/nodegroups.conf'

2014-09-11 15:10:24,891 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/nodegroups.conf

2014-09-11 15:10:24,903 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/rest_cherrypy.conf'

2014-09-11 15:10:24,905 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/rest_cherrypy.conf

2014-09-11 15:10:24,918 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/logging.conf'

2014-09-11 15:10:24,918 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/logging.conf

2014-09-11 15:10:24,919 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/security.conf'

2014-09-11 15:10:24,920 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/security.conf

2014-09-11 15:10:24,944 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/master.conf'

2014-09-11 15:10:24,945 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/master.conf

2014-09-11 15:10:24,964 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/nodegroups.conf'

2014-09-11 15:10:24,967 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/nodegroups.conf

2014-09-11 15:10:24,986 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/rest_cherrypy.conf'

2014-09-11 15:10:24,991 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/rest_cherrypy.conf

2014-09-11 15:10:25,005 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/security.conf'

2014-09-11 15:10:25,008 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/security.conf

2014-09-11 15:10:25,066 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/syndic.conf'

2014-09-11 15:10:25,068 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/syndic.conf

2014-09-11 15:10:25,101 [salt.config                              ][DEBUG   ] Missing configuration file: /root/.saltrc

2014-09-11 15:10:25,108 [salt.utils.event                         ][DEBUG   ] LocalClientEvent PUB socket URI: ipc:///var/run/salt/master/master_event_pub.ipc

2014-09-11 15:10:25,108 [salt.utils.event                         ][DEBUG   ] LocalClientEvent PULL socket URI: ipc:///var/run/salt/master/master_event_pull.ipc

2014-09-11 15:10:25,120 [salt.config                              ][DEBUG   ] Including configuration from '/etc/salt/master.d/syndic.conf'

2014-09-11 15:10:25,121 [salt.config                              ][DEBUG   ] Reading configuration from /etc/salt/master.d/syndic.conf

2014-09-11 15:10:25,130 [salt.config                              ][DEBUG   ] Missing configuration file: /root/.saltrc

2014-09-11 15:10:25,132 [salt.utils.event                         ][DEBUG   ] LocalClientEvent PUB socket URI: ipc:///var/run/salt/master/master_event_pub.ipc

2014-09-11 15:10:25,132 [salt.utils.event                         ][DEBUG   ] LocalClientEvent PULL socket URI: ipc:///var/run/salt/master/master_event_pull.ipc

minion:

[INFO    ] Returning information for job: 20140911151024654332

[DEBUG   ] Failed to authenticate message

[DEBUG   ] Waiting 59 seconds to re-authenticate

[DEBUG   ] Attempting to authenticate with the Salt Master at 10.196.45.24

[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem

[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem

[DEBUG   ] Decrypting the current master AES key

[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem

[INFO    ] Authentication with master successful!

[DEBUG   ] Failed to authenticate message

[CRITICAL] An exception occurred while polling the minion

Traceback (most recent call last):

  File "/usr/lib/python2.6/site-packages/salt/minion.py", line 1474, in tune_in_no_block

    self._handle_payload(payload)

  File "/usr/lib/python2.6/site-packages/salt/minion.py", line 661, in _handle_payload

    payload['sig'] if 'sig' in payload else None)

  File "/usr/lib/python2.6/site-packages/salt/minion.py", line 686, in _handle_aes

    data = self.crypticle.loads(load)

  File "/usr/lib/python2.6/site-packages/salt/crypt.py", line 505, in loads

    data = self.decrypt(data)

  File "/usr/lib/python2.6/site-packages/salt/crypt.py", line 488, in decrypt

    raise AuthenticationError('message authentication failed')

AuthenticationError: message authentication failed

[DEBUG   ] Failed to authenticate message

[DEBUG   ] Waiting 21 seconds to re-authenticate

[DEBUG   ] Attempting to authenticate with the Salt Master at 10.196.45.22

[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem

[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem

[DEBUG   ] Decrypting the current master AES key

[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem

[INFO    ] Authentication with master successful!

[DEBUG   ] Failed to authenticate message

[David Ward]

Did you find out a solution to this?
I seem to have the exact same problem.

Thanks