fix!: session ID stability while maintaining inactivity timeout

openedx/core/djangoapps/session_inactivity_timeout/middleware.py

@@ -14,18 +14,23 @@
 
 
 from datetime import datetime, timedelta
+import logging
 
 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'
+
+log = logging.getLogger(__name__)
 
 
 class SessionInactivityTimeout(MiddlewareMixin):
     """
     Middleware class to keep track of activity on a given session
     """
+
     def process_request(self, request):
         """
         Standard entry point for processing requests in Django
@@ -34,27 +39,63 @@ 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: 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)
 
+        current_time = datetime.utcnow()
         # Do we have this feature enabled?
         if timeout_in_seconds:
-            # what time is it now?
-            utc_now = datetime.utcnow()
+            # .. setting_name: SESSION_ACTIVITY_SAVE_DELAY_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 
+            #   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.
+            #   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)
 
             # 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:
+                    last_touch = datetime.fromisoformat(last_touch_str)
+                    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:
+                        del request.session[LAST_TOUCH_KEYNAME]
+                        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)
+                    monitoring_utils.set_custom_attribute('session_inactivity.last_touch_status', 'last-touch-error')
+
+            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')
+                log.debug("No previous activity timestamp found (first login)")
+
+            current_time_str = current_time.isoformat()
+
+            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
+            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_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')

openedx/core/djangoapps/session_inactivity_timeout/tests/__init__.py

@@ -0,0 +1,3 @@
+"""
+Tests for session inactivity timeout middleware.
+"""