Merge pull request #1668 from pbiering/login-cache

add optional cache for login result and htpasswd + fixes

final  version will be updated to 3.4.0 next

.github/workflows/test.yml

@@ -6,10 +6,8 @@ jobs:
     strategy:
       matrix:
         os: [ubuntu-latest, macos-latest, windows-latest]
-        python-version: ['3.8', '3.9', '3.10', '3.11', '3.12.3', '3.13.0', pypy-3.9]
+        python-version: ['3.9', '3.10', '3.11', '3.12.3', '3.13.0', pypy-3.9]
         exclude:
-          - os: windows-latest
-            python-version: pypy-3.8
           - os: windows-latest
             python-version: pypy-3.9
     runs-on: ${{ matrix.os }}

CHANGELOG.md

@@ -1,6 +1,14 @@
 # Changelog
 
 ## 3.3.4.dev
+* Add: option [auth] cache_logins/cache_successful_logins_expiry/cache_failed_logins for caching logins
+* Improve: [auth] log used hash method and result on debug for htpasswd authentication
+* Improve: [auth] htpasswd file now read and verified on start
+* Add: option [auth] htpasswd_cache to automatic re-read triggered on change (mtime or size) instead reading on each request
+* Improve: [auth] htpasswd: module 'bcrypt' is no longer mandatory in case digest method not used in file
+* Improve: [auth] successful/failed login logs now type and whether result was taken from cache
+* Improve: [auth] constant execution time for failed logins independent of external backend or by htpasswd used digest method
+* Drop: support for Python 3.8
 
 ## 3.3.3
 * Add: display mtime_ns precision of storage folder with condition warning if too less

DOCUMENTATION.md

@@ -55,7 +55,7 @@ Follow one of the chapters below depending on your operating system.
 
 #### Linux / \*BSD
 
-First, make sure that **python** 3.8 or later and **pip** are installed. On most distributions it should be
+First, make sure that **python** 3.9 or later and **pip** are installed. On most distributions it should be
 enough to install the package ``python3-pip``.
 
 Then open a console and type:
@@ -812,6 +812,25 @@ Available backends:
 
 Default: `none`
 
+##### cache_logins
+
+Cache successful/failed logins until expiration time. Enable this to avoid
+overload of authentication backends.
+
+Default: `false`
+
+##### cache_successful_logins_expiry
+
+Expiration time of caching successful logins in seconds
+
+Default: `15`
+
+##### cache_failed_logins_expiry
+
+Expiration time of caching failed logins in seconds
+
+Default: `90`
+
 ##### htpasswd_filename
 
 Path to the htpasswd file.
@@ -853,6 +872,12 @@ Available methods:
 
 Default: `autodetect`
 
+##### htpasswd_cache
+
+Enable caching of htpasswd file based on size and mtime_ns
+
+Default: `False`
+
 ##### delay
 
 Average delay after failed login attempts in seconds.

config

@@ -62,6 +62,15 @@
 # Value: none | htpasswd | remote_user | http_x_remote_user | ldap | denyall
 #type = none
 
+# Cache logins for until expiration time
+#cache_logins = false
+
+# Expiration time for caching successful logins in seconds
+#cache_successful_logins_expiry = 15
+
+## Expiration time of caching failed logins in seconds
+#cache_failed_logins_expiry = 90
+
 # URI to the LDAP server
 #ldap_uri = ldap://localhost
 
@@ -103,6 +112,9 @@
 # bcrypt requires the installation of 'bcrypt' module.
 #htpasswd_encryption = autodetect
 
+# Enable caching of htpasswd file based on size and mtime_ns
+#htpasswd_cache = False
+
 # Incorrect authentication delay (seconds)
 #delay = 1
 

pyproject.toml

@@ -17,7 +17,6 @@ classifiers = [
     "License :: OSI Approved :: GNU General Public License (GPL)",
     "Operating System :: OS Independent",
     "Programming Language :: Python :: 3",
-    "Programming Language :: Python :: 3.8",
     "Programming Language :: Python :: 3.9",
     "Programming Language :: Python :: 3.10",
     "Programming Language :: Python :: 3.11",
@@ -28,7 +27,7 @@ classifiers = [
     "Topic :: Office/Business :: Groupware",
 ]
 urls = {Homepage = "https://radicale.org/"}
-requires-python = ">=3.8.0"
+requires-python = ">=3.9.0"
 dependencies = [
     "defusedxml",
     "passlib",

radicale/app/__init__.py

@@ -3,7 +3,7 @@
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
 # Copyright © 2017-2019 Unrud <unrud@outlook.com>
-# Copyright © 2024-2024 Peter Bieringer <pb@bieringer.de>
+# Copyright © 2024-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -252,24 +252,24 @@ def response(status: int, headers: types.WSGIResponseHeaders,
                 self.configuration, environ, base64.b64decode(
                     authorization.encode("ascii"))).split(":", 1)
 
-        user = self._auth.login(login, password) or "" if login else ""
+        (user, info) = self._auth.login(login, password) or ("", "") if login else ("", "")
         if self.configuration.get("auth", "type") == "ldap":
             try:
                 logger.debug("Groups %r", ",".join(self._auth._ldap_groups))
                 self._rights._user_groups = self._auth._ldap_groups
             except AttributeError:
                 pass
         if user and login == user:
-            logger.info("Successful login: %r", user)
+            logger.info("Successful login: %r (%s)", user, info)
         elif user:
-            logger.info("Successful login: %r -> %r", login, user)
+            logger.info("Successful login: %r -> %r (%s)", login, user, info)
         elif login:
-            logger.warning("Failed login attempt from %s: %r",
-                           remote_host, login)
+            logger.warning("Failed login attempt from %s: %r (%s)",
+                           remote_host, login, info)
             # Random delay to avoid timing oracles and bruteforce attacks
             if self._auth_delay > 0:
                 random_delay = self._auth_delay * (0.5 + random.random())
-                logger.debug("Sleeping %.3f seconds", random_delay)
+                logger.debug("Failed login, sleeping random: %.3f sec", random_delay)
                 time.sleep(random_delay)
 
         if user and not pathutils.is_safe_path_component(user):

radicale/auth/__init__.py

@@ -3,7 +3,7 @@
 # Copyright © 2008 Pascal Halter
 # Copyright © 2008-2017 Guillaume Ayoub
 # Copyright © 2017-2022 Unrud <unrud@outlook.com>
-# Copyright © 2024-2024 Peter Bieringer <pb@bieringer.de>
+# Copyright © 2024-2025 Peter Bieringer <pb@bieringer.de>
 #
 # 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
@@ -29,6 +29,9 @@
 
 """
 
+import hashlib
+import threading
+import time
 from typing import Sequence, Set, Tuple, Union, final
 
 from radicale import config, types, utils
@@ -57,6 +60,16 @@ class BaseAuth:
     _lc_username: bool
     _uc_username: bool
     _strip_domain: bool
+    _auth_delay: float
+    _failed_auth_delay: float
+    _type: str
+    _cache_logins: bool
+    _cache_successful: dict                 # login -> (digest, time_ns)
+    _cache_successful_logins_expiry: int
+    _cache_failed: dict                     # digest_failed -> (time_ns, login)
+    _cache_failed_logins_expiry: int
+    _cache_failed_logins_salt_ns: int       # persistent over runtime
+    _lock: threading.Lock
 
     def __init__(self, configuration: "config.Configuration") -> None:
         """Initialize BaseAuth.
@@ -75,6 +88,38 @@ def __init__(self, configuration: "config.Configuration") -> None:
         logger.info("auth.uc_username: %s", self._uc_username)
         if self._lc_username is True and self._uc_username is True:
             raise RuntimeError("auth.lc_username and auth.uc_username cannot be enabled together")
+        self._auth_delay = configuration.get("auth", "delay")
+        logger.info("auth.delay: %f", self._auth_delay)
+        self._failed_auth_delay = 0
+        self._lock = threading.Lock()
+        # cache_successful_logins
+        self._cache_logins = configuration.get("auth", "cache_logins")
+        self._type = configuration.get("auth", "type")
+        if (self._type in ["dovecot", "ldap", "htpasswd"]) or (self._cache_logins is False):
+            logger.info("auth.cache_logins: %s", self._cache_logins)
+        else:
+            logger.info("auth.cache_logins: %s (but not required for type '%s' and disabled therefore)", self._cache_logins, self._type)
+            self._cache_logins = False
+        if self._cache_logins is True:
+            self._cache_successful_logins_expiry = configuration.get("auth", "cache_successful_logins_expiry")
+            if self._cache_successful_logins_expiry < 0:
+                raise RuntimeError("self._cache_successful_logins_expiry cannot be < 0")
+            self._cache_failed_logins_expiry = configuration.get("auth", "cache_failed_logins_expiry")
+            if self._cache_failed_logins_expiry < 0:
+                raise RuntimeError("self._cache_failed_logins_expiry cannot be < 0")
+            logger.info("auth.cache_successful_logins_expiry: %s seconds", self._cache_successful_logins_expiry)
+            logger.info("auth.cache_failed_logins_expiry: %s seconds", self._cache_failed_logins_expiry)
+            # cache init
+            self._cache_successful = dict()
+            self._cache_failed = dict()
+            self._cache_failed_logins_salt_ns = time.time_ns()
+
+    def _cache_digest(self, login: str, password: str, salt: str) -> str:
+        h = hashlib.sha3_512()
+        h.update(salt.encode())
+        h.update(login.encode())
+        h.update(password.encode())
+        return str(h.digest())
 
     def get_external_login(self, environ: types.WSGIEnviron) -> Union[
             Tuple[()], Tuple[str, str]]:
@@ -102,12 +147,132 @@ def _login(self, login: str, password: str) -> str:
 
         raise NotImplementedError
 
+    def _sleep_for_constant_exec_time(self, time_ns_begin: int):
+        """Sleep some time to reach a constant execution time for failed logins
+
+        Independent of time required by external backend or used digest methods
+
+        Increase final execution time in case initial limit exceeded
+
+        See also issue 591
+
+        """
+        time_delta = (time.time_ns() - time_ns_begin) / 1000 / 1000 / 1000
+        with self._lock:
+            # avoid that another thread is changing global value at the same time
+            failed_auth_delay = self._failed_auth_delay
+            failed_auth_delay_old = failed_auth_delay
+            if time_delta > failed_auth_delay:
+                # set new
+                failed_auth_delay = time_delta
+                # store globally
+                self._failed_auth_delay = failed_auth_delay
+        if (failed_auth_delay_old != failed_auth_delay):
+            logger.debug("Failed login constant execution time need increase of failed_auth_delay: %.9f -> %.9f sec", failed_auth_delay_old, failed_auth_delay)
+            # sleep == 0
+        else:
+            sleep = failed_auth_delay - time_delta
+            logger.debug("Failed login constant exection time alignment, sleeping: %.9f sec", sleep)
+            time.sleep(sleep)
+
     @final
-    def login(self, login: str, password: str) -> str:
+    def login(self, login: str, password: str) -> Tuple[str, str]:
+        time_ns_begin = time.time_ns()
+        result_from_cache = False
         if self._lc_username:
             login = login.lower()
         if self._uc_username:
             login = login.upper()
         if self._strip_domain:
             login = login.split('@')[0]
-        return self._login(login, password)
+        if self._cache_logins is True:
+            # time_ns is also used as salt
+            result = ""
+            digest = ""
+            time_ns = time.time_ns()
+            # cleanup failed login cache to avoid out-of-memory
+            cache_failed_entries = len(self._cache_failed)
+            if cache_failed_entries > 0:
+                logger.debug("Login failed cache investigation start (entries: %d)", cache_failed_entries)
+                self._lock.acquire()
+                cache_failed_cleanup = dict()
+                for digest in self._cache_failed:
+                    (time_ns_cache, login_cache) = self._cache_failed[digest]
+                    age_failed = int((time_ns - time_ns_cache) / 1000 / 1000 / 1000)
+                    if age_failed > self._cache_failed_logins_expiry:
+                        cache_failed_cleanup[digest] = (login_cache, age_failed)
+                cache_failed_cleanup_entries = len(cache_failed_cleanup)
+                logger.debug("Login failed cache cleanup start (entries: %d)", cache_failed_cleanup_entries)
+                if cache_failed_cleanup_entries > 0:
+                    for digest in cache_failed_cleanup:
+                        (login, age_failed) = cache_failed_cleanup[digest]
+                        logger.debug("Login failed cache entry for user+password expired: '%s' (age: %d > %d sec)", login_cache, age_failed, self._cache_failed_logins_expiry)
+                        del self._cache_failed[digest]
+                self._lock.release()
+                logger.debug("Login failed cache investigation finished")
+            # check for cache failed login
+            digest_failed = login + ":" + self._cache_digest(login, password, str(self._cache_failed_logins_salt_ns))
+            if self._cache_failed.get(digest_failed):
+                # login+password found in cache "failed" -> shortcut return
+                (time_ns_cache, login_cache) = self._cache_failed[digest]
+                age_failed = int((time_ns - time_ns_cache) / 1000 / 1000 / 1000)
+                logger.debug("Login failed cache entry for user+password found: '%s' (age: %d sec)", login_cache, age_failed)
+                self._sleep_for_constant_exec_time(time_ns_begin)
+                return ("", self._type + " / cached")
+            if self._cache_successful.get(login):
+                # login found in cache "successful"
+                (digest_cache, time_ns_cache) = self._cache_successful[login]
+                digest = self._cache_digest(login, password, str(time_ns_cache))
+                if digest == digest_cache:
+                    age_success = int((time_ns - time_ns_cache) / 1000 / 1000 / 1000)
+                    if age_success > self._cache_successful_logins_expiry:
+                        logger.debug("Login successful cache entry for user+password found but expired: '%s' (age: %d > %d sec)", login, age_success, self._cache_successful_logins_expiry)
+                        # delete expired success from cache
+                        del self._cache_successful[login]
+                        digest = ""
+                    else:
+                        logger.debug("Login successful cache entry for user+password found: '%s' (age: %d sec)", login, age_success)
+                        result = login
+                        result_from_cache = True
+                else:
+                    logger.debug("Login successful cache entry for user+password not matching: '%s'", login)
+            else:
+                # login not found in cache, caculate always to avoid timing attacks
+                digest = self._cache_digest(login, password, str(time_ns))
+            if result == "":
+                # verify login+password via configured backend
+                logger.debug("Login verification for user+password via backend: '%s'", login)
+                result = self._login(login, password)
+                if result != "":
+                    logger.debug("Login successful for user+password via backend: '%s'", login)
+                    if digest == "":
+                        # successful login, but expired, digest must be recalculated
+                        digest = self._cache_digest(login, password, str(time_ns))
+                    # store successful login in cache
+                    self._lock.acquire()
+                    self._cache_successful[login] = (digest, time_ns)
+                    self._lock.release()
+                    logger.debug("Login successful cache for user set: '%s'", login)
+                    if self._cache_failed.get(digest_failed):
+                        logger.debug("Login failed cache for user cleared: '%s'", login)
+                        del self._cache_failed[digest_failed]
+                else:
+                    logger.debug("Login failed for user+password via backend: '%s'", login)
+                    self._lock.acquire()
+                    self._cache_failed[digest_failed] = (time_ns, login)
+                    self._lock.release()
+                    logger.debug("Login failed cache for user set: '%s'", login)
+            if result_from_cache is True:
+                if result == "":
+                    self._sleep_for_constant_exec_time(time_ns_begin)
+                return (result, self._type + " / cached")
+            else:
+                if result == "":
+                    self._sleep_for_constant_exec_time(time_ns_begin)
+                return (result, self._type)
+        else:
+            # self._cache_logins is False
+            result = self._login(login, password)
+            if result == "":
+                self._sleep_for_constant_exec_time(time_ns_begin)
+            return (result, self._type)