diff --git a/config b/config
index 8855c1184..99220b478 100644
--- a/config
+++ b/config
@@ -111,6 +111,11 @@
 # Example: git add -A && (git diff --cached --quiet || git commit -m "Changes by "%(user)s)
 #hook =
 
+# Caching of Items files in memory
+cache_items = False
+# Caching of Props files in memory
+cache_props = False
+
 
 [logging]
 
@@ -120,15 +125,43 @@
 # http://docs.python.org/library/logging.config.html
 #config = /etc/radicale/logging
 
-# Set the default logging level to debug
+# Set the default logging level to debug (this enables also request/response logging)
 #debug = False
 
+# suppress selectable debug messages (to keep debug log cleaner)
+debug_filter = 0xffff
+# 0x0001: suppress "header content"
+# 0x0002: suppress "request content"
+# 0x0004: suppress "response content"
+# 0x0008: suppress "item content (on read)"
+# 0x0040: suppress "sanitized path"
+# 0x0080: suppress "rights" "Test if" + "Section"
+# 0x0100: suppress "read object"
+# 0x0200: suppress "delete object from cache"
+# 0x0400: suppress "read props"
+# 0x0800: suppress "delete props from cache"
+# 0x1000: suppress "store object in cache"
+# 0x2000: suppress "retrieve object from cache"
+# 0x4000: suppress "store props in cache"
+# 0x8000: suppress "retrieve props from cache"
+
 # Store all environment variables (including those set in the shell)
 #full_environment = False
 
 # Don't include passwords in logs
 #mask_passwords = True
 
+# Include performance statistics in logs on info level
+performance = False
+
+# Include exceptions in logs
+exceptions = False
+
+# Include regular cache performance statistics in logs on info level
+# 0: on each request
+# >0: minimum interval in seconds
+cache_statistics_interval = 300
+
 
 [headers]
 
diff --git a/logging b/logging
index 250359c46..ad831fd13 100644
--- a/logging
+++ b/logging
@@ -22,7 +22,7 @@ keys = console,file
 
 [formatters]
 # Logging formatters
-keys = simple,full
+keys = simple,full,filedebug
 
 
 # Loggers
@@ -31,6 +31,8 @@ keys = simple,full
 # Root logger
 level = DEBUG
 handlers = console,file
+# Disable line above and enable following line for dedicated additional debug log
+#handlers = console,file,filedebug
 
 
 # Handlers
@@ -43,10 +45,27 @@ args = (sys.stderr,)
 formatter = simple
 
 [handler_file]
+formatter = full
+# Enable following line in case dedicated debug log (see below) is activated
+#level = INFO
 # File handler
 class = FileHandler
 args = ('/var/log/radicale',)
+# Time Rotating File Handler (class+args: disable above and enable below)
+# (filename, when, interval, backupCount, ...) [see https://docs.python.org/3/library/logging.handlers.html#logging.handlers.TimedRotatingFileHandler]
+#  example: rollover at midnight every day, keep 90 files (means 90 days)
+#class = handlers.TimedRotatingFileHandler
+#args = ('/var/log/radicale/radicale.log', 'midnight', 1, 90)
+
+[handler_filedebug]
 formatter = full
+# File handler (for dedicated debug log)
+class = FileHandler
+args = ('/var/log/radicale/radicale-debug.log',)
+# Time Rotating File Handler (class+args: disable above and enable below)
+#  example: rollover every hour, keep 24 files (means 1 days)
+#class = handlers.TimedRotatingFileHandler
+#args = ('/var/log/radicale/radicale-debug.log', 'H', 1, 24)
 
 
 # Formatters
diff --git a/radicale-storage-check.py b/radicale-storage-check.py
new file mode 100755
index 000000000..13e5af90e
--- /dev/null
+++ b/radicale-storage-check.py
@@ -0,0 +1,57 @@
+#!/usr/bin/python3.4 -s
+#
+# This file is a tool for the Radicale Server - Calendar Server
+# Copyright © 2016 Peter Bieringer
+#
+# 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/>.
+
+import sys
+import traceback
+import vobject
+
+## Main
+if len(sys.argv) < 2:
+    print ('Missing file names as arguments')
+
+i = 1
+while i < len(sys.argv):
+    path = sys.argv[i]
+    print ('Analyze file:', path)
+    i += 1
+    with open(path, encoding="utf-8", newline="") as f:
+        print ('Read file:', path)
+        text = f.read()
+        print ("Parse file contents:", path)
+        try:
+            item = vobject.readOne(text)
+            print ("Parse file contents successful:", path)
+        except Exception as e:
+            print ("Parse file contents ERROR", path)
+            print ("Unexpected error:", e)
+            traceback.print_exc(file=sys.stdout)
+            exit(1);
+
+        # check whether vobject likes the VCARD item
+        try:
+            print ("Serialize file contents:", path)
+            item_ser = item.serialize()
+            print ("Serialize file contents successful:", path)
+            print ("=== CONTENTS BEGIN ===")
+            print (str(item_ser))
+            print ("=== CONTENTS END ===")
+        except Exception as e:
+            print ("Serialize file contents ERROR", path)
+            print ("Unexpected error:", e)
+            traceback.print_exc(file=sys.stdout)
+            exit(1);
diff --git a/radicale/__init__.py b/radicale/__init__.py
index 09f3d551e..4ba2866ca 100644
--- a/radicale/__init__.py
+++ b/radicale/__init__.py
@@ -42,6 +42,7 @@
 import wsgiref.simple_server
 import zlib
 import datetime
+from hashlib import md5
 from http import client
 from urllib.parse import unquote, urlparse
 
@@ -205,6 +206,8 @@ def __init__(self, configuration, logger):
         self.Collection = storage.load(configuration, logger)
         self.authorized = rights.load(configuration, logger)
         self.encoding = configuration.get("encoding", "request")
+        self.debug = configuration.getboolean("logging", "debug")
+        self.debug_filter = int(configuration.get("logging", "debug_filter"), 0)
 
     def headers_log(self, environ):
         """Sanitize headers for logging."""
@@ -261,18 +264,20 @@ def collect_allowed_items(self, items, user):
             else:
                 path = item.collection.path
             if self.authorized(user, path, "r"):
-                self.logger.debug(
-                    "%s has read access to collection %s",
-                    user or "Anonymous", path or "/")
+                if not self.debug_filter & 0x0080:
+                    self.logger.debug(
+                        "%s has read access to collection %s",
+                        user or "Anonymous", path or "/")
                 read_allowed_items.append(item)
             else:
                 self.logger.debug(
                     "%s has NO read access to collection %s",
                     user or "Anonymous", path or "/")
             if self.authorized(user, path, "w"):
-                self.logger.debug(
-                    "%s has write access to collection %s",
-                    user or "Anonymous", path or "/")
+                if not self.debug_filter & 0x0080:
+                    self.logger.debug(
+                        "%s has write access to collection %s",
+                        user or "Anonymous", path or "/")
                 write_allowed_items.append(item)
             else:
                 self.logger.debug(
@@ -287,7 +292,8 @@ def response(status, headers=(), answer=None):
             headers = dict(headers)
             # Set content length
             if answer:
-                self.logger.debug("Response content:\n%s", answer)
+                if self.debug and not (self.debug_filter & 0x0004):
+                    self.logger.debug("Response content [%s]:\n%s", self.request_token, answer)
                 answer = answer.encode(self.encoding)
                 accept_encoding = [
                     encoding.strip() for encoding in
@@ -308,14 +314,25 @@ def response(status, headers=(), answer=None):
                     headers[key] = self.configuration.get("headers", key)
 
             # Start response
-            time_end = datetime.datetime.now()
             status = "%i %s" % (
                 status, client.responses.get(status, "Unknown"))
+            start_response(status, list(headers.items()))
+            time_end = datetime.datetime.now()
+            sizeinfo = ""
+            if answer:
+                sizeinfo = sizeinfo + str(len(str(answer))) + " bytes"
+            if "Content-Encoding" in headers:
+                if len(sizeinfo) > 0:
+                    sizeinfo = sizeinfo + " "
+                sizeinfo = sizeinfo + headers["Content-Encoding"]
+            if len(sizeinfo) > 0:
+                sizeinfo = " (" + sizeinfo + ")"
             self.logger.info(
-                "%s answer status for %s in %s sec: %s",
-                environ["REQUEST_METHOD"], environ["PATH_INFO"] + depthinfo,
+                "[%s] %s response status for %s in %.3f sec status: %s",
+                self.request_token,
+                environ["REQUEST_METHOD"], environ["PATH_INFO"] + depthinfo + sizeinfo,
                 (time_end - time_begin).total_seconds(), status)
-            start_response(status, list(headers.items()))
+            storage.cache_log_statistics_overall(self)
             # Return response content
             return [answer] if answer else []
 
@@ -334,12 +351,20 @@ def response(status, headers=(), answer=None):
         if environ.get("HTTP_DEPTH"):
             depthinfo = " with depth " + environ["HTTP_DEPTH"]
         time_begin = datetime.datetime.now()
+
+        # Create an unique request token
+        request_token = md5((environ["PATH_INFO"] + depthinfo + remote_host + remote_useragent +str(time_begin)).encode('utf-8')).hexdigest()[1:8]
+        # store token for header/request/response logging
+        self.request_token = request_token
+
         self.logger.info(
-            "%s request for %s received from %s using \"%s\"",
+            "[%s] %s request  for %s received from %s using \"%s\"",
+            self.request_token,
             environ["REQUEST_METHOD"], environ["PATH_INFO"] + depthinfo,
             remote_host, remote_useragent)
-        headers = pprint.pformat(self.headers_log(environ))
-        self.logger.debug("Request headers:\n%s", headers)
+        if self.debug and not (self.debug_filter & 0x0001):
+            headers = pprint.pformat(self.headers_log(environ))
+            self.logger.debug("Request headers [%s]:\n%s", self.request_token, headers)
 
         # Let reverse proxies overwrite SCRIPT_NAME
         if "HTTP_X_SCRIPT_NAME" in environ:
@@ -354,7 +379,8 @@ def response(status, headers=(), answer=None):
         base_prefix = environ["SCRIPT_NAME"]
         # Sanitize request URI
         environ["PATH_INFO"] = storage.sanitize_path(environ["PATH_INFO"])
-        self.logger.debug("Sanitized path: %s", environ["PATH_INFO"])
+        if not (self.debug_filter & 0x0040):
+            self.logger.debug("Sanitized path: %s", environ["PATH_INFO"])
         path = environ["PATH_INFO"]
 
         # Get function corresponding to method
@@ -450,7 +476,8 @@ def _read_content(self, environ):
         if content_length > 0:
             content = self.decode(
                 environ["wsgi.input"].read(content_length), environ)
-            self.logger.debug("Request content:\n%s", content.strip())
+            if self.debug and not (self.debug_filter & 0x0002):
+                self.logger.debug("Request content [%s]:\n%s", self.request_token, content.strip())
         else:
             content = None
         return content
@@ -672,6 +699,9 @@ def do_PUT(self, environ, base_prefix, path, user):
                     parent_item.set_meta({"tag": tag})
                 href = posixpath.basename(path.strip("/"))
                 new_item = parent_item.upload(href, items[0])
+                if not new_item:
+                    # upload not possible because of error
+                    return PRECONDITION_FAILED
             headers = {"ETag": new_item.etag}
             return client.CREATED, headers, None
 
diff --git a/radicale/__main__.py b/radicale/__main__.py
index 79b410a0c..3ba18fee4 100644
--- a/radicale/__main__.py
+++ b/radicale/__main__.py
@@ -34,7 +34,7 @@
 
 from . import (
   VERSION, Application, RequestHandler, ThreadedHTTPServer,
-  ThreadedHTTPSServer, config, log)
+  ThreadedHTTPSServer, config, log, storage)
 
 
 def run():
@@ -142,13 +142,14 @@ def serve(configuration, logger):
     # Register exit function
     def cleanup():
         """Remove the PID files."""
-        logger.debug("Cleaning up")
+        logger.info("Cleaning up 'main'")
         # Remove PID file
         if (configuration.get("server", "pid") and
                 configuration.getboolean("server", "daemon")):
             os.unlink(configuration.get("server", "pid"))
 
     atexit.register(cleanup)
+    atexit.register(storage.cleanup, logger)
     logger.info("Starting Radicale")
 
     # Create collection servers
@@ -188,10 +189,10 @@ def cleanup():
         server = make_server(
             address, port, application, server_class, RequestHandler)
         servers[server.socket] = server
-        logger.debug("Listening to %s port %s",
+        logger.info("Listening to %s port %s",
                      server.server_name, server.server_port)
         if configuration.getboolean("server", "ssl"):
-            logger.debug("Using SSL")
+            logger.info("Using SSL")
 
     # Create a socket pair to notify the select syscall of program shutdown
     # This is not available in python < 3.5 on Windows
@@ -224,7 +225,10 @@ def shutdown(*args):
     else:
         # Fallback to busy waiting
         select_timeout = 1.0
-    logger.debug("Radicale server ready")
+    if configuration.getboolean("logging", "debug"):
+        logger.info("Radicale server ready (with 'debug' enabled)")
+    else:
+        logger.info("Radicale server ready")
     while not shutdown_program:
         try:
             rlist, _, xlist = select.select(
diff --git a/radicale/auth.py b/radicale/auth.py
index 2fa2807ee..30422ec96 100644
--- a/radicale/auth.py
+++ b/radicale/auth.py
@@ -63,7 +63,7 @@
 def load(configuration, logger):
     """Load the authentication manager chosen in configuration."""
     auth_type = configuration.get("auth", "type")
-    logger.debug("Authentication type is %s", auth_type)
+    logger.info("Authentication type is %s", auth_type)
     if auth_type == "None":
         class_ = NoneAuth
     elif auth_type == "htpasswd":
diff --git a/radicale/config.py b/radicale/config.py
index c4c1b38c2..45527c6de 100644
--- a/radicale/config.py
+++ b/radicale/config.py
@@ -115,6 +115,12 @@
         ("filesystem_close_lock_file", {
             "value": "False",
             "help": "close the lock file when no more clients are waiting"}),
+        ("cache_items", {
+            "value": "False",
+            "help": "enable item file caching in memory"}),
+        ("cache_props", {
+            "value": "False",
+            "help": "enable props file caching in memory"}),
         ("hook", {
             "value": "",
             "help": "command that is run after changes to storage"})])),
@@ -126,9 +132,21 @@
             "value": "False",
             "help": "print debug information",
             "aliases": ["-D", "--debug"]}),
+        ("debug_filter", {
+            "value": "0xffff",
+            "help": "filter debug log (binary mask)"}),
+        ("exceptions", {
+            "value" : "False",
+            "help": "include exceptions in logs"}),
+        ("performance", {
+            "value": "False",
+            "help": "include performance statistics in logs on info level"}),
         ("full_environment", {
             "value": "False",
             "help": "store all environment variables"}),
+        ("cache_statistics_interval", {
+            "value": "300",
+            "help": "log interval of item/props cache statistics on info level"}),
         ("mask_passwords", {
             "value": "True",
             "help": "mask passwords in logs"})]))])
diff --git a/radicale/rights.py b/radicale/rights.py
index 00928435a..2d382f78a 100644
--- a/radicale/rights.py
+++ b/radicale/rights.py
@@ -91,6 +91,7 @@ class BaseRights:
     def __init__(self, configuration, logger):
         self.configuration = configuration
         self.logger = logger
+        self.debug_filter = int(configuration.get("logging", "debug_filter"), 0)
 
     def authorized(self, user, collection, permission):
         """Check if the user is allowed to read or write the collection.
@@ -122,7 +123,8 @@ def authorized(self, user, path, permission):
             self.logger.debug("Rights type '%s'", self.rights_type)
             regex.readfp(StringIO(DEFINED_RIGHTS[self.rights_type]))
         else:
-            self.logger.debug("Reading rights from file '%s'", self.filename)
+            if not self.debug_filter & 0x0080:
+                self.logger.debug("Reading rights from file '%s'", self.filename)
             if not regex.read(self.filename):
                 self.logger.error(
                     "File '%s' not found for rights", self.filename)
@@ -131,17 +133,20 @@ def authorized(self, user, path, permission):
         for section in regex.sections():
             re_user = regex.get(section, "user")
             re_collection = regex.get(section, "collection")
-            self.logger.debug(
-                "Test if '%s:%s' matches against '%s:%s' from section '%s'",
-                user, sane_path, re_user, re_collection, section)
+            if not self.debug_filter & 0x0080:
+                self.logger.debug(
+                    "Test if '%s:%s' matches against '%s:%s' from section '%s'",
+                    user, sane_path, re_user, re_collection, section)
             # Emulate fullmatch
             user_match = re.match(r"(?:%s)\Z" % re_user, user)
             if user_match:
                 re_collection = re_collection.format(*user_match.groups())
                 # Emulate fullmatch
                 if re.match(r"(?:%s)\Z" % re_collection, sane_path):
-                    self.logger.debug("Section '%s' matches", section)
+                    if not self.debug_filter & 0x0080:
+                        self.logger.debug("Section '%s' matches", section)
                     return permission in regex.get(section, "permission")
                 else:
-                    self.logger.debug("Section '%s' does not match", section)
+                    if not self.debug_filter & 0x0080:
+                        self.logger.debug("Section '%s' does not match", section)
         return False
diff --git a/radicale/storage.py b/radicale/storage.py
index 89e06dc9c..618c915b2 100644
--- a/radicale/storage.py
+++ b/radicale/storage.py
@@ -36,6 +36,8 @@
 import threading
 import time
 import datetime
+import resource
+import gc
 from contextlib import contextmanager
 from hashlib import md5
 from importlib import import_module
@@ -89,10 +91,51 @@ class Overlapped(ctypes.Structure):
 def load(configuration, logger):
     """Load the storage manager chosen in configuration."""
     storage_type = configuration.get("storage", "type")
+    logger.info("Radicale storage manager loading: %s", storage_type)
+    debug_filter = int(configuration.get("logging", "debug_filter"), 0)
+    if (debug_filter > 0):
+        logger.info("debug filter active with: 0x%x", debug_filter)
+
     if storage_type == "multifilesystem":
         collection_class = Collection
+        ## initialize cache
+        global Items_cache_active
+        global Props_cache_active
+        global Items_cache_counter
+        global Props_cache_counter
+        if configuration.getboolean("storage", "cache_items"):
+            Items_cache_active = True
+            Items_cache_counter.loginterval = seconds=configuration.getint("logging", "cache_statistics_interval")
+            if configuration.getboolean("logging", "performance"):
+                if Items_cache_active:
+                    logger.info("Items cache enabled (performance log on info level)")
+                    Items_cache_counter.perflog = True
+            else:
+                if (Items_cache_counter.loginterval > 0):
+                    logger.info("Items cache enabled (regular statistics log on info level with minimum interval %d sec)", Items_cache_counter.loginterval)
+                else:
+                    logger.info("Items cache enabled (statistics log only on debug level)")
+        else:
+            logger.info("Items cache disabled")
+        if configuration.getboolean("storage", "cache_props"):
+            Props_cache_active = True
+            Props_cache_counter.loginterval = configuration.getint("logging", "cache_statistics_interval")
+            if configuration.getboolean("logging", "performance"):
+                if Props_cache_active:
+                    logger.info("Props cache enabled (performance log on info level)")
+                    Props_cache_counter.perflog = True
+            else:
+                if (Props_cache_counter.loginterval > 0):
+                    logger.info("Props cache enabled (regular statistics log on info level with minimum interval %d sec)", Props_cache_counter.loginterval)
+                else:
+                    logger.info("Props cache enabled (statistics log only on debug level)")
+        else:
+            logger.info("Props cache disabled")
+        if configuration.getboolean("logging", "performance"):
+            logger.info("General performance log on debug level enabled")
     else:
         collection_class = import_module(storage_type).Collection
+    logger.info("Radicale storage manager successfully loaded: %s", storage_type)
 
     class CollectionCopy(collection_class):
         """Collection copy, avoids overriding the original class attributes."""
@@ -101,6 +144,15 @@ class CollectionCopy(collection_class):
     return CollectionCopy
 
 
+def cleanup(logger):
+    """Print cache statistics."""
+    logger.info("Cleaning up 'storage'")
+    if Items_cache_active:
+        logger.info("Items cache overall statistics: %s", Items_cache_counter.string_overall())
+    if Props_cache_active:
+        logger.info("Props cache overall statistics: %s", Props_cache_counter.string_overall())
+
+
 def get_etag(text):
     """Etag from collection or item.
 
@@ -183,6 +235,102 @@ def path_to_filesystem(root, *paths):
     return safe_path
 
 
+### BEGIN Items/Props caching
+## cache counter statistics
+class Cache_counter:
+    def __init__(self):
+        self.lookup = 0
+        self.hit    = 0
+        self.miss   = 0
+        self.dirty  = 0
+        self.entries= 0
+        self.size   = 0
+        self.perflog= False
+        ## cache statistics logging on info level
+        # 0: on each request (incl. current request)
+        # >0: after at least every given loginterval (excl. current request)
+        self.lastlog= datetime.datetime.now()
+        self.loginterval = 60 # default
+
+    def string_overall(self):
+        if (self.entries > 0):
+            message = "lookup=%d hit=%d (%3.2f%%) miss=%d (%3.2f%%) dirty=%d (%3.2f%%) entries=%d memoryKiB=%.3f" % (
+                self.lookup,
+                self.hit,
+                self.hit * 100 / self.lookup,
+                self.miss,
+                self.miss * 100 / self.lookup,
+                self.dirty,
+                self.dirty * 100 / self.lookup,
+                self.entries,
+                self.size / 1024
+            )
+        else:
+            message = "no cache entries"
+        return message 
+
+    def log_overall(self, token, logger):
+        if (self.perflog) or (self.loginterval == 0) or (datetime.datetime.now() - self.lastlog > datetime.timedelta(seconds=self.loginterval)):
+            logger.info("%s cache overall statistics: %s", token, self.string_overall())
+            self.lastlog = datetime.datetime.now()
+        else:
+            logger.debug("%s cache overall statistics: %s", token, self.string_overall())
+
+
+## cache entry
+class Item_cache_entry:
+    def __init__(self, Item, size, last_modified_time):
+        self.Item = Item
+        self.size = size
+        self.last_modified_time = last_modified_time
+
+class Props_cache_entry:
+    def __init__(self, props_contents, size, last_modified_time):
+        self.props_contents = props_contents
+        self.size = size
+        self.last_modified_time = last_modified_time
+
+## cache initialization
+Items_cache_lock = threading.Lock()
+Items_cache_data = {}
+Items_cache_counter = Cache_counter()
+Items_cache_active = False
+
+Props_cache_lock = threading.Lock()
+Props_cache_data = {}
+Props_cache_counter = Cache_counter()
+Props_cache_active = False
+
+## global functions to be called also from other modules
+def cache_log_statistics_overall(self):
+    global Items_cache_counter
+    global Props_cache_counter
+    if Items_cache_active:
+        Items_cache_counter.log_overall("Items", self.logger)
+    if Props_cache_active:
+        Props_cache_counter.log_overall("Props", self.logger)
+    if self.configuration.getboolean("logging", "performance"):
+        # log process statistics
+        rusage = resource.getrusage(resource.RUSAGE_THREAD)
+        self.logger.debug("[%s] ru_utime=%.3f ru_stime=%.3f ru_maxrss=%s ru_inblock=%s ru_oublock=%s", self.request_token,
+            rusage.ru_utime,
+            rusage.ru_stime,
+            rusage.ru_maxrss,
+            rusage.ru_inblock,
+            rusage.ru_oublock)
+        # log garbage collector statistics
+        self.logger.debug("[%s] gc_count=%s gc_threshold=%s gc.unreachable=%d gc.stats.0=%s gc.stats.1=%s gc.stats.2=%s", self.request_token,
+            gc.get_count(),
+            gc.get_threshold(),
+            len(gc.garbage),
+            str(gc.get_stats()[0]),
+            str(gc.get_stats()[1]),
+            str(gc.get_stats()[2]),
+            )
+
+### END Items/Props caching
+
+
 class UnsafePathError(ValueError):
     def __init__(self, path):
         message = "Can't translate name safely to filesystem: %s" % path
@@ -223,6 +371,113 @@ def etag(self):
         return get_etag(self.serialize())
 
 
+### BEGIN Items/Props caching
+## cache counter statistics
+def log_cache_statistics(self):
+    global Item_cache_active
+    global Item_cache_counter
+    global Props_cache_active
+    global Props_cache_counter
+    if Item_cache_active:
+        Item_cache_counter.log("Items", self.logger)
+    if Props_cache_active:
+        Props_cache_counter.log("Props", self.logger)
+
+
+class Cache_counter:
+    def __init__(self):
+        self.lookup = 0
+        self.hit    = 0
+        self.miss   = 0
+        self.dirty  = 0
+        self.entries= 0
+        self.size   = 0
+        self.perflog= False
+        ## cache statistics logging on info level
+        # 0: on each request (incl. current request)
+        # >0: after at least every given loginterval (excl. current request)
+        self.lastlog= datetime.datetime.now()
+        self.loginterval = 60 # default
+
+    def string_overall(self):
+        if (self.entries > 0):
+            message = "lookup=%d hit=%d (%3.2f%%) miss=%d (%3.2f%%) dirty=%d (%3.2f%%) entries=%d memoryKiB=%.3f" % (
+                self.lookup,
+                self.hit,
+                self.hit * 100 / self.lookup,
+                self.miss,
+                self.miss * 100 / self.lookup,
+                self.dirty,
+                self.dirty * 100 / self.lookup,
+                self.entries,
+                self.size / 1024
+            )
+        else:
+            message = "no cache entries"
+        return message
+
+    def log_overall(self, token, logger):
+        if (self.perflog) or (self.loginterval == 0) or (datetime.datetime.now() - self.lastlog > datetime.timedelta(seconds=self.loginterval)):
+            logger.info("%s cache overall statistics: %s", token, self.string_overall())
+            self.lastlog = datetime.datetime.now()
+        else:
+            logger.debug("%s cache overall statistics: %s", token, self.string_overall())
+
+
+## cache entry
+class Item_cache_entry:
+    def __init__(self, Item, size, last_modified_time):
+        self.Item = Item
+        self.size = size
+        self.last_modified_time = last_modified_time
+
+class Props_cache_entry:
+    def __init__(self, props_contents, size, last_modified_time):
+        self.props_contents = props_contents
+        self.size = size
+        self.last_modified_time = last_modified_time
+
+## cache initialization
+Items_cache_lock = threading.Lock()
+Items_cache_data = {}
+Items_cache_counter = Cache_counter()
+Items_cache_active = False
+
+Props_cache_lock = threading.Lock()
+Props_cache_data = {}
+Props_cache_counter = Cache_counter()
+Props_cache_active = False
+
+## global functions to be called also from other modules
+def cache_log_statistics_overall(self):
+    global Items_cache_counter
+    global Props_cache_counter
+    if Items_cache_active:
+        Items_cache_counter.log_overall("Items", self.logger)
+    if Props_cache_active:
+        Props_cache_counter.log_overall("Props", self.logger)
+    if self.configuration.getboolean("logging", "performance"):
+        # log process statistics
+        rusage = resource.getrusage(resource.RUSAGE_THREAD)
+        self.logger.debug("[%s] ru_utime=%.3f ru_stime=%.3f ru_maxrss=%s ru_inblock=%s ru_oublock=%s", self.request_token,
+            rusage.ru_utime,
+            rusage.ru_stime,
+            rusage.ru_maxrss,
+            rusage.ru_inblock,
+            rusage.ru_oublock)
+        # log garbage collector statistics
+        self.logger.debug("[%s] gc_count=%s gc_threshold=%s gc.unreachable=%d gc.stats.0=%s gc.stats.1=%s gc.stats.2=%s", self.request_token,
+            gc.get_count(),
+            gc.get_threshold(),
+            len(gc.garbage),
+            str(gc.get_stats()[0]),
+            str(gc.get_stats()[1]),
+            str(gc.get_stats()[2]),
+            )
+
+### END Items/Props caching
+
+
 class BaseCollection:
 
     # Overriden on copy by the "load" function
@@ -390,6 +645,7 @@ def __init__(self, path, principal=False, folder=None):
         split_path = self.path.split("/")
         self.owner = split_path[0] if len(split_path) > 1 else None
         self.is_principal = principal
+        self.debug_filter = int(self.configuration.get("logging", "debug_filter"), 0)
 
     @classmethod
     def _get_collection_root_folder(cls):
@@ -633,6 +889,10 @@ def list(self):
                 yield href
 
     def get(self, href):
+        global Items_cache_data
+        global Items_cache_counter
+        global Items_cache_active
+        global Items_cache_lock
         if not href:
             return None
         if not is_safe_filesystem_path_component(href):
@@ -642,28 +902,110 @@ def get(self, href):
         path = path_to_filesystem(self._filesystem_path, href)
         if not os.path.isfile(path):
             return None
-        with open(path, encoding=self.encoding, newline="") as f:
-            text = f.read()
+        last_modified_time = os.path.getmtime(path)
         last_modified = time.strftime(
             "%a, %d %b %Y %H:%M:%S GMT",
-            time.gmtime(os.path.getmtime(path)))
-        try:
-            item = vobject.readOne(text)
-        except Exception:
-            self.logger.error("Failed to parse component: %s", href)
-            raise
-        return Item(self, item, href, last_modified)
+            time.gmtime(last_modified_time))
+
+        Item_cache_hit = 0
+        if Items_cache_active:
+            Items_cache_lock.acquire()
+
+            # Item cache lookup
+            Items_cache_counter.lookup += 1
+            if path in Items_cache_data:
+                if Items_cache_data[path].last_modified_time == last_modified_time:
+                    Items_cache_counter.hit += 1
+                    Item_cache_hit = 1
+                else:
+                    Items_cache_counter.dirty += 1
+                    # remove from cache
+                    if not self.debug_filter & 0x0200:
+                        self.logger.debug("Item delete from cache (dirty): %s", path)
+                    Items_cache_counter.entries -= 1
+                    Items_cache_counter.size -= Items_cache_data[path].size
+                    del Items_cache_data[path]
+            else:
+                Items_cache_counter.miss += 1
+
+        if Item_cache_hit == 0 or Items_cache_active == False:
+            with open(path, encoding=self.encoding, newline="") as f:
+                text = f.read()
+                if len(text) == 0:
+                    # empty file
+                    self.logger.error("Object empty (skip 'get'): %s", path)
+                    if Items_cache_active:
+                        Items_cache_lock.release()
+                    return None;
+
+            try:
+                if not self.debug_filter & 0x0100:
+                    self.logger.debug("Item read ('get'): %s", path)
+                item = vobject.readOne(text)
+                if not self.debug_filter & 0x0008:
+                    self.logger.debug("Item content ('get'): %s:\n%s", path, str(item))
+            except Exception as e:
+                self.logger.error("Object broken on read (skip 'get'): %s (%s)", path, e)
+                if self.configuration.getboolean("logging", "exceptions"):
+                    self.logger.exception("Exception details:")
+                if Items_cache_active:
+                    Items_cache_lock.release()
+                return None;
+
+            try:
+                # test whether object is parseable
+                item_serialized = item.serialize()
+            except Exception as e:
+                self.logger.error("Object broken on serialize (skip 'get'): %s (%s)", path, e)
+                if self.configuration.getboolean("logging", "exceptions"):
+                    self.logger.exception("Exception details:")
+                if Items_cache_active:
+                    Items_cache_lock.release()
+                return None;
+
+            # temp object not required
+            del item_serialized
+            # retrieve from cache
+            Item_entry = Item(self, item, href, last_modified)
+
+            if Items_cache_active:
+                # store in cache
+                if not self.debug_filter & 0x1000:
+                    self.logger.debug("Item store in cache: %s", path)
+                Items_cache_data[path] = Item_cache_entry(Item_entry, len(str(Item_entry.item)) + len(path), last_modified_time)
+                Items_cache_counter.size += Items_cache_data[path].size
+                Items_cache_counter.entries += 1
+        else:
+            if not self.debug_filter & 0x2000:
+                self.logger.debug("Item retrieve from cache: %s", path)
+            Item_entry = Items_cache_data[path].Item
+
+        if Items_cache_active:
+            Items_cache_lock.release()
+        return Item_entry
 
     def upload(self, href, vobject_item):
         if not is_safe_filesystem_path_component(href):
             raise UnsafePathError(href)
         path = path_to_filesystem(self._filesystem_path, href)
         item = Item(self, vobject_item, href)
+        try:
+            item_serialized = item.serialize()
+        except Exception as e:
+            self.logger.error("Object broken on serialize (skip 'upload'): %s (%s)", href, e)
+            self.logger.error("Item content ('upload'): %s:\n%s", href, str(vobject_item))
+            if self.configuration.getboolean("logging", "exceptions"):
+                self.logger.exception("Exception details:")
+            return None;
         with self._atomic_write(path, newline="") as fd:
-            fd.write(item.serialize())
+            fd.write(item_serialized)
         return item
 
     def delete(self, href=None):
+        global Items_cache_data
+        global Items_cache_counter
+        global Items_cache_active
+        global Items_cache_lock
         if href is None:
             # Delete the collection
             parent_dir = os.path.dirname(self._filesystem_path)
@@ -684,18 +1026,74 @@ def delete(self, href=None):
             path = path_to_filesystem(self._filesystem_path, href)
             if not os.path.isfile(path):
                 raise ComponentNotFoundError(href)
+            if Items_cache_active:
+                Items_cache_lock.acquire()
+                if path in Items_cache_data:
+                    # remove from cache, if existing
+                    self.logger.debug("Item delete from cache ('delete'): %s", path)
+                    Items_cache_counter.entries -= 1
+                    Items_cache_counter.size -= Items_cache_data[path].size
+                    del Items_cache_data[path]
             os.remove(path)
+            if Items_cache_active:
+                Items_cache_lock.release()
             self._sync_directory(os.path.dirname(path))
 
     def get_meta(self, key=None):
+        global Props_cache_data
+        global Props_cache_active
+        global Props_cache_counter
+        global Props_cache_lock
         if os.path.exists(self._props_path):
-            with open(self._props_path, encoding=self.encoding) as f:
-                meta = json.load(f)
-                return meta.get(key) if key else meta
+            Props_cache_hit = 0
+            if Props_cache_active:
+                Props_cache_lock.acquire()
+                last_modified_time = os.path.getmtime(self._props_path)
+                # Props cache lookup
+                Props_cache_counter.lookup += 1
+                if self._props_path in Props_cache_data:
+                    if Props_cache_data[self._props_path].last_modified_time == last_modified_time:
+                        Props_cache_counter.hit += 1
+                        Props_cache_hit = 1
+                    else:
+                        Props_cache_counter.dirty += 1
+                        # remove from cache
+                        if not self.debug_filter & 0x0800:
+                            self.logger.debug("Props delete from cache (dirty): %s", self._props_path)
+                        Props_cache_counter.size -= Props_cache_data[self._props_path].size
+                        Props_cache_counter.entries -= 1
+                        del Props_cache_data[self._props_path]
+                else:
+                    Props_cache_counter.miss += 1
+
+            if Props_cache_hit == 0 or Props_cache_active == False:
+                with open(self._props_path, encoding=self.encoding) as f:
+                    if not self.debug_filter & 0x0400:
+                        self.logger.debug("Props read ('get_meta')  : %s", self._props_path)
+                    props_contents = json.load(f)
+
+                if Props_cache_active:
+                    # cache handling
+                    if not self.debug_filter & 0x4000:
+                        self.logger.debug("Props store in cache     : %s", self._props_path)
+                    Props_cache_data[self._props_path] = Props_cache_entry(props_contents, len(str(props_contents)) + len(self._props_path), last_modified_time)
+                    Props_cache_counter.size += Props_cache_data[self._props_path].size
+                    Props_cache_counter.entries += 1
+
+                meta = props_contents.get(key) if key else props_contents
+            else:
+                if not self.debug_filter & 0x8000:
+                    self.logger.debug("Props retrieve from cache: %s", self._props_path)
+                meta = Props_cache_data[self._props_path].props_contents.get(key) if key else Props_cache_data[self._props_path].props_contents
+
+            if Props_cache_active:
+                Props_cache_lock.release()
+            return meta
 
     def set_meta(self, props):
         if os.path.exists(self._props_path):
             with open(self._props_path, encoding=self.encoding) as f:
+                self.logger.debug("Write props ('set_meta'): %s", self._props_path)
                 old_props = json.load(f)
                 old_props.update(props)
                 props = old_props
@@ -717,11 +1115,18 @@ def serialize(self):
         items = []
         time_begin = datetime.datetime.now()
         for href in self.list():
-            items.append(self.get(href).item)
+            if hasattr(self.get(href),'item'):
+                items.append(self.get(href).item)
         time_end = datetime.datetime.now()
-        self.logger.info(
-            "Collection read %d items in %s sec from %s", len(items),
-            (time_end - time_begin).total_seconds(), self._filesystem_path)
+        if self.configuration.getboolean("logging", "performance"):
+            self.logger.info(
+                "Collection read %d items in %.3f sec from %s", len(items),
+                (time_end - time_begin).total_seconds(), self._filesystem_path)
+        else:
+            self.logger.debug(
+                "Collection read %d items in %.3f sec from %s", len(items),
+                (time_end - time_begin).total_seconds(), self._filesystem_path)
+        result = ""
         if self.get_meta("tag") == "VCALENDAR":
             collection = vobject.iCalendar()
             for item in items:
@@ -730,10 +1135,20 @@ def serialize(self):
                         for item_part in getattr(item, "%s_list" % content):
                             collection.add(item_part)
                         break
-            return collection.serialize()
+            try:
+                result = collection.serialize()
+            except:
+                self.logger.error("VCALENDAR collection serializing broken: %s (%s)", self._filesystem_path, e)
+                if self.configuration.getboolean("logging", "exceptions"):
+                    self.logger.exception("Exception details:")
         elif self.get_meta("tag") == "VADDRESSBOOK":
-            return "".join([item.serialize() for item in items])
-        return ""
+            try:
+                result = "".join([item.serialize() for item in items])
+            except:
+                self.logger.error("VADDRESSBOOK collection serializing broken: %s (%s)", self._filesystem_path, e)
+                if self.configuration.getboolean("logging", "exceptions"):
+                    self.logger.exception("Exception details:")
+        return result
 
     _lock = threading.Lock()
     _waiters = []
diff --git a/radicale/xmlutils.py b/radicale/xmlutils.py
index 375117c13..79316178d 100644
--- a/radicale/xmlutils.py
+++ b/radicale/xmlutils.py
@@ -679,7 +679,7 @@ def _propfind_response(base_prefix, path, item, props, user, write=False,
             element.append(privilege)
         elif tag == _tag("D", "supported-report-set"):
             for report_name in (
-                    "principal-property-search", "sync-collection",
+                    "principal-property-search",
                     "expand-property", "principal-search-property-set"):
                 supported = ET.Element(_tag("D", "supported-report"))
                 report_tag = ET.Element(_tag("D", "report"))