Access to secure ejb fails after successful authentication and authorization

[Tomas Andersson]

As discussed in Elytron ldap-realm migration we try to secure ejbs with a cached ldap realm and we get so far that the connection to the ldap work and that my user is both authenticated and authorized but I still cannot access the secured ejb. It seems like the actual check to see if the ejb can be accessed is made with principal [anonymous] and not with my just authorized user. 

Does anyone have an idea on what we are doing wrong?

As stated in the other discussion I modified a simple quickstart https://github.com/wildfly/quickstart/tree/main/ejb-security that is working when using the standard other-realm but when switching to the cached ldap(with PLAIN initially as DIGEST-MD5 is not supported) I get the following:

2022-02-28 08:54:26,836 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received authentication request
2022-02-28 08:54:26,837 TRACE [org.wildfly.security] (default I/O-6) Handling MechanismInformationCallback type='SASL' name='PLAIN' host-name='localhost' protocol='remote'
2022-02-28 08:54:26,837 TRACE [org.wildfly.security] (default I/O-6) Handling MechanismInformationCallback type='SASL' name='PLAIN' host-name='localhost' protocol='remote'
2022-02-28 08:54:26,838 TRACE [org.wildfly.security] (default I/O-6) Creating SaslServer [org.wildfly.security.sasl.plain.PlainSaslServer@2c39d5bb] for mechanism [PLAIN] and protocol [remote]
2022-02-28 08:54:26,838 TRACE [org.wildfly.security] (default I/O-6) Created SaslServer [org.wildfly.security.sasl.util.SecurityIdentitySaslServerFactory$1@74be9023->org.wildfly.security.sasl.util.AuthenticationTimeoutSaslServerFactory$DelegatingTimeoutSaslServer@22569028->org.wildfly.security.sasl.util.AuthenticationCompleteCallbackSaslServerFactory$1@40200dd4->org.wildfly.security.sasl.plain.PlainSaslServer@2c39d5bb] for mechanism [PLAIN]
2022-02-28 08:54:26,840 TRACE [org.wildfly.security] (default task-1) Handling NameCallback: authenticationName = tomas
2022-02-28 08:54:26,840 TRACE [org.wildfly.security] (default task-1) Principal assigning: [tomas], pre-realm rewritten: [tomas], realm name: [CachedLdapRealm], post-realm rewritten: [tomas], realm rewritten: [tomas]
2022-02-28 08:54:26,840 DEBUG [org.wildfly.security] (default task-1) Obtaining lock for identity [tomas]...
2022-02-28 08:54:26,841 DEBUG [org.wildfly.security] (default task-1) Obtained lock for identity [tomas].
2022-02-28 08:54:26,845 DEBUG [org.wildfly.security] (default task-1) Creating [class javax.naming.directory.InitialDirContext] with environment:
2022-02-28 08:54:26,845 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.credentials] with value [******]
2022-02-28 08:54:26,845 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.authentication] with value [simple]
2022-02-28 08:54:26,845 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.provider.url] with value [ldap://my.ad:389]
2022-02-28 08:54:26,846 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.read.timeout] with value [60000]
2022-02-28 08:54:26,846 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.connect.pool] with value [false]
2022-02-28 08:54:26,846 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.connect.timeout] with value [5000]
2022-02-28 08:54:26,846 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.principal] with value [CN=ad_reader, OU=service accounts, OU=Users, OU=myCity, DC=myCompany, DC=se]
2022-02-28 08:54:26,846 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.referral] with value [ignore]
2022-02-28 08:54:26,846 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.factory.initial] with value [com.sun.jndi.ldap.LdapCtxFactory]
2022-02-28 08:54:26,950 DEBUG [org.wildfly.security] (default task-1) [javax.naming.ldap.InitialLdapContext@1c68a31a] successfully created. Connection established to LDAP server.
2022-02-28 08:54:26,951 DEBUG [org.wildfly.security] (default task-1) Trying to create identity for principal [tomas].
2022-02-28 08:54:26,952 DEBUG [org.wildfly.security] (default task-1) Executing search [(sAMAccountName={0})] in context [OU=service accounts, OU=Users, OU=myCity, DC=myCompany, DC=se] with arguments [tomas]. Returning attributes are [null]. Binary attributes are [null].
2022-02-28 08:54:27,005 DEBUG [org.wildfly.security] (default task-1) Found entry [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,005 DEBUG [org.wildfly.security] (default task-1) Identity for principal [tomas] found at [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,005 DEBUG [org.wildfly.security] (default task-1) Context [javax.naming.ldap.InitialLdapContext@1c68a31a] was closed. Connection closed or just returned to the pool.
2022-02-28 08:54:27,008 TRACE [org.wildfly.security] (default task-1) Created wrapper RealmIdentity for 'tomas' and placing in cache.
2022-02-28 08:54:27,009 TRACE [org.wildfly.security] (default task-1) verifyEvidence Falling back to direct support of identity for principal='tomas'
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1) Creating [class javax.naming.directory.InitialDirContext] with environment:
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.credentials] with value [******]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.authentication] with value [simple]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.provider.url] with value [ldap://my.ad:389]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.read.timeout] with value [60000]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.connect.pool] with value [false]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.connect.timeout] with value [5000]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.principal] with value [CN=ad_reader, OU=service accounts, OU=Users, OU=myCity, DC=myCompany, DC=se]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.referral] with value [ignore]
2022-02-28 08:54:27,010 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.factory.initial] with value [com.sun.jndi.ldap.LdapCtxFactory]
2022-02-28 08:54:27,110 DEBUG [org.wildfly.security] (default task-1) [javax.naming.ldap.InitialLdapContext@15c16aa4] successfully created. Connection established to LDAP server.
2022-02-28 08:54:27,110 DEBUG [org.wildfly.security] (default task-1) Trying to create identity for principal [tomas].
2022-02-28 08:54:27,110 DEBUG [org.wildfly.security] (default task-1) Executing search [(sAMAccountName={0})] in context [OU=service accounts, OU=Users, OU=myCity, DC=myCompany, DC=se] with arguments [tomas]. Returning attributes are []. Binary attributes are [].
2022-02-28 08:54:27,159 DEBUG [org.wildfly.security] (default task-1) Found entry [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,160 DEBUG [org.wildfly.security] (default task-1) Identity for principal [tomas] found at [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,255 DEBUG [org.wildfly.security] (default task-1) Context [javax.naming.ldap.InitialLdapContext@15c16aa4] was closed. Connection closed or just returned to the pool.
2022-02-28 08:54:27,257 TRACE [org.wildfly.security] (default task-1) getAuthorizationIdentity Caching AuthorizationIdentity for principal='tomas'
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1) Creating [class javax.naming.directory.InitialDirContext] with environment:
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.credentials] with value [******]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.authentication] with value [simple]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.provider.url] with value [ldap://my.ad:389]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.read.timeout] with value [60000]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.connect.pool] with value [false]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [com.sun.jndi.ldap.connect.timeout] with value [5000]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.security.principal] with value [CN=ad_reader, OU=service accounts, OU=Users, OU=myCity, DC=myCompany, DC=se]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.referral] with value [ignore]
2022-02-28 08:54:27,257 DEBUG [org.wildfly.security] (default task-1)     Property [java.naming.factory.initial] with value [com.sun.jndi.ldap.LdapCtxFactory]
2022-02-28 08:54:27,356 DEBUG [org.wildfly.security] (default task-1) [javax.naming.ldap.InitialLdapContext@7c5e3765] successfully created. Connection established to LDAP server.
2022-02-28 08:54:27,357 DEBUG [org.wildfly.security] (default task-1) Trying to create identity for principal [tomas].
2022-02-28 08:54:27,357 DEBUG [org.wildfly.security] (default task-1) Executing search [(sAMAccountName={0})] in context [OU=service accounts, OU=Users, OU=myCity, DC=myCompany, DC=se] with arguments [tomas]. Returning attributes are []. Binary attributes are [null].
2022-02-28 08:54:27,404 DEBUG [org.wildfly.security] (default task-1) Found entry [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,404 DEBUG [org.wildfly.security] (default task-1) Identity for principal [tomas] found at [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,406 DEBUG [org.wildfly.security] (default task-1) Executing search [(sAMAccountName={0})] in context [OU=myCity,DC=myCompany,DC=se] with arguments [tomas, CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se]. Returning attributes are [null, MEMBEROF, CN]. Binary attributes are [null].
2022-02-28 08:54:27,456 DEBUG [org.wildfly.security] (default task-1) Found entry [CN=tomas lastname,OU=Service accounts,OU=Users,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,457 TRACE [org.wildfly.security] (default task-1) Identity iterating - pagination not supported - end of list
2022-02-28 08:54:27,457 DEBUG [org.wildfly.security] (default task-1) Obtaining authorization identity attributes for principal [tomas]:
2022-02-28 08:54:27,457 DEBUG [org.wildfly.security] (default task-1) Identity [tomas] attributes are:
2022-02-28 08:54:27,458 DEBUG [org.wildfly.security] (default task-1)     Attribute [Roles] value [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,458 DEBUG [org.wildfly.security] (default task-1)     Attribute [Roles] value [CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,458 DEBUG [org.wildfly.security] (default task-1)     Attribute [Roles] value [CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se].
2022-02-28 08:54:27,458 DEBUG [org.wildfly.security] (default task-1) Context [javax.naming.ldap.InitialLdapContext@7c5e3765] was closed. Connection closed or just returned to the pool.
2022-02-28 08:54:27,459 TRACE [org.wildfly.security] (default task-1) Role mapping: principal [tomas] -> decoded roles [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se] -> domain decoded roles [] -> realm mapped roles [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se] -> domain mapped roles [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se]
2022-02-28 08:54:27,459 TRACE [org.wildfly.security] (default task-1) Authorizing principal tomas.
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Authorizing against the following attributes: [Roles] => [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se]
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Authorizing against the following runtime attributes: [Source-Address] => [127.0.0.1]
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Permission mapping: identity [tomas] with roles [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se] implies ("org.wildfly.security.auth.permission.LoginPermission" "") = true
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Authorization succeed
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) RunAs authorization succeed - the same identity
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Handling AuthorizeCallback: authenticationID = tomas  authorizationID = tomas  authorized = true
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Handling AuthenticationCompleteCallback: succeed
2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Handling SecurityIdentityCallback: identity = SecurityIdentity{principal=tomas, securityDomain=org.wildfly.security.auth.server.SecurityDomain@1fc73f50, authorizationIdentity=EMPTY, realmInfo=RealmInfo{name='CachedLdapRealm', securityRealm=org.wildfly.security.auth.realm.CachingModifiableSecurityRealm@3d64eadb}, creationTime=2022-02-28T07:54:27.459155Z}
2022-02-28 08:54:27,460 TRACE [org.jboss.remoting.remote.server] (default task-1) Server sending authentication complete
...
2022-02-28 08:54:27,655 TRACE [org.wildfly.security] (default task-1) Role mapping: principal [anonymous] -> decoded roles [] -> domain decoded roles [] -> realm mapped roles [] -> domain mapped roles []
2022-02-28 08:54:27,656 ERROR [org.jboss.as.ejb3.invocation] (default task-1) WFLYEJB0034: Jakarta Enterprise Beans Invocation failed on component SecuredEJB for method public abstract java.lang.String org.jboss.as.quickstarts.ejb_security.SecuredEJBRemote.getSecurityInfo(): javax.ejb.EJBAccessException: WFLYEJB0364: Invocation on method: public abstract java.lang.String org.jboss.as.quickstarts.ejb_security.SecuredEJBRemote.getSecurityInfo() of bean: SecuredEJB is not allowed
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.security.RolesAllowedInterceptor.processInvocation(RolesAllowedInterceptor.java:67)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.security.SecurityDomainInterceptor.processInvocation(SecurityDomainInterceptor.java:44)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jbo...@26.0.1.Final//org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
        at org.wildfly.secu...@1.18.3.Final//org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:633)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss....@1.7.0.Final//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
        at org.jbo...@26.0.1.Final//org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
        at org.wildfly.secu...@1.18.3.Final//org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:421)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:674)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:655)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:251)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.remote.AssociationImpl.execute(AssociationImpl.java:344)
        at org.jbos...@26.0.1.Final//org.jboss.as.ejb3.remote.AssociationImpl.receiveInvocationRequest(AssociationImpl.java:297)
        at org.jboss....@4.0.44.Final//org.jboss.ejb.protocol.remote.EJBServerChannel$ReceiverImpl.handleInvocationRequest(EJBServerChannel.java:473)
        at org.jboss....@4.0.44.Final//org.jboss.ejb.protocol.remote.EJBServerChannel$ReceiverImpl.handleMessage(EJBServerChannel.java:208)
        at org.jboss...@5.0.23.Final//org.jboss.remoting3.remote.RemoteConnectionChannel.lambda$handleMessageData$3(RemoteConnectionChannel.java:432)
        at org.jboss...@5.0.23.Final//org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:991)
        at org.jbos...@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
        at org.jbos...@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
        at org.jbos...@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
        at org.jbos...@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
        at org.jbo...@3.8.5.Final//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280)
        at java.base/java.lang.Thread.run(Thread.java:834)

Here is the modified client code:

And the secured ejb where all roles are allowed:

Would really appreciate any help!

Best regards,

Tomas

[Tomas Andersson]

Changes in standalone.xml:

[Tomas Andersson]

Nevermind, seems to be working when applying it to my project code in stead. 

My problem now is how to get the user roles from within the accessed ejb. I can get the context and get the logged in users username with ctx.getCallerPrincipal(), but haven´t figured out how to get the roles found in the earlier ldap search, eg Role1, Role2, Role3:

2022-02-28 08:54:27,460 TRACE [org.wildfly.security] (default task-1) Permission mapping: identity [tomas] with roles [CN=Role1,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role2,OU=Security Groups,OU=myCity,DC=myCompany,DC=se, CN=Role3,OU=Security Groups,OU=myCity,DC=myCompany,DC=se] implies ("org.wildfly.security.auth.permission.LoginPermission" "") = true

The user is supposed to prompted with a dropdown to decide what role he/she wants to log in as.

[Tomas Andersson]

Ok, so nevermind again :-) After debugging and looking around the elytron code base I realised I could just do:

SecurityDomain.getCurrent().getCurrentSecurityIdentity().getRoles();