Skip to content

Instantly share code, notes, and snippets.

@dabeaz

dabeaz/bug.py

Created Jan 7, 2016
Embed
What would you like to do?
Diabolical bug involving code that behaves differently in a class decorator vs. a metaclass
# bug.py
def decorate(func):
print('Decorating', func.__name__)
return func
def wrap_methods(cls):
for name in vars(cls):
if name.startswith('f_'):
setattr(cls, name, decorate(getattr(cls, name)))
return cls
class Meta(type):
def __new__(meta, clsname, bases, methods):
cls = super(Meta, meta).__new__(meta, clsname, bases, methods)
wrap_methods(cls)
return cls
print('---- Class Decorator ----')
@wrap_methods
class Spam1(object):
def f_1(self): pass
def f_2(self): pass
def f_3(self): pass
def f_4(self): pass
def f_5(self): pass
def f_6(self): pass
def f_7(self): pass
def f_8(self): pass
print('---- Metaclass ----')
class Spam2(metaclass=Meta):
def f_1(self): pass
def f_2(self): pass
def f_3(self): pass
def f_4(self): pass
def f_5(self): pass
def f_6(self): pass
def f_7(self): pass
def f_8(self): pass
Runing the program, you get very different results for the two classes. The class decorator
version always does what's expected. Not so much for the metaclass.
For example:
bash % python3 bug.py
---- Class Decorator ----
Decorating f_4
Decorating f_8
Decorating f_7
Decorating f_3
Decorating f_6
Decorating f_2
Decorating f_5
Decorating f_1
---- Metaclass ----
Decorating f_4
Decorating f_3
Decorating f_5
Decorating f_2 # Notice: Where is f_7? It's gone!
Decorating f_1
Decorating f_6
Decorating f_8
Try running it again:
---- Class Decorator ----
Decorating f_3
Decorating f_7
Decorating f_5
Decorating f_1
Decorating f_8
Decorating f_6
Decorating f_4
Decorating f_2
---- Metaclass ----
Decorating f_3 # <<<<<<
Decorating f_7
Decorating f_1
Decorating f_3 # WHAT?!?! This was just wrapped above
Decorating f_5
Decorating f_8
Decorating f_6
Decorating f_4
Decorating f_2
So yes, you're iterating over the class dictionary, changing the value assigned to some of the keys,
and effectively seeing the dictionary "change size", dropping one or more keys or iterating over
the same key more than once. It randomly changes run-to-run. Code behaves differently depending
if it's invoked from a metaclass or not.
Enjoy!
@alexwlchan

This comment has been minimized.

Copy link

@alexwlchan alexwlchan commented Jan 7, 2016

Which version of Python 3 are you using? If I use 3.3.5, the bug stubbornly fails to reproduce. But if I use 3.4.1, it occurs within a handful of runs.

It may or may not be significant, but the order of "Decorating f_N" for the class and the metaclass always seems to be the same on 3.3.5; on 3.4.1, even when I don't see wonky output, the orders don't always match.


A little further prodding: if I print this hash inside the for loop:

 def wrap_methods(cls):
     for name in vars(cls):
+        print(' ' * 20 + hashlib.sha224(repr(vars(cls)).encode()).hexdigest())
         if name.startswith('f_'):
             setattr(cls, name, decorate(getattr(cls, name)))
     return cls

It stays the same within a class or metaclass run on 3.3.5. But on 3.4.1, it changes after the first "Decorating f_N" is printed. Further inspection shows that it's just the order of the keys changing; not the values. Why? I have no idea.

Yuck.

@andy-5

This comment has been minimized.

Copy link

@andy-5 andy-5 commented Jan 7, 2016

On newer versions of Python it can be made consistent between runs by using a fixed hash seed value:

$ PYTHONHASHSEED=1 python bug.py

see Python Docs

But that doesn't solve or explain the bug.

@AntoineCezar

This comment has been minimized.

Copy link

@AntoineCezar AntoineCezar commented Jan 7, 2016

Tried with Python 3.5.1, and I can reproduce the bug.

Wraping vars(cls) with dict or list solves the problem. So maybe mappingproxy is in cause?

@jdnier

This comment has been minimized.

Copy link

@jdnier jdnier commented Jan 7, 2016

It's curious, types.MappingProxy was added in Python 3.3, but the bug only seems to show up in >= 3.4, not in 3.3.5. For Python < 3.3 (including 2.7), vars(cls) returns a DictProxy instead of MappingProxy (which I verified for 2.7, 3.0, 3.1, and 3.2, courtesy of python.net having all those versions installed). I thought maybe the behavior appeared with the introduction of MappingProxy, but in 3.3.5 there's no problem. It seems the behavior changed in 3.4 and 3.5.

@ncoghlan

This comment has been minimized.

Copy link

@ncoghlan ncoghlan commented Jan 9, 2016

The DictProxy -> types.MappingProxy change in 3.3 wasn't a change to the underlying implementation, just a matter of exposing the existing C implemented type to Python code.

While I haven't been able to reproduce the problem myself, https://twitter.com/caleb_hattingh/status/685097945788592132 suggests that the problem is the iteration order of C.__dict__ changing unexpectedly in a way the runtime doesn't detect. Wrapping the iteration in dict or list then avoids the problem, as it copies the original key order to a new container, unaffected by any order changes in the original namespace. (Note: the behaviour Caleb shows there is the same key ordering change that @alexwichan mentioned in the initial comment)

@ncoghlan

This comment has been minimized.

Copy link

@ncoghlan ncoghlan commented Jan 9, 2016

A simpler reproducer that looks specifically for the change in the order of the class namespace keys: https://bitbucket.org/ncoghlan/misc/src/default/tinkering/ns_reordering_bug.py

That will pretty consistently print "Broken = True" whether run via import or directly at the command line.

Switching to the commented out metaclass-as-callable implementation means it consistently prints "Broken = False", suggesting the problem lies somewhere in the use of a subclass of type as the metaclass rather than type itself, even though the subclass should be using the same tp_new implementation.

@ncoghlan

This comment has been minimized.

Copy link

@ncoghlan ncoghlan commented Jan 9, 2016

I (or more accurately, my laptop) am currently running hg bisect between 3.4.0rc2 and 3.4.1 against the reproducer script above (as it seems the regression appeared between those two tags). However, without a 100% reliable reproducer, bisect may not work.

@ncoghlan

This comment has been minimized.

Copy link

@ncoghlan ncoghlan commented Jan 9, 2016

@ncoghlan

This comment has been minimized.

Copy link

@ncoghlan ncoghlan commented Jan 9, 2016

One potential consequence of that patch: it means that instances of subclasses of type would have started to attempt to share keys with instances of type, whereas previously key sharing would have been implicitly disabled for all classes with a custom metaclass.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment