[ZODB-Dev] strange testConnection error

[Tim Peters]

[John Belmonte]
> Several months ago my ZODB 3.3a3 application mysteriously stopped
> working, perhaps triggered by some package upgrade (I track Debian
> testing).  The error message (uncovered after much fighting with the log
> system) was "CW: error in testConnection" from ZEO/zrpc/client.py.  I
> traced the exception to a strange "ImportError: No module named copy_reg"
> resulting from a cPickle.Pickler() call.
>
> I hoped that if I upgraded to ZODB 3.3.1a1, this problem might go away.
> It didn't.  I'm not usually one to post tracebacks, but I don't know what
> to make of this:
>
> Traceback (most recent call last):
>    File "/usr/lib/python2.3/threading.py", line 442, in __bootstrap
>    File "/usr/local/lib/python2.3/site-packages/ZEO/zrpc/client.py", line
293, in run
>    File "/usr/local/lib/python2.3/site-packages/ZEO/zrpc/client.py", line
317, in try_connecting
>    File "/usr/local/lib/python2.3/site-packages/ZEO/zrpc/client.py", line
345, in _create_wrappers
>    File "/usr/local/lib/python2.3/site-packages/ZEO/zrpc/client.py", line
471, in connect_procedure
>    File "/usr/local/lib/python2.3/site-packages/ZEO/zrpc/client.py", line
483, in test_connection
>    File
"/tmp/ZODB3-3.3.1a1/build/lib.linux-i686-2.3/ZEO/ClientStorage.py", line
466, in testConnection
>    File "/tmp/ZODB3-3.3.1a1/build/lib.linux-i686-2.3/ZEO/ServerStub.py",
line 85, in getAuthProtocol
>    File
"/tmp/ZODB3-3.3.1a1/build/lib.linux-i686-2.3/ZEO/zrpc/connection.py", line
370, in call
>    File
"/tmp/ZODB3-3.3.1a1/build/lib.linux-i686-2.3/ZEO/zrpc/connection.py", line
363, in send_call
>    File "/tmp/ZODB3-3.3.1a1/build/lib.linux-i686-2.3/ZEO/zrpc/marshal.py",
line 35, in encode
> ImportError: No module named copy_reg
>
> I only have Python 2.3.5 installed on my system, and it certainly has a
> copy_reg module.  I'm also wondering why build paths are showing up in
> the traceback-- the build directory doesn't even exist any longer.

.pyc files (compiled Python) contain the path of the corresponding .py file
at the time the .pyc file was compiled.  When .pyc files are moved to a
different location, the file paths within them don't change.  So if your
.pyc files got moved, it's expected that their module __file__ attributes
continue to refer to their original locations.  That the build directory
doesn't exist anymore is also why this traceback doesn't show any lines of
code (for example, the traceback machinery *tries* to show line 35 of
marshal.py (last line above), but can't find the original .py file so
silently skips showing the code).

The ImportError is much more mysterious, and I still don't have a plausible
theory for how that could happen.  Line 35 in marshal.py's encode() is:

        pickler = cPickle.Pickler(1)

and that's very mysterious for several reasons:

1. Python _itself_ normally imports copy_reg as a side effect
   of starting up.  Like:

$ ./python
Python 2.3.4 (#1, Aug  9 2004, 17:15:36)
[GCC 3.2.2 20030222 (Red Hat Linux 3.2.2-5)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> 'copy_reg' in sys.modules
True

   So if copy_reg didn't exist on sys.path, Python should have barfed
   during startup.  And if copy_reg did exist on sys.path, then it's
   already been imported by the time any application code runs, so
   it shouldn't be possible for later attempts to import copy_reg to
   fail.

2. Perhaps you're doing something that subverts the full "normal"
   Python startup dance.  Can't guess.  But even if so,
   ZEO/zrpc/marshal.py imports cPickle at module level, and it's
   not possible to import cPickle if copy_reg isn't available.  Like:

# Strip copy_reg.py's home from sys.path.
>>> sys.path.remove('/home/tim/Python-2.3.4/Lib')

# "Undo" the import of copy_reg done by Python startup.
>>> del sys.modules['copy_reg']

# Now it's impossible to import cPickle.
>>> import cPickle
Traceback (most recent call last):
  File "<stdin>", line 1, in ?
ImportError: No module named copy_reg

   So even in this case, the attempt to import ZEO/zrpc/marshal.py
   in order to _call_ its encode() function would have failed -- we
   never would have gotten into encode(), because we wouldn't have
   been able to import the module containing that function.

3. cPickle.Pickler() doesn't normally try to import copy_reg
   anyway -- copy_reg is normally imported by cPickle's module
   initialization code (which is why #2 died the way it did).

   There's one exception:  if you're in restricted execution mode,
   then (and only then) cPickle.Pickler() tries to import copy_reg,
   presumably under the theory that you may have changed the default
   copy_reg.dispatch_table "for security reasons".  If sys.modules
   was also fiddled "for security reasons", and no longer contained
   copy_reg, and sys.path was fiddled so that copy_reg couldn't be
   found anymore, then cPickle.Pickler() would die in the way shown.

#3 is the only path I can see that makes any sense at all here, but AFAIK
ZODB/ZEO never provoke Python's restricted execution mode themselves.  Ring
any bells wrt your code?  For example, are you using rexec or bastion, or
fiddling module.__builtins__ in some module?