Remote connection failed (SaslException), but the server side seems OK

[renz13]

Hello,

I'm having problem using remote EJB authentication based on Database (I'm using AS 7.1.2 Final).

On the client, a exception is thrown whereas everything seems OK on the server side.

Here is my client log :

11 oct. 2012 12:01:05 org.jboss.ejb.client.EJBClient <clinit>

INFO: JBoss EJB Client version 1.0.10.Final

11 oct. 2012 12:01:05 org.xnio.Xnio <clinit>

INFO: XNIO Version 3.0.3.GA

11 oct. 2012 12:01:05 org.xnio.nio.NioXnio <clinit>

INFO: XNIO NIO Implementation Version 3.0.3.GA

11 oct. 2012 12:01:05 org.jboss.remoting3.EndpointImpl <clinit>

INFO: JBoss Remoting version 3.2.7.GA

11 oct. 2012 12:01:05 org.jboss.remoting3.remote.RemoteConnection handleException

ERROR: JBREM000200: Remote connection failed: javax.security.sasl.SaslException: Authentication failed: all available authentication mechanisms failed

11 oct. 2012 12:01:05 org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector setupEJBReceivers

WARN: Could not register a EJB receiver for connection to 127.0.0.1:4447

java.lang.RuntimeException: javax.security.sasl.SaslException: Authentication failed: all available authentication mechanisms failed

    at org.jboss.ejb.client.remoting.IoFutureHelper.get(IoFutureHelper.java:91)

    at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector.setupEJBReceivers(ConfigBasedEJBClientContextSelector.java:119)

    at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector.<init>(ConfigBasedEJBClientContextSelector.java:76)

    at org.jboss.ejb.client.EJBClientContext.<clinit>(EJBClientContext.java:77)

    at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:120)

    at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:104)

    at $Proxy0.sayHello(Unknown Source)

    at com.areasante.helloworld.client.TestAvecProperties.main(TestAvecProperties.java:21)

Caused by: javax.security.sasl.SaslException: Authentication failed: all available authentication mechanisms failed

    at org.jboss.remoting3.remote.ClientConnectionOpenListener$Capabilities.handleEvent(ClientConnectionOpenListener.java:315)

    at org.jboss.remoting3.remote.ClientConnectionOpenListener$Capabilities.handleEvent(ClientConnectionOpenListener.java:214)

    at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:72)

    at org.xnio.channels.TranslatingSuspendableChannel.handleReadable(TranslatingSuspendableChannel.java:189)

    at org.xnio.channels.TranslatingSuspendableChannel$1.handleEvent(TranslatingSuspendableChannel.java:103)

    at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:72)

    at org.xnio.nio.NioHandle.run(NioHandle.java:90)

    at org.xnio.nio.WorkerThread.run(WorkerThread.java:184)

    at ...asynchronous invocation...(Unknown Source)

    at org.jboss.remoting3.EndpointImpl.doConnect(EndpointImpl.java:270)

    at org.jboss.remoting3.EndpointImpl.connect(EndpointImpl.java:386)

    at org.jboss.ejb.client.remoting.NetworkUtil.connect(NetworkUtil.java:151)

    at org.jboss.ejb.client.remoting.NetworkUtil.connect(NetworkUtil.java:132)

    at org.jboss.ejb.client.remoting.ConfigBasedEJBClientContextSelector.setupEJBReceivers(ConfigBasedEJBClientContextSelector.java:117)

    ... 6 more

11 oct. 2012 12:01:05 org.jboss.remoting3.remote.RemoteConnection handleException

ERROR: JBREM000200: Remote connection failed: javax.security.sasl.SaslException: Authentication failed: all available authentication mechanisms failed

java.lang.IllegalStateException: EJBCLIENT000025: No EJB receiver available for handling [appName:Helloworld, moduleName:HelloworldEJB, distinctName:] combination for invocation context org.jboss.ejb.client.EJBClientInvocationContext@3ecfff

    at org.jboss.ejb.client.EJBClientContext.requireEJBReceiver(EJBClientContext.java:588)

    at org.jboss.ejb.client.ReceiverInterceptor.handleInvocation(ReceiverInterceptor.java:116)

    at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:181)

    at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:136)

    at org.jboss.ejb.client.EJBInvocationHandler.doInvoke(EJBInvocationHandler.java:121)

    at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:104)

    at $Proxy0.sayHello(Unknown Source)

    at com.areasante.helloworld.client.TestAvecProperties.main(TestAvecProperties.java:21)

The server side log :

11:59:43,203 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 2) JBAS018559: Deployed "Helloworld.ear"

12:01:05,515 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-1) Begin isValid, principal:992600056, cache entry: null

12:01:05,515 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-1) defaultLogin, principal=992600056

12:01:05,515 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (Remoting "renz-precision" task-1) Begin getAppConfigurationEntry(HelloDomain), size=4

12:01:05,515 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] (Remoting "renz-precision" task-1) End getAppConfigurationEntry(HelloDomain), authInfo=AppConfigurationEntry[]:

[0]

LoginModule Class: org.jboss.as.security.remoting.RemotingLoginModule

ControlFlag: LoginModuleControlFlag : optional

Options:

name=password-stacking, value=useFirstPass

[1]

LoginModule Class: org.jboss.security.auth.spi.DatabaseServerLoginModule

ControlFlag: LoginModuleControlFlag : required

Options:

name=principalsQuery, value=SELECT mdp_plain FROM utilisateur WHERE id_fact=?

name=dsJndiName, value=java:jboss/datasources/AnnuaireDS

name=password-stacking, value=useFirstPass

name=rolesQuery, value=SELECT r.roles, 'Roles' FROM role r INNER JOIN utilisateur u USING (cle_utilisateur) WHERE u.id_fact=?

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) initialize

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) Security domain: HelloDomain

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) DatabaseServerLoginModule, dsJndiName=java:jboss/datasources/AnnuaireDS

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) principalsQuery=SELECT mdp_plain FROM utilisateur WHERE id_fact=?

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) rolesQuery=SELECT r.roles, 'Roles' FROM role r INNER JOIN utilisateur u USING (cle_utilisateur) WHERE u.id_fact=?

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) suspendResume=true

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) login

12:01:05,531 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) suspendAnyTransaction

12:01:05,609 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) Excuting query: SELECT mdp_plain FROM utilisateur WHERE id_fact=?, with username: 992600056

12:01:05,625 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) Obtained user password

12:01:05,625 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) resumeAnyTransaction

12:01:05,640 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) User '992600056' authenticated, loginOk=true

12:01:05,640 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) commit, loginOk=true

12:01:05,640 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) getRoleSets using rolesQuery: SELECT r.roles, 'Roles' FROM role r INNER JOIN utilisateur u USING (cle_utilisateur) WHERE u.id_fact=?, username: 992600056

12:01:05,671 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) suspendAnyTransaction

12:01:05,671 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) Excuting query: SELECT r.roles, 'Roles' FROM role r INNER JOIN utilisateur u USING (cle_utilisateur) WHERE u.id_fact=?, with username: 992600056

12:01:05,671 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) Assign user to role hello

12:01:05,671 TRACE [org.jboss.security.auth.spi.DatabaseServerLoginModule] (Remoting "renz-precision" task-1) resumeAnyTransaction

12:01:05,671 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-1) defaultLogin, lc=javax.security.auth.login.LoginContext@1fd8905, subject=Subject(18583153).principals=org.jboss.security.SimplePrincipal@2399823(992600056)org.jboss.security.SimpleGroup@1398703(CallerPrincipal(members:992600056))org.jboss.security.SimpleGroup@1398703(Roles(members:hello))

12:01:05,671 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-1) updateCache, inputSubject=Subject(18583153).principals=org.jboss.security.SimplePrincipal@2399823(992600056)org.jboss.security.SimpleGroup@1398703(CallerPrincipal(members:992600056))org.jboss.security.SimpleGroup@1398703(Roles(members:hello)), cacheSubject=Subject(1701135).principals=org.jboss.security.SimplePrincipal@2399823(992600056)org.jboss.security.SimpleGroup@1398703(CallerPrincipal(members:992600056))org.jboss.security.SimpleGroup@1398703(Roles(members:hello))

12:01:05,671 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-1) Inserted cache info: org.jboss.security.authentication.JBossCachedAuthenticationManager$DomainInfo@27b40b

12:01:05,671 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-1) End isValid, true

12:01:05,687 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-2) Begin isValid, principal:992600056, cache entry: org.jboss.security.authentication.JBossCachedAuthenticationManager$DomainInfo@27b40b

12:01:05,687 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-2) Begin validateCache, info=org.jboss.security.authentication.JBossCachedAuthenticationManager$DomainInfo@27b40b;credential.class=java.lang.String@33040770

12:01:05,687 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-2) End validateCache, isValid=true

12:01:05,687 TRACE [org.jboss.security.authentication.JBossCachedAuthenticationManager] (Remoting "renz-precision" task-2) End isValid, true

I should have missed something, but what?

Thanks for you help

[dlofthouse]

Would it be possible for you to try 7.1.3, I don't have the exact versions to hand but we did have an issue of JAAS silently failing that I know is resolved in the latest.

[renz13]

7.1.3 is the answer!

Thank you very much.