Log a warning when interpreter optimization level is nonzero

[Ryan J Ollos]

Documented in #8956 and recently raised in ​gmessage:trac-users:AQpVWTXVwsg/Rkey-2SHFQAJ, the header and footer are non displayed when Python interpreter optimizations are enabled.

The issue can be reproduced with TracStandalone using the PYTHONOPTIMIZE environment variable.

$PYTHONOPTIMIZE=1 tracd -r -s -p 8000 proj-1.0

The optimization level can be retrieved at runtime, so we could log a warning, raise an error or display the optimization level in the System Information on the About Trac page.

$python -OO
Python 2.7.11 (default, Dec  5 2015, 14:44:53) 
[GCC 4.2.1 Compatible Apple LLVM 7.0.0 (clang-700.1.76)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.flags.optimize
2
$python
Python 2.7.11 (default, Dec  5 2015, 14:44:53) 
[GCC 4.2.1 Compatible Apple LLVM 7.0.0 (clang-700.1.76)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.flags.optimize
0

[Ryan J Ollos]

I'm unsure of the best location to do this check. Here is a proposed patch, which puts the check next to warn_setuptools_issue:

trac/web/main.py

@@ -391 +391 @@
         return resp
 
 
-_warn_setuptools = False
+_initialization_checks = False
 _slashes_re = re.compile(r'/+')
 
 def dispatch_request(environ, start_response):
@@ -401 +401 @@
     :param start_response: the WSGI callback for starting the response
     """
 
-    global _warn_setuptools
-    if _warn_setuptools is False:
-        _warn_setuptools = True
+    global _initialization_checks
+    if _initialization_checks is False:
         warn_setuptools_issue(out=environ.get('wsgi.errors'))
 
+        if sys.flags.optimize != 0:
+            raise EnvironmentError("Python with optimizations enabled is not "
+                                   "supported.")
+        _initialization_checks = True
+
     # SCRIPT_URL is an Apache var containing the URL before URL rewriting
     # has been applied, so we can use it to reconstruct logical SCRIPT_NAME
     script_url = environ.get('SCRIPT_URL')

The EnvironmentError is used because it's also used here: tags/trac-1.0.10/trac/web/main.py@:486-490#L441​. However, this results in an empty response.

Another idea is to raise an exception in the Environment initializer.

[Ryan J Ollos]

Replying to Ryan J Ollos:

Another idea is to raise an exception in the Environment initializer.

I'm tending to favor this approach because I think the error message will be more clear.

[Jun Omae]

Raising an EnvironmentError sounds good. I consider we should check sys.flags.optimize every time rather than first time. If checking only first time, it might be ignored. Also, it would be good to add the same check to run() in trac/admin/console.py.

[Ryan J Ollos]

Replying to Jun Omae:

Also, it would be good to add the same check to run() in trac/admin/console.py.

Do you think we should raise an error there too, or just log a warning to the console?

[Jun Omae]

Also, it would be good to add the same check to run() in trac/admin/console.py.

Do you think we should raise an error there too, or just log a warning to the console?

I think trac-admin should raise an error and stop, if trac-admin doesn't work with non-zero optimization level. However, it seems trac-admin $ENV initenv at least works well with non-zero optimization level.

[Ryan J Ollos]

Replying to Jun Omae:

I think trac-admin should raise an error and stop, if trac-admin doesn't work with non-zero optimization level. However, it seems trac-admin $ENV initenv at least works well with non-zero optimization level.

I was thinking similarly. As far as I know the only problem seen with non-zero optimization level is when rendering templates. The result is missing content on the page, and it may just be a Genshi issue that will go away when we switch to Jinja2.

[Christian Boos]

Replying to Ryan J Ollos:

… and it may just be a Genshi issue that will go away when we switch to Jinja2.

JFYI, I run the tests on the Jinja2 branch and got 3 unit-tests failing:

======================================================================
ERROR: test_invalid_argument_raises (trac.tests.core.ComponentTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "d:\Trac\repos\trunk\trac\tests\core.py", line 363, in test_invalid_argument_raises
    self.assertRaises(AssertionError, Component)
  File "C:\Dev\Miniconda2-x64\lib\unittest\case.py", line 473, in assertRaises
    callableObj(*args, **kwargs)
  File "d:\Trac\repos\trunk\trac\core.py", line 134, in __call__
    compmgr = args[0]
IndexError: tuple index out of range

======================================================================
ERROR: test_invalid_nesting (trac.db.tests.api.WithTransactionTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "d:\Trac\repos\trunk\trac\db\tests\api.py", line 213, in test_invalid_nesting
    @with_transaction(env)
  File "d:\Trac\repos\trunk\trac\db\api.py", line 97, in transaction_wrapper
    fn(ldb)
  File "d:\Trac\repos\trunk\trac\db\tests\api.py", line 215, in level0
    @with_transaction(env, Connection())
  File "d:\Trac\repos\trunk\trac\db\api.py", line 91, in transaction_wrapper
    fn(db)
  File "d:\Trac\repos\trunk\trac\db\tests\api.py", line 217, in level1
    raise Error()
Error

======================================================================
FAIL: test_implements_called_outside_classdef (trac.tests.core.ComponentTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "d:\Trac\repos\trunk\trac\tests\core.py", line 154, in test_implements_called_outside_classdef
    self.fail('Expected AssertionError')
AssertionError: Expected AssertionError

----------------------------------------------------------------------

Actually, you'd get the same on trunk (see r14624).

[Ryan J Ollos]

Proposed changes in log:rjollos.git:t12352_warn_python_optimizations.

I noticed that return code was not being set in the shell. After [d9dd962b/rjollos.git], the return code is set.

$PYTHONOPTIMIZE=2 trac-admin help
Python with optimizations is not supported.
$echo $?
2

[Ryan J Ollos]

Replying to Jun Omae:

Raising an EnvironmentError sounds good. I consider we should check sys.flags.optimize every time rather than first time. If checking only first time, it might be ignored.

It appears it's not possible to change the Python optimization level without restarting the Python process and recompiling the byte code, so I'm not sure that it's really necessary to check sys.flags.optimize on every request. However, the changes I've proposed implement a check of sys.flags.optimize on every request in case there is something I've overlooked.