openstack/swift
Code Issues Proposed changes

Merge "Don't monkey patch logging on import"

Browse Source
This commit is contained in:
Zuul 2023-04-28 22:44:29 +00:00 committed by Gerrit Code Review
commit b1dc6237c1
6 changed files with 108 additions and 19 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

6
swift/common/daemon.py
View File

@ -20,8 +20,8 @@ import time
import signal
from re import sub
import eventlet
import eventlet.debug
from eventlet.hubs import use_hub
from swift.common import utils
@ -281,7 +281,9 @@ def run_daemon(klass, conf_file, section_name='', once=False, **kwargs):
# and results in an exit code of 1.
sys.exit(e)
use_hub(utils.get_hub())
# patch eventlet/logging early
utils.monkey_patch()
eventlet.hubs.use_hub(utils.get_hub())
# once on command line (i.e. daemonize=false) will over-ride config
once = once or not utils.config_true_value(conf.get('daemonize', 'true'))

30
swift/common/utils/__init__.py
View File

@ -119,16 +119,10 @@ from swift.common.utils.timestamp import ( # noqa
normalize_delete_at_timestamp,
)
# logging doesn't import patched as cleanly as one would like
from logging.handlers import SysLogHandler
import logging
logging.thread = eventlet.green.thread
logging.threading = eventlet.green.threading
logging._lock = logging.threading.RLock()
# setup notice level logging
NOTICE = 25
logging.addLevelName(NOTICE, 'NOTICE')
SysLogHandler.priority_map['NOTICE'] = 'notice'
# Used by hash_path to offer a bit more security when generating hashes for
# paths. It simply appends this value to all paths; guessing the hash a path
@ -442,6 +436,17 @@ def config_read_prefixed_options(conf, prefix_name, defaults):
return params
def logging_monkey_patch():
# explicitly patch the logging lock
logging._lock = logging.threading.RLock()
# setup notice level logging
logging.addLevelName(NOTICE, 'NOTICE')
SysLogHandler.priority_map['NOTICE'] = 'notice'
# Trying to log threads while monkey-patched can lead to deadlocks; see
# https://bugs.launchpad.net/swift/+bug/1895739
logging.logThreads = 0
def eventlet_monkey_patch():
"""
Install the appropriate Eventlet monkey patches.
@ -452,9 +457,14 @@ def eventlet_monkey_patch():
# if thread is monkey-patched.
eventlet.patcher.monkey_patch(all=False, socket=True, select=True,
thread=True)
# Trying to log threads while monkey-patched can lead to deadlocks; see
# https://bugs.launchpad.net/swift/+bug/1895739
logging.logThreads = 0
def monkey_patch():
"""
Apply all swift monkey patching consistently in one place.
"""
eventlet_monkey_patch()
logging_monkey_patch()
def validate_configuration():

2
swift/common/wsgi.py
View File

@ -838,7 +838,7 @@ def run_wsgi(conf_path, app_section, *args, **kwargs):
return 1
# patch event before loadapp
utils.eventlet_monkey_patch()
utils.monkey_patch()
# Ensure the configuration and application can be loaded before proceeding.
global_conf = {'log_name': log_name}

32
test/unit/common/test_daemon.py
View File

@ -148,9 +148,12 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
])
def test_run_daemon(self):
logging.logThreads = 1 # reset to default
sample_conf = "[my-daemon]\nuser = %s\n" % getuser()
with tmpfile(sample_conf) as conf_file, \
mock.patch('swift.common.daemon.use_hub') as mock_use_hub:
mock.patch('swift.common.utils.eventlet') as _utils_evt, \
mock.patch('eventlet.hubs.use_hub') as mock_use_hub, \
mock.patch('eventlet.debug') as _debug_evt:
with mock.patch.dict('os.environ', {'TZ': ''}), \
mock.patch('time.tzset') as mock_tzset:
daemon.run_daemon(MyDaemon, conf_file)
@ -160,6 +163,12 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
self.assertEqual(mock_use_hub.mock_calls,
[mock.call(utils.get_hub())])
daemon.run_daemon(MyDaemon, conf_file, once=True)
_utils_evt.patcher.monkey_patch.assert_called_with(all=False,
socket=True,
select=True,
thread=True)
self.assertEqual(0, logging.logThreads) # fixed in monkey_patch
_debug_evt.hub_exceptions.assert_called_with(False)
self.assertEqual(MyDaemon.once_called, True)
# test raise in daemon code
@ -196,7 +205,9 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
sample_conf = "[my-daemon]\nuser = %s\n" % getuser()
with tmpfile(sample_conf) as conf_file, \
mock.patch('swift.common.daemon.use_hub'):
mock.patch('swift.common.utils.eventlet'), \
mock.patch('eventlet.hubs.use_hub'), \
mock.patch('eventlet.debug'):
daemon.run_daemon(MyDaemon, conf_file)
self.assertFalse(MyDaemon.once_called)
self.assertTrue(MyDaemon.forever_called)
@ -222,7 +233,9 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
contents = dedent(conf_body)
with open(conf_path, 'w') as f:
f.write(contents)
with mock.patch('swift.common.daemon.use_hub'):
with mock.patch('swift.common.utils.eventlet'), \
mock.patch('eventlet.hubs.use_hub'), \
mock.patch('eventlet.debug'):
d = daemon.run_daemon(MyDaemon, conf_path)
# my-daemon section takes priority (!?)
self.assertEqual('2', d.conf['client_timeout'])
@ -244,7 +257,9 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
contents = dedent(conf_body)
with open(conf_path, 'w') as f:
f.write(contents)
with mock.patch('swift.common.daemon.use_hub'):
with mock.patch('swift.common.utils.eventlet'), \
mock.patch('eventlet.hubs.use_hub'), \
mock.patch('eventlet.debug'):
app_config = lambda: daemon.run_daemon(MyDaemon, tempdir)
# N.B. CLIENT_TIMEOUT/client_timeout are unique options
self.assertDuplicateOption(app_config, 'conn_timeout', '1.2')
@ -270,7 +285,9 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
path = os.path.join(tempdir, filename + '.conf')
with open(path, 'wt') as fd:
fd.write(dedent(conf_body))
with mock.patch('swift.common.daemon.use_hub'):
with mock.patch('swift.common.utils.eventlet'), \
mock.patch('eventlet.hubs.use_hub'), \
mock.patch('eventlet.debug'):
d = daemon.run_daemon(MyDaemon, tempdir)
# my-daemon section takes priority (!?)
self.assertEqual('2', d.conf['client_timeout'])
@ -296,7 +313,9 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
path = os.path.join(tempdir, filename + '.conf')
with open(path, 'wt') as fd:
fd.write(dedent(conf_body))
with mock.patch('swift.common.daemon.use_hub'):
with mock.patch('swift.common.utils.eventlet'), \
mock.patch('eventlet.hubs.use_hub'), \
mock.patch('eventlet.debug'):
app_config = lambda: daemon.run_daemon(MyDaemon, tempdir)
# N.B. CLIENT_TIMEOUT/client_timeout are unique options
self.assertDuplicateOption(app_config, 'conn_timeout', '1.2')
@ -322,6 +341,7 @@ class TestRunDaemon(unittest.TestCase, ConfigAssertMixin):
yield
def test_fork_workers(self):
utils.logging_monkey_patch() # needed to log at notice
d = MyWorkerDaemon({'workers': 3})
strategy = daemon.DaemonStrategy(d, d.logger)
with self.mock_os():

55
test/unit/common/test_utils.py
View File

@ -210,6 +210,61 @@ class TestUtils(unittest.TestCase):
self.md5_digest = '0d6dc3c588ae71a04ce9a6beebbbba06'
self.fips_enabled = True
def test_monkey_patch(self):
def take_and_release(lock):
try:
lock.acquire()
finally:
lock.release()
def do_test():
res = 0
try:
# this module imports eventlet original threading, so re-import
# locally...
import threading
import traceback
logging_lock_before = logging._lock
my_lock_before = threading.RLock()
self.assertIsInstance(logging_lock_before,
type(my_lock_before))
utils.monkey_patch()
logging_lock_after = logging._lock
my_lock_after = threading.RLock()
self.assertIsInstance(logging_lock_after,
type(my_lock_after))
self.assertTrue(logging_lock_after.acquire())
thread = threading.Thread(target=take_and_release,
args=(logging_lock_after,))
thread.start()
self.assertTrue(thread.isAlive())
# we should timeout while the thread is still blocking on lock
eventlet.sleep()
thread.join(timeout=0.1)
self.assertTrue(thread.isAlive())
logging._lock.release()
thread.join(timeout=0.1)
self.assertFalse(thread.isAlive())
except AssertionError:
traceback.print_exc()
res = 1
finally:
os._exit(res)
pid = os.fork()
if pid == 0:
# run the test in an isolated environment to avoid monkey patching
# in this one
do_test()
else:
child_pid, errcode = os.waitpid(pid, 0)
self.assertEqual(0, os.WEXITSTATUS(errcode),
'Forked do_test failed')
def test_get_zero_indexed_base_string(self):
self.assertEqual(utils.get_zero_indexed_base_string('something', 0),
'something')

2
test/unit/common/test_wsgi.py
View File

@ -995,6 +995,7 @@ class TestWSGI(unittest.TestCase, ConfigAssertMixin):
def _loadapp(uri, name=None, **kwargs):
calls['_loadapp'] += 1
logging.logThreads = 1 # reset to default
with mock.patch.object(wsgi, '_initrp', _initrp), \
mock.patch.object(wsgi, 'get_socket'), \
mock.patch.object(wsgi, 'drop_privileges') as _d_privs, \
@ -1015,6 +1016,7 @@ class TestWSGI(unittest.TestCase, ConfigAssertMixin):
# just clean_up_deemon_hygene()
self.assertEqual([], _d_privs.mock_calls)
self.assertEqual([mock.call()], _c_hyg.mock_calls)
self.assertEqual(0, logging.logThreads) # fixed in our monkey_patch
@mock.patch('swift.common.wsgi.run_server')
@mock.patch('swift.common.wsgi.WorkersStrategy')