GSSAPI + EJB failing on JDK9. ----------------------------- Key: WFLY-9899 URL: https://issues.jboss.org/browse/WFLY-9899 Project: WildFly Issue Type: Bug Components: EJB, Security Affects Versions: 12.0.0.Beta1 Reporter: Martin Choma Assignee: Farah Juma Priority: Blocker Fix For: 12.0.0.Final UseCase: EJB are secured with GSSAPI. When client access with valid kerberos ticket then authentication should succeed. But it is failing. Similar working configurations: * GSSAPI + EJB + JDK8 works * GS2-KRB5 + EJB + JDK9 works * GSSAPI + CLI + JDK9 works Compared to working configurations I don't see {{Server received authentication request}} in log, which make me think some problem on client is there. Test is using {{JBoss EJB Client version 4.0.9.Final}} {code:title=GSSAPI+EJB+JDK9} 09:25:21,504 INFO [KerberosEjbGssapiTestCase] (main) testSimpleKerberosRealmWithKerberos Debug is true storeKey false useTicketCache false useKeyTab false doNotPrompt false ticketCache is null isInitiator true KeyTab is null refreshKrb5Config is true principal is null tryFirstPass is false useFirstPass is false storePass is false clearPass is false Refreshing Kerberos configuration [Krb5LoginModule] user entered username: hnelson539055a4-9809-4a9a-9810-52153181a8cb(a)JBOSS.ORG principal is hnelson539055a4-9809-4a9a-9810-52153181a8cb(a)JBOSS.ORG Commit Succeeded 09:25:21,545 INFO [org.wildfly.naming] (main) WildFly Naming version 1.0.7.Final-redhat-1 09:25:21,633 INFO [org.jboss.ejb.client] (main) JBoss EJB Client version 4.0.9.Final 09:25:21,748 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Initialized connection from /127.0.0.1:49309 to /127.0.0.1:8080 with options {org.xnio.Options.TCP_NODELAY=>true,org.jboss.remoting3.RemotingOptions.SASL_PROTOCOL=>remote,org.xnio.Options.REUSE_ADDRESSES=>true} 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Accepted connection from /127.0.0.1:49309 to localhost/127.0.0.1:8080 09:25:21,749 TRACE [org.jboss.remoting.remote] (default I/O-14) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial@385af14 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Sent 16 bytes 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Flushed channel 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) No buffers in queue for message header 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Allocated fresh buffers 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Received 46 bytes 09:25:21,749 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Received message java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 09:25:21,749 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Received java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 09:25:21,749 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capabilities request 09:25:21,749 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: version 1 09:25:21,749 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: message close protocol supported 09:25:21,750 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: remote version is "5.0.5.Final-redhat-1" 09:25:21,750 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: remote channels in is "40" 09:25:21,750 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: remote channels out is "40" 09:25:21,750 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: authentication service 09:25:21,750 TRACE [org.jboss.remoting.remote.server] (default I/O-14) No EXTERNAL mechanism due to lack of SSL 09:25:21,753 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Added mechanism GSSAPI 09:25:21,753 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Added mechanism PLAIN 09:25:21,753 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Sent 72 bytes 09:25:21,753 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Flushed channel 09:25:21,789 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) No buffers in queue for message header 09:25:21,789 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Allocated fresh buffers 09:25:21,789 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Received 46 bytes 09:25:21,789 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Received message java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 09:25:21,789 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Received java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 09:25:21,789 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capabilities request 09:25:21,789 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: version 1 09:25:21,789 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: message close protocol supported 09:25:21,790 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: remote version is "5.0.5.Final-redhat-1" 09:25:21,790 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: remote channels in is "40" 09:25:21,790 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: remote channels out is "40" 09:25:21,790 TRACE [org.jboss.remoting.remote.server] (default I/O-14) Server received capability: authentication service 09:25:21,790 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Sent 72 bytes 09:25:21,790 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Flushed channel 09:25:21,794 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) No buffers in queue for message header 09:25:21,795 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Allocated fresh buffers 09:25:21,795 TRACE [org.jboss.remoting.remote.connection] (default I/O-14) Received EOF 09:25:21,795 TRACE [org.jboss.remoting.remote] (default I/O-14) Received connection end-of-stream 09:25:21,813 ERROR [KerberosEjbGssapiTestCase] (main) Access to EJB method was denied for invocation with Kerberos user.: java.security.PrivilegedActionException: org.jboss.ejb.client.RequestSendFailedException: EJBCLIENT000409: No more destinations are available at org.wildfly.common.context.Contextual.runExceptionAction(Contextual.java:110) at org.wildfly.security.auth.client.AuthenticationContext.run(AuthenticationContext.java:270) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase.testAuthenticationWithKerberos(AbstractKerberosEjbTestCase.java:756) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase.testAuthenticationWithKerberos(AbstractKerberosEjbTestCase.java:701) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase.testSimpleKerberosRealmWithKerberos(AbstractKerberosEjbTestCase.java:307) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.jboss.arquillian.junit.Arquillian$8$1.invoke(Arquillian.java:379) at org.jboss.arquillian.container.test.impl.execution.LocalTestExecuter.execute(LocalTestExecuter.java:60) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:85) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:143) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67) at org.jboss.arquillian.container.test.impl.execution.ClientTestExecuter.execute(ClientTestExecuter.java:53) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:85) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:142) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createTestContext(ContainerEventController.java:129) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:130) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:92) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:73) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:143) at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.test(EventTestRunnerAdaptor.java:136) at org.jboss.arquillian.junit.Arquillian$8.evaluate(Arquillian.java:372) at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:246) at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:431) at org.jboss.arquillian.junit.Arquillian.access$200(Arquillian.java:55) at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:260) at org.jboss.arquillian.junit.Arquillian$7$1.invoke(Arquillian.java:324) at org.jboss.arquillian.container.test.impl.execution.ClientBeforeAfterLifecycleEventExecuter.execute(ClientBeforeAfterLifecycleEventExecuter.java:99) at org.jboss.arquillian.container.test.impl.execution.ClientBeforeAfterLifecycleEventExecuter.on(ClientBeforeAfterLifecycleEventExecuter.java:72) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:85) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:142) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createBeforeContext(ContainerEventController.java:124) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:130) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:92) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:73) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:143) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.fireCustomLifecycle(EventTestRunnerAdaptor.java:159) at org.jboss.arquillian.junit.Arquillian$7.evaluate(Arquillian.java:317) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:205) at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:431) at org.jboss.arquillian.junit.Arquillian.access$200(Arquillian.java:55) at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:219) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:167) at org.jboss.eapqe.krbldap.arquillian.runner.LdapKrbRunner.run(LdapKrbRunner.java:50) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:254) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:149) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) Caused by: org.jboss.ejb.client.RequestSendFailedException: EJBCLIENT000409: No more destinations are available at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:567) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:503) at org.jboss.ejb.protocol.remote.RemotingEJBClientInterceptor.handleInvocationResult(RemotingEJBClientInterceptor.java:56) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:569) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:503) at org.jboss.ejb.client.TransactionPostDiscoveryInterceptor.handleInvocationResult(TransactionPostDiscoveryInterceptor.java:133) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:569) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:503) at org.jboss.ejb.client.DiscoveryEJBClientInterceptor.handleInvocationResult(DiscoveryEJBClientInterceptor.java:108) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:569) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:503) at org.jboss.ejb.client.NamingEJBClientInterceptor.handleInvocationResult(NamingEJBClientInterceptor.java:78) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:569) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:503) at org.jboss.ejb.client.TransactionInterceptor.handleInvocationResult(TransactionInterceptor.java:172) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:569) at org.jboss.ejb.client.EJBClientInvocationContext.getResult(EJBClientInvocationContext.java:503) at org.jboss.ejb.client.EJBClientInvocationContext.awaitResponse(EJBClientInvocationContext.java:913) at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:177) at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:112) at com.sun.proxy.$Proxy36.hello(Unknown Source) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase$2.run(AbstractKerberosEjbTestCase.java:760) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase$2.run(AbstractKerberosEjbTestCase.java:756) at org.wildfly.common.context.Contextual.runExceptionAction(Contextual.java:108) ... 131 more Suppressed: org.jboss.ejb.client.RequestSendFailedException at org.jboss.ejb.protocol.remote.RemoteEJBReceiver$1.handleFailed(RemoteEJBReceiver.java:101) at org.jboss.ejb.protocol.remote.RemoteEJBReceiver$1.handleFailed(RemoteEJBReceiver.java:74) at org.xnio.IoFuture$HandlingNotifier.notify(IoFuture.java:215) at org.xnio.AbstractIoFuture$NotifierRunnable.run(AbstractIoFuture.java:720) at org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:926) at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1348) at java.base/java.lang.Thread.run(Thread.java:844) Caused by: javax.security.sasl.SaslException: PLAIN: authorization ID and password must be specified at java.security.sasl/com.sun.security.sasl.PlainClient.<init>(PlainClient.java:58) at java.security.sasl/com.sun.security.sasl.ClientFactoryImpl.createSaslClient(ClientFactoryImpl.java:97) at org.wildfly.security.sasl.util.SecurityProviderSaslClientFactory.createSaslClient(SecurityProviderSaslClientFactory.java:111) at org.wildfly.security.sasl.util.AbstractDelegatingSaslClientFactory.createSaslClient(AbstractDelegatingSaslClientFactory.java:66) at org.wildfly.security.sasl.util.ProtocolSaslClientFactory.createSaslClient(ProtocolSaslClientFactory.java:50) at org.wildfly.security.sasl.util.AbstractDelegatingSaslClientFactory.createSaslClient(AbstractDelegatingSaslClientFactory.java:66) at org.wildfly.security.sasl.util.ServerNameSaslClientFactory.createSaslClient(ServerNameSaslClientFactory.java:50) at org.wildfly.security.sasl.util.AbstractDelegatingSaslClientFactory.createSaslClient(AbstractDelegatingSaslClientFactory.java:66) at org.wildfly.security.sasl.util.PropertiesSaslClientFactory.createSaslClient(PropertiesSaslClientFactory.java:54) at org.wildfly.security.sasl.util.AbstractDelegatingSaslClientFactory.createSaslClient(AbstractDelegatingSaslClientFactory.java:66) at org.wildfly.security.sasl.util.ServerNameSaslClientFactory.createSaslClient(ServerNameSaslClientFactory.java:50) at org.wildfly.security.sasl.util.FilterMechanismSaslClientFactory.createSaslClient(FilterMechanismSaslClientFactory.java:102) at org.wildfly.security.sasl.util.AbstractDelegatingSaslClientFactory.createSaslClient(AbstractDelegatingSaslClientFactory.java:66) at org.wildfly.security.sasl.util.LocalPrincipalSaslClientFactory.createSaslClient(LocalPrincipalSaslClientFactory.java:76) at org.wildfly.security.sasl.util.PrivilegedSaslClientFactory.lambda$createSaslClient$0(PrivilegedSaslClientFactory.java:64) at java.base/java.security.AccessController.doPrivileged(Native Method) at org.wildfly.security.sasl.util.PrivilegedSaslClientFactory.createSaslClient(PrivilegedSaslClientFactory.java:64) at org.wildfly.security.auth.client.AuthenticationConfiguration.createSaslClient(AuthenticationConfiguration.java:1346) at org.wildfly.security.auth.client.AuthenticationContextConfigurationClient.createSaslClient(AuthenticationContextConfigurationClient.java:395) at org.jboss.remoting3.remote.ClientConnectionOpenListener$Capabilities.handleEvent(ClientConnectionOpenListener.java:420) at org.jboss.remoting3.remote.ClientConnectionOpenListener$Capabilities.handleEvent(ClientConnectionOpenListener.java:242) at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92) at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66) at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89) at org.xnio.nio.WorkerThread.run(WorkerThread.java:591) at ...asynchronous invocation...(Unknown Source) at org.jboss.remoting3.EndpointImpl.connect(EndpointImpl.java:570) at org.jboss.remoting3.EndpointImpl.connect(EndpointImpl.java:536) at org.jboss.remoting3.ConnectionInfo$None.getConnection(ConnectionInfo.java:82) at org.jboss.remoting3.ConnectionInfo.getConnection(ConnectionInfo.java:55) at org.jboss.remoting3.EndpointImpl.doGetConnection(EndpointImpl.java:487) at org.jboss.remoting3.EndpointImpl.getConnectedIdentity(EndpointImpl.java:433) at org.jboss.remoting3.UncloseableEndpoint.getConnectedIdentity(UncloseableEndpoint.java:51) at org.jboss.remoting3.Endpoint.getConnectedIdentity(Endpoint.java:122) at org.jboss.ejb.protocol.remote.RemoteEJBReceiver.lambda$getConnection$2(RemoteEJBReceiver.java:185) at java.base/java.security.AccessController.doPrivileged(Native Method) at org.jboss.ejb.protocol.remote.RemoteEJBReceiver.getConnection(RemoteEJBReceiver.java:185) at org.jboss.ejb.protocol.remote.RemoteEJBReceiver.processInvocation(RemoteEJBReceiver.java:128) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:454) at org.jboss.ejb.protocol.remote.RemotingEJBClientInterceptor.handleInvocation(RemotingEJBClientInterceptor.java:51) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466) at org.jboss.ejb.client.TransactionPostDiscoveryInterceptor.handleInvocation(TransactionPostDiscoveryInterceptor.java:79) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466) at org.jboss.ejb.client.DiscoveryEJBClientInterceptor.handleInvocation(DiscoveryEJBClientInterceptor.java:89) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466) at org.jboss.ejb.client.NamingEJBClientInterceptor.handleInvocation(NamingEJBClientInterceptor.java:66) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466) at org.jboss.ejb.client.TransactionInterceptor.handleInvocation(TransactionInterceptor.java:165) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequest(EJBClientInvocationContext.java:466) at org.wildfly.common.context.Contextual.runExConsumer(Contextual.java:203) at org.jboss.ejb.client.EJBClientInvocationContext.sendRequestInitial(EJBClientInvocationContext.java:302) at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:173) at org.jboss.ejb.client.EJBInvocationHandler.invoke(EJBInvocationHandler.java:112) at com.sun.proxy.$Proxy36.hello(Unknown Source) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase$2.run(AbstractKerberosEjbTestCase.java:760) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase$2.run(AbstractKerberosEjbTestCase.java:756) at org.wildfly.common.context.Contextual.runExceptionAction(Contextual.java:108) at org.wildfly.security.auth.client.AuthenticationContext.run(AuthenticationContext.java:270) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase.testAuthenticationWithKerberos(AbstractKerberosEjbTestCase.java:756) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase.testAuthenticationWithKerberos(AbstractKerberosEjbTestCase.java:701) at org.jboss.eapqe.krbldap.eap71.tests.krb.ejb.AbstractKerberosEjbTestCase.testSimpleKerberosRealmWithKerberos(AbstractKerberosEjbTestCase.java:307) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.jboss.arquillian.junit.Arquillian$8$1.invoke(Arquillian.java:379) at org.jboss.arquillian.container.test.impl.execution.LocalTestExecuter.execute(LocalTestExecuter.java:60) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:85) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:143) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67) at org.jboss.arquillian.container.test.impl.execution.ClientTestExecuter.execute(ClientTestExecuter.java:53) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:85) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:142) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createTestContext(ContainerEventController.java:129) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:130) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:92) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:73) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:143) at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.test(EventTestRunnerAdaptor.java:136) at org.jboss.arquillian.junit.Arquillian$8.evaluate(Arquillian.java:372) at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:246) at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:431) at org.jboss.arquillian.junit.Arquillian.access$200(Arquillian.java:55) at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:260) at org.jboss.arquillian.junit.Arquillian$7$1.invoke(Arquillian.java:324) at org.jboss.arquillian.container.test.impl.execution.ClientBeforeAfterLifecycleEventExecuter.execute(ClientBeforeAfterLifecycleEventExecuter.java:99) at org.jboss.arquillian.container.test.impl.execution.ClientBeforeAfterLifecycleEventExecuter.on(ClientBeforeAfterLifecycleEventExecuter.java:72) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:103) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:85) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:142) at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createBeforeContext(ContainerEventController.java:124) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:130) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:92) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:73) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:96) at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:92) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:143) at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:114) at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.fireCustomLifecycle(EventTestRunnerAdaptor.java:159) at org.jboss.arquillian.junit.Arquillian$7.evaluate(Arquillian.java:317) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:205) at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:431) at org.jboss.arquillian.junit.Arquillian.access$200(Arquillian.java:55) at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:219) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:167) at org.jboss.eapqe.krbldap.arquillian.runner.LdapKrbRunner.run(LdapKrbRunner.java:50) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:254) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:149) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [Krb5LoginModule]: Entering logout [Krb5LoginModule]: logged out Subject {code} Working configuration logs: {code:title=GSSAPI+EJB+JDK8} 10:08:00,009 INFO [KerberosEjbGssapiTestCase] (main) testSimpleKerberosRealmWithKerberos Debug is true storeKey false useTicketCache false useKeyTab false doNotPrompt false ticketCache is null isInitiator true KeyTab is null refreshKrb5Config is true principal is null tryFirstPass is false useFirstPass is false storePass is false clearPass is false Refreshing Kerberos configuration [Krb5LoginModule] user entered username: hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG principal is hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG Commit Succeeded 10:08:00,031 INFO [org.wildfly.naming] (main) WildFly Naming version 1.0.7.Final-redhat-1 10:08:00,084 INFO [org.jboss.ejb.client] (main) JBoss EJB Client version 4.0.9.Final 10:08:00,166 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Initialized connection from /127.0.0.1:57515 to /127.0.0.1:8080 with options {org.xnio.Options.TCP_NODELAY=>true,org.xnio.Options.REUSE_ADDRESSES=>true,org.jboss.remoting3.RemotingOptions.SASL_PROTOCOL=>remote} 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Accepted connection from /127.0.0.1:57515 to localhost/127.0.0.1:8080 10:08:00,167 TRACE [org.jboss.remoting.remote] (default I/O-12) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial@29e0c8bf 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Sent 16 bytes 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Flushed channel 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) No buffers in queue for message header 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Allocated fresh buffers 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Received 46 bytes 10:08:00,167 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Received message java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 10:08:00,167 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Received java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capabilities request 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capability: version 1 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capability: message close protocol supported 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capability: remote version is "5.0.5.Final-redhat-1" 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capability: remote channels in is "40" 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capability: remote channels out is "40" 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received capability: authentication service 10:08:00,168 TRACE [org.jboss.remoting.remote.server] (default I/O-12) No EXTERNAL mechanism due to lack of SSL 10:08:00,171 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Added mechanism GSSAPI 10:08:00,171 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Added mechanism PLAIN 10:08:00,171 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Sent 72 bytes 10:08:00,171 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Flushed channel 10:08:00,234 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) No buffers in queue for message header 10:08:00,234 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Allocated fresh buffers 10:08:00,234 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Received 577 bytes 10:08:00,234 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Received message java.nio.HeapByteBuffer[pos=0 lim=573 cap=8192] 10:08:00,234 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Received java.nio.HeapByteBuffer[pos=0 lim=573 cap=8192] 10:08:00,234 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received authentication request 10:08:00,234 TRACE [org.wildfly.security] (default I/O-12) Handling MechanismInformationCallback type='SASL' name='GSSAPI' host-name='localhost' protocol='remote' 10:08:00,234 TRACE [org.wildfly.security] (default I/O-12) Handling MechanismInformationCallback type='SASL' name='GSSAPI' host-name='localhost' protocol='remote' 10:08:00,236 TRACE [org.wildfly.security.sasl.gssapi] (default I/O-12) configuredMaxReceiveBuffer=16777215 10:08:00,236 TRACE [org.wildfly.security.sasl.gssapi] (default I/O-12) relaxComplianceChecks=false 10:08:00,236 TRACE [org.wildfly.security.sasl.gssapi] (default I/O-12) QOP={AUTH} 10:08:00,237 TRACE [org.wildfly.security.sasl.gssapi] (default I/O-12) Obtaining GSSCredential for the service from callback handler... 10:08:00,237 TRACE [org.wildfly.security] (default I/O-12) No valid cached credential, obtaining new one... 10:08:00,238 TRACE [org.wildfly.security] (default I/O-12) Logging in using LoginContext and subject [Subject: ] 10:08:00,241 INFO [stdout] (default I/O-12) Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator false KeyTab is /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.8005181333076164002.keytab refreshKrb5Config is false principal is remote/localhost(a)JBOSS.ORG tryFirstPass is false useFirstPass is false storePass is false clearPass is false 10:08:00,242 INFO [stdout] (default I/O-12) principal is remote/localhost(a)JBOSS.ORG 10:08:00,242 INFO [stdout] (default I/O-12) Will use keytab 10:08:00,243 INFO [stdout] (default I/O-12) Commit Succeeded 10:08:00,243 INFO [stdout] (default I/O-12) 10:08:00,243 TRACE [org.wildfly.security] (default I/O-12) Logging in using LoginContext and subject [Subject: Principal: remote/localhost(a)JBOSS.ORG Private Credential: /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.8005181333076164002.keytab for remote/localhost(a)JBOSS.ORG ] succeed 10:08:00,244 TRACE [org.wildfly.security] (default I/O-12) Creating GSSName for Principal &#39;remote/localhost(a)JBOSS.ORG&#39; 10:08:00,247 INFO [stdout] (default I/O-12) Found KeyTab /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.8005181333076164002.keytab for remote/localhost(a)JBOSS.ORG 10:08:00,248 INFO [stdout] (default I/O-12) Found KeyTab /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.8005181333076164002.keytab for remote/localhost(a)JBOSS.ORG 10:08:00,249 TRACE [org.wildfly.security] (default I/O-12) Obtained GSSCredentialCredential [org.wildfly.security.credential.GSSKerberosCredential@1f] 10:08:00,249 TRACE [org.wildfly.security] (default I/O-12) Handling ServerCredentialCallback: successfully obtained credential type type=class org.wildfly.security.credential.GSSKerberosCredential, algorithm=null, params=null 10:08:00,250 TRACE [org.wildfly.security] (default I/O-12) Creating SaslServer [org.wildfly.security.sasl.gssapi.GssapiServer@6b2bab2] for mechanism [GSSAPI] and protocol [remote] 10:08:00,250 TRACE [org.wildfly.security] (default I/O-12) Created SaslServer [org.wildfly.security.sasl.util.SecurityIdentitySaslServerFactory$1@6e8ea6c4-&gt;org.wildfly.security.sasl.util.AuthenticationTimeoutSaslServerFactory$DelegatingTimeoutSaslServer@211d1ee1-&gt;org.wildfly.security.sasl.util.AuthenticationCompleteCallbackSaslServerFactory$1@7482557f-&gt;org.wildfly.security.sasl.gssapi.GssapiServer(a)6b2bab2] for mechanism [GSSAPI] 10:08:00,250 TRACE [org.jboss.remoting.endpoint] (default I/O-12) Allocated tick to 8 of endpoint "localhost" <460b9f22> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor@7cd534db) 10:08:00,252 INFO [stdout] (default task-1) Entered Krb5Context.acceptSecContext with state=STATE_NEW 10:08:00,254 INFO [stdout] (default task-1) Java config name: /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb5-1930606025917449414.conf 10:08:00,255 INFO [stdout] (default task-1) Loaded from Java config 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 53; type: 3 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 69; type: 16 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 61; type: 23 10:08:00,257 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 77; type: 18 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 10:08:00,258 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 61; type: 17 10:08:00,258 INFO [stdout] (default task-1) Looking for keys for: remote/localhost(a)JBOSS.ORG 10:08:00,258 INFO [stdout] (default task-1) Added key: 17version: 0 10:08:00,259 INFO [stdout] (default task-1) Added key: 18version: 0 10:08:00,259 INFO [stdout] (default task-1) Added key: 23version: 0 10:08:00,259 INFO [stdout] (default task-1) Added key: 16version: 0 10:08:00,259 INFO [stdout] (default task-1) Found unsupported keytype (3) for remote/localhost(a)JBOSS.ORG 10:08:00,259 INFO [stdout] (default task-1) >>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType 10:08:00,294 INFO [stdout] (default task-1) default etypes for permitted_enctypes: 17. 10:08:00,294 INFO [stdout] (default task-1) >>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType 10:08:00,296 INFO [stdout] (default task-1) MemoryCache: add 1519376880/232584/6CD5D750C87B7182529F598C3B1B582C/hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG to hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618@JBOSS.ORG|remote/localhost(a)JBOSS.ORG 10:08:00,296 INFO [stdout] (default task-1) >>> KrbApReq: authenticate succeed. 10:08:00,297 INFO [stdout] (default task-1) Krb5Context setting peerSeqNumber to: 1033362602 10:08:00,297 INFO [stdout] (default task-1) Krb5Context setting mySeqNumber to: 1033362602 10:08:00,297 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) Negotiated mechanism 1.2.840.113554.1.2.2 10:08:00,297 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) No response so triggering next state immediately. 10:08:00,297 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) Not offering a security layer so zero length. 10:08:00,298 INFO [stdout] (default task-1) Krb5Context.wrap: data=[01 00 00 00 ] 10:08:00,298 INFO [stdout] (default task-1) Krb5Context.wrap: token=[05 04 01 ff 00 0c 00 00 00 00 00 00 3d 97 dc aa 01 00 00 00 d0 8e 9b 4d 59 58 b9 88 55 35 eb 56 ] 10:08:00,298 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) Transitioning to receive chosen security layer from client 10:08:00,298 TRACE [org.jboss.remoting.remote.server] (default task-1) Server sending authentication challenge 10:08:00,298 TRACE [org.jboss.remoting.remote] (default task-1) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Authentication@146ea2c7 10:08:00,299 TRACE [org.jboss.remoting.endpoint] (default task-1) Resource closed count 00000007 of endpoint "localhost" <460b9f22> (closed org.jboss.remoting3.EndpointImpl$TrackingExecutor@7cd534db) 10:08:00,299 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Sent 37 bytes 10:08:00,299 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Flushed channel 10:08:00,300 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) No buffers in queue for message header 10:08:00,300 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Allocated fresh buffers 10:08:00,300 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Received 37 bytes 10:08:00,300 TRACE [org.jboss.remoting.remote.connection] (default I/O-12) Received message java.nio.HeapByteBuffer[pos=0 lim=33 cap=8192] 10:08:00,300 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Received java.nio.HeapByteBuffer[pos=0 lim=33 cap=8192] 10:08:00,300 TRACE [org.jboss.remoting.remote.server] (default I/O-12) Server received authentication response 10:08:00,300 TRACE [org.jboss.remoting.endpoint] (default I/O-12) Allocated tick to 8 of endpoint "localhost" <460b9f22> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor@7cd534db) 10:08:00,301 INFO [stdout] (default task-1) Krb5Context.unwrap: token=[05 04 00 ff 00 0c 00 00 00 00 00 00 3d 97 dc aa 01 00 00 00 9a 59 ac 3d f2 ba 62 92 61 1a bd bf ] 10:08:00,301 INFO [stdout] (default task-1) Krb5Context.unwrap: data=[01 00 00 00 ] 10:08:00,301 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) Client selected security layer AUTH, with maxBuffer of 0 10:08:00,301 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) Authentication ID=hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG, Authorization ID=hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG 10:08:00,302 TRACE [org.wildfly.security] (default task-1) Principal assigning: [hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG], pre-realm rewritten: [hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618], realm name: [fileSystemRealm], post-realm rewritten: [hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618], realm rewritten: [hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618] 10:08:00,303 TRACE [org.wildfly.security] (default task-1) Role mapping: principal [hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618] -> decoded roles [Users] -> realm mapped roles [Users] -> domain mapped roles [Users] 10:08:00,303 TRACE [org.wildfly.security] (default task-1) Authorizing principal hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618. 10:08:00,303 TRACE [org.wildfly.security] (default task-1) Authorizing against the following attributes: [Roles] => [Users] 10:08:00,303 TRACE [org.wildfly.security] (default task-1) Permission mapping: identity [hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618] with roles [Users] implies ("org.wildfly.security.auth.permission.LoginPermission" "") = true 10:08:00,303 TRACE [org.wildfly.security] (default task-1) Authorization succeed 10:08:00,303 TRACE [org.wildfly.security] (default task-1) RunAs authorization succeed - the same identity 10:08:00,303 TRACE [org.wildfly.security] (default task-1) Handling AuthorizeCallback: authenticationID = hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG authorizationID = hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618(a)JBOSS.ORG authorized = true 10:08:00,304 INFO [stdout] (default task-1) >>> Constrained deleg from GSSCaller{UNKNOWN} 10:08:00,304 TRACE [org.wildfly.security.sasl.gssapi] (default task-1) Negotiation complete. 10:08:00,304 TRACE [org.wildfly.security] (default task-1) Handling AuthenticationCompleteCallback: succeed 10:08:00,304 TRACE [org.wildfly.security] (default task-1) Handling SecurityIdentityCallback: identity = SecurityIdentity{principal=hnelson1b0632f4-8d94-47ec-938a-988e3b9b2618, securityDomain=org.wildfly.security.auth.server.SecurityDomain@5a9e7026, authorizationIdentity=EMPTY, realmInfo=RealmInfo{name='fileSystemRealm', securityRealm=org.wildfly.security.auth.realm.FileSystemSecurityRealm@53f94811}, creationTime=2018-02-23T09:08:00.302Z} 10:08:00,305 TRACE [org.jboss.remoting.remote.server] (default task-1) Server sending authentication complete {code} {code:title=GS2-KRB5+EJB+JDK9} 09:29:32,446 INFO [KerberosEjbGs2Krb5TestCase] (main) testSimpleKerberosRealmWithKerberos Debug is true storeKey false useTicketCache false useKeyTab false doNotPrompt false ticketCache is null isInitiator true KeyTab is null refreshKrb5Config is true principal is null tryFirstPass is false useFirstPass is false storePass is false clearPass is false Refreshing Kerberos configuration [Krb5LoginModule] user entered username: hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG principal is hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG Commit Succeeded 09:29:32,471 INFO [org.wildfly.naming] (main) WildFly Naming version 1.0.7.Final-redhat-1 09:29:32,528 INFO [org.jboss.ejb.client] (main) JBoss EJB Client version 4.0.9.Final 09:29:32,604 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Initialized connection from /127.0.0.1:46357 to /127.0.0.1:8080 with options {org.jboss.remoting3.RemotingOptions.SASL_PROTOCOL=>remote,org.xnio.Options.TCP_NODELAY=>true,org.xnio.Options.REUSE_ADDRESSES=>true} 09:29:32,604 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Accepted connection from /127.0.0.1:46357 to localhost/127.0.0.1:8080 09:29:32,604 TRACE [org.jboss.remoting.remote] (default I/O-6) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial@1eb6a527 09:29:32,605 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Sent 16 bytes 09:29:32,605 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Flushed channel 09:29:32,605 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) No buffers in queue for message header 09:29:32,605 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Allocated fresh buffers 09:29:32,605 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Received 46 bytes 09:29:32,605 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Received message java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Received java.nio.HeapByteBuffer[pos=0 lim=42 cap=8192] 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capabilities request 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capability: version 1 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capability: message close protocol supported 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capability: remote version is "5.0.5.Final-redhat-1" 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capability: remote channels in is "40" 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capability: remote channels out is "40" 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received capability: authentication service 09:29:32,605 TRACE [org.jboss.remoting.remote.server] (default I/O-6) No EXTERNAL mechanism due to lack of SSL 09:29:32,608 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Added mechanism GS2-KRB5 09:29:32,608 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Added mechanism PLAIN 09:29:32,609 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Sent 74 bytes 09:29:32,609 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Flushed channel 09:29:32,680 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) No buffers in queue for message header 09:29:32,680 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Allocated fresh buffers 09:29:32,680 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Received 567 bytes 09:29:32,680 TRACE [org.jboss.remoting.remote.connection] (default I/O-6) Received message java.nio.HeapByteBuffer[pos=0 lim=563 cap=8192] 09:29:32,680 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Received java.nio.HeapByteBuffer[pos=0 lim=563 cap=8192] 09:29:32,680 TRACE [org.jboss.remoting.remote.server] (default I/O-6) Server received authentication request 09:29:32,681 TRACE [org.wildfly.security] (default I/O-6) Handling MechanismInformationCallback type='SASL' name='GS2-KRB5' host-name='localhost' protocol='remote' 09:29:32,681 TRACE [org.wildfly.security] (default I/O-6) Handling MechanismInformationCallback type='SASL' name='GS2-KRB5' host-name='localhost' protocol='remote' 09:29:32,682 TRACE [org.wildfly.security.sasl.gs2] (default I/O-6) Obtaining GSSCredential for the service from callback handler 09:29:32,682 TRACE [org.wildfly.security] (default I/O-6) No valid cached credential, obtaining new one... 09:29:32,683 TRACE [org.wildfly.security] (default I/O-6) Logging in using LoginContext and subject [Subject: ] 09:29:32,719 INFO [stdout] (default I/O-6) Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator false KeyTab is /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.12303747801898463853.keytab refreshKrb5Config is false principal is remote/localhost(a)JBOSS.ORG tryFirstPass is false useFirstPass is false storePass is false clearPass is false 09:29:32,725 INFO [stdout] (default I/O-6) principal is remote/localhost(a)JBOSS.ORG 09:29:32,725 INFO [stdout] (default I/O-6) Will use keytab 09:29:32,726 INFO [stdout] (default I/O-6) Commit Succeeded 09:29:32,726 INFO [stdout] (default I/O-6) 09:29:32,726 TRACE [org.wildfly.security] (default I/O-6) Logging in using LoginContext and subject [Subject: Principal: remote/localhost(a)JBOSS.ORG Private Credential: /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.12303747801898463853.keytab for remote/localhost(a)JBOSS.ORG ] succeed 09:29:32,730 TRACE [org.wildfly.security] (default I/O-6) Creating GSSName for Principal &#39;remote/localhost(a)JBOSS.ORG&#39; 09:29:32,750 INFO [stdout] (default I/O-6) Found KeyTab /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.12303747801898463853.keytab for remote/localhost(a)JBOSS.ORG 09:29:32,753 INFO [stdout] (default I/O-6) Found KeyTab /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.12303747801898463853.keytab for remote/localhost(a)JBOSS.ORG 09:29:32,753 TRACE [org.wildfly.security] (default I/O-6) Obtained GSSCredentialCredential [org.wildfly.security.credential.GSSKerberosCredential@1f] 09:29:32,754 TRACE [org.wildfly.security] (default I/O-6) Handling ServerCredentialCallback: successfully obtained credential type type=class org.wildfly.security.credential.GSSKerberosCredential, algorithm=null, params=null 09:29:32,757 TRACE [org.wildfly.security] (default I/O-6) Creating SaslServer [org.wildfly.security.sasl.gs2.Gs2SaslServer@3e9a20c] for mechanism [GS2-KRB5] and protocol [remote] 09:29:32,757 TRACE [org.wildfly.security] (default I/O-6) Created SaslServer [org.wildfly.security.sasl.util.SecurityIdentitySaslServerFactory$1@a3b3cd2-&gt;org.wildfly.security.sasl.util.AuthenticationTimeoutSaslServerFactory$DelegatingTimeoutSaslServer@6a35adf7-&gt;org.wildfly.security.sasl.util.AuthenticationCompleteCallbackSaslServerFactory$1@12fa9e2c-&gt;org.wildfly.security.sasl.gs2.Gs2SaslServer(a)3e9a20c] for mechanism [GS2-KRB5] 09:29:32,757 TRACE [org.jboss.remoting.endpoint] (default I/O-6) Allocated tick to 8 of endpoint "localhost" <70d3c176> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor@f43cd5a) 09:29:32,770 INFO [stdout] (default task-1) Entered Krb5Context.acceptSecContext with state=STATE_NEW 09:29:32,776 INFO [stdout] (default task-1) Java config name: /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb5-5558851378941484104.conf 09:29:32,777 INFO [stdout] (default task-1) Loading krb5 profile at /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb5-5558851378941484104.conf 09:29:32,778 INFO [stdout] (default task-1) Loaded from Java config 09:29:32,784 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 09:29:32,784 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 09:29:32,784 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 09:29:32,789 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 53; type: 3 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 77; type: 18 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 61; type: 23 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 09:29:32,790 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 09:29:32,791 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 61; type: 17 09:29:32,791 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): JBOSS.ORG 09:29:32,791 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): remote 09:29:32,791 INFO [stdout] (default task-1) >>> KeyTabInputStream, readName(): localhost 09:29:32,791 INFO [stdout] (default task-1) >>> KeyTab: load() entry length: 69; type: 16 09:29:32,791 INFO [stdout] (default task-1) Looking for keys for: remote/localhost(a)JBOSS.ORG 09:29:32,795 INFO [stdout] (default task-1) Added key: 16version: 0 09:29:32,795 INFO [stdout] (default task-1) Added key: 17version: 0 09:29:32,795 INFO [stdout] (default task-1) Added key: 23version: 0 09:29:32,795 INFO [stdout] (default task-1) Added key: 18version: 0 09:29:32,795 INFO [stdout] (default task-1) Added key: 3version: 0 09:29:32,797 INFO [stdout] (default task-1) >>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType 09:29:32,815 INFO [stdout] (default task-1) default etypes for permitted_enctypes: 17. 09:29:32,815 INFO [stdout] (default task-1) >>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType 09:29:32,820 INFO [stdout] (default task-1) MemoryCache: add 1519374572/673841/3F544EB85A4DA258070AFB184058AA45EB0654B36B8C91BC9C3BF08EEFD0751F/hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG to hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1@JBOSS.ORG|remote/localhost(a)JBOSS.ORG 09:29:32,821 INFO [stdout] (default task-1) >>> KrbApReq: authenticate succeed. 09:29:32,824 INFO [stdout] (default task-1) Krb5Context setting peerSeqNumber to: 437700117 09:29:32,827 INFO [stdout] (default task-1) >>> EType: sun.security.krb5.internal.crypto.Aes128CtsHmacSha1EType 09:29:32,828 INFO [stdout] (default task-1) Krb5Context setting mySeqNumber to: 536514998 09:29:32,828 TRACE [org.wildfly.security.sasl.gs2] (default task-1) checking if [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG] is authorized to act as [null]... 09:29:32,828 TRACE [org.wildfly.security] (default task-1) Principal assigning: [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG], pre-realm rewritten: [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1], realm name: [fileSystemRealm], post-realm rewritten: [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1], realm rewritten: [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1] 09:29:32,830 TRACE [org.wildfly.security] (default task-1) Role mapping: principal [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1] -> decoded roles [Users] -> realm mapped roles [Users] -> domain mapped roles [Users] 09:29:32,830 TRACE [org.wildfly.security] (default task-1) Authorizing principal hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1. 09:29:32,830 TRACE [org.wildfly.security] (default task-1) Authorizing against the following attributes: [Roles] => [Users] 09:29:32,830 TRACE [org.wildfly.security] (default task-1) Permission mapping: identity [hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1] with roles [Users] implies ("org.wildfly.security.auth.permission.LoginPermission" "") = true 09:29:32,830 TRACE [org.wildfly.security] (default task-1) Authorization succeed 09:29:32,830 TRACE [org.wildfly.security] (default task-1) RunAs authorization succeed - the same identity 09:29:32,830 TRACE [org.wildfly.security] (default task-1) Handling AuthorizeCallback: authenticationID = hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG authorizationID = hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1(a)JBOSS.ORG authorized = true 09:29:32,830 TRACE [org.wildfly.security.sasl.gs2] (default task-1) authorization id check successful 09:29:32,831 INFO [stdout] (default task-1) >>> Constrained deleg from GSSCaller{UNKNOWN} 09:29:32,832 TRACE [org.wildfly.security] (default task-1) Handling AuthenticationCompleteCallback: succeed 09:29:32,833 TRACE [org.wildfly.security] (default task-1) Handling SecurityIdentityCallback: identity = SecurityIdentity{principal=hnelson3ded7446-d6b0-45f4-ae78-99b7dc8b7cc1, securityDomain=org.wildfly.security.auth.server.SecurityDomain@510db9c2, authorizationIdentity=EMPTY, realmInfo=RealmInfo{name='fileSystemRealm', securityRealm=org.wildfly.security.auth.realm.FileSystemSecurityRealm@3962acf1}, creationTime=2018-02-23T08:29:32.830034Z} 09:29:32,833 TRACE [org.jboss.remoting.remote.server] (default task-1) Server sending authentication complete {code} {code:title=GSSAPI+CLI+JDK9} 09:51:37,313 INFO [KerberosCLIGssapiTestCase] (main) testValidKerberosTicketRemoteHttpProtocol 09:51:37,314 INFO [org.jboss.eapqe.krbldap.utils.CustomCLIExecutor] (main) Command:[/home/mchoma/Repos/tests-ldap-kerberos/eap71/../tests/target/dist/jboss-eap/bin/jboss-cli.sh, -Djboss.cli.config=/home/mchoma/Repos/tests-ldap-kerberos/eap71/../tests/target/dist/jboss-eap/bin/jboss-cli.xml, -c, --controller=remote+http://localhost:9990, --timeout=60000, -Djavax.security.auth.useSubjectCredsOnly=false, -Djava.security.krb5.conf=/home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb5-13746111561959284054.conf, -Dsun.security.krb5.debug=true, -Dcom.ibm.security.jgss.debug=all, -Dcom.ibm.security.krb5.Krb5Debug=all, -Dwildfly.config.url=/home/mchoma/Repos/tests-ldap-kerberos/eap71/target/KerberosCLIGssapiTestCase/wildfly-config.xml, --error-on-interact, :whoami] 09:51:38,436 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Initialized connection from /127.0.0.1:38177 to /127.0.0.1:9990 with options {org.jboss.remoting3.RemotingOptions.SASL_PROTOCOL=>remote} 09:51:38,437 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Accepted connection from /127.0.0.1:38177 to localhost/127.0.0.1:9990 09:51:38,437 TRACE [org.jboss.remoting.remote] (management I/O-2) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial@1cd4c654 09:51:38,437 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Sent 16 bytes 09:51:38,437 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Flushed channel 09:51:38,451 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) No buffers in queue for message header 09:51:38,451 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Allocated fresh buffers 09:51:38,451 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Received 58 bytes 09:51:38,451 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Received message java.nio.HeapByteBuffer[pos=0 lim=54 cap=8192] 09:51:38,451 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Received java.nio.HeapByteBuffer[pos=0 lim=54 cap=8192] 09:51:38,451 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capabilities request 09:51:38,451 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: version 1 09:51:38,451 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: remote endpoint name "cli-client" 09:51:38,451 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: message close protocol supported 09:51:38,452 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: remote version is "5.0.5.Final-redhat-1" 09:51:38,452 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: remote channels in is "40" 09:51:38,452 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: remote channels out is "40" 09:51:38,452 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received capability: authentication service 09:51:38,452 TRACE [org.jboss.remoting.remote.server] (management I/O-2) No EXTERNAL mechanism due to lack of SSL 09:51:38,456 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Added mechanism GSSAPI 09:51:38,456 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Added mechanism PLAIN 09:51:38,457 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Sent 83 bytes 09:51:38,457 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Flushed channel 09:51:38,662 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) No buffers in queue for message header 09:51:38,662 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Allocated fresh buffers 09:51:38,662 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Received 573 bytes 09:51:38,662 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Received message java.nio.HeapByteBuffer[pos=0 lim=569 cap=8192] 09:51:38,663 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Received java.nio.HeapByteBuffer[pos=0 lim=569 cap=8192] 09:51:38,663 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received authentication request 09:51:38,663 TRACE [org.wildfly.security] (management I/O-2) Handling MechanismInformationCallback type='SASL' name='GSSAPI' host-name='localhost' protocol='remote' 09:51:38,663 TRACE [org.wildfly.security] (management I/O-2) Handling MechanismInformationCallback type='SASL' name='GSSAPI' host-name='localhost' protocol='remote' 09:51:38,665 TRACE [org.wildfly.security.sasl.gssapi] (management I/O-2) configuredMaxReceiveBuffer=16777215 09:51:38,665 TRACE [org.wildfly.security.sasl.gssapi] (management I/O-2) relaxComplianceChecks=false 09:51:38,666 TRACE [org.wildfly.security.sasl.gssapi] (management I/O-2) QOP={AUTH} 09:51:38,666 TRACE [org.wildfly.security.sasl.gssapi] (management I/O-2) Obtaining GSSCredential for the service from callback handler... 09:51:38,666 TRACE [org.wildfly.security] (management I/O-2) No valid cached credential, obtaining new one... 09:51:38,667 TRACE [org.wildfly.security] (management I/O-2) Logging in using LoginContext and subject [Subject: ] 09:51:38,697 INFO [stdout] (management I/O-2) Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator false KeyTab is /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.2004356857582769790.keytab refreshKrb5Config is false principal is remote/localhost(a)JBOSS.ORG tryFirstPass is false useFirstPass is false storePass is false clearPass is false 09:51:38,703 INFO [stdout] (management I/O-2) principal is remote/localhost(a)JBOSS.ORG 09:51:38,703 INFO [stdout] (management I/O-2) Will use keytab 09:51:38,703 INFO [stdout] (management I/O-2) Commit Succeeded 09:51:38,703 INFO [stdout] (management I/O-2) 09:51:38,704 TRACE [org.wildfly.security] (management I/O-2) Logging in using LoginContext and subject [Subject: Principal: remote/localhost(a)JBOSS.ORG Private Credential: /home/mchoma/Repos/tests-ldap-kerberos/eap71/target/krb/krb.2004356857582769790.keytab for remote/localhost(a)JBOSS.ORG ] succeed 09:51:38,706 TRACE [org.wildfly.security] (management I/O-2) Creating GSSName for Principal &#39;remote/localhost(a)JBOSS.ORG&#39; 09:51:38,721 TRACE [org.wildfly.security] (management I/O-2) Obtained GSSCredentialCredential [org.wildfly.security.credential.GSSKerberosCredential@1f] 09:51:38,721 TRACE [org.wildfly.security] (management I/O-2) Handling ServerCredentialCallback: successfully obtained credential type type=class org.wildfly.security.credential.GSSKerberosCredential, algorithm=null, params=null 09:51:38,723 TRACE [org.wildfly.security] (management I/O-2) Creating SaslServer [org.wildfly.security.sasl.gssapi.GssapiServer@1884b726] for mechanism [GSSAPI] and protocol [remote] 09:51:38,723 TRACE [org.wildfly.security] (management I/O-2) Created SaslServer [org.wildfly.security.sasl.util.SecurityIdentitySaslServerFactory$1@4247966e-&gt;org.wildfly.security.sasl.util.AuthenticationTimeoutSaslServerFactory$DelegatingTimeoutSaslServer@206d1c8f-&gt;org.wildfly.security.sasl.util.AuthenticationCompleteCallbackSaslServerFactory$1@6a98aabd-&gt;org.wildfly.security.sasl.gssapi.GssapiServer(a)1884b726] for mechanism [GSSAPI] 09:51:38,724 TRACE [org.jboss.remoting.endpoint] (management I/O-2) Allocated tick to 9 of endpoint "localhost:MANAGEMENT" <5d2572a9> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor@29920534) 09:51:38,765 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) Negotiated mechanism 1.2.840.113554.1.2.2 09:51:38,765 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) No response so triggering next state immediately. 09:51:38,765 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) Not offering a security layer so zero length. 09:51:38,766 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) Transitioning to receive chosen security layer from client 09:51:38,766 TRACE [org.jboss.remoting.remote.server] (management task-1) Server sending authentication challenge 09:51:38,766 TRACE [org.jboss.remoting.remote] (management task-1) Setting read listener to org.jboss.remoting3.remote.ServerConnectionOpenListener$Authentication@73beac33 09:51:38,767 TRACE [org.jboss.remoting.endpoint] (management task-1) Resource closed count 00000008 of endpoint "localhost:MANAGEMENT" <5d2572a9> (closed org.jboss.remoting3.EndpointImpl$TrackingExecutor@29920534) 09:51:38,767 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Sent 37 bytes 09:51:38,767 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Flushed channel 09:51:38,772 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) No buffers in queue for message header 09:51:38,772 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Allocated fresh buffers 09:51:38,772 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Received 37 bytes 09:51:38,772 TRACE [org.jboss.remoting.remote.connection] (management I/O-2) Received message java.nio.HeapByteBuffer[pos=0 lim=33 cap=8192] 09:51:38,772 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Received java.nio.HeapByteBuffer[pos=0 lim=33 cap=8192] 09:51:38,772 TRACE [org.jboss.remoting.remote.server] (management I/O-2) Server received authentication response 09:51:38,772 TRACE [org.jboss.remoting.endpoint] (management I/O-2) Allocated tick to 9 of endpoint "localhost:MANAGEMENT" <5d2572a9> (opened org.jboss.remoting3.EndpointImpl$TrackingExecutor@29920534) 09:51:38,773 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) Client selected security layer AUTH, with maxBuffer of 0 09:51:38,773 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) Authentication ID=jduke07a018ca-8274-4f86-964e-8a9fcdf8355e(a)JBOSS.ORG, Authorization ID=jduke07a018ca-8274-4f86-964e-8a9fcdf8355e(a)JBOSS.ORG 09:51:38,773 TRACE [org.wildfly.security] (management task-1) Principal assigning: [jduke07a018ca-8274-4f86-964e-8a9fcdf8355e(a)JBOSS.ORG], pre-realm rewritten: [jduke07a018ca-8274-4f86-964e-8a9fcdf8355e], realm name: [fileSystemRealm], post-realm rewritten: [jduke07a018ca-8274-4f86-964e-8a9fcdf8355e], realm rewritten: [jduke07a018ca-8274-4f86-964e-8a9fcdf8355e] 09:51:38,777 TRACE [org.wildfly.security] (management task-1) Role mapping: principal [jduke07a018ca-8274-4f86-964e-8a9fcdf8355e] -> decoded roles [] -> realm mapped roles [] -> domain mapped roles [] 09:51:38,777 TRACE [org.wildfly.security] (management task-1) Authorizing principal jduke07a018ca-8274-4f86-964e-8a9fcdf8355e. 09:51:38,777 TRACE [org.wildfly.security] (management task-1) Authorizing against the following attributes: [] => [] 09:51:38,777 TRACE [org.wildfly.security] (management task-1) Permission mapping: identity [jduke07a018ca-8274-4f86-964e-8a9fcdf8355e] with roles [] implies ("org.wildfly.security.auth.permission.LoginPermission" "") = true 09:51:38,777 TRACE [org.wildfly.security] (management task-1) Authorization succeed 09:51:38,777 TRACE [org.wildfly.security] (management task-1) RunAs authorization succeed - the same identity 09:51:38,777 TRACE [org.wildfly.security] (management task-1) Handling AuthorizeCallback: authenticationID = jduke07a018ca-8274-4f86-964e-8a9fcdf8355e(a)JBOSS.ORG authorizationID = jduke07a018ca-8274-4f86-964e-8a9fcdf8355e(a)JBOSS.ORG authorized = true 09:51:38,778 TRACE [org.wildfly.security.sasl.gssapi] (management task-1) Negotiation complete. 09:51:38,778 TRACE [org.wildfly.security] (management task-1) Handling AuthenticationCompleteCallback: succeed 09:51:38,778 TRACE [org.wildfly.security] (management task-1) Handling SecurityIdentityCallback: identity = SecurityIdentity{principal=jduke07a018ca-8274-4f86-964e-8a9fcdf8355e, securityDomain=org.wildfly.security.auth.server.SecurityDomain@1f16ead7, authorizationIdentity=EMPTY, realmInfo=RealmInfo{name='fileSystemRealm', securityRealm=org.wildfly.security.auth.realm.FileSystemSecurityRealm@4bc23b83}, creationTime=2018-02-23T08:51:38.776780Z} 09:51:38,779 TRACE [org.jboss.remoting.remote.server] (management task-1) Server sending authentication complete {code}