[JBoss JIRA] (ISPN-4502) KrbLdapAuthenticationIT fails on all environments
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-4502?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-4502:
-----------------------------------------------
Roman Macor <rmacor(a)redhat.com> changed the Status of [bug 1118607|https://bugzilla.redhat.com/show_bug.cgi?id=1118607] from VERIFIED to ASSIGNED
> KrbLdapAuthenticationIT fails on all environments
> -------------------------------------------------
>
> Key: ISPN-4502
> URL: https://issues.jboss.org/browse/ISPN-4502
> Project: Infinispan
> Issue Type: Bug
> Components: Integration
> Affects Versions: 7.0.0.Alpha3, 7.0.0.Alpha4
> Environment: RHEL, Windows, Solaris
> Reporter: Vitalii Chepeliuk
> Assignee: Vitalii Chepeliuk
> Priority: Blocker
> Labels: testsuite_stability
> Fix For: 7.0.0.CR1, 8.1.0.Alpha1, 8.1.0.Final
>
>
> Following exception is thrown
> {noformat}
> java.lang.Exception: Unexpected exception, expected<java.security.PrivilegedActionException> but was<javax.security.auth.login.LoginException>
> at com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:105)
> at com.sun.jndi.ldap.Connection.readReply(Connection.java:449)
> at com.sun.jndi.ldap.LdapClient.ldapBind(LdapClient.java:364)
> at com.sun.jndi.ldap.sasl.LdapSasl.saslBind(LdapSasl.java:126)
> at com.sun.jndi.ldap.LdapClient.authenticate(LdapClient.java:235)
> at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2740)
> at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316)
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193)
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211)
> at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154)
> at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84)
> at org.jboss.as.naming.InitialContext.getDefaultInitCtx(InitialContext.java:122)
> at org.jboss.as.naming.InitialContext.init(InitialContext.java:107)
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153)
> at org.jboss.as.naming.InitialContext.<init>(InitialContext.java:98)
> at org.jboss.as.naming.InitialContextFactory.getInitialContext(InitialContextFactory.java:44)
> at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684)
> at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307)
> at javax.naming.InitialContext.init(InitialContext.java:242)
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153)
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.constructLdapContext(AdvancedLdapLoginModule.java:470)
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.innerLogin(AdvancedLdapLoginModule.java:361)
> at org.jboss.security.negotiation.AdvancedLdapLoginModule$AuthorizeAction.run(AdvancedLdapLoginModule.java:943)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:356)
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.login(AdvancedLdapLoginModule.java:305)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at javax.security.auth.login.LoginContext.invoke(LoginContext.java:762)
> at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203)
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:690)
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:688)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:687)
> at javax.security.auth.login.LoginContext.login(LoginContext.java:595)
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.authenticateWithKrb(AbstractAuthentication.java:69)
> at org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.getAdminSubject(KrbLdapAuthenticationIT.java:70)
> {noformat}
> Solaris output
> {noformat}
> &#27;[0m14:01:24,746 INFO [org.jboss.modules] (main) JBoss Modules version 1.3.3.Final-redhat-1
> &#27;[0m&#27;[0m14:01:25,118 INFO [org.jboss.msc] (main) JBoss MSC version 1.0.4.GA-redhat-1
> &#27;[0m&#27;[0m14:01:25,253 INFO [org.jboss.as] (MSC service thread 1-6) JBAS015899: JBoss EAP 6.2.4.GA (AS 7.3.4.Final-redhat-1) starting
> &#27;[0m&#27;[0m14:01:26,916 INFO [org.xnio] (MSC service thread 1-55) XNIO Version 3.0.10.GA-redhat-1
> &#27;[0m&#27;[0m14:01:26,917 INFO [org.jboss.as.server] (Controller Boot Thread) JBAS015888: Creating http management service using socket-binding (management-http)
> &#27;[0m&#27;[0m14:01:26,927 INFO [org.xnio.nio] (MSC service thread 1-55) XNIO NIO Implementation Version 3.0.10.GA-redhat-1
> &#27;[0m&#27;[0m14:01:26,955 INFO [org.jboss.remoting] (MSC service thread 1-55) JBoss Remoting version 3.2.19.GA-redhat-1
> &#27;[0m&#27;[0m14:01:26,993 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 29) JBAS010280: Activating Infinispan subsystem.
> &#27;[0m&#27;[0m14:01:26,996 INFO [org.jboss.as.security] (ServerService Thread Pool -- 42) JBAS013171: Activating Security Subsystem
> &#27;[0m&#27;[0m14:01:26,998 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 37) JBAS011800: Activating Naming Subsystem
> &#27;[0m&#27;[0m14:01:27,000 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 46) JBAS015537: Activating WebServices Extension
> &#27;[0m&#27;[0m14:01:27,002 INFO [org.jboss.as.jsf] (ServerService Thread Pool -- 35) JBAS012605: Activated the following JSF Implementations: [main, 1.2]
> &#27;[0m&#27;[0m14:01:27,007 INFO [org.jboss.as.security] (MSC service thread 1-37) JBAS013170: Current PicketBox version=4.0.19.SP8-redhat-1
> &#27;[0m&#27;[0m14:01:27,021 INFO [org.jboss.as.connector.logging] (MSC service thread 1-112) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.23.1.Final-redhat-1)
> &#27;[0m&#27;[0m14:01:27,057 INFO [org.jboss.as.naming] (MSC service thread 1-112) JBAS011802: Starting Naming Service
> &#27;[0m&#27;[0m14:01:27,058 INFO [org.jboss.as.mail.extension] (MSC service thread 1-96) JBAS015400: Bound mail session [java:jboss/mail/Default]
> &#27;[0m&#27;[0m14:01:27,153 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 25) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
> &#27;[0m&#27;[0m14:01:27,265 INFO [org.apache.coyote.http11] (MSC service thread 1-10) JBWEB003001: Coyote HTTP/1.1 initializing on : http-/127.0.0.1:8080
> &#27;[0m&#27;[0m14:01:27,273 INFO [org.apache.coyote.http11] (MSC service thread 1-10) JBWEB003000: Coyote HTTP/1.1 starting on: http-/127.0.0.1:8080
> &#27;[0m&#27;[0m14:01:27,429 INFO [org.jboss.ws.common.management] (MSC service thread 1-95) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.2.4.Final-redhat-1
> &#27;[0m&#27;[0m14:01:27,495 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-91) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
> &#27;[0m&#27;[0m14:01:27,659 INFO [org.jboss.as.server.deployment.scanner] (MSC service thread 1-52) JBAS015012: Started FileSystemDeploymentService for directory /mnt/hudson_workspace/workspace/edg-60-ispn-testsuite-solaris/425a0ff4/infinispan/integrationtests/security-it/target/jboss-eap-6.2/standalone/deployments
> &#27;[0m&#27;[0m14:01:27,667 INFO [org.jboss.as.remoting] (MSC service thread 1-110) JBAS017100: Listening on 127.0.0.1:4447
> &#27;[0m&#27;[0m14:01:27,667 INFO [org.jboss.as.remoting] (MSC service thread 1-28) JBAS017100: Listening on 127.0.0.1:9999
> &#27;[0m&#27;[0m14:01:27,903 INFO [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management
> &#27;[0m&#27;[0m14:01:27,904 INFO [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990
> &#27;[0m&#27;[0m14:01:27,905 INFO [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.2.4.GA (AS 7.3.4.Final-redhat-1) started in 3795ms - Started 142 of 199 services (56 services are passive or on-demand)
> &#27;[0m&#27;[0m14:01:30,299 INFO [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location /mnt/hudson_workspace/workspace/edg-60-ispn-testsuite-solaris/425a0ff4/infinispan/integrationtests/security-it/target/jboss-eap-6.2/standalone/data/content/a1/608ba0fcf068c3e432515d73a23c16b518699d/content
> &#27;[0m&#27;[0m14:01:30,330 INFO [org.jboss.as.server.deployment] (MSC service thread 1-121) JBAS015876: Starting deployment of "arquillian-service" (runtime-name: "arquillian-service")
> &#27;[0m&#27;[33m14:01:30,833 WARN [org.jboss.as.dependency.private] (MSC service thread 1-2) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.jmx:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m14:01:30,834 WARN [org.jboss.as.dependency.private] (MSC service thread 1-2) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.server:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m14:01:30,843 WARN [org.jboss.as.dependency.private] (MSC service thread 1-2) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.osgi:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m14:01:30,843 WARN [org.jboss.as.dependency.private] (MSC service thread 1-2) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.jandex:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m14:01:30,844 WARN [org.jboss.as.dependency.private] (MSC service thread 1-2) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.osgi.framework:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m14:01:30,892 WARN [org.jboss.weld.deployer] (MSC service thread 1-3) JBAS016012: Deployment deployment "arquillian-service" contains CDI annotations but beans.xml was not found.
> &#27;[0m&#27;[0m14:01:31,191 INFO [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "arquillian-service" (runtime-name : "arquillian-service")
> &#27;[0m&#27;[0m14:01:34,201 INFO [org.jboss.as.repository] (management-handler-thread - 3) JBAS014900: Content added at location /mnt/hudson_workspace/workspace/edg-60-ispn-testsuite-solaris/425a0ff4/infinispan/integrationtests/security-it/target/jboss-eap-6.2/standalone/data/content/13/704e306c78cc3756745a6fdb065723aa2705ad/content
> &#27;[0m&#27;[0m14:01:34,209 INFO [org.jboss.as.server.deployment] (MSC service thread 1-71) JBAS015876: Starting deployment of "9d90e489-66da-492f-a06a-38c83deea6fe.war" (runtime-name: "9d90e489-66da-492f-a06a-38c83deea6fe.war")
> &#27;[0m&#27;[33m14:01:34,972 WARN [org.jboss.as.dependency.private] (MSC service thread 1-29) JBAS018567: Deployment "deployment.9d90e489-66da-492f-a06a-38c83deea6fe.war" is using a private module ("org.apache.commons.lang:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m14:01:34,973 WARN [org.jboss.as.dependency.private] (MSC service thread 1-29) JBAS018567: Deployment "deployment.9d90e489-66da-492f-a06a-38c83deea6fe.war" is using a private module ("org.apache.commons.lang:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[0m14:01:35,106 INFO [org.jboss.as.arquillian] (MSC service thread 1-21) Arquillian deployment detected: ArquillianConfig[service=jboss.arquillian.config."9d90e489-66da-492f-a06a-38c83deea6fe.war",unit=9d90e489-66da-492f-a06a-38c83deea6fe.war,tests=[org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT, org.infinispan.test.integration.security.embedded.LdapAuthenticationIT]]
> &#27;[0m&#27;[0m14:01:35,126 INFO [org.jboss.web] (ServerService Thread Pool -- 7) JBAS018210: Register web context: /9d90e489-66da-492f-a06a-38c83deea6fe
> &#27;[0m&#27;[0m14:01:35,305 INFO [org.jboss.as.server] (management-handler-thread - 3) JBAS018559: Deployed "9d90e489-66da-492f-a06a-38c83deea6fe.war" (runtime-name : "9d90e489-66da-492f-a06a-38c83deea6fe.war")
> &#27;[0m2014-07-10 14:01:37,678 WARN [DefaultDirectoryService] (main) ApacheDS shutdown hook has NOT been registered with the runtime. This default setting for standalone operation has been overriden.
> 2014-07-10 14:01:41,056 WARN [DefaultDirectoryService] (main) You didn't change the admin password of directory service instance 'InfinispanDS'. Please update the admin password as soon as possible to prevent a possible security breach.
> &#27;[0m14:01:44,382 INFO [org.jboss.arquillian.testenricher.cdi.container.BeanManagerProducer] (pool-1-thread-1) BeanManager not found.
> &#27;[0m2014-07-10 14:01:45,923 ERROR [KERBEROS_LOG] (NioDatagramAcceptor-1) No timestamp found
> 2014-07-10 14:01:45,930 WARN [KerberosProtocolHandler] (NioDatagramAcceptor-1) Additional pre-authentication required (25)
> 2014-07-10 14:01:45,930 WARN [KERBEROS_LOG] (NioDatagramAcceptor-1) Additional pre-authentication required (25)
> 2014-07-10 14:01:47,133 ERROR [KERBEROS_LOG] (NioDatagramAcceptor-1) No timestamp found
> 2014-07-10 14:01:47,133 WARN [KerberosProtocolHandler] (NioDatagramAcceptor-1) Additional pre-authentication required (25)
> 2014-07-10 14:01:47,133 WARN [KERBEROS_LOG] (NioDatagramAcceptor-1) Additional pre-authentication required (25)
> 2014-07-10 14:01:47,480 WARN [LdapProtocolHandler] (pool-8-thread-1) Unexpected exception forcing session to close: sending disconnect notice to client.
> java.security.PrivilegedActionException: javax.security.sasl.SaslException: Failure to initialize security context [Caused by GSSException: Invalid name provided (Mechanism level: Cannot locate default realm)]
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:415)
> at org.apache.directory.server.ldap.handlers.sasl.gssapi.GssapiMechanismHandler.handleMechanism(GssapiMechanismHandler.java:74)
> at org.apache.directory.server.ldap.handlers.request.BindRequestHandler.handleSaslAuth(BindRequestHandler.java:577)
> at org.apache.directory.server.ldap.handlers.request.BindRequestHandler.handle(BindRequestHandler.java:630)
> at org.apache.directory.server.ldap.handlers.request.BindRequestHandler.handle(BindRequestHandler.java:66)
> at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:193)
> at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:56)
> at org.apache.mina.handler.demux.DemuxingIoHandler.messageReceived(DemuxingIoHandler.java:221)
> at org.apache.directory.server.ldap.LdapProtocolHandler.messageReceived(LdapProtocolHandler.java:217)
> at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:690)
> at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:417)
> at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:47)
> at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:765)
> at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:74)
> at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
> at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.runTask(UnorderedThreadPoolExecutor.java:474)
> at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.run(UnorderedThreadPoolExecutor.java:428)
> at java.lang.Thread.run(Thread.java:744)
> Caused by: javax.security.sasl.SaslException: Failure to initialize security context [Caused by GSSException: Invalid name provided (Mechanism level: Cannot locate default realm)]
> at com.sun.security.sasl.gsskerb.GssKrb5Server.<init>(GssKrb5Server.java:113)
> at com.sun.security.sasl.gsskerb.FactoryImpl.createSaslServer(FactoryImpl.java:85)
> at javax.security.sasl.Sasl.createSaslServer(Sasl.java:509)
> at org.apache.directory.server.ldap.handlers.sasl.gssapi.GssapiMechanismHandler$1.run(GssapiMechanismHandler.java:78)
> at org.apache.directory.server.ldap.handlers.sasl.gssapi.GssapiMechanismHandler$1.run(GssapiMechanismHandler.java:75)
> ... 19 more
> Caused by: GSSException: Invalid name provided (Mechanism level: Cannot locate default realm)
> at sun.security.jgss.krb5.Krb5NameElement.getInstance(Krb5NameElement.java:127)
> at sun.security.jgss.krb5.Krb5MechFactory.getNameElement(Krb5MechFactory.java:95)
> at sun.security.jgss.GSSManagerImpl.getNameElement(GSSManagerImpl.java:202)
> at sun.security.jgss.GSSNameImpl.getElement(GSSNameImpl.java:472)
> at sun.security.jgss.GSSNameImpl.init(GSSNameImpl.java:201)
> at sun.security.jgss.GSSNameImpl.<init>(GSSNameImpl.java:170)
> at sun.security.jgss.GSSManagerImpl.createName(GSSManagerImpl.java:137)
> at com.sun.security.sasl.gsskerb.GssKrb5Server.<init>(GssKrb5Server.java:93)
> ... 23 more
> 2014-07-10 14:01:47,496 WARN [LdapProtocolHandler] (NioProcessor-3) Null LdapSession given to cleanUpSession.
> &#27;[31m14:01:47,510 SEVERE [org.jboss.arquillian.protocol.jmx.JMXTestRunner] (pool-1-thread-1) Failed: org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.testUnprivilegedWrite: javax.security.auth.login.LoginException: Unable to create new InitialLdapContext
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.constructLdapContext(AdvancedLdapLoginModule.java:474) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.innerLogin(AdvancedLdapLoginModule.java:361) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule$AuthorizeAction.run(AdvancedLdapLoginModule.java:943) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_51]
> at javax.security.auth.Subject.doAs(Subject.java:356) [rt.jar:1.7.0_51]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.login(AdvancedLdapLoginModule.java:305) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.invoke(LoginContext.java:762) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:690) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:688) [rt.jar:1.7.0_51]
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:687) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.login(LoginContext.java:595) [rt.jar:1.7.0_51]
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.authenticateWithKrb(AbstractAuthentication.java:69) [classes:]
> at org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.getAdminSubject(KrbLdapAuthenticationIT.java:70) [classes:]
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.setupCache(AbstractAuthentication.java:100) [classes:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [arquillian-service:]
> at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [arquillian-service:]
> at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [arquillian-service:]
> at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$StatementLifecycleExecutor.invoke(Arquillian.java:351) [arquillian-service:]
> at org.jboss.arquillian.container.test.impl.execution.BeforeLifecycleEventExecuter.on(BeforeLifecycleEventExecuter.java:35) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:89) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:75) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:60) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135) [arquillian-service:]
> at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115) [arquillian-service:]
> at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.before(EventTestRunnerAdaptor.java:95) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:222) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:240) [arquillian-service:]
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [arquillian-service:]
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [arquillian-service:]
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [arquillian-service:]
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [arquillian-service:]
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [arquillian-service:]
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [arquillian-service:]
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [arquillian-service:]
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:185) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:199) [arquillian-service:]
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:147) [arquillian-service:]
> at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [arquillian-service:]
> at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [arquillian-service:]
> at org.jboss.arquillian.junit.container.JUnitTestRunner.execute(JUnitTestRunner.java:65) [arquillian-service:]
> at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethodInternal(JMXTestRunner.java:129) [arquillian-service:]
> at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethod(JMXTestRunner.java:108) [arquillian-service:]
> at org.jboss.as.arquillian.service.ArquillianService$ExtendedJMXTestRunner.runTestMethod(ArquillianService.java:214) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:75) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:279) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:112) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:46) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) [rt.jar:1.7.0_51]
> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) [rt.jar:1.7.0_51]
> at org.jboss.as.jmx.PluggableMBeanServerImpl$TcclMBeanServer.invoke(PluggableMBeanServerImpl.java:1453)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.invoke(PluggableMBeanServerImpl.java:731)
> at org.jboss.remotingjmx.protocol.v2.ServerProxy$InvokeHandler.handle(ServerProxy.java:952)
> at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1$1.run(ServerCommon.java:153)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:75)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:70)
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_51]
> at javax.security.auth.Subject.doAs(Subject.java:415) [rt.jar:1.7.0_51]
> at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:94)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor.handleEvent(ServerInterceptorFactory.java:70)
> at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1.run(ServerCommon.java:149)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
> at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
> Caused by: javax.naming.NamingException: JBAS011843: Failed instantiate InitialContextFactory com.sun.jndi.ldap.LdapCtxFactory from classloader ModuleClassLoader for Module "deployment.9d90e489-66da-492f-a06a-38c83deea6fe.war:main" from Service Module Loader [Root exception is javax.naming.CommunicationException: Request: 1 cancelled]
> at org.jboss.as.naming.InitialContext.getDefaultInitCtx(InitialContext.java:124)
> at org.jboss.as.naming.InitialContext.init(InitialContext.java:107)
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) [rt.jar:1.7.0_51]
> at org.jboss.as.naming.InitialContext.<init>(InitialContext.java:98)
> at org.jboss.as.naming.InitialContextFactory.getInitialContext(InitialContextFactory.java:44)
> at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) [rt.jar:1.7.0_51]
> at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307) [rt.jar:1.7.0_51]
> at javax.naming.InitialContext.init(InitialContext.java:242) [rt.jar:1.7.0_51]
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) [rt.jar:1.7.0_51]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.constructLdapContext(AdvancedLdapLoginModule.java:470) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> ... 115 more
> Caused by: javax.naming.CommunicationException: Request: 1 cancelled
> at com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:105) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.Connection.readReply(Connection.java:449) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapClient.ldapBind(LdapClient.java:364) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.sasl.LdapSasl.saslBind(LdapSasl.java:126) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapClient.authenticate(LdapClient.java:235) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2740) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84) [rt.jar:1.7.0_51]
> at org.jboss.as.naming.InitialContext.getDefaultInitCtx(InitialContext.java:122)
> ... 124 more
> &#27;[0m
> {noformat}
> Windows output
> {noformat}
> 19:10:48,302 INFO [org.jboss.modules] (main) JBoss Modules version 1.3.3.Final-redhat-1
> 19:10:49,810 INFO [org.jboss.msc] (main) JBoss MSC version 1.0.4.GA-redhat-1
> 19:10:50,423 INFO [org.jboss.as] (MSC service thread 1-2) JBAS015899: JBoss EAP 6.2.4.GA (AS 7.3.4.Final-redhat-1) starting
> 19:10:57,418 INFO [org.xnio] (MSC service thread 1-1) XNIO Version 3.0.10.GA-redhat-1
> 19:10:57,434 INFO [org.jboss.as.server] (Controller Boot Thread) JBAS015888: Creating http management service using socket-binding (management-http)
> 19:10:57,464 INFO [org.xnio.nio] (MSC service thread 1-1) XNIO NIO Implementation Version 3.0.10.GA-redhat-1
> 19:10:57,622 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 37) JBAS011800: Activating Naming Subsystem
> 19:10:57,652 INFO [org.jboss.as.security] (ServerService Thread Pool -- 42) JBAS013171: Activating Security Subsystem
> 19:10:57,682 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 29) JBAS010280: Activating Infinispan subsystem.
> 19:10:57,739 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 46) JBAS015537: Activating WebServices Extension
> 19:10:57,753 INFO [org.jboss.remoting] (MSC service thread 1-1) JBoss Remoting version 3.2.19.GA-redhat-1
> 19:10:58,006 INFO [org.jboss.as.jsf] (ServerService Thread Pool -- 35) JBAS012605: Activated the following JSF Implementations: [main, 1.2]
> 19:10:58,283 INFO [org.jboss.as.naming] (MSC service thread 1-1) JBAS011802: Starting Naming Service
> 19:10:58,413 INFO [org.jboss.as.mail.extension] (MSC service thread 1-1) JBAS015400: Bound mail session [java:jboss/mail/Default]
> 19:10:58,444 INFO [org.jboss.as.security] (MSC service thread 1-1) JBAS013170: Current PicketBox version=4.0.19.SP8-redhat-1
> 19:10:58,717 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 25) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3)
> 19:10:59,211 INFO [org.jboss.as.connector.logging] (MSC service thread 1-1) JBAS010408: Starting JCA Subsystem (IronJacamar 1.0.23.1.Final-redhat-1)
> 19:11:01,802 INFO [org.jboss.as.server.deployment.scanner] (MSC service thread 1-1) JBAS015012: Started FileSystemDeploymentService for directory W:\workspace\edg-60-ispn-testsuite-windows\dec96de9\infinispan\integrationtests\security-it\target\jboss-eap-6.2\standalone\deployments
> 19:11:01,903 INFO [org.jboss.as.remoting] (MSC service thread 1-2) JBAS017100: Listening on 127.0.0.1:4447
> 19:11:02,145 INFO [org.jboss.ws.common.management] (MSC service thread 1-4) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.2.4.Final-redhat-1
> 19:11:02,164 INFO [org.apache.coyote.http11] (MSC service thread 1-2) JBWEB003001: Coyote HTTP/1.1 initializing on : http-/127.0.0.1:8080
> 19:11:02,196 INFO [org.apache.coyote.http11] (MSC service thread 1-2) JBWEB003000: Coyote HTTP/1.1 starting on: http-/127.0.0.1:8080
> 19:11:02,328 INFO [org.jboss.as.remoting] (MSC service thread 1-3) JBAS017100: Listening on 127.0.0.1:9999
> 19:11:03,009 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]
> 19:11:03,464 INFO [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management
> 19:11:03,468 INFO [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990
> 19:11:03,471 INFO [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.2.4.GA (AS 7.3.4.Final-redhat-1) started in 17670ms - Started 142 of 199 services (56 services are passive or on-demand)
> 19:11:09,101 INFO [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location W:\workspace\edg-60-ispn-testsuite-windows\dec96de9\infinispan\integrationtests\security-it\target\jboss-eap-6.2\standalone\data\content\86\4229fa8028234886af76b97986bbe0a8ec9520\content
> 19:11:09,230 INFO [org.jboss.as.server.deployment] (MSC service thread 1-2) JBAS015876: Starting deployment of "arquillian-service" (runtime-name: "arquillian-service")
> 19:11:10,375 WARN [org.jboss.as.dependency.private] (MSC service thread 1-1) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.jmx:main") which may be changed or removed in future versions without notice.
> 19:11:10,384 WARN [org.jboss.as.dependency.private] (MSC service thread 1-1) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.server:main") which may be changed or removed in future versions without notice.
> 19:11:10,417 WARN [org.jboss.as.dependency.private] (MSC service thread 1-1) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.as.osgi:main") which may be changed or removed in future versions without notice.
> 19:11:10,419 WARN [org.jboss.as.dependency.private] (MSC service thread 1-1) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.jandex:main") which may be changed or removed in future versions without notice.
> 19:11:10,421 WARN [org.jboss.as.dependency.private] (MSC service thread 1-1) JBAS018567: Deployment "deployment.arquillian-service" is using a private module ("org.jboss.osgi.framework:main") which may be changed or removed in future versions without notice.
> 19:11:10,613 WARN [org.jboss.weld.deployer] (MSC service thread 1-2) JBAS016012: Deployment deployment "arquillian-service" contains CDI annotations but beans.xml was not found.
> 19:11:11,861 INFO [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "arquillian-service" (runtime-name : "arquillian-service")
> 19:11:20,920 INFO [org.jboss.as.repository] (management-handler-thread - 3) JBAS014900: Content added at location W:\workspace\edg-60-ispn-testsuite-windows\dec96de9\infinispan\integrationtests\security-it\target\jboss-eap-6.2\standalone\data\content\3d\1ba9b5c871390b08bb8fff8f70c0cfb2e9bd92\content
> 19:11:20,942 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) JBAS015876: Starting deployment of "cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war" (runtime-name: "cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war")
> 19:11:23,615 WARN [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war" is using a private module ("org.apache.commons.lang:main") which may be changed or removed in future versions without notice.
> 19:11:23,618 WARN [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war" is using a private module ("org.apache.commons.lang:main") which may be changed or removed in future versions without notice.
> 19:11:23,914 INFO [org.jboss.as.arquillian] (MSC service thread 1-4) Arquillian deployment detected: ArquillianConfig[service=jboss.arquillian.config."cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war",unit=cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war,tests=[org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT, org.infinispan.test.integration.security.embedded.LdapAuthenticationIT]]
> 19:11:24,001 INFO [org.jboss.web] (ServerService Thread Pool -- 53) JBAS018210: Register web context: /cdfec128-cadf-4cfb-9ffe-f5445e7f3980
> 19:11:24,313 INFO [org.jboss.as.server] (management-handler-thread - 3) JBAS018559: Deployed "cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war" (runtime-name : "cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war")
> 19:11:57,265 INFO [org.jboss.arquillian.testenricher.cdi.container.BeanManagerProducer] (pool-2-thread-1) BeanManager not found.
> 19:12:01,993 SEVERE [org.jboss.arquillian.protocol.jmx.JMXTestRunner] (pool-2-thread-1) Failed: org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.testUnprivilegedWrite: javax.security.auth.login.LoginException: Unable to create new InitialLdapContext
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.constructLdapContext(AdvancedLdapLoginModule.java:474) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.innerLogin(AdvancedLdapLoginModule.java:361) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule$AuthorizeAction.run(AdvancedLdapLoginModule.java:943) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_51]
> at javax.security.auth.Subject.doAs(Subject.java:356) [rt.jar:1.7.0_51]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.login(AdvancedLdapLoginModule.java:305) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.invoke(LoginContext.java:762) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:690) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:688) [rt.jar:1.7.0_51]
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:687) [rt.jar:1.7.0_51]
> at javax.security.auth.login.LoginContext.login(LoginContext.java:595) [rt.jar:1.7.0_51]
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.authenticateWithKrb(AbstractAuthentication.java:69) [classes:]
> at org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.getAdminSubject(KrbLdapAuthenticationIT.java:70) [classes:]
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.setupCache(AbstractAuthentication.java:100) [classes:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [arquillian-service:]
> at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [arquillian-service:]
> at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [arquillian-service:]
> at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$StatementLifecycleExecutor.invoke(Arquillian.java:351) [arquillian-service:]
> at org.jboss.arquillian.container.test.impl.execution.BeforeLifecycleEventExecuter.on(BeforeLifecycleEventExecuter.java:35) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:89) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:60) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:75) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135) [arquillian-service:]
> at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115) [arquillian-service:]
> at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.before(EventTestRunnerAdaptor.java:95) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:222) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:240) [arquillian-service:]
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [arquillian-service:]
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [arquillian-service:]
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [arquillian-service:]
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [arquillian-service:]
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [arquillian-service:]
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [arquillian-service:]
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [arquillian-service:]
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:185) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:199) [arquillian-service:]
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:147) [arquillian-service:]
> at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [arquillian-service:]
> at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [arquillian-service:]
> at org.jboss.arquillian.junit.container.JUnitTestRunner.execute(JUnitTestRunner.java:65) [arquillian-service:]
> at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethodInternal(JMXTestRunner.java:129) [arquillian-service:]
> at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethod(JMXTestRunner.java:108) [arquillian-service:]
> at org.jboss.as.arquillian.service.ArquillianService$ExtendedJMXTestRunner.runTestMethod(ArquillianService.java:214) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:75) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_51]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_51]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51]
> at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:279) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:112) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:46) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) [rt.jar:1.7.0_51]
> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) [rt.jar:1.7.0_51]
> at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) [rt.jar:1.7.0_51]
> at org.jboss.as.jmx.PluggableMBeanServerImpl$TcclMBeanServer.invoke(PluggableMBeanServerImpl.java:1453)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.invoke(PluggableMBeanServerImpl.java:731)
> at org.jboss.remotingjmx.protocol.v2.ServerProxy$InvokeHandler.handle(ServerProxy.java:952)
> at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1$1.run(ServerCommon.java:153)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:75)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:70)
> at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_51]
> at javax.security.auth.Subject.doAs(Subject.java:415) [rt.jar:1.7.0_51]
> at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:94)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor.handleEvent(ServerInterceptorFactory.java:70)
> at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1.run(ServerCommon.java:149)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
> at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
> Caused by: javax.naming.NamingException: JBAS011843: Failed instantiate InitialContextFactory com.sun.jndi.ldap.LdapCtxFactory from classloader ModuleClassLoader for Module "deployment.cdfec128-cadf-4cfb-9ffe-f5445e7f3980.war:main" from Service Module Loader [Root exception is javax.naming.CommunicationException: Request: 1 cancelled]
> at org.jboss.as.naming.InitialContext.getDefaultInitCtx(InitialContext.java:124)
> at org.jboss.as.naming.InitialContext.init(InitialContext.java:107)
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) [rt.jar:1.7.0_51]
> at org.jboss.as.naming.InitialContext.<init>(InitialContext.java:98)
> at org.jboss.as.naming.InitialContextFactory.getInitialContext(InitialContextFactory.java:44)
> at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) [rt.jar:1.7.0_51]
> at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307) [rt.jar:1.7.0_51]
> at javax.naming.InitialContext.init(InitialContext.java:242) [rt.jar:1.7.0_51]
> at javax.naming.ldap.InitialLdapContext.<init>(InitialLdapContext.java:153) [rt.jar:1.7.0_51]
> at org.jboss.security.negotiation.AdvancedLdapLoginModule.constructLdapContext(AdvancedLdapLoginModule.java:470) [jboss-negotiation-extras-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> ... 115 more
> Caused by: javax.naming.CommunicationException: Request: 1 cancelled
> at com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:105) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.Connection.readReply(Connection.java:449) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapClient.ldapBind(LdapClient.java:364) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.sasl.LdapSasl.saslBind(LdapSasl.java:126) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapClient.authenticate(LdapClient.java:235) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2740) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154) [rt.jar:1.7.0_51]
> at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84) [rt.jar:1.7.0_51]
> at org.jboss.as.naming.InitialContext.getDefaultInitCtx(InitialContext.java:122)
> ... 124 more
> {noformat}
> RHEL output
> {noformat}
> &#27;[0m21:26:37,168 INFO [org.jboss.web] (ServerService Thread Pool -- 48) JBAS018224: Unregister web context: /64e34336-6dd0-4c6b-9fd6-913daa9d642f
> &#27;[0m&#27;[0m21:26:37,214 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) JBAS015877: Stopped deployment 64e34336-6dd0-4c6b-9fd6-913daa9d642f.war (runtime-name: 64e34336-6dd0-4c6b-9fd6-913daa9d642f.war) in 53ms
> &#27;[0m&#27;[0m21:26:37,423 INFO [org.jboss.as.repository] (management-handler-thread - 1) JBAS014901: Content removed from location /mnt/hudson_workspace/workspace/edg-60-ispn-testsuite-rhel/7e5d4f04/infinispan/integrationtests/security-it/target/jboss-eap-6.2/standalone/data/content/87/98da4175288acfb013ead50aeafacbcffd6665/content
> &#27;[0m&#27;[0m21:26:37,425 INFO [org.jboss.as.server] (management-handler-thread - 1) JBAS018558: Undeployed "64e34336-6dd0-4c6b-9fd6-913daa9d642f.war" (runtime-name: "64e34336-6dd0-4c6b-9fd6-913daa9d642f.war")
> &#27;[0m&#27;[0m21:26:38,619 INFO [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location /mnt/hudson_workspace/workspace/edg-60-ispn-testsuite-rhel/7e5d4f04/infinispan/integrationtests/security-it/target/jboss-eap-6.2/standalone/data/content/9b/d49faaf8de933f75b057612f4c6977283012be/content
> &#27;[0m&#27;[0m21:26:38,625 INFO [org.jboss.as.server.deployment] (MSC service thread 1-7) JBAS015876: Starting deployment of "62aeffb3-3fe5-4936-b589-3ce731f3f77e.war" (runtime-name: "62aeffb3-3fe5-4936-b589-3ce731f3f77e.war")
> &#27;[0m&#27;[33m21:26:39,054 WARN [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.62aeffb3-3fe5-4936-b589-3ce731f3f77e.war" is using a private module ("org.apache.commons.lang:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[33m21:26:39,056 WARN [org.jboss.as.dependency.private] (MSC service thread 1-3) JBAS018567: Deployment "deployment.62aeffb3-3fe5-4936-b589-3ce731f3f77e.war" is using a private module ("org.apache.commons.lang:main") which may be changed or removed in future versions without notice.
> &#27;[0m&#27;[0m21:26:39,086 INFO [org.jboss.as.arquillian] (MSC service thread 1-5) Arquillian deployment detected: ArquillianConfig[service=jboss.arquillian.config."62aeffb3-3fe5-4936-b589-3ce731f3f77e.war",unit=62aeffb3-3fe5-4936-b589-3ce731f3f77e.war,tests=[org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT, org.infinispan.test.integration.security.embedded.LdapAuthenticationIT]]
> &#27;[0m&#27;[0m21:26:39,092 INFO [org.jboss.web] (ServerService Thread Pool -- 53) JBAS018210: Register web context: /62aeffb3-3fe5-4936-b589-3ce731f3f77e
> &#27;[0m&#27;[0m21:26:39,332 INFO [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "62aeffb3-3fe5-4936-b589-3ce731f3f77e.war" (runtime-name : "62aeffb3-3fe5-4936-b589-3ce731f3f77e.war")
> &#27;[0m2014-07-10 21:26:40,594 WARN [DefaultDirectoryService] (main) ApacheDS shutdown hook has NOT been registered with the runtime. This default setting for standalone operation has been overriden.
> 2014-07-10 21:26:50,069 WARN [DefaultDirectoryService] (main) You didn't change the admin password of directory service instance 'InfinispanDS'. Please update the admin password as soon as possible to prevent a possible security breach.
> &#27;[0m21:26:59,483 INFO [org.jboss.arquillian.testenricher.cdi.container.BeanManagerProducer] (pool-1-thread-2) BeanManager not found.
> &#27;[0m&#27;[31m21:26:59,566 SEVERE [org.jboss.arquillian.protocol.jmx.JMXTestRunner] (pool-1-thread-2) Failed: org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.testUnprivilegedWrite: javax.security.auth.login.LoginException: unable to find LoginModule class: com.sun.security.auth.module.Krb5LoginModule
> at javax.security.auth.login.LoginContext.invoke(LoginContext.java:820) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext.access$000(LoginContext.java:215) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:706) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:704) [rt.jar:1.7.0]
> at java.security.AccessController.doPrivileged(AccessController.java:366) [vm.jar:1.7.0]
> at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:703) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext.login(LoginContext.java:609) [rt.jar:1.7.0]
> at org.jboss.security.negotiation.spnego.SPNEGOLoginModule.usernamePasswordLogin(SPNEGOLoginModule.java:218) [jboss-negotiation-spnego-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at org.jboss.security.negotiation.spnego.SPNEGOLoginModule.innerLogin(SPNEGOLoginModule.java:204) [jboss-negotiation-spnego-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at org.jboss.security.negotiation.spnego.SPNEGOLoginModule.login(SPNEGOLoginModule.java:145) [jboss-negotiation-spnego-2.2.10.Final-redhat-1.jar:2.2.10.Final-redhat-1]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94) [rt.jar:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at javax.security.auth.login.LoginContext.invoke(LoginContext.java:781) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext.access$000(LoginContext.java:215) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:706) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext$4.run(LoginContext.java:704) [rt.jar:1.7.0]
> at java.security.AccessController.doPrivileged(AccessController.java:366) [vm.jar:1.7.0]
> at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:703) [rt.jar:1.7.0]
> at javax.security.auth.login.LoginContext.login(LoginContext.java:609) [rt.jar:1.7.0]
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.authenticateWithKrb(AbstractAuthentication.java:69) [classes:]
> at org.infinispan.test.integration.security.embedded.KrbLdapAuthenticationIT.getAdminSubject(KrbLdapAuthenticationIT.java:70) [classes:]
> at org.infinispan.test.integration.security.embedded.AbstractAuthentication.setupCache(AbstractAuthentication.java:100) [classes:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94) [rt.jar:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [arquillian-service:]
> at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [arquillian-service:]
> at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [arquillian-service:]
> at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$StatementLifecycleExecutor.invoke(Arquillian.java:351) [arquillian-service:]
> at org.jboss.arquillian.container.test.impl.execution.BeforeLifecycleEventExecuter.on(BeforeLifecycleEventExecuter.java:35) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94) [rt.jar:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:89) [arquillian-service:]
> at sun.reflect.GeneratedMethodAccessor13.invoke(Unknown Source) [:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:75) [arquillian-service:]
> at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source) [:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:60) [arquillian-service:]
> at sun.reflect.GeneratedMethodAccessor8.invoke(Unknown Source) [:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94) [arquillian-service:]
> at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88) [arquillian-service:]
> at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135) [arquillian-service:]
> at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115) [arquillian-service:]
> at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.before(EventTestRunnerAdaptor.java:95) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:222) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:240) [arquillian-service:]
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [arquillian-service:]
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [arquillian-service:]
> at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [arquillian-service:]
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [arquillian-service:]
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [arquillian-service:]
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [arquillian-service:]
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [arquillian-service:]
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:185) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:199) [arquillian-service:]
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [arquillian-service:]
> at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:147) [arquillian-service:]
> at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [arquillian-service:]
> at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [arquillian-service:]
> at org.jboss.arquillian.junit.container.JUnitTestRunner.execute(JUnitTestRunner.java:65) [arquillian-service:]
> at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethodInternal(JMXTestRunner.java:129) [arquillian-service:]
> at org.jboss.arquillian.protocol.jmx.JMXTestRunner.runTestMethod(JMXTestRunner.java:108) [arquillian-service:]
> at org.jboss.as.arquillian.service.ArquillianService$ExtendedJMXTestRunner.runTestMethod(ArquillianService.java:214) [arquillian-service:]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94) [rt.jar:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:87) [rt.jar:1.7.0]
> at sun.reflect.GeneratedMethodAccessor89.invoke(Unknown Source) [:1.7.0]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) [rt.jar:1.7.0]
> at java.lang.reflect.Method.invoke(Method.java:619) [rt.jar:2.6 (04-10-2014)]
> at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:291) [rt.jar:1.7.0]
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:124) [rt.jar:1.7.0]
> at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:58) [rt.jar:1.7.0]
> at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:249) [rt.jar:1.7.0]
> at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:150) [rt.jar:1.7.0]
> at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:264) [rt.jar:1.7.0]
> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:831) [rt.jar:1.7.0]
> at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:813) [rt.jar:1.7.0]
> at org.jboss.as.jmx.PluggableMBeanServerImpl$TcclMBeanServer.invoke(PluggableMBeanServerImpl.java:1453)
> at org.jboss.as.jmx.PluggableMBeanServerImpl.invoke(PluggableMBeanServerImpl.java:731)
> at org.jboss.remotingjmx.protocol.v2.ServerProxy$InvokeHandler.handle(ServerProxy.java:952)
> at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1$1.run(ServerCommon.java:153)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:75)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor$1.run(ServerInterceptorFactory.java:70)
> at java.security.AccessController.doPrivileged(AccessController.java:366) [vm.jar:1.7.0]
> at javax.security.auth.Subject.doAs(Subject.java:572) [rt.jar:1.7.0]
> at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:94)
> at org.jboss.as.jmx.ServerInterceptorFactory$Interceptor.handleEvent(ServerInterceptorFactory.java:70)
> at org.jboss.remotingjmx.protocol.v2.ServerCommon$MessageReciever$1.run(ServerCommon.java:149)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176) [rt.jar:1.7.0]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [rt.jar:1.7.0]
> at java.lang.Thread.run(Thread.java:853) [vm.jar:1.7.0]
> &#27;[0m
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5876) Pre-commit cache invalidation creates stale cache vulnerability
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5876?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-5876:
-----------------------------------------------
Enrique Gonzalez Martinez <egonzale(a)redhat.com> changed the Status of [bug 1273147|https://bugzilla.redhat.com/show_bug.cgi?id=1273147] from ASSIGNED to POST
> Pre-commit cache invalidation creates stale cache vulnerability
> ---------------------------------------------------------------
>
> Key: ISPN-5876
> URL: https://issues.jboss.org/browse/ISPN-5876
> Project: Infinispan
> Issue Type: Bug
> Components: Eviction
> Affects Versions: 5.2.7.Final
> Reporter: Stephen Fikes
> Assignee: Galder Zamarreño
> Fix For: 5.2.15.Final, 8.1.0.Beta1, 8.1.0.Final
>
>
> In a cluster where Infinispan serves as the level 2 cache for Hibernate (configured for invalidation), because invalidation requests for modified entities are sent *before* database commit, it is possible for nodes receiving the invalidation request to perform eviction and then (due to "local" read requests) reload the evicted entities prior to the time the database commit takes place in the server where the entity was modified.
> Consequently, other servers in the cluster may contain data that remains stale until a subsequent change in another server or until the entity times out from lack of use.
> It isn't easy to write a testcase for this - it required manual intervention to reproduce - but can be seen with any entity class, cluster, etc. (at least using Oracle - results may vary with specific databases) so I've not attached a testcase. The issue can be seen/understood by code inspection (i.e. the timing of invalidation vs. database commit). That said, my test consisted of a two node cluster and I used Byteman rules to delay database commit of a change to an entity (with an optimistic version property) long enough in "server 1" for eviction to complete and a subsequent re-read (by a worker thread on behalf of an EJB) to take place in "server 2". Following the re-read in "server 2", I the database commit proceeds in "server 1" and "server 2" now has a stale copy of the entity in cache.
> One option is pessimistic locking which will block any read attempt until the DB commit completes. It is not feasible, however, for many applications to use pessimistic locking for all reads as this can have a severe impact on concurrency - and is the reason for using optimistic version control. But due to the early timing of invalidation broadcast (*before* database commit, while the data is not yet stale), optimistic locking is insufficient to guard against "permanently" stale data. We did see that some databases default to blocking repeatable reads even outside of transactions and without explicit lock requests. Oracle does not provide such a mode. So, all reads must be implemented to use pessimistic locks (which must be enclosed in explicit transactions - (b)locking reads are disallowed when autocommit=true in Oracle) and this could require significant effort (re-writes) to use pessimistic reads throughout - in addition to the performance issues this can introduce.
> If broadcast of an invalidation message always occurs *after* database commit, optimistic control attributes are sufficient to block attempts to write stale data and though a few failures may occur (as they would in a single server with multiple active threads), it can be known that the stale data will be removed in some finite period.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5884) ClusteredListenerReplTest.testPrimaryOwnerGoesDownAfterBackupRaisesEvent random failures
by Dan Berindei (JIRA)
Dan Berindei created ISPN-5884:
----------------------------------
Summary: ClusteredListenerReplTest.testPrimaryOwnerGoesDownAfterBackupRaisesEvent random failures
Key: ISPN-5884
URL: https://issues.jboss.org/browse/ISPN-5884
Project: Infinispan
Issue Type: Bug
Components: Core, Test Suite - Core
Affects Versions: 8.1.0.Alpha2
Reporter: Dan Berindei
Assignee: Dan Berindei
Priority: Blocker
Fix For: 8.1.0.Beta1
{{ClusteredListenerReplTest}} uses a {{BlockingInterceptor}} to ensure a write command is blocked on the backup owners while the primary owner is killed.
The {{BlockingInterceptor}} is removed after the primary owner was killed, but only on one of the backups. This is enough if the node 0 becomes the primary owner of the key, because the command is retried before the previous invocation is unblocked, and {{BlockingInterceptor}} only blocks one command at a time. But if node 2 becomes the primary owner, the retry happens after the initial command was unblocked, and it blocks in {{BlockingInterceptor}}.
The fix would be to remove the interceptor from both nodes.
I also believe the "block one command at a time" logic should be removed, because it makes tests too dependent on timing.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5883) Node can apply new topology after sending status response
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5883?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5883:
-------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/infinispan/infinispan/pull/3782
> Node can apply new topology after sending status response
> ---------------------------------------------------------
>
> Key: ISPN-5883
> URL: https://issues.jboss.org/browse/ISPN-5883
> Project: Infinispan
> Issue Type: Bug
> Components: Core, Test Suite - Core
> Affects Versions: 8.0.1.Final, 7.2.5.Final, 8.1.0.Alpha2
> Reporter: Dan Berindei
> Priority: Critical
> Labels: testsuite_stability
> Fix For: 8.1.0.Beta1
>
>
> {{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
> This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
> {noformat}
> 22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
> // Topology from NodeC
> 22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
> // Later, topology from NodeA
> 22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
> {noformat}
> As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). We already check that the sender is the current coordinator before applying a topology update, so this will guarantee that the we don't apply other topology updates from the old coordinator. Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5883) Node can apply new topology after sending status response
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5883?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5883:
-------------------------------
Status: Open (was: New)
> Node can apply new topology after sending status response
> ---------------------------------------------------------
>
> Key: ISPN-5883
> URL: https://issues.jboss.org/browse/ISPN-5883
> Project: Infinispan
> Issue Type: Bug
> Components: Core, Test Suite - Core
> Affects Versions: 8.0.1.Final, 7.2.5.Final, 8.1.0.Alpha2
> Reporter: Dan Berindei
> Priority: Critical
> Labels: testsuite_stability
> Fix For: 8.1.0.Beta1
>
>
> {{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
> This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
> {noformat}
> 22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
> // Topology from NodeC
> 22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
> // Later, topology from NodeA
> 22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
> {noformat}
> As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). We already check that the sender is the current coordinator before applying a topology update, so this will guarantee that the we don't apply other topology updates from the old coordinator. Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5883) Node can apply new topology after sending status response
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5883?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5883:
-------------------------------
Description:
{{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
{noformat}
22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
// Topology from NodeC
22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
// Later, topology from NodeA
22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
{noformat}
As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). We already check that the sender is the current coordinator before applying a topology update, so this will guarantee that the we don't apply other topology updates from the old coordinator. Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
was:
{{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
{noformat}
22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
// Topology from NodeC
22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
// Later, topology from NodeA
22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
{noformat}
As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
> Node can apply new topology after sending status response
> ---------------------------------------------------------
>
> Key: ISPN-5883
> URL: https://issues.jboss.org/browse/ISPN-5883
> Project: Infinispan
> Issue Type: Bug
> Components: Core, Test Suite - Core
> Affects Versions: 8.0.1.Final, 7.2.5.Final, 8.1.0.Alpha2
> Reporter: Dan Berindei
> Priority: Critical
> Labels: testsuite_stability
> Fix For: 8.1.0.Beta1
>
>
> {{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
> This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
> {noformat}
> 22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
> // Topology from NodeC
> 22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
> // Later, topology from NodeA
> 22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
> {noformat}
> As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). We already check that the sender is the current coordinator before applying a topology update, so this will guarantee that the we don't apply other topology updates from the old coordinator. Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5883) Node can apply new topology after sending status response
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5883?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5883:
-------------------------------
Description:
{{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
{noformat}
22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
// Topology from NodeC
22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
// Later, topology from NodeA
22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
{noformat}
As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
> Node can apply new topology after sending status response
> ---------------------------------------------------------
>
> Key: ISPN-5883
> URL: https://issues.jboss.org/browse/ISPN-5883
> Project: Infinispan
> Issue Type: Bug
> Components: Core, Test Suite - Core
> Affects Versions: 8.0.1.Final, 7.2.5.Final, 8.1.0.Alpha2
> Reporter: Dan Berindei
> Priority: Critical
> Labels: testsuite_stability
> Fix For: 8.1.0.Beta1
>
>
> {{LocalTopologyManagerImpl}} is responsible for sending the {{ClusterTopologyControlCommand(GET_STATUS)}} response, and when it sends the response it doesn't check the current view id against the new coordinator's view id. If the old coordinator already sent a topology update before the merge, that topology update might be processed after sending the status response. The new coordinator will send a topology update with a topology id of {{max(status response topology ids) + 1}}. The node will then process the topology update from the old coordinator, but it will ignore the topology update from the new coordinator with the same topology id.
> This is extra common in the partition handling tests, because the test "injects" the JGroups view on each node serially, and often the 4th node sends the status response before it gets the new view.
> {noformat}
> 22:16:37,776 DEBUG (remote-thread-NodeD-p26-t6:[]) [LocalTopologyManagerImpl] Sending cluster status response for view 10
> // Topology from NodeC
> 22:16:37,778 DEBUG (transport-thread-NodeD-p28-t2:[]) [LocalTopologyManagerImpl] Updating local topology for cache pes-cache: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeC-46467, NodeD-30486]}
> // Later, topology from NodeA
> 22:16:37,827 DEBUG (transport-thread-NodeD-p28-t1:[]) [LocalTopologyManagerImpl] Ignoring late consistent hash update for cache pes-cache, current topology is 8: CacheTopology{id=8, rebalanceId=3, currentCH=DefaultConsistentHash{ns=60, owners = (4)[NodeA-37631: 15+15, NodeB-47846: 15+15, NodeC-46467: 15+15, NodeD-30486: 15+15]}, pendingCH=null, unionCH=null, actualMembers=[NodeA-37631, NodeB-47846, NodeC-46467, NodeD-30486]}
> {noformat}
> As a solution, we can delay sending the status response until we have the same view as the coordinator (or a later one). Since the status request is only sent after the new view was installed, this will not introduce any delays in the vast majority of cases.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5883) Node can apply new topology after sending status response
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5883?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5883:
-------------------------------
Labels: testsuite_stability (was: )
> Node can apply new topology after sending status response
> ---------------------------------------------------------
>
> Key: ISPN-5883
> URL: https://issues.jboss.org/browse/ISPN-5883
> Project: Infinispan
> Issue Type: Bug
> Components: Core, Test Suite - Core
> Affects Versions: 8.0.1.Final, 7.2.5.Final, 8.1.0.Alpha2
> Reporter: Dan Berindei
> Priority: Critical
> Labels: testsuite_stability
> Fix For: 8.1.0.Beta1
>
>
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5883) Node can apply new topology after sending status response
by Dan Berindei (JIRA)
Dan Berindei created ISPN-5883:
----------------------------------
Summary: Node can apply new topology after sending status response
Key: ISPN-5883
URL: https://issues.jboss.org/browse/ISPN-5883
Project: Infinispan
Issue Type: Bug
Components: Core, Test Suite - Core
Affects Versions: 8.1.0.Alpha2, 7.2.5.Final, 8.0.1.Final
Reporter: Dan Berindei
Priority: Critical
Fix For: 8.1.0.Beta1
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0
[JBoss JIRA] (ISPN-5878) Deprecate MurmurHash2 and remove MurmurHash2Compat
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5878?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5878:
-------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/infinispan/infinispan/pull/3779
> Deprecate MurmurHash2 and remove MurmurHash2Compat
> --------------------------------------------------
>
> Key: ISPN-5878
> URL: https://issues.jboss.org/browse/ISPN-5878
> Project: Infinispan
> Issue Type: Task
> Components: Core
> Affects Versions: 8.0.1.Final
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Fix For: 8.1.0.Beta1, 8.1.0.Final
>
>
> {{MurmurHash3}} was introduced in version 5.0, obsoleting {{MurmurHash2}}.
> {{MurmurHash2Compat}} was only introduced to preserve compatibility with the pre-4.2.1 {{MurmurHash2}} implementation.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
8 years, 7 months
- 1
- 0