On Wed, 14 Nov 2012 13:52:06 -0800 Glyph <glyph@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