Thanks Brian, As far as I know we don’t use async servlets at all. If you look at the logs the same thread http-apr-8080-exec-7 (from the Tomcat pool) is processing the entire request. I am working on adding a Thread.printStackTrace in ThreadContext to find out what/who is putting the Subject in the thread context. I could try to extract a reproducible test case, but the code is quite complex so that would be at least ½ day of work…
Franck From: Brian Demers <[email protected]> Reply to: "[email protected]" <[email protected]> Date: Thursday, 10 October 2019 at 15:45 To: "[email protected]" <[email protected]> Subject: Re: ThreadContext not cleaned up after REST request Take a look at https://shiro.apache.org/subject.html#thread-association<https://urldefense.proofpoint.com/v2/url?u=https-3A__shiro.apache.org_subject.html-23thread-2Dassociation&d=DwMFaQ&c=ObqWq9831a7badpzAhIKIA&r=nQOltkjOzdXqkPdbNY4_HrRBjeSbKdDUhyndw0GHR7M&m=d2ZwgM0QaCqU3iMd8ajna0ixN8ytuv8QuvA8VG5Q3yY&s=ZUxl3fOiUdbjYZbLEmluV2aCpJWrkE0h_GE5P4wMq5s&e=> Async Servlets are processed outside the context of a thread (different thread pool). Typically you need to configure the binding/unbinding of the subject to those threads using a different mechanism. If you put together a simple reproduction example we can probably point you in the right direction (possibly turning it into an official example) -Brian On Oct 10, 2019, at 5:32 AM, Franck Mangin <[email protected]> wrote: <Posting through nabble removed all quotes, retrying through email> Hi all, We have a stateless JAX-RS application that uses Shiro. Once a user has authenticated and its Subject has been put in the ThreadContext, shiro will return that Subject for all subsequent requests processed by the same Tomcat thread. Going through the logs this seems to happen because AbstractShiroFilter#doFilterInternal calls createSubject(...) before calling subject.execute(...) createSubject somehow binds the Subject to the session, however there is no corresponding unbind call, as confirmed by the logs (see below) "Bound value of type..." and "Removed value of type..." entries. I have been pounding my head against the wall with this, any help would be greatly appreciated! Thanks,<raw></raw> Franck <h4>Configuration</h4> Shiro.ini: <pre> [main] fdoRealm = com.fico.dmp.fdo.common.shiro.FDORealm securityManager.realms = $iniRealm, $fdoRealm securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false [roles] ... </pre> ShiroFilter: <pre> @Bean public ShiroFilterFactoryBean shiroFilter() { ShiroFilterFactoryBean bean = new ShiroFilterFactoryBean(); bean.setSecurityManager(securityManager()); Map<String, String> filters = new HashMap<>(); filters.put("/health", "anon"); filters.put("/**", "authDMS"); bean.setFilterChainDefinitionMap(filters); return bean; } @Bean public SecurityManager securityManager() { Realm realm = _applicationContext.getBean("fdoRealm", Realm.class); return new DefaultWebSecurityManager(realm); } </pre> web.xml: <pre> <filter> <filter-name>shiroFilter</filter-name> <filter-class>org.springframework.web.filter.DelegatingFilterProxy</filter-class> <async-supported>true</async-supported> <init-param> <param-name>targetFilterLifecycle</param-name> <param-value>true</param-value> </init-param> </filter> </pre> <h4>Logs</h4> The logs for the first request to come in looks like this: our Realm is invoked to authenticate the request, but there is no "Removed value of type..." anywhere in the logs so the authenticated Subject remains in the ThreadContext: <pre> FDO 08:12:15.486 [http-apr-8080-exec-7] TRACE o.a.s.w.servlet.OncePerRequestFilter - Filter 'shiroFilter' not yet executed. Executing now. FDO 08:12:15.486 [http-apr-8080-exec-7] TRACE o.a.shiro.mgt.DefaultSecurityManager - Context already contains a SecurityManager instance. Returning. FDO 08:12:15.486 [http-apr-8080-exec-7] TRACE o.a.shiro.mgt.DefaultSecurityManager - No identity (PrincipalCollection) found in the context. Looking for a remembered identity. FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.shiro.web.servlet.SimpleCookie - No 'rememberMe' cookie value FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.shiro.mgt.DefaultSecurityManager - No remembered identity found. Returning original context. FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Bound value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] to thread [http-apr-8080-exec-7] FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Bound value of type [org.apache.shiro.web.mgt.DefaultWebSecurityManager] for key [org.apache.shiro.util.ThreadContext_SECURITY_MANAGER_KEY] to thread [http-apr-8080-exec-7] FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.w.f.m.PathMatchingFilterChainResolver - Matched path pattern [/**] for requestURI [/rest/service/api/webenv]. Utilizing corresponding filter chain... FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.w.servlet.AbstractShiroFilter - Resolved a configured FilterChain for the current request. FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.web.servlet.ProxiedFilterChain - Invoking wrapped filter at index [0] FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.w.servlet.OncePerRequestFilter - Filter 'authDMS' not yet executed. Executing now. FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Attempting to match pattern '/**' with current requestURI '/rest/service/api/webenv'... FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Current requestURI matches pattern '/**'. Determining filter chain execution... FDO 08:12:15.487 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Filter 'authDMS' is enabled for the current request under path '/**' with config [null]. Delegating to subclass implementation for 'onPreHandle' check. FDO 08:12:15.488 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - get() - in thread [http-apr-8080-exec-7] FDO 08:12:15.488 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Retrieved value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] bound to thread [http-apr-8080-exec-7] FDO 08:12:15.488 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Attempting to match pattern '/login.jsp' with current requestURI '/rest/service/api/webenv'... FDO 08:12:15.488 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - get() - in thread [http-apr-8080-exec-7] FDO 08:12:15.488 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Retrieved value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] bound to thread [http-apr-8080-exec-7] FDO 08:12:15.488 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.489 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - get() - in thread [http-apr-8080-exec-7] FDO 08:12:15.489 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Retrieved value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] bound to thread [http-apr-8080-exec-7] FDO 08:12:15.489 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = true; session has id = false FDO 08:12:15.489 [http-apr-8080-exec-7] TRACE o.a.s.authc.AbstractAuthenticator - Authentication attempt received for token [FDO 08:12:15.494 [http-apr-8080-exec-7] DEBUG c.fico.dmp.fdo.common.shiro.FDORealm - Returning authentication info: {mail=ficooptotenantadmin@...] </pre> The next request to come in on the same thread generates this log, our Realm is not invoked: <pre> FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.w.servlet.OncePerRequestFilter - Filter 'shiroFilter' not yet executed. Executing now. FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.shiro.mgt.DefaultSecurityManager - Context already contains a SecurityManager instance. Returning. FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = false; session has id = true FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = false; session has id = true FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = false; session has id = true FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = false; session has id = true FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = false; session has id = true FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Bound value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] to thread [http-apr-8080-exec-7] FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Bound value of type [org.apache.shiro.web.mgt.DefaultWebSecurityManager] for key [org.apache.shiro.util.ThreadContext_SECURITY_MANAGER_KEY] to thread [http-apr-8080-exec-7] FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.w.f.m.PathMatchingFilterChainResolver - Matched path pattern [/**] for requestURI [/rest/service/api/webenv]. Utilizing corresponding filter chain... FDO 08:13:38.455 [http-apr-8080-exec-7] TRACE o.a.s.w.servlet.AbstractShiroFilter - Resolved a configured FilterChain for the current request. FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.s.web.servlet.ProxiedFilterChain - Invoking wrapped filter at index [0] FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.s.w.servlet.OncePerRequestFilter - Filter 'authDMS' not yet executed. Executing now. FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Attempting to match pattern '/**' with current requestURI '/rest/service/api/webenv'... FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Current requestURI matches pattern '/**'. Determining filter chain execution... FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.s.web.filter.PathMatchingFilter - Filter 'authDMS' is enabled for the current request under path '/**' with config [null]. Delegating to subclass implementation for 'onPreHandle' check. FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - get() - in thread [http-apr-8080-exec-7] FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Retrieved value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] bound to thread [http-apr-8080-exec-7] FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.shiro.web.servlet.AdviceFilter - Invoked preHandle method. Continuing chain?: [true] FDO 08:13:38.456 [http-apr-8080-exec-7] TRACE o.a.s.web.servlet.ProxiedFilterChain - Invoking original filter chain. FDO 08:13:38.459 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - get() - in thread [http-apr-8080-exec-7] FDO 08:13:38.459 [http-apr-8080-exec-7] TRACE org.apache.shiro.util.ThreadContext - Retrieved value of type [org.apache.shiro.web.subject.support.WebDelegatingSubject] for key [org.apache.shiro.util.ThreadContext_SUBJECT_KEY] bound to thread [http-apr-8080-exec-7] FDO 08:13:38.459 [http-apr-8080-exec-7] TRACE o.a.s.s.support.DelegatingSubject - attempting to get session; create = false; session is null = false; session has id = true FDO 08:13:38.459 [http-apr-8080-exec-7] TRACE o.a.shiro.web.servlet.AdviceFilter - Successfully invoked postHandle method FDO 08:13:38.459 [http-apr-8080-exec-7] TRACE o.a.shiro.web.servlet.AdviceFilter - Successfully invoked afterCompletion method. </pre> This email and any files transmitted with it are confidential, proprietary and intended solely for the individual or entity to whom they are addressed. If you have received this email in error please delete it immediately. This email and any files transmitted with it are confidential, proprietary and intended solely for the individual or entity to whom they are addressed. If you have received this email in error please delete it immediately.
