Edgewall Software
Modify

Opened 8 years ago

Closed 8 years ago

Last modified 6 years ago

#12352 closed enhancement (fixed)

Log a warning when interpreter optimization level is nonzero

Reported by: Ryan J Ollos Owned by: Ryan J Ollos
Priority: normal Milestone: 1.2
Component: general Version:
Severity: normal Keywords:
Cc: Branch:
Release Notes:
  • An EnvironmentError is raised when processing a request if the Python interpreter optimization level is nonzero.
  • An error code is returned and a message printed to the terminal when calling trac-admin in a Python process that has a nonzero optimization level.
API Changes:
Internal Changes:

Description

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

Attachments (0)

Change History (31)

comment:1 by Ryan J Ollos, 8 years ago

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

    diff --git a/trac/web/main.py b/trac/web/main.py
    index 84a881f..dfcbadb 100644
    a b class RequestDispatcher(Component):  
    391391        return resp
    392392
    393393
    394 _warn_setuptools = False
     394_initialization_checks = False
    395395_slashes_re = re.compile(r'/+')
    396396
    397397def dispatch_request(environ, start_response):
    def dispatch_request(environ, start_response):  
    401401    :param start_response: the WSGI callback for starting the response
    402402    """
    403403
    404     global _warn_setuptools
    405     if _warn_setuptools is False:
    406         _warn_setuptools = True
     404    global _initialization_checks
     405    if _initialization_checks is False:
    407406        warn_setuptools_issue(out=environ.get('wsgi.errors'))
    408407
     408        if sys.flags.optimize != 0:
     409            raise EnvironmentError(_("Python with optimizations enabled is not "
     410                                     "supported."))
     411        _initialization_checks = True
     412
    409413    # SCRIPT_URL is an Apache var containing the URL before URL rewriting
    410414    # has been applied, so we can use it to reconstruct logical SCRIPT_NAME
    411415    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.

Version 0, edited 8 years ago by Ryan J Ollos (next)

in reply to:  1 comment:2 by Ryan J Ollos, 8 years ago

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.

comment:3 by Jun Omae, 8 years ago

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.

comment:4 by Ryan J Ollos, 8 years ago

Owner: set to Ryan J Ollos
Status: newassigned

comment:5 by Ryan J Ollos, 8 years ago

Release Notes: modified (diff)

in reply to:  3 ; comment:6 by Ryan J Ollos, 8 years ago

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?

in reply to:  6 ; comment:7 by Jun Omae, 8 years ago

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.

in reply to:  7 ; comment:8 by Ryan J Ollos, 8 years ago

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.

in reply to:  8 comment:9 by Christian Boos, 8 years ago

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).

comment:10 by Ryan J Ollos, 8 years ago

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

in reply to:  3 comment:11 by Ryan J Ollos, 8 years ago

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.

comment:12 by Ryan J Ollos, 8 years ago

Release Notes: modified (diff)

comment:13 by Jun Omae, 8 years ago

The sys.flags is available since Python 2.6.

  File "/run/shm/0288adadc5aaed1f038d03fb7d89997b748675ec/py25-sqlite/trac/admin/console.py", line 575, in _run
    if sys.flags.optimize != 0:
AttributeError: 'module' object has no attribute 'flags'

comment:14 by Ryan J Ollos, 8 years ago

I guess we can just apply the change to 1.2dev then. The issue is rather rare anyway.

comment:15 by Ryan J Ollos, 8 years ago

Milestone: 1.0.111.2

in reply to:  10 comment:16 by Ryan J Ollos, 8 years ago

Replying to Ryan J Ollos:

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

See comment:27:ticket:6998.

in reply to:  3 comment:17 by Ryan J Ollos, 8 years ago

Replying to Jun Omae:

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

That makes sense. I misunderstood the issue when discussing in comment:11, and didn't see the issue previously because I was running tracd with -r.

comment:18 by Ryan J Ollos, 8 years ago

Resolution: fixed
Status: assignedclosed

Fixed on trunk in [14688].

comment:19 by Jun Omae, 8 years ago

Tests failing on AppVeyor CI, https://ci.appveyor.com/project/edgewall-org/trac/build/trunk.174/job/ai70ynepcidgde1s. It seems newline on Windows leads the failure.

comment:20 by Ryan J Ollos, 8 years ago

Resolution: fixed
Status: closedreopened

comment:21 by Ryan J Ollos, 8 years ago

Resolution: fixed
Status: reopenedclosed

Fixed in [14699].

comment:22 by Ryan J Ollos, 8 years ago

Release Notes: modified (diff)

comment:23 by Ryan J Ollos, 8 years ago

Refactoring in r15053, merged to trunk in r15054.

comment:24 by Ryan J Ollos, 7 years ago

Oddly, I get a test failure when Babel is not installed:

FAIL: test_python_with_optimizations_returns_error (trac.admin.tests.console.TracadminTestCase)
Error is returned when a command is executed in interpreter
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/rjollos/Documents/Workspace/trac-dev/teo-rjollos.git/trac/admin/tests/console.py", line 221, in test_python_with_optimizations_returns_error
    self.assertEqual(2, proc.returncode)
  File "/Users/rjollos/Documents/Workspace/trac-dev/teo-rjollos.git/trac/admin/tests/console.py", line 155, in assertEqual
    output, msg)
AssertionError: 2 != 1

I can reproduce from the command line:

$ python -O -m trac.admin.console
Traceback (most recent call last):
  File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 174, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/Users/rjollos/Documents/Workspace/trac-dev/teo-rjollos.git/trac/admin/console.py", line 651, in <module>
    sys.exit(run())
  File "/Users/rjollos/Documents/Workspace/trac-dev/teo-rjollos.git/trac/admin/console.py", line 642, in run
    translation.activate(get_console_locale())
  File "trac/admin/api.py", line 226, in get_console_locale
    return get_negotiated_locale(locales)
  File "trac/util/translation.py", line 360, in get_negotiated_locale
    normalize(available_locales))
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/core.py", line 218, in negotiate
    SVN_ERR_FS_NO_SUCH_STRING = _core.SVN_ERR_FS_NO_SUCH_STRING
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/core.py", line 287, in parse
    SVN_ERR_RA_OUT_OF_DATE = _core.SVN_ERR_RA_OUT_OF_DATE
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/core.py", line 272, in _try_load
    SVN_ERR_REPOS_LOCKED = _core.SVN_ERR_REPOS_LOCKED
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/core.py", line 166, in __init__
    SVN_ERR_WC_UNWIND_MISMATCH = _core.SVN_ERR_WC_UNWIND_MISMATCH
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/localedata.py", line 50, in exists
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/localedata.py", line 35, in normalize_locale
  File "/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/localedata.py", line 62, in locale_identifiers
OSError: [Errno 2] No such file or directory: '/Users/rjollos/Documents/Workspace/trac-dev/pve/lib/python2.7/site-packages/babel/locale-data'

It seems an ImportError is not raised when using -O:

$ python -O -c "from babel import Locale"
$ python -c "from babel import Locale"
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ImportError: No module named babel

comment:25 by Ryan J Ollos, 7 years ago

It seems there was a babel directory in site-packages, even though Babel was uninstalled using pip:

$ ls ../pve/lib/python2.7/site-packages/babel
__init__.pyo    dates.pyo       numbers.pyo     util.pyo
_compat.pyo     localedata.pyo  plural.pyo
core.pyo        localtime       support.pyo

After deleting that directory there is no test failure.

comment:26 by Ryan J Ollos, 7 years ago

It's a defect with pip, that the .pyo files are not uninstalled. The issue is claimed to be fixed, but does not seem to be fixed in pip 10.0.0dev.

Here's the behavior with pip 9.0.1 (same behavior with 10.0.0dev):

$ pip install requests
Collecting requests
  Using cached requests-2.14.1-py2.py3-none-any.whl
Installing collected packages: requests
Successfully installed requests-2.14.1
$ python -O -c "import requests"
$ pip uninstall requests
Uninstalling requests-2.14.1:
[...]
$ ls pve/lib/python2.7/site-packages/requests/
__init__.pyo            exceptions.pyo
_internal_utils.pyo     hooks.pyo
adapters.pyo            models.pyo
api.pyo                 packages
auth.pyo                sessions.pyo
certs.pyo               status_codes.pyo
compat.pyo              structures.pyo
cookies.pyo             utils.pyo

comment:27 by Ryan J Ollos, 7 years ago

Reported the issue for pip.

in reply to:  27 comment:28 by Ryan J Ollos, 6 years ago

Replying to Ryan J Ollos:

Reported the issue for pip.

The issue has been fixed on master and should be included in the next pip release (10.0.2 or 10.1, I would guess).

comment:29 by Ryan J Ollos, 6 years ago

Edited 1.3/TracModWSGI@2 to account for switch to Jinja2.

Also, edited WikiMacros@54 since running with optimizations is no longer allowed. However, macro documentation is no longer removed when running with -OO optimizations with introduction of cleandoc_ in r10617, so the issue would only be present for a plugin that doesn't use cleandoc_.

I don't see any reason to raise an error when running with Python optimizations on trunk. Proposed changes in [2c8f2cd28/rjollos.git]. Edits to 1.3/TracModWSGI and 1.3/TracModPython would also be needed.

in reply to:  29 comment:30 by Jun Omae, 6 years ago

Replying to Ryan J Ollos:

I don't see any reason to raise an error when running with Python optimizations on trunk. Proposed changes in [2c8f2cd28/rjollos.git]. Edits to 1.3/TracModWSGI and 1.3/TracModPython would also be needed.

I tested the proposed changes. Removing the check looks good to me.

comment:31 by Ryan J Ollos, 6 years ago

Thanks for the review. Reverted r14688, r14699 and r15053 on trunk in r16697.

Edited 1.3/TracModPython@2.

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Ryan J Ollos.
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from Ryan J Ollos to the specified user.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.