Breezy 3.2.0+bzr7543-1 FTBFS

Looking at the build logs (https://launchpadlibrarian.net/543881602/buildlog_ubuntu-impish-amd64.breezy_3.2.0+bzr7543-1_BUILDING.txt.gz) I'm actually seeing a lot of issues regarding plugins.

test_plugins.TestDisablePlugin.test_partial_imports FAIL 4ms
    log: {{{
1138.617 loading plugins!
1138.618 using _Path('breezy.testingplugins', ['bad', 'ugly'], [], ['.'])
1138.618 Traceback (most recent call last):
  File "/<<BUILDDIR>>/breezy-3.2.0+bzr7543/breezy/plugin.py", line 429, in _load_plugin_module
    __import__(_MODULE_PREFIX + name)
ModuleNotFoundError: No module named 'breezy.testingplugins.good'

1138.618 Unable to load plugin 'good' from '.': No module named 'breezy.testingplugins.good'
 WARNING Unable to load plugin 'good' from '.': No module named 'breezy.testingplugins.good'
1138.619 removed breezy.testingplugins from sys.modules
1138.619 removed breezy.testingplugins.bad from sys.modules
1138.619 removed breezy.testingplugins.ugly from sys.modules
}}}

Traceback (most recent call last):
  File "/<<BUILDDIR>>/breezy-3.2.0+bzr7543/breezy/tests/test_plugins.py", line 718, in test_partial_imports
    self.assertEqual({'good'}, self.plugins.keys())
  File "/<<BUILDDIR>>/breezy-3.2.0+bzr7543/breezy/tests/__init__.py", line 1307, in assertEqual
    raise AssertionError("%snot equal:\na = %s\nb = %s\n"
AssertionError: not equal:
a = {'good'}
b = dict_keys([])

If I build python3.9.4 and run the tests with that, the tests pass, so it seems to be issues with 3.9.5. Looking into the changelog for 3.9.5, it seems that the new version of importlib is the likeliest candidate for the cause of this issue. I'm continuing to dig into breezy to try to resolve the incompatibility.

I've bisected python commits between a working and non-working version and https://github.com/python/cpython/commit/0af99b44edf559305def22b2d68be685ce50d7f6 seems to be the culprit

the Python commit was reverted in the 3.9.6 release. Does this still show up with 3.9.6?

I just checked out the cpython v3.9.6 tag and tested again with that, still getting errors like:

======================================================================
ERROR: breezy.tests.test_plugins.TestPlugins.test_test_suite_gives_test_suite_result
----------------------------------------------------------------------
Traceback (most recent call last):
testtools.testresult.real._StringException: log: {{{
1.776 loading plugins!
1.776 using _Path('breezy.testingplugins', [], [], ['.'])
1.776 Traceback (most recent call last):
  File "/root/brz/breezy/plugin.py", line 429, in _load_plugin_module
    __import__(_MODULE_PREFIX + name)
ModuleNotFoundError: No module named 'breezy.testingplugins.plugin'

1.776 Unable to load plugin 'plugin' from '.': No module named 'breezy.testingplugins.plugin'
 WARNING Unable to load plugin 'plugin' from '.': No module named 'breezy.testingplugins.plugin'
1.777 removed breezy.testingplugins from sys.modules
}}}

Traceback (most recent call last):
  File "/root/brz/breezy/tests/test_plugins.py", line 402, in test_test_suite_gives_test_suite_result
    p = plugin.plugins()['plugin']
KeyError: 'plugin'

For reference, I'm running:

    ./brz -Derror selftest -v -Oselftest.timeout=6000 breezy.tests.test_plugins.TestPlugins

which just failed with:

    FAILED (failures=2, errors=20)

Python version:

# python3
Python 3.9.6 (tags/v3.9.6:db3ff76da1, Jul 7 2021, 13:36:18)
[GCC 10.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.

I don't see any evidence this was reverted in 3.9.6 fwiw. Maybe you were thinking of a different change?

As Michael mentions, it's not clear to me that this was reverted in upstream python. I did a test against python 3.10.0b4 and 3.9.6 and was able to see the same problem in both.

The above line from Chris is a very efficient test case.
./brz -Derror selftest -v -Oselftest.timeout=6000 breezy.tests.test_plugins.TestPlugins

The python PR addresses https://bugs.python.org/issue43105,
which links to https://<email address hidden>/thread/DE3MDGB2JGOJ3X4NWEGJS26BK6PJUPKW/ ,
which talks about sys.path problems when using '.' as a method to reference CWD.

I'm testing this change, which makes the above TestPlugins pass but still has failures elsewhere

--- old/breezy/plugin.py 2020-07-28 02:11:05 +0000
+++ new/breezy/plugin.py 2021-07-26 22:50:14 +0000
@@ -154,6 +154,8 @@
     _install_importer_if_needed(extra_details)

     paths = _iter_plugin_paths(_env_plugin_path(), path)
+ # Workaround regression in py3.9.5 where '.' doesn't get treated as cwd
+ paths = [os.getcwd() if path == '.' else path for path in paths]

     return _Path(name, blocks, extra_details, paths)

Confirmed Dan's findings. His patch reduces the failure+error count significantly, but as he mentions a few issues remain, like:

1. ModuleNotFoundError: No module named 'breezy.testingplugins'

2. KeyError in _get_cmd_object

995.171 brz arguments: ['not-a-command']

Traceback (most recent call last):
  File "/home/bryce/pkg/Breezy/ubuntu-impish/breezy-3.2.1/breezy/commands.py", line 296, in get_cmd_object
    return _get_cmd_object(cmd_name, plugins_override)
  File "/home/bryce/pkg/Breezy/ubuntu-impish/breezy-3.2.1/breezy/commands.py", line 337, in _get_cmd_object
    raise KeyError
KeyError

3. ModuleNotFoundError: No module named 'breezy.testingplugins.test_foo'

4. ModuleNotFoundError: No module named 'breezy.testingplugins.brz-bad plugin-name'

Unable to load 'brz-bad plugin-name.' in '/tmp/testbzr-6co5pg3w.tmp/breezy.tests.test_plugins.TestLoadingPlugins.test_plugin_with_bad_name_does_not_load/work' as a plugin because the file path isn't a valid module name; try renaming it to 'bad_plugin_name_'.

5. '.' != CWD

a = "Unable to load plugin 'some_error' from '.': bad\n"
b = ("Unable to load plugin 'some_error' from "
 "'/tmp/testbzr-6co5pg3w.tmp/breezy.tests.test_plugins.TestLoadingPlugins.test_plugin_with_error/work': "
 'bad\n')

6. ModuleNotFoundError: No module named 'breezy.testingplugins.plugin'

983.683 Unable to load plugin 'plugin' from 'first': No module named 'breezy.testingplugins.plugin'
 WARNING Unable to load plugin 'plugin' from 'first': No module named 'breezy.testingplugins.plugin'
983.684 removed breezy.testingplugins from sys.modules

A couple failures are just because the test was expecting '.' in error messages but now is getting CWD. The other test failures aren't as obvious.

I've attached a patch that rolls these two fixes with Dan's.

I suspect the remaining issues are related, and stem from how the breezy.testingplugins module is created in test_plugins.py BaseTestPlugins.setUp(). This is a dynamically created module established in that routine via:

        self.module = types.ModuleType(self.module_name)
 self.overrideAttr(plugin, "_MODULE_PREFIX", self.module_prefix)
 self.overrideAttr(breezy, "testingplugins", self.module)
 sys.modules[self.module_name] = self.module

I wonder if whatever caused the '.' import to fail maybe results in this dynamic creation to fail as well?

The machinery here (BaseTestPlugins.reset() in particular) is also munging things and adjusting caches, which may play into the odd caching behavior Christian mentions in LP: #1937173

https://launchpad.net/ubuntu/+source/breezy/3.2.1-1ubuntu1 fixes the FTBFS due to test failures. (autopkgtest is still processing and may get stuck due to other packages.)

I think this is Fix Released now.