openfisca / openfisca-core

OpenFisca core engine. See other repositories for countries-specific code & data.
https://openfisca.org
GNU Affero General Public License v3.0
168 stars 75 forks source link

AttributeError 'NoneType' object has no attribute 'tracer' on tests and package mismatch #1213

Open sandcha opened 1 month ago

sandcha commented 1 month ago

Hi there!

I really enjoy OpenFisca, but I recently encountered an issue.

Here is what a user did:

He installed openfisca-france (v167.1.0) and an other country package (like openfisca-country-template) and tried to run a YAML test:

[openfisca-france]$ openfisca test tests/formulas/age.yaml

Here is what we expected to happen:

We expected age.yaml execution result to be successful or to get an explicit error if the used command was not right.

Here is what actually happened:

AttributeError: 'NoneType' object has no attribute 'tracer' is raised on openfisca_core/tools/test_runner.py:262.

This error message is also disturbing in a context where we didn't ask for trace (aka openfisca test --verbose option).

🧐 See full stack trace... ```shell ============================================================================= test session starts ============================================================================= platform darwin -- Python 3.10.6, pytest-7.4.4, pluggy-1.5.0 rootdir: /Users/sch/dev/gitruc/openfisca-france configfile: setup.cfg collected 12 items tests/formulas/age.yaml ..F ================================================================================== FAILURES =================================================================================== ________________________________________________________________________________ test session _________________________________________________________________________________ self = def runtest(self): self.name = self.test.name if self.test.output is None: msg = f"Missing key 'output' in test '{self.name}' in file '{self.path}'" raise ValueError(msg) self.tax_benefit_system = _get_tax_benefit_system( self.baseline_tax_benefit_system, self.test.reforms, self.test.extensions, ) builder = SimulationBuilder() input = self.test.input period = self.test.period max_spiral_loops = self.test.max_spiral_loops verbose = self.options.get("verbose") aggregate = self.options.get("aggregate") max_depth = self.options.get("max_depth") performance_graph = self.options.get("performance_graph") performance_tables = self.options.get("performance_tables") try: builder.set_default_period(period) self.simulation = builder.build_from_dict(self.tax_benefit_system, input) except (VariableNotFound, SituationParsingError): raise except Exception as e: error_message = os.linesep.join( [str(e), "", f"Unexpected error raised while parsing '{self.path}'"] ) raise ValueError(error_message).with_traceback( sys.exc_info()[2] ) from e # Keep the stack trace from the root error if max_spiral_loops: self.simulation.max_spiral_loops = max_spiral_loops try: > self.simulation.trace = verbose or performance_graph or performance_tables E AttributeError: 'NoneType' object has no attribute 'trace' aggregate = False builder = input = {'age_en_mois': '40 * 12 + 6'} max_depth = None max_spiral_loops = None performance_graph = False performance_tables = False period = '2013-05' self = verbose = False ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/openfisca_core/tools/test_runner.py:259: AttributeError During handling of the above exception, another exception occurred: cls = , func = . at 0x114f01f30>, when = 'call' reraise = (, ) @classmethod def from_call( cls, func: "Callable[[], TResult]", when: "Literal['collect', 'setup', 'call', 'teardown']", reraise: Optional[ Union[Type[BaseException], Tuple[Type[BaseException], ...]] ] = None, ) -> "CallInfo[TResult]": """Call func, wrapping the result in a CallInfo. :param func: The function to call. Called without arguments. :param when: The phase in which the function is called. :param reraise: Exception or exceptions that shall propagate if raised by the function, instead of being wrapped in the CallInfo. """ excinfo = None start = timing.time() precise_start = timing.perf_counter() try: > result: Optional[TResult] = func() cls = duration = 0.00033788601285777986 excinfo = func = . at 0x114f01f30> precise_start = 186268.027533355 precise_stop = 186268.027871241 reraise = (, ) result = None start = 1721120428.403501 stop = 1721120428.4038389 when = 'call' ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/_pytest/runner.py:341: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ > lambda: ihook(item=item, **kwds), when=when, reraise=reraise ) ihook = item = kwds = {} ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/_pytest/runner.py:262: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = , kwargs = {'item': }, firstresult = False def __call__(self, **kwargs: object) -> Any: """Call the hook. Only accepts keyword arguments, which should match the hook specification. Returns the result(s) of calling all registered plugins, see :ref:`calling`. """ assert ( not self.is_historic() ), "Cannot directly call a historic hook - use call_historic instead." self._verify_all_args_are_provided(kwargs) firstresult = self.spec.opts.get("firstresult", False) if self.spec else False # Copy because plugins may register other plugins during iteration (#438). > return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult) firstresult = False kwargs = {'item': } self = ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/pluggy/_hooks.py:513: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = <_pytest.config.PytestPluginManager object at 0x114dcfd30>, hook_name = 'pytest_runtest_call' methods = [>] kwargs = {'item': }, firstresult = False def _hookexec( self, hook_name: str, methods: Sequence[HookImpl], kwargs: Mapping[str, object], firstresult: bool, ) -> object | list[object]: # called from all hookcaller instances. # enable_tracing will set its own wrapping function at self._inner_hookexec > return self._inner_hookexec(hook_name, methods, kwargs, firstresult) firstresult = False hook_name = 'pytest_runtest_call' kwargs = {'item': } methods = [>] self = <_pytest.config.PytestPluginManager object at 0x114dcfd30> ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/pluggy/_manager.py:120: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ hook_name = 'pytest_runtest_call' hook_impls = [>] caller_kwargs = {'item': }, firstresult = False def _multicall( hook_name: str, hook_impls: Sequence[HookImpl], caller_kwargs: Mapping[str, object], firstresult: bool, ) -> object | list[object]: """Execute a call into multiple python functions/methods and return the result(s). ``caller_kwargs`` comes from HookCaller.__call__(). """ __tracebackhide__ = True results: list[object] = [] exception = None only_new_style_wrappers = True try: # run impl and wrapper setup functions in a loop teardowns: list[Teardown] = [] try: for hook_impl in reversed(hook_impls): try: args = [caller_kwargs[argname] for argname in hook_impl.argnames] except KeyError: for argname in hook_impl.argnames: if argname not in caller_kwargs: raise HookCallError( f"hook call must provide argument {argname!r}" ) if hook_impl.hookwrapper: only_new_style_wrappers = False try: # If this cast is not valid, a type error is raised below, # which is the desired response. res = hook_impl.function(*args) wrapper_gen = cast(Generator[None, Result[object], None], res) next(wrapper_gen) # first yield teardowns.append((wrapper_gen, hook_impl)) except StopIteration: _raise_wrapfail(wrapper_gen, "did not yield") elif hook_impl.wrapper: try: # If this cast is not valid, a type error is raised below, # which is the desired response. res = hook_impl.function(*args) function_gen = cast(Generator[None, object, object], res) next(function_gen) # first yield teardowns.append(function_gen) except StopIteration: _raise_wrapfail(function_gen, "did not yield") else: res = hook_impl.function(*args) if res is not None: results.append(res) if firstresult: # halt further impl calls break except BaseException as exc: exception = exc finally: # Fast path - only new-style wrappers, no Result. if only_new_style_wrappers: if firstresult: # first result hooks return a single value result = results[0] if results else None else: result = results # run all wrapper post-yield blocks for teardown in reversed(teardowns): try: if exception is not None: teardown.throw(exception) # type: ignore[union-attr] else: teardown.send(result) # type: ignore[union-attr] # Following is unreachable for a well behaved hook wrapper. # Try to force finalizers otherwise postponed till GC action. # Note: close() may raise if generator handles GeneratorExit. teardown.close() # type: ignore[union-attr] except StopIteration as si: result = si.value exception = None continue except BaseException as e: exception = e continue _raise_wrapfail(teardown, "has second yield") # type: ignore[arg-type] if exception is not None: raise exception.with_traceback(exception.__traceback__) else: return result # Slow path - need to support old-style wrappers. else: if firstresult: # first result hooks return a single value outcome: Result[object | list[object]] = Result( results[0] if results else None, exception ) else: outcome = Result(results, exception) # run all wrapper post-yield blocks for teardown in reversed(teardowns): if isinstance(teardown, tuple): try: teardown[0].send(outcome) except StopIteration: pass except BaseException as e: _warn_teardown_exception(hook_name, teardown[1], e) raise else: _raise_wrapfail(teardown[0], "has second yield") else: try: if outcome._exception is not None: teardown.throw(outcome._exception) else: teardown.send(outcome._result) # Following is unreachable for a well behaved hook wrapper. # Try to force finalizers otherwise postponed till GC action. # Note: close() may raise if generator handles GeneratorExit. teardown.close() except StopIteration as si: outcome.force_result(si.value) continue except BaseException as e: outcome.force_exception(e) continue _raise_wrapfail(teardown, "has second yield") > return outcome.get_result() __tracebackhide__ = True args = [] caller_kwargs = {'item': } exception = AttributeError("'NoneType' object has no attribute 'tracer'") firstresult = False hook_impl = > hook_impls = [>] hook_name = 'pytest_runtest_call' only_new_style_wrappers = False outcome = res = results = [] teardown = (, >) teardowns = [(, >)] wrapper_gen = ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/pluggy/_callers.py:182: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = def get_result(self) -> ResultType: """Get the result(s) for this hook call. If the hook was marked as a ``firstresult`` only a single value will be returned, otherwise a list of results. """ __tracebackhide__ = True exc = self._exception if exc is None: return cast(ResultType, self._result) else: > raise exc.with_traceback(exc.__traceback__) __tracebackhide__ = True exc = AttributeError("'NoneType' object has no attribute 'tracer'") self = ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/pluggy/_result.py:100: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ hook_name = 'pytest_runtest_call' hook_impls = [>] caller_kwargs = {'item': }, firstresult = False def _multicall( hook_name: str, hook_impls: Sequence[HookImpl], caller_kwargs: Mapping[str, object], firstresult: bool, ) -> object | list[object]: """Execute a call into multiple python functions/methods and return the result(s). ``caller_kwargs`` comes from HookCaller.__call__(). """ __tracebackhide__ = True results: list[object] = [] exception = None only_new_style_wrappers = True try: # run impl and wrapper setup functions in a loop teardowns: list[Teardown] = [] try: for hook_impl in reversed(hook_impls): try: args = [caller_kwargs[argname] for argname in hook_impl.argnames] except KeyError: for argname in hook_impl.argnames: if argname not in caller_kwargs: raise HookCallError( f"hook call must provide argument {argname!r}" ) if hook_impl.hookwrapper: only_new_style_wrappers = False try: # If this cast is not valid, a type error is raised below, # which is the desired response. res = hook_impl.function(*args) wrapper_gen = cast(Generator[None, Result[object], None], res) next(wrapper_gen) # first yield teardowns.append((wrapper_gen, hook_impl)) except StopIteration: _raise_wrapfail(wrapper_gen, "did not yield") elif hook_impl.wrapper: try: # If this cast is not valid, a type error is raised below, # which is the desired response. res = hook_impl.function(*args) function_gen = cast(Generator[None, object, object], res) next(function_gen) # first yield teardowns.append(function_gen) except StopIteration: _raise_wrapfail(function_gen, "did not yield") else: > res = hook_impl.function(*args) __tracebackhide__ = True args = [] caller_kwargs = {'item': } exception = AttributeError("'NoneType' object has no attribute 'tracer'") firstresult = False hook_impl = > hook_impls = [>] hook_name = 'pytest_runtest_call' only_new_style_wrappers = False outcome = res = results = [] teardown = (, >) teardowns = [(, >)] wrapper_gen = ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/pluggy/_callers.py:103: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ item = def pytest_runtest_call(item: Item) -> None: _update_current_test_var(item, "call") try: del sys.last_type del sys.last_value del sys.last_traceback except AttributeError: pass try: item.runtest() except Exception as e: # Store trace info to allow postmortem debugging sys.last_type = type(e) sys.last_value = e assert e.__traceback__ is not None # Skip *this* frame sys.last_traceback = e.__traceback__.tb_next > raise e item = ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/_pytest/runner.py:177: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ item = def pytest_runtest_call(item: Item) -> None: _update_current_test_var(item, "call") try: del sys.last_type del sys.last_value del sys.last_traceback except AttributeError: pass try: > item.runtest() item = ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/_pytest/runner.py:169: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = def runtest(self): self.name = self.test.name if self.test.output is None: msg = f"Missing key 'output' in test '{self.name}' in file '{self.path}'" raise ValueError(msg) self.tax_benefit_system = _get_tax_benefit_system( self.baseline_tax_benefit_system, self.test.reforms, self.test.extensions, ) builder = SimulationBuilder() input = self.test.input period = self.test.period max_spiral_loops = self.test.max_spiral_loops verbose = self.options.get("verbose") aggregate = self.options.get("aggregate") max_depth = self.options.get("max_depth") performance_graph = self.options.get("performance_graph") performance_tables = self.options.get("performance_tables") try: builder.set_default_period(period) self.simulation = builder.build_from_dict(self.tax_benefit_system, input) except (VariableNotFound, SituationParsingError): raise except Exception as e: error_message = os.linesep.join( [str(e), "", f"Unexpected error raised while parsing '{self.path}'"] ) raise ValueError(error_message).with_traceback( sys.exc_info()[2] ) from e # Keep the stack trace from the root error if max_spiral_loops: self.simulation.max_spiral_loops = max_spiral_loops try: self.simulation.trace = verbose or performance_graph or performance_tables self.check_output() finally: > tracer = self.simulation.tracer E AttributeError: 'NoneType' object has no attribute 'tracer' aggregate = False builder = input = {'age_en_mois': '40 * 12 + 6'} max_depth = None max_spiral_loops = None performance_graph = False performance_tables = False period = '2013-05' self = verbose = False ../../../.local/share/virtualenvs/of167-debug/lib/python3.10/site-packages/openfisca_core/tools/test_runner.py:262: AttributeError =========================================================================== short test summary info =========================================================================== FAILED tests/formulas/age.yaml:: - AttributeError: 'NoneType' object has no attribute 'tracer' !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 1 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! ========================================================================= 1 failed, 2 passed in 0.12s ========================================================================= ```

Here is data (or links to it) that can help you reproduce this issue:

It's possible to "force" the issue by giving a country package different from the current directory and test module with, for example:

[openfisca-france]$ openfisca test tests/formulas/age.yaml -c openfisca_country_template

And I remember that when openfisca test needs to choose between multiple installed packages, its behavior is inherited from pytest. Looking into this line in openfisca-core might explain how it works under the hood.

Even if our use case is unconsistent (running a test of a module on a different module might be a kind of issue that we will never completely guess in openfisca-core), we might be able to give some hints to the user. A minimal one could be adding the name of the country package to the error message.

Context

I identify more as a:

sylvainipp commented 1 month ago

I think a good first step to avoid this error happening could be to add the --country-package command in the documentation (Running a test, end of the page). Another possibility is to force the use of the option if there are several openfisca packages in the environment to have an explicit error (until now, there is only a warning).

sandcha commented 1 month ago

@sylvainipp Do you remember how you ended up with 2 country packages in the same environment? Was it intentional or an unseen side effect of some documentation that you followed?

sylvainipp commented 1 month ago

I had first this kind of problem with openfisca-france-data, that requires to have also openfisca-france in the environment. And then, because of a test environment with several country packages, but intentionnally, and there is no reason to tackle this test case I think. I also needed openfisca-country-template to use some functionnality with openfisca-senegal, but I don't remember why exactly.

sandcha commented 1 month ago

I forgot that we already added a warning : WARNING:openfisca_core.scripts:Several country packages detected :openfisca_country_template, openfisca_france. Usingopenfisca_country_templateby default. To use another package, please use the --country-package option.

But it didn't show up in the example above (open "🧐 " section in the description above to see the full stack trace).

Here is a simple test on openfisca_country_template:

- name: test something
  period: 2023-01
  input: 
    accommodation_size: 20
  output:
    housing_allowance: 123

It displays the warning at the top of the trace with: openfisca test country-template/test_keynames.yaml In this context:

OpenFisca-Core             41.4.7
openfisca-country_template 7.1.1
OpenFisca-France           167.1.0
sylvainipp commented 1 month ago

The warning shows up at the beginning of the log, I think it wasn't on the screenshot but above (or at least, it was the case for me).