Skip to content

SessionDestroyedEvent not getting triggered under certain conditions #12140

@attitudemattrs

Description

@attitudemattrs

We currently have class SessionDestroyedListener implements ApplicationListener<SessionDestroyedEvent> defined which handles logout auditing and application session cleanup within the onApplicationEvent(SessionDestroyedEvent evt) method.

Within the web.xml we have the HttpSessionEventPublisher defined as below:

   <listener>
       <listener-class>org.springframework.security.web.session.HttpSessionEventPublisher</listener-class>
   </listener>

Within the <sec:http> definition we have <sec:session-management invalid-session-url="/login"/> defined, allowing multiple logins for the same user principal. Have also tried the configuration below:

   <sec:session-management invalid-session-url="/login">
         <sec:concurrency-control max-sessions="-1" session-registry-alias="sessionRegistry"/>
   </sec:session-management>

When a user logs into the application we use session.setMaxInactiveInterval(time) to set the max inactive interval for the session to 3 minutes (for example).

Under normal circumstances, if the user logs into the application and logs out or closes the browser completely we get the SessionDestoryedEvent as expected, and we can do our auditing and cleanup. However, in the described scenario below we are seeing an issue.

The issue is best explained using the steps to reproduce below.

Expected Behavior

  1. Open Chrome (or Edge or Firefox) browser
  2. Login to the application using a user 'user1'
  3. Close the browser (so that no tabs or other instances of the browser are open)
  4. Open a new instance of the same browser again, in this case Chrome
  5. Login to the application using the same (or different) user
  6. Close the browser (so that no tabs or other instances of the browser are open)
  7. Wait for the configured MaxInactiveInterval and the SessionDestroyedEvent gets called twice, once for each previous session, as expected.
[2022-11-04 08:19:28,642] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-138) Registering session E8NJiFuMgIrrBEPAoaC1PHIMfBKGiDHUWans3yZF, for principal user1
[2022-11-04 08:19:28,644] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-138) Sessions used by 'user1' : [E8NJiFuMgIrrBEPAoaC1PHIMfBKGiDHUWans3yZF]
[2022-11-04 08:19:28,659] DEBUG [com.company.app.client.security.AppAuthenticationSuccessHandler] (default task-138) Using default Url: /home
    |
[2022-11-04 08:19:45,252] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-170) Registering session ofWZ6OHTj-MAnsQ9jVXoz2eidjs380sMtD4xibE4, for principal user1
[2022-11-04 08:19:45,252] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-170) Sessions used by 'user1' : [E8NJiFuMgIrrBEPAoaC1PHIMfBKGiDHUWans3yZF, ofWZ6OHTj-MAnsQ9jVXoz2eidjs380sMtD4xibE4]
[2022-11-04 08:19:45,255] DEBUG [com.company.app.client.security.AppAuthenticationSuccessHandler] (default task-170) Using default Url: /home
   |
[2022-11-04 08:19:56,091] DEBUG [com.company.app.client.security.SessionDestroyedListener] (default task-191) SessionDestroyedListener: about to audit: Successful logout
[2022-11-04 08:19:56,266] DEBUG [com.company.app.cesp.core.bo.dao.DAOBase] (default task-191) Successfully deleted session record for user = user1
[2022-11-04 08:19:56,266] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-191) Removing session E8NJiFuMgIrrBEPAoaC1PHIMfBKGiDHUWans3yZF from set of registered sessions
[2022-11-04 08:19:56,268] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-191) Removing session E8NJiFuMgIrrBEPAoaC1PHIMfBKGiDHUWans3yZF from principal's set of registered sessions
[2022-11-04 08:19:56,268] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-191) Sessions used by 'user1' : [ofWZ6OHTj-MAnsQ9jVXoz2eidjs380sMtD4xibE4]
   |
[2022-11-04 08:21:06,860] DEBUG [com.company.app.client.security.SessionDestroyedListener] (ServerService Thread Pool -- 117) SessionDestroyedListener: about to audit: Successful logout
[2022-11-04 08:21:07,023] DEBUG [com.company.app.cesp.core.bo.dao.DAOBase] (ServerService Thread Pool -- 117) Successfully deleted session record for user = user1
[2022-11-04 08:21:07,023] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (ServerService Thread Pool -- 117) Removing session ofWZ6OHTj-MAnsQ9jVXoz2eidjs380sMtD4xibE4 from set of registered sessions
[2022-11-04 08:21:07,023] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (ServerService Thread Pool -- 117) Removing session ofWZ6OHTj-MAnsQ9jVXoz2eidjs380sMtD4xibE4 from principal's set of registered sessions
[2022-11-04 08:21:07,023] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (ServerService Thread Pool -- 117) Removing principal user1 from registry
[2022-11-04 08:21:07,023] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (ServerService Thread Pool -- 117) Sessions used by 'user1' : null

Unexpected Behavior

  1. Open Chrome (or Edge or Firefox) browser
  2. Navigate to some non-application page, such as google.com and leave browser open
  3. Open a new instance of the same browser, in this case Chrome
  4. Login to the application using a user 'user1'
  5. Close the browser (leave the original browser instance open - i.e., google.com)
  6. Open a new instance of the same browser again
  7. Login to the application using the same (or different) user
  8. Close the browser (leave the original browser instance open - i.e., google.com)
  9. Wait for the configured MaxInactiveInterval and the SessionDestroyedEvent gets called ONCE, only for the 2nd application session established.
[2022-11-04 08:22:00,616] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-197) Registering session yeRXm12kS6hs0OAmizS3ntEhYTkIDer5LVWWyQF0, for principal user1
[2022-11-04 08:22:00,617] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-197) Sessions used by 'user1' : [yeRXm12kS6hs0OAmizS3ntEhYTkIDer5LVWWyQF0]
[2022-11-04 08:22:00,623] DEBUG [com.company.app.client.security.AppAuthenticationSuccessHandler] (default task-197) Using default Url: /home
   |
[2022-11-04 08:22:20,618] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-218) Registering session RK_J-V2xprRUqWif26Pw91Jtp2m6CJo1yrWWGhXB, for principal user1
[2022-11-04 08:22:20,618] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-218) Sessions used by 'user1' : [yeRXm12kS6hs0OAmizS3ntEhYTkIDer5LVWWyQF0, RK_J-V2xprRUqWif26Pw91Jtp2m6CJo1yrWWGhXB]
[2022-11-04 08:22:20,624] DEBUG [com.company.app.client.security.AppAuthenticationSuccessHandler] (default task-218) Using default Url: /home
   |
[2022-11-04 08:25:25,892] DEBUG [com.company.app.client.security.SessionDestroyedListener] (default task-248) SessionDestroyedListener: about to audit: Successful logout
[2022-11-04 08:25:26,064] DEBUG [com.company.app.cesp.core.bo.dao.DAOBase] (default task-248) Successfully deleted session record for user = user1
[2022-11-04 08:25:26,064] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-248) Removing session RK_J-V2xprRUqWif26Pw91Jtp2m6CJo1yrWWGhXB from set of registered sessions
[2022-11-04 08:25:26,064] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-248) Removing session RK_J-V2xprRUqWif26Pw91Jtp2m6CJo1yrWWGhXB from principal's set of registered sessions
[2022-11-04 08:25:26,064] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-248) Sessions used by 'user1' : [yeRXm12kS6hs0OAmizS3ntEhYTkIDer5LVWWyQF0]

As you can see, in the Unexpected Behavior scenario, only the 2nd session triggers the SessionDestroyedEvent and gets cleaned up. The first one remains out there and seems to never expire. Looking through the SessionRegistry in the debugger in subsequent requests, the last activity time remains static at the last activity time before the original browser was closed and the session expired flag remains false for the remaining session. Even if I close the remaining browser windows the session never gets cleaned up until the application server is shutdown. Though in my Un-Expected Behavior scenario I used the same user, this exact behavior can be repeated even if the second user login is done using a completely unique principal. See below:

[2022-11-04 09:12:15,579] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-248) Registering session 0Hn13-u69b_ARczcAWJvuRmIJy-qwrkzXoqCxmMf, for principal user1
[2022-11-04 09:12:15,580] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-248) Sessions used by 'user1' : [0Hn13-u69b_ARczcAWJvuRmIJy-qwrkzXoqCxmMf]
[2022-11-04 09:12:15,584] DEBUG [com.company.app.client.security.AppAuthenticationSuccessHandler] (default task-248) Using default Url: /home
   |
[2022-11-04 09:12:47,804] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-297) Registering session 2Vu_bVJ6fB8fGPABBXqgWa7b-Bd88ZKeTaZqh6AH, for principal user2
[2022-11-04 09:12:47,804] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-297) Sessions used by 'user2' : [2Vu_bVJ6fB8fGPABBXqgWa7b-Bd88ZKeTaZqh6AH]
[2022-11-04 09:12:47,810] DEBUG [com.company.app.client.security.AppAuthenticationSuccessHandler] (default task-297) Using default Url: /home
   |
[2022-11-04 09:15:52,965] DEBUG [com.company.app.client.security.SessionDestroyedListener] (default task-318) SessionDestroyedListener: about to audit: Successful logout
[2022-11-04 09:15:53,146] DEBUG [com.company.app.cesp.core.bo.dao.DAOBase] (default task-318) Successfully deleted session record for user = user2
[2022-11-04 09:15:53,146] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-318) Removing session 2Vu_bVJ6fB8fGPABBXqgWa7b-Bd88ZKeTaZqh6AH from set of registered sessions
[2022-11-04 09:15:53,147] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-318) Removing session 2Vu_bVJ6fB8fGPABBXqgWa7b-Bd88ZKeTaZqh6AH from principal's set of registered sessions
[2022-11-04 09:15:53,148] DEBUG [org.springframework.security.core.session.SessionRegistryImpl] (default task-318) Removing principal user2 from registry
[2022-11-04 09:15:53,148] TRACE [org.springframework.security.core.session.SessionRegistryImpl] (default task-318) Sessions used by 'user2' : null

Note, I even changed the user principal to be unique within the application code by adding a unique UUID to it and it didn't matter, despite the fact that even with the same user logging in, the principal was always unique. Just the existence of another instance of the same browser (even browsing a different site) seems to affect the behavior.

One final remark. In the Unexpected Behavior scenario, if I stop at step 5 and wait, without logging in again, the SessionDestroyedEvent does get triggered and the session is cleaned up as expected.

This behavior was repeated with Chrome, Edge, and Firefox.

I'm not ruling out configuration issues on the application side, but this certainly seems like odd and incorrect behavior to me that seems outside the control of the application or its configuration.

Any assistance in this matter would be greatly appreciated!

Thanks

Metadata

Metadata

Labels

in: webAn issue in web modules (web, webmvc)type: bugA general bug

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions