Add logs (fixes #162)

NEWS

@@ -10,6 +10,7 @@
 ========================
 
 * IPv6 support
+* Smart, verbose and configurable logs
 
 
 0.5 - Historical Artifacts

TODO

@@ -11,7 +11,6 @@
 
 * [IN PROGRESS] Group calendars
 * [IN PROGRESS] LDAP and databases auth support
-* [IN PROGRESS] Smart, verbose and configurable logs
 * CalDAV rights
 * Read-only access for foreign users
 

config

@@ -28,8 +28,8 @@ stock = utf-8
 
 [acl]
 # Access method
-# Value: fake | htpasswd
+# Value: None | htpasswd
-type = fake
+type = None
 # Personal calendars only available for logged in users (if needed)
 personal = False
 # Htpasswd filename (if needed)
@@ -43,4 +43,13 @@ encryption = crypt
 # created if not present
 folder = ~/.config/radicale/calendars
 
+[logging]
+# Logging configuration file
+# If no config is given, simple information is printed on the standard output
+# For more information about the syntax of the configuration file, see:
+# http://docs.python.org/library/logging.config.html
+config = /etc/radicale/logging
+# Set the default logging level to debug
+debug = False
+
 # vim:ft=cfg

radicale.py

@@ -32,8 +32,6 @@ Launch the server according to configuration and command-line options.
 
 """
 
-# TODO: Manage smart and configurable logs
-
 import os
 import sys
 import optparse
@@ -70,14 +68,22 @@ parser.add_option(
     "-c", "--certificate",
     default=radicale.config.get("server", "certificate"),
     help="set certificate file")
+parser.add_option(
+    "-D", "--debug", action="store_true",
+    default=radicale.config.getboolean("logging", "debug"),
+    help="print debug information")
 options = parser.parse_args()[0]
 
 # Update Radicale configuration according to options
 for option in parser.option_list:
     key = option.dest
     if key:
+        section = "logging" if key == "debug" else "server"
         value = getattr(options, key)
-        radicale.config.set("server", key, value)
+        radicale.config.set(section, key, value)
+
+# Start logging
+radicale.log.start(options.debug)
 
 # Fork if Radicale is launched as daemon
 if options.daemon:
@@ -85,6 +91,8 @@ if options.daemon:
         sys.exit()
     sys.stdout = sys.stderr = open(os.devnull, "w")
 
+radicale.log.LOGGER.info("Starting Radicale")
+
 # Create calendar servers
 servers = []
 server_class = radicale.HTTPSServer if options.ssl else radicale.HTTPServer
@@ -110,6 +118,10 @@ def serve_forever(server):
 # a server exists but another server is added to the list at the same time
 for server in servers:
     threading.Thread(target=serve_forever, args=(server,)).start()
+    radicale.log.LOGGER.debug(
+        "Listening to %s port %s" % (server.server_name, server.server_port))
+
+radicale.log.LOGGER.debug("Radicale server ready")
 
 # Main loop: wait until all servers are exited
 try:
@@ -126,5 +138,10 @@ finally:
     signal.signal(signal.SIGINT, signal.SIG_IGN)
     signal.signal(signal.SIGTERM, signal.SIG_IGN)
 
+    radicale.log.LOGGER.info("Stopping Radicale")
+
     for server in servers:             
+        radicale.log.LOGGER.debug(
+            "Closing server listening to %s port %s" % (
+                server.server_name, server.server_port))
         server.shutdown()

radicale/__init__.py

@@ -46,20 +46,22 @@ except ImportError:
     import BaseHTTPServer as server
 # pylint: enable=F0401
 
-from radicale import acl, config, ical, xmlutils
+from radicale import acl, config, ical, log, xmlutils
 
 
 VERSION = "git"
 
-def _check(request, function):
+# Decorators can access ``request`` protected functions
-    """Check if user has sufficient rights for performing ``request``."""
-    # ``_check`` decorator can access ``request`` protected functions
 # pylint: disable=W0212
 
-    # If we have no calendar, don't check rights
+def _check(request, function):
-    if not request._calendar:
+    """Check if user has sufficient rights for performing ``request``."""
+    # If we have no calendar or no acl, don't check rights
+    if not request._calendar or not request.server.acl:
         return function(request)
 
+    log.LOGGER.info("Checking rights for %s" % request._calendar.owner)
+
     authorization = request.headers.get("Authorization", None)
     if authorization:
         challenge = authorization.lstrip("Basic").strip().encode("ascii")
@@ -70,12 +72,30 @@ def _check(request, function):
 
     if request.server.acl.has_right(request._calendar.owner, user, password):
         function(request)
+        log.LOGGER.info("%s allowed" % request._calendar.owner)
     else:
         request.send_response(client.UNAUTHORIZED)
         request.send_header(
             "WWW-Authenticate",
             "Basic realm=\"Radicale Server - Password Required\"")
         request.end_headers()
+        log.LOGGER.info("%s refused" % request._calendar.owner)
+
+def _log_request_content(request, function):
+    """Log the content of the request and store it in the request object."""
+    log.LOGGER.info(
+        "%s request at %s recieved from %s" % (
+            request.command, request.path, request.client_address[0]))
+
+    content_length = int(request.headers.get("Content-Length", 0))
+    if content_length:
+        request._content = request.rfile.read(content_length)
+        log.LOGGER.debug("Request content:\n%s" % request._content)
+    else:
+        request._content = None
+
+    return function(request)
+
 # pylint: enable=W0212
 
 
@@ -135,8 +155,19 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
     """HTTP requests handler for calendars."""
     _encoding = config.get("encoding", "request")
 
-    # Decorator checking rights before performing request
+    # Request handlers decorators
     check_rights = lambda function: lambda request: _check(request, function)
+    log_request_content = \
+        lambda function: lambda request: _log_request_content(request, function)
+
+    # Maybe a Pylint bug, ``__init__`` calls ``server.HTTPServer.__init__``
+    # pylint: disable=W0231
+    def __init__(self, request, client_address, http_server):
+        self._content = None
+        self._answer = None
+        server.BaseHTTPRequestHandler.__init__(
+            self, request, client_address, http_server)
+    # pylint: enable=W0231
 
     @property
     def _calendar(self):
@@ -171,15 +202,20 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
                 pass
         raise UnicodeDecodeError
 
+    def log_message(self, *args, **kwargs):
+        """Disable inner logging management."""
+
     # Naming methods ``do_*`` is OK here
     # pylint: disable=C0103
 
+    @log_request_content
     def do_GET(self):
         """Manage GET request."""
         self.do_HEAD()
         if self._answer:
             self.wfile.write(self._answer)
 
+    @log_request_content
     @check_rights
     def do_HEAD(self):
         """Manage HEAD request."""
@@ -210,6 +246,7 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
         self.send_header("ETag", etag)
         self.end_headers()
 
+    @log_request_content
     @check_rights
     def do_DELETE(self):
         """Manage DELETE request."""
@@ -226,12 +263,14 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
             # No item or ETag precondition not verified, do not delete item
             self.send_response(client.PRECONDITION_FAILED)
 
+    @log_request_content
     @check_rights
     def do_MKCALENDAR(self):
         """Manage MKCALENDAR request."""
         self.send_response(client.CREATED)
         self.end_headers()
 
+    @log_request_content
     def do_OPTIONS(self):
         """Manage OPTIONS request."""
         self.send_response(client.OK)
@@ -241,11 +280,11 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
         self.send_header("DAV", "1, calendar-access")
         self.end_headers()
 
+    @log_request_content
     def do_PROPFIND(self):
         """Manage PROPFIND request."""
-        xml_request = self.rfile.read(int(self.headers["Content-Length"]))
         self._answer = xmlutils.propfind(
-            self.path, xml_request, self._calendar,
+            self.path, self._content, self._calendar,
             self.headers.get("depth", "infinity"))
 
         self.send_response(client.MULTI_STATUS)
@@ -255,6 +294,7 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
         self.end_headers()
         self.wfile.write(self._answer)
 
+    @log_request_content
     @check_rights
     def do_PUT(self):
         """Manage PUT request."""
@@ -266,8 +306,7 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
             # Case 1: No item and no ETag precondition: Add new item
             # Case 2: Item and ETag precondition verified: Modify item
             # Case 3: Item and no Etag precondition: Force modifying item
-            ical_request = self._decode(
+            ical_request = self._decode(self._content)
-                self.rfile.read(int(self.headers["Content-Length"])))
             xmlutils.put(self.path, ical_request, self._calendar)
             etag = self._calendar.get_item(item_name).etag
 
@@ -278,11 +317,11 @@ class CalendarHTTPHandler(server.BaseHTTPRequestHandler):
             # PUT rejected in all other cases
             self.send_response(client.PRECONDITION_FAILED)
 
+    @log_request_content
     @check_rights
     def do_REPORT(self):
         """Manage REPORT request."""
-        xml_request = self.rfile.read(int(self.headers["Content-Length"]))
+        self._answer = xmlutils.report(self.path, self._content, self._calendar)
-        self._answer = xmlutils.report(self.path, xml_request, self._calendar)
 
         self.send_response(client.MULTI_STATUS)
         self.send_header("Content-Length", len(self._answer))

radicale/acl/__init__.py

@@ -31,5 +31,9 @@ from radicale import config
 
 def load():
     """Load list of available ACL managers."""
-    module = __import__("radicale.acl", fromlist=[config.get("acl", "type")])
+    acl_type = config.get("acl", "type")
-    return getattr(module, config.get("acl", "type"))
+    if acl_type == "None":
+        return None
+    else:
+        module = __import__("radicale.acl", fromlist=[acl_type])
+        return getattr(module, acl_type)

radicale/acl/fake.py

@@ -1,30 +0,0 @@
-# -*- coding: utf-8 -*-
-#
-# This file is part of Radicale Server - Calendar Server
-# Copyright © 2008-2011 Guillaume Ayoub
-# Copyright © 2008 Nicolas Kandel
-# Copyright © 2008 Pascal Halter
-#
-# This library is free software: you can redistribute it and/or modify
-# it under the terms of the GNU General Public License as published by
-# the Free Software Foundation, either version 3 of the License, or
-# (at your option) any later version.
-#
-# This library is distributed in the hope that it will be useful,
-# but WITHOUT ANY WARRANTY; without even the implied warranty of
-# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
-# GNU General Public License for more details.
-#
-# You should have received a copy of the GNU General Public License
-# along with Radicale.  If not, see <http://www.gnu.org/licenses/>.
-
-"""
-Fake ACL.
-
-No rights management.
-
-"""
-
-def has_right(*_):
-    """Check if ``user``/``password`` couple is valid."""
-    return True

radicale/config.py

@@ -48,12 +48,15 @@ INITIAL_CONFIG = {
         "request": "utf-8",
         "stock": "utf-8"},
     "acl": {
-        "type": "fake",
+        "type": "None",
         "personal": "False",
         "filename": "/etc/radicale/users",
         "encryption": "crypt"},
     "storage": {
-        "folder": os.path.expanduser("~/.config/radicale/calendars")}}
+        "folder": os.path.expanduser("~/.config/radicale/calendars")},
+    "logging": {
+        "config": "/etc/radicale/logging",
+        "debug": "False"}}
 
 # Create a ConfigParser and configure it
 _CONFIG_PARSER = ConfigParser()

radicale/log.py

@@ -0,0 +1,50 @@
+# -*- coding: utf-8 -*-
+#
+# This file is part of Radicale Server - Calendar Server
+# Copyright © 2011 Guillaume Ayoub
+#
+# This library is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# This library is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with Radicale.  If not, see <http://www.gnu.org/licenses/>.
+
+"""
+Radicale logging module.
+
+Manage logging from a configuration file. For more information, see:
+http://docs.python.org/library/logging.config.html
+
+"""
+
+import os
+import sys
+import logging
+import logging.config
+
+from radicale import config
+
+
+LOGGER = logging.getLogger("radicale")
+FILENAME = os.path.expanduser(config.get("logging", "config"))
+
+def start(debug=False):
+    """Start the logging according to the configuration."""
+    if debug:
+        LOGGER.setLevel(logging.DEBUG)
+
+    if os.path.exists(FILENAME):
+        # Configuration taken from file
+        logging.config.fileConfig(FILENAME)
+    else:
+        # Default configuration, standard output
+        handler = logging.StreamHandler(sys.stdout)
+        handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
+        LOGGER.addHandler(handler)