File prevent-logging-deadlock-on-salt-api-subprocesses-bs.patch of Package salt.23569
From 4e6cc0c401bd6c9e47b324fc2df99e3bd679da33 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Pablo=20Su=C3=A1rez=20Hern=C3=A1ndez?=
<psuarezhernandez@suse.com>
Date: Wed, 22 Jan 2020 08:19:55 +0000
Subject: [PATCH] Prevent logging deadlock on salt-api subprocesses
(bsc#1159284)
---
salt/_logging/impl.py | 127 +++++++++++++++-------------------
salt/client/ssh/__init__.py | 12 +++-
salt/client/ssh/client.py | 21 +++---
salt/client/ssh/wrapper/cp.py | 10 +--
salt/loader.py | 2 +-
salt/utils/lazy.py | 10 +--
6 files changed, 85 insertions(+), 97 deletions(-)
diff --git a/salt/_logging/impl.py b/salt/_logging/impl.py
index 5a6292b445..2f15bf0025 100644
--- a/salt/_logging/impl.py
+++ b/salt/_logging/impl.py
@@ -1,4 +1,3 @@
-# -*- coding: utf-8 -*-
"""
salt._logging.impl
~~~~~~~~~~~~~~~~~~
@@ -6,15 +5,12 @@
Salt's logging implementation classes/functionality
"""
-# Import python libs
-from __future__ import absolute_import, print_function, unicode_literals
import logging
import re
import sys
import types
-# Import 3rd-party libs
import salt.ext.six as six
# Let's define these custom logging levels before importing the salt._logging.mixins
@@ -23,8 +19,8 @@ PROFILE = logging.PROFILE = 15
TRACE = logging.TRACE = 5
GARBAGE = logging.GARBAGE = 1
QUIET = logging.QUIET = 1000
+DEBUG = logging.DEBUG = 10
-# Import Salt libs
from salt._logging.handlers import StreamHandler # isort:skip
# from salt._logging.handlers import SysLogHandler # isort:skip
@@ -52,7 +48,7 @@ LOG_LEVELS = {
"warning": logging.WARNING,
}
-LOG_VALUES_TO_LEVELS = dict((v, k) for (k, v) in LOG_LEVELS.items())
+LOG_VALUES_TO_LEVELS = {v: k for (k, v) in LOG_LEVELS.items()}
LOG_COLORS = {
"levels": {
@@ -96,9 +92,7 @@ LOG_COLORS = {
}
# Make a list of log level names sorted by log level
-SORTED_LEVEL_NAMES = [
- l[0] for l in sorted(six.iteritems(LOG_LEVELS), key=lambda x: x[1])
-]
+SORTED_LEVEL_NAMES = [l[0] for l in sorted(LOG_LEVELS.items(), key=lambda x: x[1])]
MODNAME_PATTERN = re.compile(r"(?P<name>%%\(name\)(?:\-(?P<digits>[\d]+))?s)")
@@ -168,8 +162,7 @@ def set_log_record_factory(factory):
Set the logging log record factory
"""
get_log_record_factory.__factory__ = factory
- if not six.PY2:
- logging.setLogRecordFactory(factory)
+ logging.setLogRecordFactory(factory)
set_log_record_factory(SaltLogRecord)
@@ -180,7 +173,7 @@ LOGGING_LOGGER_CLASS = logging.getLoggerClass()
class SaltLoggingClass(
- six.with_metaclass(LoggingMixinMeta, LOGGING_LOGGER_CLASS, NewStyleClassMixin)
+ LOGGING_LOGGER_CLASS, NewStyleClassMixin, metaclass=LoggingMixinMeta
):
def __new__(cls, *args):
"""
@@ -194,13 +187,11 @@ class SaltLoggingClass(
logging.getLogger(__name__)
"""
- instance = super(SaltLoggingClass, cls).__new__(cls)
+ instance = super().__new__(cls)
- try:
- max_logger_length = len(
- max(list(logging.Logger.manager.loggerDict), key=len)
- )
- for handler in logging.root.handlers:
+ max_logger_length = len(max(list(logging.Logger.manager.loggerDict), key=len))
+ for handler in logging.root.handlers:
+ try:
if handler in (
LOGGING_NULL_HANDLER,
LOGGING_STORE_HANDLER,
@@ -221,18 +212,15 @@ class SaltLoggingClass(
match = MODNAME_PATTERN.search(fmt)
if not match:
# Not matched. Release handler and return.
- handler.release()
return instance
if "digits" not in match.groupdict():
# No digits group. Release handler and return.
- handler.release()
return instance
digits = match.group("digits")
if not digits or not (digits and digits.isdigit()):
# No valid digits. Release handler and return.
- handler.release()
return instance
if int(digits) < max_logger_length:
@@ -243,9 +231,14 @@ class SaltLoggingClass(
)
handler.setFormatter(formatter)
handler.release()
- except ValueError:
- # There are no registered loggers yet
- pass
+ except ValueError:
+ # There are no registered loggers yet
+ pass
+ finally:
+ try:
+ handler.release()
+ except:
+ pass
return instance
def _log(
@@ -279,7 +272,7 @@ class SaltLoggingClass(
"Only one of 'exc_info' and 'exc_info_on_loglevel' is " "permitted"
)
if exc_info_on_loglevel is not None:
- if isinstance(exc_info_on_loglevel, six.string_types):
+ if isinstance(exc_info_on_loglevel, str):
exc_info_on_loglevel = LOG_LEVELS.get(
exc_info_on_loglevel, logging.ERROR
)
@@ -295,31 +288,37 @@ class SaltLoggingClass(
else:
extra["exc_info_on_loglevel"] = exc_info_on_loglevel
- if sys.version_info < (3,):
- LOGGING_LOGGER_CLASS._log(
- self, level, msg, args, exc_info=exc_info, extra=extra
- )
- elif sys.version_info < (3, 8):
- LOGGING_LOGGER_CLASS._log(
- self,
- level,
- msg,
- args,
- exc_info=exc_info,
- extra=extra,
- stack_info=stack_info,
- )
- else:
- LOGGING_LOGGER_CLASS._log(
- self,
- level,
- msg,
- args,
- exc_info=exc_info,
- extra=extra,
- stack_info=stack_info,
- stacklevel=stacklevel,
- )
+ try:
+ logging._acquireLock()
+ if sys.version_info < (3,):
+ LOGGING_LOGGER_CLASS._log(
+ self, level, msg, args, exc_info=exc_info, extra=extra
+ )
+ elif sys.version_info < (3, 8):
+ LOGGING_LOGGER_CLASS._log(
+ self,
+ level,
+ msg,
+ args,
+ exc_info=exc_info,
+ extra=extra,
+ stack_info=stack_info,
+ )
+ else:
+ LOGGING_LOGGER_CLASS._log(
+ self,
+ level,
+ msg,
+ args,
+ exc_info=exc_info,
+ extra=extra,
+ stack_info=stack_info,
+ stacklevel=stacklevel,
+ )
+ except:
+ pass
+ finally:
+ logging._releaseLock()
def makeRecord(
self,
@@ -357,7 +356,7 @@ class SaltLoggingClass(
except NameError:
salt_system_encoding = "utf-8"
- if isinstance(msg, six.string_types) and not isinstance(msg, six.text_type):
+ if isinstance(msg, str) and not isinstance(msg, str):
try:
_msg = msg.decode(salt_system_encoding, "replace")
except UnicodeDecodeError:
@@ -367,9 +366,7 @@ class SaltLoggingClass(
_args = []
for item in args:
- if isinstance(item, six.string_types) and not isinstance(
- item, six.text_type
- ):
+ if isinstance(item, str) and not isinstance(item, str):
try:
_args.append(item.decode(salt_system_encoding, "replace"))
except UnicodeDecodeError:
@@ -378,24 +375,9 @@ class SaltLoggingClass(
_args.append(item)
_args = tuple(_args)
- if six.PY2:
- # Recreate what's done for Py >= 3.5
- _log_record_factory = get_log_record_factory()
- logrecord = _log_record_factory(
- name, level, fn, lno, _msg, _args, exc_info, func
- )
-
- if extra is not None:
- for key in extra:
- if (key in ["message", "asctime"]) or (key in logrecord.__dict__):
- raise KeyError(
- "Attempt to overwrite '{}' in LogRecord".format(key)
- )
- logrecord.__dict__[key] = extra[key]
- else:
- logrecord = LOGGING_LOGGER_CLASS.makeRecord(
- self, name, level, fn, lno, _msg, _args, exc_info, func, sinfo
- )
+ logrecord = LOGGING_LOGGER_CLASS.makeRecord(
+ self, name, level, fn, lno, _msg, _args, exc_info, func, sinfo
+ )
if exc_info_on_loglevel is not None:
# Let's add some custom attributes to the LogRecord class in order
@@ -419,6 +401,7 @@ if logging.getLoggerClass() is not SaltLoggingClass:
logging.addLevelName(PROFILE, "PROFILE")
logging.addLevelName(TRACE, "TRACE")
logging.addLevelName(GARBAGE, "GARBAGE")
+ logging.addLevelName(DEBUG, "DEBUG")
# ----- REMOVE ON REFACTORING COMPLETE -------------------------------------------------------------------------->
if not logging.root.handlers:
diff --git a/salt/client/ssh/__init__.py b/salt/client/ssh/__init__.py
index ef9eb0c07e..6570fba5b1 100644
--- a/salt/client/ssh/__init__.py
+++ b/salt/client/ssh/__init__.py
@@ -532,7 +532,9 @@ class SSH:
**target
)
ret = {"id": single.id}
+ logging._acquireLock()
stdout, stderr, retcode = single.run()
+ logging._releaseLock()
# This job is done, yield
try:
data = salt.utils.json.find_json(stdout)
@@ -600,8 +602,14 @@ class SSH:
self.targets[host],
mine,
)
- routine = Process(target=self.handle_routine, args=args)
- routine.start()
+ try:
+ logging._acquireLock()
+ routine = Process(target=self.handle_routine, args=args)
+ routine.start()
+ except:
+ pass
+ finally:
+ logging._releaseLock()
running[host] = {"thread": routine}
continue
ret = {}
diff --git a/salt/client/ssh/client.py b/salt/client/ssh/client.py
index 55436366cf..d2dbdeb00e 100644
--- a/salt/client/ssh/client.py
+++ b/salt/client/ssh/client.py
@@ -1,14 +1,10 @@
-# -*- coding: utf-8 -*-
-
-# Import Python libs
-from __future__ import absolute_import, print_function, unicode_literals
-
import copy
import logging
+import multiprocessing
import os
import random
+import time
-# Import Salt libs
import salt.config
import salt.syspaths as syspaths
import salt.utils.args
@@ -16,8 +12,10 @@ from salt.exceptions import SaltClientError # Temporary
log = logging.getLogger(__name__)
+_LOCK = multiprocessing.Lock()
-class SSHClient(object):
+
+class SSHClient:
"""
Create a client object for executing routines via the salt-ssh backend
@@ -60,7 +58,11 @@ class SSHClient(object):
opts["selected_target_option"] = tgt_type
opts["tgt"] = tgt
opts["arg"] = arg
- return salt.client.ssh.SSH(opts)
+ _LOCK.acquire()
+ ret = salt.client.ssh.SSH(opts)
+ time.sleep(0.01)
+ _LOCK.release()
+ return ret
def cmd_iter(
self,
@@ -80,8 +82,7 @@ class SSHClient(object):
.. versionadded:: 2015.5.0
"""
ssh = self._prep_ssh(tgt, fun, arg, timeout, tgt_type, kwarg, **kwargs)
- for ret in ssh.run_iter(jid=kwargs.get("jid", None)):
- yield ret
+ yield from ssh.run_iter(jid=kwargs.get("jid", None))
def cmd(
self, tgt, fun, arg=(), timeout=None, tgt_type="glob", kwarg=None, **kwargs
diff --git a/salt/client/ssh/wrapper/cp.py b/salt/client/ssh/wrapper/cp.py
index e369d8475f..eb37ae971b 100644
--- a/salt/client/ssh/wrapper/cp.py
+++ b/salt/client/ssh/wrapper/cp.py
@@ -1,15 +1,11 @@
-# -*- coding: utf-8 -*-
"""
Wrap the cp module allowing for managed ssh file transfers
"""
-# Import Python libs
-from __future__ import absolute_import, print_function
-import logging
import os
-# Import salt libs
import salt.client.ssh
+import salt.log.setup as logging
import salt.utils.files
import salt.utils.stringutils
import salt.utils.templates
@@ -107,7 +103,7 @@ def _render_filenames(path, dest, saltenv, template):
if template not in salt.utils.templates.TEMPLATE_REGISTRY:
raise CommandExecutionError(
"Attempted to render file paths with unavailable engine "
- "{0}".format(template)
+ "{}".format(template)
)
kwargs = {}
@@ -133,7 +129,7 @@ def _render_filenames(path, dest, saltenv, template):
if not data["result"]:
# Failed to render the template
raise CommandExecutionError(
- "Failed to render file path with error: {0}".format(data["data"])
+ "Failed to render file path with error: {}".format(data["data"])
)
else:
return data["data"]
diff --git a/salt/loader.py b/salt/loader.py
index 9a9c11b401..cfcd18f6f3 100644
--- a/salt/loader.py
+++ b/salt/loader.py
@@ -8,7 +8,6 @@ import functools
import importlib.machinery # pylint: disable=no-name-in-module,import-error
import importlib.util # pylint: disable=no-name-in-module,import-error
import inspect
-import logging
import os
import re
import sys
@@ -23,6 +22,7 @@ from zipimport import zipimporter
import salt.config
import salt.defaults.events
import salt.defaults.exitcodes
+import salt.log.setup as logging
import salt.syspaths
import salt.utils.args
import salt.utils.context
diff --git a/salt/utils/lazy.py b/salt/utils/lazy.py
index 8fc538164a..c828dd2c32 100644
--- a/salt/utils/lazy.py
+++ b/salt/utils/lazy.py
@@ -1,15 +1,13 @@
-# -*- coding: utf-8 -*-
"""
Lazily-evaluated data structures, primarily used by Salt's loader
"""
-# Import Python Libs
-from __future__ import absolute_import, unicode_literals
-import logging
+import time
from collections.abc import MutableMapping
import salt.exceptions
+import salt.log.setup as logging
log = logging.getLogger(__name__)
@@ -81,7 +79,7 @@ class LazyDict(MutableMapping):
Override this to return a more meaningfull error message if possible
"""
- return "'{0}' is not available.".format(function_name)
+ return "'{}' is not available.".format(function_name)
def __setitem__(self, key, val):
self._dict[key] = val
@@ -100,11 +98,13 @@ class LazyDict(MutableMapping):
# load the item
if self._load(key):
log.debug("LazyLoaded %s", key)
+ time.sleep(0.0001)
return self._dict[key]
else:
log.debug(
"Could not LazyLoad %s: %s", key, self.missing_fun_string(key)
)
+ time.sleep(0.0001)
raise KeyError(key)
else:
return self._dict[key]
--
2.29.2
