def test_rwlock_different_threads():
lock = RWLock("test")
ea = threading.Event()
eb = threading.Event()
def a(id=None):
lock.acquire(id)
ea.set()
eb.wait()
def b(id=None):
lock.release(id)
eb.set()
with concurrent(a):
ea.wait()
assert lock.owners
with pytest.raises(RuntimeError):
b()
eb.set()
assert lock.owners
with concurrent(a, "same"):
assert lock.owners
with concurrent(b, "same"):
pass
assert lock.owners
def test_call_concurrent():
func = lambda a, b: a * 10 + b
c = concurrent(func, 1, b=2, threadname='add')
assert c() == 12
c = concurrent(func, 1, 2, threadname='add')
assert c() == 12
c = concurrent(func, 1, threadname='add')
assert c(2) == 12
c = concurrent(func, threadname='add')
assert c(1, 2) == 12
def test_concurrent_real_thread():
from easypy.concurrency import IS_GEVENT
from gevent.monkey import get_original
import logging
sleep = get_original("time", "sleep")
current_thread = get_original("threading", "get_ident")
main_thread = current_thread()
ran = 0
def log_and_sleep():
nonlocal ran
logging.info("test")
sleep(.1)
ran += 1
return current_thread()
if IS_GEVENT:
before = ran
with concurrent(log_and_sleep, real_thread_no_greenlet=True) as c:
pass
result = c.result()
assert ran == before + 1
assert main_thread != result
before = ran
with concurrent(log_and_sleep) as c:
pass
result = c.result()
assert ran == before + 1
assert main_thread == result
else:
before = ran
with concurrent(log_and_sleep, real_thread_no_greenlet=True) as c:
pass
result = c.result()
assert ran == before + 1
assert main_thread != result
before = ran
with concurrent(log_and_sleep) as c:
pass
result = c.result()
assert ran == before + 1
assert main_thread != result
assert ran
def test_logged_lock():
lock = LoggedRLock("test", lease_expiration=1, log_interval=.2)
step1 = threading.Event()
step2 = threading.Event()
def do_lock():
with lock:
step1.set()
step2.wait()
with concurrent(do_lock):
# wait for thread to hold the lock
step1.wait()
# we'll mock the logger so we can ensure it logged
with patch("easypy.sync._logger") as _logger:
assert not lock.acquire(timeout=0.5) # below the lease_expiration
# the expiration mechanism should kick in
with pytest.raises(LockLeaseExpired):
lock.acquire()
# let other thread finish
step2.set()
with lock:
pass
assert sum(c == call("%s - waiting...", lock)
for c in _logger.debug.call_args_list) > 3
def watch_threads(interval):
from easypy.resilience import resilient
from easypy.concurrency import concurrent
cmdline = " ".join(sys.argv)
_logger = logging.getLogger(__name__)
_threads_logger = logging.getLogger('threads')
last_threads = set()
@contextmanager
def no_exceptions():
try:
yield
except Exception:
pass
@no_exceptions()
@resilient.warning
def dump_threads():
nonlocal last_threads
with _logger.indented('getting thread tree', level=logging.DEBUG):
tree = get_thread_tree(including_this=False)
with _logger.indented('logging threads to yaml', level=logging.DEBUG):
_threads_logger.debug("threads",
extra=dict(cmdline=cmdline,
tree=tree.to_dict()))
with _logger.indented('creating current thread set',
level=logging.DEBUG):
current_threads = set()
for thread in threading.enumerate():
if thread.ident:
current_threads.add(thread.ident)
new_threads = current_threads - last_threads
closed_threads = last_threads - current_threads
stringify = lambda idents: ", ".join("%X" % ident for ident in idents)
if new_threads:
_logger.debug("WHITE<<NEW>> threads (%s): %s", len(new_threads),
stringify(new_threads))
if closed_threads:
_logger.debug("threads terminated (%s): %s", len(closed_threads),
stringify(closed_threads))
_logger.debug("total threads: %s", len(current_threads))
last_threads = current_threads
thread = concurrent(dump_threads,
threadname="ThreadWatch",
loop=True,
sleep=interval,
real_thread_no_greenlet=True)
thread.start()
_logger.info("threads watcher started")
def check1():
assert TC.i == 1
assert TC.j == 0
with TC(i=1, j=1):
def check2():
assert TC.i == 2
assert TC.j == 1
with concurrent(check2):
pass
def check1():
assert TC.i == ['a']
assert TC.j == []
with TC(i='i', j='j'):
def check2():
assert TC.i == ['a', 'i']
assert TC.j == ['j']
with concurrent(check2):
pass
def test_logged_condition_waited_for():
cond = LoggedCondition('test', log_interval=15)
progress = 0
executed = []
def wait_then_set_to(wait_to, set_to):
nonlocal progress
with cond.waited_for(lambda: progress == wait_to, 'progress to be %s',
wait_to):
executed.append('%s -> %s' % (progress, set_to))
progress = set_to
with concurrent(wait_then_set_to, 10,
20), concurrent(wait_then_set_to, 20,
30), concurrent(wait_then_set_to, 30, 40):
with cond.notifying_all('setting progress to 10'):
progress = 10
assert executed == ['10 -> 20', '20 -> 30', '30 -> 40']
def __init__(self, talker):
self.talker = talker
self._max_workers = 5
self._executors = ThreadPoolExecutor(max_workers=self._max_workers)
self._commands_queue = Queue()
self._commands = dict()
self._lock = RLock()
self._current_workers = Semaphore(self._max_workers)
self._cmd_idx = 0
reactor_loop = _logger.context(host="TLKR-reactor-loop")(
self._get_main_loop)
self._main_loop = concurrent(func=reactor_loop,
threadname="TLKR-reactor")
self._main_loop.start()
def test_logged_condition_exception():
cond = LoggedCondition('test', log_interval=.2)
should_throw = False
class TestException(Exception):
pass
def waiter():
if should_throw:
raise TestException
with pytest.raises(TestException):
with concurrent(cond.wait_for, waiter, 'throw'):
sleep(0.5)
should_throw = True
def test_concurrent_done_status(throw):
from threading import Event
continue_func = Event()
def func():
continue_func.wait()
if throw:
raise Exception()
with concurrent(func, throw=False) as c:
assert not c.done()
continue_func.set()
sleep(0.1)
assert c.done()
assert c.done()
def test_thread_context_stacks():
TC = ThreadContexts(stacks=('i', 'j'))
assert TC.i == TC.j == []
with TC(i='a'):
def check1():
assert TC.i == ['a']
assert TC.j == []
with TC(i='i', j='j'):
def check2():
assert TC.i == ['a', 'i']
assert TC.j == ['j']
with concurrent(check2):
pass
with concurrent(check1):
pass
def test_thread_contexts_counters():
TC = ThreadContexts(counters=('i', 'j'))
assert TC.i == TC.j == 0
with TC(i=1):
def check1():
assert TC.i == 1
assert TC.j == 0
with TC(i=1, j=1):
def check2():
assert TC.i == 2
assert TC.j == 1
with concurrent(check2):
pass
with concurrent(check1):
pass
def watch_threads(interval):
from easypy.resilience import resilient
from easypy.concurrency import concurrent
cmdline = " ".join(sys.argv)
_logger = logging.getLogger(__name__)
_threads_logger = logging.getLogger('threads')
last_threads = set()
@resilient.warning
def dump_threads():
nonlocal last_threads
tree = get_thread_tree(including_this=False)
_threads_logger.debug("threads",
extra=dict(cmdline=cmdline, tree=tree.to_dict()))
current_threads = set()
for thread in threading.enumerate():
if thread.ident:
current_threads.add(thread.ident)
new_threads = current_threads - last_threads
closed_threads = last_threads - current_threads
stringify = lambda idents: ", ".join("%X" % ident for ident in idents)
if new_threads:
_logger.debug("WHITE<<NEW>> threads (%s): %s", len(new_threads),
stringify(new_threads))
if closed_threads:
_logger.debug("threads terminated (%s): %s", len(closed_threads),
stringify(closed_threads))
_logger.debug("total threads: %s", len(current_threads))
last_threads = current_threads
thread = concurrent(dump_threads,
threadname="ThreadWatch",
loop=True,
sleep=interval)
thread.start()
_logger.info("threads watcher started")
def disable_test_logged_lock_races():
lease_expiration = 1
lock = LoggedRLock("test",
lease_expiration=lease_expiration,
log_interval=.1)
import logging
def do_lock(idx):
sleep(random.random())
if lock.acquire(timeout=1, blocking=random.random() > 0.5):
logging.info("%02d: acquired", idx)
sleep(random.random() * lease_expiration * 0.9)
lock.release()
logging.info("%02d: released", idx)
else:
logging.info("%02d: timed out", idx)
with ExitStack() as stack:
for i in range(30):
stack.enter_context(concurrent(do_lock, idx=i, loop=True, sleep=0))
sleep(5)
def watch_threads(interval, logger_name='threads'):
"""
Starts a daemon thread that logs the active-threads to a ``threads`` logger, at the specified interval.
The data is logged using the ``extra`` logging struct.
It is recommended to configure the logger to use ``easypy.logging.YAMLFormatter``, so that the log can be
easily parsed by other tools.
"""
from easypy.resilience import resilient
from easypy.concurrency import concurrent
cmdline = " ".join(sys.argv)
_logger = logging.getLogger(__name__)
_threads_logger = logging.getLogger(logger_name)
last_threads = set()
@contextmanager
def no_exceptions():
try:
yield
except Exception:
pass
@no_exceptions()
@resilient.warning
def dump_threads():
nonlocal last_threads
with _logger.indented('getting thread tree', level=logging.DEBUG):
trees = get_thread_trees(including_this=False)
with _logger.indented('logging threads to yaml', level=logging.DEBUG):
_threads_logger.debug("threads",
extra=dict(
cmdline=cmdline,
tree=Bunch(children=trees).to_dict()))
with _logger.indented('creating current thread set',
level=logging.DEBUG):
current_threads = set()
for thread in threading.enumerate():
if thread.ident:
current_threads.add(thread.ident)
new_threads = current_threads - last_threads
closed_threads = last_threads - current_threads
stringify = lambda idents: ", ".join("%X" % ident for ident in idents)
if new_threads:
_logger.debug("WHITE<<NEW>> threads (%s): %s", len(new_threads),
stringify(new_threads))
if closed_threads:
_logger.debug("threads terminated (%s): %s", len(closed_threads),
stringify(closed_threads))
_logger.debug("total threads: %s", len(current_threads))
last_threads = current_threads
thread = concurrent(dump_threads,
threadname="ThreadWatch",
loop=True,
sleep=interval,
real_thread_no_greenlet=True)
thread.start()
_logger.info("threads watcher started")
def test_logged_condition():
cond = LoggedCondition('test', log_interval=.1)
progress = 0
executed = []
def wait_for_progress_to(progress_to):
cond.wait_for(lambda: progress_to <= progress, 'progress to %s',
progress_to)
executed.append(progress_to)
with concurrent(wait_for_progress_to,
10), concurrent(wait_for_progress_to,
20), concurrent(wait_for_progress_to, 30):
with patch("easypy.sync._logger") as _logger:
sleep(0.3)
assert any(c == call("%s - waiting for progress to %s", cond, 10)
for c in _logger.debug.call_args_list)
assert any(c == call("%s - waiting for progress to %s", cond, 20)
for c in _logger.debug.call_args_list)
assert any(c == call("%s - waiting for progress to %s", cond, 30)
for c in _logger.debug.call_args_list)
assert executed == []
with patch("easypy.sync._logger") as _logger:
with cond.notifying_all('setting progress to 10'):
progress = 10
assert [
c for c in _logger.debug.call_args_list if 'performed' in c[0][0]
] == [call("%s - performed: setting progress to 10", cond)]
with patch("easypy.sync._logger") as _logger:
sleep(0.3)
assert not any(c == call("%s - waiting for progress to %s", cond, 10)
for c in _logger.debug.call_args_list)
assert any(c == call("%s - waiting for progress to %s", cond, 20)
for c in _logger.debug.call_args_list)
assert any(c == call("%s - waiting for progress to %s", cond, 30)
for c in _logger.debug.call_args_list)
assert executed == [10]
with patch("easypy.sync._logger") as _logger:
with cond.notifying_all('setting progress to 30'):
progress = 30
assert [
c for c in _logger.debug.call_args_list if 'performed' in c[0][0]
] == [call("%s - performed: setting progress to 30", cond)]
with patch("easypy.sync._logger") as _logger:
sleep(0.3)
assert not any(c == call("%s - waiting for progress to %s", cond, 10)
for c in _logger.debug.call_args_list)
assert not any(c == call("%s - waiting for progress to %s", cond, 20)
for c in _logger.debug.call_args_list)
assert not any(c == call("%s - waiting for progress to %s", cond, 30)
for c in _logger.debug.call_args_list)
assert executed == [10, 20, 30] or executed == [10, 30, 20]
with patch("easypy.sync._logger") as _logger:
with pytest.raises(TimeoutException):
cond.wait_for(lambda: False, 'the impossible', timeout=1)
assert sum(c == call("%s - waiting for the impossible", cond)
for c in _logger.debug.call_args_list) > 3
def test_call_concurrent_timeout():
c = concurrent(sleep, 1, threadname='sleep')
with pytest.raises(TimeoutError):
c(timeout_=0.1)
def test_rwlock():
main_ctrl = threading.Event()
reader_ctrl = threading.Event()
writer_ctrl = threading.Event()
lock = RWLock("test")
state = Bunch(reading=False, writing=False)
def read():
logging.info("Before read")
reader_ctrl.wait()
reader_ctrl.clear()
with lock:
logging.info("Reading...")
state.reading = True
main_ctrl.set()
reader_ctrl.wait()
reader_ctrl.clear()
state.reading = False
logging.info("Done reading")
logging.info("After read")
def write():
logging.info("Before write")
writer_ctrl.wait()
writer_ctrl.clear()
with lock.exclusive():
logging.info("Writing...")
state.writing = True
main_ctrl.set()
writer_ctrl.wait()
writer_ctrl.clear()
state.writing = False
logging.info("Done writing")
logging.info("After write")
main_ctrl.set()
reader = concurrent(read, threadname='read')
writer = concurrent(write, threadname='write')
with reader, writer:
assert not state.reading and not state.writing
reader_ctrl.set()
main_ctrl.wait()
logging.info("lock acquired non-exclusively")
main_ctrl.clear()
assert state.reading and not state.writing
writer_ctrl.set()
logging.info("writer awaits exclusivity")
with lock:
assert state.reading and not state.writing
reader_ctrl.set()
main_ctrl.wait()
main_ctrl.clear()
logging.info("read lock released")
assert not state.reading and state.writing
writer_ctrl.set()
main_ctrl.wait()
main_ctrl.clear()
logging.info("write lock released")
assert not state.reading and not state.writing
def test_thread_stacks():
with concurrent(sleep, .1, threadname='sleep'):
print(get_thread_stacks().render())
