LoginModule defined with cached=true, but called between web and ejb container

[dastraub]

In JBoss 4/5 the JassSecurityManager uses a cache so not reauthentification was requirered if we call a secured ejb from the web-container.

In JBoss 7 we defined the loginmodule with the option cache=true, but the loginmodule is now called by the login (web-container) and for each ejb call (huge performance impact !)

During the login in the web-container, the realm uses a JBossCachedAuthenticationManager (what we expected).

But during the ejb-call, the SecurityContextInterceptor/SimpleSecurityManager pushes the current SecurtiyContext in a thread local and creates a new SecurtiyContext with a new JBossAuthenticationManager.

In org.jboss.as.security.service.SimpleSecurityManager:

public void push(final String securityDomain, final String runAs, final String runAsPrincipal, final Set<String> extraRoles) {

   final SecurityContext previous = SecurityContextAssociation.getSecurityContext(); <--- the web container context, uses a JBossCachedAuthenticationManager

   contexts.push(previous);

   SecurityContext current = establishSecurityContext(securityDomain);  <--- creates a new SecurityContext with a new JBossAuthenticationManager

   if (previous != null) {

      current.setSubjectInfo(previous.getSubjectInfo());

      current.setIncomingRunAs(previous.getOutgoingRunAs());

   }

       ...

    authenticated = authenticationManager.isValid(principal, credential, subject); <-- uses principal, credentials from previous, but with the new JBossAuthenticationManager

and therefore the loginmodule is called again.

Why is the existing context isn't reused (web and ejb using the same security domain) ?

[dlofthouse]

The reason for the second call is because a new username and credential could have been set by the web app to run as a different user - on the final line you reference the authentication cache should be used and skip the login modules, are you saying that is not happening?

[dastraub]

Nope, nothing changed beetween web and ejb-call

For tests we  use a simple scenario :

- simple webapp with form based login, security domain

- the loginmodule is first called during the web login (I added a simple new Exception().printStacktrace() in the login module)

java.lang.Exception

          at de.xxxxx.XXXLoginModule.login(XXXLoginModule.java:144)

          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

          at java.lang.reflect.Method.invoke(Method.java:597)

          at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)

          at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)

          at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)

          at java.security.AccessController.doPrivileged(Native Method)

          at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)

          at javax.security.auth.login.LoginContext.login(LoginContext.java:579)

          at org.jboss.security.authentication.JBossCachedAuthenticationManager.defaultLogin(JBossCachedAuthenticationManager.java:449)

          at org.jboss.security.authentication.JBossCachedAuthenticationManager.proceedWithJaasLogin(JBossCachedAuthenticationManager.java:383)

          at org.jboss.security.authentication.JBossCachedAuthenticationManager.authenticate(JBossCachedAuthenticationManager.java:371)

          at org.jboss.security.authentication.JBossCachedAuthenticationManager.isValid(JBossCachedAuthenticationManager.java:160)

          at org.jboss.as.web.security.JBossWebRealm.authenticate(JBossWebRealm.java:214)

          at org.apache.catalina.authenticator.FormAuthenticator.authenticate(FormAuthenticator.java:280)

          at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:381)

- the login forwards to a jsf-page, the managed bean of this page calls a secured ejb within the same security domain (nothing changed, same thread, same song )

java.lang.Exception

          at de.xxxxx.XXXLoginModule.login(XXXLoginModule.java:144)

          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

          at java.lang.reflect.Method.invoke(Method.java:597)

          at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)

          at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)

          at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)

          at java.security.AccessController.doPrivileged(Native Method)

          at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)

          at javax.security.auth.login.LoginContext.login(LoginContext.java:579)

          at org.jboss.security.plugins.auth.JaasSecurityManagerBase.defaultLogin(JaasSecurityManagerBase.java:402)

          at org.jboss.security.plugins.auth.JaasSecurityManagerBase.proceedWithJaasLogin(JaasSecurityManagerBase.java:341)

          at org.jboss.security.plugins.auth.JaasSecurityManagerBase.authenticate(JaasSecurityManagerBase.java:329)

          at org.jboss.security.plugins.auth.JaasSecurityManagerBase.isValid(JaasSecurityManagerBase.java:207)

          at org.jboss.as.security.service.SimpleSecurityManager.authenticate(SimpleSecurityManager.java:267)

          at org.jboss.as.security.service.SimpleSecurityManager.push(SimpleSecurityManager.java:234)

          at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:49)

          at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:45)

          at java.security.AccessController.doPrivileged(Native Method)

          at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:74)

          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

          at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)

          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

          at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45)

          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

          at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:57)

          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

          at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

          at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165)

          at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:173)

          at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288)

          at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

          at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72)

          at de.xxxxx.SecuredEjb$$$view42.getCaller(Unknown Source)

          at de.xxxxx.sample.LoginData.getName(LoginData.java:66)

          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

          at java.lang.reflect.Method.invoke(Method.java:597)

          at javax.el.BeanELResolver.getValue(BeanELResolver.java:302)

          at com.sun.faces.el.DemuxCompositeELResolver._getValue(DemuxCompositeELResolver.java:176)

          at com.sun.faces.el.DemuxCompositeELResolver.getValue(DemuxCompositeELResolver.java:203)

          at org.apache.el.parser.AstValue.getValue(AstValue.java:169)

          at org.apache.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:189)

          at com.sun.faces.facelets.el.TagValueExpression.getValue(TagValueExpression.java:109)

In the source code of the SecurityContextInterceptor and SimpleSecurityManager - I can't find anything what deals with the principal name/credential (to detect a change).

From my understanding - if  the existing security domain (from the web container) the as the security domain of the ejb, the it must reuse the existing context and therefore the same JBossCachedAuthenticationManager instance.

Only if the security domain change, then you should to push the exisiting domain and use the name/credential for the new domain.

We have a login before each ejb call - and we use a lot of ejb's - and the login module uses a LDAP...

(Unfortunately, I can't provide the sample because it contains some confidential code).

[dastraub]

Amendment:  In the SimpleSecurityManager :

private static SecurityContext establishSecurityContext(final String securityDomain) {

  ...

creates every time a new SecurityContext instance - why is the existing (singleton) instance not used agin - which is bound in the jndi-tree with java:/jboss/jaas/.... ?

This should also solve the problem.

In JBoss 4/5 there were a global cache for principals (if I remember me correctly, we had some OutOfMemory with this ), now is the cache bound to the concrete (org.jboss.as.security.service.) SecurityDomainService instance.

[dastraub]

I moved this thread to "picketbox", can someone please look at that ?

We are currently migrating a large banking/loan application from JBoss EAP 4 to EAP 6.

This issue is a critical blocker for us.

[dlofthouse]

Please go ahead and create a Jira issue against AS 7, we need the SecurityDomainContext to be made available to the SimpleSecurityManager so that the cache will be used on the second isValid call.

[dastraub]

see https://issues.jboss.org/browse/AS7-3498

But why is a "isValid" call required, if both using the same security domain ?

[dlofthouse]

The reason for the second call is that between the authentication in the web tier and the call to the EJB the username and password could have been set in code to run as a different authenticated user, the switch to use the SecurityDomainContext will cause thise second call to use the same cache as the first call so no second authentication will actually occur and the identity will remain the same - should a username and password  be set then the identity will be switched to the new identity, this is also implemented as a stack so as the call returns the state of the stack is restored to the state it was when the call arrived at the EJB.

[dastraub]

Unitl you can find a solution, I patched the SimpleSecurityManager because of this problem we are massive hindered during our development process. Each ejb-call forces a call to a complex login module.

I changed in jboss-as-security the methode  SimpleSecurityManager.establishSecurityContext like this :

{code}

    private static SecurityContext establishSecurityContext(final String securityDomain) {

        // Do not use SecurityFactory.establishSecurityContext, its static init is broken.

        try {

            final AuthenticationManager authenticationManager = new JNDIBasedSecurityManagement().getAuthenticationManager(securityDomain);

            final SecurityContext securityContext = SecurityContextFactory.createSecurityContext(securityDomain);

            if (authenticationManager != null) {

                      final ISecurityManagement delegate = securityContext.getSecurityManagement();

                      securityContext.setSecurityManagement(new ISecurityManagement() {

                        @Override

                         public MappingManager getMappingManager(String securityDomain) {

                                   return delegate.getMappingManager(securityDomain);

                          }

                         @Override

                         public JSSESecurityDomain getJSSE(String securityDomain) {

                                return delegate.getJSSE(securityDomain);

                          }

                         @Override

                         public IdentityTrustManager getIdentityTrustManager(String securityDomain) {

                                  return delegate.getIdentityTrustManager(securityDomain);

                         }

                         @Override

                         public AuthorizationManager getAuthorizationManager(String securityDomain) {

                                  return delegate.getAuthorizationManager(securityDomain);

                         }

                         @Override

                         public AuthenticationManager getAuthenticationManager(String securityDomain) {

                                   return authenticationManager;

                          }

                         @Override

                         public AuditManager getAuditManager(String securityDomain) {

                                   return delegate.getAuditManager(securityDomain);

                         }

                   });

            }

            SecurityContextAssociation.setSecurityContext(securityContext);

            return securityContext;

        } catch (Exception e) {

            throw new SecurityException(e);

        }

    }

{code}

Does not look good, but is a workaround for us.

Btw, this solves only the problem in the ejb-container.

In the web-container, the SecurityContextAssociationValve creates also a new SecurityContext (without associated JBossCachedAuthenticationManager) for each request. At the moment, the only part using the corrrect AuthenticationManager is the JBossWebRealm.

But in the web-container, as you know the principal is stored in the session so no new login is required.

So a general solution should be prefered instead of this hack.

But we need some measured results for a decision if we should go ahed with JBoss 7 (greeting from management ..) 

[pgarner]

Immediately after updating an application user's password in the database, JBoss throws javax.ejb.EJBAccessException: JBAS013323: Invalid User.  It appears that JBoss security attempts to reauthenticate the principal with every method invocation between web and ejb container, which fails because the principal's password has become stale.  I was surprised to see the UsernamePasswordLoginModule trying to login again, with the resulting "Password invalid/Password required" error.  I'm using 7.2.0.Alpha-1-SNAPSHOT.  Shouldn't this problem have been resolved (AS7-3498)?

00:25:35,521 ERROR [org.jboss.security] (http-/127.0.0.1:8443-2) PBOX000206: Login failure: javax.security.auth.login.FailedLoginException: PBOX000070: Password invalid/Password required
    at org.jboss.security.auth.spi.UsernamePasswordLoginModule.login(UsernamePasswordLoginModule.java:283) [picketbox-4.0.13.Final.jar:4.0.13.Final]
    at sun.reflect.GeneratedMethodAccessor590.invoke(Unknown Source) [:1.7.0_07]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_07]
    at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.invoke(LoginContext.java:784) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696) [rt.jar:1.7.0_07]
    at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.login(LoginContext.java:594) [rt.jar:1.7.0_07]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.defaultLogin(JBossCachedAuthenticationManager.java:408) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.proceedWithJaasLogin(JBossCachedAuthenticationManager.java:345) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.authenticate(JBossCachedAuthenticationManager.java:333) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.isValid(JBossCachedAuthenticationManager.java:146) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.as.security.service.SimpleSecurityManager.authenticate(SimpleSecurityManager.java:354) [jboss-as-security-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.security.service.SimpleSecurityManager.push(SimpleSecurityManager.java:292) [jboss-as-security-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:49) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:45) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_07]
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:74) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:42) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at com.patrac.service.LoginHistoryService$$$view94.create(Unknown Source) [Patrac-ejb.jar:]
    at com.patrac.controller.SessionManager.createLoginHistoryRecord(SessionManager.java:163) [classes:]
    at com.patrac.controller.SessionManager.endOfSessionHouseKeeping(SessionManager.java:130) [classes:]
    at com.patrac.controller.SessionManager.logout(SessionManager.java:87) [classes:]
    at com.patrac.controller.SessionManager.changePassword(SessionManager.java:236) [classes:]
    at com.patrac.controller.SessionManager$Proxy$_$$_WeldClientProxy.changePassword(SessionManager$Proxy$_$$_WeldClientProxy.java) [classes:]
    at com.patrac.controller.backingbean.ChangePasswordBean.updateUserPasswordInSession(ChangePasswordBean.java:44) [classes:]
    at com.patrac.controller.statemachine.effect.ChangePasswordEffect.performAction(ChangePasswordEffect.java:21) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.effect.ChangePasswordEffect.performAction(ChangePasswordEffect.java:10) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.transition.Transition.fire(Transition.java:60) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.transition.GoToWorkflowTransition.fire(GoToWorkflowTransition.java:49) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.workflow.ChangePasswordWorkflow$1.evaluate(ChangePasswordWorkflow.java:62) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.workflow.ChangePasswordWorkflow$1.evaluate(ChangePasswordWorkflow.java:56) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.event.Event.trigger(Event.java:85) [Patrac-ejb.jar:]
    at com.patrac.controller.backingbean.BackingBean.dispatch(BackingBean.java:68) [classes:]
    at com.patrac.controller.backingbean.ChangePasswordBean$Proxy$_$$_WeldClientProxy.dispatch(ChangePasswordBean$Proxy$_$$_WeldClientProxy.java) [classes:]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_07]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_07]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_07]
    at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_07]
    at org.apache.el.parser.AstValue.invoke(AstValue.java:264) [jbossweb-7.0.17.Final.jar:]
    at org.apache.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:278) [jbossweb-7.0.17.Final.jar:]
    at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:39) [weld-core-1.1.9.Final.jar:2012-08-06 19:12]
    at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:50) [weld-core-1.1.9.Final.jar:2012-08-06 19:12]
    at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:88) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:101) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at javax.faces.component.UICommand.broadcast(UICommand.java:315) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:794) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:1259) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:81) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:118) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:593) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.17.Final.jar:]
    at org.jboss.weld.servlet.ConversationPropagationFilter.doFilter(ConversationPropagationFilter.java:62) [weld-core-1.1.9.Final.jar:2012-08-06 19:12]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.17.Final.jar:]
    at com.patrac.filter.NoCacheFilter.doFilter(NoCacheFilter.java:46) [classes:]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:489) [jbossweb-7.0.17.Final.jar:]
    at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50) [jboss-as-jpa-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50) [jboss-as-jpa-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:165) [jboss-as-web-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:372) [jbossweb-7.0.17.Final.jar:]
    at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:897) [jbossweb-7.0.17.Final.jar:]
    at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:634) [jbossweb-7.0.17.Final.jar:]
    at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:2039) [jbossweb-7.0.17.Final.jar:]
    at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_07]


00:25:35,566 ERROR [org.jboss.security] (http-/127.0.0.1:8443-2) PBOX000206: Login failure: javax.security.auth.login.FailedLoginException: PBOX000070: Password invalid/Password required
    at org.jboss.security.auth.spi.UsernamePasswordLoginModule.login(UsernamePasswordLoginModule.java:283) [picketbox-4.0.13.Final.jar:4.0.13.Final]
    at sun.reflect.GeneratedMethodAccessor590.invoke(Unknown Source) [:1.7.0_07]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_07]
    at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.invoke(LoginContext.java:784) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696) [rt.jar:1.7.0_07]
    at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:695) [rt.jar:1.7.0_07]
    at javax.security.auth.login.LoginContext.login(LoginContext.java:594) [rt.jar:1.7.0_07]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.defaultLogin(JBossCachedAuthenticationManager.java:408) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.proceedWithJaasLogin(JBossCachedAuthenticationManager.java:345) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.authenticate(JBossCachedAuthenticationManager.java:333) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.security.authentication.JBossCachedAuthenticationManager.isValid(JBossCachedAuthenticationManager.java:146) [picketbox-infinispan-4.0.13.Final.jar:4.0.13.Final]
    at org.jboss.as.security.service.SimpleSecurityManager.authenticate(SimpleSecurityManager.java:354) [jboss-as-security-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.security.service.SimpleSecurityManager.push(SimpleSecurityManager.java:292) [jboss-as-security-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:49) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:45) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_07]
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:74) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:42) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ejb3.component.stateful.StatefulComponentIdInterceptor.processInvocation(StatefulComponentIdInterceptor.java:52) [jboss-as-ejb3-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
    at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at com.patrac.controller.statemachine.screen.ChangePasswordScreen$$$view77.findLeafStateAndExitUpward(Unknown Source) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.transition.Transition.exitSource(Transition.java:90) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.transition.Transition.fire(Transition.java:62) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.transition.GoToWorkflowTransition.fire(GoToWorkflowTransition.java:49) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.workflow.ChangePasswordWorkflow$1.evaluate(ChangePasswordWorkflow.java:62) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.workflow.ChangePasswordWorkflow$1.evaluate(ChangePasswordWorkflow.java:56) [Patrac-ejb.jar:]
    at com.patrac.controller.statemachine.event.Event.trigger(Event.java:85) [Patrac-ejb.jar:]
    at com.patrac.controller.backingbean.BackingBean.dispatch(BackingBean.java:68) [classes:]
    at com.patrac.controller.backingbean.ChangePasswordBean$Proxy$_$$_WeldClientProxy.dispatch(ChangePasswordBean$Proxy$_$$_WeldClientProxy.java) [classes:]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_07]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_07]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_07]
    at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_07]
    at org.apache.el.parser.AstValue.invoke(AstValue.java:264) [jbossweb-7.0.17.Final.jar:]
    at org.apache.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:278) [jbossweb-7.0.17.Final.jar:]
    at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:39) [weld-core-1.1.9.Final.jar:2012-08-06 19:12]
    at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:50) [weld-core-1.1.9.Final.jar:2012-08-06 19:12]
    at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:88) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:101) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at javax.faces.component.UICommand.broadcast(UICommand.java:315) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:794) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:1259) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:81) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:118) [jsf-impl-2.1.13-jbossorg-1.jar:]
    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:593) [jboss-jsf-api_2.1_spec-2.0.6.Final.jar:2.0.6.Final]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.17.Final.jar:]
    at org.jboss.weld.servlet.ConversationPropagationFilter.doFilter(ConversationPropagationFilter.java:62) [weld-core-1.1.9.Final.jar:2012-08-06 19:12]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.17.Final.jar:]
    at com.patrac.filter.NoCacheFilter.doFilter(NoCacheFilter.java:46) [classes:]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:489) [jbossweb-7.0.17.Final.jar:]
    at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50) [jboss-as-jpa-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50) [jboss-as-jpa-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:165) [jboss-as-web-7.2.0.Alpha1-SNAPSHOT.jar:7.2.0.Alpha1-SNAPSHOT]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb-7.0.17.Final.jar:]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:372) [jbossweb-7.0.17.Final.jar:]
    at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:897) [jbossweb-7.0.17.Final.jar:]
    at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:634) [jbossweb-7.0.17.Final.jar:]
    at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:2039) [jbossweb-7.0.17.Final.jar:]
    at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_07]

	<subsystem xmlns="urn:jboss:domain:security:1.2">
	<security-domains>
	<security-domain name="PatracSecurityDomain" cache-type="default">
	<authentication>
	<login-module code="org.jboss.security.auth.spi.DatabaseServerLoginModule" flag="required">
	<module-option name="dsJndiName" value="java:/postgresdb"/>
	<module-option name="principalsQuery" value="SELECT userpassword FROM applicationuser WHERE email=?"/>
	<module-option name="rolesQuery" value="SELECT r.name, 'Roles' FROM USER_ROLE ur JOIN APPLICATIONUSER u ON ur.userid=u.id JOIN ROLE r ON ur.roleid=r.id where u.email=?"/>
	</login-module>
	</authentication>
	</security-domain>
	<security-domain name="jboss-web-policy" cache-type="default">
	<authorization>
	<policy-module code="Delegating" flag="required"/>
	</authorization>
	</security-domain>
	<security-domain name="jboss-ejb-policy" cache-type="default">
	<authorization>
	<policy-module code="Delegating" flag="required"/>
	</authorization>
	</security-domain>
	</security-domains>
	</subsystem>

[sguilhen]

This shouldn't be happening. I'll setup a sample app here to see if I can reproduce what you're seeing.

[pgarner]

I think the problem is that SessionManager#logout (which programmatically logs out the user e.g. HttpServletRequest#logout)) is invoked before invoking LoginHistoryService#create.  SessionManager is a CDI bean and LoginHistoryService is SLSB.  I think the "Invalid User" is a result of logout removing the principal prior to the invocation of create on the SLSB.

I'm looking into it, but want to let you know now what I think the problem is before you spend time on this.

[pgarner]

Sure enough, invoking LoginHistoryService#create before HttpServletRequest#logout solved the problem.  Sorry!  I should have caught that!  My fault for looking at code through blurry eyes at 4 AM.


[sguilhen]

Heh, that's fine!

[anil.saldhana]

Patrick Garner wrote:

Sure enough, invoking LoginHistoryService#create before HttpServletRequest#logout solved the problem.  Sorry!  I should have caught that!  My fault for looking at code through blurry eyes at 4 AM.


Hey Patrick.   

Glad things worked out. You had us worried.

Patrick, you should atone by helping the community by creating some kind of a quickstarter app (web,ejb) etc and show that this problem does not exist. Maybe a wiki article?