LogCaptureTestCase: use almost non-blocking handling by getvalue/_is_logged (especially important in tests with waiting for logged via `assertLogged(..., wait=TO)`):

- try to acquire lock without blocking, if not possible - return cached/empty (max 5 times, otherwise do lock);
- minimized time of the lock of messages list;
- avoid sporadic dead-locking during cross lock together with lock within handling of self._strm.
pull/2034/head
sebres 7 years ago
parent 5f3ba289d6
commit f547a7c7b1

@ -640,7 +640,9 @@ class LogCaptureTestCase(unittest.TestCase):
def __init__(self, lazy=True): def __init__(self, lazy=True):
self._lock = threading.Lock() self._lock = threading.Lock()
self._val = None self._val = None
self._dirty = True
self._recs = list() self._recs = list()
self._nolckCntr = 0
self._strm = StringIO() self._strm = StringIO()
logging.Handler.__init__(self) logging.Handler.__init__(self)
if lazy: if lazy:
@ -650,10 +652,11 @@ class LogCaptureTestCase(unittest.TestCase):
"""Truncate the internal buffer and records.""" """Truncate the internal buffer and records."""
if size: if size:
raise Exception('invalid size argument: %r, should be None or 0' % size) raise Exception('invalid size argument: %r, should be None or 0' % size)
with self._lock:
self._strm.truncate(0)
self._val = None self._val = None
self._dirty = True
with self._lock:
self._recs = list() self._recs = list()
self._strm.truncate(0)
def __write(self, record): def __write(self, record):
msg = record.getMessage() + '\n' msg = record.getMessage() + '\n'
@ -664,29 +667,42 @@ class LogCaptureTestCase(unittest.TestCase):
def getvalue(self): def getvalue(self):
"""Return current buffer as whole string.""" """Return current buffer as whole string."""
with self._lock: # if cached (still unchanged/no write operation), we don't need to enter lock:
# cached: if not self._dirty:
if self._val is not None:
return self._val return self._val
# try to lock, if not possible - return cached/empty (max 5 times):
lck = self._lock.acquire(False)
if not lck: # pargma: no cover (may be too sporadic on slow systems)
self._nolckCntr += 1
if self._nolckCntr <= 5:
return self._val if self._val is not None else ''
self._nolckCntr = 0
self._lock.acquire()
# minimize time of lock, avoid dead-locking during cross lock within self._strm ...
try:
recs = self._recs
self._recs = list()
finally:
self._lock.release()
# submit already emitted (delivered to handle) records: # submit already emitted (delivered to handle) records:
for record in self._recs: for record in recs:
self.__write(record) self.__write(record)
self._recs = list()
# cache and return: # cache and return:
self._val = self._strm.getvalue() self._val = self._strm.getvalue()
self._dirty = False
return self._val return self._val
def handle(self, record): # pragma: no cover def handle(self, record): # pragma: no cover
"""Handle the specified record direct (not lazy)""" """Handle the specified record direct (not lazy)"""
with self._lock:
self._val = None
self.__write(record) self.__write(record)
self._dirty = True
def _handle_lazy(self, record): def _handle_lazy(self, record):
"""Lazy handle the specified record on demand""" """Lazy handle the specified record on demand"""
with self._lock: with self._lock:
self._val = None
self._recs.append(record) self._recs.append(record)
# logged - causes changed string buffer (signal by set _dirty):
self._dirty = True
def setUp(self): def setUp(self):

Loading…
Cancel
Save