Conditional debug statement not executed though debug is True

Question

Short Version

I have a section of code I'm debugging that checks the value of __debug__ and executes some code if it is True.

if __debug__:
  <stuff happens>

The problem is that "stuff" never happens, even though __debug__ appears to be True.

Long Version / Details

To check this, I am printing out the values of several variables, most notably __debug__, to a file as the function executes, using the following pattern. (I am using os.open because open is already defined in this module.)

try:
  myfile = os.open("test.txt", os.O_RDWR|os.O_CREAT|os.O_APPEND)
  # work + some print statements to check the value of __DEBUG__
finally:
  os.close(myfile)

The piece of code I'm most confused by looks like this:

os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, __debug__))
os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, type(__debug__)))
os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, bool(__debug__)))
if __debug__:
  os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, __debug__))
if bool(__debug__):
  os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, __debug__))
if True:
  os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, __debug__))
if __debug__:
  os.write(myfile, "LINE %s | LDAP FUNCTION __DEBUG__: %s \n" %(sys._getframe(0).f_lineno, __debug__))

And the output file looks like this:

LINE 82 | LDAP FUNCTION __DEBUG__: True 
LINE 83 | LDAP FUNCTION __DEBUG__: <type 'bool'> 
LINE 84 | LDAP FUNCTION __DEBUG__: True 
LINE 88 | LDAP FUNCTION __DEBUG__: True 
LINE 90 | LDAP FUNCTION __DEBUG__: True

The first 3 statements (lines 82-84) are every way I could think of checking if __debug__ is "truthy", and all 3 imply that __debug__ is True. Similarly, casting __debug__ as a boolean and then evaluating if (line 88) works as expected too. Line 90 is a silly sanity check.

Is there anything I'm missing in the way __debug__ works that may be causing this?

Note: I found this while I was working through an error I am getting in the _ldap_function_call function in the python-ldap module. I only get this error when using IIS - everything works fine with Django's development server.

What version of Python is this? In 2.7 and 3.x, assigning to `__debug__` is a `SyntaxError`; in earlier 2.x versions `__debug__` wasn't a magic constant—but in 2.6, and a few versions before that (not sure how many), it is a magic constant, but you can rebind the name to something else, which leads to weirdness. — abarnert, Mar 09 '13 at 00:51
Maybe it's caused by something strange: I suspect .pyc/.pyo files. Does removing any .pyc/.pyo file help solve the problem? — Armin Rigo, Mar 09 '13 at 00:53
@abarnert: Ah. But the weirdness is still possible: http://bpaste.net/show/82378/ . turtlemonvh: either your code mangle `__debug__` in this way, or more likely, the context code does (python-ldap?). — Armin Rigo, Mar 09 '13 at 00:58
@ArminRigo: Ah, I was thinking more about `sys.modules[__name__].__debug__`, which is legal in 2.6 but not 2.7, and can cause symptoms exactly like what he's seeing. But you're right, `globals()['__debug__']` still works in 2.7, and it might cause the same problems. Let me check. — abarnert, Mar 09 '13 at 00:59
@ArminRigo I'm going to give deleting the *.pyc/*.pyo files a try and see what comes of that. Thank you both for the suggestions! — turtlemonvh, Mar 09 '13 at 20:51
I checked the `ldap` and `django-ldap` directories, and neither seems to reassign `__debug__`. I also deleted all .pyc/.pyo files in `ldap`, but I'm still getting the same behavior. — turtlemonvh, Mar 09 '13 at 21:09

abarnert · Accepted Answer · 2013-03-09T01:19:32.580

12

If you rebind __debug__, it can cause symptoms exactly like this.

This is because __debug__ is somewhat magical. During module compilation, the same code that handles literals also handles the magic constants ..., None, True, False, and __debug__. (See, for example, expr_constant.)

If you run dis on your code to dump out the bytecode, you'll see that if __debug__: statements are either removed entirely, or use LOAD_CONST to load the compile-time debug constant, while if bool(__debug__): statements use LOAD_GLOBAL to load the value of __debug__.

Of course these are guaranteed to be the same… unless you rebind __debug__. Somewhere around 2.3, it became illegal to just write __debug__ = False. In 2.7 and 3.0, it became illegal to bind any attribute named __debug__, which means you can no longer do things like sys.modules[__name__].__debug__ = False. But you can still do, e.g., globals()['__debug__'] = False.

And either way, you get the same effect:

if __debug__:
    print "debug"
if bool(__debug__):
    print "bool"

import sys
sys.modules[__name__].__debug__ = False

if __debug__:
    print "debug2"
if bool(__debug__):
    print "bool2"

This prints out:

debug
bool
debug2

And likewise for code that sets it to True when run with python -O.

edited Mar 09 '13 at 01:19

answered Mar 09 '13 at 01:04

abarnert

354,177
51
601
671

1

In 2.6-3.3, any rich comparison to `__debug__` will also trigger `LOAD_NAME` (in a module/class) or `LOAD_GLOBAL` (in a function). If you're running without `-O`, then the suite for `if __debug__` is inlined; otherwise it's omitted. I didn't see a `LOAD_CONST` used to test the debug state in any of my tests. Which Python version compiles it to `co_consts`? – Eryk Sun Mar 09 '13 at 06:53
@abarnert This sound like solid logic to me. I didn't find any place in the ldap-related modules where `__debug__` was modified, but I think that the [PyISAPIe library](http://sourceforge.net/apps/trac/pyisapie) I'm using to run django on IIS may be part of the issue. – turtlemonvh Mar 09 '13 at 21:48
@abarnet A related question - because of the pre-processing step, `if __debug__ and True:` != `if __debug__:`, right? I originally found this anomaly by breaking up `and`ed if statements into multiple statements and noticing this changed what errors I was getting. I'm guessing these are the same phenomena. – turtlemonvh Mar 09 '13 at 21:55
1

@turtlemonvh: The only way to be sure is to test. So, write `def foo(): if __debug__ and True: pass` and `def bar(): if __debug__: pass` and `dis.dis` each one. The first does `LOAD_GLOBAL` then `POP_JUMP_IF_FALSE` on each constant; the second just removes the comparison entirely (as eryksun pointed out). So yes, your guess is correct. – abarnert Mar 10 '13 at 02:13
1

@eryksun: I didn't test every version or read all of the relevant source, so I didn't want to say categorically that it always omits the test in every version. Even if there were a version that didn't omit the test, it would still be treated as a magic immutable literal, which means that assigning to `__debug__` would still lead to inconsistent behavior in different statements, exactly like the OP is seeing. But thanks for testing all 6 versions! – abarnert Mar 10 '13 at 02:18
Actually I didn't test 3.0 and 3.1, but I did check [`expr_constant`](http://hg.python.org/cpython/file/7395330e495e/Python/compile.c#l3020) in the 3.1.5 source (that's a tag link, so it should be rteliable). If it kept the test and ran the suite, then the OP would have output for lines 86 and 92, since `__debug__` is true -- unless there's a version that compiles a `__debug__` boolean constant into the code object. It seems silly, but you never know, which is why I asked. – Eryk Sun Mar 10 '13 at 06:49

Conditional __debug__ statement not executed though __debug__ is True

1 Answers1

Conditional debug statement not executed though debug is True