Description of problem: Parallel invocations on a secured REST ejb can result in a loss of the security-context. The odd thing is that the security context is set correctly at the web layer, but it is lost at the ejb layer. This ends up in the security checks passing at the web layer, but the ejb call gets denied: 10:39:33,187 DEBUG [org.jboss.security] (http-127.0.0.1:8080-80) PBOX000291: Method: ping, interface: Local, required roles: Roles(ANYONE,) 10:39:33,189 DEBUG [org.jboss.security] (http-127.0.0.1:8080-80) PBOX000292: Insufficient method permissions [principal: null, EJB name: EchoSecureRestBean, method: ping, interface: Local, required roles: Roles(ANYONE,), principal roles: Roles(), run-as roles: null] 10:39:33,189 DEBUG [org.jboss.security] (http-127.0.0.1:8080-80) PBOX000299: Required module org.jboss.security.authorization.modules.DelegatingAuthorizationModule failed 10:39:33,190 DEBUG [org.jboss.security] (http-127.0.0.1:8080-80) PBOX000325: Authorization processing error: org.jboss.security.authorization.AuthorizationException: PBOX000017: Access denied: authorization failed I think I see what is doing on here. It looks like a race condition to me. flow: http client --> SecurityContextAssociationValve -> AuthenticatorBase -> BasicAuthenticator -> ... -> ejb layer Failure case: - SecurityContextAssociationValve says there is no principal to restore - in the failure case (see logs below), there is _no_ "Restoring principal..." log message - AuthenticatorBase.invoke() finds a principal ("We have cached auth type BASIC..."). The principal was not found in the session while in the SecurityContextAssociationValve, but it is retrieved from the HttpRequest.getUserPrincipal() method in side the AuthenticatorBase. - the principal ends up set at the web layer - there is nothing left to set the principal/subject for the ejb layer In the success case, the Principal is "restored" at the SecurityContextAssociationValve ... this appears to set the security-context so that it is available at the ejb layer. So all is well. Failure log messages: 08:52:53,429 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-50) Begin invoke, caller=null 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-50) *** JBossSecurityContextUtil.createSubjectInfo(principa, credential, subject) 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-50) *** SubjectInfo.addIdentity() 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-50) *** SecurityContext.setSubjectInfo(Identities=[null] Subject=null Roles=null) 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-50) *** SecurityContextAssociation.setSecurityContext([org.jboss.security.plugins.JBossSecurityContext()LOSSPI)]) 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-50) *** SecurityContextAssociation.setSecurityContext([org.jboss.security.plugins.JBossSecurityContext()LOSSPI)]) - subjectinfo - Identities=[null] Subject=null Roles=null 08:52:53,429 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) Security checking request GET /RestPbAuthWeb/rest/EchoSecureSvc/ping 08:52:53,429 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) We have cached auth type BASIC for principal GenericPrincipal[ludo(ANYONE,)] 08:52:53,429 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-50) Checking constraint 'SecurityConstraint[RestSecureServices]' against GET /rest/EchoSecureSvc/ping --> true 08:52:53,429 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-50) Checking constraint 'SecurityConstraint[RestSecureServices]' against GET /rest/EchoSecureSvc/ping --> true 08:52:53,429 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) Calling hasUserDataPermission() 08:52:53,429 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-50) User data constraint has no restrictions 08:52:53,429 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) Calling authenticate() 08:52:53,429 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) Already authenticated 'ludo' 08:52:53,431 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) Calling accessControl() 08:52:53,431 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-50) Checking roles GenericPrincipal[ludo(ANYONE,)] 08:52:53,431 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-50) JBWEB000017: User [ludo] has role [ANYONE] 08:52:53,431 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-50) hasRole:RealmBase says:true::Authz framework says:true:final=true 08:52:53,432 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-50) Role found: ANYONE 08:52:53,432 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-50) hasResourcePermission:RealmBase says:true::Authz framework says:true:final=true 08:52:53,432 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-50) Successfully passed all security constraints ... ... fails at the ejb layer No "Restoring principal info from cache" ^^ Success: 08:52:53,428 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-364) Begin invoke, caller=null 08:52:53,428 ERROR [stderr] (http-127.0.0.1:8080-364) *** JBossSecurityContextUtil.createSubjectInfo(principa, credential, subject) 08:52:53,428 ERROR [stderr] (http-127.0.0.1:8080-364) *** SubjectInfo.addIdentity() 08:52:53,428 ERROR [stderr] (http-127.0.0.1:8080-364) *** SecurityContext.setSubjectInfo(Identities=[null] Subject=null Roles=null) 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-364) *** SecurityContextAssociation.setSecurityContext([org.jboss.security.plugins.JBossSecurityContext()LOSSPI)]) 08:52:53,429 ERROR [stderr] (http-127.0.0.1:8080-364) *** SecurityContextAssociation.setSecurityContext([org.jboss.security.plugins.JBossSecurityContext()LOSSPI)]) - subjectinfo - Identities=[null] Subject=null Roles=null 08:52:53,429 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-364) Restoring principal info from cache 08:52:53,433 ERROR [stderr] (http-127.0.0.1:8080-364) *** JBossSecurityContextUtil.createSubjectInfo(principa, credential, subject) 08:52:53,433 ERROR [stderr] (http-127.0.0.1:8080-364) *** SubjectInfo.addIdentity() 08:52:53,434 ERROR [stderr] (http-127.0.0.1:8080-364) *** SubjectInfo.removeIdentity() 08:52:53,437 ERROR [stderr] (http-127.0.0.1:8080-364) *** SecurityContext.setSubjectInfo(Identities=[CredentialIdentity[principal=ludo;roles=null]] Subject=Subject: 08:52:53,438 ERROR [stderr] (http-127.0.0.1:8080-364) Principal: ludo 08:52:53,438 ERROR [stderr] (http-127.0.0.1:8080-364) Principal: Roles(members:ANYONE) 08:52:53,438 ERROR [stderr] (http-127.0.0.1:8080-364) Principal: CallerPrincipal(members:ludo) 08:52:53,438 ERROR [stderr] (http-127.0.0.1:8080-364) Roles=null) 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) Security checking request GET /RestPbAuthWeb/rest/EchoSecureSvc/ping 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) We have cached auth type BASIC for principal GenericPrincipal[ludo(ANYONE,)] 08:52:53,438 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-364) Checking constraint 'SecurityConstraint[RestSecureServices]' against GET /rest/EchoSecureSvc/ping --> true 08:52:53,438 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-364) Checking constraint 'SecurityConstraint[RestSecureServices]' against GET /rest/EchoSecureSvc/ping --> true 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) Calling hasUserDataPermission() 08:52:53,438 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-364) User data constraint has no restrictions 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) Calling authenticate() 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) Already authenticated 'ludo' 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) Calling accessControl() 08:52:53,438 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-364) Checking roles GenericPrincipal[ludo(ANYONE,)] 08:52:53,438 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-364) JBWEB000017: User [ludo] has role [ANYONE] 08:52:53,438 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-364) hasRole:RealmBase says:true::Authz framework says:true:final=true 08:52:53,438 DEBUG [org.apache.catalina.realm] (http-127.0.0.1:8080-364) Role found: ANYONE 08:52:53,438 TRACE [org.jboss.as.web.security] (http-127.0.0.1:8080-364) hasResourcePermission:RealmBase says:true::Authz framework says:true:final=true 08:52:53,438 DEBUG [org.apache.catalina.authenticator] (http-127.0.0.1:8080-364) Successfully passed all security constraints ... ... successful at the ejb layer This only appears to be an issue if the client passes in the JSESSIONID.
Reproducer instructions: JBoss EAP 6.4.14 setup: <security-domain name="LOSSPI" cache-type="default"> <authentication> <login-module code="UsersRoles" flag="required"> <module-option name="usersProperties" value="file:///${jboss.server.config.dir}/users.properties"/> <module-option name="rolesProperties" value="file:///${jboss.server.config.dir}/roles.properties"/> </login-module> </authentication> </security-domain> standalone/configuration/users.properties ludo=password standalone/configuration/roles.properties ludo=ANYONE - tar -xf RestPbAuth.tar.gz - change the jbossHome property in the RestPbAuthTest/src/test/resources/arquillian.xml file - start your JBoss instance - run "mvn -P arq-jbossas-managed test" The reproducer will deploy the test application and run the client. When the issue happens the error in the log will look like the following: 13:37:56,930 ERROR [org.jboss.as.ejb3.invocation] (http-127.0.0.1:8080-9) JBAS014134: EJB Invocation failed on component EchoSecureRestBean for method public abstract java.lang.String com.lodh.artetest.restpbauth.rest.IEchoSecureRest.ping(): javax.ejb.EJBAccessException: JBAS014502: Invocation on method: public abstract java.lang.String com.lodh.artetest.restpbauth.rest.IEchoSecureRest.ping() of bean: EchoSecureRestBean is not allowed
Created attachment 1291278 [details] reproducer
Stefan Guilhen has developed a patch for this issue.
Workaround: Disable the caching on the BasicAuthenticator in the WEB-INF/jboss-web.xml file: <valve> <class-name>org.apache.catalina.authenticator.BasicAuthenticator</class-name> <param> <param-name>cache</param-name> <param-value>false</param-value> </param> </valve>
Fix committed here: http://git.app.eng.bos.redhat.com/git/jbossas/jboss-as.git/commit/?h=EAP_6.4.16.CP_bz-1464597 I don't think an upstream fix is required since upstream is using undertow.
Verified with EAP 6.4.19.CP.CR2