Revision: 1460 http://trac.macosforge.org/projects/calendarserver/changeset/1460 Author: dreid@apple.com Date: 2007-04-10 10:29:38 -0700 (Tue, 10 Apr 2007) Log Message: ----------- There is no longer a single process mode. There is always a controlling process. Empty UserName or GroupName options disables that option being passed to twistd in the child. Logging is now handled entirely in a single master process. Children use a simple AMP based LogMessage protocol to talk to the parent and tell it to write lines to the log. Modified Paths: -------------- CalendarServer/trunk/conf/caldavd-test.plist CalendarServer/trunk/twistedcaldav/cluster.py CalendarServer/trunk/twistedcaldav/config.py CalendarServer/trunk/twistedcaldav/logging.py CalendarServer/trunk/twistedcaldav/tap.py Modified: CalendarServer/trunk/conf/caldavd-test.plist =================================================================== --- CalendarServer/trunk/conf/caldavd-test.plist 2007-04-09 23:24:02 UTC (rev 1459) +++ CalendarServer/trunk/conf/caldavd-test.plist 2007-04-10 17:29:38 UTC (rev 1460) @@ -275,10 +275,10 @@ --> <key>UserName</key> - <string>calendar</string> + <string></string> <key>GroupName</key> - <string>calendar</string> + <string></string> <key>ProcessType</key> <string>Combined</string> Modified: CalendarServer/trunk/twistedcaldav/cluster.py =================================================================== --- CalendarServer/trunk/twistedcaldav/cluster.py 2007-04-09 23:24:02 UTC (rev 1459) +++ CalendarServer/trunk/twistedcaldav/cluster.py 2007-04-10 17:29:38 UTC (rev 1460) @@ -24,6 +24,9 @@ from twisted.runner import procmon from twisted.scripts.mktap import getid +from twisted.application import internet, service + +from twistedcaldav import logging from twistedcaldav.config import config from twistedcaldav.util import getNCPU @@ -71,20 +74,28 @@ return '%s-%s' % (self.prefix, self.sslPorts[0]) def getCommandLine(self): - return [ + args = [ sys.executable, - self.twistd, - '-u', config.UserName, - '-g', config.GroupName, - '-n', self.tapname, - '-f', self.configFile, - '-o', 'ProcessType=Slave', - '-o', 'BindAddresses=%s' % (','.join(self.interfaces),), - '-o', 'BindHTTPPorts=%s' % (','.join(map(str, self.ports)),), - '-o', 'BindSSLPorts=%s' % (','.join(map(str, self.sslPorts)),), - '-o', 'PIDFile=None', - '-o', 'ErrorLogFile=None'] + self.twistd] + if config.UserName: + args.extend(('-u', config.UserName)) + + if config.GroupName: + args.extend(('-g', config.GroupName)) + + args.extend( + ['-n', self.tapname, + '-f', self.configFile, + '-o', 'ProcessType=Slave', + '-o', 'BindAddresses=%s' % (','.join(self.interfaces),), + '-o', 'BindHTTPPorts=%s' % (','.join(map(str, self.ports)),), + '-o', 'BindSSLPorts=%s' % (','.join(map(str, self.sslPorts)),), + '-o', 'PIDFile=None', + '-o', 'ErrorLogFile=None']) + + return args + def getHostLine(self, ssl=None): name = self.getName() port = self.ports @@ -98,7 +109,9 @@ 'bindAddress': '127.0.0.1'} def makeService_Combined(self, options): - service = procmon.ProcessMonitor() + s = service.MultiService() + monitor = procmon.ProcessMonitor() + monitor.setServiceParent(s) parentEnv = {'PYTHONPATH': os.environ.get('PYTHONPATH', ''),} @@ -157,7 +170,7 @@ bindAddress, port, sslPort) - service.addProcess(process.getName(), + monitor.addProcess(process.getName(), process.getCommandLine(), env=parentEnv) @@ -229,13 +242,20 @@ log.msg("Adding pydirector service with configuration: %s" % (fname,)) - service.addProcess('pydir', [sys.executable, + monitor.addProcess('pydir', [sys.executable, config.PythonDirector['pydir'], fname], env=parentEnv) - return service + logger = logging.AMPLoggingFactory( + logging.RotatingFileAccessLoggingObserver(config.AccessLogFile)) + loggingService = internet.UNIXServer(config.ControlSocket, logger) + + loggingService.setServiceParent(s) + + return s + def makeService_Master(self, options): service = procmon.ProcessMonitor() Modified: CalendarServer/trunk/twistedcaldav/config.py =================================================================== --- CalendarServer/trunk/twistedcaldav/config.py 2007-04-09 23:24:02 UTC (rev 1459) +++ CalendarServer/trunk/twistedcaldav/config.py 2007-04-10 17:29:38 UTC (rev 1460) @@ -120,9 +120,13 @@ # # Process management # - "UserName": "daemon", - "GroupName": "daemon", - "ProcessType": "Slave", + + # Username and Groupname to drop privileges to, if empty privileges will + # not be dropped. + + "UserName": "", + "GroupName": "", + "ProcessType": "Combined", "MultiProcess": { "ProcessCount": 0, "LoadBalancer": { @@ -162,6 +166,10 @@ # Umask "umask": 0027, + + # A unix socket used for communication between the child and master + # processes. + "ControlSocket": "/var/run/caldavd.sock", } class Config (object): Modified: CalendarServer/trunk/twistedcaldav/logging.py =================================================================== --- CalendarServer/trunk/twistedcaldav/logging.py 2007-04-09 23:24:02 UTC (rev 1459) +++ CalendarServer/trunk/twistedcaldav/logging.py 2007-04-10 17:29:38 UTC (rev 1460) @@ -25,6 +25,8 @@ import time from twisted.python import log +from twisted.internet import protocol + from twisted.web2 import iweb from twisted.web2.dav import davxml from twisted.web2.log import BaseCommonAccessLoggingObserver @@ -47,80 +49,63 @@ def canLog(type): """ Determine whether a particular log level type is current active. - + @param type: a string with one of the types above. @return: True if the log level is currently active. """ - + return currentLogLevel >= logtypes.get(type, 1) def info(message, **kwargs): """ Log a message at the "info" level. - + @param message: message to log. @param **kwargs: additional log arguments. """ - + if canLog("info"): log.msg(message, **kwargs) def warn(message, **kwargs): """ Log a message at the "warning" level. - + @param message: message to log. @param **kwargs: additional log arguments. """ - + if canLog("warning"): log.msg(message, **kwargs) def err(message, **kwargs): """ Log a message at the "error" level. - + @param message: message to log. @param **kwargs: additional log arguments. """ - + if canLog("error"): log.msg(message, **kwargs) def debug(message, **kwargs): """ Log a message at the "debug" level. - + @param message: message to log. @param **kwargs: additional log arguments. """ - + if canLog("debug"): log.msg(message, debug=True, **kwargs) -class RotatingFileAccessLoggingObserver(BaseCommonAccessLoggingObserver): + +class CommonAccessLoggingObserverExtensions(BaseCommonAccessLoggingObserver): """ - Class to do 'apache' style access logging to a rotating log file. The log - file is rotated after midnight each day. + A base class for our extension to the L{BaseCommonAccessLoggingObserver} """ - - def __init__(self, logpath): - self.logpath = logpath - - def logMessage(self, message, allowrotate=True): - """ - Log a message to the file and possibly rotate if date has changed. - @param message: C{str} for the message to log. - @param allowrotate: C{True} if log rotate allowed, C{False} to log to current file - without testing for rotation. - """ - - if self.shouldRotate() and allowrotate: - self.flush() - self.rotate() - self.f.write(message + '\n') - def emit(self, eventDict): if eventDict.get('interface') is not iweb.IRequest: return @@ -132,7 +117,7 @@ request.method, request.uri, '.'.join([str(x) for x in request.clientproto])) - + # Try to determine authentication and authorization identifiers uid = "-" if hasattr(request, "authnUser"): @@ -140,7 +125,6 @@ uid = str(request.authnUser.children[0]) if hasattr(request, "authzUser") and str(request.authzUser.children[0]) != uid: uid = '"%s as %s"' % (uid, request.authzUser.children[0]) - self.logMessage( '%s - %s [%s] "%s" %s %d "%s" "%s" [%.1f ms]' %( @@ -157,20 +141,44 @@ ) ) + +class RotatingFileAccessLoggingObserver(CommonAccessLoggingObserverExtensions): + """ + Class to do 'apache' style access logging to a rotating log file. The log + file is rotated after midnight each day. + """ + + def __init__(self, logpath): + self.logpath = logpath + + def logMessage(self, message, allowrotate=True): + """ + Log a message to the file and possibly rotate if date has changed. + + @param message: C{str} for the message to log. + @param allowrotate: C{True} if log rotate allowed, C{False} to log to current file + without testing for rotation. + """ + + if self.shouldRotate() and allowrotate: + self.flush() + self.rotate() + self.f.write(message + '\n') + def start(self): """ Start logging. Open the log file and log an 'open' message. """ - + super(RotatingFileAccessLoggingObserver, self).start() self._open() self.logMessage("Log opened - server start: [%s]." % (datetime.datetime.now().ctime(),)) - + def stop(self): """ Stop logging. Close the log file and log an 'open' message. """ - + self.logMessage("Log closed - server stop: [%s]." % (datetime.datetime.now().ctime(),), False) super(RotatingFileAccessLoggingObserver, self).stop() self._close() @@ -182,21 +190,21 @@ self.f = open(self.logpath, 'a', 1) self.lastDate = self.toDate(os.stat(self.logpath)[8]) - + def _close(self): """ Close the log file. """ self.f.close() - + def flush(self): """ Flush the log file. """ self.f.flush() - + def shouldRotate(self): """ Rotate when the date has changed since last write @@ -211,7 +219,7 @@ """ Convert a unixtime to (year, month, day) localtime tuple, or return the current (year, month, day) localtime tuple. - + This function primarily exists so you may overload it with gmtime, or some cruft to make unit testing possible. """ @@ -249,3 +257,82 @@ self._open() self.logMessage("Log opened - rotated: [%s]." % (datetime.datetime.now().ctime(),), False) + +from twisted.protocols import amp + + +class LogMessage(amp.Command): + arguments = [('message', amp.String())] + + +class AMPCommonAccessLoggingObserver(CommonAccessLoggingObserverExtensions): + def __init__(self, socket): + self.socket = socket + self.protocol = None + self._buffer = [] + + def flushBuffer(self): + if self._buffer: + for msg in self._buffer: + self.logMessage(msg) + + def start(self): + super(AMPCommonAccessLoggingObserver, self).start() + + from twisted.internet import reactor + + def _gotProtocol(proto): + self.protocol = proto + self.flushBuffer() + + self.client = protocol.ClientCreator(reactor, amp.AMP) + d = self.client.connectUNIX(self.socket) + d.addCallback(_gotProtocol) + + def stop(self): + super(AMPCommonAccessLoggingObserver, self).stop() + self.client.disconnect() + + def logMessage(self, message): + """ + Log a message to the remote AMP Protocol + """ + if self.protocol is not None: + # XXX: Yeah we're not waiting for anything to happen here. + # but we will log an error. + d = self.protocol.callRemote(LogMessage, message=message) + d.addErrback(log.err) + else: + self._buffer.append(message) + + +class AMPLoggingProtocol(amp.AMP): + """ + A server side protocol for logging to the given observer. + """ + + def __init__(self, observer): + self.observer = observer + + super(AMPLoggingProtocol, self).__init__() + + def logMessage(self, message): + self.observer.logMessage(message) + return {} + + LogMessage.responder(logMessage) + + +class AMPLoggingFactory(protocol.ServerFactory): + def __init__(self, observer): + self.observer = observer + + def doStart(self): + self.observer.start() + + def doStop(self): + self.observer.stop() + + def buildProtocol(self, addr): + return AMPLoggingProtocol(self.observer) + Modified: CalendarServer/trunk/twistedcaldav/tap.py =================================================================== --- CalendarServer/trunk/twistedcaldav/tap.py 2007-04-09 23:24:02 UTC (rev 1459) +++ CalendarServer/trunk/twistedcaldav/tap.py 2007-04-10 17:29:38 UTC (rev 1460) @@ -42,6 +42,8 @@ from twisted.web2.log import LogWrapperResource from twisted.web2.server import Site +from twistedcaldav import logging + from twistedcaldav.cluster import makeService_Combined, makeService_Master from twistedcaldav.config import config, parseConfig, defaultConfig, ConfigurationError from twistedcaldav.logging import RotatingFileAccessLoggingObserver @@ -435,11 +437,12 @@ channel = http.HTTPFactory(site) - log.msg("Configuring rotating log observer for file: %s" % ( - config.AccessLogFile,)) + log.msg("Configuring log observer: %s" % ( + config.ControlSocket,)) - logObserver = RotatingFileAccessLoggingObserver(config.AccessLogFile) - + logObserver = logging.AMPCommonAccessLoggingObserver( + config.ControlSocket) + service = CalDAVService(logObserver) if not config.BindAddresses: