[CalendarServer-dev] [debian] testing trunk

Fredrik Unger fred at tree.se
Thu Nov 15 05:23:00 PST 2012


On Wed, 14 Nov 2012 13:52:06 -0800 Glyph <glyph at twistedmatrix.com> wrote:

> This is "documented" by the call to py_dependency in support/build.sh.

Yes, I know, I forgot to look there. Not a big deal.

> .. we depend on a very specific version of python-sqlparse: 0.1.2.

Ok, I understand.

> Thanks.  Can you attach this patch to a bug in Trac

Patch  :
https://trac.calendarserver.org/ticket/759

I might have used the wrong milestone and type for the bug, sorry.

> This is most likely because './run' is pulling all of its dependencies from its working directory, rather than the system.  On your system, something - probably a Twisted plugin from some other package which is neither Twisted nor CalendarServer - is pulling in twisted.internet.address before this code can run.

I think I tracked it down..partially

When starting the *subprocesses* the --reactor flag is used.
This starts the reactor select early and before the caldav 
plugin. It eventually imports twisted.internet.tcp
Longer I did not trace.

The initial start of the caldav process is ok.

Why is the reactor select working in the original code ? 
Is it a different plugin order ? Both should be Twisted 12.0.0.

Due to my limited knowledge of twisted and caldav I am stuck here.
I am also not sure if it is a bug in any way, or the Debian environment.

Below is a detailed log of my testing for reference.

/Fred



python -vvvv `which twistd` caldavd --help &> caldav.log
grep -n 'import twext.patches' caldav.log
4332:import twext.patches # precompiled from /usr/lib/python2.7/dist-packages/twext/patches.pyc
grep -n 'import twisted.internet.address' caldav.log 
5681:import twisted.internet.address # precompiled from /usr/lib/python2.7/dist-packages/twext/backport/internet/address.pyc

It works.

BUT, what fails are the subprocesses. I dug into calendarserver/tap/caldav.py
and added a simple patch [1], maybe for improved logging.

The printout is forwarded by the subprocess logger to the error.log [2]
The subprocesses all fail with the exception from patches.py, trying to patch
twisted.internet.address.

Using the commandline :
/usr/bin/python2.7 -vvvv /usr/bin/twistd -u caldavd -g caldavd --reactor=select -n caldav -f /etc/caldavd/caldavd.plist -o ProcessType=Slave -o BindAddresses=,:: -o PIDFile=caldav-instance-0.pid -o ErrorLogFile=None -o ErrorLogEnabled=False -o LogID=0 -o MultiProcess/ProcessCount=2 -o ControlPort=0 -o MetaFD=19 &> failure.log

To produce a new log showed the problem :
grep -n 'import twisted.internet.address' failure.log 
4588:import twisted.internet.address # precompiled from /usr/lib/python2.7/dist-packages/twisted/internet/address.pyc

grep -n 'import twext.patches' failure.log 
4808:import twext.patches # from /home/fred/dev/src/debian/calendarserver/twext/patches.py
4896:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc
4965:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc
5039:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc
5185:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc
5254:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc
5328:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc
5402:import twext.patches # precompiled from /home/fred/dev/src/debian/calendarserver/twext/patches.pyc

The twisted.internet.address is imported earlier in this case.

Why ?
The only difference to the twisted command is --reactor=select.

By removing that for the test :
/usr/bin/python2.7 -vvvv /usr/bin/twistd -u caldavd -g caldavd -n caldav -f /etc/caldavd/caldavd.plist -o ProcessType=Slave -o BindAddresses=,:: -o PIDFile=caldav-instance-0.pid -o ErrorLogFile=None -o ErrorLogEnabled=False -o LogID=0 -o MultiProcess/ProcessCount=2 -o ControlPort=0 -o MetaFD=19 &> working.log

we get a working patching method again :
grep -n 'import twisted.internet.address' working.log
5573:import twisted.internet.address # from /home/fred/dev/src/debian/calendarserver/twext/backport/internet/address.py

Now, from where does it come ?
557 :                "--reactor=%s" % (config.Twisted.reactor,),
in calendarserver/tap/caldav.py (for example).

This is set in ./twistedcaldav/stdconfig.py I think
853    "Twisted": {
854        "reactor": "select",
855    },

comparing the two logs (sdiff) show that where select is not used,
(also the case with the initial start of caldav under debian) 
the plugin 
import twisted.plugins.caldav 
gets loaded.

With the reactor flag 
import twisted.plugins.twisted_reactors
gets loaded BEFORE caldav which in turn loads :
twisted.internet.selectreactor
which 
from twisted.internet import posixbase
and which
from twisted.internet import tcp, udp

I guess after tcp is loaded the patching will fail.
I did not follow the trail to where address gets loaded.

The selectreactor is part of :
python-twisted-core: /usr/share/pyshared/twisted/internet/selectreactor.py
Package: python-twisted-core
Version: 12.0.0-1

[1]
Index: calendarserver/tap/caldav.py
===================================================================
--- calendarserver/tap/caldav.py        (revision 10029)
+++ calendarserver/tap/caldav.py        (working copy)
@@ -1808,7 +1808,7 @@
         childFDs.update(procObj.getFileDescriptors())
 
         args = procObj.getCommandLine()
-
+        print p.name+' :>'+' '.join(args)
         self._reactor.spawnProcess(
             p, args[0], args, uid=uid, gid=gid, env=env,
             childFDs=childFDs

[2]
2012-11-15 10:09:07+0100 [-] [calendarserver.tap.caldav.CalDAVServiceMaker#info] Adding notification service
2012-11-15 10:09:07+0100 [-] [calendarserver.tap.caldav.CalDAVServiceMaker#info] Adding group caching service
2012-11-15 10:09:07+0100 [-] caldav-0 :>/usr/bin/python2.7 /usr/bin/twistd -u caldavd -g caldavd --reactor=select -n caldav -f /etc/caldavd/caldavd.plist -o ProcessType=Slave -o BindAddresses=,:: -o PIDFile=caldav-instance-0.pid -o ErrorLogFile=None -o ErrorLogEnabled=False -o LogID=0 -o MultiProcess/ProcessCount=2 -o ControlPort=0 -o MetaFD=19
2012-11-15 10:09:07+0100 [-] caldav-1 :>/usr/bin/python2.7 /usr/bin/twistd -u caldavd -g caldavd --reactor=select -n caldav -f /etc/caldavd/caldavd.plist -o ProcessType=Slave -o BindAddresses=,:: -o PIDFile=caldav-instance-1.pid -o ErrorLogFile=None -o ErrorLogEnabled=False -o LogID=1 -o MultiProcess/ProcessCount=2 -o ControlPort=0 -o MetaFD=21
2012-11-15 10:09:07+0100 [-] notifications :>/usr/bin/python2.7 /usr/bin/twistd -u caldavd -g caldavd --reactor=select -n caldav_notifier -f /etc/caldavd/caldavd.plist
2012-11-15 10:09:07+0100 [-] groupcacher :>/usr/bin/python2.7 /usr/bin/twistd -u caldavd -g caldavd --reactor=select -n caldav_groupcacher -f /etc/caldavd/caldavd.plist -o PIDFile=groupcacher.pid
2012-11-15 10:09:08+0100 [-] [caldav-0] Unhandled Error



More information about the calendarserver-dev mailing list