Reasons why an SP would expire a session early?

[Peter Murray]

I'm running the Shibboleth SP version 3.3.0 on Ubuntu. I have an IdP partner where the SP seems to be expiring a signed on user's session cache early. I've turned on debugging for the session cache and storage service, and recorded these log lines:

2023-08-08 15:48:29 DEBUG XMLTooling.StorageService [12438] [default]: inserted record (session) in context (_126a6e98f1011e7d796a2febdca11635) with expiration (1691513309)
2023-08-08 15:48:29 DEBUG XMLTooling.StorageService [12438] [default]: inserted record (AAdzZWNyZXQx4qPbBxcwJ0NxqvgpQ8VUQboOaaVYd+FmxhlXBJUhlfhjtCp5zWesj7MmmT0NIvUb66qC+Oyq+JJalfnPl/15A9oNDIzpOxJIZw55vhLxyOPZcJYQTgYAcvLUtYyBfao3LRH82qooiCyCp00EDQ==) in context (NameID) with expiration (1691538509)
2023-08-08 15:48:29 INFO Shibboleth.SessionCache [12438] [default]: new session created: ID (_126a6e98f1011e7d796a2febdca11635) IdP (https://fedauth.colorado.edu/idp/shibboleth) Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address (172.16.159.138)
2023-08-08 15:48:29 DEBUG XMLTooling.StorageService [12438] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513309)
2023-08-08 15:48:29 DEBUG XMLTooling.StorageService [12438] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513309)
2023-08-08 15:49:35 DEBUG XMLTooling.StorageService [12495] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513375)
2023-08-08 15:49:35 DEBUG XMLTooling.StorageService [12495] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513375)
2023-08-08 15:49:36 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513376)
2023-08-08 15:49:37 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513377)
2023-08-08 15:49:38 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513378)
2023-08-08 15:49:38 DEBUG XMLTooling.StorageService [12495] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513378)
2023-08-08 15:49:38 DEBUG XMLTooling.StorageService [12493] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513378)
2023-08-08 15:49:38 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513378)
2023-08-08 15:49:44 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513384)
2023-08-08 15:49:45 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513385)
2023-08-08 15:49:46 DEBUG XMLTooling.StorageService [12471] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691513386)
2023-08-08 16:29:42 DEBUG XMLTooling.StorageService [12996] [default]: updated expiration of valid records in context (_126a6e98f1011e7d796a2febdca11635) to (1691515782)
2023-08-08 16:29:42 INFO Shibboleth.SessionCache [12996] [default]: removed session (_126a6e98f1011e7d796a2febdca11635)

In summary:

• Shibboleth session started at 15:48:29 with an initial expiration of 16:48:29 (1691597475)
• Shibboleth session repeatedly extended until 15:49:46, at which point the expiration was 16:49:46 (1691513386)
• At 16:29:42, the expiration was updated to 17:29:42 (1691515782), but then removed from the cache.


The application is a PHP app running in Apache/2.4.52 with mod_shib from the package manager as "libapache2-mod-shib/jammy,now 3.3.0+dfsg1-1". The PHP app expects to see the Shib state in its session variables, but when it comes to the last HTTP transaction (at 16:29:42) the ship state is no longer there.

Any advise on where I might look to see why this session is being expired early?

Peter
--
Peter Murray
Open Source Community Advocate
Index Data, LLC
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20230809/325f3447/attachment.htm>