Bug 66025 - uno.py Importing bindings causes python to crash.
Summary: uno.py Importing bindings causes python to crash.
Status: RESOLVED FIXED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: sdk (show other bugs)
Version:
(earliest affected)
4.1.0.0.beta2
Hardware: x86-64 (AMD64) Linux (All)
: medium major
Assignee: David Bolen
URL:
Whiteboard: target:4.2.0 target:4.1.1 target:4.0.5
Keywords:
Depends on:
Blocks:
 
Reported: 2013-06-21 20:40 UTC by Tim Bentley
Modified: 2013-12-16 23:07 UTC (History)
7 users (show)

See Also:
Crash report or crash signature:


Attachments
Run Log file (68.08 KB, text/plain)
2013-06-22 13:30 UTC, Tim Bentley
Details
The value of name and x before the exception was raised. (1.11 KB, text/plain)
2013-06-22 13:32 UTC, Tim Bentley
Details
trace file (1.11 KB, text/plain)
2013-07-18 20:47 UTC, Tim Bentley
Details
Import handler patch (2.86 KB, patch)
2013-07-23 23:37 UTC, David Bolen
Details
Patch test script (398 bytes, text/x-python)
2013-07-23 23:38 UTC, David Bolen
Details
Patch test script output (6.44 KB, text/plain)
2013-07-23 23:38 UTC, David Bolen
Details
Patch correction (493 bytes, patch)
2013-07-24 08:38 UTC, David Bolen
Details
Patch without use of sentinel (2.15 KB, patch)
2013-07-24 11:22 UTC, David Bolen
Details
Final patch (4.16 KB, patch)
2013-07-26 20:09 UTC, David Bolen
Details
Updated test output for final patch (15.25 KB, text/plain)
2013-07-26 20:11 UTC, David Bolen
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Tim Bentley 2013-06-21 20:40:22 UTC
OpenLP 2.0 uses uno.py to access LibreOffice.
This worked fine for the 3.x series but for the 4.x this is crashing the OpenLP code.

The problem is that uno.py overrides the default import method and then triggers errors within the normal python code.

A local hack has been found to work but this is not a production fix.

In the _uno_import method comment out the exception raise!

    RuntimeException = pyuno.getClass( "com.sun.star.uno.RuntimeException" )
    for x in fromlist:
       if x not in d:
          if x.startswith( "typeOf" ):
             try:
                d[x] = pyuno.getTypeByName( name + "." + x[6:len(x)] )
             except RuntimeException as e:
                #raise ImportError( "type " + name + "." + x[6:len(x)] +" is unknown" )
                pass

This was causing code (not related to the libreoffice integration to fail.
Comment 1 Joel Madero 2013-06-21 21:04:42 UTC
Removing MAB - MAB MUST be confirmed and must be done independent of the original reporter unless your a developer on the project.
Comment 2 Tim Bentley 2013-06-22 06:21:14 UTC
I was requested to add the mad4.1 by Michael Meeks
Comment 3 Julien Nabet 2013-06-22 11:19:22 UTC
Indeed the code hasn't been changed for the moment, see http://opengrok.libreoffice.org/xref/core/pyuno/source/module/uno.py#281

Michael: do you confirm the patch? I could push the change but I don't know what could be the sideeffects.
Comment 4 Tim Bentley 2013-06-22 11:34:38 UTC
The patch was a hack to see if we could get the code working.
I would not confirm that it is correct or what the side effects would be.

All I can confirm is there is now a breakage in functionality!
Comment 5 Julien Nabet 2013-06-22 12:45:04 UTC
(In reply to comment #4)
> The patch was a hack to see if we could get the code working.
> I would not confirm that it is correct or what the side effects would be.
> 
> All I can confirm is there is now a breakage in functionality!
Thank you for your feedback Tim. Indeed the question was for Michael.

Could you reproduce the crash by adding some traces before this line?
d[x] = pyuno.getTypeByName( name + "." + x[6:len(x)] )

It could be very helpful to know the value of:
-name
-x
at the moment of the crash.
Comment 6 Tim Bentley 2013-06-22 13:30:25 UTC
Created attachment 81214 [details]
Run Log file

This log file shows the exceptions being called and the back trace.
Comment 7 Tim Bentley 2013-06-22 13:32:01 UTC
Created attachment 81215 [details]
The value of name and x before the exception was raised.

httpserver is part of Cherrypy

openlp classes are all our code.
Comment 8 Julien Nabet 2013-06-22 14:27:59 UTC
Tim: I know almost nothing in Python but perhaps you should start with these first errors in the logs:
2013-06-22 14:28:04,108 openlp.core.lib.pluginmanager                           DEBUG    Importing songsplugin from /home/tim/Projects/openlp/python3-productive/openlp/plugins/songs. Depth 10
2013-06-22 14:28:04,114 openlp.core.lib.pluginmanager                           ERROR    Failed to import module songsplugin on path /home/tim/Projects/openlp/python3-productive/openlp/plugins/songs/songsplugin.py: type openlp.core.lib.db.Manager is unknown
Traceback (most recent call last):
  File "/usr/lib64/python3.3/site-packages/uno.py", line 298, in _uno_import
    d[x] = pyuno.getClass( name + "." + x )
uno.com.sun.star.uno.RuntimeException: pyuno.getClass: uno exception openlp.core.lib.db.Manager is unknown

Anyway, you must know that LO has included Python 3.3 since LO 4.0 version. 
Is openlp code compliant with Python 3.3? If not perhaps this thread may help:
http://nabble.documentfoundation.org/ANNOUNCE-Python-3-3-is-now-bundled-with-LibreOffice-4-0-td4021038.html, I quote:
"however for a transition period of a few releases it will still be
possible to use a Python 2 version 2.6 or later, by explicitly setting
PYTHON, PYTHON_CFLAGS, PYTHON_LIBS variables.
"
Comment 9 Julien Nabet 2013-06-22 15:35:59 UTC
Just thought there could be a link with fdo#66031 put in see also.
Comment 10 Joel Madero 2013-06-22 18:06:55 UTC
Ah - in the future please put that in comments so QA knows, else we assume that you're just a user trying to push their own bug without following workflow. Orders from Michael definitely valid enough to put on MAB but the bug should still be confirmed first
Comment 11 Tim Bentley 2013-06-22 18:39:20 UTC
(In reply to comment #8)
> Tim: I know almost nothing in Python but perhaps you should start with these
> first errors in the logs:
> 2013-06-22 14:28:04,108 openlp.core.lib.pluginmanager                       
> DEBUG    Importing songsplugin from
> /home/tim/Projects/openlp/python3-productive/openlp/plugins/songs. Depth 10
> 2013-06-22 14:28:04,114 openlp.core.lib.pluginmanager                       
> ERROR    Failed to import module songsplugin on path
> /home/tim/Projects/openlp/python3-productive/openlp/plugins/songs/
> songsplugin.py: type openlp.core.lib.db.Manager is unknown
> Traceback (most recent call last):
>   File "/usr/lib64/python3.3/site-packages/uno.py", line 298, in _uno_import
>     d[x] = pyuno.getClass( name + "." + x )
> uno.com.sun.star.uno.RuntimeException: pyuno.getClass: uno exception
> openlp.core.lib.db.Manager is unknown
> 
> Anyway, you must know that LO has included Python 3.3 since LO 4.0 version. 
> Is openlp code compliant with Python 3.3? If not perhaps this thread may
> help:
> http://nabble.documentfoundation.org/ANNOUNCE-Python-3-3-is-now-bundled-with-
> LibreOffice-4-0-td4021038.html, I quote:
> "however for a transition period of a few releases it will still be
> possible to use a Python 2 version 2.6 or later, by explicitly setting
> PYTHON, PYTHON_CFLAGS, PYTHON_LIBS variables.
> "
Fedora only packages the 3.x version and we are trying to upgrade the OpenLP programme from python 2 to python 3.  The code has been working fine with LO 3.5/6 but these errors started when we swapped to python 3.
Comment 12 Julien Nabet 2013-06-22 18:59:26 UTC
Tim: I think you need to keep on the Python3 migration since LO uses it + Fedora doesn't seem to offer Python 2 (according what you said).
I noticed you use pylint in this page http://wiki.openlp.org/Development:Cleanup
pep8 might help you too.
If you need specific help for the interface with LO, don't hesitate to email the dev mailing list (see http://nabble.documentfoundation.org/Dev-f1639786.html) 

Michael/Joel: At this point, I don't know if this tracker shouldn't be considered as "NOTOURBUG". What do you think?
Comment 13 Michael Meeks 2013-06-27 11:07:35 UTC
Hi guys,

Yes - I did ask for this to be a MAB, but I guess we need more details here.

http://docs.python.org/3/reference/import.html#replacing-the-standard-import-system

Seems to suggest that it is correct for an __import__ hook to raise ImportError to allow processing of other hooks to continue - but I'm no expert here - I CC David Bolen who is though :-)

Tim - the values of name and 'x' - don't seem to start with 'typeOf':

          if x.startswith( "typeOf" ):
             try: 
                d[x] = pyuno.getTypeByName( name + "." + x[6:len(x)] )
             except RuntimeException as e:
                raise ImportError( "type " + name + "." + x[6:len(x)] +" is unknown" )

So I'm a tad confused by the first fragment. I guess that it comes from:

                   except RuntimeException as e3:
                      # no known uno type !
                      raise ImportError( "type "+ name + "." +x + " is unknown" )

ie. this is not an UNO type: which is fine of course - and AFAICS we should throw that exception.

That is presumably creates noise on the console - but ... it's unclear to me how to do better :-) [ but I'm no python guy ].
Comment 14 David Bolen 2013-06-27 21:17:02 UTC
Well, expert is a bit strong, but I do at least have some Python/LibO overlap...

Michael: The doc reference you made to raising ImportError to *prevent* further processing, but that paragraph also only applies to individual loaders on the meta path, whereas uno is doing a wholesale import replacement (the second paragraph in that section).  If it was being implemented now, an import loader as opposed to wholesale __import__ replacement would be cleaner (and avoid uno having to be concerned with default import behavior), but such a change now would require some caution to ensure all existing behavior is maintained, so the cost/benefit tradeoffs are unclear.

Tim: At first glance, I'm thinking the issue is not necessarily inside uno per se, but at the very least it's masking the original problem.  I'm guessing there is something causing a regular ImportError outside of LibreOffice in your environment for these imports.  While uno does do a wholesale import override, the first thing it always does is use the default Python import loader to try to process the import and only does extra processing if that fails.

I agree with Michael that your tracebacks (and name/x debug output) don't appear to match the location in your workaround patch.  But I don't think that's critical, since from what I can see, it appears uno.py can only reach any of those exceptions if the regular Python import machinery (via the _g_delegatee call to the original __import__ at the top of _uno_import) itself has raised an ImportError.  In such a case, the issue is then that any usage of the form "from xxx import yyy" must match a pre-existing imported module, or is assumed to be uno related, with corresponding exceptions.

For example:

> /opt/libreoffice4.1/program/python
Python 3.3.0 (default, Jun 18 2013, 17:24:23) 
[GCC 4.1.2 20080704 (Red Hat 4.1.2-54)] on linux
Type "help", "copyright", "credits" or "license" for more information.

(... first without uno ...)

>>> import foo  
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ImportError: No module named 'foo'

>>> from foo import bar
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ImportError: No module named 'foo'

(... next, with uno import override ...)

>>> import uno
>>> import foo
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "./uno.py", line 265, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
ImportError: No module named 'foo'

(... fails, but within the uno import function ...)

>>> from foo import bar
Traceback (most recent call last):
  File "./uno.py", line 292, in _uno_import
    d[x] = pyuno.getClass( name + "." + x )
uno.RuntimeException: pyuno.getClass: uno exception foo.bar is unknown

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./uno.py", line 296, in _uno_import
    d[x] = Enum( name , x )
  File "./uno.py", line 123, in __init__
    pyuno.checkEnum( self )
uno.RuntimeException: enum foo is unknown

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./uno.py", line 300, in _uno_import
    d[x] = getConstantByName( name + "." + x )
  File "./uno.py", line 48, in getConstantByName
    return pyuno.getConstantByName( constant )
uno.RuntimeException: foo.bar

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "./uno.py", line 303, in _uno_import
    raise ImportError( "type "+ name + "." +x + " is unknown" )
ImportError: type foo.bar is unknown
>>> 

Without knowing the original exception, it's hard to say whether uno is involved in the issue.  If you were to dump the ImportError exception from the original Python import call, you might get a hint as to the underlying failure, e.g.:

*** uno.py.orig 2013-06-18 18:53:44.000000000 -0400
--- uno.py      2013-06-27 16:32:03.000000000 -0400
***************
*** 269,273 ****
--- 269,278 ----
          if not fromlist:
              raise
+         print("--- Python import error --")
+         import traceback
+         traceback.print_exc()
+         print("--- Python import error --")
+ 
      modnames = name.split( "." )
      mod = None
      d = sys.modules

(Tweak as needed to get output in a way you can see it in your environment)

Alternatively, making uno's custom import processing more selective could help prevent masking non-uno imports, as in:

--- uno.py.orig 2013-06-18 18:53:44.000000000 -0400
+++ uno.py      2013-06-27 17:08:26.000000000 -0400
@@ -266,7 +266,7 @@
     except ImportError:
         # process optargs
         globals, locals, fromlist = list(optargs)[:3] + [kwargs.get('globals',{}), kwargs.get('locals',{}), kwargs.get('fromlist',[])][len(optargs):]
-        if not fromlist:
+        if not (name.startswith('com.sun.star.') and fromlist):
             raise
     modnames = name.split( "." )
     mod = None

I'm reasonably confident all uno imports will start with com.sun.star - certainly enough for this level of testing.

There may still be a dependency on some uno behavior that triggers or contributes to the issue, but seeing the underlying ImportError is probably a good next step towards figuring out where to look.
Comment 15 Petr Mladek 2013-07-04 15:21:04 UTC
I add Michael Stahl into CC who did the migration to python 3.3 in LO. He might have some ideas.

Anyway, the problem is specific to an extension. The initial comment suggests that it happens already with LO 4.0 but nobody reported it earlier. Such bugs can't block the release => lowering the severity a bit.
Comment 16 Andreas 2013-07-18 06:51:57 UTC
@ David Bolen:

I applied your changes to uno.py.

*** uno.py.orig 2013-06-18 18:53:44.000000000 -0400
--- uno.py      2013-06-27 16:32:03.000000000 -0400
***************
*** 269,273 ****
--- 269,278 ----
          if not fromlist:
              raise
+         print("--- Python import error --")
+         import traceback
+         traceback.print_exc()
+         print("--- Python import error --")
+ 
      modnames = name.split( "." )
      mod = None
      d = sys.modules

The output: http://pastebin.com/T6mEB519
And for completeness our debug log: http://pastebin.com/9zYJp6cR

Currently I have the second changed applied to be able to continue our python 2/3 migration.
Comment 17 David Bolen 2013-07-18 19:50:06 UTC
Tim: 

Ok, so at first glance I'm guessing that somewhere in your code base there's something like "from pygments.lexers.web import HtmlLexer" which is either (a) new, (b) used to handle the case of a missing pygments module but isn't under LO4+ or (c) the port to Py3 introduced a bug in handling the missing module case that interacts badly with existing LO behavior.

While LO (after an uno import) clearly affects the exact exception instance raised, in testing each of 3.6.6, 4.0.4 and 4.1.0, I don't really see any material difference in LO's behavior in this regard.  In each case the final exception remains an ImportError.

That is, code such as:

   try:
      from foo import bar
   except ImportError:
      pass

seems to work fine in plain Python, and each LO release with or without uno imported.

It is true that the text message in the exception differs from a regular Python ImportError, and also that with the shift to Py3 the exception has a "msg" attribute rather than "message".  But I wouldn't normally expect any parent code trying to trap an optional module import to depend on that (or if it did, it would be fragile itself across Python versions).

Can you perhaps locate the code attempting the import to see how it might be trying to trap the import failure (either itself or through a parent handler up the call chain)?  I've downloaded the OpenLP source for 2.0.1, the latest 2.2.2 and a python3-productive branch I found on launchpad, and can't seem to find any reference to pygments anywhere in the source tree?

Others:

It does feel wrong that simply importing uno changes future import errors (even if just subtly) from statements of the form of "from xxx import yyy".  

I did do some experiments switch to an import loader instead, but realized that the semantics differ enough as to potentially be an compatibility issue.  That is, the current implementation has characteristics of (a) working without needing intermediate "com", "com.sun", and "com.sun.star" modules and (b) working even if some other modules of those names are already imported.  The second case is particularly hard to do with a loader.  So sticking with the global import hook replacement seems safer.

However, I think my earlier patch at the end of comment 14 (which Tim is using) to at least constrain the namespace under which the uno-specific code runs seems like a plausible change, unless anyone is aware of anything accessed via uno not being under the "com.sun.star" namespace.
Comment 18 Tim Bentley 2013-07-18 20:26:23 UTC
We / I have never used pygments.
I have reinstalled libreoffice-pyuno to get a clean version and added 
the traceback code.  At that point OpenLP creashed looking for pygments so I needed to install that.  The it asked for PIL.

the last dump I got on a clean install running python 3 is 

21:02:53,275 openlp.core.lib.pluginmanager                           INFO     bootstrap_initialise
2013-07-18 21:02:53,276 openlp.core.lib.pluginmanager                           INFO     Finding plugins
2013-07-18 21:02:53,276 openlp.core.lib.pluginmanager                           DEBUG    finding plugins in /home/tim/Projects/openlp/python3-run/openlp/plugins at depth 8
2013-07-18 21:02:53,276 openlp.core.lib.pluginmanager                           DEBUG    Importing remoteplugin from /home/tim/Projects/openlp/python3-run/openlp/plugins/remotes. Depth 10
2013-07-18 21:02:53,304 openlp.core.lib.pluginmanager                           ERROR    Failed to import module remoteplugin on path /home/tim/Projects/openlp/python3-run/openlp/plugins/remotes/remoteplugin.py: type openlp.plugins.remotes.lib.RemoteTab is unknown
Traceback (most recent call last):
  File "/usr/lib64/python3.3/site-packages/uno.py", line 295, in _uno_import
    d[x] = pyuno.getClass( name + "." + x )
uno.com.sun.star.uno.RuntimeException: pyuno.getClass: uno exception openlp.plugins.remotes.lib.RemoteTab is unknown

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib64/python3.3/site-packages/uno.py", line 299, in _uno_import
    d[x] = Enum( name , x )
  File "/usr/lib64/python3.3/site-packages/uno.py", line 126, in __init__
    pyuno.checkEnum( self )
uno.com.sun.star.uno.RuntimeException: enum openlp.plugins.remotes.lib is unknown

Now the remotes plugin is a wrapper for CherryPy and has nothing to do with uno so how it is needing uno is a mystery at present by I am continuing to hunt.

We have in the pas had issues with imports of uno.py see our pluginmanager.py file for the comments.
Comment 19 Tim Bentley 2013-07-18 20:27:56 UTC
The markuptrace looks like this 

Traceback (most recent call last):
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
ImportError: No module named 'markupsafe._speedups'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/tim/Projects/openlp/python3-run/openlp.py", line 45, in <module>
    main()
  File "/home/tim/Projects/openlp/python3-run/openlp/core/__init__.py", line 326, in main
    sys.exit(application.run(qt_args))
  File "/home/tim/Projects/openlp/python3-run/openlp/core/__init__.py", line 137, in run
    Registry().execute('bootstrap_initialise')
  File "/home/tim/Projects/openlp/python3-run/openlp/core/lib/registry.py", line 159, in execute
    result = function(*args, **kwargs)
  File "/home/tim/Projects/openlp/python3-run/openlp/core/lib/pluginmanager.py", line 68, in bootstrap_initialise
    self.find_plugins()
  File "/home/tim/Projects/openlp/python3-run/openlp/core/lib/pluginmanager.py", line 118, in find_plugins
    imp.load_module(module_name, fp, path_name, description)
  File "/usr/lib64/python3.3/imp.py", line 175, in load_module
    return load_source(name, filename, file)
  File "/usr/lib64/python3.3/imp.py", line 114, in load_source
    _LoadSourceCompatibility(name, pathname, file).load_module(name)
  File "<frozen importlib._bootstrap>", line 586, in _check_name_wrapper
  File "<frozen importlib._bootstrap>", line 1024, in load_module
  File "<frozen importlib._bootstrap>", line 1005, in load_module
  File "<frozen importlib._bootstrap>", line 562, in module_for_loader_wrapper
  File "<frozen importlib._bootstrap>", line 870, in _load_module
  File "<frozen importlib._bootstrap>", line 313, in _call_with_frames_removed
  File "/home/tim/Projects/openlp/python3-run/openlp/plugins/remotes/remoteplugin.py", line 35, in <module>
    from openlp.plugins.remotes.lib import RemoteTab, HttpServer
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/home/tim/Projects/openlp/python3-run/openlp/plugins/remotes/lib/__init__.py", line 31, in <module>
    from .httpserver import HttpServer
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/home/tim/Projects/openlp/python3-run/openlp/plugins/remotes/lib/httpserver.py", line 124, in <module>
    from mako.template import Template
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib/python3.3/site-packages/mako/template.py", line 10, in <module>
    from mako.lexer import Lexer
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib/python3.3/site-packages/mako/lexer.py", line 10, in <module>
    from mako import parsetree, exceptions, util
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib/python3.3/site-packages/mako/parsetree.py", line 9, in <module>
    from mako import exceptions, ast, util, filters
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib/python3.3/site-packages/mako/filters.py", line 31, in <module>
    import markupsafe
  File "/usr/lib64/python3.3/site-packages/uno.py", line 268, in _uno_import
    return _g_delegatee( name, *optargs, **kwargs )
  File "/usr/lib64/python3.3/site-packages/markupsafe/__init__.py", line 227, in <module>
    from markupsafe._speedups import escape, escape_silent, soft_unicode
  File "/usr/lib64/python3.3/site-packages/uno.py", line 276, in _uno_import
    traceback.print.exc()
AttributeError: 'module' object has no attribute 'print'
Comment 20 Tim Bentley 2013-07-18 20:47:32 UTC
Created attachment 82636 [details]
trace file

Here is the trace file from uno.py
Comment 21 David Bolen 2013-07-18 21:04:19 UTC
These two statements seem contradictory:
"We / I have never used pygments."
"At that point OpenLP creashed looking for pygments so I needed to install that."

So it sounds like you're saying OpenLP does use (or conditionally support) pygments, right?

It's probably not critical though since that was just once instance of the issue, so we can pick another instead.

Would it be possible to provide me (here or offline) with some specific instructions on how to set up an environment similar to yours and run exactly the same scenario you are?  Can I just start with the bzr python3-productive branch and run setup.py?  Are you using the LO python to run setup or a system version?

"Now the remotes plugin is a wrapper for CherryPy and has nothing to do with uno so how it is needing uno is a mystery at present by I am continuing to hunt."

It doesn't really, but once uno.py is imported any import statement runs through that that code since it intercepts the global import hook.  What still has me confused though is that even though that code runs and you'll see uno stuff in the exception traceback, you only get into the uno code if Python already rejected the import and the final result for a bad import should still be an ImportError with or without uno.

For example, in your first case:

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

DEBUG    Importing remoteplugin from /home/tim/Projects/openlp/python3-run/openlp/plugins/remotes. Depth 10
2013-07-18 21:02:53,304 openlp.core.lib.pluginmanager                           ERROR    Failed to import module remoteplugin on path /home/tim/Projects/openlp/python3-run/openlp/plugins/remotes/remoteplugin.py: type openlp.plugins.remotes.lib.RemoteTab is unknown
Traceback (most recent call last):
  File "/usr/lib64/python3.3/site-packages/uno.py", line 295, in _uno_import
    d[x] = pyuno.getClass( name + "." + x )
uno.com.sun.star.uno.RuntimeException: pyuno.getClass: uno exception openlp.plugins.remotes.lib.RemoteTab is unknown

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

The ERROR line is from pluginmanager.py in the "except ImportError" clause, so that indicates that the attempt to import remoteplugin failed with an ImportError.  The rest of the traceback is from when the uno codes runs.  It appears to have been triggered by a failure on the line:

  from openlp.plugins.remotes.lib import RemoteTab, HttpServer

Now, it's flowing through the uno code, but that can only happen if treating it as a regular Python import already failed (and it was a from xxx import yyy syntax).  But there's no import failure protection here, so I'd expect to see some sort of failure even without uno imported - so that's perplexing.

The comments in pluginmanager (where it uses imp directly to get around a PyUNO issue) references tests.  So are you seeing errors during tests, or in actual operation?  The pluginmanager code avoids the uno path for the actual module load, but not for internal imports within the module itself (e.g., the above import in remoteplugin.py itself).

I may just be missing something obvious though, so being able to run this locally might help.

BTW, in the other traceback the missing print attribute bit is because it should be print_exc not print.exc
Comment 22 David Bolen 2013-07-19 01:30:04 UTC
Tim, I've gotten a (sorta, kinda, mostly) working copy of the OpenLP python3-productive branch under Python 3.3.2 with LibreOffice 4.1.0.2.  I had to hack a bunch of stuff in terms of missing Python 3'isms, but it gets through the first time wizard and to the main screen, and all but 20 or so of the self-tests run (and they're mostly 3'isms related to the test resource files).

I will say that so far I don't see any issue that would point to an error in the uno module.  I will agree that given the import changes needed to the OpenLP code base for Python 3 (lots of current failures) the way uno interferes with import errors is definitely a bit of a pain, so would suggest doing the porting work without uno as long as possible, just introducing it when needed at the end.  Or, keep my patch in place.  But I don't see it actually breaking anything that isn't already broken.

In terms of running, I will note that the branch has a top level openlp.py script which hides the openlp package, so I couldn't even start it without renaming that.

In terms of testing, the single biggest issue creating failed imports is probably relative module references (closely followed by exception syntax), which I'm guessing is what you've been working on cleaning up.  For example, in plugins/remotes/lib/__init__ the imports won't work as is (you need to add a "." prefix to let it search relative in its own package).  Without this fix, in turn the higher level remoteplugin import line fails just as you're seeing.  It fails with or without uno, but with uno imported, you get precisely the sort of tracebacks you are seeing.  Even though uno code is shown in the traceback, the root issue is still inside of OpenLP, at least for the cases I've been able to recreate.
Comment 23 Andreas 2013-07-19 08:19:41 UTC
@ David Bolen:
bzr checkout  lp:~openlp-core/openlp/python3-productive
cd python3-productive
2to3 --write --nobackups --no-diffs -x next print *
sh scripts/generate_resources.sh

Also run python3 scripts/check_dependencies.py to check if you have all dependencies installed.

Then you should have a python3 code base.

Start with python3 openlp.py -l d -d
Comment 24 Andreas 2013-07-19 08:31:09 UTC
@ David Bolen:
bzr checkout  lp:~openlp-core/openlp/python3-productive
cd python3-productive
2to3 --write --nobackups --no-diffs -x next print *
sh scripts/generate_resources.sh

Also run python3 scripts/check_dependencies.py to check if you have all dependencies installed.

Then you should have a python3 code base.

Start with python3 openlp.py -l d -d
Comment 25 David Bolen 2013-07-19 21:29:36 UTC
@Andreas:

Thanks.

Doing that works fine for me with or without uno, so either the python3-productive branch is more up to date, or that's not quite how Tim has been running it.  Maybe somehow some of the plugins didn't get run through 2to3, since that does generate errors such as he's seen. 

For those reading later, I also recommend removing openlp/core/resources.py before running 2to3 on the tree - it took a huge amount of time (cpu-bound) to process that file for me (at least in a VM), and generate_resources.sh re-generates a Py3 compatible file anyway.  I also think there should be another "-x" before print in the 2to3 command though whether I ran that filter or not didn't seem to change the final behavior.
Comment 26 Andreas 2013-07-22 09:25:53 UTC
@David:

Suddenly it works. The only thing I remember doing is to reinstall LO (to ensure that uno.py is up to date). Unfortunately I do not have a backup of the old (?) uno.py because I did not expect that things work :D

Anyway, I might check my pacman log for any updates, but a brief look did not show that any of the relevant packages were updated lately-

What distro did you test this on BTW?
Comment 27 Andreas 2013-07-22 09:39:47 UTC
Note, it was a reinstall, not an update (http://pastebin.com/8vhvArgR)

I also tried older revisions of python3-productive, which also worked, so it was not our branch which fixed it.
Comment 28 David Bolen 2013-07-22 18:30:30 UTC
@Andreas:

Yeah, I hate it when an issue just disappears like that.  Not quite sure what to say.  I'm still unable to see a way for the uno.py code to create import errors that aren't already there, though it clearly masks their origin, making the original error harder to detect, so I'm guessing the original attribution of the source of the issue in this ticket may have been misplaced.  Hard to be completely confident without some way to reproduce though.

Any chance you somehow had an OpenLP tree that maybe was only partially processed with 2to3?  That was the only way I was able to create failures such as reported earlier in the bug.  It would appear with any source issue resulting in an ImportError anywhere along the way.

For my part I've been testing under Ubuntu 12.04.  LibreOffice was installed from debs from the web site, not distribution packages.  Python and PyQt were local builds from source, using distribution packages for C/C++ dependencies.  Python module dependencies were all installed directly from pypi.  OpenLP was from its repository.

-- David
Comment 29 Stephan Bergmann 2013-07-23 08:36:35 UTC
(In reply to comment #17)
> However, I think my earlier patch at the end of comment 14 (which Tim is
> using) to at least constrain the namespace under which the uno-specific code
> runs seems like a plausible change, unless anyone is aware of anything
> accessed via uno not being under the "com.sun.star" namespace.

Not everything "accessed via uno [is] under the 'com.sun.star' namespace."  Most of the UNOIDL entities coming with LO are, but:
* at least the stuff coming with LO from offapi/org/freedesktop/PackageKit/ is not;
* anything coming with 3rd-party extensions should not be.
Comment 30 David Bolen 2013-07-23 08:57:49 UTC
(In reply to comment #29)
> * at least the stuff coming with LO from offapi/org/freedesktop/PackageKit/
> is not;
> * anything coming with 3rd-party extensions should not be.

Thanks, good to know.  So assuming those other namespaces are also accessible from the uno import code, clearly that means hardcoded namespace checks can't work.

It would still be a nice improvement if there was some way to avoid uno losing the original python import error and traceback for non-uno stuff, but offhand it sounds like there's no safe way to distinguish uno vs. non-uno in the failure case.

I wonder if it might be better to prefer re-raising the original python import error if present if the default uno processing fails.  The uno failure exception is pretty generic anyway, so the original Python exception should work about as well, while in the non-uno case, the original Python exception (and more critically, traceback) is far superior to the current uno exception.
Comment 31 Stephan Bergmann 2013-07-23 09:13:23 UTC
(In reply to comment #30)
> I wonder if it might be better to prefer re-raising the original python
> import error if present if the default uno processing fails.  The uno
> failure exception is pretty generic anyway, so the original Python exception
> should work about as well, while in the non-uno case, the original Python
> exception (and more critically, traceback) is far superior to the current
> uno exception.

Sounds reasonable to me, feel free to provide a patch.  (Note that an original python ImportError will always be present for re-raising in the two places that currently raise a fresh ImportError in _uno_import.)
Comment 32 David Bolen 2013-07-23 23:37:55 UTC
Created attachment 82883 [details]
Import handler patch

Ok, so in looking a little deeper just using the python exception has its own problems.  In that case, with Python 3, the python exception for uno failures will just declare an import error of the top level namespace (e.g, "com") since uno.py never actually installs anything in sys.modules.  But changing that would break the same semantics I ran into problems with in comment 17 trying the new Python 3 import handler model.

So I've opted to try to combine some aspects of both. I re-raise a new exception (so I can include the full name to cover uno issues), but I model the exception text after a regular module import error, and include the original python traceback to better satisfy cases where the issue is outside of LO.

I've attached a suggested patch (uno.py.patch), a small test script (exctest.py) and some test output (exctest.txt) reflecting running the script under plain python 2.7.5 and 3.3.2 (no uno), and LibreOffice 3.6.6.2, 4.0.4.2 and 4.1.0.3, both unpatched and patched.  I'm attaching them to this ticket since it seems reasonable to treat them as a response to the issue reported here (which I still believe was likely due to a non-LO module error, but obscured by the uno traceback).

As the output shows, it's really the LO 4.x and Python 3.x where the unpatched traceback is particularly rough in a python import failure case.  LO 3.x isn't all that bad, so while the patch is compatible, I'm not sure it needs back-porting.
Comment 33 David Bolen 2013-07-23 23:38:24 UTC
Created attachment 82884 [details]
Patch test script
Comment 34 David Bolen 2013-07-23 23:38:56 UTC
Created attachment 82885 [details]
Patch test script output
Comment 35 Commit Notification 2013-07-24 08:11:56 UTC
David Bolen committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=7fd81244c21ad54a8b9766902fd7c34e8055b165

fdo#66025: Improve ImportError raised from _uno_import



The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 36 David Bolen 2013-07-24 08:38:34 UTC
Created attachment 82905 [details]
Patch correction

Hmm, this is embarrassing.  In seeing the patch committed, I suddenly realized I left one bit of test code in it, in the first exception handler (which has no need to assign the exception to 'e').  This patch just removes that small bit of code, and applies on top of the prior patch.

The original patch technically works fine as-is, and I considered not even bothering with a fix, but some future reviewer may wonder about any relationship between that variable and the final exception (there isn't any) due to their naming, so it feels worth cleaning up.

My apologies.  I don't know how I missed it originally.
Comment 37 Stephan Bergmann 2013-07-24 10:16:46 UTC
(In reply to comment #36)
> Created attachment 82905 [details] [review]
> Patch correction
> 
> Hmm, this is embarrassing.  In seeing the patch committed, I suddenly
> realized I left one bit of test code in it, in the first exception handler
> (which has no need to assign the exception to 'e').  This patch just removes
> that small bit of code, and applies on top of the prior patch.
> 
> The original patch technically works fine as-is, and I considered not even
> bothering with a fix, but some future reviewer may wonder about any
> relationship between that variable and the final exception (there isn't any)
> due to their naming, so it feels worth cleaning up.
> 
> My apologies.  I don't know how I missed it originally.

No problem at all, will push that additional patch in an instant.  (In the future, it would be extra helpful if you could produce patches with "git format-patch", which are directly applicable via "git am", or even push them directly to LO's gerrit, see <https://wiki.documentfoundation.org/Development/gerrit>.)

Funnily enough, I had wondered about that spurious "as e" when looking at the patch, but decided that it is harmless enough and/or my non-existent Python knowledge plays tricks on me.

Another thing that made me wonder is:  I assume that _uno_import will never be called by multiple threads in parallel, anyway, or else the "d[x] = unknown" and "del d[x]" might introduce a new race there.
Comment 38 Michael Meeks 2013-07-24 10:21:53 UTC
Hi David - thanks -so- much for digging into this one so thoroughly :-) that is nothing to be ashamed of ! you should see the number of corrective fixes to my patches ;->

Should we back-port this to the -4-1 branch ? if so, can we close this bug ? It's turned into rather a monster sprawl; are you happy with the result Tim and/or is OpenLP setup ? :-)
Comment 39 Commit Notification 2013-07-24 11:10:25 UTC
David Bolen committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=329125abb63061214897e4f215d41cfa4b13b4b0

fdo#66025: Minor clean-up of previous patch



The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 40 David Bolen 2013-07-24 11:22:44 UTC
Created attachment 82928 [details]
Patch without use of sentinel

(In reply to comment #37)

> Another thing that made me wonder is:  I assume that _uno_import will never
> be called by multiple threads in parallel, anyway, or else the "d[x] =
> unknown" and "del d[x]" might introduce a new race there.

It should be safe - the Python import lock prevents two threads from importing simultaneously (and possibly seeing partial modules).  In retrospect, it appears more complicated than necessary, and your uncertainty could be shared by future viewers.  A simple flag set at the bottom of each exception path works just as well.

This patch (via git format-patch) uses that approach.  It's off of the current master and incorporates the patch2 change since that wasn't there yet).  I'll look into gerrit for the future when I have a chance.
Comment 41 Commit Notification 2013-07-24 13:46:07 UTC
David Bolen committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=fbe28de6fbfdce41544e4e93168d32661add8285

fdo#66025: Simplify new ImportError logic



The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 42 Tim Bentley 2013-07-24 16:43:20 UTC
Many thanks for the updates and the hard work.

Running the test on our code the errors are cleaner but we still seem to have a problem with uno.py.

In the original OpenLP code we had an exception window which imported uno outside the class (when the file was read).  This triggered of all the import checking.  At the same time we had a bug (due to the python3 conversion in our HTTPServer class).  Uno.py just reported that HttpServer was missing and not why.

I recoded our exception form to only import uno when it was needed and the traces showed what the error was in HttpServer.  This is now being fixed.

Whist this has cleaned things up and we have learnt by our mistakes the loss of the original exception has not helped. 

If someone knows how to throw the original exception there would seem not much more we can do with this issue.  A back port to 4.1 would be nice though.
Comment 43 David Bolen 2013-07-24 20:34:47 UTC
(In reply to comment #42)
> I recoded our exception form to only import uno when it was needed and the
> traces showed what the error was in HttpServer.  This is now being fixed.
(...)
> If someone knows how to throw the original exception there would seem not
> much more we can do with this issue.  A back port to 4.1 would be nice
> though.

It's a bit of a catch-22.  If uno re-throws the exact original exception directly, while best for regular import failures, it's worse on LO import failures since the exception will only refer to a top level com module.  And the uno code can't know for sure which case it is in.

But it's still an ImportError, and the traceback should help.  I'm wondering if a trade-off I made in the current patch favors uno imports too much.  It skips the lowest frame from the _g_delegatee failure at a given level, which works well for uno failures since it avoids many extra g_delegatee frames while the "fake" uno module hierarchy is traversed, but is probably hiding needed frames in non-uno nested import failures.

Would it be possible for you to reintroduce the httpserver error, then try the patched version of uno.py but with the following change:

--- uno.py.patch	2013-07-24 06:54:38.703357947 -0400
+++ uno.py	2013-07-24 16:26:29.436937908 -0400
@@ -266,2 +266,3 @@
     except ImportError as e:
+        python_tb = sys.exc_info()[2]
         # process optargs
@@ -318,3 +319,3 @@
                              (name, name, x))
-             e.__traceback__ = sys.exc_info()[2]
+             e.__traceback__ = python_tb
 

and let me know if this produces a traceback that would have worked for your issue with httpserver (without needing to remove the uno import)?  It still won't be exactly the same as the original Python exception and traceback, but should have all the needed references to the OpenLP code.
Comment 44 Tim Bentley 2013-07-24 20:41:36 UTC
That does the trick.
The original error is present in the stack trace.
Comment 45 David Bolen 2013-07-26 20:09:01 UTC
Created attachment 83056 [details]
Final patch

Ok, let's see if we can't close this out.  The attached is a (hopefully) final patch.  I will also be attaching some updated samples of before and after tracebacks.

This patch incorporates a full traceback, with an ImportError always of the form "ImportError: XXX (or YYY)" where XXX is the original Python exception text, and YYY is the name uno tried to resolve after the Python exception.

I've run this by Tim independently, and I believe it now fully satisfies his original problem case where his import issue was completely obscured by uno (my other attachment will include tracebacks from his testing).

On the back-port question, I don't know if there are any guidelines for what qualifies or not.  Technically this behavior (obscuring the underlying failure) has been around for a really long time (including in 3.x) so it's not a new bug or regression.  With that said, I think the new behavior is a real improvement for problem diagnosis in the nested import case.  As written it is compatible with any 4.x series, and can even apply to 3.x with minor changes, though I suspect it's not worth the hassle to go back further than 4.1.


A few other details, mostly for the bug record:

The patch provides inclusion of the full traceback (so you'll always see the actual line of the failure) and for the exception text, combines the original Python text with the first uno lookup error.  The "first" part is important since the uno code will perform additional lookups higher up the import nesting chain on an error and the uno failure would be out of sync with the traceback if the failure was in a nested module.

As this is still a mash-up of two possibilities (a python import issue versus an uno lookup problem) the exception is of necessity more ambiguous, and sub-optimal in some cases (which I can't see any way to resolve without an unambiguous way to identify uno modules/namespaces):

1. The full traceback includes all uno_import frames, so there will be a number of _g_delegatee entries that are potentially confusing and cannot be avoided.  But on balance you get to see the actual point of failure, even for uno issues occurring in a nested module, where previously all you saw was the highest level "from x import y" that uno processed.
2. For a python exception, the uno reference is going to be unnecessary and could be potentially confusing.  No real way to avoid this however, since the original python exception is often useless for uno diagnostics (see next point).
3. For an uno issue, the import processing walks the module hierarchy so for example "from com.sun.star.style import foo" will attempt to import com.sun.star.style, com.sun.star, com.sun and com.  This isn't an issue if foo is found, but if not, in Python 3 the exception will have _g_delegatee traceback frames for each nested (missing) module, and the failure cause will be the uppermost com module.

Point (3) means that most usual uno issues now have an exception of the form "ImportError: No module named 'com' (or YYY)" where YYY is the real problem.  (This is a change from Python 2 was where it would show the full com.sun.star.style in such an exception).  So the com reference may be confusing as it never actually exists.

I debated flipping XXX and YYY in the exception message for this reason, since arguably importing uno could be an implicit acceptance of wanting to see uno-related errors primarily.   But I feel that it is more defensible to keep the actual Python exception as the base and augment with uno, especially since importing uno is going to affect all import errors across a code base (at least using from x import y) - OpenLP being a good example.

I also debated doing special processing in the "com" case to adjust the message (since even if not the exclusive namespace for uno, seems likely to be the most heavily used), but opted against it as not being worth the additional logic.

It does mean you'll probably need to always ignore the first part of the exception message in an uno issue, but the YYY is the same as that currently shown (or even more accurate, in a nested case) so I don't think it's much of a hardship.
Comment 46 David Bolen 2013-07-26 20:11:28 UTC
Created attachment 83058 [details]
Updated test output for final patch

This is a sample of test imports (both nested and non-nested) showing the final patch compared to a stock LO 4.1.0.4.

It also includes a before/after traceback sample from Tim Bentley for OpenLP.

The most notable improvements are in the nested cases (which includes OpenLP).
Comment 47 Commit Notification 2013-07-29 09:43:13 UTC
David Bolen committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=948b6ea02ea9de7fb4e1e2baf95ecae3ba1cd54e

fdo#66025: Improve accuracy of ImportError traceback and message



The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 48 Commit Notification 2013-07-29 10:59:13 UTC
David Bolen committed a patch related to this issue.
It has been pushed to "libreoffice-4-1":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=52a533cc31f630ad482fe0fde8d925b459c787bf&h=libreoffice-4-1

fdo#66025: Improve accuracy of ImportError traceback and message


It will be available in LibreOffice 4.1.1.

The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 49 Commit Notification 2013-07-29 11:38:53 UTC
David Bolen committed a patch related to this issue.
It has been pushed to "libreoffice-4-0":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=acc7484b0fd1d5df2a709399bcdf03ec81943e71&h=libreoffice-4-0

fdo#66025: Improve accuracy of ImportError traceback and message


It will be available in LibreOffice 4.0.5.

The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 50 Stephan Bergmann 2013-07-29 11:42:55 UTC
So I take it that the accumulated patches by David (and thanks again a lot for them) fix the original problem.  I backported them up to LO 4.0 now and mark this issue as fixed.