From 567bd9120fab7b30e91a511d82e93d6f0c0696a8 Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Thu, 12 Jun 2025 10:03:27 +0000 Subject: [PATCH 01/19] fix: session ID stability while maintaining inactivity timeout This change modifies the SessionInactivityTimeout middleware to prevent the session ID from changing on every request while still enforcing the inactivity timeout. Key improvements: - Store datetime values as ISO strings for proper serialization - Implement hybrid session save approach that only allows full session saves periodically (controlled by SESSION_SAVE_FREQUENCY_SECONDS) - Preserve session ID between requests while still tracking user activity This resolves the issue where lms_sessionid was changing on every user interaction, which caused problems. --- .../session_inactivity_timeout/middleware.py | 54 ++++++++++++++----- 1 file changed, 41 insertions(+), 13 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 08e9d0e0e879..da737d66a427 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -14,13 +14,16 @@ from datetime import datetime, timedelta +import logging from django.conf import settings from django.contrib import auth from django.utils.deprecation import MiddlewareMixin LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch' +LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' +LOG = logging.getLogger(__name__) class SessionInactivityTimeout(MiddlewareMixin): """ @@ -38,23 +41,48 @@ def process_request(self, request): # Do we have this feature enabled? if timeout_in_seconds: + frequency_time_in_seconds = getattr(settings, "SESSION_SAVE_FREQUENCY_SECONDS", 60) # what time is it now? utc_now = datetime.utcnow() # Get the last time user made a request to server, which is stored in session data - last_touch = request.session.get(LAST_TOUCH_KEYNAME) + last_touch_str = request.session.get(LAST_TOUCH_KEYNAME) # have we stored a 'last visited' in session? NOTE: first time access after login # this key will not be present in the session data - if last_touch: - # compute the delta since last time user came to the server - time_since_last_activity = utc_now - last_touch - - # did we exceed the timeout limit? - if time_since_last_activity > timedelta(seconds=timeout_in_seconds): - # yes? Then log the user out - del request.session[LAST_TOUCH_KEYNAME] - auth.logout(request) - return - - request.session[LAST_TOUCH_KEYNAME] = utc_now + if last_touch_str: + try: + # Convert the ISO string back to a datetime object + last_touch = datetime.fromisoformat(last_touch_str) + + # compute the delta since last time user came to the server + time_since_last_activity = utc_now - last_touch + + # did we exceed the timeout limit? + if time_since_last_activity > timedelta(seconds=timeout_in_seconds): + # yes? Then log the user out + del request.session[LAST_TOUCH_KEYNAME] + auth.logout(request) + return + except (ValueError, TypeError) as e: + # If parsing fails, treat as if no timestamp exists + pass + else: + LOG.info("No previous activity timestamp found (first login)") + + # Store activity timestamp + request.session[LAST_TOUCH_KEYNAME] = utc_now.isoformat() + + # Periodically allow a full save (every n seconds) + last_save = request.session.get(LAST_SESSION_SAVE_TIME_KEYNAME) + current_time = datetime.utcnow().isoformat() + + if not last_save or ( + datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < datetime.utcnow() + ): + # Allow a full session save periodically + request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time + # Don't set modified=was_modified here! Let Django save the session + else: + # Only prevent saving in this branch + request.session.modified = False From f4a3d7479d06adcb2f787a489e581450ba017830 Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Fri, 13 Jun 2025 05:03:10 +0000 Subject: [PATCH 02/19] fix: linter issue --- openedx/core/djangoapps/session_inactivity_timeout/middleware.py | 1 + 1 file changed, 1 insertion(+) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index da737d66a427..78ecde0d4901 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -25,6 +25,7 @@ LOG = logging.getLogger(__name__) + class SessionInactivityTimeout(MiddlewareMixin): """ Middleware class to keep track of activity on a given session From b5f4baf00fba8aa28bb98fca247e8f531913fa26 Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Tue, 17 Jun 2025 12:08:24 +0000 Subject: [PATCH 03/19] fix!: session ID stability while maintaining inactivity timeout This change modifies the SessionInactivityTimeout middleware to prevent the session ID from changing on every request while still enforcing the inactivity timeout. --- .../session_inactivity_timeout/middleware.py | 2 +- .../tests/__init__.py | 3 + .../tests/test_middleware.py | 523 ++++++++++++++++++ 3 files changed, 527 insertions(+), 1 deletion(-) create mode 100644 openedx/core/djangoapps/session_inactivity_timeout/tests/__init__.py create mode 100644 openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 78ecde0d4901..5b595c3660cb 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -42,7 +42,7 @@ def process_request(self, request): # Do we have this feature enabled? if timeout_in_seconds: - frequency_time_in_seconds = getattr(settings, "SESSION_SAVE_FREQUENCY_SECONDS", 60) + frequency_time_in_seconds = getattr(settings, "SESSION_SAVE_FREQUENCY_SECONDS", 900) # what time is it now? utc_now = datetime.utcnow() diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/__init__.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/__init__.py new file mode 100644 index 000000000000..3588e949e3b1 --- /dev/null +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/__init__.py @@ -0,0 +1,3 @@ +""" +Tests for session inactivity timeout middleware. +""" diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py new file mode 100644 index 000000000000..5820ae9d9a4e --- /dev/null +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -0,0 +1,523 @@ +""" +Unit tests for SessionInactivityTimeout middleware. +""" +import logging +from datetime import datetime, timedelta +from unittest.mock import Mock, patch + +from django.conf import settings +from django.contrib.auth import SESSION_KEY +from django.contrib.auth.models import AnonymousUser +from django.test import TestCase, RequestFactory, override_settings + +from common.djangoapps.student.tests.factories import UserFactory +from openedx.core.djangolib.testing.utils import get_mock_request + +from ..middleware import ( + SessionInactivityTimeout, + LAST_TOUCH_KEYNAME, + LAST_SESSION_SAVE_TIME_KEYNAME +) + + +class SessionInactivityTimeoutTestCase(TestCase): + """ + Test cases for SessionInactivityTimeout middleware. + """ + + def setUp(self): + """ + Set up test data. + """ + super().setUp() + self.user = UserFactory.create() + self.middleware = SessionInactivityTimeout(get_response=lambda request: None) + self.request = get_mock_request(self.user) + + # Create a proper session object with all necessary attributes + from django.contrib.sessions.backends.db import SessionStore + self.request.session = SessionStore() + self.request.session.create() + self.request.session.modified = False + + def test_process_request_unauthenticated_user_does_nothing(self): + """ + Test that middleware does nothing for unauthenticated users. + """ + self.request.user = AnonymousUser() + + response = self.middleware.process_request(self.request) + + assert response is None + assert LAST_TOUCH_KEYNAME not in self.request.session + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=None) + def test_process_request_timeout_disabled_does_nothing(self): + """ + Test that middleware does nothing when timeout is disabled. + """ + response = self.middleware.process_request(self.request) + + assert response is None + assert LAST_TOUCH_KEYNAME not in self.request.session + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_first_visit_sets_timestamp(self, mock_datetime): + """ + Test that first visit sets timestamp in session. + """ + mock_now = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = mock_now + + with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='INFO') as log: + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == mock_now.isoformat() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_within_timeout_updates_timestamp(self, mock_datetime): + """ + Test that request within timeout period and updates timestamp. + """ + # Set up existing timestamp (5 minutes ago) + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 4, 0) # 4 minutes later + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + # Should not log out user + assert hasattr(self.request, 'user') + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') + def test_process_request_timeout_exceeded_logs_out_user(self, mock_auth, mock_datetime): + """ + Test that request exceeding timeout period logs out user. + """ + # Set up existing timestamp (10 minutes ago) + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 10, 0) # 10 minutes later + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + + # Mock all datetime.utcnow() calls to return current_time + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + response = self.middleware.process_request(self.request) + + assert response is None + # The middleware deletes the key before logging out + assert LAST_TOUCH_KEYNAME not in self.request.session + mock_auth.logout.assert_called_once_with(self.request) + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_invalid_timestamp_handles_gracefully(self, mock_datetime): + """ + Test that invalid timestamp in session is handled gracefully. + """ + # Set up invalid timestamp + self.request.session[LAST_TOUCH_KEYNAME] = "invalid-timestamp" + mock_now = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = mock_now + + response = self.middleware.process_request(self.request) + + assert response is None + # Should set new timestamp despite invalid old one + assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + + @override_settings( + SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900, # 15 minutes timeout + SESSION_SAVE_FREQUENCY_SECONDS=600 + ) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_session_save_frequency_within_period(self, mock_datetime): + """ + Test that session.modified is set to False when within save frequency period. + """ + # Set up times + last_save = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 5, 0) # 5 minutes later (< 10 min frequency, < 15 min timeout) + + self.request.session[LAST_TOUCH_KEYNAME] = last_save.isoformat() + self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = last_save.isoformat() + + # Mock datetime methods properly + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session.modified is False + + @override_settings( + SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900, # 15 minutes timeout + SESSION_SAVE_FREQUENCY_SECONDS=600 + ) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_session_save_frequency_exceeded(self, mock_datetime): + """ + Test that session save time is updated when frequency period is exceeded. + """ + # Set up times + last_save = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 12, 0) # 12 minutes later (> 10 min frequency, < 15 min timeout) + + self.request.session[LAST_TOUCH_KEYNAME] = last_save.isoformat() + self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = last_save.isoformat() + + # Mock datetime methods properly + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() + # session.modified should not be explicitly set to False + + @override_settings( + SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300, + SESSION_SAVE_FREQUENCY_SECONDS=600 + ) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_no_last_save_time_sets_new_save_time(self, mock_datetime): + """ + Test that when no last save time exists, a new one is set. + """ + current_time = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = current_time + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_type_error_in_timestamp_parsing(self, mock_datetime): + """ + Test that TypeError in timestamp parsing is handled gracefully. + """ + # Set up session with non-string value that would cause TypeError + self.request.session[LAST_TOUCH_KEYNAME] = 12345 # Not a string + mock_now = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = mock_now + + response = self.middleware.process_request(self.request) + + assert response is None + # Should set new timestamp despite type error + assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') + def test_process_request_exact_timeout_logs_out_user(self, mock_auth, mock_datetime): + """ + Test that request just after timeout period logs out user. + """ + # Set up existing timestamp just over 300 seconds ago + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 5, 1) # 301 seconds later (> 300) + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + + # Mock datetime methods properly + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + response = self.middleware.process_request(self.request) + + assert response is None + assert LAST_TOUCH_KEYNAME not in self.request.session + mock_auth.logout.assert_called_once_with(self.request) + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') + def test_process_request_one_second_before_timeout_does_not_logout(self, mock_auth, mock_datetime): + """ + Test that request one second before timeout does not log out user. + """ + # Set up existing timestamp 299 seconds ago (just under timeout) + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 4, 59) # 299 seconds later + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + mock_auth.logout.assert_not_called() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') + def test_process_request_exactly_timeout_does_not_logout(self, mock_auth, mock_datetime): + """ + Test that request at exactly timeout period does NOT log out user (> not >=). + """ + # Set up existing timestamp exactly 300 seconds ago + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 5, 0) # Exactly 300 seconds later + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + mock_auth.logout.assert_not_called() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_uses_default_save_frequency(self, mock_datetime): + """ + Test that default save frequency (900 seconds) is used when not specified. + """ + current_time = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = current_time + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() + + def test_middleware_inherits_from_middleware_mixin(self): + """ + Test that SessionInactivityTimeout properly inherits from MiddlewareMixin. + """ + from django.utils.deprecation import MiddlewareMixin + assert issubclass(SessionInactivityTimeout, MiddlewareMixin) + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_empty_session(self, mock_datetime): + """ + Test that middleware works correctly with completely empty session. + """ + # Clear the session but keep it as a proper session object + self.request.session.flush() + mock_now = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = mock_now + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == mock_now.isoformat() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=0) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') + def test_process_request_zero_timeout_disables_feature(self, mock_auth, mock_datetime): + """ + Test that zero timeout disables the timeout feature entirely. + In Python, 0 is falsy, so `if timeout_in_seconds:` is False. + """ + # Set up existing timestamp + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 0, 10) # 10 seconds later + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + + # Mock all datetime methods properly + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + response = self.middleware.process_request(self.request) + + assert response is None + # User should NOT be logged out because 0 timeout disables the feature + mock_auth.logout.assert_not_called() + # Original timestamp should remain unchanged + assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_microsecond_precision_timestamps(self, mock_datetime): + """ + Test that middleware handles timestamps with microsecond precision. + """ + # Set up timestamp with microseconds + last_touch = datetime(2025, 6, 16, 12, 0, 0, 123456) + current_time = datetime(2025, 6, 16, 12, 2, 0, 654321) + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + + response = self.middleware.process_request(self.request) + + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + def test_constants_are_properly_defined(self): + """ + Test that the required constants are properly defined. + """ + assert LAST_TOUCH_KEYNAME == 'SessionInactivityTimeout:last_touch' + assert LAST_SESSION_SAVE_TIME_KEYNAME == 'SessionInactivityTimeout:last_session_save_time' + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900) # 15 minutes timeout + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_process_request_session_modified_flag_behavior(self, mock_datetime): + """ + Test the session.modified flag behavior under different conditions. + """ + current_time = datetime(2025, 6, 16, 12, 0, 0) + + # Mock datetime methods properly + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + # First request - should not set modified to False + response = self.middleware.process_request(self.request) + assert response is None + # Default behavior for new session data + + # Second request within save frequency - should set modified to False + with override_settings(SESSION_SAVE_FREQUENCY_SECONDS=600): + self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time.isoformat() + response = self.middleware.process_request(self.request) + assert response is None + assert self.request.session.modified is False + + +class SessionInactivityTimeoutLoggingTestCase(TestCase): + """ + Test cases specifically for logging behavior. + """ + + def setUp(self): + """ + Set up test data. + """ + super().setUp() + self.user = UserFactory.create() + self.middleware = SessionInactivityTimeout(get_response=lambda request: None) + self.request = get_mock_request(self.user) + + # Create a proper session object with all necessary attributes + from django.contrib.sessions.backends.db import SessionStore + self.request.session = SessionStore() + self.request.session.create() + self.request.session.modified = False + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + def test_logging_first_login_message(self): + """ + Test that first login message is logged appropriately. + """ + with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='INFO') as log: + self.middleware.process_request(self.request) + + assert len(log.output) == 1 + assert "No previous activity timestamp found (first login)" in log.output[0] + assert "INFO" in log.output[0] + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + def test_no_logging_for_normal_requests(self, mock_datetime): + """ + Test that normal requests (not first login) don't generate log messages. + """ + # Set up existing timestamp + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 2, 0) + + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + + # Process request - should not generate any logs + response = self.middleware.process_request(self.request) + assert response is None + + +class SessionInactivityTimeoutIntegrationTestCase(TestCase): + """ + Integration test cases for SessionInactivityTimeout middleware. + """ + + def setUp(self): + """ + Set up test data. + """ + super().setUp() + self.user = UserFactory.create() + self.factory = RequestFactory() + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + def test_integration_with_django_session_framework(self): + """ + Test integration with Django's session framework. + """ + from django.contrib.sessions.middleware import SessionMiddleware + + # Create a request + request = self.factory.get('/test/') + request.user = self.user + + # Process through session middleware first + session_middleware = SessionMiddleware(get_response=lambda request: None) + session_middleware.process_request(request) + + # Process through our middleware + timeout_middleware = SessionInactivityTimeout(get_response=lambda request: None) + response = timeout_middleware.process_request(request) + + assert response is None + assert LAST_TOUCH_KEYNAME in request.session + assert LAST_SESSION_SAVE_TIME_KEYNAME in request.session + + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=1) # Very short timeout + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') + def test_integration_logout_behavior(self, mock_auth, mock_datetime): + """ + Test integration of logout behavior with auth system. + """ + from django.contrib.sessions.middleware import SessionMiddleware + + # Create a request + request = self.factory.get('/test/') + request.user = self.user + + # Set up session + session_middleware = SessionMiddleware(get_response=lambda request: None) + session_middleware.process_request(request) + + # Set up existing timestamp (3 seconds ago, which exceeds 1-second timeout) + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = datetime(2025, 6, 16, 12, 0, 3) + + request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + + # Mock datetime methods properly + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + # Process through our middleware + timeout_middleware = SessionInactivityTimeout(get_response=lambda request: None) + response = timeout_middleware.process_request(request) + + assert response is None + assert LAST_TOUCH_KEYNAME not in request.session + mock_auth.logout.assert_called_once_with(request) From 8dd5bd2bc391e92b9e9d8cfa6904f85cf2a044d4 Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Tue, 17 Jun 2025 12:20:00 +0000 Subject: [PATCH 04/19] fix!: session ID stability while maintaining inactivity timeout This change modifies the SessionInactivityTimeout middleware to prevent the session ID from changing on every request while still enforcing the inactivity timeout. --- .../session_inactivity_timeout/middleware.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 5b595c3660cb..518fb76f8996 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -38,10 +38,24 @@ def process_request(self, request): #Can't log out if not logged in return + # .. setting_name: SESSION_INACTIVITY_TIMEOUT_IN_SECONDS + # .. setting_default: None + # .. setting_description: Used for maintaining session inactivity up to n hours + # .. setting_warning: Keep in sync with SESSION_COOKIE_AGE and SESSION_SAVE_FREQUENCY_SECONDS timeout_in_seconds = getattr(settings, "SESSION_INACTIVITY_TIMEOUT_IN_SECONDS", None) # Do we have this feature enabled? if timeout_in_seconds: + # .. setting_name: SESSION_SAVE_FREQUENCY_SECONDS + # .. setting_default: 900 + # .. setting_description: How often to allow a full session save (in seconds). + # This controls how frequently the session ID might change + # A user could be inactive for almost SESSION_SAVE_FREQUENCY_SECONDS but since their session + # isn't being saved during that time, their last activity timestamp isn't being updated. + # When they hit the inactivity timeout, it will be based on the last saved activity time + # So the effective timeout could be as short as: SESSION_INACTIVITY_TIMEOUT_IN_SECONDS - SESSION_SAVE_FREQUENCY_SECONDS + # This means users might be logged out earlier than expected in some edge cases. + # .. setting_warning: Used in sync with SESSION_INACTIVITY_TIMEOUT_IN_SECONDS frequency_time_in_seconds = getattr(settings, "SESSION_SAVE_FREQUENCY_SECONDS", 900) # what time is it now? utc_now = datetime.utcnow() From 4f2ca2943daa1ef049f154d48b78fe83f32ecbcc Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Fri, 20 Jun 2025 11:13:23 +0000 Subject: [PATCH 05/19] fix: update session inactivity middleware to use consistent naming and improve logging levels --- .../session_inactivity_timeout/middleware.py | 30 +++++++++++------- .../tests/test_middleware.py | 31 +++++++++---------- 2 files changed, 32 insertions(+), 29 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 518fb76f8996..36baae80e2fe 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -19,8 +19,9 @@ from django.conf import settings from django.contrib import auth from django.utils.deprecation import MiddlewareMixin +from edx_django_utils import monitoring as monitoring_utils -LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch' +LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' LOG = logging.getLogger(__name__) @@ -40,23 +41,23 @@ def process_request(self, request): # .. setting_name: SESSION_INACTIVITY_TIMEOUT_IN_SECONDS # .. setting_default: None - # .. setting_description: Used for maintaining session inactivity up to n hours - # .. setting_warning: Keep in sync with SESSION_COOKIE_AGE and SESSION_SAVE_FREQUENCY_SECONDS + # .. setting_description: If set, this is used to end the session when there is no activity for N seconds. + # .. setting_warning: Keep in sync with SESSION_COOKIE_AGE and must be larger than SESSION_ACTIVITY_SAVE_DELAY_SECONDS. timeout_in_seconds = getattr(settings, "SESSION_INACTIVITY_TIMEOUT_IN_SECONDS", None) # Do we have this feature enabled? if timeout_in_seconds: - # .. setting_name: SESSION_SAVE_FREQUENCY_SECONDS - # .. setting_default: 900 + # .. setting_name: SESSION_ACTIVITY_SAVE_DELAY_SECONDS + # .. setting_default: 15 minutes (in seconds) # .. setting_description: How often to allow a full session save (in seconds). - # This controls how frequently the session ID might change - # A user could be inactive for almost SESSION_SAVE_FREQUENCY_SECONDS but since their session + # This controls how frequently the session ID might change. + # A user could be inactive for almost SESSION_ACTIVITY_SAVE_DELAY_SECONDS but since their session # isn't being saved during that time, their last activity timestamp isn't being updated. - # When they hit the inactivity timeout, it will be based on the last saved activity time - # So the effective timeout could be as short as: SESSION_INACTIVITY_TIMEOUT_IN_SECONDS - SESSION_SAVE_FREQUENCY_SECONDS + # When they hit the inactivity timeout, it will be based on the last saved activity time. + # So the effective timeout could be as short as: SESSION_INACTIVITY_TIMEOUT_IN_SECONDS - SESSION_ACTIVITY_SAVE_DELAY_SECONDS. # This means users might be logged out earlier than expected in some edge cases. - # .. setting_warning: Used in sync with SESSION_INACTIVITY_TIMEOUT_IN_SECONDS - frequency_time_in_seconds = getattr(settings, "SESSION_SAVE_FREQUENCY_SECONDS", 900) + # .. setting_warning: Must be smaller than SESSION_INACTIVITY_TIMEOUT_IN_SECONDS. + frequency_time_in_seconds = getattr(settings, "SESSION_ACTIVITY_SAVE_DELAY_SECONDS", 900) # what time is it now? utc_now = datetime.utcnow() @@ -80,10 +81,13 @@ def process_request(self, request): auth.logout(request) return except (ValueError, TypeError) as e: + LOG.debug("Parsing last touch time failed: %s", e) # If parsing fails, treat as if no timestamp exists pass else: - LOG.info("No previous activity timestamp found (first login)") + # Enable NR tracing for this view based on course + monitoring_utils.set_custom_attribute('session_inactivity.first_login', True) + LOG.debug("No previous activity timestamp found (first login)") # Store activity timestamp request.session[LAST_TOUCH_KEYNAME] = utc_now.isoformat() @@ -92,11 +96,13 @@ def process_request(self, request): last_save = request.session.get(LAST_SESSION_SAVE_TIME_KEYNAME) current_time = datetime.utcnow().isoformat() + monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time) if not last_save or ( datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < datetime.utcnow() ): # Allow a full session save periodically request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time + monitoring_utils.set_custom_attribute('session_inactivity.session_extended', True) # Don't set modified=was_modified here! Let Django save the session else: # Only prevent saving in this branch diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index 5820ae9d9a4e..2d8f23ff9f98 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -70,7 +70,7 @@ def test_process_request_first_visit_sets_timestamp(self, mock_datetime): mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='INFO') as log: + with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='DEBUG') as log: response = self.middleware.process_request(self.request) assert response is None @@ -140,7 +140,7 @@ def test_process_request_invalid_timestamp_handles_gracefully(self, mock_datetim @override_settings( SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900, # 15 minutes timeout - SESSION_SAVE_FREQUENCY_SECONDS=600 + SESSION_ACTIVITY_SAVE_DELAY_SECONDS=600 # 10 minutes save frequency ) @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') def test_process_request_session_save_frequency_within_period(self, mock_datetime): @@ -163,28 +163,25 @@ def test_process_request_session_save_frequency_within_period(self, mock_datetim assert response is None assert self.request.session.modified is False - @override_settings( - SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900, # 15 minutes timeout - SESSION_SAVE_FREQUENCY_SECONDS=600 - ) + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600) # 1 hour @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') def test_process_request_session_save_frequency_exceeded(self, mock_datetime): """ Test that session save time is updated when frequency period is exceeded. """ - # Set up times + # Set up times - Note: we need 60+ seconds difference for the save frequency to be exceeded last_save = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 12, 0) # 12 minutes later (> 10 min frequency, < 15 min timeout) - + current_time = datetime(2025, 6, 16, 12, 11, 0) # 11 minutes (660 seconds) later + self.request.session[LAST_TOUCH_KEYNAME] = last_save.isoformat() - self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = last_save.isoformat() - + # DON'T set LAST_SESSION_SAVE_TIME_KEYNAME - let the "not last_save" condition trigger + # Mock datetime methods properly mock_datetime.utcnow.return_value = current_time mock_datetime.fromisoformat = datetime.fromisoformat - + response = self.middleware.process_request(self.request) - + assert response is None assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() # session.modified should not be explicitly set to False @@ -373,7 +370,7 @@ def test_constants_are_properly_defined(self): """ Test that the required constants are properly defined. """ - assert LAST_TOUCH_KEYNAME == 'SessionInactivityTimeout:last_touch' + assert LAST_TOUCH_KEYNAME == 'SessionInactivityTimeout:last_touch_str' assert LAST_SESSION_SAVE_TIME_KEYNAME == 'SessionInactivityTimeout:last_session_save_time' @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900) # 15 minutes timeout @@ -394,7 +391,7 @@ def test_process_request_session_modified_flag_behavior(self, mock_datetime): # Default behavior for new session data # Second request within save frequency - should set modified to False - with override_settings(SESSION_SAVE_FREQUENCY_SECONDS=600): + with override_settings(SESSION_ACTIVITY_SAVE_DELAY_SECONDS=600): self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time.isoformat() response = self.middleware.process_request(self.request) assert response is None @@ -426,12 +423,12 @@ def test_logging_first_login_message(self): """ Test that first login message is logged appropriately. """ - with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='INFO') as log: + with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='DEBUG') as log: self.middleware.process_request(self.request) assert len(log.output) == 1 assert "No previous activity timestamp found (first login)" in log.output[0] - assert "INFO" in log.output[0] + assert "DEBUG" in log.output[0] @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') From 02c0114b8eae5689e116b805b685a3406760a707 Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Wed, 25 Jun 2025 11:27:33 +0000 Subject: [PATCH 06/19] fix: correct logging variable name and improve log levels in session inactivity middleware --- .../session_inactivity_timeout/middleware.py | 16 ++++++---------- 1 file changed, 6 insertions(+), 10 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 36baae80e2fe..9ccf6b9b5553 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -24,7 +24,7 @@ LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' -LOG = logging.getLogger(__name__) +log = logging.getLogger(__name__) class SessionInactivityTimeout(MiddlewareMixin): @@ -48,7 +48,7 @@ def process_request(self, request): # Do we have this feature enabled? if timeout_in_seconds: # .. setting_name: SESSION_ACTIVITY_SAVE_DELAY_SECONDS - # .. setting_default: 15 minutes (in seconds) + # .. setting_default: 900 (15 minutes in seconds) # .. setting_description: How often to allow a full session save (in seconds). # This controls how frequently the session ID might change. # A user could be inactive for almost SESSION_ACTIVITY_SAVE_DELAY_SECONDS but since their session @@ -68,26 +68,22 @@ def process_request(self, request): # this key will not be present in the session data if last_touch_str: try: - # Convert the ISO string back to a datetime object last_touch = datetime.fromisoformat(last_touch_str) - - # compute the delta since last time user came to the server time_since_last_activity = utc_now - last_touch # did we exceed the timeout limit? - if time_since_last_activity > timedelta(seconds=timeout_in_seconds): - # yes? Then log the user out + has_exceeded_timeout_limit = time_since_last_activity > timedelta(seconds=timeout_in_seconds) + if has_exceeded_timeout_limit: del request.session[LAST_TOUCH_KEYNAME] auth.logout(request) return except (ValueError, TypeError) as e: - LOG.debug("Parsing last touch time failed: %s", e) + log.warning("Parsing last touch time failed: %s", e) # If parsing fails, treat as if no timestamp exists pass else: - # Enable NR tracing for this view based on course monitoring_utils.set_custom_attribute('session_inactivity.first_login', True) - LOG.debug("No previous activity timestamp found (first login)") + log.debug("No previous activity timestamp found (first login)") # Store activity timestamp request.session[LAST_TOUCH_KEYNAME] = utc_now.isoformat() From 43e08422226ccac8763f9e1f7cd8187e0c77c4ed Mon Sep 17 00:00:00 2001 From: Tarun Tak Date: Thu, 26 Jun 2025 12:59:18 +0000 Subject: [PATCH 07/19] fix: enhance session inactivity tracking with TieredCache and custom monitoring attributes --- .../session_inactivity_timeout/middleware.py | 23 ++++++++++--------- 1 file changed, 12 insertions(+), 11 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 9ccf6b9b5553..03ae33e6a2ab 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -20,6 +20,7 @@ from django.contrib import auth from django.utils.deprecation import MiddlewareMixin from edx_django_utils import monitoring as monitoring_utils +from edx_django_utils.cache import TieredCache LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' @@ -71,7 +72,6 @@ def process_request(self, request): last_touch = datetime.fromisoformat(last_touch_str) time_since_last_activity = utc_now - last_touch - # did we exceed the timeout limit? has_exceeded_timeout_limit = time_since_last_activity > timedelta(seconds=timeout_in_seconds) if has_exceeded_timeout_limit: del request.session[LAST_TOUCH_KEYNAME] @@ -82,24 +82,25 @@ def process_request(self, request): # If parsing fails, treat as if no timestamp exists pass else: + # .. custom_attribute_name: session_inactivity.first_login + # .. custom_attribute_description: Tracks when users have no stored activity + # timestamp (first access after login). monitoring_utils.set_custom_attribute('session_inactivity.first_login', True) log.debug("No previous activity timestamp found (first login)") - # Store activity timestamp - request.session[LAST_TOUCH_KEYNAME] = utc_now.isoformat() - - # Periodically allow a full save (every n seconds) - last_save = request.session.get(LAST_SESSION_SAVE_TIME_KEYNAME) + cached_response = TieredCache.get_cached_response(LAST_SESSION_SAVE_TIME_KEYNAME) + last_save = cached_response.value if cached_response.is_found else None current_time = datetime.utcnow().isoformat() + # .. custom_attribute_name: session_inactivity.activity_seen + # .. custom_attribute_description: Records the timestamp when user activity is detected. monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time) if not last_save or ( datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < datetime.utcnow() ): # Allow a full session save periodically - request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time + TieredCache.set_all_tiers(LAST_SESSION_SAVE_TIME_KEYNAME, current_time, frequency_time_in_seconds) + # .. custom_attribute_name: session_inactivity.session_extended + # .. custom_attribute_description: Marks when sessions are extended through the periodic save. monitoring_utils.set_custom_attribute('session_inactivity.session_extended', True) - # Don't set modified=was_modified here! Let Django save the session - else: - # Only prevent saving in this branch - request.session.modified = False + request.session[LAST_TOUCH_KEYNAME] = utc_now.isoformat() From 81f043f8404b3fb7eef589d15b1902b02dd38f19 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Thu, 3 Jul 2025 11:45:22 +0000 Subject: [PATCH 08/19] fix: update session inactivity tracking to use user-specific cache keys and improve timestamp handling --- .../session_inactivity_timeout/middleware.py | 28 +++++++++++-------- 1 file changed, 16 insertions(+), 12 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 03ae33e6a2ab..54bc42d8b8d6 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -23,7 +23,7 @@ from edx_django_utils.cache import TieredCache LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' -LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' +LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time:user_{}' log = logging.getLogger(__name__) @@ -32,6 +32,10 @@ class SessionInactivityTimeout(MiddlewareMixin): """ Middleware class to keep track of activity on a given session """ + + def _get_last_session_save_time_key(self, user_id): + return LAST_SESSION_SAVE_TIME_KEYNAME.format(user_id) + def process_request(self, request): """ Standard entry point for processing requests in Django @@ -46,6 +50,7 @@ def process_request(self, request): # .. setting_warning: Keep in sync with SESSION_COOKIE_AGE and must be larger than SESSION_ACTIVITY_SAVE_DELAY_SECONDS. timeout_in_seconds = getattr(settings, "SESSION_INACTIVITY_TIMEOUT_IN_SECONDS", None) + current_time = datetime.utcnow() # Do we have this feature enabled? if timeout_in_seconds: # .. setting_name: SESSION_ACTIVITY_SAVE_DELAY_SECONDS @@ -59,8 +64,6 @@ def process_request(self, request): # This means users might be logged out earlier than expected in some edge cases. # .. setting_warning: Must be smaller than SESSION_INACTIVITY_TIMEOUT_IN_SECONDS. frequency_time_in_seconds = getattr(settings, "SESSION_ACTIVITY_SAVE_DELAY_SECONDS", 900) - # what time is it now? - utc_now = datetime.utcnow() # Get the last time user made a request to server, which is stored in session data last_touch_str = request.session.get(LAST_TOUCH_KEYNAME) @@ -70,7 +73,7 @@ def process_request(self, request): if last_touch_str: try: last_touch = datetime.fromisoformat(last_touch_str) - time_since_last_activity = utc_now - last_touch + time_since_last_activity = current_time - last_touch has_exceeded_timeout_limit = time_since_last_activity > timedelta(seconds=timeout_in_seconds) if has_exceeded_timeout_limit: @@ -88,19 +91,20 @@ def process_request(self, request): monitoring_utils.set_custom_attribute('session_inactivity.first_login', True) log.debug("No previous activity timestamp found (first login)") - cached_response = TieredCache.get_cached_response(LAST_SESSION_SAVE_TIME_KEYNAME) + cache_key = self._get_last_session_save_time_key(request.user.id) + cached_response = TieredCache.get_cached_response(cache_key) last_save = cached_response.value if cached_response.is_found else None - current_time = datetime.utcnow().isoformat() + current_time_str = current_time.isoformat() # .. custom_attribute_name: session_inactivity.activity_seen # .. custom_attribute_description: Records the timestamp when user activity is detected. - monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time) - if not last_save or ( - datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < datetime.utcnow() - ): + monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time_str) + has_save_delay_been_exceeded = datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < current_time + proceed_with_period_save = not last_save or has_save_delay_been_exceeded + if proceed_with_period_save: # Allow a full session save periodically - TieredCache.set_all_tiers(LAST_SESSION_SAVE_TIME_KEYNAME, current_time, frequency_time_in_seconds) + TieredCache.set_all_tiers(cache_key, current_time_str, timeout_in_seconds) # .. custom_attribute_name: session_inactivity.session_extended # .. custom_attribute_description: Marks when sessions are extended through the periodic save. monitoring_utils.set_custom_attribute('session_inactivity.session_extended', True) - request.session[LAST_TOUCH_KEYNAME] = utc_now.isoformat() + request.session[LAST_TOUCH_KEYNAME] = current_time_str From c801c230e316fe0eae89e3e423a4db1178cf79d9 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Tue, 8 Jul 2025 05:33:06 +0000 Subject: [PATCH 09/19] fix: simplify session save time key handling and improve logging for inactivity tracking --- .../session_inactivity_timeout/middleware.py | 36 ++++++++----------- 1 file changed, 15 insertions(+), 21 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 54bc42d8b8d6..c0df0968d0e6 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -20,10 +20,9 @@ from django.contrib import auth from django.utils.deprecation import MiddlewareMixin from edx_django_utils import monitoring as monitoring_utils -from edx_django_utils.cache import TieredCache LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' -LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time:user_{}' +LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' log = logging.getLogger(__name__) @@ -33,9 +32,6 @@ class SessionInactivityTimeout(MiddlewareMixin): Middleware class to keep track of activity on a given session """ - def _get_last_session_save_time_key(self, user_id): - return LAST_SESSION_SAVE_TIME_KEYNAME.format(user_id) - def process_request(self, request): """ Standard entry point for processing requests in Django @@ -81,30 +77,28 @@ def process_request(self, request): auth.logout(request) return except (ValueError, TypeError) as e: + # If parsing fails, log warning and then treat as if no timestamp exists log.warning("Parsing last touch time failed: %s", e) - # If parsing fails, treat as if no timestamp exists - pass + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-error') + else: - # .. custom_attribute_name: session_inactivity.first_login - # .. custom_attribute_description: Tracks when users have no stored activity - # timestamp (first access after login). - monitoring_utils.set_custom_attribute('session_inactivity.first_login', True) + # .. custom_attribute_name: session_inactivity.last_touch_status + # .. custom_attribute_description: Tracks the status of session activity timestamps. + # Values: 'first-login' (Tracks when users have no stored activity), 'last-touch-error' (failed to parse timestamp), + # 'last-touch-exceeded' (Marks when sessions are extended through the periodic save), 'last-touch-not-exceeded' (within save delay). + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'first-login') log.debug("No previous activity timestamp found (first login)") - cache_key = self._get_last_session_save_time_key(request.user.id) - cached_response = TieredCache.get_cached_response(cache_key) - last_save = cached_response.value if cached_response.is_found else None + last_save = request.session.get(LAST_SESSION_SAVE_TIME_KEYNAME) current_time_str = current_time.isoformat() - # .. custom_attribute_name: session_inactivity.activity_seen - # .. custom_attribute_description: Records the timestamp when user activity is detected. monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time_str) - has_save_delay_been_exceeded = datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < current_time + has_save_delay_been_exceeded = last_save and datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < current_time proceed_with_period_save = not last_save or has_save_delay_been_exceeded if proceed_with_period_save: # Allow a full session save periodically - TieredCache.set_all_tiers(cache_key, current_time_str, timeout_in_seconds) - # .. custom_attribute_name: session_inactivity.session_extended - # .. custom_attribute_description: Marks when sessions are extended through the periodic save. - monitoring_utils.set_custom_attribute('session_inactivity.session_extended', True) + request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time_str + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-exceeded') request.session[LAST_TOUCH_KEYNAME] = current_time_str + else: + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-not-exceeded') \ No newline at end of file From 25a339fb4854cb4c75a62d9a4b4b31ec27b520a7 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Tue, 8 Jul 2025 06:34:11 +0000 Subject: [PATCH 10/19] fix: remove unused last session save time key and streamline session save logic --- .../session_inactivity_timeout/middleware.py | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index c0df0968d0e6..e0b03b25e8ba 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -22,7 +22,6 @@ from edx_django_utils import monitoring as monitoring_utils LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' -LAST_SESSION_SAVE_TIME_KEYNAME = 'SessionInactivityTimeout:last_session_save_time' log = logging.getLogger(__name__) @@ -89,16 +88,14 @@ def process_request(self, request): monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'first-login') log.debug("No previous activity timestamp found (first login)") - last_save = request.session.get(LAST_SESSION_SAVE_TIME_KEYNAME) current_time_str = current_time.isoformat() monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time_str) - has_save_delay_been_exceeded = last_save and datetime.fromisoformat(last_save) + timedelta(seconds=frequency_time_in_seconds) < current_time - proceed_with_period_save = not last_save or has_save_delay_been_exceeded + has_save_delay_been_exceeded = last_touch_str and datetime.fromisoformat(last_touch_str) + timedelta(seconds=frequency_time_in_seconds) < current_time + proceed_with_period_save = not last_touch_str or has_save_delay_been_exceeded if proceed_with_period_save: # Allow a full session save periodically - request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time_str - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-exceeded') request.session[LAST_TOUCH_KEYNAME] = current_time_str + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-exceeded') else: - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-not-exceeded') \ No newline at end of file + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-not-exceeded') From 495e2d6bcc27c315a29926ab45748a74109751e8 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Fri, 25 Jul 2025 12:37:33 +0000 Subject: [PATCH 11/19] fix: enhance session inactivity tracking with improved logging and error handling --- .../session_inactivity_timeout/middleware.py | 16 +- .../tests/test_middleware.py | 601 +++++------------- 2 files changed, 177 insertions(+), 440 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index e0b03b25e8ba..2dcd52921a30 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -78,14 +78,14 @@ def process_request(self, request): except (ValueError, TypeError) as e: # If parsing fails, log warning and then treat as if no timestamp exists log.warning("Parsing last touch time failed: %s", e) - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-error') + # .. custom_attribute_name: session_inactivity.last_touch_error + # .. custom_attribute_description: Boolean. True if parsing the last activity timestamp failed for this request, indicating a session data error. + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_error', True) else: - # .. custom_attribute_name: session_inactivity.last_touch_status - # .. custom_attribute_description: Tracks the status of session activity timestamps. - # Values: 'first-login' (Tracks when users have no stored activity), 'last-touch-error' (failed to parse timestamp), - # 'last-touch-exceeded' (Marks when sessions are extended through the periodic save), 'last-touch-not-exceeded' (within save delay). - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'first-login') + # .. custom_attribute_name: session_inactivity.first_login + # .. custom_attribute_description: Boolean. True if the user has no stored activity timestamp for this request. + monitoring_utils.set_custom_attribute('session_inactivity.first_login', True) log.debug("No previous activity timestamp found (first login)") current_time_str = current_time.isoformat() @@ -96,6 +96,10 @@ def process_request(self, request): if proceed_with_period_save: # Allow a full session save periodically request.session[LAST_TOUCH_KEYNAME] = current_time_str + # .. custom_attribute_name: session_inactivity.last_touch_status + # .. custom_attribute_description: Tracks the status of session activity timestamps. + # Values: 'last-touch-exceeded' (when sessions are extended through the periodic save), + # 'last-touch-not-exceeded' (within save delay). monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-exceeded') else: monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-not-exceeded') diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index 2d8f23ff9f98..90c41a7026bb 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -1,520 +1,253 @@ """ Unit tests for SessionInactivityTimeout middleware. """ -import logging + from datetime import datetime, timedelta -from unittest.mock import Mock, patch +from unittest.mock import patch -from django.conf import settings -from django.contrib.auth import SESSION_KEY +import ddt from django.contrib.auth.models import AnonymousUser +from django.contrib.sessions.backends.db import SessionStore from django.test import TestCase, RequestFactory, override_settings from common.djangoapps.student.tests.factories import UserFactory from openedx.core.djangolib.testing.utils import get_mock_request -from ..middleware import ( +from openedx.core.djangoapps.session_inactivity_timeout.middleware import ( SessionInactivityTimeout, LAST_TOUCH_KEYNAME, - LAST_SESSION_SAVE_TIME_KEYNAME ) +@ddt.ddt class SessionInactivityTimeoutTestCase(TestCase): - """ - Test cases for SessionInactivityTimeout middleware. - """ def setUp(self): - """ - Set up test data. - """ super().setUp() self.user = UserFactory.create() self.middleware = SessionInactivityTimeout(get_response=lambda request: None) self.request = get_mock_request(self.user) - - # Create a proper session object with all necessary attributes - from django.contrib.sessions.backends.db import SessionStore + self.request.session = SessionStore() self.request.session.create() self.request.session.modified = False def test_process_request_unauthenticated_user_does_nothing(self): - """ - Test that middleware does nothing for unauthenticated users. - """ self.request.user = AnonymousUser() - response = self.middleware.process_request(self.request) - assert response is None assert LAST_TOUCH_KEYNAME not in self.request.session - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=None) - def test_process_request_timeout_disabled_does_nothing(self): - """ - Test that middleware does nothing when timeout is disabled. - """ - response = self.middleware.process_request(self.request) - + @ddt.data(None, 0) + def test_process_request_timeout_disabled_does_nothing(self, timeout_value): + with override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_value): + response = self.middleware.process_request(self.request) + assert response is None assert LAST_TOUCH_KEYNAME not in self.request.session @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_first_visit_sets_timestamp(self, mock_datetime): - """ - Test that first visit sets timestamp in session. - """ + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch( + "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" + ) + def test_process_request_first_visit_sets_timestamp( + self, mock_monitoring, mock_datetime + ): mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - - with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='DEBUG') as log: + + with self.assertLogs( + "openedx.core.djangoapps.session_inactivity_timeout.middleware", + level="DEBUG", + ) as log: response = self.middleware.process_request(self.request) - + assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == mock_now.isoformat() - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_within_timeout_updates_timestamp(self, mock_datetime): - """ - Test that request within timeout period and updates timestamp. - """ - # Set up existing timestamp (5 minutes ago) - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 4, 0) # 4 minutes later - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - mock_datetime.utcnow.return_value = current_time - - response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - # Should not log out user - assert hasattr(self.request, 'user') + # Verify monitoring calls + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.first_login", True + ) + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.activity_seen", mock_now.isoformat() + ) + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.last_touch_status", "last-touch-exceeded" + ) + + @ddt.data( + # (timeout_seconds, minutes_elapsed, should_logout) + (300, 4, False), + (300, 6, True), + (300, 5, False), + (600, 9, False), + (600, 11, True), + ) + @ddt.unpack + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.auth") + def test_process_request_timeout_behavior( + self, timeout_seconds, minutes_elapsed, should_logout, mock_auth, mock_datetime + ): + with override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_seconds): + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = last_touch + timedelta(minutes=minutes_elapsed) + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') - def test_process_request_timeout_exceeded_logs_out_user(self, mock_auth, mock_datetime): - """ - Test that request exceeding timeout period logs out user. - """ - # Set up existing timestamp (10 minutes ago) - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 10, 0) # 10 minutes later - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - - # Mock all datetime.utcnow() calls to return current_time - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - response = self.middleware.process_request(self.request) - - assert response is None - # The middleware deletes the key before logging out - assert LAST_TOUCH_KEYNAME not in self.request.session - mock_auth.logout.assert_called_once_with(self.request) + response = self.middleware.process_request(self.request) - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_invalid_timestamp_handles_gracefully(self, mock_datetime): - """ - Test that invalid timestamp in session is handled gracefully. - """ - # Set up invalid timestamp - self.request.session[LAST_TOUCH_KEYNAME] = "invalid-timestamp" - mock_now = datetime(2025, 6, 16, 12, 0, 0) - mock_datetime.utcnow.return_value = mock_now - - response = self.middleware.process_request(self.request) - - assert response is None - # Should set new timestamp despite invalid old one - assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + assert response is None - @override_settings( - SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900, # 15 minutes timeout - SESSION_ACTIVITY_SAVE_DELAY_SECONDS=600 # 10 minutes save frequency + if should_logout: + assert LAST_TOUCH_KEYNAME not in self.request.session + mock_auth.logout.assert_called_once_with(self.request) + else: + # User should not be logged out, but timestamp may or may not be updated + # depending on save delay logic (900 seconds default) + mock_auth.logout.assert_not_called() + # The session should contain either the old or new timestamp + assert LAST_TOUCH_KEYNAME in self.request.session + + @ddt.data( + # (save_delay_seconds, minutes_elapsed, should_save) + (900, 10, False), + (900, 20, True), + (600, 8, False), + (600, 12, True), ) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_session_save_frequency_within_period(self, mock_datetime): - """ - Test that session.modified is set to False when within save frequency period. - """ - # Set up times - last_save = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 5, 0) # 5 minutes later (< 10 min frequency, < 15 min timeout) - - self.request.session[LAST_TOUCH_KEYNAME] = last_save.isoformat() - self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = last_save.isoformat() - - # Mock datetime methods properly - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session.modified is False - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600) # 1 hour - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_session_save_frequency_exceeded(self, mock_datetime): - """ - Test that session save time is updated when frequency period is exceeded. - """ - # Set up times - Note: we need 60+ seconds difference for the save frequency to be exceeded - last_save = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 11, 0) # 11 minutes (660 seconds) later - - self.request.session[LAST_TOUCH_KEYNAME] = last_save.isoformat() - # DON'T set LAST_SESSION_SAVE_TIME_KEYNAME - let the "not last_save" condition trigger - - # Mock datetime methods properly - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat + @ddt.unpack + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600) # 1 hour timeout + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch( + "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" + ) + def test_process_request_save_delay_behavior( + self, + save_delay_seconds, + minutes_elapsed, + should_save, + mock_monitoring, + mock_datetime, + ): + with override_settings(SESSION_ACTIVITY_SAVE_DELAY_SECONDS=save_delay_seconds): + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = last_touch + timedelta(minutes=minutes_elapsed) + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) - assert response is None - assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() - # session.modified should not be explicitly set to False + assert response is None - @override_settings( - SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300, - SESSION_SAVE_FREQUENCY_SECONDS=600 + if should_save: + # Session should be saved with new timestamp + assert ( + self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + ) + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.last_touch_status", "last-touch-exceeded" + ) + else: + # Session should not be saved, timestamp remains the same + assert ( + self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() + ) + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.last_touch_status", "last-touch-not-exceeded" + ) + + @ddt.data( + "invalid-timestamp", + 12345, # Not a string + "2025-13-01T12:00:00", # Invalid month ) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_no_last_save_time_sets_new_save_time(self, mock_datetime): - """ - Test that when no last save time exists, a new one is set. - """ - current_time = datetime(2025, 6, 16, 12, 0, 0) - mock_datetime.utcnow.return_value = current_time - - response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_type_error_in_timestamp_parsing(self, mock_datetime): - """ - Test that TypeError in timestamp parsing is handled gracefully. - """ - # Set up session with non-string value that would cause TypeError - self.request.session[LAST_TOUCH_KEYNAME] = 12345 # Not a string + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + def test_process_request_invalid_timestamp_handles_gracefully( + self, invalid_timestamp, mock_datetime + ): + self.request.session[LAST_TOUCH_KEYNAME] = invalid_timestamp mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - - response = self.middleware.process_request(self.request) - - assert response is None - # Should set new timestamp despite type error - assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') - def test_process_request_exact_timeout_logs_out_user(self, mock_auth, mock_datetime): - """ - Test that request just after timeout period logs out user. - """ - # Set up existing timestamp just over 300 seconds ago - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 5, 1) # 301 seconds later (> 300) - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - - # Mock datetime methods properly - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - response = self.middleware.process_request(self.request) - - assert response is None - assert LAST_TOUCH_KEYNAME not in self.request.session - mock_auth.logout.assert_called_once_with(self.request) + with self.assertRaises((ValueError, TypeError)): + self.middleware.process_request(self.request) @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') - def test_process_request_one_second_before_timeout_does_not_logout(self, mock_auth, mock_datetime): - """ - Test that request one second before timeout does not log out user. - """ - # Set up existing timestamp 299 seconds ago (just under timeout) - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 4, 59) # 299 seconds later - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - mock_datetime.utcnow.return_value = current_time - - response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - mock_auth.logout.assert_not_called() + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch( + "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" + ) + def test_process_request_empty_string_timestamp_as_first_login( + self, mock_monitoring, mock_datetime + ): + self.request.session[LAST_TOUCH_KEYNAME] = "" + mock_now = datetime(2025, 6, 16, 12, 0, 0) + mock_datetime.utcnow.return_value = mock_now - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') - def test_process_request_exactly_timeout_does_not_logout(self, mock_auth, mock_datetime): - """ - Test that request at exactly timeout period does NOT log out user (> not >=). - """ - # Set up existing timestamp exactly 300 seconds ago - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 5, 0) # Exactly 300 seconds later - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - mock_datetime.utcnow.return_value = current_time - response = self.middleware.process_request(self.request) - + assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - mock_auth.logout.assert_not_called() + # Empty string is falsy, so it should be treated as first login + assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.first_login", True + ) @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") def test_process_request_uses_default_save_frequency(self, mock_datetime): - """ - Test that default save frequency (900 seconds) is used when not specified. - """ current_time = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = current_time - + response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == current_time.isoformat() - def test_middleware_inherits_from_middleware_mixin(self): - """ - Test that SessionInactivityTimeout properly inherits from MiddlewareMixin. - """ - from django.utils.deprecation import MiddlewareMixin - assert issubclass(SessionInactivityTimeout, MiddlewareMixin) + assert response is None + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") def test_process_request_empty_session(self, mock_datetime): - """ - Test that middleware works correctly with completely empty session. - """ # Clear the session but keep it as a proper session object self.request.session.flush() mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - - response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - assert self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] == mock_now.isoformat() - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=0) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') - def test_process_request_zero_timeout_disables_feature(self, mock_auth, mock_datetime): - """ - Test that zero timeout disables the timeout feature entirely. - In Python, 0 is falsy, so `if timeout_in_seconds:` is False. - """ - # Set up existing timestamp - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 0, 10) # 10 seconds later - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - - # Mock all datetime methods properly - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - response = self.middleware.process_request(self.request) - - assert response is None - # User should NOT be logged out because 0 timeout disables the feature - mock_auth.logout.assert_not_called() - # Original timestamp should remain unchanged - assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_microsecond_precision_timestamps(self, mock_datetime): - """ - Test that middleware handles timestamps with microsecond precision. - """ - # Set up timestamp with microseconds - last_touch = datetime(2025, 6, 16, 12, 0, 0, 123456) - current_time = datetime(2025, 6, 16, 12, 2, 0, 654321) - - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - mock_datetime.utcnow.return_value = current_time - response = self.middleware.process_request(self.request) - - assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - def test_constants_are_properly_defined(self): - """ - Test that the required constants are properly defined. - """ - assert LAST_TOUCH_KEYNAME == 'SessionInactivityTimeout:last_touch_str' - assert LAST_SESSION_SAVE_TIME_KEYNAME == 'SessionInactivityTimeout:last_session_save_time' - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=900) # 15 minutes timeout - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_process_request_session_modified_flag_behavior(self, mock_datetime): - """ - Test the session.modified flag behavior under different conditions. - """ - current_time = datetime(2025, 6, 16, 12, 0, 0) - - # Mock datetime methods properly - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - # First request - should not set modified to False - response = self.middleware.process_request(self.request) assert response is None - # Default behavior for new session data - - # Second request within save frequency - should set modified to False - with override_settings(SESSION_ACTIVITY_SAVE_DELAY_SECONDS=600): - self.request.session[LAST_SESSION_SAVE_TIME_KEYNAME] = current_time.isoformat() - response = self.middleware.process_request(self.request) - assert response is None - assert self.request.session.modified is False - - -class SessionInactivityTimeoutLoggingTestCase(TestCase): - """ - Test cases specifically for logging behavior. - """ - - def setUp(self): - """ - Set up test data. - """ - super().setUp() - self.user = UserFactory.create() - self.middleware = SessionInactivityTimeout(get_response=lambda request: None) - self.request = get_mock_request(self.user) - - # Create a proper session object with all necessary attributes - from django.contrib.sessions.backends.db import SessionStore - self.request.session = SessionStore() - self.request.session.create() - self.request.session.modified = False - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - def test_logging_first_login_message(self): - """ - Test that first login message is logged appropriately. - """ - with self.assertLogs('openedx.core.djangoapps.session_inactivity_timeout.middleware', level='DEBUG') as log: - self.middleware.process_request(self.request) - - assert len(log.output) == 1 - assert "No previous activity timestamp found (first login)" in log.output[0] - assert "DEBUG" in log.output[0] + assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + @ddt.data( + # Test boundary conditions more precisely + (300, 299, False), + (300, 300, False), + (300, 301, True), + ) + @ddt.unpack @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - def test_no_logging_for_normal_requests(self, mock_datetime): - """ - Test that normal requests (not first login) don't generate log messages. - """ - # Set up existing timestamp + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.auth") + def test_process_request_timeout_boundary_conditions( + self, timeout_seconds, seconds_elapsed, should_logout, mock_auth, mock_datetime + ): last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 2, 0) - + current_time = last_touch + timedelta(seconds=seconds_elapsed) self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() mock_datetime.utcnow.return_value = current_time - - # Process request - should not generate any logs + mock_datetime.fromisoformat = datetime.fromisoformat response = self.middleware.process_request(self.request) - assert response is None - - -class SessionInactivityTimeoutIntegrationTestCase(TestCase): - """ - Integration test cases for SessionInactivityTimeout middleware. - """ - - def setUp(self): - """ - Set up test data. - """ - super().setUp() - self.user = UserFactory.create() - self.factory = RequestFactory() - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - def test_integration_with_django_session_framework(self): - """ - Test integration with Django's session framework. - """ - from django.contrib.sessions.middleware import SessionMiddleware - - # Create a request - request = self.factory.get('/test/') - request.user = self.user - - # Process through session middleware first - session_middleware = SessionMiddleware(get_response=lambda request: None) - session_middleware.process_request(request) - - # Process through our middleware - timeout_middleware = SessionInactivityTimeout(get_response=lambda request: None) - response = timeout_middleware.process_request(request) - - assert response is None - assert LAST_TOUCH_KEYNAME in request.session - assert LAST_SESSION_SAVE_TIME_KEYNAME in request.session - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=1) # Very short timeout - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime') - @patch('openedx.core.djangoapps.session_inactivity_timeout.middleware.auth') - def test_integration_logout_behavior(self, mock_auth, mock_datetime): - """ - Test integration of logout behavior with auth system. - """ - from django.contrib.sessions.middleware import SessionMiddleware - - # Create a request - request = self.factory.get('/test/') - request.user = self.user - - # Set up session - session_middleware = SessionMiddleware(get_response=lambda request: None) - session_middleware.process_request(request) - - # Set up existing timestamp (3 seconds ago, which exceeds 1-second timeout) - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = datetime(2025, 6, 16, 12, 0, 3) - - request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - - # Mock datetime methods properly - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - # Process through our middleware - timeout_middleware = SessionInactivityTimeout(get_response=lambda request: None) - response = timeout_middleware.process_request(request) - assert response is None - assert LAST_TOUCH_KEYNAME not in request.session - mock_auth.logout.assert_called_once_with(request) + + if should_logout: + assert LAST_TOUCH_KEYNAME not in self.request.session + mock_auth.logout.assert_called_once_with(self.request) + else: + mock_auth.logout.assert_not_called() + assert LAST_TOUCH_KEYNAME in self.request.session From 6bdf73fd322765475ce490c72e44b83c8bd2df02 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Mon, 28 Jul 2025 11:32:19 +0000 Subject: [PATCH 12/19] fix: linting fix --- .../session_inactivity_timeout/middleware.py | 16 +++++++++---- .../tests/test_middleware.py | 24 ++++++++++--------- 2 files changed, 24 insertions(+), 16 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index 2dcd52921a30..cc67d583c23e 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -21,10 +21,10 @@ from django.utils.deprecation import MiddlewareMixin from edx_django_utils import monitoring as monitoring_utils -LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' - log = logging.getLogger(__name__) +LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' + class SessionInactivityTimeout(MiddlewareMixin): """ @@ -52,10 +52,11 @@ def process_request(self, request): # .. setting_default: 900 (15 minutes in seconds) # .. setting_description: How often to allow a full session save (in seconds). # This controls how frequently the session ID might change. - # A user could be inactive for almost SESSION_ACTIVITY_SAVE_DELAY_SECONDS but since their session + # A user could be inactive for almost SESSION_ACTIVITY_SAVE_DELAY_SECONDS but since their session # isn't being saved during that time, their last activity timestamp isn't being updated. # When they hit the inactivity timeout, it will be based on the last saved activity time. - # So the effective timeout could be as short as: SESSION_INACTIVITY_TIMEOUT_IN_SECONDS - SESSION_ACTIVITY_SAVE_DELAY_SECONDS. + # So the effective timeout could be as short as: + # SESSION_INACTIVITY_TIMEOUT_IN_SECONDS - SESSION_ACTIVITY_SAVE_DELAY_SECONDS. # This means users might be logged out earlier than expected in some edge cases. # .. setting_warning: Must be smaller than SESSION_INACTIVITY_TIMEOUT_IN_SECONDS. frequency_time_in_seconds = getattr(settings, "SESSION_ACTIVITY_SAVE_DELAY_SECONDS", 900) @@ -90,8 +91,13 @@ def process_request(self, request): current_time_str = current_time.isoformat() + # .. custom_attribute_name: session_inactivity.activity_seen + # .. custom_attribute_description: The current timestamp when user activity was detected for this request. monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time_str) - has_save_delay_been_exceeded = last_touch_str and datetime.fromisoformat(last_touch_str) + timedelta(seconds=frequency_time_in_seconds) < current_time + has_save_delay_been_exceeded = ( + last_touch_str and + datetime.fromisoformat(last_touch_str) + timedelta(seconds=frequency_time_in_seconds) < current_time + ) proceed_with_period_save = not last_touch_str or has_save_delay_been_exceeded if proceed_with_period_save: # Allow a full session save periodically diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index 90c41a7026bb..e9e642ae038d 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -8,7 +8,7 @@ import ddt from django.contrib.auth.models import AnonymousUser from django.contrib.sessions.backends.db import SessionStore -from django.test import TestCase, RequestFactory, override_settings +from django.test import TestCase, override_settings from common.djangoapps.student.tests.factories import UserFactory from openedx.core.djangolib.testing.utils import get_mock_request @@ -21,7 +21,9 @@ @ddt.ddt class SessionInactivityTimeoutTestCase(TestCase): - + """ + Test case for SessionInactivityTimeout middleware + """ def setUp(self): super().setUp() self.user = UserFactory.create() @@ -34,14 +36,14 @@ def setUp(self): def test_process_request_unauthenticated_user_does_nothing(self): self.request.user = AnonymousUser() - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert LAST_TOUCH_KEYNAME not in self.request.session @ddt.data(None, 0) def test_process_request_timeout_disabled_does_nothing(self, timeout_value): with override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_value): - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert LAST_TOUCH_KEYNAME not in self.request.session @@ -61,7 +63,7 @@ def test_process_request_first_visit_sets_timestamp( "openedx.core.djangoapps.session_inactivity_timeout.middleware", level="DEBUG", ) as log: - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() @@ -98,7 +100,7 @@ def test_process_request_timeout_behavior( mock_datetime.utcnow.return_value = current_time mock_datetime.fromisoformat = datetime.fromisoformat - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None @@ -140,7 +142,7 @@ def test_process_request_save_delay_behavior( mock_datetime.utcnow.return_value = current_time mock_datetime.fromisoformat = datetime.fromisoformat - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None @@ -190,7 +192,7 @@ def test_process_request_empty_string_timestamp_as_first_login( mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None # Empty string is falsy, so it should be treated as first login @@ -205,7 +207,7 @@ def test_process_request_uses_default_save_frequency(self, mock_datetime): current_time = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = current_time - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() @@ -218,7 +220,7 @@ def test_process_request_empty_session(self, mock_datetime): mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() @@ -241,7 +243,7 @@ def test_process_request_timeout_boundary_conditions( self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() mock_datetime.utcnow.return_value = current_time mock_datetime.fromisoformat = datetime.fromisoformat - response = self.middleware.process_request(self.request) + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None From c666449a2e4ef6618ea6fcdb898736c4f7c64aab Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Fri, 1 Aug 2025 05:45:09 +0000 Subject: [PATCH 13/19] fix: enhance session inactivity monitoring with improved error handling --- .../session_inactivity_timeout/middleware.py | 19 +- .../tests/test_middleware.py | 211 +++++++----------- 2 files changed, 96 insertions(+), 134 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index cc67d583c23e..ba580ff39e56 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -21,6 +21,7 @@ from django.utils.deprecation import MiddlewareMixin from edx_django_utils import monitoring as monitoring_utils + log = logging.getLogger(__name__) LAST_TOUCH_KEYNAME = 'SessionInactivityTimeout:last_touch_str' @@ -81,7 +82,8 @@ def process_request(self, request): log.warning("Parsing last touch time failed: %s", e) # .. custom_attribute_name: session_inactivity.last_touch_error # .. custom_attribute_description: Boolean. True if parsing the last activity timestamp failed for this request, indicating a session data error. - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_error', True) + monitoring_utils.set_custom_attribute('session_inactivity.last_touch_error', str(e)) + monitoring_utils.record_exception() else: # .. custom_attribute_name: session_inactivity.first_login @@ -99,13 +101,14 @@ def process_request(self, request): datetime.fromisoformat(last_touch_str) + timedelta(seconds=frequency_time_in_seconds) < current_time ) proceed_with_period_save = not last_touch_str or has_save_delay_been_exceeded + # .. custom_attribute_name: session_inactivity.proceed_with_period_save + # .. custom_attribute_description: Boolean indicating whether a session save should proceed based on the + # save delay frequency. True when either no previous timestamp exists (first login) or the save delay + # period has been exceeded since the last timestamp update. + monitoring_utils.set_custom_attribute( + 'session_inactivity.proceed_with_period_save', + proceed_with_period_save + ) if proceed_with_period_save: # Allow a full session save periodically request.session[LAST_TOUCH_KEYNAME] = current_time_str - # .. custom_attribute_name: session_inactivity.last_touch_status - # .. custom_attribute_description: Tracks the status of session activity timestamps. - # Values: 'last-touch-exceeded' (when sessions are extended through the periodic save), - # 'last-touch-not-exceeded' (within save delay). - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-exceeded') - else: - monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-not-exceeded') diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index e9e642ae038d..d058680b9f1a 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -48,14 +48,22 @@ def test_process_request_timeout_disabled_does_nothing(self, timeout_value): assert response is None assert LAST_TOUCH_KEYNAME not in self.request.session + @ddt.data( + None, # No timestamp key in session + "", # Empty string timestamp + ) @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") @patch( "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" ) def test_process_request_first_visit_sets_timestamp( - self, mock_monitoring, mock_datetime + self, timestamp_value, mock_monitoring, mock_datetime ): + if timestamp_value is not None: + self.request.session[LAST_TOUCH_KEYNAME] = timestamp_value + # else: leave the session without the timestamp key (None case) + mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now @@ -68,34 +76,42 @@ def test_process_request_first_visit_sets_timestamp( assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - # Verify monitoring calls - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.first_login", True - ) - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.activity_seen", mock_now.isoformat() - ) - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.last_touch_status", "last-touch-exceeded" - ) + # Verify monitoring calls for first login + from unittest.mock import call + mock_monitoring.set_custom_attribute.assert_has_calls([ + call("session_inactivity.first_login", True), + call("session_inactivity.activity_seen", mock_now.isoformat()), + call("session_inactivity.proceed_with_period_save", True), + ], any_order=True) @ddt.data( - # (timeout_seconds, minutes_elapsed, should_logout) - (300, 4, False), - (300, 6, True), - (300, 5, False), - (600, 9, False), - (600, 11, True), + # (timeout_seconds, save_delay_seconds, seconds_elapsed, should_logout) + # Test timeout behavior + (300, 900, 240, False), # 4 minutes, no timeout + (300, 900, 300, False), # 5 minutes, no timeout + (300, 900, 360, True), # 6 minutes, timeout occurs + (600, 900, 540, False), # 9 minutes, no timeout + (600, 900, 660, True), # 11 minutes, timeout occurs + # Test save delay behavior (with long timeout to avoid logout) + (3600, 900, 600, False), # 10 min < 15 min save delay, no save + (3600, 900, 1200, False), # 20 min > 15 min save delay, save occurs + (3600, 600, 480, False), # 8 min < 10 min save delay, no save + (3600, 600, 720, False), # 12 min > 10 min save delay, save occurs ) @ddt.unpack @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.auth") - def test_process_request_timeout_behavior( - self, timeout_seconds, minutes_elapsed, should_logout, mock_auth, mock_datetime + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils") + def test_process_request_timeout_and_save_behavior( + self, timeout_seconds, save_delay_seconds, seconds_elapsed, should_logout, + mock_monitoring, mock_auth, mock_datetime ): - with override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_seconds): + with override_settings( + SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_seconds, + SESSION_ACTIVITY_SAVE_DELAY_SECONDS=save_delay_seconds + ): last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = last_touch + timedelta(minutes=minutes_elapsed) + current_time = last_touch + timedelta(seconds=seconds_elapsed) self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() mock_datetime.utcnow.return_value = current_time mock_datetime.fromisoformat = datetime.fromisoformat @@ -108,128 +124,71 @@ def test_process_request_timeout_behavior( assert LAST_TOUCH_KEYNAME not in self.request.session mock_auth.logout.assert_called_once_with(self.request) else: - # User should not be logged out, but timestamp may or may not be updated - # depending on save delay logic (900 seconds default) mock_auth.logout.assert_not_called() - # The session should contain either the old or new timestamp assert LAST_TOUCH_KEYNAME in self.request.session - @ddt.data( - # (save_delay_seconds, minutes_elapsed, should_save) - (900, 10, False), - (900, 20, True), - (600, 8, False), - (600, 12, True), - ) - @ddt.unpack - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600) # 1 hour timeout - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - @patch( - "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" - ) - def test_process_request_save_delay_behavior( - self, - save_delay_seconds, - minutes_elapsed, - should_save, - mock_monitoring, - mock_datetime, - ): - with override_settings(SESSION_ACTIVITY_SAVE_DELAY_SECONDS=save_delay_seconds): - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = last_touch + timedelta(minutes=minutes_elapsed) - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none - - assert response is None - - if should_save: - # Session should be saved with new timestamp - assert ( - self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - ) - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.last_touch_status", "last-touch-exceeded" - ) - else: - # Session should not be saved, timestamp remains the same - assert ( - self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() - ) - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.last_touch_status", "last-touch-not-exceeded" - ) + # Check if timestamp was updated based on save delay + should_save = seconds_elapsed > save_delay_seconds + + if should_save: + # Session should be saved with new timestamp + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + # Verify monitoring calls for save case + from unittest.mock import call + mock_monitoring.set_custom_attribute.assert_has_calls([ + call("session_inactivity.activity_seen", current_time.isoformat()), + call("session_inactivity.proceed_with_period_save", True), + ], any_order=True) + else: + # Session should not be saved, timestamp remains the same + assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.proceed_with_period_save", False + ) @ddt.data( - "invalid-timestamp", - 12345, # Not a string - "2025-13-01T12:00:00", # Invalid month + # (seconds_elapsed, should_save) - testing around default 900 second save delay + (800, False), # 13.3 min < 15 min default, no save + (900, False), # exactly 15 min default, no save (not exceeded) + (1000, True), # 16.7 min > 15 min default, save occurs ) - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - def test_process_request_invalid_timestamp_handles_gracefully( - self, invalid_timestamp, mock_datetime - ): - self.request.session[LAST_TOUCH_KEYNAME] = invalid_timestamp - mock_now = datetime(2025, 6, 16, 12, 0, 0) - mock_datetime.utcnow.return_value = mock_now - - with self.assertRaises((ValueError, TypeError)): - self.middleware.process_request(self.request) - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @ddt.unpack + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600) @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - @patch( - "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" - ) - def test_process_request_empty_string_timestamp_as_first_login( - self, mock_monitoring, mock_datetime + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils") + def test_process_request_uses_default_save_frequency( + self, seconds_elapsed, should_save, mock_monitoring, mock_datetime ): - self.request.session[LAST_TOUCH_KEYNAME] = "" - mock_now = datetime(2025, 6, 16, 12, 0, 0) - mock_datetime.utcnow.return_value = mock_now - - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none - - assert response is None - # Empty string is falsy, so it should be treated as first login - assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.first_login", True - ) - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - def test_process_request_uses_default_save_frequency(self, mock_datetime): - current_time = datetime(2025, 6, 16, 12, 0, 0) + # Don't set SESSION_ACTIVITY_SAVE_DELAY_SECONDS to test default behavior + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = last_touch + timedelta(seconds=seconds_elapsed) + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - def test_process_request_empty_session(self, mock_datetime): - # Clear the session but keep it as a proper session object - self.request.session.flush() - mock_now = datetime(2025, 6, 16, 12, 0, 0) - mock_datetime.utcnow.return_value = mock_now - - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none - assert response is None - assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + if should_save: + # Session should be saved with new timestamp + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.proceed_with_period_save", True + ) + else: + # Session should not be saved, timestamp remains the same + assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.proceed_with_period_save", False + ) @ddt.data( + # (timeout_seconds, seconds_elapsed, should_logout) # Test boundary conditions more precisely - (300, 299, False), - (300, 300, False), - (300, 301, True), + (300, 299, False), # 299 sec < 300 sec timeout, no logout + (300, 300, False), # exactly 300 sec timeout, no logout (not exceeded) + (300, 301, True), # 301 sec > 300 sec timeout, logout occurs ) @ddt.unpack @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) From 47ca3b4e903b8f614959a190671c7f1058e7a428 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Fri, 1 Aug 2025 07:11:14 +0000 Subject: [PATCH 14/19] fix: fix linter and import --- .../session_inactivity_timeout/tests/test_middleware.py | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index d058680b9f1a..071d43a8701c 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -12,6 +12,7 @@ from common.djangoapps.student.tests.factories import UserFactory from openedx.core.djangolib.testing.utils import get_mock_request +from unittest.mock import call from openedx.core.djangoapps.session_inactivity_timeout.middleware import ( SessionInactivityTimeout, @@ -76,8 +77,6 @@ def test_process_request_first_visit_sets_timestamp( assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - # Verify monitoring calls for first login - from unittest.mock import call mock_monitoring.set_custom_attribute.assert_has_calls([ call("session_inactivity.first_login", True), call("session_inactivity.activity_seen", mock_now.isoformat()), @@ -94,7 +93,7 @@ def test_process_request_first_visit_sets_timestamp( (600, 900, 660, True), # 11 minutes, timeout occurs # Test save delay behavior (with long timeout to avoid logout) (3600, 900, 600, False), # 10 min < 15 min save delay, no save - (3600, 900, 1200, False), # 20 min > 15 min save delay, save occurs + (3600, 900, 1200, False), # 20 min > 15 min save delay, save occurs (3600, 600, 480, False), # 8 min < 10 min save delay, no save (3600, 600, 720, False), # 12 min > 10 min save delay, save occurs ) @@ -127,14 +126,10 @@ def test_process_request_timeout_and_save_behavior( mock_auth.logout.assert_not_called() assert LAST_TOUCH_KEYNAME in self.request.session - # Check if timestamp was updated based on save delay should_save = seconds_elapsed > save_delay_seconds if should_save: - # Session should be saved with new timestamp assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - # Verify monitoring calls for save case - from unittest.mock import call mock_monitoring.set_custom_attribute.assert_has_calls([ call("session_inactivity.activity_seen", current_time.isoformat()), call("session_inactivity.proceed_with_period_save", True), From 21d1b29aa34a6eb8834641e8598508773e496796 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Thu, 14 Aug 2025 07:39:44 +0000 Subject: [PATCH 15/19] fix: incorporated review comment --- .../session_inactivity_timeout/middleware.py | 12 +- .../tests/test_middleware.py | 207 ++++++++++-------- 2 files changed, 123 insertions(+), 96 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py index ba580ff39e56..a84abc9e8ab3 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/middleware.py @@ -73,6 +73,15 @@ def process_request(self, request): time_since_last_activity = current_time - last_touch has_exceeded_timeout_limit = time_since_last_activity > timedelta(seconds=timeout_in_seconds) + + # .. custom_attribute_name: session_inactivity.has_exceeded_timeout_limit + # .. custom_attribute_description: Boolean indicating whether the user's session has exceeded the + # inactivity timeout limit and should be logged out. + monitoring_utils.set_custom_attribute( + 'session_inactivity.has_exceeded_timeout_limit', + has_exceeded_timeout_limit + ) + if has_exceeded_timeout_limit: del request.session[LAST_TOUCH_KEYNAME] auth.logout(request) @@ -93,9 +102,6 @@ def process_request(self, request): current_time_str = current_time.isoformat() - # .. custom_attribute_name: session_inactivity.activity_seen - # .. custom_attribute_description: The current timestamp when user activity was detected for this request. - monitoring_utils.set_custom_attribute('session_inactivity.activity_seen', current_time_str) has_save_delay_been_exceeded = ( last_touch_str and datetime.fromisoformat(last_touch_str) + timedelta(seconds=frequency_time_in_seconds) < current_time diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index 071d43a8701c..1db6395d083a 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -3,7 +3,7 @@ """ from datetime import datetime, timedelta -from unittest.mock import patch +from unittest.mock import patch, call, ANY import ddt from django.contrib.auth.models import AnonymousUser @@ -12,7 +12,6 @@ from common.djangoapps.student.tests.factories import UserFactory from openedx.core.djangolib.testing.utils import get_mock_request -from unittest.mock import call from openedx.core.djangoapps.session_inactivity_timeout.middleware import ( SessionInactivityTimeout, @@ -41,25 +40,18 @@ def test_process_request_unauthenticated_user_does_nothing(self): assert response is None assert LAST_TOUCH_KEYNAME not in self.request.session - @ddt.data(None, 0) - def test_process_request_timeout_disabled_does_nothing(self, timeout_value): - with override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_value): - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none - - assert response is None - assert LAST_TOUCH_KEYNAME not in self.request.session - @ddt.data( None, # No timestamp key in session - "", # Empty string timestamp + "", # Empty string timestamp in session ) @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.log") @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") @patch( "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" ) def test_process_request_first_visit_sets_timestamp( - self, timestamp_value, mock_monitoring, mock_datetime + self, timestamp_value, mock_monitoring, mock_datetime, mock_log ): if timestamp_value is not None: self.request.session[LAST_TOUCH_KEYNAME] = timestamp_value @@ -68,47 +60,60 @@ def test_process_request_first_visit_sets_timestamp( mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - with self.assertLogs( - "openedx.core.djangoapps.session_inactivity_timeout.middleware", - level="DEBUG", - ) as log: - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() mock_monitoring.set_custom_attribute.assert_has_calls([ call("session_inactivity.first_login", True), - call("session_inactivity.activity_seen", mock_now.isoformat()), call("session_inactivity.proceed_with_period_save", True), ], any_order=True) @ddt.data( - # (timeout_seconds, save_delay_seconds, seconds_elapsed, should_logout) - # Test timeout behavior - (300, 900, 240, False), # 4 minutes, no timeout - (300, 900, 300, False), # 5 minutes, no timeout - (300, 900, 360, True), # 6 minutes, timeout occurs - (600, 900, 540, False), # 9 minutes, no timeout - (600, 900, 660, True), # 11 minutes, timeout occurs - # Test save delay behavior (with long timeout to avoid logout) - (3600, 900, 600, False), # 10 min < 15 min save delay, no save - (3600, 900, 1200, False), # 20 min > 15 min save delay, save occurs - (3600, 600, 480, False), # 8 min < 10 min save delay, no save - (3600, 600, 720, False), # 12 min > 10 min save delay, save occurs + "invalid-timestamp", # Invalid ISO format + "2025-13-01T12:00:00", # Invalid date + ) + @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.log") + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils") + def test_process_request_invalid_timestamp_handling( + self, invalid_timestamp, mock_monitoring, mock_log + ): + # Set an invalid timestamp in the session + self.request.session[LAST_TOUCH_KEYNAME] = invalid_timestamp + + # The middleware should raise an exception when it tries to parse the invalid timestamp + # in the save delay logic (after already catching it once in the timeout logic) + with self.assertRaises(ValueError): + self.middleware.process_request(self.request) + + # Should log warning about parsing failure (from the first parsing attempt) + mock_log.warning.assert_called_once() + + # Should set error tracking attributes (from the first parsing attempt) + mock_monitoring.set_custom_attribute.assert_any_call("session_inactivity.last_touch_error", ANY) + mock_monitoring.record_exception.assert_called_once() + + @ddt.data( + # (timeout_seconds, seconds_elapsed, should_logout) + # Test timeout behavior including boundary conditions + (300, 240, False), # 240 sec < 300 sec timeout, no logout + (300, 299, False), # 299 sec < 300 sec timeout, no logout + (300, 300, False), # 300 sec = 300 sec timeout, no logout (not exceeded) + (300, 301, True), # 301 sec > 300 sec timeout, logout occurs + (300, 360, True), # 360 sec > 300 sec timeout, logout occurs ) @ddt.unpack @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.auth") @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils") - def test_process_request_timeout_and_save_behavior( - self, timeout_seconds, save_delay_seconds, seconds_elapsed, should_logout, - mock_monitoring, mock_auth, mock_datetime + def test_process_request_timeout_behavior( + self, timeout_seconds, seconds_elapsed, should_logout, + mock_monitoring, mock_datetime ): - with override_settings( - SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_seconds, - SESSION_ACTIVITY_SAVE_DELAY_SECONDS=save_delay_seconds - ): + with override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=timeout_seconds): + assert self.request.user.is_authenticated + last_touch = datetime(2025, 6, 16, 12, 0, 0) current_time = last_touch + timedelta(seconds=seconds_elapsed) self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() @@ -121,31 +126,75 @@ def test_process_request_timeout_and_save_behavior( if should_logout: assert LAST_TOUCH_KEYNAME not in self.request.session - mock_auth.logout.assert_called_once_with(self.request) + assert not self.request.user.is_authenticated + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.has_exceeded_timeout_limit", True + ) else: - mock_auth.logout.assert_not_called() + assert self.request.user.is_authenticated assert LAST_TOUCH_KEYNAME in self.request.session + mock_monitoring.set_custom_attribute.assert_any_call( + "session_inactivity.has_exceeded_timeout_limit", False + ) + + @ddt.data( + # (save_delay_seconds, seconds_elapsed, should_save) + # Test save delay behavior (with long timeout to avoid logout) + (900, 600, False), # 600 sec < 900 sec save delay, no save + (900, 899, False), # 899 sec < 900 sec save delay, no save + (900, 900, False), # 900 sec = 900 sec save delay, no save (not exceeded) + (900, 901, True), # 901 sec > 900 sec save delay, save occurs + (900, 1200, True), # 1200 sec > 900 sec save delay, save occurs + (600, 480, False), # 480 sec < 600 sec save delay, no save + (600, 599, False), # 599 sec < 600 sec save delay, no save + (600, 600, False), # 600 sec = 600 sec save delay, no save (not exceeded) + (600, 601, True), # 601 sec > 600 sec save delay, save occurs + (600, 720, True), # 720 sec > 600 sec save delay, save occurs + ) + @ddt.unpack + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils") + def test_process_request_save_behavior( + self, save_delay_seconds, seconds_elapsed, should_save, + mock_monitoring, mock_datetime + ): + with override_settings( + SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600, # Long timeout to avoid logout + SESSION_ACTIVITY_SAVE_DELAY_SECONDS=save_delay_seconds + ): + assert self.request.user.is_authenticated + + last_touch = datetime(2025, 6, 16, 12, 0, 0) + current_time = last_touch + timedelta(seconds=seconds_elapsed) + self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() + mock_datetime.utcnow.return_value = current_time + mock_datetime.fromisoformat = datetime.fromisoformat + + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none + + assert response is None + assert self.request.user.is_authenticated + assert LAST_TOUCH_KEYNAME in self.request.session - should_save = seconds_elapsed > save_delay_seconds - - if should_save: - assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - mock_monitoring.set_custom_attribute.assert_has_calls([ - call("session_inactivity.activity_seen", current_time.isoformat()), - call("session_inactivity.proceed_with_period_save", True), - ], any_order=True) - else: - # Session should not be saved, timestamp remains the same - assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.proceed_with_period_save", False - ) + if should_save: + assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() + mock_monitoring.set_custom_attribute.assert_has_calls([ + call("session_inactivity.has_exceeded_timeout_limit", False), + call("session_inactivity.proceed_with_period_save", True), + ], any_order=True) + else: + # Session should not be saved, timestamp remains the same + assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() + mock_monitoring.set_custom_attribute.assert_has_calls([ + call("session_inactivity.has_exceeded_timeout_limit", False), + call("session_inactivity.proceed_with_period_save", False), + ], any_order=True) @ddt.data( # (seconds_elapsed, should_save) - testing around default 900 second save delay - (800, False), # 13.3 min < 15 min default, no save - (900, False), # exactly 15 min default, no save (not exceeded) - (1000, True), # 16.7 min > 15 min default, save occurs + (899, False), # 899 sec < 900 sec default, no save + (900, False), # 900 sec = 900 sec default, no save (not exceeded) + (901, True), # 901 sec > 900 sec default, save occurs ) @ddt.unpack @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=3600) @@ -168,42 +217,14 @@ def test_process_request_uses_default_save_frequency( if should_save: # Session should be saved with new timestamp assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.proceed_with_period_save", True - ) + mock_monitoring.set_custom_attribute.assert_has_calls([ + call("session_inactivity.has_exceeded_timeout_limit", False), + call("session_inactivity.proceed_with_period_save", True), + ], any_order=True) else: # Session should not be saved, timestamp remains the same assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() - mock_monitoring.set_custom_attribute.assert_any_call( - "session_inactivity.proceed_with_period_save", False - ) - - @ddt.data( - # (timeout_seconds, seconds_elapsed, should_logout) - # Test boundary conditions more precisely - (300, 299, False), # 299 sec < 300 sec timeout, no logout - (300, 300, False), # exactly 300 sec timeout, no logout (not exceeded) - (300, 301, True), # 301 sec > 300 sec timeout, logout occurs - ) - @ddt.unpack - @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.auth") - def test_process_request_timeout_boundary_conditions( - self, timeout_seconds, seconds_elapsed, should_logout, mock_auth, mock_datetime - ): - last_touch = datetime(2025, 6, 16, 12, 0, 0) - current_time = last_touch + timedelta(seconds=seconds_elapsed) - self.request.session[LAST_TOUCH_KEYNAME] = last_touch.isoformat() - mock_datetime.utcnow.return_value = current_time - mock_datetime.fromisoformat = datetime.fromisoformat - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none - - assert response is None - - if should_logout: - assert LAST_TOUCH_KEYNAME not in self.request.session - mock_auth.logout.assert_called_once_with(self.request) - else: - mock_auth.logout.assert_not_called() - assert LAST_TOUCH_KEYNAME in self.request.session + mock_monitoring.set_custom_attribute.assert_has_calls([ + call("session_inactivity.has_exceeded_timeout_limit", False), + call("session_inactivity.proceed_with_period_save", False), + ], any_order=True) From b18b107085f4713717db8f767eec545995cd1894 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Thu, 14 Aug 2025 11:22:03 +0000 Subject: [PATCH 16/19] fix: removed unwanted comments --- .../session_inactivity_timeout/tests/test_middleware.py | 8 +------- 1 file changed, 1 insertion(+), 7 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index 1db6395d083a..e95f6e78118a 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -45,13 +45,12 @@ def test_process_request_unauthenticated_user_does_nothing(self): "", # Empty string timestamp in session ) @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) - @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.log") @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") @patch( "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" ) def test_process_request_first_visit_sets_timestamp( - self, timestamp_value, mock_monitoring, mock_datetime, mock_log + self, timestamp_value, mock_monitoring, mock_datetime ): if timestamp_value is not None: self.request.session[LAST_TOUCH_KEYNAME] = timestamp_value @@ -80,7 +79,6 @@ def test_process_request_first_visit_sets_timestamp( def test_process_request_invalid_timestamp_handling( self, invalid_timestamp, mock_monitoring, mock_log ): - # Set an invalid timestamp in the session self.request.session[LAST_TOUCH_KEYNAME] = invalid_timestamp # The middleware should raise an exception when it tries to parse the invalid timestamp @@ -88,10 +86,8 @@ def test_process_request_invalid_timestamp_handling( with self.assertRaises(ValueError): self.middleware.process_request(self.request) - # Should log warning about parsing failure (from the first parsing attempt) mock_log.warning.assert_called_once() - # Should set error tracking attributes (from the first parsing attempt) mock_monitoring.set_custom_attribute.assert_any_call("session_inactivity.last_touch_error", ANY) mock_monitoring.record_exception.assert_called_once() @@ -215,14 +211,12 @@ def test_process_request_uses_default_save_frequency( assert response is None if should_save: - # Session should be saved with new timestamp assert self.request.session[LAST_TOUCH_KEYNAME] == current_time.isoformat() mock_monitoring.set_custom_attribute.assert_has_calls([ call("session_inactivity.has_exceeded_timeout_limit", False), call("session_inactivity.proceed_with_period_save", True), ], any_order=True) else: - # Session should not be saved, timestamp remains the same assert self.request.session[LAST_TOUCH_KEYNAME] == last_touch.isoformat() mock_monitoring.set_custom_attribute.assert_has_calls([ call("session_inactivity.has_exceeded_timeout_limit", False), From 567dd9a6979a4feb3fd609bb6704573e3c90c46b Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Thu, 14 Aug 2025 11:59:57 +0000 Subject: [PATCH 17/19] fix: updated mock for log --- .../session_inactivity_timeout/tests/test_middleware.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index e95f6e78118a..ca1a8288f19a 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -46,11 +46,12 @@ def test_process_request_unauthenticated_user_does_nothing(self): ) @override_settings(SESSION_INACTIVITY_TIMEOUT_IN_SECONDS=300) @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") + @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.log") @patch( "openedx.core.djangoapps.session_inactivity_timeout.middleware.monitoring_utils" ) def test_process_request_first_visit_sets_timestamp( - self, timestamp_value, mock_monitoring, mock_datetime + self, timestamp_value, mock_monitoring, mock_log, mock_datetime ): if timestamp_value is not None: self.request.session[LAST_TOUCH_KEYNAME] = timestamp_value @@ -59,11 +60,15 @@ def test_process_request_first_visit_sets_timestamp( mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now + response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() + # Verify debug log is called for first login scenarios + mock_log.debug.assert_called_once_with("No previous activity timestamp found (first login)") + mock_monitoring.set_custom_attribute.assert_has_calls([ call("session_inactivity.first_login", True), call("session_inactivity.proceed_with_period_save", True), From 68f1514b7e0c04f5457da8bc26d0aec2ec5ada61 Mon Sep 17 00:00:00 2001 From: ttak-apphelix Date: Mon, 18 Aug 2025 06:04:40 +0000 Subject: [PATCH 18/19] fix!: session ID stability while maintaining inactivity timeout BREAKING CHANGE: The breaking change is that SESSION_ACTIVITY_SAVE_DELAY_SECONDS was introduced with a 15 minute default, which will change the current behavior. It is not necessarily breaking (since it actually fixes an issue), but this is to bring more attention to the new setting because the default is reasonable, but also somewhat arbitrary. --- .../tests/test_middleware.py | 10 ---------- 1 file changed, 10 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index ca1a8288f19a..635783711333 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -60,13 +60,10 @@ def test_process_request_first_visit_sets_timestamp( mock_now = datetime(2025, 6, 16, 12, 0, 0) mock_datetime.utcnow.return_value = mock_now - response = self.middleware.process_request(self.request) # lint-amnesty, pylint: disable=assignment-from-none assert response is None assert self.request.session[LAST_TOUCH_KEYNAME] == mock_now.isoformat() - - # Verify debug log is called for first login scenarios mock_log.debug.assert_called_once_with("No previous activity timestamp found (first login)") mock_monitoring.set_custom_attribute.assert_has_calls([ @@ -141,16 +138,9 @@ def test_process_request_timeout_behavior( @ddt.data( # (save_delay_seconds, seconds_elapsed, should_save) # Test save delay behavior (with long timeout to avoid logout) - (900, 600, False), # 600 sec < 900 sec save delay, no save (900, 899, False), # 899 sec < 900 sec save delay, no save (900, 900, False), # 900 sec = 900 sec save delay, no save (not exceeded) (900, 901, True), # 901 sec > 900 sec save delay, save occurs - (900, 1200, True), # 1200 sec > 900 sec save delay, save occurs - (600, 480, False), # 480 sec < 600 sec save delay, no save - (600, 599, False), # 599 sec < 600 sec save delay, no save - (600, 600, False), # 600 sec = 600 sec save delay, no save (not exceeded) - (600, 601, True), # 601 sec > 600 sec save delay, save occurs - (600, 720, True), # 720 sec > 600 sec save delay, save occurs ) @ddt.unpack @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime") From 390fd8b4041ec1829451ba1fe90e370601b795fd Mon Sep 17 00:00:00 2001 From: Robert Raposa Date: Wed, 20 Aug 2025 21:37:22 -0400 Subject: [PATCH 19/19] fixup! Update openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py --- .../session_inactivity_timeout/tests/test_middleware.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py index 635783711333..c47505a9836a 100644 --- a/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py +++ b/openedx/core/djangoapps/session_inactivity_timeout/tests/test_middleware.py @@ -95,12 +95,9 @@ def test_process_request_invalid_timestamp_handling( @ddt.data( # (timeout_seconds, seconds_elapsed, should_logout) - # Test timeout behavior including boundary conditions - (300, 240, False), # 240 sec < 300 sec timeout, no logout (300, 299, False), # 299 sec < 300 sec timeout, no logout (300, 300, False), # 300 sec = 300 sec timeout, no logout (not exceeded) (300, 301, True), # 301 sec > 300 sec timeout, logout occurs - (300, 360, True), # 360 sec > 300 sec timeout, logout occurs ) @ddt.unpack @patch("openedx.core.djangoapps.session_inactivity_timeout.middleware.datetime")