def pytest_exception_interact(self, node, call, report):
"""
Hook called when an exception raised and it can be handled. This hook
is only called if the exception is not an PyTest internal exception.
:param node: PyTest Function or Module object
:param call: PyTest CallInfo object
:param report: PyTest TestReport or CollectReport object
"""
if call.when in ('memocollect', 'collect'):
# Failed to collect tests: log to console and mark the report as
# ERROR.
self._report.logger.error(format_trace(
inspect.getinnerframes(call.excinfo.tb), call.excinfo.value))
self._report.status_override = Status.ERROR
elif self._current_case_report is not None:
# Log assertion errors or exceptions in testcase report
traceback = call.excinfo.traceback[-1]
message = getattr(call.excinfo.value, 'message', None) or \
getattr(call.excinfo.value, 'msg', None) or \
getattr(call.excinfo.value, 'args', None) or ''
if isinstance(message, (tuple, list)):
message = message[0]
header = (('Assertion - Fail' if
call.excinfo.typename == 'AssertionError' else
'Exception raised') if call.when == 'call' else
'{} - Fail'.format(call.when))
details = 'File: {}{}Line: {}{}{}: {}'.format(
traceback.path.strpath,
os.linesep,
traceback.lineno + 1,
os.linesep,
call.excinfo.typename,
message
) if call.excinfo.typename == 'AssertionError' else (
report.longreprtext if hasattr(report, 'longreprtext') else
str(report.longrepr))
assertion_obj = assertions.RawAssertion(
description=header,
content=details,
passed=False
)
serialized_obj = schema_registry.serialize(assertion_obj)
self._current_case_report.append(serialized_obj)
self._current_case_report.status_override = Status.FAILED
else:
self._report.logger.error(
'Exception occured outside of a testcase: during %s',
call.when)
self._report.logger.error(format_trace(
inspect.getinnerframes(call.excinfo.tb), call.excinfo.value))
def _loop(self):
"""
Main executor work loop - runs in a seperate thread when the Pool is
started.
"""
self.logger.debug('Starting worker monitor thread.')
self._worker_monitor = threading.Thread(target=self._workers_monitoring)
self._worker_monitor.daemon = True
self._worker_monitor.start()
while (self.active
and self.status.tag is not self.status.STOPPING
and self.status.tag is not self.status.STOPPED):
msg = self._conn.accept()
if msg:
try:
self.logger.debug('Received message from worker: %s.', msg)
with self._pool_lock:
self.handle_request(msg)
except Exception as exc:
self.logger.error(format_trace(inspect.trace(), exc))
time.sleep(self.cfg.active_loop_sleep)
def run(self):
"""Executes the defined steps and populates the result object."""
try:
if self.cfg.interactive is True:
if self._ihandler is not None:
raise RuntimeError('{} already has an active {}'.format(
self, self._ihandler))
self.logger.test_info(
'Starting {} in interactive mode'.format(self))
self._ihandler = self.cfg.interactive_handler(target=self)
thread = threading.Thread(target=self._ihandler)
thread.start()
# Check if we are on interactive session.
if self.cfg.interactive_block is True:
while self._ihandler.active:
time.sleep(self.cfg.active_loop_sleep)
return self._ihandler
else:
self._run_batch_steps()
except Exception as exc:
self._result.run = exc
self.logger.error(format_trace(inspect.trace(), exc))
else:
# TODO fix swallow exceptions in self._result.step_results.values()
self._result.run = self.status.tag == RunnableStatus.FINISHED and\
self.run_result() is True
return self._result
def _loop_process_work(self, curr_status):
"""
Poll for work based on the current pool state and process the next item
if there is one.
:return: Whether to continue the main work loop.
:rtype: ``bool``
"""
if curr_status == self.status.STARTING:
self.status.change(self.status.STARTED)
elif curr_status == self.status.STOPPING:
self.status.change(self.status.STOPPED)
return False # Indicate to break from the main work loop.
elif curr_status != self.status.STARTED:
raise RuntimeError('Pool in unexpected state {}'
.format(curr_status))
else:
msg = self._conn.accept()
if msg:
try:
self.logger.debug('Received message from worker: %s.',
msg)
self.handle_request(msg)
except Exception as exc:
self.logger.error(format_trace(inspect.trace(), exc))
# The main work loop can continue.
return True
def stop(self, reversed=False):
"""
Stop all resources in reverse order and log exceptions.
"""
resources = list(self._resources.values())
if reversed is True:
resources = resources[::-1]
# Stop all resources
for resource in resources:
if (resource.status.tag is None) or (resource.status.tag
== resource.STATUS.STOPPED):
# Skip resources not even triggered to start.
continue
try:
resource.stop()
except Exception as exc:
msg = 'While stopping resource [{}]{}{}'.format(
resource.cfg.name, os.linesep,
format_trace(inspect.trace(), exc))
self.stop_exceptions[resource] = msg
# Wait resources status to be STOPPED.
for resource in resources:
if resource in self.stop_exceptions:
continue
elif resource.status.tag is None:
# Skip resources not even triggered to start.
continue
else:
resource.wait(resource.STATUS.STOPPED)
def _run_loop(self):
"""Main work loop. Process incoming operations while we are RUNNING."""
while self.active and self.target.active:
if self.status.tag == RunnableStatus.RUNNING:
try:
uid = self._queue.pop(0)
operation, args, kwargs = self._operations[uid]
except IndexError:
time.sleep(self.cfg.active_loop_sleep)
else:
try:
try:
owner = '{}.{}, '.format(
self, operation.im_class.__name__)
except AttributeError:
owner = ''
self.logger.debug('Performing operation:{}{}'.format(
owner, operation.__name__))
start_time = time.time()
result = operation(*args, **kwargs)
self._results[uid] = result
self.logger.debug(
'Finished operation {}{} - {}s'.format(
owner, operation.__name__,
round(time.time() - start_time, 5)))
except Exception as exc:
self.logger.test_info(
format_trace(inspect.trace(), exc))
self._results[uid] = exc
finally:
del self._operations[uid]
def start(self):
"""
Start all resources sequentially and log errors.
"""
# Trigger start all resources
for resource in self._resources.values():
try:
resource.start()
if resource.cfg.async_start is False:
resource.wait(resource.STATUS.STARTED)
except Exception as exc:
msg = 'While starting resource [{}]{}{}'.format(
resource.cfg.name, os.linesep,
format_trace(inspect.trace(), exc))
self.logger.error(msg)
self.start_exceptions[resource] = msg
# Environment start failure. Won't start the rest.
break
# Wait resources status to be STARTED.
for resource in self._resources.values():
if resource in self.start_exceptions:
break
if resource.cfg.async_start is False:
continue
else:
resource.wait(resource.STATUS.STARTED)
def execute(self, task):
"""
Executes a task and return the associated task result.
:param task: Task that worker pulled for execution.
:type task: :py:class:`~testplan.runners.pools.tasks.base.Task`
:return: Task result.
:rtype: :py:class:`~testplan.runners.pools.tasks.base.TaskResult`
"""
try:
target = task.materialize()
if isinstance(target, Runnable):
if not target.parent:
target.parent = self
if not target.cfg.parent:
target.cfg.parent = self.cfg
result = target.run()
elif callable(target):
result = target()
else:
result = target.run()
except BaseException as exc:
task_result = TaskResult(task=task,
result=None,
status=False,
reason=format_trace(inspect.trace(), exc))
else:
task_result = TaskResult(task=task, result=result, status=True)
return task_result
def run_exporter(cls, exporter, source, type):
result = ExporterResult(exporter=exporter, type=type)
try:
exporter.export(source)
except Exception as exc:
result.traceback = format_trace(inspect.trace(), exc)
return result
def wrapper(*args, **kargs):
try:
func(*args, **kargs)
except Exception as exe:
msg = 'While executing {} of resource [{}]{}{}'.format(
func.__name__, resource.cfg.name, os.linesep,
format_trace(inspect.trace(), exe))
self.logger.error(msg)
self.start_exceptions[resource] = msg
def _execute_step(self, step, *args, **kwargs):
try:
res = step(*args, **kwargs)
except Exception as exc:
print('Exception on {} {}, step {} - {}'.format(
self.__class__.__name__, self.uid(), step.__name__, exc))
self.logger.error(format_trace(inspect.trace(), exc))
res = exc
finally:
self.result.step_results[step.__name__] = res
self.status.update_metadata(**{str(step): res})
def __exit__(self, exc_type, exc_value, tb):
if exc_type is not None and issubclass(exc_type,
self.exception_classes):
# Custom exception message with extra args
exc_msg = format_trace(inspect.trace(), exc_value)
self.report.logger.error(exc_msg)
if self.fail:
self.report.status_override = Status.ERROR
return True
def do_POST(self):
"""
Handle post requests.
"""
outer.logger.debug('path: {}'.format(self.path))
url = urlparse(self.path)
outer.logger.debug('url: {}'.format(url))
try:
try:
length = int(self.headers.get('content-length'))
except:
# No data in request.
request = {}
else:
request = {}
content = self.rfile.read(length).decode()
for key, value in json.loads(content).items():
if isinstance(value, six.string_types):
request[str(key)] = str(value)
else:
request[str(key)] = value
mode, method = self._extract_mode_method(self.path)
if mode not in self.MODES:
raise ValueError('Execution {} not valid: {}'.format(
mode, self.MODES))
if mode == 'sync':
result = self._sync(method, **request)
msg = 'Sync operation performed: {}'.format(method)
response = self._make_response(msg, result=result)
elif mode == 'async':
result = self._async(method, **request)
msg = 'Async operation performed: {}'.format(method)
response = self._make_response(msg, result=result)
elif mode == 'async_result':
res_dict = self._async_result(**request)
response = self._make_response(**res_dict)
self._header_json(
code=200 if not response['error'] else 400)
self._write_json(response)
except Exception as exc:
msg = '{} exception in do_POST: {}'.format(
outer.__class__.__name__, exc)
outer.logger.critical(msg)
response = self._make_response(message=msg,
error=True,
trace=format_trace(
inspect.trace()))
self._header_json(code=500)
self._write_json(response)
def _abort_entity(self, entity, wait_timeout=None):
"""Method to abort an entity and log exceptions."""
timeout = wait_timeout or self.cfg.abort_wait_timeout
try:
self.logger.debug('Aborting {}'.format(entity))
entity.abort()
self.logger.debug('Aborted {}'.format(entity))
except Exception as exc:
self.logger.error(format_trace(inspect.trace(), exc))
self.logger.error('Exception on aborting {} - {}'.format(
self, exc))
else:
if wait(lambda: entity.aborted is True, timeout) is False:
self.logger.error(
'Timeout on waiting to abort {}.'.format(self))
def run(self):
"""Executes the defined steps and populates the result object."""
try:
if self.cfg.interactive is True:
raise
else:
self._run_batch_steps()
except Exception as exc:
self._result.run = exc
self.logger.error(format_trace(inspect.trace(), exc))
else:
# TODO fix swallow exceptions in self._result.step_results.values()
self._result.run = self.status.tag == RunnableStatus.FINISHED and\
self.run_result() is True
return self._result
def _loop(self):
worker_monitor = threading.Thread(target=self._workers_monitoring)
worker_monitor.daemon = True
worker_monitor.start()
while self.active:
if self.status.tag == self.status.STARTING:
self.status.change(self.status.STARTED)
elif self.status.tag == self.status.STOPPING:
self.status.change(self.status.STOPPED)
break
else:
msg = self._conn.accept()
if msg:
try:
with self._pool_lock:
self.handle_request(msg)
except Exception as exc:
self.logger.error(format_trace(inspect.trace(), exc))
time.sleep(self.cfg.active_loop_sleep)
def __call__(self, *args, **kwargs):
self.status.change(RunnableStatus.RUNNING)
self.logger.test_info('Starting {} for {}'.format(
self.__class__.__name__, self.target))
if self._http_handler is not None:
self._start_http_handler()
while self.active and self.target.active:
if self.status.tag == RunnableStatus.RUNNING:
try:
uid = self._queue.pop(0)
operation, args, kwargs = self._operations[uid]
except IndexError:
time.sleep(self.cfg.active_loop_sleep)
else:
try:
try:
owner = '{}.{}, '.format(
self, operation.im_class.__name__)
except AttributeError:
owner = ''
self.logger.debug('Performing operation:{}{}'.format(
owner, operation.__name__))
start_time = time.time()
result = operation(*args, **kwargs)
self._results[uid] = result
self.logger.debug(
'Finished operation {}{} - {}s'.format(
owner, operation.__name__,
round(time.time() - start_time, 5)))
except Exception as exc:
self.logger.test_info(
format_trace(inspect.trace(), exc))
self._results[uid] = exc
finally:
del self._operations[uid]
self.status.change(RunnableStatus.FINISHED)
def worker_loop(self):
"""
Child process worker loop. Manages an underlying thread pool, pulls and
sends back results to the main pool.
"""
from testplan.runners.pools.communication import Message
from testplan.common.utils.exceptions import format_trace
message = Message(**self.metadata)
try:
self._pre_loop_setup(message)
except Exception as exc:
self._transport.send_and_receive(message.make(
message.SetupFailed,
data=format_trace(inspect.trace(), exc)), expect=message.Ack)
return
with self._child_pool():
if self._pool_cfg.worker_heartbeat:
self.heartbeat_setup()
message = Message(**self.metadata)
next_possible_request = time.time()
request_delay = self._pool_cfg.active_loop_sleep
while True:
if self._pool_cfg.worker_heartbeat and self._to_heartbeat <= 0:
hb_resp = self._transport.send_and_receive(message.make(
message.Heartbeat, data=time.time()))
if hb_resp is None:
self.logger.critical('Pool seems dead, child exits.')
self.exit_loop()
break
else:
self.logger.debug(
'Pool heartbeat response:'
' {} at {} before {}s.'.format(
hb_resp.cmd, hb_resp.data,
time.time() - hb_resp.data))
self._to_heartbeat = self._pool_cfg.worker_heartbeat
# Send back results
if self._pool.results:
task_results = []
for uid in list(self._pool.results.keys()):
task_results.append(self._pool.results[uid])
self.logger.debug('Sending back result for {}'.format(
self._pool.results[uid].task))
del self._pool.results[uid]
self._transport.send_and_receive(message.make(
message.TaskResults,
data=task_results), expect=message.Ack)
# Request new tasks
demand = self._pool.workers_requests() -\
len(self._pool.unassigned)
if demand > 0 and time.time() > next_possible_request:
received = self._transport.send_and_receive(message.make(
message.TaskPullRequest, data=demand))
if received is None or received.cmd == Message.Stop:
self.logger.critical('Child exits.')
self.exit_loop()
break
elif received.cmd == Message.TaskSending:
next_possible_request = time.time()
request_delay = 0
for task in received.data:
self.logger.debug('Added {} to local pool'.format(
task))
self._pool.add(task, task.uid())
# Reset workers request counters
for worker in self._pool._workers:
worker.requesting = 0
elif received.cmd == Message.Ack:
request_delay = min(
(request_delay + 0.2) * 1.5,
self._pool_cfg.max_active_loop_sleep)
next_possible_request = time.time() + request_delay
pass
time.sleep(self._pool_cfg.active_loop_sleep)
self.logger.info('Local pool {} stopped.'.format(self._pool))
def error_func(value):
try:
raise Exception('some message')
except Exception as exc:
error_ctx['msg'] = format_trace(inspect.trace(), exc)
raise
