From 78b4dcecf84d1bb483959bdbf6112d3538075b85 Mon Sep 17 00:00:00 2001 From: Paul Lizer Date: Thu, 7 May 2026 10:35:37 -0400 Subject: [PATCH] improve login loggin --- application/single_app/app.py | 19 ++ application/single_app/config.py | 36 +++- .../single_app/functions_activity_logging.py | 103 +++++++++- .../route_frontend_authentication.py | 3 +- ...UTHENTICATED_REQUEST_LOGIN_ACTIVITY_FIX.md | 99 +++++++++ ...st_authenticated_request_login_activity.py | 192 ++++++++++++++++++ 6 files changed, 441 insertions(+), 11 deletions(-) create mode 100644 docs/explanation/fixes/v0.241.130/AUTHENTICATED_REQUEST_LOGIN_ACTIVITY_FIX.md create mode 100644 functional_tests/test_authenticated_request_login_activity.py diff --git a/application/single_app/app.py b/application/single_app/app.py index fdbaee55d..c1afa7c68 100644 --- a/application/single_app/app.py +++ b/application/single_app/app.py @@ -603,6 +603,23 @@ def _is_idle_timeout_exempt(path): return True return any(path.startswith(prefix) for prefix in IDLE_TIMEOUT_EXEMPT_PREFIXES) + +def maybe_log_authenticated_browser_request(): + """Record throttled login activity for authenticated browser page requests.""" + if request.method != 'GET' or request.path.startswith('/api/'): + return + + user_id = session.get('user', {}).get('oid') or session.get('user', {}).get('sub') + if not user_id: + return + + maybe_log_authenticated_request_login( + user_id=user_id, + session_state=session, + request_path=request.path, + request_method=request.method + ) + @app.before_request def enforce_idle_session_timeout(): """ @@ -646,6 +663,7 @@ def enforce_idle_session_timeout(): if should_refresh_last_activity: session['last_activity_epoch'] = now_epoch session.modified = True + maybe_log_authenticated_browser_request() return None idle_timeout_minutes, _ = get_idle_timeout_settings(request_settings) @@ -698,6 +716,7 @@ def enforce_idle_session_timeout(): session['last_activity_epoch'] = now_epoch session.modified = True + maybe_log_authenticated_browser_request() return None @app.after_request diff --git a/application/single_app/config.py b/application/single_app/config.py index 4d0cb7f0a..7958b14a3 100644 --- a/application/single_app/config.py +++ b/application/single_app/config.py @@ -94,7 +94,7 @@ EXECUTOR_TYPE = 'thread' EXECUTOR_MAX_WORKERS = 30 SESSION_TYPE = 'filesystem' -VERSION = "0.241.022" +VERSION = "0.241.130" SECRET_KEY = os.getenv('SECRET_KEY', 'dev-secret-key-change-in-production') @@ -106,9 +106,9 @@ 'Referrer-Policy': 'strict-origin-when-cross-origin', 'Content-Security-Policy': ( "default-src 'self'; " - "script-src 'self' 'unsafe-inline' 'unsafe-eval'; " + "script-src 'self' 'unsafe-inline' 'unsafe-eval' https://cdn.jsdelivr.net; " #"script-src 'self' 'unsafe-inline' 'unsafe-eval' https://cdn.jsdelivr.net https://code.jquery.com https://stackpath.bootstrapcdn.com; " - "style-src 'self' 'unsafe-inline'; " + "style-src 'self' 'unsafe-inline' https://cdn.jsdelivr.net; " #"style-src 'self' 'unsafe-inline' https://cdn.jsdelivr.net https://stackpath.bootstrapcdn.com; " "img-src 'self' data: https: blob:; " "font-src 'self'; " @@ -309,6 +309,18 @@ def get_redis_cache_infrastructure_endpoint(redis_hostname: str) -> str: partition_key=PartitionKey(path="/conversation_id") ) +cosmos_personal_workflows_container_name = "personal_workflows" +cosmos_personal_workflows_container = cosmos_database.create_container_if_not_exists( + id=cosmos_personal_workflows_container_name, + partition_key=PartitionKey(path="/user_id") +) + +cosmos_personal_workflow_runs_container_name = "personal_workflow_runs" +cosmos_personal_workflow_runs_container = cosmos_database.create_container_if_not_exists( + id=cosmos_personal_workflow_runs_container_name, + partition_key=PartitionKey(path="/user_id") +) + cosmos_group_conversations_container_name = "group_conversations" cosmos_group_conversations_container = cosmos_database.create_container_if_not_exists( id=cosmos_group_conversations_container_name, @@ -321,6 +333,24 @@ def get_redis_cache_infrastructure_endpoint(redis_hostname: str) -> str: partition_key=PartitionKey(path="/conversation_id") ) +cosmos_collaboration_conversations_container_name = "collaboration_conversations" +cosmos_collaboration_conversations_container = cosmos_database.create_container_if_not_exists( + id=cosmos_collaboration_conversations_container_name, + partition_key=PartitionKey(path="/id") +) + +cosmos_collaboration_messages_container_name = "collaboration_messages" +cosmos_collaboration_messages_container = cosmos_database.create_container_if_not_exists( + id=cosmos_collaboration_messages_container_name, + partition_key=PartitionKey(path="/conversation_id") +) + +cosmos_collaboration_user_state_container_name = "collaboration_user_state" +cosmos_collaboration_user_state_container = cosmos_database.create_container_if_not_exists( + id=cosmos_collaboration_user_state_container_name, + partition_key=PartitionKey(path="/user_id") +) + cosmos_settings_container_name = "settings" cosmos_settings_container = cosmos_database.create_container_if_not_exists( id=cosmos_settings_container_name, diff --git a/application/single_app/functions_activity_logging.py b/application/single_app/functions_activity_logging.py index 987a3dec9..f5337562e 100644 --- a/application/single_app/functions_activity_logging.py +++ b/application/single_app/functions_activity_logging.py @@ -5,6 +5,7 @@ """ import logging +import time import uuid from datetime import datetime from typing import Optional, Dict, Any @@ -13,6 +14,83 @@ from config import cosmos_activity_logs_container +USER_LOGIN_ACTIVITY_SESSION_KEY = 'last_user_login_activity_epoch' +USER_LOGIN_ACTIVITY_MIN_INTERVAL_SECONDS = 15 * 60 + + +def _parse_session_epoch(session_state: Optional[dict], session_key: str) -> Optional[int]: + """Safely parse an epoch value stored in session state.""" + if session_state is None: + return None + + raw_epoch = session_state.get(session_key) + if raw_epoch is None: + return None + + try: + return int(float(raw_epoch)) + except (TypeError, ValueError): + return None + + +def record_user_login_session_activity( + session_state: Optional[dict], + now_epoch: Optional[int] = None +) -> Optional[int]: + """Persist the last time login activity was recorded for the current session.""" + if session_state is None: + return None + + resolved_epoch = int(now_epoch if now_epoch is not None else time.time()) + session_state[USER_LOGIN_ACTIVITY_SESSION_KEY] = resolved_epoch + + if hasattr(session_state, 'modified'): + session_state.modified = True + + return resolved_epoch + + +def maybe_log_authenticated_request_login( + user_id: str, + session_state: Optional[dict], + request_path: str, + request_method: str = 'GET', + now_epoch: Optional[int] = None, + login_method: str = 'authenticated_request', + min_interval_seconds: int = USER_LOGIN_ACTIVITY_MIN_INTERVAL_SECONDS +) -> bool: + """ + Log a throttled login-style activity for authenticated browser requests. + + This captures passive SSO/session-based access that never re-enters the + explicit OAuth callback, while preventing per-request log spam. + """ + if not user_id or session_state is None: + return False + + normalized_method = (request_method or '').upper() + if normalized_method != 'GET': + return False + + resolved_epoch = int(now_epoch if now_epoch is not None else time.time()) + last_logged_epoch = _parse_session_epoch(session_state, USER_LOGIN_ACTIVITY_SESSION_KEY) + if last_logged_epoch is not None and (resolved_epoch - last_logged_epoch) < min_interval_seconds: + return False + + log_user_login( + user_id, + login_method, + activity_details={ + 'auth_signal': 'authenticated_request', + 'request_path': request_path, + 'request_method': normalized_method, + 'is_interactive_login': False + } + ) + record_user_login_session_activity(session_state, resolved_epoch) + return True + + def _get_email_domain(email: str) -> str: """Return only the email domain for low-sensitivity audit metadata.""" normalized_email = (email or '').strip() @@ -1113,7 +1191,8 @@ def log_conversation_archival( def log_user_login( user_id: str, - login_method: str = 'azure_ad' + login_method: str = 'azure_ad', + activity_details: Optional[Dict[str, Any]] = None ) -> None: """ Log user login activity to the activity_logs container. @@ -1125,7 +1204,16 @@ def log_user_login( try: # Create login activity record - import uuid + login_details = { + 'login_method': login_method, + 'success': True + } + if activity_details: + login_details.update({ + key: value for key, value in activity_details.items() + if value is not None + }) + login_activity = { 'id': str(uuid.uuid4()), 'user_id': user_id, @@ -1133,11 +1221,12 @@ def log_user_login( 'login_method': login_method, 'timestamp': datetime.utcnow().isoformat(), 'created_at': datetime.utcnow().isoformat(), - 'details': { - 'login_method': login_method, - 'success': True - } + 'details': login_details } + + for key, value in login_details.items(): + if key not in {'login_method', 'success'}: + login_activity[key] = value # Save to activity_logs container cosmos_activity_logs_container.create_item(body=login_activity) @@ -1148,7 +1237,7 @@ def log_user_login( extra=login_activity, level=logging.INFO ) - debug_print(f"✅ User login activity logged for user {user_id}") + debug_print(f"✅ User login activity logged for user {user_id} via {login_method}") except Exception as e: # Log error but don't break the login flow diff --git a/application/single_app/route_frontend_authentication.py b/application/single_app/route_frontend_authentication.py index 3dbec4526..95de17e3d 100644 --- a/application/single_app/route_frontend_authentication.py +++ b/application/single_app/route_frontend_authentication.py @@ -2,6 +2,7 @@ from unittest import result from config import * +from functions_activity_logging import log_user_login, record_user_login_session_activity from functions_authentication import _build_msal_app, _load_cache, _save_cache, clear_requested_oauth_scopes, get_requested_oauth_scopes from functions_debug import debug_print from swagger_wrapper import swagger_route, get_auth_security @@ -133,10 +134,10 @@ def authorized(): # Log the login activity try: - from functions_activity_logging import log_user_login user_id = session['user'].get('oid') or session['user'].get('sub') if user_id: log_user_login(user_id, 'azure_ad') + record_user_login_session_activity(session) except Exception as e: debug_print(f"Could not log login activity: {e}") diff --git a/docs/explanation/fixes/v0.241.130/AUTHENTICATED_REQUEST_LOGIN_ACTIVITY_FIX.md b/docs/explanation/fixes/v0.241.130/AUTHENTICATED_REQUEST_LOGIN_ACTIVITY_FIX.md new file mode 100644 index 000000000..52c5112bf --- /dev/null +++ b/docs/explanation/fixes/v0.241.130/AUTHENTICATED_REQUEST_LOGIN_ACTIVITY_FIX.md @@ -0,0 +1,99 @@ +# Authenticated Request Login Activity Fix + +Fixed/Implemented in version: **0.241.130** + +## Overview + +This fix closes the gap between explicit OAuth callback logins and real authenticated usage. Previously, activity tracking only recorded `user_login` when the `/getAToken` callback completed. Users who arrived with an already-authenticated session or seamless SSO reuse could browse the app without creating the login-style activity that the Control Center and profile dashboards rely on. + +Version implemented: +`config.py` now reports `VERSION = "0.241.130"` for this fix. + +## Issue Description + +- Login analytics depended on an explicit callback event rather than the broader fact that the user had an authenticated browser session. +- Passive SSO or session reuse could authenticate the user successfully but leave login metrics empty or understated. +- Simply logging every authenticated request would have created noisy over-counting, especially for API-heavy pages. + +## Root Cause + +- The application treated `user_login` as a one-time OAuth callback event instead of a reusable authenticated-session signal. +- The authenticated request pipeline had no throttled activity writer for browser page access. +- The explicit callback flow had no session marker to prevent a duplicate login record on the immediate redirect to the landing page. + +## Technical Changes + +### Throttled Authenticated Request Tracking + +Changes implemented: + +- Added a shared authenticated-request helper in `functions_activity_logging.py` that records a `user_login` activity with `login_method = authenticated_request`. +- Added a session-scoped throttle window so repeated authenticated page loads do not emit a record on every request. +- Captured request metadata such as `request_path`, `request_method`, and `auth_signal` for later diagnostics. + +Files involved: + +- `application/single_app/functions_activity_logging.py` +- `application/single_app/app.py` + +Behavioral outcome: + +Authenticated page visits now show up in the existing login analytics even when the user did not intentionally click a login button during that session. + +### OAuth Callback Deduplication + +Changes implemented: + +- Marked the session immediately after the explicit `/getAToken` callback logs `user_login`. +- Reused that session marker to suppress an immediate second `user_login` on the redirect to `/`. + +Files involved: + +- `application/single_app/route_frontend_authentication.py` + +Behavioral outcome: + +Explicit callback logins remain single-counted while passive authenticated navigation still becomes visible later in the session. + +## Files Modified + +- `application/single_app/functions_activity_logging.py` +- `application/single_app/app.py` +- `application/single_app/route_frontend_authentication.py` +- `application/single_app/config.py` +- `functional_tests/test_authenticated_request_login_activity.py` + +## Validation + +Testing approach: + +- Added a focused functional regression test that loads `functions_activity_logging.py` with stubbed dependencies so the new throttle and dedup behavior can be exercised without a live Cosmos dependency. +- Ran targeted compile checks on the edited Python files. + +Validation performed for this implementation: + +- `python -m py_compile application/single_app/functions_activity_logging.py` +- `python -m py_compile application/single_app/app.py` +- `python -m py_compile application/single_app/route_frontend_authentication.py` +- `python -m py_compile functional_tests/test_authenticated_request_login_activity.py` +- `python functional_tests/test_authenticated_request_login_activity.py` + +## Before And After + +Before: + +- Login metrics depended almost entirely on explicit OAuth callback completions. +- Passive SSO/session-reuse visits could authenticate successfully without contributing to login analytics. +- A naive request-level fix risked over-counting every authenticated browser/API request. + +After: + +- Authenticated browser page requests can emit a throttled `user_login` record when no recent login activity has been recorded in the current session. +- Explicit OAuth callback logins still record normally and are not immediately double-counted on redirect. +- Existing dashboards that already query `activity_type = 'user_login'` now see a more representative picture of real authenticated use. + +## User Experience Impact + +- Admins get more representative login activity in the Control Center and profile trends for users who rely on seamless SSO. +- Users do not see any UI change. +- Login metrics should remain substantially less noisy than per-request tracking because the authenticated-request signal is throttled and limited to browser GET requests. \ No newline at end of file diff --git a/functional_tests/test_authenticated_request_login_activity.py b/functional_tests/test_authenticated_request_login_activity.py new file mode 100644 index 000000000..d66db92ba --- /dev/null +++ b/functional_tests/test_authenticated_request_login_activity.py @@ -0,0 +1,192 @@ +# test_authenticated_request_login_activity.py +#!/usr/bin/env python3 +""" +Functional test for authenticated request login activity tracking. +Version: 0.241.130 +Implemented in: 0.241.130 + +This test ensures that passive authenticated browser requests emit a throttled +login activity record and that explicit OAuth callback logins do not double +count on the immediate redirect. +""" + +import importlib.util +import sys +import types +from pathlib import Path + + +REPO_ROOT = Path(__file__).resolve().parents[1] +MODULE_PATH = REPO_ROOT / 'application' / 'single_app' / 'functions_activity_logging.py' +MODULE_NAME = 'functional_test_functions_activity_logging' + + +class FakeContainer: + def __init__(self): + self.items = [] + + def create_item(self, body): + self.items.append(body) + + +class FakeSession(dict): + def __init__(self): + super().__init__() + self.modified = False + + +def load_functions_activity_logging(fake_container): + fake_config = types.ModuleType('config') + fake_config.cosmos_activity_logs_container = fake_container + + fake_appinsights = types.ModuleType('functions_appinsights') + fake_appinsights.logged_events = [] + + def log_event(message, extra=None, level=None, debug_only=False): + fake_appinsights.logged_events.append({ + 'message': message, + 'extra': extra, + 'level': level, + 'debug_only': debug_only + }) + + fake_appinsights.log_event = log_event + + fake_debug = types.ModuleType('functions_debug') + fake_debug.debug_messages = [] + + def debug_print(*args, **kwargs): + fake_debug.debug_messages.append({'args': args, 'kwargs': kwargs}) + + fake_debug.debug_print = debug_print + + module_spec = importlib.util.spec_from_file_location(MODULE_NAME, MODULE_PATH) + module = importlib.util.module_from_spec(module_spec) + + original_modules = { + 'config': sys.modules.get('config'), + 'functions_appinsights': sys.modules.get('functions_appinsights'), + 'functions_debug': sys.modules.get('functions_debug') + } + + sys.modules['config'] = fake_config + sys.modules['functions_appinsights'] = fake_appinsights + sys.modules['functions_debug'] = fake_debug + + try: + module_spec.loader.exec_module(module) + finally: + for name, original_module in original_modules.items(): + if original_module is None: + sys.modules.pop(name, None) + else: + sys.modules[name] = original_module + + return module + + +def assert_true(condition, message): + if not condition: + raise AssertionError(message) + + +def test_authenticated_request_login_is_throttled(): + print('🔍 Testing throttled authenticated-request login activity...') + fake_container = FakeContainer() + activity_logging = load_functions_activity_logging(fake_container) + fake_session = FakeSession() + + first_emit = activity_logging.maybe_log_authenticated_request_login( + user_id='user-123', + session_state=fake_session, + request_path='/profile', + request_method='GET', + now_epoch=2000 + ) + second_emit = activity_logging.maybe_log_authenticated_request_login( + user_id='user-123', + session_state=fake_session, + request_path='/profile', + request_method='GET', + now_epoch=2005 + ) + third_emit = activity_logging.maybe_log_authenticated_request_login( + user_id='user-123', + session_state=fake_session, + request_path='/profile', + request_method='GET', + now_epoch=2000 + activity_logging.USER_LOGIN_ACTIVITY_MIN_INTERVAL_SECONDS + 1 + ) + + assert_true(first_emit is True, 'First authenticated GET should emit a login activity record.') + assert_true(second_emit is False, 'Second authenticated GET inside the throttle window should not emit a record.') + assert_true(third_emit is True, 'Authenticated GET after the throttle window should emit a new record.') + assert_true(len(fake_container.items) == 2, 'Expected exactly two login activity records after throttle validation.') + + first_record = fake_container.items[0] + assert_true(first_record.get('activity_type') == 'user_login', 'Authenticated request should reuse the user_login activity type.') + assert_true(first_record.get('login_method') == 'authenticated_request', 'Authenticated request should record the authenticated_request login method.') + assert_true(first_record.get('auth_signal') == 'authenticated_request', 'Authenticated request should capture the auth signal on the activity record.') + assert_true(first_record.get('request_path') == '/profile', 'Authenticated request should capture the request path on the activity record.') + + +def test_callback_login_marks_session_to_avoid_duplicate_redirect_logging(): + print('🔍 Testing callback-login dedup on immediate redirect...') + fake_container = FakeContainer() + activity_logging = load_functions_activity_logging(fake_container) + fake_session = FakeSession() + + activity_logging.log_user_login('user-123', 'azure_ad') + activity_logging.record_user_login_session_activity(fake_session, now_epoch=3000) + + emitted = activity_logging.maybe_log_authenticated_request_login( + user_id='user-123', + session_state=fake_session, + request_path='/', + request_method='GET', + now_epoch=3005 + ) + + assert_true(emitted is False, 'Immediate browser redirect after explicit login should not create a duplicate login record.') + assert_true(len(fake_container.items) == 1, 'Explicit callback login should remain a single record after immediate redirect.') + assert_true(fake_container.items[0].get('login_method') == 'azure_ad', 'Explicit callback login should preserve the azure_ad login method.') + + +def test_non_get_requests_do_not_emit_login_activity(): + print('🔍 Testing non-GET request exclusion...') + fake_container = FakeContainer() + activity_logging = load_functions_activity_logging(fake_container) + fake_session = FakeSession() + + emitted = activity_logging.maybe_log_authenticated_request_login( + user_id='user-123', + session_state=fake_session, + request_path='/profile', + request_method='POST', + now_epoch=4000 + ) + + assert_true(emitted is False, 'Non-GET authenticated requests should not be counted as login activity.') + assert_true(len(fake_container.items) == 0, 'Non-GET authenticated requests should not create login activity records.') + + +if __name__ == '__main__': + tests = [ + test_authenticated_request_login_is_throttled, + test_callback_login_marks_session_to_avoid_duplicate_redirect_logging, + test_non_get_requests_do_not_emit_login_activity + ] + + failures = 0 + for test in tests: + try: + test() + print(f'✅ {test.__name__} passed') + except Exception as exc: + failures += 1 + print(f'❌ {test.__name__} failed: {exc}') + + if failures: + sys.exit(1) + + print('✅ All authenticated request login activity tests passed') \ No newline at end of file