Random fails - `ImportError: module '' not in sys.modules`

[mzebrak]

I ran into random failing tests when using the tavern plugin. It looks like there is a problem with its dependencies. Probably pykwalify

Unfortunately, I have not found any dependence on which to deduce why this is happening. Re-launching tests causes them to success in most cases, but during CI it is a problematic bug

The exception is raised from importlib/_bootstrap.py:588:

 with _ModuleLockManager(name):
        if sys.modules.get(name) is not module:
            msg = 'module {!r} not in sys.modules'.format(name)
            raise ImportError(msg, name=name)

here is the entire message:

cls = <class '_pytest.runner.CallInfo'>
func = <function call_runtest_hook.<locals>.<lambda> at 0x7fbab93a98b0>
when = 'call'
reraise = (<class '_pytest.outcomes.Exit'>, <class 'KeyboardInterrupt'>)
    @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()
../../../../.tox/tavern/lib/python3.8/site-packages/_pytest/runner.py:338: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
>       lambda: ihook(item=item, **kwds), when=when, reraise=reraise
    )
../../../../.tox/tavern/lib/python3.8/site-packages/_pytest/runner.py:259: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <_HookCaller 'pytest_runtest_call'>, args = ()
kwargs = {'item': <YamlItem XYZ>}, argname = 'item', firstresult = False
    def __call__(self, *args, **kwargs):
        if args:
            raise TypeError("hook calling supports only keyword arguments")
        assert not self.is_historic()

        # This is written to avoid expensive operations when not needed.
        if self.spec:
            for argname in self.spec.argnames:
                if argname not in kwargs:
                    notincall = tuple(set(self.spec.argnames) - kwargs.keys())
                    warnings.warn(
                        "Argument(s) {} which are declared in the hookspec "
                        "can not be found in this hook call".format(notincall),
                        stacklevel=2,
                    )
                    break

            firstresult = self.spec.opts.get("firstresult")
        else:
            firstresult = False

>       return self._hookexec(self.name, self.get_hookimpls(), kwargs, firstresult)
../../../../.tox/tavern/lib/python3.8/site-packages/pluggy/_hooks.py:265: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <_pytest.config.PytestPluginManager object at 0x7fbad5789d90>
hook_name = 'pytest_runtest_call'
methods = [<HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/builds/XYZ/.tox/tavern/lib/python3.8...est.threadexception' from '/builds/XYZ/.tox/tavern/lib/python3.8/site-packages/_pytest/threadexception.py'>>]
kwargs = {'item': <YamlItem XYZ>}, firstresult = False
    def _hookexec(self, hook_name, methods, kwargs, firstresult):
        # 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)
../../../../.tox/tavern/lib/python3.8/site-packages/pluggy/_manager.py:80: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
hook_name = 'pytest_runtest_call'
hook_impls = [<HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/builds/XYZ/.tox/tavern/lib/python3.8...est.threadexception' from '/builds/XYZ/.tox/tavern/lib/python3.8/site-packages/_pytest/threadexception.py'>>]
caller_kwargs = {'item': <YamlItem XYZ>}, firstresult = False
    def _multicall(hook_name, hook_impls, caller_kwargs, firstresult):
        """Execute a call into multiple python functions/methods and return the
        result(s).

        ``caller_kwargs`` comes from _HookCaller.__call__().
        """
        __tracebackhide__ = True
        results = []
        excinfo = None
        try:  # run impl and wrapper setup functions in a loop
            teardowns = []
            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:
                        try:
                            gen = hook_impl.function(*args)
                            next(gen)  # first yield
                            teardowns.append(gen)
                        except StopIteration:
                            _raise_wrapfail(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:
                excinfo = sys.exc_info()
        finally:
            if firstresult:  # first result hooks return a single value
                outcome = _Result(results[0] if results else None, excinfo)
            else:
                outcome = _Result(results, excinfo)

            # run all wrapper post-yield blocks
            for gen in reversed(teardowns):
                try:
                    gen.send(outcome)
                    _raise_wrapfail(gen, "has second yield")
                except StopIteration:
                    pass

>           return outcome.get_result()
../../../../.tox/tavern/lib/python3.8/site-packages/pluggy/_callers.py:60: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <pluggy._result._Result object at 0x7fbab9615a90>
    def get_result(self):
        """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
        if self._excinfo is None:
            return self._result
        else:
            ex = self._excinfo
>           raise ex[1].with_traceback(ex[2])
../../../../.tox/tavern/lib/python3.8/site-packages/pluggy/_result.py:60: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
hook_name = 'pytest_runtest_call'
hook_impls = [<HookImpl plugin_name='runner', plugin=<module '_pytest.runner' from '/builds/XYZ/.tox/tavern/lib/python3.8...est.threadexception' from '/builds/XYZ/.tox/tavern/lib/python3.8/site-packages/_pytest/threadexception.py'>>]
caller_kwargs = {'item': <YamlItem XYZ>}, firstresult = False
    def _multicall(hook_name, hook_impls, caller_kwargs, firstresult):
        """Execute a call into multiple python functions/methods and return the
        result(s).

        ``caller_kwargs`` comes from _HookCaller.__call__().
        """
        __tracebackhide__ = True
        results = []
        excinfo = None
        try:  # run impl and wrapper setup functions in a loop
            teardowns = []
            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:
                        try:
                            gen = hook_impl.function(*args)
                            next(gen)  # first yield
                            teardowns.append(gen)
                        except StopIteration:
                            _raise_wrapfail(gen, "did not yield")
                    else:
>                       res = hook_impl.function(*args)
../../../../.tox/tavern/lib/python3.8/site-packages/pluggy/_callers.py:39: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
item = <YamlItem XYZ>
    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
../../../../.tox/tavern/lib/python3.8/site-packages/_pytest/runner.py:174: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
item = <YamlItem XYZ>
    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()
../../../../.tox/tavern/lib/python3.8/site-packages/_pytest/runner.py:166: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <YamlItem XYZ>
    def runtest(self):
        # Do a deep copy because this sometimes still retains things from previous tests(?)
        self.global_cfg = copy.deepcopy(load_global_cfg(self.config))

        self.global_cfg.setdefault("variables", {})

        load_plugins(self.global_cfg)

        self.global_cfg["tavern_internal"] = {"pytest_hook_caller": self.config.hook}

        # INTERNAL
        # NOTE - now that we can 'mark' tests, we could use pytest.mark.xfail
        # instead. This doesn't differentiate between an error in verification
        # and an error when running the test though.
        xfail = self.spec.get("_xfail", False)

        try:
            fixture_values = self._load_fixture_values()
            self.global_cfg["variables"].update(fixture_values)

            call_hook(
                self.global_cfg,
                "pytest_tavern_beta_before_every_test_run",
                test_dict=self.spec,
                variables=self.global_cfg["variables"],
            )

>           verify_tests(self.spec)
../../../../.tox/tavern/lib/python3.8/site-packages/tavern/testutils/pytesthook/item.py:184: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
test_spec = {'test_name': 'XYZ', 'marks': ['patterntest'], 'includes': [{'name': 'Common test values', 'description': 'Common...unction': 'validate_response:compare_response_with_pattern', 'extra_kwargs': {'ignore_tags': '<bridge community>'}}}}]}
with_plugins = True
    def verify_tests(test_spec, with_plugins=True):
        """Verify that a specific test block is correct

        Todo:
            Load schema file once. Requires some caching of the file

        Args:
            test_spec (dict): Test in dictionary form

        Raises:
            BadSchemaError: Schema did not match
        """
        here = os.path.dirname(os.path.abspath(__file__))

        schema_filename = os.path.join(here, "tests.schema.yaml")
        schema = load_schema_file(schema_filename, with_plugins)

>       verify_generic(test_spec, schema)
../../../../.tox/tavern/lib/python3.8/site-packages/tavern/schemas/files.py:152: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
to_verify = {'test_name': 'XYZ', 'marks': ['patterntest'], 'includes': [{'name': 'Common test values', 'description': 'Common...unction': 'validate_response:compare_response_with_pattern', 'extra_kwargs': {'ignore_tags': '<bridge community>'}}}}]}
schema = {'name': 'Test schema', 'desc': 'Matches test blocks', 'schema;any_request_json': {'func': 'validate_request_json', 't... 'map', 'mapping': {'username': {'type': 'str', 'required': True}, 'password': {'type': 'str', 'required': False}}}}}}}
    def verify_generic(to_verify, schema):
        """Verify a generic file against a given schema

        Args:
            to_verify (dict): Filename of source tests to check
            schema (dict): Schema to verify against

        Raises:
            BadSchemaError: Schema did not match
        """
        logger.debug("Verifying %s against %s", to_verify, schema)

        here = os.path.dirname(os.path.abspath(__file__))
        extension_module_filename = os.path.join(here, "extensions.py")

>       verifier = core.Core(
            source_data=to_verify,
            schema_data=schema,
            extensions=[extension_module_filename],
        )
../../../../.tox/tavern/lib/python3.8/site-packages/tavern/schemas/files.py:99: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <pykwalify.core.Core object at 0x7fbab94ec820>, source_file = None
schema_files = []
source_data = {'test_name': 'XYZ', 'marks': ['patterntest'], 'includes': [{'name': 'Common test values', 'description': 'Common...unction': 'validate_response:compare_response_with_pattern', 'extra_kwargs': {'ignore_tags': '<bridge community>'}}}}]}
schema_data = {'name': 'Test schema', 'desc': 'Matches test blocks', 'schema;any_request_json': {'func': 'validate_request_json', 't... 'map', 'mapping': {'username': {'type': 'str', 'required': True}, 'password': {'type': 'str', 'required': False}}}}}}}
extensions = ['/builds/XYZ/.tox/tavern/lib/python3.8/site-packages/tavern/schemas/extensions.py']
strict_rule_validation = False, fix_ruby_style_regex = False
allow_assertions = False, file_encoding = None, schema_file_obj = None
data_file_obj = None
    def __init__(self, source_file=None, schema_files=None, source_data=None, schema_data=None, extensions=None, strict_rule_validation=False,
                 fix_ruby_style_regex=False, allow_assertions=False, file_encoding=None, schema_file_obj=None, data_file_obj=None):
        """
        :param extensions:
            List of paths to python files that should be imported and available via 'func' keywork.
            This list of extensions can be set manually or they should be provided by the `--extension`
            flag from the cli. This list should not contain files specified by the `extensions` list keyword
            that can be defined at the top level of the schema.
        """
        if schema_files is None:
            schema_files = []
        if extensions is None:
            extensions = []

        log.debug(u"source_file: %s", source_file)
        log.debug(u"schema_file: %s", schema_files)
        log.debug(u"source_data: %s", source_data)
        log.debug(u"schema_data: %s", schema_data)
        log.debug(u"extension files: %s", extensions)

        self.source = None
        self.schema = None
        self.validation_errors = None
        self.validation_errors_exceptions = None
        self.root_rule = None
        self.extensions = extensions
        self.errors = []
        self.strict_rule_validation = strict_rule_validation
        self.fix_ruby_style_regex = fix_ruby_style_regex
        self.allow_assertions = allow_assertions

        # Patch in all the normal python types into the yaml load instance so we can use all the
        # internal python types in the yaml loading.
        yml.constructor.add_constructor('tag:yaml.org,2002:python/bool', Constructor.construct_yaml_bool)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/complex', Constructor.construct_python_complex)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/dict', Constructor.construct_yaml_map)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/float', Constructor.construct_yaml_float)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/int', Constructor.construct_yaml_int)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/list', Constructor.construct_yaml_seq)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/long', Constructor.construct_python_long)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/none', Constructor.construct_yaml_null)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/str', Constructor.construct_python_str)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/tuple', Constructor.construct_python_tuple)
        yml.constructor.add_constructor('tag:yaml.org,2002:python/unicode', Constructor.construct_python_unicode)

        if data_file_obj:
            try:
                self.source = yml.load(data_file_obj.read())
            except Exception as e:
                raise CoreError("Unable to load data_file_obj input")

        if schema_file_obj:
            try:
                self.schema = yml.load(schema_file_obj.read())
            except Exception as e:
                raise CoreError("Unable to load schema_file_obj")

        if source_file is not None:
            if not os.path.exists(source_file):
                raise CoreError(u"Provided source_file do not exists on disk: {0}".format(source_file))

            with open(source_file, "r", encoding=file_encoding) as stream:
                if source_file.endswith(".json"):
                    self.source = json.load(stream)
                elif source_file.endswith(".yaml") or source_file.endswith('.yml'):
                    self.source = yml.load(stream)
                else:
                    raise CoreError(u"Unable to load source_file. Unknown file format of specified file path: {0}".format(source_file))

        if not isinstance(schema_files, list):
            raise CoreError(u"schema_files must be of list type")

        # Merge all schema files into one single file for easy parsing
        if len(schema_files) > 0:
            schema_data = {}
            for f in schema_files:
                if not os.path.exists(f):
                    raise CoreError(u"Provided source_file do not exists on disk : {0}".format(f))

                with open(f, "r", encoding=file_encoding) as stream:
                    if f.endswith(".json"):
                        data = json.load(stream)
                    elif f.endswith(".yaml") or f.endswith(".yml"):
                        data = yml.load(stream)
                        if not data:
                            raise CoreError(u"No data loaded from file : {0}".format(f))
                    else:
                        raise CoreError(u"Unable to load file : {0} : Unknown file format. Supported file endings is [.json, .yaml, .yml]")

                    for key in data.keys():
                        if key in schema_data.keys():
                            raise CoreError(u"Parsed key : {0} : two times in schema files...".format(key))

                    schema_data = dict(schema_data, **data)

            self.schema = schema_data

        # Nothing was loaded so try the source_data variable
        if self.source is None:
            log.debug(u"No source file loaded, trying source data variable")
            self.source = source_data
        if self.schema is None:
            log.debug(u"No schema file loaded, trying schema data variable")
            self.schema = schema_data

        # Test if anything was loaded
        if self.source is None:
            raise CoreError(u"No source file/data was loaded")
        if self.schema is None:
            raise CoreError(u"No schema file/data was loaded")

        # Merge any extensions defined in the schema with the provided list of extensions from the cli
        for f in self.schema.get('extensions', []):
            self.extensions.append(f)

        if not isinstance(self.extensions, list) and all(isinstance(e, str) for e in self.extensions):
            raise CoreError(u"Specified extensions must be a list of file paths")

>       self._load_extensions()
../../../../.tox/tavern/lib/python3.8/site-packages/pykwalify/core.py:153: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <pykwalify.core.Core object at 0x7fbab94ec820>
    def _load_extensions(self):
        """
        Load all extension files into the namespace pykwalify.ext
        """
        log.debug(u"loading all extensions : %s", self.extensions)

        self.loaded_extensions = []

        for f in self.extensions:
            if not os.path.isabs(f):
                f = os.path.abspath(f)

            if not os.path.exists(f):
                raise CoreError(u"Extension file: {0} not found on disk".format(f))

>           self.loaded_extensions.append(SourceFileLoader("", f).load_module())
../../../../.tox/tavern/lib/python3.8/site-packages/pykwalify/core.py:173: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <_frozen_importlib_external.SourceFileLoader object at 0x7fbab94ecb80>
name = '', args = (), kwargs = {}
>   ???
<frozen importlib._bootstrap_external>:522: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <_frozen_importlib_external.SourceFileLoader object at 0x7fbab94ecb80>
fullname = ''
>   ???
<frozen importlib._bootstrap_external>:1022: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <_frozen_importlib_external.SourceFileLoader object at 0x7fbab94ecb80>
fullname = ''
>   ???
<frozen importlib._bootstrap_external>:847: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <_frozen_importlib_external.SourceFileLoader object at 0x7fbab94ecb80>
fullname = ''
>   ???
<frozen importlib._bootstrap>:262: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
spec = ModuleSpec(name='', loader=<_frozen_importlib_external.SourceFileLoader object at 0x7fbab94ecb80>, origin='/builds/XYZ/.tox/tavern/lib/python3.8/site-packages/tavern/schemas/extensions.py')
module = <module '' from '/builds/XYZ/.tox/tavern/lib/python3.8/site-packages/tavern/schemas/extensions.py'>
>   ???
E   ImportError: module '' not in sys.modules
<frozen importlib._bootstrap>:589: ImportError
------ generated xml file: /builds/XYZ/api_smoketest_bridge.xml ------
=========================== short test summary info ============================
FAILED patterns/get_community/1.tavern.yaml::XYZ - ...
======================== 1 failed, 455 passed in 30.33s ========================

[michaelboulton]

That's a weird error, it looks like it may be some kind of race condition?