diff --git a/openhtf/core/phase_descriptor.py b/openhtf/core/phase_descriptor.py index fe510069..fb0f8af1 100644 --- a/openhtf/core/phase_descriptor.py +++ b/openhtf/core/phase_descriptor.py @@ -21,6 +21,8 @@ import collections import enum import inspect +import logging +import os.path import pdb from typing import Any, Callable, Dict, Iterator, List, Optional, Sequence, Set, Text, TYPE_CHECKING, Type, Union @@ -36,10 +38,13 @@ from openhtf.core import test_record import openhtf.plugs from openhtf.util import data +from openhtf.util import logs if TYPE_CHECKING: from openhtf.core import test_state # pylint: disable=g-import-not-at-top +_LOGGER = logging.getLogger(__name__) + class PhaseWrapError(Exception): """Error with phase wrapping.""" @@ -174,6 +179,8 @@ class PhaseDescriptor(phase_nodes.PhaseNode): Attributes: func: Function to be called (with TestApi as first argument). + func_location: Location of the function, as 'name at file:line' for + user-defined functions, or 'name ' for built-in functions. options: PhaseOptions instance. plugs: List of PhasePlug instances. measurements: List of Measurement objects. @@ -185,6 +192,29 @@ class PhaseDescriptor(phase_nodes.PhaseNode): """ func = attr.ib(type=PhaseCallableT) + func_location = attr.ib(type=Text) + + @func_location.default + def _func_location(self): + """Assigns this field assuming func is a function or callable instance.""" + obj = self.func + try: + name = obj.__name__ + except AttributeError: + try: + name = obj.__class__.__name__ + except AttributeError: + logs.log_once(_LOGGER.warning, + 'Cannot determine name of callable: %r', obj) + return '' + obj = obj.__class__ + try: + filename = os.path.basename(inspect.getsourcefile(obj)) + line_number = inspect.getsourcelines(obj)[1] + except TypeError: + return name + ' ' + return f'{name} at {filename}:{line_number}' + options = attr.ib(type=PhaseOptions, factory=PhaseOptions) plugs = attr.ib(type=List[base_plugs.PhasePlug], factory=list) measurements = attr.ib(type=List[core_measurements.Measurement], factory=list) diff --git a/openhtf/core/phase_executor.py b/openhtf/core/phase_executor.py index 9e9381f9..6c1139bc 100644 --- a/openhtf/core/phase_executor.py +++ b/openhtf/core/phase_executor.py @@ -310,11 +310,13 @@ def _execute_phase_once( override_result = None with self.test_state.running_phase_context(phase_desc) as phase_state: if subtest_rec: - self.logger.debug('Executing phase %s under subtest %s', - phase_desc.name, subtest_rec.name) + self.logger.debug('Executing phase %s under subtest %s (from %s)', + phase_desc.name, phase_desc.func_location, + subtest_rec.name) phase_state.set_subtest_name(subtest_rec.name) else: - self.logger.debug('Executing phase %s', phase_desc.name) + self.logger.debug('Executing phase %s (from %s)', phase_desc.name, + phase_desc.func_location) with self._current_phase_thread_lock: # Checking _stopping must be in the lock context, otherwise there is a # race condition: this thread checks _stopping and then switches to diff --git a/openhtf/core/test_executor.py b/openhtf/core/test_executor.py index 6457b6f9..8b9f80c5 100644 --- a/openhtf/core/test_executor.py +++ b/openhtf/core/test_executor.py @@ -327,10 +327,11 @@ def _execute_phase(self, phase: phase_descriptor.PhaseDescriptor, subtest_rec: Optional[test_record.SubtestRecord], in_teardown: bool) -> _ExecutorReturn: if subtest_rec: - self.logger.debug('Executing phase %s under subtest %s', phase.name, - subtest_rec.name) + self.logger.debug('Executing phase %s (from %s) under subtest %s', + phase.name, phase.func_location, subtest_rec.name) else: - self.logger.debug('Executing phase %s', phase.name) + self.logger.debug('Executing phase %s (from %s)', phase.name, + phase.func_location) if not in_teardown and subtest_rec and subtest_rec.is_fail: self.phase_executor.skip_phase(phase, subtest_rec) diff --git a/test/phase_descriptor_test.py b/test/phase_descriptor_test.py index 1397b9bf..72751359 100644 --- a/test/phase_descriptor_test.py +++ b/test/phase_descriptor_test.py @@ -133,7 +133,8 @@ def test_multiple_phases(self): phase = openhtf.PhaseDescriptor.wrap_or_copy(plain_func) second_phase = openhtf.PhaseDescriptor.wrap_or_copy(phase) for field in attr.fields(type(phase)): - if field.name == 'func': + if field.name in [openhtf.PhaseDescriptor.func.__name__, + openhtf.PhaseDescriptor.func_location.__name__]: continue self.assertIsNot( getattr(phase, field.name), getattr(second_phase, field.name))