Skip to content

[BUG] SaltStack hangs when starting php-fpm 8.1.11 on FreeBSD and Ubuntu #62891

New issue
New issue
Closed
Closed
[BUG] SaltStack hangs when starting php-fpm 8.1.11 on FreeBSD and Ubuntu#62891
Labels
Upstream-Bugis a result of an upstream issue, not in saltbugbroken, incorrect, or confusing behaviordependencyunderlying Salt dependency issueneeds-triage
@bgdnlp

Description

@bgdnlp
bgdnlp
opened on Oct 14, 2022

Description
I am completely lost here, I have no idea what's going on. When running

salt-call cmd.run '/usr/local/sbin/php-fpm'

SaltStack simply hangs.

The most visible effect is that I can no longer install PHP 8.1 or 8.0 with Salt, because SaltStack won't continue past the point where it runs service php-fpm onestart.

The php-fpm process does start, but SaltStack hangs on

self.stdout, self.stderr = self.process.communicate(input=self.stdin)

from timed_subprocess.py

I am on FreeBSD 13.1 and this happens with PHP 8.0.24 and 8.1.11, it does NOT happen with php 7.4.32. Also, it only happens in SaltStack, if I run subprocess.Popen(['/usr/local/sbin/php-fpm']) manually in Python I see no issues.

I modified timed_subprocess.py to print vars(self.process) just before communicate().

For PHP 7.4 (which works) I see:

{'_waitpid_lock': <unlocked _thread.lock object at 0x804a3c900>, '_input': None, '_communication_started': False, 'args': '/usr/local/sbin/php-fpm', 'stdin': None, 'stdout': <_io.BufferedReader name=13>, 'stderr': None, 'pid': 39788, 'returncode': None, 'encoding': None, 'errors': None, 'text_mode': None, '_sigint_wait_secs': 0.25, '_closed_child_pipe_fds': True, '_child_created': True}

For PHP 8.1 (which hangs) I see:

{'_waitpid_lock': <unlocked _thread.lock object at 0x804a3e930>, '_input': None, '_communication_started': False, 'args': '/usr/local/sbin/php-fpm', 'stdin': None, 'stdout': <_io.BufferedReader name=13>, 'stderr': None, 'pid': 40231, 'returncode': None, 'encoding': None, 'errors': None, 'text_mode': None, '_sigint_wait_secs': 0.25, '_closed_child_pipe_fds': True, '_child_created': True}

Aside from process IDs they are identical. I don't know what else to look at. I don't fully understand the code around running a process in Salt, but as I said, I can't replicate manually in Python.

Setup

  • on-prem machine
  • VM (EC2 on AWS)
  • VM running in AWS, EC2 instance
  • container (Kubernetes, Docker, containerd, etc. please specify)
  • or a combination, please be explicit
  • jails if it is FreeBSD
  • FreeBSD package from latest repository
  • onedir packaging
  • used bootstrap to install

Steps to Reproduce the behavior
I added a timeout=5 to self.stdout, self.stderr = self.process.communicate(input=self.stdin, timeout=5) and called salt-call -l all:

(...)
[DEBUG   ] salt.crypt.verify_signature: Verifying signature
[DEBUG   ] Closing AsyncReqChannel instance
[DEBUG   ] The functions from module 'jinja' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] The functions from module 'yaml' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded yaml.render
[TRACE   ] Loaded cmdmod as virtual cmd
[DEBUG   ] The functions from module 'cmd' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded cmd.run
[DEBUG   ] The functions from module 'direct_call' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded direct_call.execute
[DEBUG   ] The functions from module 'config' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded config.get
[INFO    ] Executing command '/usr/local/sbin/php-fpm' in directory '/root'
[ERROR   ] An un-handled exception was caught by Salt's global exception handler:                                                                                                                                                                                                                                                                                                                                                                                                                                                                         [46/1920]
TimeoutExpired: Command '/usr/local/sbin/php-fpm' timed out after 5 seconds
Traceback (most recent call last):
  File "/usr/local/bin/salt-call", line 33, in <module>
    sys.exit(load_entry_point('salt==3005', 'console_scripts', 'salt-call')())
  File "/usr/local/lib/python3.9/site-packages/salt/scripts.py", line 441, in salt_call
    client.run()
  File "/usr/local/lib/python3.9/site-packages/salt/cli/call.py", line 50, in run
    caller.run()
  File "/usr/local/lib/python3.9/site-packages/salt/cli/caller.py", line 95, in run
    ret = self.call()
  File "/usr/local/lib/python3.9/site-packages/salt/cli/caller.py", line 202, in call
    ret["return"] = self.minion.executors[fname](
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1228, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1243, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/executors/direct_call.py", line 10, in execute
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1228, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1243, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/modules/cmdmod.py", line 1272, in run
    ret = _run(
  File "/usr/local/lib/python3.9/site-packages/salt/modules/cmdmod.py", line 724, in _run
    proc.run()
  File "/usr/local/lib/python3.9/site-packages/salt/utils/timed_subprocess.py", line 111, in run
    receive()
  File "/usr/local/lib/python3.9/site-packages/salt/utils/timed_subprocess.py", line 100, in receive
    self.stdout, self.stderr = self.process.communicate(input=self.stdin, timeout=5)
  File "/usr/local/lib/python3.9/subprocess.py", line 1134, in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
  File "/usr/local/lib/python3.9/subprocess.py", line 1980, in _communicate
    self._check_timeout(endtime, orig_timeout, stdout, stderr)
  File "/usr/local/lib/python3.9/subprocess.py", line 1178, in _check_timeout
    raise TimeoutExpired(
subprocess.TimeoutExpired: Command '/usr/local/sbin/php-fpm' timed out after 5 seconds
Traceback (most recent call last):
  File "/usr/local/bin/salt-call", line 33, in <module>
    sys.exit(load_entry_point('salt==3005', 'console_scripts', 'salt-call')())
  File "/usr/local/lib/python3.9/site-packages/salt/scripts.py", line 441, in salt_call
    client.run()
  File "/usr/local/lib/python3.9/site-packages/salt/cli/call.py", line 50, in run
    caller.run()
  File "/usr/local/lib/python3.9/site-packages/salt/cli/caller.py", line 95, in run
    ret = self.call()
  File "/usr/local/lib/python3.9/site-packages/salt/cli/caller.py", line 202, in call
    ret["return"] = self.minion.executors[fname](
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1228, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1243, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/executors/direct_call.py", line 10, in execute
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1228, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/loader/lazy.py", line 1243, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/salt/modules/cmdmod.py", line 1272, in run
    ret = _run(
  File "/usr/local/lib/python3.9/site-packages/salt/modules/cmdmod.py", line 724, in _run
    proc.run()
  File "/usr/local/lib/python3.9/site-packages/salt/utils/timed_subprocess.py", line 111, in run
    receive()
  File "/usr/local/lib/python3.9/site-packages/salt/utils/timed_subprocess.py", line 100, in receive
    self.stdout, self.stderr = self.process.communicate(input=self.stdin, timeout=5)
  File "/usr/local/lib/python3.9/subprocess.py", line 1134, in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
  File "/usr/local/lib/python3.9/subprocess.py", line 1980, in _communicate
    self._check_timeout(endtime, orig_timeout, stdout, stderr)
  File "/usr/local/lib/python3.9/subprocess.py", line 1178, in _check_timeout
    raise TimeoutExpired(
subprocess.TimeoutExpired: Command '/usr/local/sbin/php-fpm' timed out after 5 seconds

Expected behavior
Not hanging, php-fpm does start and it does return an error code (0).

Screenshots
NA

Versions Report

salt --versions-report /usr/local/lib/python3.9/site-packages/_distutils_hack/__init__.py:33: UserWarning: Setuptools is replacing distutils. warnings.warn("Setuptools is replacing distutils.") Salt Version: Salt: 3005

Dependency Versions:
cffi: 1.15.1
cherrypy: Not Installed
dateutil: 2.8.2
docker-py: Not Installed
gitdb: Not Installed
gitpython: Not Installed
Jinja2: 3.0.1
libgit2: Not Installed
M2Crypto: Not Installed
Mako: Not Installed
msgpack: 1.0.4
msgpack-pure: Not Installed
mysql-python: Not Installed
pycparser: 2.21
pycrypto: Not Installed
pycryptodome: 3.15.0
pygit2: Not Installed
Python: 3.9.14 (main, Sep 20 2022, 01:16:05)
python-gnupg: Not Installed
PyYAML: 5.4.1
PyZMQ: 22.3.0
smmap: Not Installed
timelib: Not Installed
Tornado: 4.5.3
ZMQ: 4.3.4

System Versions:
dist: freebsd 13.1
locale: utf-8
machine: amd64
release: 13.1-RELEASE-p2
system: FreeBSD
version: FreeBSD 13.1

Metadata

Metadata

Assignees

No one assigned

    Labels

    Upstream-Bugis a result of an upstream issue, not in saltbugbroken, incorrect, or confusing behaviordependencyunderlying Salt dependency issueneeds-triage

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions