Ordering of modules on command line affects reported errors

[OddBloke]

Steps to reproduce

1. We see this on the cloud-init repo, and I haven't yet found a minimal reproducer, so:
   git clone https://github.com/canonical/cloud-init
2. We have inadvertently masked this in cloud-init master (so we never see the no-value-for-parameter error reported at all!), so reset our tree back to a point where this issue will reproduce:
   git reset --hard d10ce3ecf
3. Run pylint with a couple of (test) modules specified:
   pylint -j1 cloudinit.tests.test_util cloudinit.tests.test_conftest
4. Run pylint with the same modules specified, but in the other order:
   pylint -j1 cloudinit.tests.test_conftest cloudinit.tests.test_util

Current behavior

Different output for each run:

# pylint -j1 cloudinit.tests.test_util cloudinit.tests.test_conftest

--------------------------------------------------------------------
Your code has been rated at 10.00/10 (previous run: 10.00/10, +0.00)

# pylint -j1 cloudinit.tests.test_conftest cloudinit.tests.test_util
************* Module cloudinit.tests.test_conftest
cloudinit/tests/test_conftest.py:14: [E1120(no-value-for-parameter), TestDisableSubpUsage.test_typeerrors_on_incorrect_usage] No value for argument 'args' in function call

------------------------------------------------------------------
Your code has been rated at 9.82/10 (previous run: 9.82/10, +0.00)

Expected behavior

The same output for each run.

pylint --version output

pylint 2.6.0-dev1
astroid 2.4.1
Python 3.8.2 (default, Apr 27 2020, 15:53:34) 
[GCC 9.3.0]

but I have observed this on pylints back to what pip install pylint<2.1 gave me (with the same Python version), and reproduced in a xenial container to be sure:

pylint 2.3.1
astroid 2.4.1
Python 3.5.2 (default, Apr 16 2020, 17:47:17) 
[GCC 5.4.0 20160609]

[OddBloke]

I discovered this issue when trying to figure out why one particular environment in which we run pylint reports the error in test_conftest while no others do.

This feels like something to do with the ordering of tests within the processes that pylint is running: without -j1 on the reproducers, they pass and my guess is that's because each module is the only one running in a process (as I have more than a single core on my system).

[OddBloke]

By applying this diff:

diff --git a/pylint/lint/check_parallel.py b/pylint/lint/check_parallel.py
index 480dae73..4b5c2b25 100644
--- a/pylint/lint/check_parallel.py
+++ b/pylint/lint/check_parallel.py
@@ -65,6 +65,8 @@ def _worker_initialize(linter, arguments=None):
 def _worker_check_single_file(file_item):
     name, filepath, modname = file_item
 
+    print(multiprocessing.current_process(), name)
+
     _worker_linter.open()
     _worker_linter.check_single_file(name, filepath, modname)

I can see which workers are linting which file. And there's an interesting difference with -j2 passed and three modules. When test_conftest is the second module tested by a worker, we don't see the expected error:

$ pylint -j2 cloudinit.tests.test_util cloudinit.tests.test_gpg cloudinit.tests.test_conftest
<ForkProcess name='ForkPoolWorker-1' parent=1138189 started daemon> cloudinit.tests.test_util
<ForkProcess name='ForkPoolWorker-2' parent=1138189 started daemon> cloudinit.tests.test_gpg
<ForkProcess name='ForkPoolWorker-2' parent=1138189 started daemon> cloudinit.tests.test_conftest

but when it's the first module tested by a worker, then we do:

$ pylint -j2 cloudinit.tests.test_util cloudinit.tests.test_conftest cloudinit.tests.test_gpg
<ForkProcess name='ForkPoolWorker-1' parent=1138232 started daemon> cloudinit.tests.test_util
<ForkProcess name='ForkPoolWorker-2' parent=1138232 started daemon> cloudinit.tests.test_conftest
<ForkProcess name='ForkPoolWorker-2' parent=1138232 started daemon> cloudinit.tests.test_gpg
************* Module cloudinit.tests.test_conftest
cloudinit/tests/test_conftest.py:14: [E1120(no-value-for-parameter), TestDisableSubpUsage.test_typeerrors_on_incorrect_usage] No value for argument 'args' in function call
cloudinit/tests/test_conftest.py:14: [E1120(no-value-for-parameter), TestDisableSubpUsage.test_typeerrors_on_incorrect_usage] No value for argument 'args' in function call

[RemiCardona]

I have something like too (hopefully it's related and I'm not highjacking the issue)

$ pylint $opts pynar.access_control.rfid.serial
pynar/access_control/rfid/serial.py:148: [E1135(unsupported-membership-test), SerialReaderManager.initialize] Value 'exc.strerror' doesn't support membership test

------------------------------------------------------------------
Your code has been rated at 9.83/10 (previous run: 9.83/10, +0.00)

$ pylint $opts pynar
--------------------------------------------------------------------
Your code has been rated at 10.00/10 (previous run: 10.00/10, +0.00)

Then, trying to narrow it down (and after adding a bunch of prints to figure out what pylint was up to):

$ pylint $opts pynar.ws pynar.access_control

-------------------------------------------------------------------
Your code has been rated at 10.00/10 (previous run: 9.98/10, +0.02)

$ pylint $opts pynar.access_control pynar.ws
************* Module pynar.access_control.rfid.serial
pynar/access_control/rfid/serial.py:148: [E1135(unsupported-membership-test), SerialReaderManager.initialize] Value 'exc.strerror' doesn't support membership test

-----------------------------------
Your code has been rated at 9.98/10

I'm going to go further down the rabbit hole to figure out what in my sub-package pynar.ws is "breaking" the error in my other sub-package pynar.access_control.

[OddBloke]

OK, so I think I've worked out more of the underlying issue. And, unfortunately, it does involve digging into the cloud-init codebase a little, so bear with me.

cloudinit.util.subp is our wrapper around the subprocess stdlib module. It's called in a lot of places, and we want to be sure that during unit testing we won't accidentally shell out, so we monkey patch it in our common TestCase class, CiTestCase.

This monkeypatching means that pylint/astroid cannot infer a single type for util.subp (because it's defined/set in multiple places in the codebase with incompatible types). See the separate section below for how I reached this conclusion.

So I think there are two distinct problems here: (a) pylint cannot infer the type of util.subp in the cloud-init codebase, and (b) pylint sometimes does infer the type of util.subp, and whether it does is influenced by the order in which modules are passed to pylint and/or the order in which pylint chooses to process modules internally.

I don't think there's anything pylint can (or should) do to address (a); our codebase gives contradictory definitions for util.subp and that's the end of it. But I do think that (b) is a legitimate pylint issue: I would not expect the types pylint infers to differ based on the ordering of modules on the command line or, as we've seen, based on the order in which modules are processed internally.

Interesting Inference Investigation

With a breakpoint on astroid/inference.py:293, I can see a clear difference between the types inferred for each pylint invocation. With cloudinit.tests.test_conftest specified first, I see that util.subps type is being inferred based on only its definition in util.py:

ipdb> p list(owner.igetattr(self.attrname, context))                                                                                                                                                                                                                                      
[<FunctionDef.subp l.2014 at 0x7fb0bf1b77f0>]

And, as we would expect, this is the invocation that does report the error (because it is able to infer a type for util.subp and therefore correctly infer that we are calling it incorrectly).

With cloudinit.tests.test_util (which imports the module that performs the monkey-patching of util.subp) specified first, we can see that util.subps type is being inferred from the function definition but also a bunch of other things, some of which are Uninferable (_fake_subp is from the monkey-patching module so I infer the others are also):

p list(owner.igetattr(self.attrname, context))                                                                                                                                                                                                                                      
[<FunctionDef.subp l.2014 at 0x7f2f58fc5490>,
 <FunctionDef.subp l.2014 at 0x7f2f58fc5490>,
 Uninferable,
 <BoundMethod _fake_subp of cloudinit.tests.helpers.CiTestCase at 0x139841250223488,
 Uninferable,
 Uninferable]

And, also as we would expect at this point, this means that the error is not reported, because pylint isn't able to determine what the call signature for util.subp should be, and therefore can't tell us anything about how our usage of it differs from the signature.

[OddBloke]

An aside: we inadvertently "fixed" this in cloud-init master by adding an import of the monkey-patching module to test_conftest (which means that the type of util.subp is always inferred correctly as uninferrable, and so we never see the error). I've updated the description of the issue to include a step to git reset --hard to the last commit before the "fixing" change.

@RemiCardona I agree that your issue looks similar. That said, if you don't think that your issue is to do with inferred types changing based on the order in which modules are processed, then it's probably more appropriate as a separate issue.

[OddBloke]

A simpler reproducer that doesn't involve explicitly ordering modules on the CLI:

$ pylint -j1 cloudinit.tests

-------------------------------------------------------------------
Your code has been rated at 10.00/10 (previous run: 9.91/10, +0.09)

$ pylint -j16 cloudinit.tests
************* Module cloudinit.tests.test_conftest
cloudinit/tests/test_conftest.py:14: [E1120(no-value-for-parameter), TestDisableSubpUsage.test_typeerrors_on_incorrect_usage] No value for argument 'args' in function call

(Though note that this is not only an issue when multiprocessing, as the explicit ordering of modules with -j1 indicates.)

[RemiCardona]

I've opened another bug to reduce the noise here, but they could very well still be related, at least in part. Cheers.

[marcaurele]

We have a similar error when upgrading from 2.10.2 to 2.11.1 as we were using -j 0. The modules order is on our side strictly the same for each run.

With -j 0 we have from time to time (1 every 5 times approx.) an exception popping up E1135(unsupported-membership-test). If we change it to -j 1, I cannot reproduce the flaky error and have a constant correct linting result.

Isolating the version

While keeping the option -j 0 to use the parallel processing:

• downgrading to 2.11.0 does not help and the error comes up.
• downgrading to 2.10.2, the error does not show up after many runs and looks fine.

[Pierre-Sassoulas]

Closing as duplicate of #374 or #689