search

saltstack / salt

Software to automate the management and configuration of any infrastructure or application at scale. Get access to the Salt software package repository here:
https://repo.saltproject.io/
Apache License 2.0
14.15k stars 5.48k forks source link

[BUG] SaltCacheError 'maximum recursion depth exceeded while calling a Python object' with ETCD cache #57377

Open cerberek opened 4 years ago

cerberek commented 4 years ago

Description A clear and concise description of what the bug is. When calling mine.update I got this error even that it looks that grains are updated properly.

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 855, in wrapper
    params=params, timeout=timeout)
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 923, in api_execute
    preload_content=False)
  File "/usr/lib/python3/dist-packages/urllib3/request.py", line 68, in request
    **urlopen_kw)
  File "/usr/lib/python3/dist-packages/urllib3/request.py", line 89, in request_encode_url
    return self.urlopen(method, url, **extra_kw)
  File "/usr/lib/python3/dist-packages/urllib3/poolmanager.py", line 323, in urlopen
    response = conn.urlopen(method, u.request_uri, **kw)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 384, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 380, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.7/http/client.py", line 1321, in getresponse
    response.begin()
  File "/usr/lib/python3.7/http/client.py", line 320, in begin
    self.headers = self.msg = parse_headers(self.fp)
  File "/usr/lib/python3.7/http/client.py", line 214, in parse_headers
    return email.parser.Parser(_class=_class).parsestr(hstring)
  File "/usr/lib/python3.7/email/parser.py", line 68, in parsestr
    return self.parse(StringIO(text), headersonly=headersonly)
  File "/usr/lib/python3.7/email/parser.py", line 57, in parse
    feedparser.feed(data)
  File "/usr/lib/python3.7/email/feedparser.py", line 176, in feed
    self._call_parse()
  File "/usr/lib/python3.7/email/feedparser.py", line 180, in _call_parse
    self._parse()
  File "/usr/lib/python3.7/email/feedparser.py", line 295, in _parsegen
    if self._cur.get_content_maintype() == 'message':
  File "/usr/lib/python3.7/email/message.py", line 594, in get_content_maintype
    ctype = self.get_content_type()
  File "/usr/lib/python3.7/email/message.py", line 578, in get_content_type
    value = self.get('content-type', missing)
  File "/usr/lib/python3.7/email/message.py", line 471, in get
    return self.policy.header_fetch_parse(k, v)
  File "/usr/lib/python3.7/email/_policybase.py", line 316, in header_fetch_parse
    return self._sanitize_header(name, value)
  File "/usr/lib/python3.7/email/_policybase.py", line 287, in _sanitize_header
    if _has_surrogates(value):
  File "/usr/lib/python3.7/email/utils.py", line 57, in _has_surrogates
    s.encode()
RecursionError: maximum recursion depth exceeded while calling a Python object
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
SaltCacheError: There was an error getting the key "minions": maximum recursion depth exceeded while calling a Python object
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 201, in ls
    return _walk(client.read(path))
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  [Previous line repeated 962 more times]
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 188, in _walk
    for c in client.read(r.key).children:
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 597, in read
    timeout=timeout)
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 855, in wrapper
    params=params, timeout=timeout)
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 923, in api_execute
    preload_content=False)
  File "/usr/lib/python3/dist-packages/urllib3/request.py", line 68, in request
    **urlopen_kw)
  File "/usr/lib/python3/dist-packages/urllib3/request.py", line 89, in request_encode_url
    return self.urlopen(method, url, **extra_kw)
  File "/usr/lib/python3/dist-packages/urllib3/poolmanager.py", line 323, in urlopen
    response = conn.urlopen(method, u.request_uri, **kw)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 384, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 380, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.7/http/client.py", line 1321, in getresponse
    response.begin()
  File "/usr/lib/python3.7/http/client.py", line 320, in begin
    self.headers = self.msg = parse_headers(self.fp)
  File "/usr/lib/python3.7/http/client.py", line 214, in parse_headers
    return email.parser.Parser(_class=_class).parsestr(hstring)
  File "/usr/lib/python3.7/email/parser.py", line 68, in parsestr
    return self.parse(StringIO(text), headersonly=headersonly)
  File "/usr/lib/python3.7/email/parser.py", line 57, in parse
    feedparser.feed(data)
  File "/usr/lib/python3.7/email/feedparser.py", line 176, in feed
    self._call_parse()
  File "/usr/lib/python3.7/email/feedparser.py", line 180, in _call_parse
    self._parse()
  File "/usr/lib/python3.7/email/feedparser.py", line 295, in _parsegen
    if self._cur.get_content_maintype() == 'message':
  File "/usr/lib/python3.7/email/message.py", line 594, in get_content_maintype
    ctype = self.get_content_type()
  File "/usr/lib/python3.7/email/message.py", line 578, in get_content_type
    value = self.get('content-type', missing)
  File "/usr/lib/python3.7/email/message.py", line 471, in get
    return self.policy.header_fetch_parse(k, v)
  File "/usr/lib/python3.7/email/_policybase.py", line 316, in header_fetch_parse
    return self._sanitize_header(name, value)
  File "/usr/lib/python3.7/email/_policybase.py", line 287, in _sanitize_header
    if _has_surrogates(value):
  File "/usr/lib/python3.7/email/utils.py", line 57, in _has_surrogates
    s.encode()
RecursionError: maximum recursion depth exceeded while calling a Python object

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/salt", line 10, in <module>
    salt_main()
  File "/usr/lib/python3/dist-packages/salt/scripts.py", line 516, in salt_main
    client.run()
  File "/usr/lib/python3/dist-packages/salt/cli/salt.py", line 194, in run
    for full_ret in cmd_func(**kwargs):
  File "/usr/lib/python3/dist-packages/salt/client/__init__.py", line 780, in cmd_cli
    **kwargs):
  File "/usr/lib/python3/dist-packages/salt/client/__init__.py", line 1542, in get_cli_event_returns
    connected_minions = salt.utils.minions.CkMinions(self.opts).connected_ids()
  File "/usr/lib/python3/dist-packages/salt/utils/minions.py", line 652, in connected_ids
    search = self.cache.list('minions')
  File "/usr/lib/python3/dist-packages/salt/cache/__init__.py", line 244, in list
    return self.modules[fun](bank, **self._kwargs)
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 205, in ls
    bank, exc
salt.exceptions.SaltCacheError: There was an error getting the key "minions": maximum recursion depth exceeded while calling a Python object
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 201, in ls
    return _walk(client.read(path))
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  [Previous line repeated 962 more times]
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 188, in _walk
    for c in client.read(r.key).children:
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 597, in read
    timeout=timeout)
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 855, in wrapper
    params=params, timeout=timeout)
  File "/usr/local/lib/python3.7/dist-packages/etcd/client.py", line 923, in api_execute
    preload_content=False)
  File "/usr/lib/python3/dist-packages/urllib3/request.py", line 68, in request
    **urlopen_kw)
  File "/usr/lib/python3/dist-packages/urllib3/request.py", line 89, in request_encode_url
    return self.urlopen(method, url, **extra_kw)
  File "/usr/lib/python3/dist-packages/urllib3/poolmanager.py", line 323, in urlopen
    response = conn.urlopen(method, u.request_uri, **kw)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 384, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 380, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.7/http/client.py", line 1321, in getresponse
    response.begin()
  File "/usr/lib/python3.7/http/client.py", line 320, in begin
    self.headers = self.msg = parse_headers(self.fp)
  File "/usr/lib/python3.7/http/client.py", line 214, in parse_headers
    return email.parser.Parser(_class=_class).parsestr(hstring)
  File "/usr/lib/python3.7/email/parser.py", line 68, in parsestr
    return self.parse(StringIO(text), headersonly=headersonly)
  File "/usr/lib/python3.7/email/parser.py", line 57, in parse
    feedparser.feed(data)
  File "/usr/lib/python3.7/email/feedparser.py", line 176, in feed
    self._call_parse()
  File "/usr/lib/python3.7/email/feedparser.py", line 180, in _call_parse
    self._parse()
  File "/usr/lib/python3.7/email/feedparser.py", line 295, in _parsegen
    if self._cur.get_content_maintype() == 'message':
  File "/usr/lib/python3.7/email/message.py", line 594, in get_content_maintype
    ctype = self.get_content_type()
  File "/usr/lib/python3.7/email/message.py", line 578, in get_content_type
    value = self.get('content-type', missing)
  File "/usr/lib/python3.7/email/message.py", line 471, in get
    return self.policy.header_fetch_parse(k, v)
  File "/usr/lib/python3.7/email/_policybase.py", line 316, in header_fetch_parse
    return self._sanitize_header(name, value)
  File "/usr/lib/python3.7/email/_policybase.py", line 287, in _sanitize_header
    if _has_surrogates(value):
  File "/usr/lib/python3.7/email/utils.py", line 57, in _has_surrogates
    s.encode()
RecursionError: maximum recursion depth exceeded while calling a Python object

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/salt", line 10, in <module>
    salt_main()
  File "/usr/lib/python3/dist-packages/salt/scripts.py", line 516, in salt_main
    client.run()
  File "/usr/lib/python3/dist-packages/salt/cli/salt.py", line 194, in run
    for full_ret in cmd_func(**kwargs):
  File "/usr/lib/python3/dist-packages/salt/client/__init__.py", line 780, in cmd_cli
    **kwargs):
  File "/usr/lib/python3/dist-packages/salt/client/__init__.py", line 1542, in get_cli_event_returns
    connected_minions = salt.utils.minions.CkMinions(self.opts).connected_ids()
  File "/usr/lib/python3/dist-packages/salt/utils/minions.py", line 652, in connected_ids
    search = self.cache.list('minions')
  File "/usr/lib/python3/dist-packages/salt/cache/__init__.py", line 244, in list
    return self.modules[fun](bank, **self._kwargs)
  File "/usr/lib/python3/dist-packages/salt/cache/etcd_cache.py", line 205, in ls
    bank, exc
salt.exceptions.SaltCacheError: There was an error getting the key "minions": maximum recursion depth exceeded while calling a Python object

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

etcd.host: 10.120.0.1 etcd.port: 2379 etcd.protocol: http etcd.allow_reconnect: True etcd.allow_redirect: False etcd.read_timeout: 60 etcd.username: None etcd.password: None etcd.cert: None etcd.ca_cert: None cache: etcd

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

Expected behavior A clear and concise description of what you expected to happen.

No errors

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 Version: Salt: 2019.2.4 Dependency Versions: cffi: Not Installed cherrypy: Not Installed dateutil: 2.7.3 docker-py: Not Installed gitdb: 2.0.5 gitpython: 2.1.11 ioflo: Not Installed Jinja2: 2.10 libgit2: Not Installed libnacl: Not Installed M2Crypto: Not Installed Mako: Not Installed msgpack-pure: Not Installed msgpack-python: 0.5.6 mysql-python: Not Installed pycparser: Not Installed pycrypto: 2.6.1 pycryptodome: Not Installed pygit2: Not Installed Python: 3.7.3 (default, Apr 3 2019, 05:39:12) python-gnupg: Not Installed PyYAML: 3.13 PyZMQ: 17.1.2 RAET: Not Installed smmap: 2.0.5 timelib: Not Installed Tornado: 4.5.3 ZMQ: 4.3.1 System Versions: dist: debian 10.0 locale: UTF-8 machine: x86_64 release: 4.19.0-5-amd64 system: Linux version: debian 10.0 ```

Additional context Add any other context about the problem here.

garethgreenaway commented 4 years ago

@cerberek Thanks for the report. The above errors look similar to this other issue, https://github.com/saltstack/salt/issues/37646, which has a fix (https://github.com/saltstack/salt/pull/54018) that will be in the upcoming Sodium release. Are you in a position where you're able to test that fix?

cerberek commented 4 years ago

I did upgrade to new version, but I'm getting still same errors

           Salt: 2019.2.5

Dependency Versions:
           cffi: Not Installed
       cherrypy: Not Installed
       dateutil: 2.7.3
      docker-py: Not Installed
          gitdb: 2.0.5
      gitpython: 2.1.11
          ioflo: Not Installed
         Jinja2: 2.10
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.5.6
   mysql-python: Not Installed
      pycparser: Not Installed
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: Not Installed
         Python: 3.7.3 (default, Apr  3 2019, 05:39:12)
   python-gnupg: Not Installed
         PyYAML: 3.13
          PyZMQ: 17.1.2
           RAET: Not Installed
          smmap: 2.0.5
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.3.1

System Versions:
           dist: debian 10.0 
         locale: UTF-8
        machine: x86_64
        release: 4.19.0-5-amd64
         system: Linux
        version: debian 10.0
ggiesen commented 2 years ago

I'm also hitting this on 3004.1 while running a grains.ls on the esxi proxy minion (direct, not through vSphere):

# salt hv01 grains.ls -l debug
[INFO    ] Loading Saltfile from '/root/.salt/Saltfile'
[DEBUG   ] Reading configuration from /root/.salt/Saltfile
[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/api.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/api.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/auth.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/auth.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/cache_etcd.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/cache_etcd.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_recv.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_recv.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_roots.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_roots.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/ipv6.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/ipv6.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_atlassian.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_atlassian.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_office365.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_office365.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/reactor.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/reactor.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/returner.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/returner.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/sdb.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/sdb.conf
[DEBUG   ] Using importlib_metadata to load entry points
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] Missing configuration file: /root/.saltrc
[DEBUG   ] Override  __grains__: <module 'salt.loaded.int.log_handlers.sentry_mod' from '/usr/lib/python3.6/site-packages/salt/log/handlers/sentry_mod.py'>
[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/api.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/api.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/auth.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/auth.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/cache_etcd.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/cache_etcd.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_recv.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_recv.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_roots.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_roots.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/ipv6.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/ipv6.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_atlassian.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_atlassian.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_office365.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_office365.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/reactor.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/reactor.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/returner.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/returner.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/sdb.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/sdb.conf
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] Using importlib_metadata to load entry points
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[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   ] Connecting the Minion to the Master URI (for the return server): tcp://[::]:4506
[DEBUG   ] Trying to connect to: tcp://[::]:4506
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] LazyLoaded postgres.get_load
[DEBUG   ] LazyLoaded config.option
[DEBUG   ] get_iter_returns for jid 20220426092345505179 sent to {'hv01'} will timeout at 09:23:50.571445
[DEBUG   ] Checking whether jid 20220426092345505179 is still running
[DEBUG   ] Connecting the Minion to the Master URI (for the return server): tcp://[::]:4506
[DEBUG   ] Trying to connect to: tcp://[::]:4506
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] retcode missing from client return
[DEBUG   ] return event: {'hv01': {'failed': True}}
[DEBUG   ] Using importlib_metadata to load entry points
[DEBUG   ] Could not LazyLoad etcd.init_kwargs: 'etcd.init_kwargs' is not available.
[INFO    ] etcd: Setting up client with params: {'host': '[2001:db8::11]', 'port': 2379, 'protocol': 'http', 'allow_reconnect': True, 'allow_redirect': False, 'srv_domain': 'None', 'read_timeout': 60, 'username': 'None', 'password': 'None', 'cert': 'None', 'ca_cert': 'None'}
[ERROR   ] Could not discover the etcd hosts from None: None of DNS query names exist: _etcd._tcp.None., _etcd._tcp.None.example.com.
[DEBUG   ] Starting new HTTP connection (1): 2001:db8::11:2379
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/machines HTTP/1.1" 200 106
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache HTTP/1.1" 200 194
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions HTTP/1.1" 200 1272
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions HTTP/1.1" 200 1272
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions/otherminion01 HTTP/1.1" 200 116
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions/otherminion01 HTTP/1.1" 200 116
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions/otherminion01 HTTP/1.1" 200 116
.. <Repeats 945 times>
[DEBUG   ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions/otherminion01 HTTP/1.1" 200 116
[ERROR   ] Unexpected request failure, re-raising.
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 855, in wrapper
    params=params, timeout=timeout)
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 923, in api_execute
    preload_content=False)
  File "/usr/lib/python3.6/site-packages/urllib3/request.py", line 68, in request
    **urlopen_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/request.py", line 89, in request_encode_url
    return self.urlopen(method, url, **extra_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/poolmanager.py", line 324, in urlopen
    response = conn.urlopen(method, u.request_uri, **kw)
  File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 393, in _make_request
    httplib_response.length)
  File "/usr/lib64/python3.6/logging/__init__.py", line 1296, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 298, in _log
    stack_info=stack_info,
  File "/usr/lib64/python3.6/logging/__init__.py", line 1443, in _log
    exc_info, func, extra, sinfo)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 368, in makeRecord
    self, name, level, fn, lno, _msg, _args, exc_info, func, sinfo
  File "/usr/lib64/python3.6/logging/__init__.py", line 1413, in makeRecord
    sinfo)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 129, in __init__
    SaltLogRecord.__init__(self, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 121, in __init__
    logging.LogRecord.__init__(self, *args, **kwargs)
  File "/usr/lib64/python3.6/logging/__init__.py", line 286, in __init__
    self.module = os.path.splitext(self.filename)[0]
  File "/usr/lib64/python3.6/posixpath.py", line 129, in splitext
    return genericpath._splitext(p, sep, None, extsep)
  File "/usr/lib64/python3.6/genericpath.py", line 130, in _splitext
    if dotIndex > sepIndex:
RecursionError: maximum recursion depth exceeded in comparison
[DEBUG   ] Closing IPCMessageSubscriber instance
[ERROR   ] An un-handled exception was caught by salt's global exception handler:
SaltCacheError: There was an error getting the key "minions": maximum recursion depth exceeded in comparison
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 201, in ls
    return _walk(client.read(path))
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  [Previous line repeated 943 more times]
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 188, in _walk
    for c in client.read(r.key).children:
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 597, in read
    timeout=timeout)
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 855, in wrapper
    params=params, timeout=timeout)
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 923, in api_execute
    preload_content=False)
  File "/usr/lib/python3.6/site-packages/urllib3/request.py", line 68, in request
    **urlopen_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/request.py", line 89, in request_encode_url
    return self.urlopen(method, url, **extra_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/poolmanager.py", line 324, in urlopen
    response = conn.urlopen(method, u.request_uri, **kw)
  File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 393, in _make_request
    httplib_response.length)
  File "/usr/lib64/python3.6/logging/__init__.py", line 1296, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 298, in _log
    stack_info=stack_info,
  File "/usr/lib64/python3.6/logging/__init__.py", line 1443, in _log
    exc_info, func, extra, sinfo)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 368, in makeRecord
    self, name, level, fn, lno, _msg, _args, exc_info, func, sinfo
  File "/usr/lib64/python3.6/logging/__init__.py", line 1413, in makeRecord
    sinfo)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 129, in __init__
    SaltLogRecord.__init__(self, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 121, in __init__
    logging.LogRecord.__init__(self, *args, **kwargs)
  File "/usr/lib64/python3.6/logging/__init__.py", line 286, in __init__
    self.module = os.path.splitext(self.filename)[0]
  File "/usr/lib64/python3.6/posixpath.py", line 129, in splitext
    return genericpath._splitext(p, sep, None, extsep)
  File "/usr/lib64/python3.6/genericpath.py", line 130, in _splitext
    if dotIndex > sepIndex:
RecursionError: maximum recursion depth exceeded in comparison

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/bin/salt", line 11, in <module>
    load_entry_point('salt==3004.1', 'console_scripts', 'salt')()
  File "/usr/lib/python3.6/site-packages/salt/scripts.py", line 521, in salt_main
    client.run()
  File "/usr/lib/python3.6/site-packages/salt/cli/salt.py", line 200, in run
    for full_ret in cmd_func(**kwargs):
  File "/usr/lib/python3.6/site-packages/salt/client/__init__.py", line 841, in cmd_cli
    **kwargs
  File "/usr/lib/python3.6/site-packages/salt/client/__init__.py", line 1673, in get_cli_event_returns
    self.opts
  File "/usr/lib/python3.6/site-packages/salt/utils/minions.py", line 633, in connected_ids
    search = self.cache.list("minions")
  File "/usr/lib/python3.6/site-packages/salt/cache/__init__.py", line 233, in list
    return self.modules[fun](bank, **self._kwargs)
  File "/usr/lib/python3.6/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/loader/lazy.py", line 1201, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/contextvars/__init__.py", line 38, in run
    return callable(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/loader/lazy.py", line 1216, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 204, in ls
    'There was an error getting the key "{}": {}'.format(bank, exc)
salt.exceptions.SaltCacheError: There was an error getting the key "minions": maximum recursion depth exceeded in comparison
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 201, in ls
    return _walk(client.read(path))
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 189, in _walk
    keys.extend(_walk(c))
  [Previous line repeated 943 more times]
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 188, in _walk
    for c in client.read(r.key).children:
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 597, in read
    timeout=timeout)
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 855, in wrapper
    params=params, timeout=timeout)
  File "/usr/lib/python3.6/site-packages/etcd/client.py", line 923, in api_execute
    preload_content=False)
  File "/usr/lib/python3.6/site-packages/urllib3/request.py", line 68, in request
    **urlopen_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/request.py", line 89, in request_encode_url
    return self.urlopen(method, url, **extra_kw)
  File "/usr/lib/python3.6/site-packages/urllib3/poolmanager.py", line 324, in urlopen
    response = conn.urlopen(method, u.request_uri, **kw)
  File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/usr/lib/python3.6/site-packages/urllib3/connectionpool.py", line 393, in _make_request
    httplib_response.length)
  File "/usr/lib64/python3.6/logging/__init__.py", line 1296, in debug
    self._log(DEBUG, msg, args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 298, in _log
    stack_info=stack_info,
  File "/usr/lib64/python3.6/logging/__init__.py", line 1443, in _log
    exc_info, func, extra, sinfo)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 368, in makeRecord
    self, name, level, fn, lno, _msg, _args, exc_info, func, sinfo
  File "/usr/lib64/python3.6/logging/__init__.py", line 1413, in makeRecord
    sinfo)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 129, in __init__
    SaltLogRecord.__init__(self, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/_logging/impl.py", line 121, in __init__
    logging.LogRecord.__init__(self, *args, **kwargs)
  File "/usr/lib64/python3.6/logging/__init__.py", line 286, in __init__
    self.module = os.path.splitext(self.filename)[0]
  File "/usr/lib64/python3.6/posixpath.py", line 129, in splitext
    return genericpath._splitext(p, sep, None, extsep)
  File "/usr/lib64/python3.6/genericpath.py", line 130, in _splitext
    if dotIndex > sepIndex:
RecursionError: maximum recursion depth exceeded in comparison

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/bin/salt", line 11, in <module>
    load_entry_point('salt==3004.1', 'console_scripts', 'salt')()
  File "/usr/lib/python3.6/site-packages/salt/scripts.py", line 521, in salt_main
    client.run()
  File "/usr/lib/python3.6/site-packages/salt/cli/salt.py", line 200, in run
    for full_ret in cmd_func(**kwargs):
  File "/usr/lib/python3.6/site-packages/salt/client/__init__.py", line 841, in cmd_cli
    **kwargs
  File "/usr/lib/python3.6/site-packages/salt/client/__init__.py", line 1673, in get_cli_event_returns
    self.opts
  File "/usr/lib/python3.6/site-packages/salt/utils/minions.py", line 633, in connected_ids
    search = self.cache.list("minions")
  File "/usr/lib/python3.6/site-packages/salt/cache/__init__.py", line 233, in list
    return self.modules[fun](bank, **self._kwargs)
  File "/usr/lib/python3.6/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/loader/lazy.py", line 1201, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/contextvars/__init__.py", line 38, in run
    return callable(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/loader/lazy.py", line 1216, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/cache/etcd_cache.py", line 204, in ls
    'There was an error getting the key "{}": {}'.format(bank, exc)
salt.exceptions.SaltCacheError: There was an error getting the key "minions": maximum recursion depth exceeded in comparison

The name of the minion varies from run-to-run in:

[DEBUG ] http://2001:db8::11:2379 "GET /v2/keys/salt_cache/minions/otherminion01 HTTP/1.1" 200 116

but is not the name of the proxy minion I'm running grains.ls on.

Occasionally it will be successful:

# salt hv01 grains.ls -l debug
[INFO    ] Loading Saltfile from '/root/.salt/Saltfile'
[DEBUG   ] Reading configuration from /root/.salt/Saltfile
[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/api.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/api.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/auth.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/auth.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/cache_etcd.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/cache_etcd.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_recv.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_recv.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_roots.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_roots.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/ipv6.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/ipv6.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_atlassian.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_atlassian.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_office365.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_office365.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/reactor.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/reactor.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/returner.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/returner.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/sdb.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/sdb.conf
[DEBUG   ] Using importlib_metadata to load entry points
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] Using importlib_metadata to load entry points
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] Missing configuration file: /root/.saltrc
[DEBUG   ] Override  __grains__: <module 'salt.loaded.int.log_handlers.sentry_mod' from '/usr/lib/python3.6/site-packages/salt/log/handlers/sentry_mod.py'>
[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/api.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/api.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/auth.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/auth.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/cache_etcd.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/cache_etcd.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_recv.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_recv.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/file_roots.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/file_roots.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/ipv6.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/ipv6.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_atlassian.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_atlassian.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/pillar_office365.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/pillar_office365.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/reactor.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/reactor.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/returner.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/returner.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/sdb.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/sdb.conf
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[DEBUG   ] LazyLoaded yaml.get
[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   ] Connecting the Minion to the Master URI (for the return server): tcp://[::]:4506
[DEBUG   ] Trying to connect to: tcp://[::]:4506
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] LazyLoaded postgres.get_load
[DEBUG   ] LazyLoaded config.option
[DEBUG   ] get_iter_returns for jid 20220426092255728543 sent to {'hv01'} will timeout at 09:23:00.829379
[DEBUG   ] Checking whether jid 20220426092255728543 is still running
[DEBUG   ] Connecting the Minion to the Master URI (for the return server): tcp://[::]:4506
[DEBUG   ] Trying to connect to: tcp://[::]:4506
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] retcode missing from client return
[DEBUG   ] jid 20220426092255728543 return from hv01
[DEBUG   ] return event: {'hv01': {'ret': ['apiType', 'apiVersion', 'biosreleasedate', 'biosversion', 'build', 'cpu_model', 'cpuarch', 
'cwd', 'dns', 'domain', 'dynamicProperty', 'dynamicType', 'efi', 'efi-secure-boot', 'fqdn', 'fqdns', 'fullName', 'gpus', 'host', 'hwaddr_interfaces', 'id', 'instanceUuid', 'ip4_gw', 'ip4_interfaces', 'ip6_gw', 'ip6_interfaces', 'ip_gw', 'ip_interfaces', 'kernel', 'kernelparams', 
'kernelrelease', 'kernelversion', 'licenseProductName', 'licenseProductVersion', 'localeBuild', 'localeVersion', 'locale_info', 'machine_id', 'manufacturer', 'master', 'mem_total', 'name', 'nodename', 'num_cpu_cores', 'num_cpu_sockets', 'num_cpus', 'num_gpus', 'os', 'osType', 'os_family', 'osarch', 'osbuild', 'osfinger', 'osfullname', 'osmanufacturer', 'osrelease', 'osrelease_info', 'patchLevel', 'path', 'productLineId', 'productname', 'ps', 'pythonexecutable', 'pythonpath', 'pythonversion', 'saltpath', 'saltversion', 'saltversioninfo', 'serialnumber', 'shell', 'systempath', 'timezone', 'transactional', 'vendor', 'version', 'virtual', 'zmqversion'], 'retcode': 0, 'jid': '20220426092255728543'}}
[DEBUG   ] Using importlib_metadata to load entry points
[DEBUG   ] LazyLoaded nested.output
hv01:
    - apiType
    - apiVersion
    - biosreleasedate
    - biosversion
    - build
    - cpu_model
    - cpuarch
    - cwd
    - dns
    - domain
    - dynamicProperty
    - dynamicType
    - efi
    - efi-secure-boot
    - fqdn
    - fqdns
    - fullName
    - gpus
    - host
    - hwaddr_interfaces
    - id
    - instanceUuid
    - ip4_gw
    - ip4_interfaces
    - ip6_gw
    - ip6_interfaces
    - ip_gw
    - ip_interfaces
    - kernel
    - kernelparams
    - kernelrelease
    - kernelversion
    - licenseProductName
    - licenseProductVersion
    - localeBuild
    - localeVersion
    - locale_info
    - machine_id
    - manufacturer
    - master
    - mem_total
    - name
    - nodename
    - num_cpu_cores
    - num_cpu_sockets
    - num_cpus
    - num_gpus
    - os
    - osType
    - os_family
    - osarch
    - osbuild
    - osfinger
    - osfullname
    - osmanufacturer
    - osrelease
    - osrelease_info
    - patchLevel
    - path
    - productLineId
    - productname
    - ps
    - pythonexecutable
    - pythonpath
    - pythonversion
    - saltpath
    - saltversion
    - saltversioninfo
    - serialnumber
    - shell
    - systempath
    - timezone
    - transactional
    - vendor
    - version
    - virtual
    - zmqversion
[DEBUG   ] jid 20220426092255728543 found all minions {'hv01'}
[DEBUG   ] Closing IPCMessageSubscriber instance
ggiesen commented 2 years ago

I've been able to determine the issue occurs, at least my case, if there is no cached data for at least one minion in etcd, ie. ETCDCTL_API=2 etcdctl ls /salt_cache/minions/otherminion01 returns nothing (the data key doesn't exist)

If I restart all the minions which have missing data keys, or manually create empty keys (ie. echo "" | ETCDCTL_API=2 etcdctl set /salt_cache/minions/otherminion01/data) so that ETCDCTL_API=2 etcdctl ls /salt_cache/minions/otherminion01 returns /salt_cache/minions/otherminion01/data) then I no longer encounter this.

The issue is somewhere in this block of code:

https://github.com/saltstack/salt/blob/98cd52d79b6947925566ec967f509a4077ea58ea/salt/cache/etcd_cache.py#L192-L223

ggiesen commented 1 year ago

I believe I have found both the issue and at the fix.

Per https://github.com/jplana/python-etcd/issues/54, the client.children method returns itself if it's empty, causing the _walk function to keep recursing over the same key until it exceeds maximum recursion depth.

A simple check to see if the child is the same as the key we're checking fixes this. If we insert the following code between lines 204 and 205 (https://github.com/saltstack/salt/blob/98cd52d79b6947925566ec967f509a4077ea58ea/salt/cache/etcd_cache.py#L204-L205)

        if c.key == r.key:
            log.debug('Empty folder found: "%s"', r.key)
            break

It seems to solve the issue.