Salt minion sometime return empty ret dict and it fails if failhard set to True

[Oloremo]

Description of Issue

So Salt has this logic for batch execution: https://github.com/saltstack/salt/blob/master/salt/cli/batch.py#L246-L259

I have an orchestration, with batch and failhard set to True and sometimes get this exception:

2020-02-28 14:59:44,383 [salt.state] [ERROR]  An exception occurred in this state: Traceback (most recent call last):
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/state.py", line 1933, in call
    **cdata['kwargs'])
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/loader.py", line 1951, in wrapper
    return f(*args, **kwargs)
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/states/saltmod.py", line 331, in state
    cmd_ret = __salt__['saltutil.cmd'](tgt, fun, **cmd_kw)
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/modules/saltutil.py", line 1503, in cmd
    client, tgt, fun, arg, timeout, tgt_type, ret, kwarg, **kwargs)
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/modules/saltutil.py", line 1467, in _exec
    for ret_comp in _cmd(**cmd_kwargs):
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/client/__init__.py", line 574, in cmd_batch
    for ret in batch.run():
  File "/opt/behavox/salt/venv/lib/python3.6/site-packages/salt/cli/batch.py", line 258, in run
    if self.opts.get('failhard') and data['retcode'] > 0:
KeyError: 'retcode'

So I dig in and printed the minion and data variables from this logic during error and the problem was that for one minion data is {'ret': {}}.

I checked this minions logs and see that it has finished its logic correctly and sent the results back to master:

2020-02-28 14:56:08,445 [salt.minion] [INFO] [JID: 20200228145436184480] Returning information for job: 20200228145436184480

Steps to Reproduce Issue

It's flapping and looks like only happening during the load.

Versions Report

Same for master and minion.

Salt Version:
           Salt: 2019.2.2

Dependency Versions:
           cffi: Not Installed
       cherrypy: Not Installed
       dateutil: Not Installed
      docker-py: Not Installed
          gitdb: Not Installed
      gitpython: Not Installed
          ioflo: Not Installed
         Jinja2: 2.10.3
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.6.2
   mysql-python: Not Installed
      pycparser: Not Installed
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: Not Installed
         Python: 3.6.8 (default, Aug  7 2019, 17:28:10)
   python-gnupg: 0.4.5
         PyYAML: 3.11
          PyZMQ: 18.0.2
           RAET: Not Installed
          smmap: Not Installed
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.3.1

System Versions:
           dist: centos 7.5.1804 Core
         locale: UTF-8
        machine: x86_64
        release: 3.10.0-862.3.2.el7.x86_64
         system: Linux
        version: CentOS Linux 7.5.1804 Core

[Oloremo]

After some discussion in Slack there was an idea that it could be a race condition in https://github.com/saltstack/salt/blob/master/salt/client/__init__.py#L1100

[Oloremo]

So I guess this particular error could be fixed by something like:

if self.opts.get('failhard') and data.get('ret', {}) and data.get('retcode', 255) > 0:

[garethgreenaway]

@Oloremo Thanks for the report. Have you been able to test the 3000 release to see if this particular bug is happening there as well? The fact that it is only happening sporadically will make it difficult to reproduce.

[Oloremo]

Yes, it's hard to reproduce.

First of all, there are 2 different problems:

1. Some kind of race in Salt minion return gather logic, we kinda assume it didn't fetch the last batch of returns sometimes(race). Can't confirm it yet.
2. While 1) happens this logic in batch.py can't handle it properly and raise that exception.

I'm trying to find a reproducible scenario for this issue, right now I can catch it like 1 in 50 runs on a specific cluster.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

If this issue is closed prematurely, please leave a comment and we will gladly reopen the issue.

[Oloremo]

Not stale

[stale]

Thank you for updating this issue. It is no longer marked as stale.

[Oloremo]

Have you been able to test the 3000 release

Reproduced from time to time in 3000.3.

We heavily use orchestrate runner with batch. Batch is set with a percentage of 34%. It's ofter reproduces on bigger clusters, we don't see almost at all on ~10 nodes cluster. See it sometimes on 30 nodes cluster and actually reproduced more or less stable(like in 30% of times) on a 100 nodes cluster.

[seanzhang422]

We are running 3000.2 and is having same issue here. One of the application we manage has 50+ nodes and this issue has been witnessed multiple times. In the master log, we found the exeption:

KeyError: u'retcode'
Traceback (most recent call last):
  File "/bin/salt", line 9, in <module>
    load_entry_point('salt==3000.2', 'console_scripts', 'salt')()
  File "/usr/lib/python2.7/dist-packages/salt/scripts.py", line 530, in salt_main
    client.run()
  File "/usr/lib/python2.7/dist-packages/salt/cli/salt.py", line 66, in run
    self._run_batch()
  File "/usr/lib/python2.7/dist-packages/salt/cli/salt.py", line 284, in _run_batch
    for res in batch.run():
  File "/usr/lib/python2.7/dist-packages/salt/cli/batch.py", line 258, in run
    if self.opts.get('failhard') and data['retcode'] > 0

When this issue was witnessed, test.ping to minions also had multiple minion not returned. I don't see logs for that in master log. The list of minions that didn't return upon test.ping changed when re-run test.ping so it was likely not minion issue.

Our experience is that a restart of salt-master always fix this. Seems like something was broken with the master process at that moment and the master process can't fix itself.

[sagetherage]

Fix released in v3003.1 and ported to the master branch