Log and count user logins (#4020)

* Log and count user logins

* Allow metrics without label

---------

Co-authored-by: Mira Weller <weller@rami.io>

src/pretix/base/forms/auth.py

@@ -35,6 +35,7 @@
 
 import hashlib
 import ipaddress
+import logging
 
 from django import forms
 from django.conf import settings
@@ -44,10 +45,13 @@ from django.contrib.auth.password_validation import (
 from django.utils.functional import cached_property
 from django.utils.translation import gettext_lazy as _
 
+from pretix.base.metrics import pretix_failed_logins
 from pretix.base.models import User
 from pretix.helpers.dicts import move_to_end
 from pretix.helpers.http import get_client_ip
 
+logger = logging.getLogger(__name__)
+
 
 class LoginForm(forms.Form):
     """
@@ -104,12 +108,16 @@ class LoginForm(forms.Form):
                 rc = get_redis_connection("redis")
                 cnt = rc.get(self.ratelimit_key)
                 if cnt and int(cnt) > 10:
+                    pretix_failed_logins.inc(1, reason="ratelimit")
+                    logger.info("Backend login rejected due to rate limit.")
                     raise forms.ValidationError(self.error_messages['rate_limit'], code='rate_limit')
             self.user_cache = self.backend.form_authenticate(self.request, self.cleaned_data)
             if self.user_cache is None:
                 if self.ratelimit_key:
                     rc.incr(self.ratelimit_key)
                     rc.expire(self.ratelimit_key, 300)
+                logger.info("Backend login invalid.")
+                pretix_failed_logins.inc(1, reason="invalid")
                 raise forms.ValidationError(
                     self.error_messages['invalid_login'],
                     code='invalid_login'
@@ -131,6 +139,8 @@ class LoginForm(forms.Form):
         If the given user may log in, this method should return None.
         """
         if not user.is_active:
+            logger.info("Backend login rejected due to user inactive.")
+            pretix_failed_logins.inc(1, reason="inactive")
             raise forms.ValidationError(
                 self.error_messages['inactive'],
                 code='inactive',

src/pretix/base/metrics.py

@@ -268,7 +268,10 @@ def metric_values():
             dkey = key.decode("utf-8")
             splitted = dkey.split("{", 2)
             value = float(value.decode("utf-8"))
-            metrics[splitted[0]]["{" + splitted[1]] = value
+            if len(splitted) == 1:
+                metrics[splitted[0]][""] = value
+            else:
+                metrics[splitted[0]]["{" + splitted[1]] = value
 
     # Aliases
     aliases = {
@@ -314,3 +317,5 @@ pretix_task_runs_total = Counter("pretix_task_runs_total", "Total calls to a cel
                                  ["task_name", "status"])
 pretix_task_duration_seconds = Histogram("pretix_task_duration_seconds", "Call time of a celery task",
                                          ["task_name"])
+pretix_successful_logins = Counter("pretix_logins_successful", "Successful logins", [])
+pretix_failed_logins = Counter("pretix_logins_failed", "Failed logins", ["reason"])

src/pretix/control/views/auth.py

@@ -60,6 +60,7 @@ from pretix.base.auth import get_auth_backends
 from pretix.base.forms.auth import (
     LoginForm, PasswordForgotForm, PasswordRecoverForm, RegistrationForm,
 )
+from pretix.base.metrics import pretix_failed_logins, pretix_successful_logins
 from pretix.base.models import TeamInvite, U2FDevice, User, WebAuthnDevice
 from pretix.base.services.mail import SendMailException
 from pretix.helpers.http import redirect_to_url
@@ -77,6 +78,7 @@ def process_login(request, user, keep_logged_in):
     request.session['pretix_auth_long_session'] = settings.PRETIX_LONG_SESSIONS and keep_logged_in
     next_url = get_auth_backends()[user.auth_backend].get_next_url(request)
     if user.require_2fa:
+        logger.info(f"Backend login redirected to 2FA for user {user.pk}.")
         request.session['pretix_auth_2fa_user'] = user.pk
         request.session['pretix_auth_2fa_time'] = str(int(time.time()))
         twofa_url = reverse('control:auth.login.2fa')
@@ -84,6 +86,8 @@ def process_login(request, user, keep_logged_in):
             twofa_url += '?next=' + quote(next_url)
         return redirect_to_url(twofa_url)
     else:
+        logger.info(f"Backend login successful for user {user.pk}.")
+        pretix_successful_logins.inc(1)
         auth_login(request, user)
         request.session['pretix_auth_login_time'] = int(time.time())
         if next_url and url_has_allowed_host_and_scheme(next_url, allowed_hosts=None):
@@ -284,7 +288,7 @@ class Forgot(TemplateView):
                         rc.setex('pretix_pwreset_%s' % (user.id), 3600 * 24, '1')
 
             except User.DoesNotExist:
-                logger.warning('Password reset for unregistered e-mail \"' + email + '\" requested.')
+                logger.warning('Backend password reset for unregistered e-mail \"' + email + '\" requested.')
 
             except SendMailException:
                 logger.exception('Sending password reset e-mail to \"' + email + '\" failed.')
@@ -411,6 +415,7 @@ class Login2FAView(TemplateView):
                 fail = True
         logintime = int(request.session.get('pretix_auth_2fa_time', '1'))
         if time.time() - logintime > 300:
+            pretix_failed_logins.inc(1, reason="2fa-timeout")
             fail = True
         if fail:
             messages.error(request, _('Please try again.'))
@@ -443,6 +448,7 @@ class Login2FAView(TemplateView):
                     )
                     sign_count = webauthn_assertion_response.new_sign_count
                     if sign_count < credential_current_sign_count:
+                        pretix_failed_logins.inc(1, reason="webauthn-replay")
                         raise Exception("Possible replay attack, sign count not higher")
                 except Exception:
                     if isinstance(d, U2FDevice):
@@ -460,11 +466,13 @@ class Login2FAView(TemplateView):
                             if webauthn_assertion_response.new_sign_count < 1:
                                 raise Exception("Possible replay attack, sign count set")
                         except Exception:
+                            pretix_failed_logins.inc(1, reason="u2f")
                             logger.exception('U2F login failed')
                         else:
                             valid = True
                             break
                     else:
+                        pretix_failed_logins.inc(1, reason="webauthn")
                         logger.exception('Webauthn login failed')
                 else:
                     if isinstance(d, WebAuthnDevice):
@@ -477,6 +485,8 @@ class Login2FAView(TemplateView):
 
         if valid:
             auth_login(request, self.user)
+            logger.info(f"Backend login successful for user {self.user.pk} with 2FA.")
+            pretix_successful_logins.inc(1)
             request.session['pretix_auth_login_time'] = int(time.time())
             del request.session['pretix_auth_2fa_user']
             del request.session['pretix_auth_2fa_time']
@@ -484,6 +494,7 @@ class Login2FAView(TemplateView):
                 return redirect_to_url(request.GET.get("next"))
             return redirect('control:index')
         else:
+            pretix_failed_logins.inc(1, reason="2fa")
             messages.error(request, _('Invalid code, please try again.'))
             return redirect('control:auth.login.2fa')