2.1.0 finds it suddenly unable to find the tasks directory

[gmmeyer]

I have a directory /tasks/*.py with a bunch of python files in it. With 2.1.0 I suddenly get the following error:

Traceback (most recent call last):
  File "/usr/local/bin/invoke", line 8, in <module>
    sys.exit(program.run())
  File "/usr/local/lib/python3.10/site-packages/invoke/program.py", line 387, in run
    self.parse_collection()
  File "/usr/local/lib/python3.10/site-packages/invoke/program.py", line 479, in parse_collection
    self.load_collection()
  File "/usr/local/lib/python3.10/site-packages/invoke/program.py", line 716, in load_collection
    module, parent = loader.load(coll_name)
  File "/usr/local/lib/python3.10/site-packages/invoke/loader.py", line 80, in load
    spec.loader.exec_module(module)
  File "<frozen importlib._bootstrap_external>", line 883, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "/code/tasks/__init__.py", line 3, in <module>
    from . import (
ModuleNotFoundError: No module named 'tasks'

It works perfectly in 2.0.0. It seems like there was a regression of some kind

[rberger]

We're seeing the same problem

inv --list
Traceback (most recent call last):
  File "/Users/rberger/.pyenv/versions/3.11.2/bin/inv", line 8, in <module>
    sys.exit(program.run())
             ^^^^^^^^^^^^^
  File "/Users/rberger/.pyenv/versions/3.11.2/lib/python3.11/site-packages/invoke/program.py", line 387, in run
    self.parse_collection()
  File "/Users/rberger/.pyenv/versions/3.11.2/lib/python3.11/site-packages/invoke/program.py", line 479, in parse_collection
    self.load_collection()
  File "/Users/rberger/.pyenv/versions/3.11.2/lib/python3.11/site-packages/invoke/program.py", line 716, in load_collection
    module, parent = loader.load(coll_name)
                     ^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/rberger/.pyenv/versions/3.11.2/lib/python3.11/site-packages/invoke/loader.py", line 80, in load
    spec.loader.exec_module(module)
  File "<frozen importlib._bootstrap_external>", line 940, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "/code/tasks/__init__.py", line 2, in <module>
    from . import install, utils
ModuleNotFoundError: No module named 'tasks'

[bitprophet]

Thanks for the reports! Almost certainly something to do with #919, except all our tests and CI pass (eg: https://app.circleci.com/pipelines/github/pyinvoke/invoke/288/workflows/9aa4cffc-8199-4158-ae94-cf29e1dd761d). I think the crux is:

I have a directory /tasks/*.py

I can confirm that this breaks in my one (personal) project using a tasks/ directory, but works everywhere else, so it's clearly specific to the package-not-module variant. We do have tests for that though, see eg this test and the package it should be loading.

@kuwv you got time to hunt this down? If not I will try to take a look early next week.

Anyone afflicted should have no problem temporarily pinning to invoke<2.1, 2.1 itself doesn't have anything super juicy in it.

[kuwv]

Unfortunately, I'm currently traveling at the moment. Soonest I'll be able get to it might be Wednesday.

[bitprophet]

Dug some (but also got sniped by adjacent issue that throws irritating test errors, now fixed). Already kind of cross as I blew half my freakin Saturday getting turned in circles with all this, but the upshot is:

• Issue may only be reproducible under Python 3.7 and up, certain versions of it don't error on 3.6
• Issue may be related to how the import machinery "looks" from inside a package's __init__.py since the actual proximate symptom is tasks/__init__.py trying to do eg from . import submodule.
  • IOW, simply having a tasks/__init__.py holding its own self contained tasks, and not doing any from-self imports, does not reproduce the error - though it's possible I saw this during the 3.6 vs 3.7 confusion so it needs a double check.

My offhand guess is either:

• something imp did supports this pattern, in a way that the new use of importlib does not, eg maybe imp was somehow performing path manipulation under the hood.
• something related to the upgrade incidentally broke this specific case (eg the logic being subtly reorganized within Loader.load around the sys.path.insert call, but I just triplechecked that and it looks safe; def needs some debug printouts to be sure though)

I will try taking a closer look early next week.

[bitprophet]

Moar dig:

• it's reproducible under 3.6, the main difference under 3.7 might be the exception class changed (which I think is mentioned somewhere in importlib docs). so hopefully just ignore that from above.
• sys.path munging is happening seemingly correctly (the 'task package' is being injected to 0th position)
• importlib is all new to me (not that I was an expert with imp either) but at a glance, the derived module spec seems accurate wrt its submodule_search_locations (it's a singleton list containing the tasks/ directory, as we would expect) and its origin (tasks/__init__.py)
• Annoyingly, trying to examine the issue with ipdb results in it not happening: both setting breakpoint just above the from . import module and calling next, and manually doing the import call via the ipdb REPL, work fine with no error.
• At this point in execution (both inside and outside ipdb), sys.path continues to look like it did earlier (which was from viewpoint of the loader).

So this is pretty weird. Will continue reading importlib's docs and/or seeing if this is somehow a stdlib bug (would be pretty damn weird if so, to exist for so long & in such a critical spot, people do from . imports all the time these days).

[bitprophet]

• sys.modules also not helping here, it does not contain the local tasks package before the import in any scenario.
  • when I can get the import to work under ipdb, both tasks and tasks.module (now renamed to tasks.wtf btw 😇) appear afterwards in sys.modules, but again, neither appear before then.
• Reverting from exec_module to the "legacy" load_module works great! so I guess that's the fallback plan for now...yes, it's deprecated, but it's still importlib instead of imp? 🙃
  • The resulting module object still looks the "same" as what we had before, eg its __path__ is identical to the 'new style' one's submodule_search_locations.
• The docs strongly imply that as long as your loader calls create_module followed by exec_module that "the import machinery does everything for you" but clearly there is some kind of gap here.
  • refactor: replace imp with importlib #919 leverages spec_from_file_location to get a spec, then stuffs that into module_from_spec, which is described as using create_module...so we should be compliant here?

[bitprophet]

https://docs.python.org/3/library/importlib.html#approximating-importlib-import-module implies we might be missing a step (or two) here, such as manually manipulating sys.modules. This does seem to work!

(As long as I don't fuck up and do that manipulation after the exec_module call instead of before...wasn't reading the example closely enough, but in hindsight it makes perfect sense, execution of the module-level code in our tasks file is what needs to 'see' the module?)

I'm a bit salty that this "new improved" importlib API still requires the user to do this, but I guess I also shouldn't fault other folks for "here's our new much more flexible API and also oops you still have to do some manual labor in corner cases that wasn't required before, sorry"...

---

So it looks like @kuwv missed this one spot when adapting that importlib example snippet to Invoke's loader classes. I'm going to put out a bugfix on this basis, assuming all the other tests pass for me afterwards...

[bitprophet]

In trying to get the unit test for this breaking properly, I found:

• the unit test wasn't doing any imports in its __init__.py (ie the only useful code of any sort is in package.module), so that's awkward. was that ever supposed to work? I don't think so...
• even with that fixed, the test still passes if I comment out the core fix.
  • strong implications that something in pytest land is papering over the issue somehow, even tho no other tests are loading up the package task tree.
• oho: no, if I put literal garbage in the submodule, a bunch of other tests also blow up, so something they are doing is incidentally importing package.module. so that's almost surely what is making this test incidentally pass (by accidentally warming up the cache in sys.modules), but is its own mystery.
  • Sure enough if I use pytest -k to select just the package test, it fails as we expect. God bless testing...
• aha! I was ready to blame pytest's assertion rewriting, but that is only proximately at fault - we're reusing this test fixture from inside another (more commonly used) one that tests namespacing. ugh. if I make a separate 'package test tree' so these two don't overlap, I bet we'll be good.