Remote Client - Error when switching from 7.1.0 to 7.1.1.
rathm1 May 24, 2012 6:04 PMHello all,
We are having some trouble switching our remote client from 7.1.0 to 7.1.1 and we need to do this because of some performance testing issues that appear to be resolved in 7.1.1.
If we use the code below and first call the findUnique and then the update methods, the update method fails with the error:
ERROR [ServerError] javax.ejb.EJBAccessException: JBAS013323: Invalid User on the client side.
Using the 7.1.0 jboss-client-7.1.0.Final.jar, the error did not occur.
On the server side, enabling TRACE for org.jboss.security we see this for the update method being called:
15:47:45,916 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (EJB default - 6) Begin isValid, principal:5be9354e-b783-4073-a1f3-4c70d1cdbdee, cache entry: null
15:47:45,919 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (EJB default - 6) defaultLogin, principal=5be9354e-b783-4073-a1f3-4c70d1cdbdee
15:47:45,921 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (EJB default - 6) Begin getAppConfigurationEntry(my_logon), size=4
15:47:45,922 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (EJB default - 6) End getAppConfigurationEntry(my_logon), authInfo=AppConfigurationEntry[]:
[0]
LoginModule Class: org.jboss.security.auth.spi.LdapLoginModule
ControlFlag: LoginModuleControlFlag: optional
Options:
{omitted for security reasons}
[1]
LoginModule Class: org.jboss.security.auth.spi.LdapLoginModule
ControlFlag: LoginModuleControlFlag: optional
Options:
{omitted for security reasons}
15:47:45,936 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) initialize
15:47:45,937 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Security domain: my_logon
15:47:45,937 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Saw unauthenticatedIdentity=anonymous
15:47:45,939 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) login
15:47:45,940 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Logging into LDAP server, env={java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, unauthenticatedIdentity=anonymous, principalDNPrefix=uid=, java.naming.security.principal=uid=5be9354e-b783-4073-a1f3-4c70d1cdbdee{omitted for security reasons}}
15:47:45,948 DEBUG [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Bad password for username=5be9354e-b783-4073-a1f3-4c70d1cdbdee
15:47:45,949 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) initialize
15:47:45,950 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Security domain: my_logon
15:47:45,951 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Saw unauthenticatedIdentity=anonymous
15:47:45,952 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) login
15:47:45,953 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Logging into LDAP server, env={java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, unauthenticatedIdentity=anonymous, principalDNPrefix=uid=, java.naming.security.principal=uid=5be9354e-b783-4073-a1f3-4c70d1cdbdee {omitted for security reasons}}
15:47:45,961 DEBUG [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) Bad password for username=5be9354e-b783-4073-a1f3-4c70d1cdbdee
15:47:45,963 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) abort
15:47:45,963 TRACE [org.jboss.security.auth.spi.LdapLoginModule] (EJB default - 6) abort
15:47:45,964 ERROR [org.jboss.security.authentication.JBossCachedAuthenticationManager] (EJB default - 6) Login failure: javax.security.auth.login.FailedLoginException: Password Incorrect/Password Required
at org.jboss.security.auth.spi.UsernamePasswordLoginModule.login(UsernamePasswordLoginModule.java:270) [picketbox-4.0.7.Final.jar:4.0.7.Final]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_26]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_26]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_26]
at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_26]
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769) [rt.jar:1.6.0_26]
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186) [rt.jar:1.6.0_26]
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683) [rt.jar:1.6.0_26]
at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.6.0_26]
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680) [rt.jar:1.6.0_26]
at javax.security.auth.login.LoginContext.login(LoginContext.java:579) [rt.jar:1.6.0_26]
at org.jboss.security.authentication.JBossCachedAuthenticationManager.defaultLogin(JBossCachedAuthenticationManager.java:449) [picketbox-infinispan-4.0.7.Final.jar:4.0.7.Final]
at org.jboss.security.authentication.JBossCachedAuthenticationManager.proceedWithJaasLogin(JBossCachedAuthenticationManager.java:383) [picketbox-infinispan-4.0.7.Final.jar:4.0.7.Final]
at org.jboss.security.authentication.JBossCachedAuthenticationManager.authenticate(JBossCachedAuthenticationManager.java:371) [picketbox-infinispan-4.0.7.Final.jar:4.0.7.Final]
at org.jboss.security.authentication.JBossCachedAuthenticationManager.isValid(JBossCachedAuthenticationManager.java:160) [picketbox-infinispan-4.0.7.Final.jar:4.0.7.Final]
at org.jboss.as.security.service.SimpleSecurityManager.authenticate(SimpleSecurityManager.java:306) [jboss-as-security-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.security.service.SimpleSecurityManager.push(SimpleSecurityManager.java:272) [jboss-as-security-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:49) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:45) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.6.0_26]
at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:74) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
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.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:43) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:302) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$200(MethodInvocationMessageHandler.java:64) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:196) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [rt.jar:1.6.0_26]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_26]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_26]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_26]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_26]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_26]
at org.jboss.threads.JBossThread.run(JBossThread.java:122)
15:47:46,005 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (EJB default - 6) End isValid, false
15:47:46,008 ERROR [org.jboss.ejb3.invocation] (EJB default - 6) JBAS014134: EJB Invocation failed on component RemoteServiceBean for method public abstract com.dto.MyObjectDto com.service.RemoteService.update(com.dto.MyObjectDto): javax.ejb.EJBAccessException: JBAS013323: Invalid User
at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:54) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.security.SecurityContextInterceptor$1.run(SecurityContextInterceptor.java:45) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.6.0_26]
at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:74) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
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.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:43) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
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.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:302) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$200(MethodInvocationMessageHandler.java:64) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:196) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [rt.jar:1.6.0_26]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_26]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_26]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_26]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_26]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_26]
at org.jboss.threads.JBossThread.run(JBossThread.java:122)
Previously in the logs we could see the proper username going to the ldap for authorization/authentication.
The set up is as follows:
jboss-ejb-client.properties:
remote.connections=default
endpoint.name=client-endpoint
remote.connection.default.port=4447
remote.connection.default.host=localhost
remote.connectionprovider.create.options.org.xnio.Options.SSL_ENABLED=false
remote.connection.default.connect.options.org.xnio.Options.SASL_POLICY_NOANONYMOUS=false
Client.java
public class Client {
private static Properties props = new Properties();
private static Context context;
private RemoteService home;
public Client() {
}
private RemoteService createService() {
try {
if (home == null) {
String jndiHomeName = "ejb:MyEar/MyApp//com.service.RemoteServiceBean!com.service.RemoteService";
Context context = getInitialContext();
home = context.lookup(jndiHomeName);
}
return ((RemoteService)home);
} catch (Exception ex) {
ex.printStackTrace();
}
}
private Context getInitialContext() throws NamingException {
if(context == null ) {
props.put(Context.URL_PKG_PREFIXES, "org.jboss.ejb.client.naming");
props.put(Context.INITIAL_CONTEXT_FACTORY, org.jboss.naming.remote.client.InitialContextFactory.class.getName());
props.put("jboss.naming.client.ejb.context", true);
props.put("jboss.naming.client.connect.options.org.xnio.Options.SASL_POLICY_NOPLAINTEXT", "false");
props.put(Context.SECURITY_PRINCIPAL, "username");
props.put(Context.SECURITY_CREDENTIALS, "password");
context = new InitialContext(props);
}
return context;
}
public MyObjectDto update(MyObjectDto myObjectDto) {
try {
return createService().update(myObjectDto);
}
catch (EJBException ex) {
ex.printStackTrace();
}
}
public MyObjectDto findUnique() {
MyObjectDto myObjectDto = null;
try {
myObjectDto = createService().findUnique();
}
catch (EJBException ex) {
ex.printStackTrace();
}
return myObjectDto ;
}
}
So to summarize, the 2nd remote method invocation (update in this case) on the same proxy interface fails with an authentication error.
If we again try to call the 1st, it once again works fine (findUnique in this case).
This issue seems to have been introduced in 7.1.1 since going back to the 7.1.0 jar, the error is gone but the performance issues appear again.
If anyone has any suggestions to help that would be greatly appreciated, this issue is critical to our application's success.
Thanks.