Improve log messages

Log failed login attempts with remote host as warning (closes #1104)
Add component UID to log message about invalid recurrence rules (reference #602)
Use "forwarded for" instead of "forwarded by" for remote host
This commit is contained in:
Unrud 2020-09-26 22:08:23 +02:00
parent ca27156605
commit d48bacc8e3
9 changed files with 16 additions and 15 deletions

View File

@ -167,8 +167,8 @@ class Application(
elif environ.get("REMOTE_ADDR"): elif environ.get("REMOTE_ADDR"):
remote_host = environ["REMOTE_ADDR"] remote_host = environ["REMOTE_ADDR"]
if environ.get("HTTP_X_FORWARDED_FOR"): if environ.get("HTTP_X_FORWARDED_FOR"):
remote_host = "%r (forwarded by %s)" % ( remote_host = "%s (forwarded for %r)" % (
environ["HTTP_X_FORWARDED_FOR"], remote_host) remote_host, environ["HTTP_X_FORWARDED_FOR"])
remote_useragent = "" remote_useragent = ""
if environ.get("HTTP_USER_AGENT"): if environ.get("HTTP_USER_AGENT"):
remote_useragent = " using %r" % environ["HTTP_USER_AGENT"] remote_useragent = " using %r" % environ["HTTP_USER_AGENT"]
@ -230,7 +230,8 @@ class Application(
elif user: elif user:
logger.info("Successful login: %r -> %r", login, user) logger.info("Successful login: %r -> %r", login, user)
elif login: elif login:
logger.info("Failed login attempt: %r", login) logger.warning("Failed login attempt from %s: %r",
remote_host, login)
# Random delay to avoid timing oracles and bruteforce attacks # Random delay to avoid timing oracles and bruteforce attacks
delay = self.configuration.get("auth", "delay") delay = self.configuration.get("auth", "delay")
if delay > 0: if delay > 0:

View File

@ -39,7 +39,7 @@ class ApplicationMkcalendarMixin:
"Bad MKCALENDAR request on %r: %s", path, e, exc_info=True) "Bad MKCALENDAR request on %r: %s", path, e, exc_info=True)
return httputils.BAD_REQUEST return httputils.BAD_REQUEST
except socket.timeout: except socket.timeout:
logger.debug("client timed out", exc_info=True) logger.debug("Client timed out", exc_info=True)
return httputils.REQUEST_TIMEOUT return httputils.REQUEST_TIMEOUT
# Prepare before locking # Prepare before locking
props = xmlutils.props_from_request(xml_content) props = xmlutils.props_from_request(xml_content)

View File

@ -40,7 +40,7 @@ class ApplicationMkcolMixin:
"Bad MKCOL request on %r: %s", path, e, exc_info=True) "Bad MKCOL request on %r: %s", path, e, exc_info=True)
return httputils.BAD_REQUEST return httputils.BAD_REQUEST
except socket.timeout: except socket.timeout:
logger.debug("client timed out", exc_info=True) logger.debug("Client timed out", exc_info=True)
return httputils.REQUEST_TIMEOUT return httputils.REQUEST_TIMEOUT
# Prepare before locking # Prepare before locking
props = xmlutils.props_from_request(xml_content) props = xmlutils.props_from_request(xml_content)

View File

@ -357,7 +357,7 @@ class ApplicationPropfindMixin:
"Bad PROPFIND request on %r: %s", path, e, exc_info=True) "Bad PROPFIND request on %r: %s", path, e, exc_info=True)
return httputils.BAD_REQUEST return httputils.BAD_REQUEST
except socket.timeout: except socket.timeout:
logger.debug("client timed out", exc_info=True) logger.debug("Client timed out", exc_info=True)
return httputils.REQUEST_TIMEOUT return httputils.REQUEST_TIMEOUT
with self._storage.acquire_lock("r", user): with self._storage.acquire_lock("r", user):
items = self._storage.discover( items = self._storage.discover(

View File

@ -76,7 +76,7 @@ class ApplicationProppatchMixin:
"Bad PROPPATCH request on %r: %s", path, e, exc_info=True) "Bad PROPPATCH request on %r: %s", path, e, exc_info=True)
return httputils.BAD_REQUEST return httputils.BAD_REQUEST
except socket.timeout: except socket.timeout:
logger.debug("client timed out", exc_info=True) logger.debug("Client timed out", exc_info=True)
return httputils.REQUEST_TIMEOUT return httputils.REQUEST_TIMEOUT
with self._storage.acquire_lock("w", user): with self._storage.acquire_lock("w", user):
item = next(self._storage.discover(path), None) item = next(self._storage.discover(path), None)

View File

@ -123,7 +123,7 @@ class ApplicationPutMixin:
logger.warning("Bad PUT request on %r: %s", path, e, exc_info=True) logger.warning("Bad PUT request on %r: %s", path, e, exc_info=True)
return httputils.BAD_REQUEST return httputils.BAD_REQUEST
except socket.timeout: except socket.timeout:
logger.debug("client timed out", exc_info=True) logger.debug("Client timed out", exc_info=True)
return httputils.REQUEST_TIMEOUT return httputils.REQUEST_TIMEOUT
# Prepare before locking # Prepare before locking
content_type = environ.get("CONTENT_TYPE", "").split(";")[0] content_type = environ.get("CONTENT_TYPE", "").split(";")[0]

View File

@ -181,7 +181,7 @@ def xml_report(base_prefix, path, xml_request, collection, encoding,
radicale_filter.prop_match(item.vobject_item, f, "CR") radicale_filter.prop_match(item.vobject_item, f, "CR")
for f in filter_) for f in filter_)
raise ValueError("Unsupported filter test: %r" % test) raise ValueError("Unsupported filter test: %r" % test)
raise ValueError("unsupported filter %r for %r" % (filter_.tag, tag)) raise ValueError("Unsupported filter %r for %r" % (filter_.tag, tag))
while retrieved_items: while retrieved_items:
# ``item.vobject_item`` might be accessed during filtering. # ``item.vobject_item`` might be accessed during filtering.
@ -268,7 +268,7 @@ class ApplicationReportMixin:
"Bad REPORT request on %r: %s", path, e, exc_info=True) "Bad REPORT request on %r: %s", path, e, exc_info=True)
return httputils.BAD_REQUEST return httputils.BAD_REQUEST
except socket.timeout: except socket.timeout:
logger.debug("client timed out", exc_info=True) logger.debug("Client timed out", exc_info=True)
return httputils.REQUEST_TIMEOUT return httputils.REQUEST_TIMEOUT
with contextlib.ExitStack() as lock_stack: with contextlib.ExitStack() as lock_stack:
lock_stack.enter_context(self._storage.acquire_lock("r", user)) lock_stack.enter_context(self._storage.acquire_lock("r", user))

View File

@ -94,7 +94,7 @@ def unspecified_type(value):
def _convert_to_bool(value): def _convert_to_bool(value):
if value.lower() not in RawConfigParser.BOOLEAN_STATES: if value.lower() not in RawConfigParser.BOOLEAN_STATES:
raise ValueError("Not a boolean: %r" % value) raise ValueError("not a boolean: %r" % value)
return RawConfigParser.BOOLEAN_STATES[value.lower()] return RawConfigParser.BOOLEAN_STATES[value.lower()]

View File

@ -134,8 +134,8 @@ def check_and_sanitize_items(vobject_items, is_collection=False, tag=None):
try: try:
component.rruleset component.rruleset
except Exception as e: except Exception as e:
raise ValueError("invalid recurrence rules in %s" % raise ValueError("Invalid recurrence rules in %s in object %r"
component.name) from e % (component.name, component_uid)) from e
elif tag == "VADDRESSBOOK": elif tag == "VADDRESSBOOK":
# https://tools.ietf.org/html/rfc6352#section-5.1 # https://tools.ietf.org/html/rfc6352#section-5.1
object_uids = set() object_uids = set()
@ -311,10 +311,10 @@ class Item:
""" """
if text is None and vobject_item is None: if text is None and vobject_item is None:
raise ValueError( raise ValueError(
"at least one of 'text' or 'vobject_item' must be set") "At least one of 'text' or 'vobject_item' must be set")
if collection_path is None: if collection_path is None:
if collection is None: if collection is None:
raise ValueError("at least one of 'collection_path' or " raise ValueError("At least one of 'collection_path' or "
"'collection' must be set") "'collection' must be set")
collection_path = collection.path collection_path = collection.path
assert collection_path == pathutils.strip_path( assert collection_path == pathutils.strip_path(