saltstack / saltstack/salt

[BUG] un-handled exception ProcessPayload .iostream.StreamClosedError: Stream is closed

Open
#64,631 9 comments 0 reactions 1 assignee View on GitHub

@dwoz is already working on this.

Since Jul 24, 2023.

bug needs-more-info needs-triage Proxy-Minion
Dominant language
Python
Stars
15.7k
Forks
5.6k
Avg merge
2d 44m
Merged PRs (30d)
80

Description

Description
Hi, I have an issue running long running salt minion jobs via salt-nornir, not sure if its a timeout issue and I need to tune some settings or if its a bug...

Setup
master

`default_include: master.d/*.conf

interface: 0.0.0.0
transport: tcp
pki_dir: /var/cache/salt/pki/master
timeout: 600
gather_job_timeout: 600
sock_pool_size: 15
worker_threads: 64
show_timeout: True
max_open_files: 100000
ext_pillar_first: False
#ext_pillar_first: True
grains_cache: False
top_file_merging_strategy: merge_all
#user: kmx
auto_accept: True`

proxy minion

default_include: proxy.d/*.conf

master: salt-master
multiprocessing: true
pki_dir: /var/cache/salt/pki/proxy
transport: tcp
max_open_files: 95000
timeout: 60
#user: kmx

Proxy config

proxy:
  proxytype: nornir
  multiprocessing: True
  process_max_count: 3
  proxy_always_alive: False
  connections_idle_timeout: 1
  watchdog_interval: 30
  child_process_max_age: 660
  job_wait_timeout: 600
  memory_threshold_mbyte: 1800
  memory_threshold_action: log
  files_max_count: 20
  event_progress_all: True
  pillar_source_merging_strategy: recurse
  pillar_merge_lists: True
  nornir_workers: 3
  runner:
     plugin: RetryRunner
     options:
        num_workers: 50
        num_connectors: 30
        connect_retry: 3
        connect_backoff: 500
        connect_splay: 100
        task_retry: 3
        task_backoff: 500
        task_splay: 100
        reconnect_on_fail: True
        task_timeout: 600

Please be as specific as possible and give set-up details.

  • [* ] on-prem machine
  • [* ] Master and Proxy Minion both are containers running inside a VM with own docker bridge. 6 vcpu 12GB ram
  • [* ] containers (Docker)
  • [* ] combination see above
  • classic packaging
  • onedir packaging
  • used bootstrap to install

Steps to Reproduce the behavior
Running the job from rundeck and never get any job output (even though the job completes / succeeds)

Logs

** master logs **

nrp1:
    Minion did not return. [No response]
    The minions may not have all finished running and any remaining minions will return upon completion. To look up the return data for this job later, run the following command:

** View from Minion logs (docker logs of proxy minion) **

[INFO    ] Executing state module.run for [final_flush]
[INFO    ] {'nr.nornir': {'nornir-worker-2': True, 'nornir-worker-1': True, 'nornir-worker-3': True}}
[INFO    ] Completed state [final_flush] at time 10:41:30.582569 (duration_in_ms=302.481)
[INFO    ] Returning information for job: 20230713103611835557
[ERROR   ] An un-handled exception from the multiprocessing process 'ProcessPayload(jid=20230713103611835557)' was caught:
Traceback (most recent call last):
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/process.py", line 993, in wrapped_run_func
    return run_func()
  File "/usr/local/lib/python3.9/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 3869, in _target
    return mp_call(cls, minion_instance, opts, data, connected)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/metaproxy/proxy.py", line 387, in target
    ProxyMinion._thread_return(minion_instance, opts, data)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 3874, in _thread_return
    return mp_call(cls, minion_instance, opts, data)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/metaproxy/proxy.py", line 593, in thread_return
    minion_instance._return_pub(ret, timeout=minion_instance._return_retry_timer())
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 2251, in _return_pub
    ret_val = self._send_req_sync(load, timeout=timeout)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 1609, in _send_req_sync
    return event.fire_event(
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/event.py", line 835, in fire_event
    self.pusher.send(msg)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/asynchronous.py", line 125, in wrap
    raise exc_info[1].with_traceback(exc_info[2])
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/asynchronous.py", line 131, in _target
    result = io_loop.run_sync(lambda: getattr(self.obj, key)(*args, **kwargs))
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/ioloop.py", line 459, in run_sync
    return future_cell[0].result()
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/concurrent.py", line 249, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/gen.py", line 1070, in run
    yielded = self.gen.send(value)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/transport/ipc.py", line 455, in send
    yield self.stream.write(pack)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/iostream.py", line 388, in write
    self._check_closed()
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/iostream.py", line 926, in _check_closed
    raise StreamClosedError(real_error=self.error)
salt.ext.tornado.iostream.StreamClosedError: Stream is closed
Process ProcessPayload(jid=20230713103611835557):
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/process.py", line 993, in wrapped_run_func
    return run_func()
  File "/usr/local/lib/python3.9/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 3869, in _target
    return mp_call(cls, minion_instance, opts, data, connected)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/metaproxy/proxy.py", line 387, in target
    ProxyMinion._thread_return(minion_instance, opts, data)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 3874, in _thread_return
    return mp_call(cls, minion_instance, opts, data)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/metaproxy/proxy.py", line 593, in thread_return
    minion_instance._return_pub(ret, timeout=minion_instance._return_retry_timer())
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 2251, in _return_pub
    ret_val = self._send_req_sync(load, timeout=timeout)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/minion.py", line 1609, in _send_req_sync
    return event.fire_event(
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/event.py", line 835, in fire_event
    self.pusher.send(msg)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/asynchronous.py", line 125, in wrap
    raise exc_info[1].with_traceback(exc_info[2])
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/utils/asynchronous.py", line 131, in _target
    result = io_loop.run_sync(lambda: getattr(self.obj, key)(*args, **kwargs))
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/ioloop.py", line 459, in run_sync
    return future_cell[0].result()
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/concurrent.py", line 249, in result
    raise_exc_info(self._exc_info)
  File "<string>", line 4, in raise_exc_info
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/gen.py", line 1070, in run
    yielded = self.gen.send(value)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/transport/ipc.py", line 455, in send
    yield self.stream.write(pack)
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/iostream.py", line 388, in write
    self._check_closed()
  File "/home/kmx/.venv/lib/python3.9/site-packages/salt/ext/tornado/iostream.py", line 926, in _check_closed
    raise StreamClosedError(real_error=self.error)
salt.ext.tornado.iostream.StreamClosedError: Stream is closed
[INFO    ] fire_master failed: master could not be contacted. Request timed out.

Expected behavior
Job should complete and master gets the JID output from proxy minion.

Versions Report

Salt Version:
          Salt: 3006.1

Python Version:
        Python: 3.9.13 (main, Aug 23 2022, 09:07:44)

Dependency Versions:
          cffi: 1.15.1
      cherrypy: unknown
      dateutil: 2.8.2
     docker-py: Not Installed
         gitdb: 4.0.10
     gitpython: 3.1.18
        Jinja2: 3.1.2
       libgit2: Not Installed
  looseversion: 1.2.0
      M2Crypto: Not Installed
          Mako: Not Installed
       msgpack: 1.0.5
  msgpack-pure: Not Installed
  mysql-python: Not Installed
     packaging: 23.1
     pycparser: 2.21
      pycrypto: Not Installed
  pycryptodome: 3.18.0
        pygit2: Not Installed
  python-gnupg: 2.3.1
        PyYAML: 5.4.1
         PyZMQ: 25.1.0
        relenv: Not Installed
         smmap: 5.0.0
       timelib: Not Installed
       Tornado: 4.5.3
           ZMQ: 4.3.4

Salt Extensions:
   salt-nornir: 0.19.4

System Versions:
          dist: debian 11.4 bullseye
        locale: utf-8
       machine: x86_64
       release: 5.15.90.1-microsoft-standard-WSL2
        system: Linux
       version: Debian GNU/Linux 11.4 bullseye</summary>

(Provided by running salt --versions-report. Please also mention any differences in master/minion versions.)

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.