ThreadContext not cleaned up after REST request

classic Classic list List threaded Threaded
13 messages Options
Reply | Threaded
Open this post in threaded view
|

ThreadContext not cleaned up after REST request

franck102
This post was updated on .
CONTENTS DELETED
The author has deleted this message.
Reply | Threaded
Open this post in threaded view
|

ThreadContext not cleaned up after REST request

franck102

<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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

Brian Demers
Take a look at https://shiro.apache.org/subject.html#thread-association

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 <[hidden email]> 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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

franck102

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 <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

franck102

I may be completely missing something, but I don’t understand how SecurityUtils.getSubject() couldn’t be causing problems. If there isn’t a Subject in the ThreadContext the method creates one, and registers it in the context.

 

The problem is that the method is called from many places, most of which don’t take care of unregistering the Subject… for example:

org.springframework.web.context.request.ServletWebRequest#getDescription   calls

org.apache.shiro.web.servlet.ShiroHttpServletRequest#getSession(boolean)         calls (if session is null)

org.apache.shiro.web.servlet.ShiroHttpServletRequest#getSubject                            which calls SecurityUtils.getSubject()

 

… now clearly any code calling servletRequest.getDescription() is not expecting they need to remove the Subject from the context once they are done?

The Subject.execute() block that is invoked later won’t help, since it will restore the ThreadContext to a state where it had a Subject already.

 

Franck

 

From: Franck Mangin <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Friday, 11 October 2019 at 07:07
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

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 <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.

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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

franck102
In reply to this post by Brian Demers

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

franck102

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

Brian Demers
There are a few questions here, so I'll try to do my best

1. The thread context
 I'm not sure how you have your application configured, but in general, if you are just using a typical web application (nothing async, and you are not spawning threads from a request thread). All you would need to do is configure the ShiroFilter (which will handle setting up the thread-local you are referring to).  The caviaot here is you need to ensure that the ShiroFilter is triggered first (or at least very early) in the chain of Servlet Filters.

2. The cookie
How cookies are managed are up to your application
For example, you could have Shiro manage them with the "native" session support, or you could let your servlet container do it for you

I'm not sure if this actually answers your questions, but it would probably help if you put together a minimal example and we could point you in the right direction.


On Fri, Oct 11, 2019 at 11:04 AM Franck Mangin <[hidden email]> wrote:

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

franck102

Hi Brian,

 

Thanks for the help. The web application is a just a component in a larger framework: it doesn’t get to control servlet session management, and there are servlet filters executing before the Shiro filter (though none of them are Shiro aware).

Shiro is only used for authorization, its authentication filter merely makes sure that an OAuth servlet executing before Shiro has accepted a principal in the request context.

 

I solved my problem with a custom security manager that never resolves sessions:


   
@Override
   
protected SubjectContext resolveSession(SubjectContext context)
    {
       
// Disable sessions altogether
       
return context;
    }

Regarding the thread-local and SecurityUtils.getSubject() I found out that the method will fail in fact unless a security manager has been bound to the thread, and that only happens inside try/finally code that properly unbinds the manager… so no problem there I guess.

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Monday, 14 October 2019 at 17:27
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

There are a few questions here, so I'll try to do my best

 

1. The thread context

 I'm not sure how you have your application configured, but in general, if you are just using a typical web application (nothing async, and you are not spawning threads from a request thread). All you would need to do is configure the ShiroFilter (which will handle setting up the thread-local you are referring to).  The caviaot here is you need to ensure that the ShiroFilter is triggered first (or at least very early) in the chain of Servlet Filters.

 

2. The cookie
How cookies are managed are up to your application
For example, you could have Shiro manage them with the "native" session support, or you could let your servlet container do it for you

 

I'm not sure if this actually answers your questions, but it would probably help if you put together a minimal example and we could point you in the right direction.

 

 

On Fri, Oct 11, 2019 at 11:04 AM Franck Mangin <[hidden email]> wrote:

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.

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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

Brian Demers
Thanks for the follow-up!

On Tue, Oct 15, 2019 at 4:12 AM Franck Mangin <[hidden email]> wrote:

Hi Brian,

 

Thanks for the help. The web application is a just a component in a larger framework: it doesn’t get to control servlet session management, and there are servlet filters executing before the Shiro filter (though none of them are Shiro aware).

Shiro is only used for authorization, its authentication filter merely makes sure that an OAuth servlet executing before Shiro has accepted a principal in the request context.

 

I solved my problem with a custom security manager that never resolves sessions:


   
@Override
   
protected SubjectContext resolveSession(SubjectContext context)
    {
       
// Disable sessions altogether
       
return context;
    }

Regarding the thread-local and SecurityUtils.getSubject() I found out that the method will fail in fact unless a security manager has been bound to the thread, and that only happens inside try/finally code that properly unbinds the manager… so no problem there I guess.

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Monday, 14 October 2019 at 17:27
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

There are a few questions here, so I'll try to do my best

 

1. The thread context

 I'm not sure how you have your application configured, but in general, if you are just using a typical web application (nothing async, and you are not spawning threads from a request thread). All you would need to do is configure the ShiroFilter (which will handle setting up the thread-local you are referring to).  The caviaot here is you need to ensure that the ShiroFilter is triggered first (or at least very early) in the chain of Servlet Filters.

 

2. The cookie
How cookies are managed are up to your application
For example, you could have Shiro manage them with the "native" session support, or you could let your servlet container do it for you

 

I'm not sure if this actually answers your questions, but it would probably help if you put together a minimal example and we could point you in the right direction.

 

 

On Fri, Oct 11, 2019 at 11:04 AM Franck Mangin <[hidden email]> wrote:

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.

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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

sreenivas harshith
Hi,

I had reported this issue long back. SecurityUtils.getSubject() has a thread local storage , once a user 1 has been authenticated and after some invocations and if authentication is checked for new users, say user 2 and user 3 who are not authenticated it returns true (authenticated) for them.
I switched to Subject.Builder() and this fixed the issue. I think this is because Tomcat reuse the same threads which was used before and thread local storage is not cleared




On Wed, Oct 16, 2019 at 1:37 AM +0530, "Brian Demers" <[hidden email]> wrote:

Thanks for the follow-up!

On Tue, Oct 15, 2019 at 4:12 AM Franck Mangin <[hidden email]> wrote:

Hi Brian,

 

Thanks for the help. The web application is a just a component in a larger framework: it doesn’t get to control servlet session management, and there are servlet filters executing before the Shiro filter (though none of them are Shiro aware).

Shiro is only used for authorization, its authentication filter merely makes sure that an OAuth servlet executing before Shiro has accepted a principal in the request context.

 

I solved my problem with a custom security manager that never resolves sessions:


   
@Override
   
protected SubjectContext resolveSession(SubjectContext context)
    {
       
// Disable sessions altogether
       
return context;
    }

Regarding the thread-local and SecurityUtils.getSubject() I found out that the method will fail in fact unless a security manager has been bound to the thread, and that only happens inside try/finally code that properly unbinds the manager… so no problem there I guess.

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Monday, 14 October 2019 at 17:27
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

There are a few questions here, so I'll try to do my best

 

1. The thread context

 I'm not sure how you have your application configured, but in general, if you are just using a typical web application (nothing async, and you are not spawning threads from a request thread). All you would need to do is configure the ShiroFilter (which will handle setting up the thread-local you are referring to).  The caviaot here is you need to ensure that the ShiroFilter is triggered first (or at least very early) in the chain of Servlet Filters.

 

2. The cookie
How cookies are managed are up to your application
For example, you could have Shiro manage them with the "native" session support, or you could let your servlet container do it for you

 

I'm not sure if this actually answers your questions, but it would probably help if you put together a minimal example and we could point you in the right direction.

 

 

On Fri, Oct 11, 2019 at 11:04 AM Franck Mangin <[hidden email]> wrote:

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.

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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

Brian Demers
RIght!

For most cases of this is handled for you by `shiro-web` specifically the ShiroFIlter, but there are a couple of situations where this could bite you:
- When not using the ShiroFilter (or it's not placed early enough in the chain, most frameworks suggest hitting your security filter early)
- If you are spawning threads and you do not clean up the new thread's state


On Tue, Oct 15, 2019 at 10:56 PM sreenivas harshith <[hidden email]> wrote:
Hi,

I had reported this issue long back. SecurityUtils.getSubject() has a thread local storage , once a user 1 has been authenticated and after some invocations and if authentication is checked for new users, say user 2 and user 3 who are not authenticated it returns true (authenticated) for them.
I switched to Subject.Builder() and this fixed the issue. I think this is because Tomcat reuse the same threads which was used before and thread local storage is not cleared




On Wed, Oct 16, 2019 at 1:37 AM +0530, "Brian Demers" <[hidden email]> wrote:

Thanks for the follow-up!

On Tue, Oct 15, 2019 at 4:12 AM Franck Mangin <[hidden email]> wrote:

Hi Brian,

 

Thanks for the help. The web application is a just a component in a larger framework: it doesn’t get to control servlet session management, and there are servlet filters executing before the Shiro filter (though none of them are Shiro aware).

Shiro is only used for authorization, its authentication filter merely makes sure that an OAuth servlet executing before Shiro has accepted a principal in the request context.

 

I solved my problem with a custom security manager that never resolves sessions:


   
@Override
   
protected SubjectContext resolveSession(SubjectContext context)
    {
       
// Disable sessions altogether
       
return context;
    }

Regarding the thread-local and SecurityUtils.getSubject() I found out that the method will fail in fact unless a security manager has been bound to the thread, and that only happens inside try/finally code that properly unbinds the manager… so no problem there I guess.

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Monday, 14 October 2019 at 17:27
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

There are a few questions here, so I'll try to do my best

 

1. The thread context

 I'm not sure how you have your application configured, but in general, if you are just using a typical web application (nothing async, and you are not spawning threads from a request thread). All you would need to do is configure the ShiroFilter (which will handle setting up the thread-local you are referring to).  The caviaot here is you need to ensure that the ShiroFilter is triggered first (or at least very early) in the chain of Servlet Filters.

 

2. The cookie
How cookies are managed are up to your application
For example, you could have Shiro manage them with the "native" session support, or you could let your servlet container do it for you

 

I'm not sure if this actually answers your questions, but it would probably help if you put together a minimal example and we could point you in the right direction.

 

 

On Fri, Oct 11, 2019 at 11:04 AM Franck Mangin <[hidden email]> wrote:

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.

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.
Reply | Threaded
Open this post in threaded view
|

Re: ThreadContext not cleaned up after REST request

franck102
In reply to this post by sreenivas harshith

I don’t see how that can happen with the 1.3.2 code base: getSubject() will fail unless a SecurityManager was bound to the ThreadContext explicitly, or you have defined it as a singleton (which you don’t want in a webapp).

And the only places calling ThreadContext.bind(SecurityManager) are  the Subject runnable/callable, which restore the context in a finally block.

 

Unless you have a singleton SecurityManager or you are calling ThreadContext.bind(SecurityManager) I don’t think you can have Subjects leaking from a request into the next because of the ThreadContext.

 

Franck

 

From: sreenivas harshith <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Wednesday, 16 October 2019 at 04:56
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Hi,

I had reported this issue long back. SecurityUtils.getSubject() has a thread local storage , once a user 1 has been authenticated and after some invocations and if authentication is checked for new users, say user 2 and user 3 who are not authenticated it returns true (authenticated) for them.

I switched to Subject.Builder() and this fixed the issue. I think this is because Tomcat reuse the same threads which was used before and thread local storage is not cleared



On Wed, Oct 16, 2019 at 1:37 AM +0530, "Brian Demers" <[hidden email]> wrote:

Thanks for the follow-up!

 

On Tue, Oct 15, 2019 at 4:12 AM Franck Mangin <[hidden email]> wrote:

Hi Brian,

 

Thanks for the help. The web application is a just a component in a larger framework: it doesn’t get to control servlet session management, and there are servlet filters executing before the Shiro filter (though none of them are Shiro aware).

Shiro is only used for authorization, its authentication filter merely makes sure that an OAuth servlet executing before Shiro has accepted a principal in the request context.

 

I solved my problem with a custom security manager that never resolves sessions:


   
@Override
   
protected SubjectContext resolveSession(SubjectContext context)
    {
       
// Disable sessions altogether
       
return context;
    }

Regarding the thread-local and SecurityUtils.getSubject() I found out that the method will fail in fact unless a security manager has been bound to the thread, and that only happens inside try/finally code that properly unbinds the manager… so no problem there I guess.

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Monday, 14 October 2019 at 17:27
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

There are a few questions here, so I'll try to do my best

 

1. The thread context

 I'm not sure how you have your application configured, but in general, if you are just using a typical web application (nothing async, and you are not spawning threads from a request thread). All you would need to do is configure the ShiroFilter (which will handle setting up the thread-local you are referring to).  The caviaot here is you need to ensure that the ShiroFilter is triggered first (or at least very early) in the chain of Servlet Filters.

 

2. The cookie
How cookies are managed are up to your application
For example, you could have Shiro manage them with the "native" session support, or you could let your servlet container do it for you

 

I'm not sure if this actually answers your questions, but it would probably help if you put together a minimal example and we could point you in the right direction.

 

 

On Fri, Oct 11, 2019 at 11:04 AM Franck Mangin <[hidden email]> wrote:

I did find the NoSessionCreationFilter, however its Javadoc is not reassuring at all:

 

* <li>
* However, if the {@code Subject} already has an associated session before this filter is invoked, either because it
* was created in another part of the application, or a filter higher in the chain created one, this filter has no
* effect.
* </li>

 

This is not what I want: even if something somewhere created a Session for some obscure / bogus reason, I don’t want Shiro using it to cache subjects. Is there a bombproof way of achieving this?

 

Thanks!

Franck

 

From: Franck Mangin <[hidden email]>
Date: Friday, 11 October 2019 at 17:00
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

I made some progress: the problem disappears if the client doesn’t send the JSessionID cookie… so this is a session management problem (the two requests w/ different credentials came from the same session).

 

I had been hoping that this would be enough to disable sessions altogether?

securityManager.subjectDAO.sessionStorageEvaluator.sessionStorageEnabled = false

 

Franck

 

From: Brian Demers <[hidden email]>
Reply to: "[hidden email]" <[hidden email]>
Date: Thursday, 10 October 2019 at 15:45
To: "[hidden email]" <[hidden email]>
Subject: Re: ThreadContext not cleaned up after REST request

 

Take a look at https://shiro.apache.org/subject.html#thread-association

 

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 <[hidden email]> 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.

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.