[BUG] Salt exit with bound method Client.__del__ of <etcd.client.Client object at ignored

[pankajghadge]

Description After upgrading salt master and minion to 2019.2.4, we started getting an error We have upgraded due to CVE issue

ERROR: Minions returned with non-zero exit code
Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method Client.__del__ of <etcd.client.Client object at 0x7f4f62781810>> ignored

This error occurs after several execution of salt run. When we restart the salt-master then it goes for a while, but after few hours it starts appearing again

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

Steps to Reproduce the behavior (Include debug logs if possible and relevant)

salt 'target' cmd.run 'ls -l /var' -l debug

[DEBUG   ] .Passing on saltutil error. Key 'u'retcode' missing from client return. This may be an error in the client
[DEBUG   ] return event: {'example1.com': {u'failed': True}}
[DEBUG   ] Could not LazyLoad etcd.init_kwargs: 'etcd.init_kwargs' is not available.
[INFO    ] etcd: Setting up client with params: {u'username': u'saltmaster', u'protocol': u'http', u'ca_cert': u'None', u'allow_redirect': False, u'srv_domain': None, u'host': u'192.168.1.98', u'read_timeout': 60, u'password': u'test_pass', u'port': 2379, u'allow_reconnect': True, u'cert': u'None'}
[DEBUG   ] Starting new HTTP connection (1): 192.168.1.98:2379
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/machines HTTP/1.1" 200 23
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/keys/salt_cache HTTP/1.1" 200 178
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/keys/salt_cache/minions HTTP/1.1" 200 None
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/keys/salt_cache/minions?recursive=true HTTP/1.1" 200 None
[DEBUG   ] Could not LazyLoad etcd.init_kwargs: 'etcd.init_kwargs' is not available.
[INFO    ] etcd: Setting up client with params: {u'username': u'saltmaster', u'protocol': u'http', u'ca_cert': u'None', u'allow_redirect': False, u'srv_domain': None, u'host': u'192.168.1.98', u'read_timeout': 60, u'password': u'test_pass', u'port': 2379, u'allow_reconnect': True, u'cert': u'None'}
[DEBUG   ] Starting new HTTP connection (1): 192.168.1.98:2379
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/machines HTTP/1.1" 200 23
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/keys/salt_cache HTTP/1.1" 200 178
[DEBUG   ] http://192.168.1.98:2379 "GET /v2/keys/salt_cache/minions?recursive=true HTTP/1.1" 200 None

[DEBUG   ] Closing IPCMessageSubscriber instance
ERROR: Minions returned with non-zero exit code
Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method Client.__del__ of <etcd.client.Client object at 0x7f4f62781810>> ignored

Warning on minion log:

2020-05-05 17:00:15,248 [salt.utils.parsers:1071][WARNING ][1844] Minion received a SIGTERM. Exiting.
2020-05-05 17:02:00,540 [salt.utils.parsers:1071][WARNING ][25113] Minion received a SIGTERM. Exiting.
2020-05-06 01:07:57,521 [salt.utils.parsers:1071][WARNING ][25358] Minion received a SIGTERM. Exiting.

For simple salt.run it occurs after 10-15 continuous salt call from master

Expected behavior Error must go, instead it should print expected output

Screenshots If applicable, add screenshots to help explain your problem.

Versions Report

salt --versions-report

(Provided by running salt --versions-report. Please also mention any differences in master/minion versions.) ``` salt --versions-report Salt Version: Salt: 2019.2.4 Dependency Versions: cffi: 1.6.0 cherrypy: Not Installed dateutil: 1.5 docker-py: Not Installed gitdb: Not Installed gitpython: Not Installed ioflo: Not Installed Jinja2: 2.7.2 libgit2: 0.26.4 libnacl: Not Installed M2Crypto: 0.21.1 Mako: Not Installed msgpack-pure: Not Installed msgpack-python: 0.5.6 mysql-python: Not Installed pycparser: 2.14 pycrypto: 2.6.1 pycryptodome: 3.9.7 pygit2: 0.26.4 Python: 2.7.5 (default, Jun 11 2019, 14:33:56) python-gnupg: 0.4.4 PyYAML: 3.10 PyZMQ: 15.3.0 RAET: Not Installed smmap: Not Installed timelib: Not Installed Tornado: 4.2.1 ZMQ: 4.1.4 System Versions: dist: redhat 7.6 Maipo locale: UTF-8 machine: x86_64 release: 3.10.0-1127.el7.x86_64 system: Linux version: Red Hat Enterprise Linux Server 7.6 ```

Additional context Add any other context about the problem here.

[DmitryKuzmenko]

@pankajghadge thank you for report. Any details about your configuration related to etcd?

[pankajghadge]

@DmitryKuzmenko I think this issue is not related to etcd service. When I run this command it give above error randomly it will not always fail but after 2-3 run it will surly fail.

salt 'target' test.ping --return etcd -l trace

When I run the same command directly from minion, it always work

salt-call test.ping --return etcd -l trace

By the way what etcd Configuration do you need? Specify command if possible

One strange thing I have observed when I restart salt-master error doesn't come for 1-2 days later on it starts coming. Note: salt-syndic also gets auto restart when I restart salt-master

One more update: 1) Following commands also show error

salt-run manage.not_reaped
salt-run manage.alived
salt-run manage.allowed

Error: Exception AttributeError: AttributeError("'NoneType' object has no attribute 'Empty'",) in <bound method Client.__del__ of <etcd.client.Client object at 0x7f6903730fd0>> ignored

This command doesn't show error but minions are changing for every run

[salt]# salt-run manage.down
- minion01
- minion02
- minion03
- minion05
- minion07
[salt]# salt-run manage.down
- minion10
- minion03
- minion06
- minion05
- minion09

[DmitryKuzmenko]

@pankajghadge thank you for additional details. About etcd: I wan't to understand what do you have in your configuration related to etcd. Do you use the only etcd returner? Do you use etcd pillars or cache? If you could provide related sanitized configuration it would be helpful.

[pankajghadge]

@DmitryKuzmenko We only have following configuration in master /etc/salt/master.d/etcd-cache.conf we don't use etcd pillars, also there is nothing like etcd returner

`cache: etcd

etcd.host: remote_host etcd.port: 2379 etcd.protocol: http etcd.allow_reconnect: True etcd.allow_redirect: False etcd.read_timeout: 60 etcd.username: etcd_name etcd.password: etcd_password etcd.cert: None etcd.ca_cert: None `

Remote etcd server version:

[user@~]# etcd --version
etcd Version: 3.3.11
Git SHA: 2cf9e51
Go Version: go1.10.3
Go OS/Arch: linux/amd64

etcd systemctl.service

[Service]
Type=notify
WorkingDirectory=/var/lib/etcd/
EnvironmentFile=-/etc/etcd/etcd.conf
User=etcd
# set GOMAXPROCS to number of processors
ExecStart=/bin/bash -c "GOMAXPROCS=$(nproc) /usr/bin/etcd --name=\"${ETCD_NAME}\" --data-dir=\"${ETCD_DATA_DIR}\" --listen-client-urls=\"${ETCD_LISTEN_CLIENT_URLS}\""
Restart=on-failure
LimitNOFILE=65536

[malletp]

Hello @DmitryKuzmenko,

I work with Pankaj. We used etcd as backend for minion data cache to synchronize mine data between all master and syndics. We got the message each time the salt command use the etcd client library.

[pankajghadge]

@DmitryKuzmenko Any finding or progress regarding this issue ?

[DmitryKuzmenko]

Sorry, I've stopped on installing environment and switched to another task. Now I'm back on this.

[DmitryKuzmenko]

I still can not reproduce this. But I have found an upstream bug in python-etcd project. https://github.com/jplana/python-etcd/issues/179 https://github.com/jplana/python-etcd/issues/190 I have tried different versions but still can not reproduce it. Anyway possibly upgrade to the latest versions of python-etcd and urllib3 could help.

@pankajghadge are you able to try it?

[pankajghadge]

@DmitryKuzmenko python-etcd already have latest version 0.4.5 from the beginning urllib3 upgraded from 1.25.7 to 1.25.9 (It is just a minor version upgrade) We are still facing this issue. If you want more trace details let me know. I will add log.trace or log.debug in salt python code.

[DmitryKuzmenko]

I've just re-read all our discussion. Could you please detail some more things?

1. In the very beginning you've provided the log ending with

   Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method Client.__del__ of <etcd.client.Client object at 0x7f4f62781810>> ignored

   This log is from salt command or from minion?

2. When it happens the targeted minion terminates? Could you provide the debug log from the targeted minion? I want to understand what's happening there before this appears:

   2020-05-05 17:00:15,248 [salt.utils.parsers:1071][WARNING ][1844] Minion received a SIGTERM. Exiting.

3. You mentioned syndic. What's your salt layout? Master - Syndic - Minion?

4. Is etcd cache enabled on all nodes: Master, Syndic, Minion?

5. What cache related things are enabled on what nodes? Just grep cache from configs would be enough.

I think the Exception TypeError could be not directly related. It happens on exit during shutdown but something is starting the shutdown process.

[pankajghadge]

@DmitryKuzmenko

1. This log is from salt command or from minion? => salt command (we execute salt command from salt master only ) => we don't execute salt command from salt-master-of-master (only few are executed )

2. When it happens the targeted minion terminates? => no target minion do not terminate, also no error log entry on target minion

3. You mentioned syndic. What's your salt layout? Master - Syndic - Minion? => (salt master of master)+(etcd server) => (Master + syndic) => (minion)

In every salt-master configuration we have entry of salt master of master (Multi master)
syndic_master: salt-master-of-master.example.com etcd configuration I already mentioned

We have total: 1 master of master + 1 etcd cache
20 salt master + syndic 90-120 minions under each master

4. Is etcd cache enabled on all nodes: Master, Syndic, Minion? => only on salt master ans salt-master-of-master we have etcd configuration

5. What cache related things are enabled on what nodes? Just grep cache from configs would be enough => nothing is enabled on minion related to cache => On master only we have configuration related to etcd server as posted earlier

detailed Trace log

[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/autoacceptkey.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/autoacceptkey.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/etcd-cache.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/etcd-cache.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/gitduma.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/gitduma.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/gitfs.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/gitfs.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/id.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/id.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/logging.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/logging.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/output.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/output.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/roots.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/roots.conf
[DEBUG   ] Missing configuration file: /root/.saltrc
[TRACE   ] The required configuration section, 'fluent_handler', was not found the in the configuration. Not loading the fluent logging handlers module.
[TRACE   ] Loaded logstash_mod as virtual logstash
[INFO    ] Processing `log_handlers.logstash`
[DEBUG   ] Adding the 'logstash' provided logging handler: '<salt.loaded.int.log_handlers.logstash_mod.ZMQLogstashHander object at 0x7f60842aaf10>'
[DEBUG   ] Configuration file path: /etc/salt/master
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/autoacceptkey.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/autoacceptkey.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/etcd-cache.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/etcd-cache.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/gitduma.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/gitduma.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/gitfs.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/gitfs.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/id.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/id.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/logging.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/logging.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/output.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/output.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/roots.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/roots.conf
[DEBUG   ] Missing configuration file: /root/.saltrc
[DEBUG   ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG   ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'salt-master1.example.com_master', u'tcp://127.0.0.1:4506', u'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
[TRACE   ] Inserted key into loop_instance_map id 140052477950864 for key (u'/etc/salt/pki/master', u'salt-master1.example.com_master', u'tcp://127.0.0.1:4506', u'clear') and process 20505
[TRACE   ] IPCClient: Connecting to socket: /var/run/salt/master/master_event_pub.ipc
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[TRACE   ] func get_cli_event_returns()
[DEBUG   ] LazyLoaded local_cache.get_load
[DEBUG   ] Reading minion list from /var/cache/salt/master/jobs/83/003c5a988f1e488df5ac21fc61c4edef90c9ed50f6dc30302dc55fd1764128/.minions.p
[DEBUG   ] get_iter_returns for jid 20200612125355282393 sent to set(['vm-minion01']) will timeout at 12:54:00.291040
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] get_event() received = {u'tag': 'salt/job/20200612125355282393/new', u'data': {u'tgt_type': u'glob', u'jid': u'20200612125355282393', u'tgt': u'vm-minion01', u'missing': [], u'_stamp': u'2020-06-12T10:53:55.283282', u'user': u'root', u'arg': [u'ls -l /var'], u'fun': u'cmd.run', u'minions': [u'vm-minion01']}}
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[DEBUG   ] Checking whether jid 20200612125355282393 is still running
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'salt-master1.example.com_master', u'tcp://127.0.0.1:4506', u'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
[TRACE   ] Inserted key into loop_instance_map id 140052460918832 for key (u'/etc/salt/pki/master', u'salt-master1.example.com_master', u'tcp://127.0.0.1:4506', u'clear') and process 20505
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] get_event() caching unwanted event = {u'tag': '20200612125400311074', u'data': {u'_stamp': u'2020-06-12T10:54:00.311398', u'minions': [u'vm-minion01']}}
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] get_event() caching unwanted event = {u'tag': 'salt/job/20200612125400311074/new', u'data': {u'tgt_type': u'list', u'jid': u'20200612125400311074', u'tgt': [u'vm-minion01'], u'missing': [], u'_stamp': u'2020-06-12T10:54:00.311905', u'user': u'root', u'arg': [u'20200612125355282393'], u'fun': u'saltutil.find_job', u'minions': [u'vm-minion01']}}
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] get_event() returning cached event = {u'tag': 'salt/job/20200612125400311074/new', u'data': {u'tgt_type': u'list', u'jid': u'20200612125400311074', u'tgt': [u'vm-minion01'], u'missing': [], u'_stamp': u'2020-06-12T10:54:00.311905', u'user': u'root', u'arg': [u'20200612125355282393'], u'fun': u'saltutil.find_job', u'minions': [u'vm-minion01']}}
[DEBUG   ] Passing on saltutil error. Key 'u'retcode' missing from client return. This may be an error in the client.
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20200612125355282393
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: salt/job/20200612125400311074
[TRACE   ] _get_event() waited 0 seconds and received nothing
[DEBUG   ] return event: {'vm-minion01': {u'failed': True}}
[TRACE   ] Loaded etcd_cache as virtual etcd
[TRACE   ] Error loading cache.consul: Failed to invoke consul.Consul, please make sure you have python-consul >= 0.2.0 installed
[TRACE   ] Error loading cache.mysql_cache: No python mysql client installed.
[TRACE   ] Error loading cache.redis_cache: Please install the python-redis package.
[DEBUG   ] Could not LazyLoad etcd.init_kwargs: 'etcd.init_kwargs' is not available.
[INFO    ] etcd: Setting up client with params: {u'username': u'salt-master-user', u'protocol': u'http', u'ca_cert': u'None', u'allow_redirect': False, u'srv_domain': None, u'host': u'etcd-cache-server', u'read_timeout': 60, u'password': u'testpass', u'port': 2379, u'allow_reconnect': True, u'cert': u'None'}
[DEBUG   ] Starting new HTTP connection (1): etcd-cache-server:2379
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/machines HTTP/1.1" 200 23
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/keys/salt_cache HTTP/1.1" 200 178
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/keys/salt_cache/minions HTTP/1.1" 200 None
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/keys/salt_cache/minions?recursive=true HTTP/1.1" 200 None
[TRACE   ] Loaded etcd_cache as virtual etcd
[TRACE   ] Error loading cache.consul: Failed to invoke consul.Consul, please make sure you have python-consul >= 0.2.0 installed
[TRACE   ] Error loading cache.mysql_cache: No python mysql client installed.
[TRACE   ] Error loading cache.redis_cache: Please install the python-redis package.
[DEBUG   ] Could not LazyLoad etcd.init_kwargs: 'etcd.init_kwargs' is not available.
[INFO    ] etcd: Setting up client with params: {u'username': u'salt-master-user', u'protocol': u'http', u'ca_cert': u'None', u'allow_redirect': False, u'srv_domain': None, u'host': u'etcd-cache-server', u'read_timeout': 60, u'password': u'testpass', u'port': 2379, u'allow_reconnect': True, u'cert': u'None'}
[DEBUG   ] Starting new HTTP connection (1): etcd-cache-server:2379
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/machines HTTP/1.1" 200 23
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/keys/salt_cache HTTP/1.1" 200 178
[DEBUG   ] http://etcd-cache-server:2379 "GET /v2/keys/salt_cache/minions?recursive=true HTTP/1.1" 200 None
[DEBUG   ] LazyLoaded no_return.output
[TRACE   ] data = {'vm-minion01': u'Minion did not return. [No response]'}
[DEBUG   ] Closing IPCMessageSubscriber instance
ERROR: Minions returned with non-zero exit code
vm-minion01:
    Minion did not return. [No response]
Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method Client.__del__ of <etcd.client.Client object at 0x7f608232ee50>> ignored

[DmitryKuzmenko]

@pankajghadge thank you for information. I still can not reproduce it on my side. Are you able to patch your etcd client python package and check would it help? In this case I can work on a patch and if it would help we can contribute it to etcd client team.

[arizvisa]

@pankajghadge, maybe a stupid question, but did you recently switch from python2 to python3?

[arizvisa]

@DmitryKuzmenko, this is a scoping issue and is based on Python's GC. So it won't be easy to reproduce unless your interpreter's garbage collection is aggressive. You might be able to reproduce by explicitly deleting the etcd client when it has gone out of scope, and then calling gc.collect to get Python to clean it up.

You can likely consider it an upstream bug, though, as python-etcd should not be trying to access anything in the object at the time it's being deleted anyways because members of said object aren't guaranteed to exist at the time of deletion (an antipattern).

[DmitryKuzmenko]

@arizvisa thank you for comment. I understand the possible reasons of the issue. And I've done a number of tests to try to reproduce it including small synthetic tests playing around destruction of the etcd client. The best way to fix it is to rewrite etcd client to be a context manager. But it's a big enough change in the upstream project. On the other hand there is etcd3 client that is already written in this way. We could port our code to it that looks better from my view point but it is not 2 lines patch because etcd3 API are different.

[arizvisa]

Agreed. It should definitely be a context manager, or even persisted.

Yeah actually, I've been trying to get my rewrite of the etcd returner merged into master since saltstack was split up into the "develop" branch like 2 years ago (#51363, with another addition in PR #55186).

Right now it's stuck in the "Merge ports into master" project, but once that finaally gets merged into the "master" branch. I'd be willing to re-implement the logic for the etcd returner to use the etcd3 api.

[pankajghadge]

@pankajghadge, maybe a stupid question, but did you recently switch from python2 to python3?

no we didn't switch to python 3

[pankajghadge]

@pankajghadge thank you for information. I still can not reproduce it on my side. Are you able to patch your etcd client python package and check would it help? In this case I can work on a patch and if it would help we can contribute it to etcd client team.

@DmitryKuzmenko I don't know how to patch etcd client python package. in pip i don't see any updates are available
Here is the list of python packages which are available updates but i don't see python etcd package

$ pip list --outdated

Babel (0.9.6) - Latest: 2.8.0 [wheel]
backports.ssl-match-hostname (3.5.0.1) - Latest: 3.7.0.1 [sdist]
cffi (1.6.0) - Latest: 1.14.0 [wheel]
chardet (2.2.1) - Latest: 3.0.4 [wheel]
cheroot (8.2.1) - Latest: 8.3.0 [wheel]
CherryPy (17.4.2) - Latest: 18.6.0 [wheel]
configobj (4.7.2) - Latest: 5.0.6 [sdist]
configshell-fb (1.1.23) - Latest: 1.1.28 [sdist]
decorator (3.4.0) - Latest: 4.4.2 [wheel]
ethtool (0.8) - Latest: 0.14 [sdist]
futures (3.1.1) - Latest: 3.3.0 [wheel]
gevent (1.4.0) - Latest: 20.6.2 [sdist]
greenlet (0.4.15) - Latest: 0.4.16 [wheel]
iniparse (0.4) - Latest: 0.5 [wheel]
ipaddress (1.0.16) - Latest: 1.0.23 [wheel]
jaraco.functools (2.0) - Latest: 3.0.1 [sdist]
Jinja2 (2.7.2) - Latest: 2.11.2 [wheel]
kitchen (1.1.1) - Latest: 1.2.6 [sdist]
kmod (0.1) - Latest: 0.9.2 [sdist]
langtable (0.0.31) - Latest: 0.0.51 [sdist]
lxml (3.2.1) - Latest: 4.5.1 [wheel]
M2Crypto (0.21.1) - Latest: 0.35.2 [sdist]
MarkupSafe (0.11) - Latest: 1.1.1 [wheel]
more-itertools (5.0.0) - Latest: 8.4.0 [sdist]
msgpack (0.6.2) - Latest: 1.0.0 [sdist]
netaddr (0.7.5) - Latest: 0.7.20 [wheel]
pip (8.1.2) - Latest: 20.1.1 [wheel]
ply (3.4) - Latest: 3.11 [wheel]
psutil (2.2.1) - Latest: 5.7.0 [sdist]
pycparser (2.19) - Latest: 2.20 [wheel]
pycurl (7.19.0) - Latest: 7.43.0.5 [sdist]
pygit2 (0.26.4) - Latest: 1.2.1 [sdist]
pygobject (3.22.0) - Latest: 3.36.1 [sdist]
pyinotify (0.9.4) - Latest: 0.9.6 [sdist]
pyOpenSSL (0.13.1) - Latest: 19.1.0 [wheel]
pyparsing (1.5.6) - Latest: 2.4.7 [wheel]
python-augeas (0.5.0) - Latest: 1.1.0 [sdist]
python-dateutil (1.5) - Latest: 2.8.1 [wheel]
python-gnupg (0.4.4) - Latest: 0.4.6 [wheel]
python-ldap (2.4.15) - Latest: 3.3.0 [sdist]
pytz (2019.3) - Latest: 2020.1 [wheel]
pyudev (0.15) - Latest: 0.22.0 [sdist]
pywbem (0.7.0) - Latest: 0.17.2 [wheel]
pyxattr (0.5.1) - Latest: 0.7.1 [sdist]
PyYAML (3.10) - Latest: 5.3.1 [sdist]
pyzmq (15.3.0) - Latest: 19.0.1 [wheel]
requests (2.6.0) - Latest: 2.24.0 [wheel]
salt (2019.2.4) - Latest: 3001 [sdist]
setuptools (36.6.0) - Latest: 47.3.1 [sdist]
six (1.12.0) - Latest: 1.15.0 [wheel]
slip (0.4.0) - Latest: 20191113 [sdist]
tempora (1.14.1) - Latest: 3.0.0 [wheel]
tornado (4.2.1) - Latest: 6.0.4 [sdist]
urlgrabber (3.10) - Latest: 4.1.0 [sdist]
urllib3 (1.25.7) - Latest: 1.25.9 [wheel]
urwid (1.1.1) - Latest: 2.1.0 [sdist]
xmldiff (2.3) - Latest: 2.4 [wheel]

[arizvisa]

Hey @DmitryKuzmenko, do you think it would be safe to assign the connection globally (in the module) so that it doesn't go out of scope, or is there some way to attach the etcd connection object somewhere so it doesn't get gc'd?

Or do you think that it would just be safer to explicitly call .__del__() when the connection object is done being used so that way client.http can be set to None to avoid hitting that conditional? I feel like tampering with client.http might break whenever upstream issues their fix, but it might be the better than the solution of avoiding garbage collection altogether...

[DmitryKuzmenko]

@arizvisa the connection is already global in the cache module. Maybe that's the issue. We can probably try to move it out of the global scope but this will produce a performance regression. Probably it is worth to try to keep the client in the __context__ dunder.

[DmitryKuzmenko]

@pankajghadge could you try to patch salt on master node where you run salt command with this patch and try to reproduce the issue again?

diff --git a/salt/cache/etcd_cache.py b/salt/cache/etcd_cache.py
index 97d43edd82..da7a33d399 100644
--- a/salt/cache/etcd_cache.py
+++ b/salt/cache/etcd_cache.py
@@ -67,7 +67,7 @@ if HAS_ETCD:
     etcd._log.setLevel(logging.INFO)  # pylint: disable=W0212

 log = logging.getLogger(__name__)
-client = None
+etcd_kwargs = None
 path_prefix = None

 # Module properties
@@ -90,9 +90,10 @@ def __virtual__():
 def _init_client():
     '''Setup client and init datastore.
     '''
-    global client, path_prefix
-    if client is not None:
-        return
+    global etcd_kwargs, path_prefix
+
+    if etcd_kwargs is not None:
+        return etcd.Client(**etcd_kwargs)

     etcd_kwargs = {
             'host': __opts__.get('etcd.host', '127.0.0.1'),
@@ -117,13 +118,14 @@ def _init_client():
     except etcd.EtcdKeyNotFound:
         log.info("etcd: Creating dir %r", path_prefix)
         client.write(path_prefix, None, dir=True)
+    return client

 def store(bank, key, data):
     '''
     Store a key value.
     '''
-    _init_client()
+    client = _init_client()
     etcd_key = '{0}/{1}/{2}'.format(path_prefix, bank, key)
     try:
         value = __context__['serial'].dumps(data)
@@ -138,7 +140,7 @@ def fetch(bank, key):
     '''
     Fetch a key value.
     '''
-    _init_client()
+    client = _init_client()
     etcd_key = '{0}/{1}/{2}'.format(path_prefix, bank, key)
     try:
         value = client.read(etcd_key).value
@@ -157,7 +159,7 @@ def flush(bank, key=None):
     '''
     Remove the key from the cache bank with all the key content.
     '''
-    _init_client()
+    client = _init_client()
     if key is None:
         etcd_key = '{0}/{1}'.format(path_prefix, bank)
     else:
@@ -195,7 +197,7 @@ def ls(bank):
     Return an iterable object containing all entries stored in the specified
     bank.
     '''
-    _init_client()
+    client = _init_client()
     path = '{0}/{1}'.format(path_prefix, bank)
     try:
         return _walk(client.read(path))
@@ -211,7 +213,7 @@ def contains(bank, key):
     '''
     Checks if the specified bank contains the specified key.
     '''
-    _init_client()
+    client = _init_client()
     etcd_key = '{0}/{1}/{2}'.format(path_prefix, bank, key)
     try:
         r = client.read(etcd_key)

[malletp]

Hello @DmitryKuzmenko,

I just applied your patch to a master and that solves the problem. Without the patch:

...
[DEBUG   ] LazyLoaded no_return.output
myminion:
    Minion did not return. [No response]
[DEBUG   ] Closing IPCMessageSubscriber instance
ERROR: Minions returned with non-zero exit code
Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method Client.__del__ of <etcd.client.Client object at 0x7facf457e5d0>> ignored

With the patch:

...
[DEBUG   ] LazyLoaded no_return.output
myminion:
    Minion did not return. [No response]
[DEBUG   ] Closing IPCMessageSubscriber instance
ERROR: Minions returned with non-zero exit code

[DmitryKuzmenko]

@malletp thank you! Just one thing: to test the change I have to fully cover the module with tests =) I'll do it some day.

[pankajghadge]

@DmitryKuzmenko : for this issue : ERROR: Minions returned with non-zero exit code We have 2 processor and 16 GB RAM . Can less CPU be the reason of it? What is the Hardware recommendation for architecture that we showed above ?

Also swap memory is 0 on salt master and minions So we have modified the /etc/sysctl.d/99-salt.conf

cat /etc/sysctl.d/99-salt.conf
#
# Kernel sysctl configuration
#
vm.hugetlb_shm_group = 439
vm.swappiness = 0