From 6ee913502ece34c0125dcac5c298e881e79b8a56 Mon Sep 17 00:00:00 2001 From: Florent Daigniere Date: Thu, 4 May 2023 00:14:44 +0200 Subject: [PATCH 1/6] Improve auth-related logging --- core/admin/mailu/__init__.py | 9 ++++++-- core/admin/mailu/configuration.py | 2 +- core/admin/mailu/internal/nginx.py | 23 +++++++++++-------- core/admin/mailu/internal/views/auth.py | 2 +- core/admin/mailu/sso/views/base.py | 9 ++++++-- core/admin/mailu/ui/templates/token/list.html | 2 ++ core/admin/mailu/utils.py | 3 +++ core/admin/start.py | 13 ++++++----- core/nginx/conf/nginx.conf | 9 ++++++++ core/nginx/conf/proxy.conf | 1 + towncrier/newsfragments/2803.bugfix | 1 + 11 files changed, 52 insertions(+), 22 deletions(-) create mode 100644 towncrier/newsfragments/2803.bugfix diff --git a/core/admin/mailu/__init__.py b/core/admin/mailu/__init__.py index e1347eac..d3971cb1 100644 --- a/core/admin/mailu/__init__.py +++ b/core/admin/mailu/__init__.py @@ -12,8 +12,11 @@ import hmac class NoPingFilter(logging.Filter): def filter(self, record): - if not (record.args['{host}i'] == 'localhost' and record.args['r'] == 'GET /ping HTTP/1.1'): - return True + if (record.args['{host}i'] == 'localhost' and record.args['r'] == 'GET /ping HTTP/1.1'): + return False + if record.args['r'].endswith(' /internal/rspamd/local_domains HTTP/1.1'): + return False + return True class Logger(glogging.Logger): def setup(self, cfg): @@ -46,6 +49,7 @@ def create_app_from_config(config): app.device_cookie_key = hmac.new(bytearray(app.secret_key, 'utf-8'), bytearray('DEVICE_COOKIE_KEY', 'utf-8'), 'sha256').digest() app.temp_token_key = hmac.new(bytearray(app.secret_key, 'utf-8'), bytearray('WEBMAIL_TEMP_TOKEN_KEY', 'utf-8'), 'sha256').digest() app.srs_key = hmac.new(bytearray(app.secret_key, 'utf-8'), bytearray('SRS_KEY', 'utf-8'), 'sha256').digest() + app.truncated_pw_key = hmac.new(bytearray(app.secret_key, 'utf-8'), bytearray('TRUNCATED_PW_KEY', 'utf-8'), 'sha256').digest() # Initialize list of translations app.config.translations = { @@ -63,6 +67,7 @@ def create_app_from_config(config): debug.profiler.init_app(app) if assets := app.config.get('DEBUG_ASSETS'): app.static_folder = assets + app.logger.setLevel(app.config.get('LOG_LEVEL')) # Inject the default variables in the Jinja parser # TODO: move this to blueprints when needed diff --git a/core/admin/mailu/configuration.py b/core/admin/mailu/configuration.py index bc91c332..bb7080c9 100644 --- a/core/admin/mailu/configuration.py +++ b/core/admin/mailu/configuration.py @@ -75,7 +75,7 @@ DEFAULT_CONFIG = { 'API': False, 'WEB_API': '/api', 'API_TOKEN': None, - 'LOG_LEVEL': 'WARNING', + 'LOG_LEVEL': 'INFO', 'SESSION_KEY_BITS': 128, 'SESSION_TIMEOUT': 3600, 'PERMANENT_SESSION_LIFETIME': 30*24*3600, diff --git a/core/admin/mailu/internal/nginx.py b/core/admin/mailu/internal/nginx.py index 0c8ce8e8..634caa52 100644 --- a/core/admin/mailu/internal/nginx.py +++ b/core/admin/mailu/internal/nginx.py @@ -27,23 +27,26 @@ STATUSES = { WEBMAIL_PORTS = ['10143', '10025'] -def check_credentials(user, password, ip, protocol=None, auth_port=None): +def check_credentials(user, password, ip, protocol=None, auth_port=None, source_port=None): if not user or not user.enabled or (protocol == "imap" and not user.enable_imap and not auth_port in WEBMAIL_PORTS) or (protocol == "pop3" and not user.enable_pop): + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: failed: accound disabled') return False - is_ok = False # webmails if auth_port in WEBMAIL_PORTS and password.startswith('token-'): if utils.verify_temp_token(user.get_id(), password): - is_ok = True - if not is_ok and utils.is_app_token(password): + app.logger.debug(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: webmail-token') + return True + if utils.is_app_token(password): for token in user.tokens: if (token.check_password(password) and (not token.ip or token.ip == ip)): - is_ok = True - break - if not is_ok and user.check_password(password): - is_ok = True - return is_ok + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}') + return True + if user.check_password(password): + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: password') + return True + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: failed: badauth: {utils.truncated_pw_hash(password)}') + return False def handle_authentication(headers): """ Handle an HTTP nginx authentication request @@ -100,7 +103,7 @@ def handle_authentication(headers): else: is_valid_user = user is not None ip = urllib.parse.unquote(headers["Client-Ip"]) - if check_credentials(user, password, ip, protocol, headers["Auth-Port"]): + if check_credentials(user, password, ip, protocol, headers["Auth-Port"], headers['Client-Port']): server, port = get_server(headers["Auth-Protocol"], True) return { "Auth-Status": "OK", diff --git a/core/admin/mailu/internal/views/auth.py b/core/admin/mailu/internal/views/auth.py index 3d0e227d..60e16297 100644 --- a/core/admin/mailu/internal/views/auth.py +++ b/core/admin/mailu/internal/views/auth.py @@ -107,7 +107,7 @@ def basic_authentication(): exc = str(exc).split('\n', 1)[0] app.logger.warn(f'Invalid user {user_email!r}: {exc}') else: - if user is not None and nginx.check_credentials(user, password.decode('utf-8'), client_ip, "web"): + if user is not None and nginx.check_credentials(user, password.decode('utf-8'), client_ip, "web", flask.request.headers.get('X-Real-Port', None)): response = flask.Response() response.headers["X-User"] = models.IdnaEmail.process_bind_param(flask_login, user.email, "") utils.limiter.exempt_ip_from_ratelimits(client_ip) diff --git a/core/admin/mailu/sso/views/base.py b/core/admin/mailu/sso/views/base.py index b2e6027f..898d30df 100644 --- a/core/admin/mailu/sso/views/base.py +++ b/core/admin/mailu/sso/views/base.py @@ -17,6 +17,7 @@ def login(): return _proxy() client_ip = flask.request.headers.get('X-Real-IP', flask.request.remote_addr) + client_port = flask.request.headers.get('X-Real-Port', None) form = forms.LoginForm() fields = [] @@ -55,13 +56,13 @@ def login(): flask_login.login_user(user) response = flask.redirect(destination) response.set_cookie('rate_limit', utils.limiter.device_cookie(username), max_age=31536000, path=flask.url_for('sso.login'), secure=app.config['SESSION_COOKIE_SECURE'], httponly=True) - flask.current_app.logger.info(f'Login succeeded for {username} from {client_ip} pwned={form.pwned.data}.') + flask.current_app.logger.info(f'Login attempt for: {username}/sso/{flask.request.headers.get("X-Forwarded-Proto")} from: {client_ip}/{client_port}: success: password: {form.pwned.data}') if msg := utils.isBadOrPwned(form): flask.flash(msg, "error") return response else: utils.limiter.rate_limit_user(username, client_ip, device_cookie, device_cookie_username, form.pw.data) if models.User.get(username) else utils.limiter.rate_limit_ip(client_ip, username) - flask.current_app.logger.warn(f'Login failed for {username} from {client_ip}.') + flask.current_app.logger.info(f'Login attempt for: {username}/sso/{flask.request.headers.get("X-Forwarded-Proto")} from: {client_ip}/{client_port}: failed: badauth: {utils.truncated_pw_hash(form.pw.data)}') flask.flash('Wrong e-mail or password', 'error') return flask.render_template('login.html', form=form, fields=fields) @@ -96,10 +97,12 @@ def _proxy(): proxy_ip = flask.request.headers.get('X-Forwarded-By', flask.request.remote_addr) ip = ipaddress.ip_address(proxy_ip) if not any(ip in cidr for cidr in app.config['PROXY_AUTH_WHITELIST']): + flask.current_app.logger.error('Login failed by proxy - not on whitelist: from {client_ip} through {flask.request.remote_addr}.') return flask.abort(500, '%s is not on PROXY_AUTH_WHITELIST' % proxy_ip) email = flask.request.headers.get(app.config['PROXY_AUTH_HEADER']) if not email: + flask.current_app.logger.error('Login failed by proxy - no header: from {client_ip} through {flask.request.remote_addr}.') return flask.abort(500, 'No %s header' % app.config['PROXY_AUTH_HEADER']) url = _has_usable_redirect(True) or app.config['WEB_ADMIN'] @@ -108,9 +111,11 @@ def _proxy(): if user: flask.session.regenerate() flask_login.login_user(user) + flask.current_app.logger.info(f'Login succeeded by proxy created user: {user} from {client_ip} through {flask.request.remote_addr}.') return flask.redirect(url) if not app.config['PROXY_AUTH_CREATE']: + flask.current_app.logger.warning('Login failed by proxy - does not exist: {user} from {client_ip} through {flask.request.remote_addr}.') return flask.abort(500, 'You don\'t exist. Go away! (%s)' % email) client_ip = flask.request.headers.get('X-Real-IP', flask.request.remote_addr) diff --git a/core/admin/mailu/ui/templates/token/list.html b/core/admin/mailu/ui/templates/token/list.html index 1e61cf6b..f50fd0b8 100644 --- a/core/admin/mailu/ui/templates/token/list.html +++ b/core/admin/mailu/ui/templates/token/list.html @@ -16,6 +16,7 @@ {%- call macros.table(order='[[1,"asc"]]') %} + {% trans %}ID{% endtrans %} {% trans %}Actions{% endtrans %} {% trans %}Comment{% endtrans %} {% trans %}Authorized IP{% endtrans %} @@ -26,6 +27,7 @@ {%- for token in user.tokens %} + {{ token.id }} diff --git a/core/admin/mailu/utils.py b/core/admin/mailu/utils.py index 5ad684ef..c0070de6 100644 --- a/core/admin/mailu/utils.py +++ b/core/admin/mailu/utils.py @@ -532,3 +532,6 @@ def is_app_token(candidate): if len(candidate) == 32 and all(c in string.hexdigits[:-6] for c in candidate): return True return False + +def truncated_pw_hash(pw): + return hmac.new(app.truncated_pw_key, bytearray(pw, 'utf-8'), 'sha256').hexdigest()[:6] diff --git a/core/admin/start.py b/core/admin/start.py index be07f84b..4f30a630 100755 --- a/core/admin/start.py +++ b/core/admin/start.py @@ -52,14 +52,15 @@ def test_DNS(): test_DNS() cmdline = [ - "gunicorn", - "--threads", f"{os.cpu_count()}", - # If SUBNET6 is defined, gunicorn must listen on IPv6 as well as IPv4 - "-b", f"{'[::]' if os.environ.get('SUBNET6') else ''}:80", + "gunicorn", + "--threads", f"{os.cpu_count()}", + # If SUBNET6 is defined, gunicorn must listen on IPv6 as well as IPv4 + "-b", f"{'[::]' if os.environ.get('SUBNET6') else ''}:80", "--logger-class mailu.Logger", + f"--log-level {os.environ.get('LOG_LEVEL', 'INFO')}", "--worker-tmp-dir /dev/shm", - "--error-logfile", "-", - "--preload" + "--error-logfile", "-", + "--preload" ] # logging diff --git a/core/nginx/conf/nginx.conf b/core/nginx/conf/nginx.conf index deadbc57..747d1ada 100644 --- a/core/nginx/conf/nginx.conf +++ b/core/nginx/conf/nginx.conf @@ -348,6 +348,7 @@ mail { protocol smtp; smtp_auth plain; auth_http_header Auth-Port 10025; + auth_http_header Client-Port $remote_port; } # Default IMAP server for the webmail (no encryption, but authentication) @@ -356,6 +357,7 @@ mail { protocol imap; smtp_auth plain; auth_http_header Auth-Port 10143; + auth_http_header Client-Port $remote_port; # ensure we talk HAPROXY protocol to the backends proxy_protocol on; } @@ -381,6 +383,7 @@ mail { protocol smtp; smtp_auth none; auth_http_header Auth-Port 25; + auth_http_header Client-Port $remote_port; } # All other protocols are disabled if TLS is failing @@ -396,6 +399,7 @@ mail { protocol imap; imap_auth plain; auth_http_header Auth-Port 143; + auth_http_header Client-Port $remote_port; # ensure we talk HAPROXY protocol to the backends proxy_protocol on; } @@ -411,6 +415,7 @@ mail { protocol pop3; pop3_auth plain; auth_http_header Auth-Port 110; + auth_http_header Client-Port $remote_port; # ensure we talk HAPROXY protocol to the backends proxy_protocol on; } @@ -426,6 +431,7 @@ mail { protocol smtp; smtp_auth plain login; auth_http_header Auth-Port 587; + auth_http_header Client-Port $remote_port; } {% if TLS %} @@ -437,6 +443,7 @@ mail { protocol smtp; smtp_auth plain login; auth_http_header Auth-Port 465; + auth_http_header Client-Port $remote_port; } server { @@ -447,6 +454,7 @@ mail { protocol imap; imap_auth plain; auth_http_header Auth-Port 993; + auth_http_header Client-Port $remote_port; # ensure we talk HAPROXY protocol to the backends proxy_protocol on; } @@ -459,6 +467,7 @@ mail { protocol pop3; pop3_auth plain; auth_http_header Auth-Port 995; + auth_http_header Client-Port $remote_port; # ensure we talk HAPROXY protocol to the backends proxy_protocol on; } diff --git a/core/nginx/conf/proxy.conf b/core/nginx/conf/proxy.conf index e01a465b..ebbd30aa 100644 --- a/core/nginx/conf/proxy.conf +++ b/core/nginx/conf/proxy.conf @@ -1,6 +1,7 @@ # Default proxy setup proxy_set_header Host $http_host; proxy_set_header X-Real-IP $remote_addr; +proxy_set_header X-Real-Port $remote_port; proxy_hide_header True-Client-IP; proxy_hide_header CF-Connecting-IP; diff --git a/towncrier/newsfragments/2803.bugfix b/towncrier/newsfragments/2803.bugfix new file mode 100644 index 00000000..e82e6bc7 --- /dev/null +++ b/towncrier/newsfragments/2803.bugfix @@ -0,0 +1 @@ +Improve auth-related logging From bd3986131d0c17246da12c19548f645a4f156026 Mon Sep 17 00:00:00 2001 From: Florent Daigniere Date: Fri, 12 May 2023 19:35:06 +0200 Subject: [PATCH 2/6] review --- core/admin/mailu/sso/views/base.py | 6 +++--- core/admin/mailu/ui/templates/token/list.html | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/core/admin/mailu/sso/views/base.py b/core/admin/mailu/sso/views/base.py index 898d30df..f0950468 100644 --- a/core/admin/mailu/sso/views/base.py +++ b/core/admin/mailu/sso/views/base.py @@ -97,12 +97,12 @@ def _proxy(): proxy_ip = flask.request.headers.get('X-Forwarded-By', flask.request.remote_addr) ip = ipaddress.ip_address(proxy_ip) if not any(ip in cidr for cidr in app.config['PROXY_AUTH_WHITELIST']): - flask.current_app.logger.error('Login failed by proxy - not on whitelist: from {client_ip} through {flask.request.remote_addr}.') + flask.current_app.logger.error(f'Login failed by proxy - not on whitelist: from {client_ip} through {flask.request.remote_addr}.') return flask.abort(500, '%s is not on PROXY_AUTH_WHITELIST' % proxy_ip) email = flask.request.headers.get(app.config['PROXY_AUTH_HEADER']) if not email: - flask.current_app.logger.error('Login failed by proxy - no header: from {client_ip} through {flask.request.remote_addr}.') + flask.current_app.logger.error(f'Login failed by proxy - no header: from {client_ip} through {flask.request.remote_addr}.') return flask.abort(500, 'No %s header' % app.config['PROXY_AUTH_HEADER']) url = _has_usable_redirect(True) or app.config['WEB_ADMIN'] @@ -115,7 +115,7 @@ def _proxy(): return flask.redirect(url) if not app.config['PROXY_AUTH_CREATE']: - flask.current_app.logger.warning('Login failed by proxy - does not exist: {user} from {client_ip} through {flask.request.remote_addr}.') + flask.current_app.logger.warning(f'Login failed by proxy - does not exist: {user} from {client_ip} through {flask.request.remote_addr}.') return flask.abort(500, 'You don\'t exist. Go away! (%s)' % email) client_ip = flask.request.headers.get('X-Real-IP', flask.request.remote_addr) diff --git a/core/admin/mailu/ui/templates/token/list.html b/core/admin/mailu/ui/templates/token/list.html index f50fd0b8..37b4e515 100644 --- a/core/admin/mailu/ui/templates/token/list.html +++ b/core/admin/mailu/ui/templates/token/list.html @@ -13,11 +13,11 @@ {%- endblock %} {%- block content %} -{%- call macros.table(order='[[1,"asc"]]') %} +{%- call macros.table(order='[[2,"asc"]]') %} - {% trans %}ID{% endtrans %} {% trans %}Actions{% endtrans %} + {% trans %}ID{% endtrans %} {% trans %}Comment{% endtrans %} {% trans %}Authorized IP{% endtrans %} {% trans %}Created{% endtrans %} @@ -27,10 +27,10 @@ {%- for token in user.tokens %} - {{ token.id }} + {{ token.id }} {{ token.comment }} {{ token.ip or "any" }} {{ token.created_at | format_date }} From c60e2fa52c42d1fa2fea9d7fcaca6766dc2e8b3b Mon Sep 17 00:00:00 2001 From: Florent Daigniere Date: Fri, 12 May 2023 19:41:32 +0200 Subject: [PATCH 3/6] add token.comment too --- core/admin/mailu/internal/nginx.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/admin/mailu/internal/nginx.py b/core/admin/mailu/internal/nginx.py index 634caa52..ecad851d 100644 --- a/core/admin/mailu/internal/nginx.py +++ b/core/admin/mailu/internal/nginx.py @@ -40,7 +40,7 @@ def check_credentials(user, password, ip, protocol=None, auth_port=None, source_ for token in user.tokens: if (token.check_password(password) and (not token.ip or token.ip == ip)): - app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}') + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}: {token.comment or \'\'}') return True if user.check_password(password): app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: password') From e88199e2746cc9c14de56ce0be3afc8ad8fcfdbf Mon Sep 17 00:00:00 2001 From: Florent Daigniere Date: Fri, 12 May 2023 20:27:29 +0200 Subject: [PATCH 4/6] Update nginx.py Doh --- core/admin/mailu/internal/nginx.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/admin/mailu/internal/nginx.py b/core/admin/mailu/internal/nginx.py index ecad851d..bf671dc9 100644 --- a/core/admin/mailu/internal/nginx.py +++ b/core/admin/mailu/internal/nginx.py @@ -40,7 +40,7 @@ def check_credentials(user, password, ip, protocol=None, auth_port=None, source_ for token in user.tokens: if (token.check_password(password) and (not token.ip or token.ip == ip)): - app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}: {token.comment or \'\'}') + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}: {token.comment or ""}') return True if user.check_password(password): app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: password') From 10429117322b0807c3384cd8fe6cfb851cfae9fe Mon Sep 17 00:00:00 2001 From: Florent Daigniere Date: Fri, 12 May 2023 21:14:39 +0200 Subject: [PATCH 5/6] Update nginx.py Fix typo --- core/admin/mailu/internal/nginx.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/admin/mailu/internal/nginx.py b/core/admin/mailu/internal/nginx.py index bf671dc9..1aab798a 100644 --- a/core/admin/mailu/internal/nginx.py +++ b/core/admin/mailu/internal/nginx.py @@ -29,7 +29,7 @@ WEBMAIL_PORTS = ['10143', '10025'] def check_credentials(user, password, ip, protocol=None, auth_port=None, source_port=None): if not user or not user.enabled or (protocol == "imap" and not user.enable_imap and not auth_port in WEBMAIL_PORTS) or (protocol == "pop3" and not user.enable_pop): - app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: failed: accound disabled') + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: failed: account disabled') return False # webmails if auth_port in WEBMAIL_PORTS and password.startswith('token-'): From 1ffb78103ff94f377ff68d31daacc6f3a7bf6525 Mon Sep 17 00:00:00 2001 From: Florent Daigniere Date: Sat, 13 May 2023 11:55:54 +0200 Subject: [PATCH 6/6] quote the comments --- core/admin/mailu/internal/nginx.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/admin/mailu/internal/nginx.py b/core/admin/mailu/internal/nginx.py index ecad851d..be004272 100644 --- a/core/admin/mailu/internal/nginx.py +++ b/core/admin/mailu/internal/nginx.py @@ -40,7 +40,7 @@ def check_credentials(user, password, ip, protocol=None, auth_port=None, source_ for token in user.tokens: if (token.check_password(password) and (not token.ip or token.ip == ip)): - app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}: {token.comment or \'\'}') + app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: token-{token.id}: {token.comment or \'\'!r}') return True if user.check_password(password): app.logger.info(f'Login attempt for: {user}/{protocol}/{auth_port} from: {ip}/{source_port}: success: password')