Class name detection fails for metaclass

[jayvdb]

green reports an error when running a test case which uses a metaclasses, and also reports the wrong name for the test class. (see __doc__ and green.result appearing below)

$ green -vvv tests.tools_tests
tests: max_retries reduced from 25 to 1
Green 2.0.7, Coverage 3.7, Python 2.7.5

tests.tools_tests
  ContextManagerWrapperTestCase
.   Check that the wrapper permits exceptions.
.   Create a test instance and verify the wrapper redirects.
.....
  __doc__
.   Test getargspec on args.
.   Test getargspec on kwargs.
.   Test getargspec on varargs.
.   Test getargspec on varkwargs.
.   Test getargspec on vars.
.....
green.result
  ProtoTestResult
.   Test getargspec on kwargs.
.   Test getargspec on varkwargs.
    errors[],Traceback (most recent call last):
  File "/usr/bin/green", line 9, in <module>
    load_entry_point('green==2.0.7', 'console_scripts', 'green')()
  File "/usr/lib/python2.7/site-packages/green/cmdline.py", line 75, in main
    result = run(test_suite, stream, args, testing)
  File "/usr/lib/python2.7/site-packages/green/runner.py", line 118, in run
    result.addProtoTestResult(proto_test_result)
  File "/usr/lib/python2.7/site-packages/green/result.py", line 337, in addProtoTestResult
    for test, err in proto_test_result.errors:
AttributeError: 'NoneType' object has no attribute 'errors'
<type 'exceptions.AttributeError'>
CRITICAL: Closing network session.

The top level entry __doc__ in the above is a metaclassed test class, and it is failing to get the class name/docstring correct, but otherwise works OK:
https://github.com/wikimedia/pywikibot-core/blob/master/tests/tools_tests.py#L521

Then the failure occurs on the 'next' test class, which inherits from the metaclass

https://github.com/wikimedia/pywikibot-core/blob/master/tests/tools_tests.py#L555

Returning to the __doc__ entry, I can fix that by sorting the names of the methods being created in __new__, e.g.

diff --git a/tests/tools_tests.py b/tests/tools_tests.py
index c58e33f..bdccb2f 100644
--- a/tests/tools_tests.py
+++ b/tests/tools_tests.py
@@ -506,7 +506,8 @@ class MetaTestArgSpec(MetaTestCaseClass):
                 self.assertNoDeprecation()
             return test_method

-        for name, tested_method in list(dct.items()):
+        for name in sorted(list(dct.keys())):
+            tested_method = dct[name]
             if name.startswith('_method_test_'):
                 suffix = name[len('_method_test_'):]
                 cls.add_method(dct, 'test_method_' + suffix,

causes the green output to be

...
  getargspec
.   Test getargspec on args.
.   Test getargspec on kwargs.
.   Test getargspec on varargs.
.   Test getargspec on varkwargs.
.   Test getargspec on vars.
...

[CleanCut]

I have never encountered metaclasses before today. It was fun to read up on them!

This section of the Python docs define how to create a testcase:

A testcase is created by subclassing unittest.TestCase. The three individual tests are
defined with methods whose names start with the letters test. This naming convention
informs the test runner about which methods represent tests.

Your metaclass subclasses unittest.TestCase (via several intermediate subclasses), which by definition makes your MetaClass a testcase according to built-in unittest.

I wouldn't be opposed to attempting to add a feature to green that omits metaclasses from discovery, but I can't find a way to detect whether a class is a metaclass in Python 3. In Python 2, it looks like I can just check for the presence of __metaclass__.

So...

• Lets find a way to detect whether a class is a metaclass in Python 3, or
• Don't subclass unittest.TestCase in your metaclasses, or
• Maybe there's another solution?

[xZise]

You misunderstood our structure. We provide a TestCase class which subclasses unittest.TestCase via TestCaseBase. And additionally it's using the MetaTestCaseClass metaclass which is the actual metaclass and that subclasses type. And the DeprecationTestCase class is not a metaclass but indirectly using it (via our TestCase).

Now I don't know what @jayvdb actually means with:

green reports an error when running a test case which uses a metaclasses[…]

As all our test cases use a class which uses MetaTestCaseClass as a metaclass at some point, but our tests never directly subclass that metaclass. Maybe he meant subclasses instead as TestPythonArgSpec does not define new tests but actually using TestArgSpec's tests.

[CleanCut]

@xZise Yep, I didn't read that quite right. Your metaclass is not subclassing unittest.TestCase. My bad. We'll have to figure out what the actual problem is here.

[jayvdb]

My limited analysis is that the underlying bug is in the "output name creation" process. The error is fixed when I change the names of the test methods, and even changing the order of the names helps.

[e3krisztian]

As an interested outsider I find it hard to understand this issue, even though I am using green with metaclassed TestCases (and had no problems so far). It would be helpful to understand what does the metaclass do or does not do that causes the problem.

@jayvdb / @xZise could you provide a reduced example (one stand-alone test file) that still reproduces and highlights what the problem is?

[xZise]

@krisztianfekete have you used subclasses as well?

[xZise]

Okay as you suggested I have tried to reduce the example drastically in https://gist.github.com/xZise/4f9e70910b020e2664ac

You just need to install green and download those 4 files and execute:

• green -vvv tools_tests
• python -m unittest -v tools_tests

The latter will work while the former will not work on Python 2.7. On Python 3.5 it does actually work. And please note that part of the code isn't actually valid (missing classes or imports) but they are never executed in the environment of the code. I'm trying to find more code which is not necessary.

[e3krisztian]

@xZise Thanks for trimming down the problem, I can reproduce now.

@CleanCut I think it is related to the protocol on the queues between the runner and processes, but do not understand what's going on. I have tried to instrument green/process.py by putting ddebug() calls before queue.put calls and here are the results on https://gist.github.com/xZise/4f9e70910b020e2664ac :

$ python -sm green tools_tests.py
(19210): start_callback:274 tools_tests.__doc__.test_method_vars 
(19210): finalize_callback:280 errors[], expectedFailures[], failures[], passing[<green.result.ProtoTest instance at 0x7f491c91e320>], skipped[], unexpectedSuccesses[] 
.(19210): finalize_callback:280 errors[], expectedFailures[], failures[], passing[<green.result.ProtoTest instance at 0x7f491c91e3f8>], skipped[], unexpectedSuccesses[] 
(19210): cleanup:252 None 
Traceback (most recent call last):
  File "/usr/lib/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/home/kr/projects/green/green/__main__.py", line 7, in <module>
    sys.exit(main())
  File "/home/kr/projects/green/green/cmdline.py", line 75, in main
    result = run(test_suite, stream, args, testing)
  File "/home/kr/projects/green/green/runner.py", line 118, in run
    result.addProtoTestResult(proto_test_result)
  File "/home/kr/projects/green/green/result.py", line 337, in addProtoTestResult
    for test, err in proto_test_result.errors:
AttributeError: 'NoneType' object has no attribute 'errors'

When uncommenting these two lines (38-39): https://gist.github.com/xZise/4f9e70910b020e2664ac#file-tools_tests-py-L38 it runs like this:

$ python -sm green tools_tests.py
(19379): start_callback:274 tools_tests.__doc__.test_example 
(19379): finalize_callback:280 errors[], expectedFailures[], failures[], passing[<green.result.ProtoTest instance at 0x7f521bb57488>], skipped[], unexpectedSuccesses[] 
.(19379): start_callback:274 tools_tests.__doc__.test_method_vars 
(19379): finalize_callback:280 errors[], expectedFailures[], failures[], passing[<green.result.ProtoTest instance at 0x7f521bb574d0>], skipped[], unexpectedSuccesses[] 
.(19379): finalize_callback:280 errors[], expectedFailures[], failures[], passing[<green.result.ProtoTest instance at 0x7f521bb575f0>], skipped[], unexpectedSuccesses[] 
(19379): finalize_callback:280 errors[], expectedFailures[], failures[], passing[<green.result.ProtoTest instance at 0x7f521bb575a8>], skipped[], unexpectedSuccesses[] 
.(19379): cleanup:252 None 


Ran 3 tests in 0.109s

OK (passes=3)

Note: the number of tests thought to be run in the latter case is wrong as well: it should be 4!

[CleanCut]

Found it! This one was really tricky.

Short version: Your for loop messed up your later call to super in MetaTestArgSpec.__new__()

Long version:

Green assumed that you can't have two classes of the same name in the same module, since that's syntactically impossible in raw source code (the second definition would simply overwrite the first). We were using this "fact" to ensure we didn't double-run things by checking the string value of our class name.

Green was dying at this check. It's a sanity check -- it shouldn't ever happen. So I started tracing backwards. How were we getting two identical classes??

I checked the class names of the testcase objects (the actual value of .__class__.__name__). For both TestArgSpec and TestPythonArgSpec it was ending up as tools_tests.__doc__ ... which is just bizarre.

So I started looking into MetaTestArgSpec.__new__() and found that you pass in name:

def __new__(cls, name, bases, dct):

and then you use name in your loop:

    for name, tested_method in list(dct.items()):

and finally you try to reuse name in your call to super, but the loop has already changed it (oops!)

    return super(MetaTestArgSpec, cls).__new__(cls, name, bases, dct)

The last value of name in the loop was __doc__, so the class name was ending up that way.

This is why python also showed the buggy behavior (strange, duplicate class names of tools_tests.__doc__ -- but built-in python just happened to not care what you did to the names, where green did.

You can fix it by either changing the loop variable or the __new__ argument.

[jayvdb]

Very big thank you!
Probably worth adding an assert somewhere in green to catch anyone doing something similar.

[jayvdb]

The bug was fixed on our side: https://gerrit.wikimedia.org/r/#/c/250940/ \o/

[CleanCut]

Great!