[
https://issues.apache.org/jira/browse/GEODE-3738?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16189952#comment-16189952
]
Jared Stewart commented on GEODE-3738:
--------------------------------------
{noformat}
Standard Output
running against these versions: [000, 120, 110, 111, 100]
Previously run tests: [RemoveAllCacheListenerClientServerRegressionTest,
ConnectionPoolAndLoaderDUnitTest, PartitionRegionHelperDUnitTest,
ParallelSnapshotDUnitTest, SnapshotByteArrayDUnitTest, SnapshotDUnitTest,
IntegratedSecurityPeerAuthDistributedTest, ClientMultiUserAuthzDUnitTest,
ClientGetPutAuthDUnitTest, PostProcessorDUnitTest, PDXPostProcessorDUnitTest,
ClientAuthorizationDUnitTest, SecurityManagerLifecycleDistributedTest,
ClientDestroyInvalidateAuthDUnitTest, ClientAuthenticationDUnitTest]
[vm0] [info 2017/10/03 08:41:28.026 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(setupVM)
[vm0] [info 2017/10/03 08:41:28.027 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm0] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(setupVM) (took 0 ms)
[vm1] [info 2017/10/03 08:41:28.027 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(setupVM)
[vm1] [info 2017/10/03 08:41:28.028 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm1] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(setupVM) (took 0 ms)
[vm2] [info 2017/10/03 08:41:28.029 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(setupVM)
[vm2] [info 2017/10/03 08:41:28.029 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Got result: null
[vm2] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(setupVM) (took 0 ms)
[vm3] [info 2017/10/03 08:41:28.031 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(setupVM)
[vm3] [info 2017/10/03 08:41:28.032 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Got result: null
[vm3] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(setupVM) (took 0 ms)
[setup] START TEST ClientAuthenticationDUnitTest.testNoCredentials[0]
[vm0] [info 2017/10/03 08:41:28.047 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$100/503795804.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$100/503795804@670492ac
[vm0] [info 2017/10/03 08:41:28.048 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: false
[vm0] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$100/503795804.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$100/503795804@670492ac
(took 0 ms)
[vm1] [info 2017/10/03 08:41:28.061 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$112/468472380.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$112/468472380@3452fdf
[vm1] [info 2017/10/03 08:41:28.061 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: false
[vm1] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$112/468472380.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$112/468472380@3452fdf
(took 0 ms)
[info 2017/10/03 08:41:28.061 UTC <Test worker> tid=0x13] <ExpectedException
action=add>Connection refused: connect</ExpectedException>
[info 2017/10/03 08:41:28.062 UTC <Test worker> tid=0x13] <ExpectedException
action=add>Connection refused: connect</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.062 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.IgnoredException$2.run
with 0 args on object: "IgnoredException addIgnoredException"
[vm0] [info 2017/10/03 08:41:28.062 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.062 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.062 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm0] from org.apache.geode.test.dunit.IgnoredException$2.run with 0 args on
object: "IgnoredException addIgnoredException" (took 0 ms)
[vm1] [info 2017/10/03 08:41:28.063 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.IgnoredException$2.run
with 0 args on object: "IgnoredException addIgnoredException"
[vm1] [info 2017/10/03 08:41:28.063 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.063 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.063 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm1] from org.apache.geode.test.dunit.IgnoredException$2.run with 0 args on
object: "IgnoredException addIgnoredException" (took 0 ms)
[vm2] [info 2017/10/03 08:41:28.064 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Received method: org.apache.geode.test.dunit.IgnoredException$2.run
with 0 args on object: "IgnoredException addIgnoredException"
[vm2] [info 2017/10/03 08:41:28.064 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm2] [info 2017/10/03 08:41:28.065 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm2] [info 2017/10/03 08:41:28.065 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Got result: null
[vm2] from org.apache.geode.test.dunit.IgnoredException$2.run with 0 args on
object: "IgnoredException addIgnoredException" (took 0 ms)
[vm3] [info 2017/10/03 08:41:28.066 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.IgnoredException$2.run
with 0 args on object: "IgnoredException addIgnoredException"
[vm3] [info 2017/10/03 08:41:28.067 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm3] [info 2017/10/03 08:41:28.067 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>Connection refused:
connect</ExpectedException>
[vm3] [info 2017/10/03 08:41:28.067 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Got result: null
[vm3] from org.apache.geode.test.dunit.IgnoredException$2.run with 0 args on
object: "IgnoredException addIgnoredException" (took 0 ms)
[vm0] [info 2017/10/03 08:41:28.070 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$101/466942107.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$101/466942107@588688bf
[vm0] [info 2017/10/03 08:41:28.070 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm0] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$101/466942107.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$101/466942107@588688bf
(took 0 ms)
[vm1] [info 2017/10/03 08:41:28.073 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$113/1058582297.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$113/1058582297@150954f2
[vm1] [info 2017/10/03 08:41:28.073 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm1] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$113/1058582297.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$113/1058582297@150954f2
(took 0 ms)
[vm2] [info 2017/10/03 08:41:28.085 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$31/516142647.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$31/516142647@6fae3ca5
[vm2] [info 2017/10/03 08:41:28.091 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Got result: null
[vm2] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$31/516142647.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$31/516142647@6fae3ca5
(took 5 ms)
[vm3] [info 2017/10/03 08:41:28.107 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$16/1855010908.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$16/1855010908@493b8619
[vm3] [info 2017/10/03 08:41:28.115 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Got result: null
[vm3] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$16/1855010908.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$16/1855010908@493b8619
(took 6 ms)
[info 2017/10/03 08:41:28.116 UTC <Test worker> tid=0x13] testNoCredentials:
Using scheme: org.apache.geode.security.templates.DummyAuthenticator.create
[info 2017/10/03 08:41:28.116 UTC <Test worker> tid=0x13] testNoCredentials:
Using authenticator:
org.apache.geode.security.templates.DummyAuthenticator.create
[info 2017/10/03 08:41:28.116 UTC <Test worker> tid=0x13] testNoCredentials:
Using authinit: org.apache.geode.security.templates.UserPasswordAuthInit.create
[vm0] [info 2017/10/03 08:41:28.123 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$102/1158334512.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$102/1158334512@3975cee1
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Set the server properties to:
{locators=172.17.0.2[28323],172.17.0.2[21410],
security-client-authenticator=org.apache.geode.security.templates.DummyAuthenticator.create,
security-log-level=finest, mcast-port=0, start-locator=172.17.0.2[28323]}
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Set the java properties to: null
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>org.apache.geode.security.GemFireSecurityException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>java.lang.ClassNotFoundException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>java.io.IOException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>javax.net.ssl.SSLException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.124 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm0] distributed system properties: {start-locator=172.17.0.2[28323],
mcast-port=0, security-log-level=finest, log-level=info,
disable-auto-reconnect=true, enable-cluster-configuration=false,
security-client-authenticator=org.apache.geode.security.templates.DummyAuthenticator.create,
locators=172.17.0.2[28323],172.17.0.2[21410], use-cluster-configuration=false}
[vm0] [info 2017/10/03 08:41:28.129 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Startup Configuration:
[vm0] ### GemFire Properties defined with api ###
[vm0] disable-auto-reconnect=true
[vm0] enable-cluster-configuration=false
[vm0] locators=172.17.0.2[28323],172.17.0.2[21410]
[vm0] log-level=info
[vm0] mcast-port=0
[vm0] security-client-authenticator=********
[vm0] security-log-level=********
[vm0] start-locator=172.17.0.2[28323]
[vm0] use-cluster-configuration=false
[vm0] ### GemFire Properties using default values ###
[vm0] ack-severe-alert-threshold=0
[vm0] ack-wait-threshold=15
[vm0] archive-disk-space-limit=0
[vm0] archive-file-size-limit=0
[vm0] async-distribution-timeout=0
[vm0] async-max-queue-size=8
[vm0] async-queue-timeout=60000
[vm0] bind-address=
[vm0] cache-xml-file=cache.xml
[vm0] cluster-configuration-dir=
[vm0] cluster-ssl-ciphers=any
[vm0] cluster-ssl-enabled=false
[vm0] cluster-ssl-keystore=
[vm0] cluster-ssl-keystore-password=
[vm0] cluster-ssl-keystore-type=
[vm0] cluster-ssl-protocols=any
[vm0] cluster-ssl-require-authentication=true
[vm0] cluster-ssl-truststore=
[vm0] cluster-ssl-truststore-password=
[vm0] conflate-events=server
[vm0] conserve-sockets=true
[vm0] delta-propagation=true
[vm0]
deploy-working-dir=/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-core/build/distributedTest160/dunit/vm0
[vm0] disable-tcp=false
[vm0] distributed-system-id=-1
[vm0] distributed-transactions=false
[vm0] durable-client-id=
[vm0] durable-client-timeout=300
[vm0] enable-network-partition-detection=true
[vm0] enable-time-statistics=false
[vm0] enforce-unique-host=false
[vm0] gateway-ssl-ciphers=any
[vm0] gateway-ssl-enabled=false
[vm0] gateway-ssl-keystore=
[vm0] gateway-ssl-keystore-password=
[vm0] gateway-ssl-keystore-type=
[vm0] gateway-ssl-protocols=any
[vm0] gateway-ssl-require-authentication=true
[vm0] gateway-ssl-truststore=
[vm0] gateway-ssl-truststore-password=
[vm0] groups=
[vm0] http-service-bind-address=
[vm0] http-service-port=7070
[vm0] http-service-ssl-ciphers=any
[vm0] http-service-ssl-enabled=false
[vm0] http-service-ssl-keystore=
[vm0] http-service-ssl-keystore-password=
[vm0] http-service-ssl-keystore-type=
[vm0] http-service-ssl-protocols=any
[vm0] http-service-ssl-require-authentication=false
[vm0] http-service-ssl-truststore=
[vm0] http-service-ssl-truststore-password=
[vm0] jmx-manager=false
[vm0] jmx-manager-access-file=
[vm0] jmx-manager-bind-address=
[vm0] jmx-manager-hostname-for-clients=
[vm0] jmx-manager-http-port=7070
[vm0] jmx-manager-password-file=
[vm0] jmx-manager-port=1099
[vm0] jmx-manager-ssl-ciphers=any
[vm0] jmx-manager-ssl-enabled=false
[vm0] jmx-manager-ssl-keystore=
[vm0] jmx-manager-ssl-keystore-password=
[vm0] jmx-manager-ssl-keystore-type=
[vm0] jmx-manager-ssl-protocols=any
[vm0] jmx-manager-ssl-require-authentication=true
[vm0] jmx-manager-ssl-truststore=
[vm0] jmx-manager-ssl-truststore-password=
[vm0] jmx-manager-start=false
[vm0] jmx-manager-update-rate=2000
[vm0] load-cluster-configuration-from-dir=false
[vm0] locator-wait-time=0
[vm0] lock-memory=false
[vm0] log-disk-space-limit=0
[vm0] log-file=
[vm0] log-file-size-limit=0
[vm0] max-num-reconnect-tries=3
[vm0] max-wait-time-reconnect=60000
[vm0] mcast-address=239.192.81.1
[vm0] mcast-flow-control=1048576, 0.25, 5000
[vm0] mcast-recv-buffer-size=1048576
[vm0] mcast-send-buffer-size=65535
[vm0] mcast-ttl=32
[vm0] member-timeout=5000
[vm0] membership-port-range=32769-61000
[vm0] memcached-bind-address=
[vm0] memcached-port=0
[vm0] memcached-protocol=ASCII
[vm0] name=
[vm0] off-heap-memory-size=
[vm0] redis-bind-address=
[vm0] redis-password=
[vm0] redis-port=0
[vm0] redundancy-zone=
[vm0] remote-locators=
[vm0] remove-unresponsive-client=false
[vm0] roles=
[vm0] security-client-accessor=
[vm0] security-client-accessor-pp=
[vm0] security-client-auth-init=
[vm0] security-client-dhalgo=
[vm0] security-log-file=
[vm0] security-manager=
[vm0] security-peer-auth-init=
[vm0] security-peer-authenticator=
[vm0] security-peer-verifymember-timeout=1000
[vm0] security-post-processor=
[vm0] security-udp-dhalgo=
[vm0] server-bind-address=
[vm0] server-ssl-ciphers=any
[vm0] server-ssl-enabled=false
[vm0] server-ssl-keystore=
[vm0] server-ssl-keystore-password=
[vm0] server-ssl-keystore-type=
[vm0] server-ssl-protocols=any
[vm0] server-ssl-require-authentication=true
[vm0] server-ssl-truststore=
[vm0] server-ssl-truststore-password=
[vm0] socket-buffer-size=32768
[vm0] socket-lease-time=60000
[vm0] ssl-ciphers=any
[vm0] ssl-cluster-alias=
[vm0] ssl-default-alias=
[vm0] ssl-enabled-components=
[vm0] ssl-gateway-alias=
[vm0] ssl-jmx-alias=
[vm0] ssl-keystore=
[vm0] ssl-keystore-password=
[vm0] ssl-keystore-type=
[vm0] ssl-locator-alias=
[vm0] ssl-protocols=any
[vm0] ssl-require-authentication=true
[vm0] ssl-server-alias=
[vm0] ssl-truststore=
[vm0] ssl-truststore-password=
[vm0] ssl-truststore-type=
[vm0] ssl-web-alias=
[vm0] ssl-web-require-authentication=false
[vm0] start-dev-rest-api=false
[vm0] statistic-archive-file=
[vm0] statistic-sample-rate=1000
[vm0] statistic-sampling-enabled=true
[vm0] tcp-port=0
[vm0] udp-fragment-size=60000
[vm0] udp-recv-buffer-size=1048576
[vm0] udp-send-buffer-size=65535
[vm0] user-command-packages=
[vm0] [debug 2017/10/03 08:41:28.129 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] skipping banner - Locator.inhibitDMBanner is set to true
[vm0] [debug 2017/10/03 08:41:28.129 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] SecurityLogWriter is created.
[vm0] [warn 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] There is no ClientProtocolMessageHandler implementation found in JVM
[vm0] [info 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting peer location for Distribution Locator on /172.17.0.2
[vm0] [info 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting Distribution Locator on /172.17.0.2
[vm0] [info 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Locator was created at Tue Oct 03 08:41:28 UTC 2017
[vm0] [info 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Listening on port 28323 bound on address /172.17.0.2
[vm0] [info 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GemFire peer location service starting. Other locators:
172.17.0.2[28323],172.17.0.2[21410] Locators preferred as coordinators: true
Network partition detection enabled: true View persistence file:
locator28323view.dat
[vm0] [info 2017/10/03 08:41:28.133 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator attempting to recover from /172.17.0.2:28323
[vm0] [info 2017/10/03 08:41:28.135 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator was unable to recover state from this locator
[vm0] [info 2017/10/03 08:41:28.135 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator attempting to recover from /172.17.0.2:21410
[vm0] [info 2017/10/03 08:41:28.136 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator was unable to recover state from this locator
[vm0] [info 2017/10/03 08:41:28.136 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] recovery file not found:
/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-core/build/distributedTest160/dunit/vm0/locator28323view.dat
[vm0] [info 2017/10/03 08:41:28.137 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting membership services
[vm0] [info 2017/10/03 08:41:28.146 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] JGroups channel created (took 9ms)
[vm0] [info 2017/10/03 08:41:28.147 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GemFire P2P Listener started on /172.17.0.2:46615
[vm0] [info 2017/10/03 08:41:28.147 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] This member is hosting a locator will be preferred as a membership
coordinator
[vm0] [info 2017/10/03 08:41:28.148 UTC <Geode Failure Detection Server thread
0> tid=0x33c5] Started failure detection server thread on /172.17.0.2:34089.
[vm0] [info 2017/10/03 08:41:28.148 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator is connecting to local membership services with ID
172.17.0.2(166)<ec>:32770
[vm0] [info 2017/10/03 08:41:28.149 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] This member is becoming the membership coordinator with address
172.17.0.2(166)<ec>:32770
[vm0] [info 2017/10/03 08:41:28.149 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] received new view: View[172.17.0.2(166)<ec><v0>:32770|0] members:
[172.17.0.2(166)<ec><v0>:32770{lead}]
[vm0] old view is: null
[vm0] [info 2017/10/03 08:41:28.149 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator received new membership view:
View[172.17.0.2(166)<ec><v0>:32770|0] members:
[172.17.0.2(166)<ec><v0>:32770{lead}]
[vm0] [info 2017/10/03 08:41:28.150 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] ViewCreator starting on:172.17.0.2(166)<ec><v0>:32770
[vm0] [info 2017/10/03 08:41:28.150 UTC <Geode Membership View Creator>
tid=0x33c8] View Creator thread is starting
[vm0] [info 2017/10/03 08:41:28.150 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Finished joining (took 2ms).
[vm0] [info 2017/10/03 08:41:28.151 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting DistributionManager 172.17.0.2(166)<ec><v0>:32770. (took 14
ms)
[vm0] [info 2017/10/03 08:41:28.151 UTC <Geode Membership View Creator>
tid=0x33c8] no recipients for new view aside from myself
[vm0] [info 2017/10/03 08:41:28.151 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initial (distribution manager) view =
View[172.17.0.2(166)<ec><v0>:32770|0] members:
[172.17.0.2(166)<ec><v0>:32770{lead}]
[vm0] [info 2017/10/03 08:41:28.151 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Admitting member <172.17.0.2(166)<ec><v0>:32770>. Now there are 1
non-admin member(s).
[vm0] [info 2017/10/03 08:41:28.152 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] 172.17.0.2(166)<ec><v0>:32770 is the elder and the only member.
[vm0] [info 2017/10/03 08:41:28.152 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Did not hear back from any other system. I am the first one.
[vm0] [info 2017/10/03 08:41:28.152 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting server location for Distribution Locator on
/172.17.0.2[28323]
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>org.apache.geode.security.GemFireSecurityException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>java.lang.ClassNotFoundException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>java.io.IOException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>javax.net.ssl.SSLException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.156 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm0] [info 2017/10/03 08:41:28.161 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Requesting cluster configuration
[vm0] [info 2017/10/03 08:41:28.161 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initializing region _monitoringRegion_172.17.0.2<v0>32770
[vm0] [info 2017/10/03 08:41:28.161 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initialization of region _monitoringRegion_172.17.0.2<v0>32770
completed
[vm0] 734.321: [GC (Allocation Failure) [PSYoungGen: 103196K->3099K(105984K)]
325226K->225593K(455680K), 0.0147168 secs] [Times: user=0.14 sys=0.00,
real=0.02 secs]
[vm0] [info 2017/10/03 08:41:28.281 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Loading previously deployed jars
[vm0] [info 2017/10/03 08:41:28.282 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initializing region PdxTypes
[vm0] [info 2017/10/03 08:41:28.282 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initialization of region PdxTypes completed
[vm0] [info 2017/10/03 08:41:28.282 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initializing region AuthRegion
[vm0] [info 2017/10/03 08:41:28.282 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initialization of region AuthRegion completed
[vm0] [info 2017/10/03 08:41:28.283 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Cache server connection listener bound to address
2d21656aaf6b-0.0.0.0/0.0.0.0:33942 with backlog 1,000.
[vm0] [info 2017/10/03 08:41:28.283 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] ClientHealthMonitorThread maximum allowed time between pings: 60,000
[vm0] [info 2017/10/03 08:41:28.285 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] CacheServer Configuration: port=33942 max-connections=800
max-threads=0 notify-by-subscription=true socket-buffer-size=32768
maximum-time-between-pings=60000 maximum-message-count=230000
message-time-to-live=180 eviction-policy=none capacity=1 overflow directory=.
groups=[] loadProbe=ConnectionCountProbe loadPollInterval=5000 tcpNoDelay=true
[vm0] [info 2017/10/03 08:41:28.285 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: 33942
[vm0] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$102/1158334512.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$102/1158334512@3975cee1
(took 162 ms)
[vm1] [info 2017/10/03 08:41:28.293 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$114/1604271970.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$114/1604271970@7ddc9111
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Set the server properties to:
{locators=172.17.0.2[28323],172.17.0.2[21410],
security-client-authenticator=org.apache.geode.security.templates.DummyAuthenticator.create,
security-log-level=finest, mcast-port=0, start-locator=172.17.0.2[21410]}
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Set the java properties to: null
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>org.apache.geode.security.GemFireSecurityException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>java.lang.ClassNotFoundException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>java.io.IOException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>javax.net.ssl.SSLException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.294 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=remove>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm1] distributed system properties: {start-locator=172.17.0.2[21410],
mcast-port=0, security-log-level=finest, log-level=info,
disable-auto-reconnect=true, enable-cluster-configuration=false,
security-client-authenticator=org.apache.geode.security.templates.DummyAuthenticator.create,
locators=172.17.0.2[28323],172.17.0.2[21410], use-cluster-configuration=false}
[vm1] [info 2017/10/03 08:41:28.299 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Startup Configuration:
[vm1] ### GemFire Properties defined with api ###
[vm1] disable-auto-reconnect=true
[vm1] enable-cluster-configuration=false
[vm1] locators=172.17.0.2[28323],172.17.0.2[21410]
[vm1] log-level=info
[vm1] mcast-port=0
[vm1] security-client-authenticator=********
[vm1] security-log-level=********
[vm1] start-locator=172.17.0.2[21410]
[vm1] use-cluster-configuration=false
[vm1] ### GemFire Properties using default values ###
[vm1] ack-severe-alert-threshold=0
[vm1] ack-wait-threshold=15
[vm1] archive-disk-space-limit=0
[vm1] archive-file-size-limit=0
[vm1] async-distribution-timeout=0
[vm1] async-max-queue-size=8
[vm1] async-queue-timeout=60000
[vm1] bind-address=
[vm1] cache-xml-file=cache.xml
[vm1] cluster-configuration-dir=
[vm1] cluster-ssl-ciphers=any
[vm1] cluster-ssl-enabled=false
[vm1] cluster-ssl-keystore=
[vm1] cluster-ssl-keystore-password=
[vm1] cluster-ssl-keystore-type=
[vm1] cluster-ssl-protocols=any
[vm1] cluster-ssl-require-authentication=true
[vm1] cluster-ssl-truststore=
[vm1] cluster-ssl-truststore-password=
[vm1] conflate-events=server
[vm1] conserve-sockets=true
[vm1] delta-propagation=true
[vm1]
deploy-working-dir=/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-core/build/distributedTest160/dunit/vm1
[vm1] disable-tcp=false
[vm1] distributed-system-id=-1
[vm1] distributed-transactions=false
[vm1] durable-client-id=
[vm1] durable-client-timeout=300
[vm1] enable-network-partition-detection=true
[vm1] enable-time-statistics=false
[vm1] enforce-unique-host=false
[vm1] gateway-ssl-ciphers=any
[vm1] gateway-ssl-enabled=false
[vm1] gateway-ssl-keystore=
[vm1] gateway-ssl-keystore-password=
[vm1] gateway-ssl-keystore-type=
[vm1] gateway-ssl-protocols=any
[vm1] gateway-ssl-require-authentication=true
[vm1] gateway-ssl-truststore=
[vm1] gateway-ssl-truststore-password=
[vm1] groups=
[vm1] http-service-bind-address=
[vm1] http-service-port=7070
[vm1] http-service-ssl-ciphers=any
[vm1] http-service-ssl-enabled=false
[vm1] http-service-ssl-keystore=
[vm1] http-service-ssl-keystore-password=
[vm1] http-service-ssl-keystore-type=
[vm1] http-service-ssl-protocols=any
[vm1] http-service-ssl-require-authentication=false
[vm1] http-service-ssl-truststore=
[vm1] http-service-ssl-truststore-password=
[vm1] jmx-manager=false
[vm1] jmx-manager-access-file=
[vm1] jmx-manager-bind-address=
[vm1] jmx-manager-hostname-for-clients=
[vm1] jmx-manager-http-port=7070
[vm1] jmx-manager-password-file=
[vm1] jmx-manager-port=1099
[vm1] jmx-manager-ssl-ciphers=any
[vm1] jmx-manager-ssl-enabled=false
[vm1] jmx-manager-ssl-keystore=
[vm1] jmx-manager-ssl-keystore-password=
[vm1] jmx-manager-ssl-keystore-type=
[vm1] jmx-manager-ssl-protocols=any
[vm1] jmx-manager-ssl-require-authentication=true
[vm1] jmx-manager-ssl-truststore=
[vm1] jmx-manager-ssl-truststore-password=
[vm1] jmx-manager-start=false
[vm1] jmx-manager-update-rate=2000
[vm1] load-cluster-configuration-from-dir=false
[vm1] locator-wait-time=0
[vm1] lock-memory=false
[vm1] log-disk-space-limit=0
[vm1] log-file=
[vm1] log-file-size-limit=0
[vm1] max-num-reconnect-tries=3
[vm1] max-wait-time-reconnect=60000
[vm1] mcast-address=239.192.81.1
[vm1] mcast-flow-control=1048576, 0.25, 5000
[vm1] mcast-recv-buffer-size=1048576
[vm1] mcast-send-buffer-size=65535
[vm1] mcast-ttl=32
[vm1] member-timeout=5000
[vm1] membership-port-range=32769-61000
[vm1] memcached-bind-address=
[vm1] memcached-port=0
[vm1] memcached-protocol=ASCII
[vm1] name=
[vm1] off-heap-memory-size=
[vm1] redis-bind-address=
[vm1] redis-password=
[vm1] redis-port=0
[vm1] redundancy-zone=
[vm1] remote-locators=
[vm1] remove-unresponsive-client=false
[vm1] roles=
[vm1] security-client-accessor=
[vm1] security-client-accessor-pp=
[vm1] security-client-auth-init=
[vm1] security-client-dhalgo=
[vm1] security-log-file=
[vm1] security-manager=
[vm1] security-peer-auth-init=
[vm1] security-peer-authenticator=
[vm1] security-peer-verifymember-timeout=1000
[vm1] security-post-processor=
[vm1] security-udp-dhalgo=
[vm1] server-bind-address=
[vm1] server-ssl-ciphers=any
[vm1] server-ssl-enabled=false
[vm1] server-ssl-keystore=
[vm1] server-ssl-keystore-password=
[vm1] server-ssl-keystore-type=
[vm1] server-ssl-protocols=any
[vm1] server-ssl-require-authentication=true
[vm1] server-ssl-truststore=
[vm1] server-ssl-truststore-password=
[vm1] socket-buffer-size=32768
[vm1] socket-lease-time=60000
[vm1] ssl-ciphers=any
[vm1] ssl-cluster-alias=
[vm1] ssl-default-alias=
[vm1] ssl-enabled-components=
[vm1] ssl-gateway-alias=
[vm1] ssl-jmx-alias=
[vm1] ssl-keystore=
[vm1] ssl-keystore-password=
[vm1] ssl-keystore-type=
[vm1] ssl-locator-alias=
[vm1] ssl-protocols=any
[vm1] ssl-require-authentication=true
[vm1] ssl-server-alias=
[vm1] ssl-truststore=
[vm1] ssl-truststore-password=
[vm1] ssl-truststore-type=
[vm1] ssl-web-alias=
[vm1] ssl-web-require-authentication=false
[vm1] start-dev-rest-api=false
[vm1] statistic-archive-file=
[vm1] statistic-sample-rate=1000
[vm1] statistic-sampling-enabled=true
[vm1] tcp-port=0
[vm1] udp-fragment-size=60000
[vm1] udp-recv-buffer-size=1048576
[vm1] udp-send-buffer-size=65535
[vm1] user-command-packages=
[vm1] [debug 2017/10/03 08:41:28.299 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] skipping banner - Locator.inhibitDMBanner is set to true
[vm1] [debug 2017/10/03 08:41:28.300 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] SecurityLogWriter is created.
[vm1] [warn 2017/10/03 08:41:28.311 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] There is no ClientProtocolMessageHandler implementation found in JVM
[vm1] [info 2017/10/03 08:41:28.312 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting peer location for Distribution Locator on /172.17.0.2
[vm1] [info 2017/10/03 08:41:28.315 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting Distribution Locator on /172.17.0.2
[vm1] [info 2017/10/03 08:41:28.315 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Locator was created at Tue Oct 03 08:41:28 UTC 2017
[vm1] [info 2017/10/03 08:41:28.315 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Listening on port 21410 bound on address /172.17.0.2
[vm1] [info 2017/10/03 08:41:28.316 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GemFire peer location service starting. Other locators:
172.17.0.2[28323],172.17.0.2[21410] Locators preferred as coordinators: true
Network partition detection enabled: true View persistence file:
locator21410view.dat
[vm1] [info 2017/10/03 08:41:28.316 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator attempting to recover from /172.17.0.2:28323
[vm1] [info 2017/10/03 08:41:28.318 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator recovered initial membership of
View[172.17.0.2(166)<ec><v0>:32770|0] members:
[172.17.0.2(166)<ec><v0>:32770{lead}]
[vm1] [info 2017/10/03 08:41:28.318 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator recovered state from LocatorAddress
[socketInetAddress=/172.17.0.2:28323, hostname=172.17.0.2, isIpString=true]
[vm1] [info 2017/10/03 08:41:28.320 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting membership services
[vm1] [info 2017/10/03 08:41:28.330 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] JGroups channel created (took 10ms)
[vm1] [info 2017/10/03 08:41:28.331 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GemFire P2P Listener started on /172.17.0.2:53736
[vm1] [info 2017/10/03 08:41:28.331 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] This member is hosting a locator will be preferred as a membership
coordinator
[vm1] [info 2017/10/03 08:41:28.332 UTC <Geode Failure Detection Server thread
0> tid=0x2f3a] Started failure detection server thread on /172.17.0.2:56722.
[vm1] [info 2017/10/03 08:41:28.332 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Peer locator is connecting to local membership services with ID
172.17.0.2(170)<ec>:32771
[vm0] [info 2017/10/03 08:41:28.333 UTC <locator request thread[1]> tid=0x33b6]
This member is becoming coordinator
[vm1] [info 2017/10/03 08:41:28.338 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Attempting to join the distributed system through coordinator
172.17.0.2(166)<ec><v0>:32770 using address 172.17.0.2(170)<ec>:32771
[vm0] [info 2017/10/03 08:41:28.339 UTC <unicast receiver,2d21656aaf6b-1666>
tid=0x33c1] received join request from 172.17.0.2(170)<ec>:32771
[vm0] [info 2017/10/03 08:41:28.639 UTC <Geode Membership View Creator>
tid=0x33c8] View Creator is processing 1 requests for the next membership view
[vm0] [info 2017/10/03 08:41:28.640 UTC <Geode Membership View Creator>
tid=0x33c8] preparing new view View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm1] [info 2017/10/03 08:41:28.641 UTC <unicast receiver,2d21656aaf6b-35619>
tid=0x2f36] received new view: View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm1] old view is: null
[vm1] [info 2017/10/03 08:41:28.641 UTC <unicast receiver,2d21656aaf6b-35619>
tid=0x2f36] Peer locator received new membership view:
View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm1] [info 2017/10/03 08:41:28.642 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Finished joining (took 310ms).
[vm1] [info 2017/10/03 08:41:28.642 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting DistributionManager 172.17.0.2(170)<ec><v1>:32771. (took
323 ms)
[vm0] [info 2017/10/03 08:41:28.642 UTC <Geode Membership View Creator>
tid=0x33c8] finished waiting for responses to view preparation
[vm0] [info 2017/10/03 08:41:28.643 UTC <Geode Membership View Creator>
tid=0x33c8] received new view: View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm0] old view is: View[172.17.0.2(166)<ec><v0>:32770|0] members:
[172.17.0.2(166)<ec><v0>:32770{lead}]
[vm0] [info 2017/10/03 08:41:28.643 UTC <Geode Membership View Creator>
tid=0x33c8] Peer locator received new membership view:
View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm1] [info 2017/10/03 08:41:28.643 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initial (distribution manager) view =
View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm1] [info 2017/10/03 08:41:28.643 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Admitting member <172.17.0.2(166)<ec><v0>:32770>. Now there are 1
non-admin member(s).
[vm1] [info 2017/10/03 08:41:28.643 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Admitting member <172.17.0.2(170)<ec><v1>:32771>. Now there are 2
non-admin member(s).
[vm0] [info 2017/10/03 08:41:28.645 UTC <Geode Membership View Creator>
tid=0x33c8] sending new view View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm0] [info 2017/10/03 08:41:28.645 UTC <View Message Processor> tid=0x33ea]
Membership: Processing addition < 172.17.0.2(170)<ec><v1>:32771 >
[vm0] [info 2017/10/03 08:41:28.645 UTC <View Message Processor> tid=0x33ea]
Admitting member <172.17.0.2(170)<ec><v1>:32771>. Now there are 2 non-admin
member(s).
[vm0] [info 2017/10/03 08:41:28.650 UTC <Pooled High Priority Message Processor
1> tid=0x33ec] Member 172.17.0.2(170)<ec><v1>:32771 is equivalent or in the
same redundancy zone.
[vm1] [info 2017/10/03 08:41:28.653 UTC <P2P message reader for
172.17.0.2(166)<ec><v0>:32770 shared unordered uid=682 port=47058> tid=0x2f42]
Member 172.17.0.2(166)<ec><v0>:32770 is equivalent or in the same redundancy
zone.
[vm1] [info 2017/10/03 08:41:28.653 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Starting server location for Distribution Locator on
/172.17.0.2[21410]
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>org.apache.geode.security.GemFireSecurityException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>java.lang.ClassNotFoundException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=add>java.io.IOException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>javax.net.ssl.SSLException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.667 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException
action=add>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm1] [info 2017/10/03 08:41:28.674 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Requesting cluster configuration
[vm1] [info 2017/10/03 08:41:28.676 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initializing region _monitoringRegion_172.17.0.2<v1>32771
[vm1] [info 2017/10/03 08:41:28.677 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initialization of region _monitoringRegion_172.17.0.2<v1>32771
completed
[vm1] 734.796: [GC (Allocation Failure) [PSYoungGen: 125505K->4350K(123904K)]
316535K->196271K(473600K), 0.0151533 secs] [Times: user=0.04 sys=0.05,
real=0.02 secs]
[vm1] [info 2017/10/03 08:41:28.829 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Loading previously deployed jars
[vm1] [info 2017/10/03 08:41:28.830 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initializing region PdxTypes
[vm1] [info 2017/10/03 08:41:28.833 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Region PdxTypes requesting initial image from
172.17.0.2(166)<ec><v0>:32770
[vm1] [info 2017/10/03 08:41:28.834 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] PdxTypes is done getting image from 172.17.0.2(166)<ec><v0>:32770.
isDeltaGII is false
[vm1] [info 2017/10/03 08:41:28.834 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initialization of region PdxTypes completed
[vm1] [info 2017/10/03 08:41:28.836 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initializing region AuthRegion
[vm1] [info 2017/10/03 08:41:28.838 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Region AuthRegion requesting initial image from
172.17.0.2(166)<ec><v0>:32770
[vm1] [info 2017/10/03 08:41:28.838 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] AuthRegion is done getting image from 172.17.0.2(166)<ec><v0>:32770.
isDeltaGII is false
[vm1] [info 2017/10/03 08:41:28.838 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Initialization of region AuthRegion completed
[vm1] [info 2017/10/03 08:41:28.843 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Cache server connection listener bound to address
2d21656aaf6b-0.0.0.0/0.0.0.0:32835 with backlog 1,000.
[vm1] [info 2017/10/03 08:41:28.843 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] ClientHealthMonitorThread maximum allowed time between pings: 60,000
[vm1] [info 2017/10/03 08:41:28.847 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] CacheServer Configuration: port=32835 max-connections=800
max-threads=0 notify-by-subscription=true socket-buffer-size=32768
maximum-time-between-pings=60000 maximum-message-count=230000
message-time-to-live=180 eviction-policy=none capacity=1 overflow directory=.
groups=[] loadProbe=ConnectionCountProbe loadPollInterval=5000 tcpNoDelay=true
[vm1] [info 2017/10/03 08:41:28.848 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: 32835
[vm1] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$114/1604271970.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$114/1604271970@7ddc9111
(took 554 ms)
[info 2017/10/03 08:41:28.848 UTC <Test worker> tid=0x13] testNoCredentials:
For first client credentials: {security-username=user0,
security-password=user0} : null
[vm2] [info 2017/10/03 08:41:28.860 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$32/1872203448.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$32/1872203448@26ca6d2a
[vm2] [info 2017/10/03 08:41:28.862 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException
action=remove>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm2] [info 2017/10/03 08:41:28.862 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException
action=remove>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm2] [info 2017/10/03 08:41:28.862 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException
action=remove>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm2] distributed system properties:
{security-client-auth-init=org.apache.geode.security.templates.UserPasswordAuthInit.create,
security-username=user0, mcast-port=0, security-log-level=finest,
log-level=info, security-password=user0, disable-auto-reconnect=true,
enable-cluster-configuration=false, locators=, use-cluster-configuration=false}
[vm2] [debug 2017/10/03 08:41:29.028 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] skipping banner - Locator.inhibitDMBanner is set to true
[vm2] [debug 2017/10/03 08:41:29.028 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] SecurityLogWriter is created.
[vm2] [info 2017/10/03 08:41:29.033 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException
action=add>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm2] [info 2017/10/03 08:41:29.033 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException
action=add>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm2] [info 2017/10/03 08:41:29.033 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] <ExpectedException
action=add>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm2] [info 2017/10/03 08:41:29.038 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Updating membership port. Port changed from 0 to 55,772. ID is now
2d21656aaf6b(17376:loner):0:c4a665e1
[vm0] [info 2017/10/03 08:41:29.082 UTC <Handshaker 0.0.0.0/0.0.0.0:33942
Thread 0> tid=0x33f1] Initializing region
_gfe_non_durable_client_with_id_172.17.0.2(17376:loner):55772:c4a665e1_1_queue
[vm0] [info 2017/10/03 08:41:29.083 UTC <Handshaker 0.0.0.0/0.0.0.0:33942
Thread 0> tid=0x33f1] Initialization of region
_gfe_non_durable_client_with_id_172.17.0.2(17376:loner):55772:c4a665e1_1_queue
completed
[vm0] [info 2017/10/03 08:41:29.085 UTC <Handshaker 0.0.0.0/0.0.0.0:33942
Thread 0> tid=0x33f1] Entry expiry tasks disabled because the queue became
primary. Old messageTimeToLive was: 180
[vm0] [debug 2017/10/03 08:41:29.085 UTC <Handshaker 0.0.0.0/0.0.0.0:33942
Thread 0> tid=0x33f1] CacheClientNotifier: verifying credentials for proxyID:
identity(172.17.0.2(17376:loner):55772:c4a665e1,connection=1
[vm0] [debug 2017/10/03 08:41:29.085 UTC <Handshaker 0.0.0.0/0.0.0.0:33942
Thread 0> tid=0x33f1] CacheClientNotifier: successfully verified credentials
for proxyID: identity(172.17.0.2(17376:loner):55772:c4a665e1,connection=1
having principal: user0
[vm2] [info 2017/10/03 08:41:29.085 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Pool testPool started with multiuser-authentication=false
[vm2] [info 2017/10/03 08:41:29.099 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Running in client mode
[vm2] [info 2017/10/03 08:41:29.102 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Requesting cluster configuration
[vm2] [info 2017/10/03 08:41:29.104 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Loading previously deployed jars
[vm2] [info 2017/10/03 08:41:29.124 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] multi-user mode false
[vm2] [info 2017/10/03 08:41:29.124 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Got expected UnsupportedOperationException in single-user mode
[vm2] [info 2017/10/03 08:41:29.178 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Got result: null
[vm2] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$32/1872203448.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$32/1872203448@26ca6d2a
(took 317 ms)
[vm2] [info 2017/10/03 08:41:29.183 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$34/143397573.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$34/143397573@3f68f189
[vm2] [info 2017/10/03 08:41:29.247 UTC <RMI TCP Connection(5)-172.17.0.2>
tid=0x24] Got result: null
[vm2] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$34/143397573.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$34/143397573@3f68f189
(took 63 ms)
[vm3] [info 2017/10/03 08:41:29.258 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$17/1871183723.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$17/1871183723@3b4ed966
[vm3] [info 2017/10/03 08:41:29.261 UTC
...[truncated 7400500 chars]...
ce/Geode-nightly/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-core/2.8.2/979fc0cf8460302e4ffbfe38c1b66a99450b0bb7/log4j-core-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-webapp/9.3.10.v20160621/d12bfc3e4e8cce8ecc07c2ef1085223968853fd4/jetty-webapp-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-core/4.3.6.RELEASE/690da099c3c2d2536210f0fd06ff3f336de43ad9/spring-core-4.3.6.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework.shell/spring-shell/1.2.0.RELEASE/d94047721f292bd5334b5654e8600cef4b845049/spring-shell-1.2.0.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.iq80.snappy/snappy/0.4/a42b2d92a89efd35bb14738000dabcac6bd07a8d/snappy-0.4.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.shiro/shiro-core/1.3.2/b5dede9d890f335998a8ebf479809fe365b927fc/shiro-core-1.3.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/commons-beanutils/commons-beanutils/1.9.3/c845703de334ddc6b4b3cd26835458cb1cba1f3d/commons-beanutils-1.9.3.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/io.github.lukehutch/fast-classpath-scanner/2.0.11/ae34a7a5e6de8ad1f86e12f6f7ae1869fcfe9987/fast-classpath-scanner-2.0.11.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-common/build/libs/geode-common-1.3.0-SNAPSHOT.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-json/build/libs/geode-json-1.3.0-SNAPSHOT.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.fusesource.jansi/jansi/1.14/38ce7f9fb0171cd20f9acfd13858751d0fb0d3e2/jansi-1.14.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-slf4j-impl/2.8.2/36bc2a99b86be26ccdc51fe288458dc712d280c1/log4j-slf4j-impl-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-jcl/2.8.2/3e3fb203422887b4a2f06d55c1344f96a0098694/log4j-jcl-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-jul/2.8.2/569ebeb8507e4ca8f9a47a0e441452e2154f5ea3/log4j-jul-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.github.stefanbirkner/system-rules/1.16.1/cb9e42b003d0668f6445505c0f81dd9a244a05d5/system-rules-1.16.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.google.code.tempus-fugit/tempus-fugit/1.1/4f47af53091985a3e3581af60e432a556a69e2cd/tempus-fugit-1.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.awaitility/awaitility/2.0.0/d819d01d141e1fe67f40c432bded9244a14ad659/awaitility-2.0.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/edu.umd.cs.mtc/multithreadedtc/1.01/43fbc1110d7e43cf79e415ef32036975ad85944c/multithreadedtc-1.01.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/eu.codearte.catch-exception/catch-exception/1.4.4/c54da7072e0ccaf1fb92118e5e6e24335039006e/catch-exception-1.4.4.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/eu.codearte.catch-exception/catch-throwable/1.4.4/e152e6679c9e57934cbf4126214e324c55603f82/catch-throwable-1.4.4.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/junit/junit/4.12/2973d150c0dc1fefe998f834810d68f278ea58ec/junit-4.12.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.assertj/assertj-core/3.6.2/cfdf0dedb199f951143b33667a9962cc2b470dec/assertj-core-3.6.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.hamcrest/hamcrest-all/1.3/63a21ebc981131004ad02e0434e799fd7f3a8d5a/hamcrest-all-1.3.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.jmock/jmock-junit4/2.8.2/7ee078b83538f1ced885a347537fe463866b3195/jmock-junit4-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.jmock/jmock-legacy/2.8.2/14c09ac094f72682ec96185ffa085f1fa392abf3/jmock-legacy-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.mockito/mockito-core/2.8.9/1afb35b2d77d40567756c379e54c18da3574a96e/mockito-core-2.8.9.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-core/1.7.1/590d998f70a97c66d32ff5f1f040f308decbdd0c/powermock-core-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-module-junit4/1.7.1/b68666adbfc6a282a231f3af7a593aad3ee0e002/powermock-module-junit4-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-api-mockito2/1.7.1/957158530a6e4552fa3addc979d62dcf3e1b1c74/powermock-api-mockito2-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/pl.pragmatists/JUnitParams/1.0.6/8635e8c7bc312eb73bdad7b5578d84699d21ed45/JUnitParams-1.0.6.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-junit/build/libs/geode-junit-1.3.0-SNAPSHOT.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-old-versions/build/libs/geode-old-versions-1.3.0-SNAPSHOT.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.jayway.jsonpath/json-path-assert/2.2.0/120f64646a7f59b15743ee027330664028b3f4d5/json-path-assert-2.2.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.bcel/bcel/6.0/7d08bcac4832f81467d3e2ca5bd58ad627288656/bcel-6.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/net.spy/spymemcached/2.12.2/9786deb5c7e92ba2b8f6342cc2d043b6991de757/spymemcached-2.12.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/redis.clients/jedis/2.9.0/292bc9cc26553acd3cccc26f2f95620bf88a04c2/jedis-2.9.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-test/4.3.6.RELEASE/233edfdbe5f895cd6585001ef30122e5604442b4/spring-test-4.3.6.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.pholser/junit-quickcheck-core/0.7/e2da071d31b3beedf98e83cebbcf4bb995bf683d/junit-quickcheck-core-0.7.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.pholser/junit-quickcheck-generators/0.7/e70dfac8d2da940cd4714ead5e5ac750864c0cd/junit-quickcheck-generators-0.7.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.pholser/junit-quickcheck-guava/0.7/a15a7f95e978edd608e57a0a5d5212115bd94b59/junit-quickcheck-guava-0.7.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/cglib/cglib/3.2.4/847edb246462b96177b6c18b85e5885f0a2a51f5/cglib-3.2.4.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.derby/derby/10.13.1.1/29c42babe5c5463c6eea45487d3cfbfe8348ccd1/derby-10.13.1.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/commons-collections/commons-collections/3.2.2/8ad72fe39fa8c91eaaf12aadb21e0c3661fe26d5/commons-collections-3.2.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/commons-configuration/commons-configuration/1.10/2b36e4adfb66d966c5aef2d73deb6be716389dc9/commons-configuration-1.10.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/xerces/xercesImpl/2.11.0/9bb329db1cfc4e22462c9d6b43a8432f5850e92c/xercesImpl-2.11.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-core/2.8.6/2ef7b1cc34de149600f5e75bc2d5bf40de894e60/jackson-core-2.8.6.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/commons-logging/commons-logging/1.2/4bfc12adfe4842bf07b657f0369c4cb522955686/commons-logging-1.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/javax.activation/activation/1.1/e6cb541461c2834bdea3eb920f1884d1eb508b50/activation-1.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/javax.transaction/javax.transaction-api/1.2/d81aff979d603edd90dcd8db2abc1f4ce6479e3e/javax.transaction-api-1.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-xml/9.3.10.v20160621/8b62f709311334b5bfdf494ff7e7008d192a4f16/jetty-xml-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-servlet/9.3.10.v20160621/5f6dc13061a64c25d8177585fd336cb3fba652c9/jetty-servlet-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/jline/jline/2.12/ce9062c6a125e0f9ad766032573c041ae8ecc986/jline-2.12.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.hamcrest/hamcrest-library/1.3/4785a3c21320980282f9f33d0d1264a69040538f/hamcrest-library-1.3.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/cglib/cglib-nodep/3.1/aa83efbd1aedc4f26bdf00e7ea78191483f2c9b3/cglib-nodep-3.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.jmock/jmock/2.8.2/af722a4cd91089de6dcb6d946010298cb6939fc0/jmock-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/net.bytebuddy/byte-buddy/1.6.14/871c3e49dc6183d0d361601c2f1d11abb1a6b48c/byte-buddy-1.6.14.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/net.bytebuddy/byte-buddy-agent/1.6.14/ba1e5ba3a84fb2fbf2f4de9138df19665eec4d59/byte-buddy-agent-1.6.14.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-reflect/1.7.1/258686cb36f6f7687017b4009d6b1267f989f66/powermock-reflect-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.javassist/javassist/3.21.0-GA/598244f595db5c5fb713731eddbb1c91a58d959b/javassist-3.21.0-GA.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-module-junit4-common/1.7.1/cfd1f8fb63e50ae4c409ace696136ec3d595e832/powermock-module-junit4-common-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-api-mockito-common/1.7.1/bca2184da31c19799cf79e8567d86c5427bbdf3d/powermock-api-mockito-common-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.jayway.jsonpath/json-path/2.2.0/22290d17944bd239fabf5ac69005a60a7ecbbbcb/json-path-2.2.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/com.google.guava/guava/21.0/3a3d111be1be1b745edfa7d91678a12d7ed38709/guava-21.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.commons/commons-pool2/2.4.2/e5f4f28f19d57716fbc3989d7a357ebf1e454fea/commons-pool2-2.4.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.javaruntype/javaruntype/1.2/d7595d6aa87b56ad207961157d15b2c59f0afb53/javaruntype-1.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/ognl/ognl/3.1.2/dbda3e3662e898f5cc76ed756e0d44c82364bb84/ognl-3.1.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/ru.vyarus/generics-resolver/2.0.1/2182e67f161ddbe3ff8cb055bb54398354fda3f5/generics-resolver-2.0.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.ow2.asm/asm/5.1/5ef31c4fe953b1fd00b8a88fa1d6820e8785bb45/asm-5.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.ant/ant/1.9.6/80e2063b01bab3c79c2d84e4ed5e73868394c85a/ant-1.9.6.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/xml-apis/xml-apis/1.4.01/3789d9fada2d3d458c4ba2de349d48780f381ee3/xml-apis-1.4.01.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-util/9.3.10.v20160621/b15c7f81876892ec70449e285367773e7657519e/jetty-util-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-security/9.3.10.v20160621/7126d4cf417bb5fbd3a20e9c0be3a58f31d626b8/jetty-security-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.jmock/jmock-testjar/2.8.2/33f7e59d01c7d8eb0283551ceb9a8ac85d2d26af/jmock-testjar-2.8.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.beanshell/bsh/1.3.0/1fed35193d56470f46c0fb33917e3e82c0c42358/bsh-1.3.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.powermock/powermock-api-support/1.7.1/366af3d58861e3754d12c8504a76642900786d8d/powermock-api-support-1.7.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/net.minidev/json-smart/2.2.1/5b9e5df7a62d1279b70dc882b041d249c4f0b002/json-smart-2.2.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.antlr/antlr-runtime/3.1.2/c4ca32c2be1b22a5553dd3171f51f9b2b04030b/antlr-runtime-3.1.2.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/javassist/javassist/3.11.0.GA/2c00105734a57e9ee4f27e4b17cd43200e5f0ff8/javassist-3.11.0.GA.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-server/9.3.10.v20160621/2bccc2b33d887ae7e8fb2b0b56f039c606ab3194/jetty-server-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/net.minidev/accessors-smart/1.1/a527213f2fea112a04c9bdf0ec0264e34104cd08/accessors-smart-1.1.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/javax.servlet/javax.servlet-api/3.1.0/3cd63d075497751784b2fa84be59432f4905bf7c/javax.servlet-api-3.1.0.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-http/9.3.10.v20160621/db39959235ac07decdf3ce97d22312d776584700/jetty-http-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.eclipse.jetty/jetty-io/9.3.10.v20160621/26b2564fe3a322bd6cf3fed071f686bfb1b59500/jetty-io-9.3.10.v20160621.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.slf4j/slf4j-api/1.7.24/3f6b4bd4f8dbe8d4bea06d107a3826469b85c3e9/slf4j-api-1.7.24.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.hamcrest/hamcrest-core/1.3/42a25dc3219429f0e5d060061f71acb49bf010a0/hamcrest-core-1.3.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.objenesis/objenesis/2.5/612ecb799912ccf77cba9b3ed8c813da086076e9/objenesis-2.5.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.ant/ant-launcher/1.9.6/d75dd4c39ba06401f20e7afffb861d268baec6bc/ant-launcher-1.9.6.jar
[vm3_v100] /usr/local/asfpackages/java/jdk1.8.0_144/lib/tools.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-webmvc/4.3.6.RELEASE/ea55690d6d61ad70e2569db1e1add1603e427862/spring-webmvc-4.3.6.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-beans/4.3.6.RELEASE/1585715ed598b76a23dac931c27aa039b189eafb/spring-beans-4.3.6.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-context/4.3.6.RELEASE/5f3041020113e3202a7ae9defe36e7b5d2fb87eb/spring-context-4.3.6.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-expression/4.3.6.RELEASE/13b53568cfd7b308e70efcbac6cdd0c5d597ba1/spring-expression-4.3.6.RELEASE.jar
[vm3_v100]
/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.springframework/spring-web/4.3.6.RELEASE/8b8bf8fc6ed4acd5ae0baa6179f1cccc52aaa9aa/spring-web-4.3.6.RELEASE.jar
[vm3_v100] Library Path:
[vm3_v100] /usr/java/packages/lib/amd64
[vm3_v100] /usr/lib/x86_64-linux-gnu/jni
[vm3_v100] /lib/x86_64-linux-gnu
[vm3_v100] /usr/lib/x86_64-linux-gnu
[vm3_v100] /usr/lib/jni
[vm3_v100] /lib
[vm3_v100] /usr/lib
[vm3_v100] System Properties:
[vm3_v100] WORKSPACE_DIR =
/home/jenkins/jenkins-slave/workspace/Geode-nightly/geode-core/build/distributedTest160/.
[vm3_v100] awt.toolkit = sun.awt.X11.XToolkit
[vm3_v100] dummyArg = true
[vm3_v100] file.encoding = ANSI_X3.4-1968
[vm3_v100] file.encoding.pkg = sun.io
[vm3_v100] file.separator = /
[vm3_v100] gemfire.DEFAULT_MAX_OPLOG_SIZE = 10
[vm3_v100] gemfire.DUnitLauncher.LAUNCHED = true
[vm3_v100] gemfire.DUnitLauncher.RMI_PORT = 22286
[vm3_v100] gemfire.DUnitLauncher.VM_NUM = 3
[vm3_v100] gemfire.DUnitLauncher.VM_VERSION = 100
[vm3_v100] gemfire.disallowMcastDefaults = true
[vm3_v100] gemfire.free-off-heap-memory = true
[vm3_v100] gemfire.sys.security-client-auth-init = ********
[vm3_v100] gemfire.sys.security-log-level = ********
[vm3_v100] gemfire.sys.security-password = ********
[vm3_v100] gemfire.sys.security-username = ********
[vm3_v100] gemfire.use-ephemeral-ports = true
[vm3_v100] java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
[vm3_v100] java.awt.printerjob = sun.print.PSPrinterJob
[vm3_v100] java.class.version = 52.0
[vm3_v100] java.endorsed.dirs =
/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/endorsed
[vm3_v100] java.ext.dirs =
/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/ext:/usr/java/packages/lib/ext
[vm3_v100] java.home = /usr/lib/jvm/java-8-openjdk-amd64/jre
[vm3_v100] java.io.tmpdir = /tmp
[vm3_v100] java.runtime.name = OpenJDK Runtime Environment
[vm3_v100] java.runtime.version = 1.8.0_141-8u141-b15-1~deb9u1-b15
[vm3_v100] java.specification.name = Java Platform API Specification
[vm3_v100] java.specification.vendor = Oracle Corporation
[vm3_v100] java.specification.version = 1.8
[vm3_v100] java.vendor = Oracle Corporation
[vm3_v100] java.vendor.url = http://java.oracle.com/
[vm3_v100] java.vendor.url.bug = http://bugreport.sun.com/bugreport/
[vm3_v100] java.version = 1.8.0_141
[vm3_v100] java.vm.info = mixed mode
[vm3_v100] java.vm.name = OpenJDK 64-Bit Server VM
[vm3_v100] java.vm.specification.name = Java Virtual Machine Specification
[vm3_v100] java.vm.specification.vendor = Oracle Corporation
[vm3_v100] java.vm.specification.version = 1.8
[vm3_v100] java.vm.vendor = Oracle Corporation
[vm3_v100] java.vm.version = 25.141-b15
[vm3_v100] line.separator =
[vm3_v100] log-level = info
[vm3_v100] os.version = 4.4.0-43-generic
[vm3_v100] path.separator = :
[vm3_v100] sun.arch.data.model = 64
[vm3_v100] sun.boot.class.path =
/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/resources.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/rt.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/sunrsasign.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/jsse.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/jce.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/charsets.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/jfr.jar:/usr/lib/jvm/java-8-openjdk-amd64/jre/classes
[vm3_v100] sun.boot.library.path =
/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/amd64
[vm3_v100] sun.cpu.endian = little
[vm3_v100] sun.cpu.isalist =
[vm3_v100] sun.io.unicode.encoding = UnicodeLittle
[vm3_v100] sun.java.command = org.apache.geode.test.dunit.standalone.ChildVM
[vm3_v100] sun.java.launcher = SUN_STANDARD
[vm3_v100] sun.jnu.encoding = ANSI_X3.4-1968
[vm3_v100] sun.management.compiler = HotSpot 64-Bit Tiered Compilers
[vm3_v100] sun.nio.ch.bugLevel =
[vm3_v100] sun.os.patch.level = unknown
[vm3_v100] user.country = US
[vm3_v100] user.language = en
[vm3_v100] user.timezone = Etc/UTC
[vm3_v100] Log4J 2 Configuration:
[vm3_v100]
jar:file:/home/jenkins/jenkins-slave/workspace/Geode-nightly/caches/modules-2/files-2.1/org.apache.geode/geode-core/1.0.0-incubating/28ed9510a84bfd48f1f01ac4bb6f2d5717fc01f/geode-core-1.0.0-incubating.jar!/log4j2.xml
[vm3_v100]
---------------------------------------------------------------------------
[vm3_v100] [debug 2017/10/03 08:46:56.670 UTC <RMI TCP
Connection(1)-172.17.0.2> tid=0x1c] SecurityLogWriter is created.
[vm3_v100] [info 2017/10/03 08:46:56.753 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException
action=add>org.apache.geode.security.AuthenticationRequiredException</ExpectedException>
[vm3_v100] [info 2017/10/03 08:46:56.754 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException
action=add>org.apache.geode.security.AuthenticationFailedException</ExpectedException>
[vm3_v100] [info 2017/10/03 08:46:56.754 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException
action=add>javax.net.ssl.SSLHandshakeException</ExpectedException>
[vm3_v100] [info 2017/10/03 08:46:56.849 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Updating membership port. Port changed from 0 to 45,160. ID is now
2d21656aaf6b(30055:loner):0:b1a66ae1
[vm0] [warn 2017/10/03 08:46:56.910 UTC <ServerConnection on port 41771 Thread
0> tid=0x3dfc] Server connection from
[identity(172.17.0.2(30055:loner):45160:b1a66ae1,connection=1; port=45160]:
Security exception: org.apache.geode.security.AuthenticationFailedException:
DummyAuthenticator: Invalid user name [invalid1], password supplied.
[vm0] [info 2017/10/03 08:46:56.929 UTC <ServerConnection on port 41771 Thread
0> tid=0x3dfc] Server connection from
[identity(172.17.0.2(30055:loner):45160:b1a66ae1,connection=1; port=45160]:
connection disconnect detected by EOF.
[vm0] [warn 2017/10/03 08:46:56.929 UTC <ServerConnection on port 41771 Thread
0> tid=0x3dfc] ClientHealthMonitor: Unregistering client with member id
identity(172.17.0.2(30055:loner):45160:b1a66ae1,connection=1 due to: The
connection has been reset while reading the header
[vm3_v100] [info 2017/10/03 08:46:56.929 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Destroying connection pool testPool
[vm3_v100] [info 2017/10/03 08:46:56.931 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got expected exception when starting client:
org.apache.geode.security.AuthenticationFailedException: While performing a
remote authenticate
[vm3_v100] [info 2017/10/03 08:46:56.931 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm3_v100] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$10/1334842304.run
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$10/1334842304@22f2505b
(took 1198 ms)
[vm0] [info 2017/10/03 08:46:56.934 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownCreationStackGenerator)
[vm0] [info 2017/10/03 08:46:56.934 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm0] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownCreationStackGenerator) (took 0 ms)
[vm1] [info 2017/10/03 08:46:56.935 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownCreationStackGenerator)
[vm1] [info 2017/10/03 08:46:56.935 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm1] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownCreationStackGenerator) (took 0 ms)
[vm2_v100] [info 2017/10/03 08:46:56.940 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownCreationStackGenerator)
[vm2_v100] [info 2017/10/03 08:46:56.941 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm2_v100] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownCreationStackGenerator) (took 0 ms)
[vm3_v100] [info 2017/10/03 08:46:56.945 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownCreationStackGenerator)
[vm3_v100] [info 2017/10/03 08:46:56.945 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm3_v100] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownCreationStackGenerator) (took 0 ms)
[info 2017/10/03 08:46:56.946 UTC <Test worker> tid=0x13] <ExpectedException
action=remove>Connection refused: connect</ExpectedException>
[info 2017/10/03 08:46:56.946 UTC <Test worker> tid=0x13] <ExpectedException
action=remove>Connection refused: connect</ExpectedException>
[vm0] [info 2017/10/03 08:46:56.947 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.IgnoredException$1.run
with 0 args on object: "IgnoredException remove"
[vm0] [info 2017/10/03 08:46:56.947 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm0] [info 2017/10/03 08:46:56.947 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm0] [info 2017/10/03 08:46:56.947 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm0] [info 2017/10/03 08:46:56.947 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm0] from org.apache.geode.test.dunit.IgnoredException$1.run with 0 args on
object: "IgnoredException remove" (took 0 ms)
[vm1] [info 2017/10/03 08:46:56.948 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.IgnoredException$1.run
with 0 args on object: "IgnoredException remove"
[vm1] [info 2017/10/03 08:46:56.948 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm1] [info 2017/10/03 08:46:56.948 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm1] [info 2017/10/03 08:46:56.948 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm1] [info 2017/10/03 08:46:56.948 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm1] from org.apache.geode.test.dunit.IgnoredException$1.run with 0 args on
object: "IgnoredException remove" (took 0 ms)
[vm2_v100] [info 2017/10/03 08:46:56.952 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Received method: org.apache.geode.test.dunit.IgnoredException$1.run
with 0 args on object: "IgnoredException remove"
[vm2_v100] [info 2017/10/03 08:46:56.952 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm2_v100] [info 2017/10/03 08:46:56.953 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm2_v100] [info 2017/10/03 08:46:56.953 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm2_v100] [info 2017/10/03 08:46:56.953 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm2_v100] from org.apache.geode.test.dunit.IgnoredException$1.run with 0 args
on object: "IgnoredException remove" (took 0 ms)
[vm3_v100] [info 2017/10/03 08:46:56.957 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Received method: org.apache.geode.test.dunit.IgnoredException$1.run
with 0 args on object: "IgnoredException remove"
[vm3_v100] [info 2017/10/03 08:46:56.957 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm3_v100] [info 2017/10/03 08:46:56.958 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm3_v100] [info 2017/10/03 08:46:56.958 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] <ExpectedException action=remove>Connection refused:
connect</ExpectedException>
[vm3_v100] [info 2017/10/03 08:46:56.958 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm3_v100] from org.apache.geode.test.dunit.IgnoredException$1.run with 0 args
on object: "IgnoredException remove" (took 0 ms)
[vm0] [info 2017/10/03 08:46:56.959 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownVM)
[vm0] [info 2017/10/03 08:46:56.962 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GemFireCache[id = 1054501861; isClosing = true; isShutDownAll =
false; created = Tue Oct 03 08:46:53 UTC 2017; server = false; copyOnRead =
false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm0] [info 2017/10/03 08:46:56.964 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Cache server on port 41,771 is shutting down.
[vm0] [info 2017/10/03 08:46:56.967 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Shutting down DistributionManager 172.17.0.2(166)<ec><v0>:32770.
[vm1] [info 2017/10/03 08:46:56.968 UTC <Pooled High Priority Message Processor
1> tid=0x3867] received leave request from 172.17.0.2(166)<ec><v0>:32770 for
172.17.0.2(166)<ec><v0>:32770
[vm1] [info 2017/10/03 08:46:56.968 UTC <Pooled High Priority Message Processor
1> tid=0x3867] This member is becoming the membership coordinator with address
172.17.0.2(170)<ec><v1>:32771
[vm1] [info 2017/10/03 08:46:56.968 UTC <Pooled High Priority Message Processor
1> tid=0x3867] ViewCreator starting on:172.17.0.2(170)<ec><v1>:32771
[vm1] [info 2017/10/03 08:46:56.968 UTC <Pooled High Priority Message Processor
1> tid=0x3867] Member at 172.17.0.2(166)<ec><v0>:32770 gracefully left the
distributed cache: shutdown message received
[vm1] [info 2017/10/03 08:46:56.968 UTC <Geode Membership View Creator>
tid=0x3887] View Creator thread is starting
[vm1] [info 2017/10/03 08:46:56.969 UTC <Geode Membership View Creator>
tid=0x3887] received new view: View[172.17.0.2(170)<ec><v1>:32771|10] members:
[172.17.0.2(170)<ec><v1>:32771{lead}] shutdown: [172.17.0.2(166)<ec><v0>:32770]
[vm1] old view is: View[172.17.0.2(166)<ec><v0>:32770|1] members:
[172.17.0.2(166)<ec><v0>:32770{lead}, 172.17.0.2(170)<ec><v1>:32771]
[vm1] [info 2017/10/03 08:46:56.969 UTC <Geode Membership View Creator>
tid=0x3887] Peer locator received new membership view:
View[172.17.0.2(170)<ec><v1>:32771|10] members:
[172.17.0.2(170)<ec><v1>:32771{lead}] shutdown: [172.17.0.2(166)<ec><v0>:32770]
[vm1] [info 2017/10/03 08:46:56.971 UTC <Geode Membership View Creator>
tid=0x3887] no recipients for new view aside from myself
[vm1] [info 2017/10/03 08:46:56.971 UTC <View Message Processor> tid=0x3888]
172.17.0.2(170)<ec><v1>:32771 is the elder and the only member.
[vm0] [info 2017/10/03 08:46:57.068 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Now closing distribution for 172.17.0.2(166)<ec><v0>:32770
[vm0] [info 2017/10/03 08:46:57.069 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Stopping membership services
[vm1] [info 2017/10/03 08:46:57.069 UTC <unicast receiver,2d21656aaf6b-11973>
tid=0x3850] received leave request from 172.17.0.2<ec><v0>:32770 for
172.17.0.2(166)<ec><v0>:32770
[vm0] [info 2017/10/03 08:46:57.070 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GMSHealthMonitor server socket is closed in stopServices().
[vm0] [info 2017/10/03 08:46:57.071 UTC <Geode Failure Detection Server thread
0> tid=0x3dcd] GMSHealthMonitor server thread exiting
[vm0] [info 2017/10/03 08:46:57.071 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GMSHealthMonitor serverSocketExecutor is terminated
[vm0] [info 2017/10/03 08:46:57.078 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] DistributionManager stopped in 111ms.
[vm0] [info 2017/10/03 08:46:57.078 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Marking DistributionManager 172.17.0.2(166)<ec><v0>:32770 as closed.
[vm0] [info 2017/10/03 08:46:57.078 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Stopping Distribution Locator on /172.17.0.2[27343]
[vm0] [info 2017/10/03 08:46:57.079 UTC <Distribution Locator on /172.17.0.2>
tid=0x3dbd] locator shutting down
[vm0] [info 2017/10/03 08:46:57.080 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Distribution Locator on /172.17.0.2[27343] is stopped
[vm0] [info 2017/10/03 08:46:57.081 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm0] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownVM) (took 121 ms)
[vm1] [info 2017/10/03 08:46:57.082 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownVM)
[vm1] [info 2017/10/03 08:46:57.084 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GemFireCache[id = 1388398244; isClosing = true; isShutDownAll =
false; created = Tue Oct 03 08:46:53 UTC 2017; server = false; copyOnRead =
false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm1] [info 2017/10/03 08:46:57.084 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Cache server on port 44,177 is shutting down.
[vm1] [info 2017/10/03 08:46:57.087 UTC <Queue Removal Thread> tid=0x3883] The
QueueRemovalThread is done.
[vm1] [info 2017/10/03 08:46:57.090 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Shutting down DistributionManager 172.17.0.2(170)<ec><v1>:32771.
[vm2_v100] [info 2017/10/03 08:46:57.091 UTC <Cache Client Updater Thread on
2d21656aaf6b(170)<ec><v1>:32771(version:UNKNOWN[ordinal=70]) port 44177>
tid=0x26] Primary subscription endpoint 2d21656aaf6b:44177 crashed. Scheduling
recovery.
[vm2_v100] [info 2017/10/03 08:46:57.097 UTC <Cache Client Updater Thread on
2d21656aaf6b(170)<ec><v1>:32771(version:UNKNOWN[ordinal=70]) port 44177>
tid=0x26] Cache client updater for Queue on endpoint 2d21656aaf6b:44177
exiting. Scheduling recovery.
[vm2_v100] [info 2017/10/03 08:46:57.097 UTC <queueTimer-testPool> tid=0x2e]
SubscriptionManager redundancy satisfier - primary endpoint has been lost.
Attempting to recover.
[vm2_v100] [warn 2017/10/03 08:46:57.099 UTC <queueTimer-testPool> tid=0x2e]
Could not connect to: 2d21656aaf6b:41771
[vm2_v100] java.net.ConnectException: Connection refused (Connection refused)
[vm2_v100] at java.net.PlainSocketImpl.socketConnect(Native Method)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
[vm2_v100] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
[vm2_v100] at java.net.Socket.connect(Socket.java:589)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:967)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:906)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connectForClient(SocketCreator.java:873)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:94)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:135)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.createNewPrimary(QueueManagerImpl.java:797)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.recoverPrimary(QueueManagerImpl.java:915)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl$RedundancySatisfierTask.run2(QueueManagerImpl.java:1443)
[vm2_v100] at
org.apache.geode.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1235)
[vm2_v100] at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[vm2_v100] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[vm2_v100] at java.lang.Thread.run(Thread.java:748)
[vm2_v100] [warn 2017/10/03 08:46:57.101 UTC <queueTimer-testPool> tid=0x2e]
Could not connect to: 2d21656aaf6b:44177
[vm2_v100] java.net.ConnectException: Connection refused (Connection refused)
[vm2_v100] at java.net.PlainSocketImpl.socketConnect(Native Method)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
[vm2_v100] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
[vm2_v100] at java.net.Socket.connect(Socket.java:589)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:967)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:906)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connectForClient(SocketCreator.java:873)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:94)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:135)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.createNewPrimary(QueueManagerImpl.java:797)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.recoverPrimary(QueueManagerImpl.java:915)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl$RedundancySatisfierTask.run2(QueueManagerImpl.java:1443)
[vm2_v100] at
org.apache.geode.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1235)
[vm2_v100] at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[vm2_v100] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[vm2_v100] at java.lang.Thread.run(Thread.java:748)
[vm2_v100] [warn 2017/10/03 08:46:57.103 UTC <queueTimer-testPool> tid=0x2e]
Could not connect to: 2d21656aaf6b:41771
[vm2_v100] java.net.ConnectException: Connection refused (Connection refused)
[vm2_v100] at java.net.PlainSocketImpl.socketConnect(Native Method)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
[vm2_v100] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
[vm2_v100] at java.net.Socket.connect(Socket.java:589)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:967)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:906)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connectForClient(SocketCreator.java:873)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:94)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:135)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.createNewPrimary(QueueManagerImpl.java:797)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.recoverPrimary(QueueManagerImpl.java:915)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl$RedundancySatisfierTask.run2(QueueManagerImpl.java:1443)
[vm2_v100] at
org.apache.geode.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1235)
[vm2_v100] at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[vm2_v100] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[vm2_v100] at java.lang.Thread.run(Thread.java:748)
[vm2_v100] [warn 2017/10/03 08:46:57.104 UTC <queueTimer-testPool> tid=0x2e]
Could not connect to: 2d21656aaf6b:44177
[vm2_v100] java.net.ConnectException: Connection refused (Connection refused)
[vm2_v100] at java.net.PlainSocketImpl.socketConnect(Native Method)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
[vm2_v100] at
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
[vm2_v100] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
[vm2_v100] at java.net.Socket.connect(Socket.java:589)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:967)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connect(SocketCreator.java:906)
[vm2_v100] at
org.apache.geode.internal.net.SocketCreator.connectForClient(SocketCreator.java:873)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:94)
[vm2_v100] at
org.apache.geode.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:135)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.createNewPrimary(QueueManagerImpl.java:797)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl.recoverPrimary(QueueManagerImpl.java:915)
[vm2_v100] at
org.apache.geode.cache.client.internal.QueueManagerImpl$RedundancySatisfierTask.run2(QueueManagerImpl.java:1443)
[vm2_v100] at
org.apache.geode.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1235)
[vm2_v100] at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[vm2_v100] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[vm2_v100] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[vm2_v100] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[vm2_v100] at java.lang.Thread.run(Thread.java:748)
[vm1] [info 2017/10/03 08:46:57.192 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Now closing distribution for 172.17.0.2(170)<ec><v1>:32771
[vm1] [info 2017/10/03 08:46:57.192 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Stopping membership services
[vm1] [info 2017/10/03 08:46:57.192 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GMSHealthMonitor server socket is closed in stopServices().
[vm1] [info 2017/10/03 08:46:57.193 UTC <Geode Failure Detection Server thread
0> tid=0x3854] GMSHealthMonitor server thread exiting
[vm1] [info 2017/10/03 08:46:57.193 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] GMSHealthMonitor serverSocketExecutor is terminated
[vm1] [info 2017/10/03 08:46:57.196 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] DistributionManager stopped in 106ms.
[vm1] [info 2017/10/03 08:46:57.196 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Marking DistributionManager 172.17.0.2(170)<ec><v1>:32771 as closed.
[vm1] [info 2017/10/03 08:46:57.196 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Stopping Distribution Locator on /172.17.0.2[27149]
[vm1] [info 2017/10/03 08:46:57.198 UTC <Distribution Locator on /172.17.0.2>
tid=0x3845] locator shutting down
[vm1] [info 2017/10/03 08:46:57.200 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Distribution Locator on /172.17.0.2[27149] is stopped
[vm1] [info 2017/10/03 08:46:57.201 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: null
[vm1] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownVM) (took 119 ms)
[vm2_v100] [info 2017/10/03 08:46:57.205 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownVM)
[vm2_v100] [info 2017/10/03 08:46:57.227 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] GemFireCache[id = 1995525007; isClosing = true; isShutDownAll =
false; created = Tue Oct 03 08:46:55 UTC 2017; server = false; copyOnRead =
false; lockLease = 120; lockTimeout = 60]: Now closing.
[vm2_v100] [info 2017/10/03 08:46:57.281 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Destroying connection pool testPool
[vm2_v100] [info 2017/10/03 08:46:57.371 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm2_v100] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownVM) (took 165 ms)
[vm3_v100] [info 2017/10/03 08:46:57.374 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Received method: org.apache.geode.test.dunit.NamedRunnable.run with 0
args on object: runnable(tearDownVM)
[vm3_v100] [info 2017/10/03 08:46:57.444 UTC <RMI TCP Connection(1)-172.17.0.2>
tid=0x1c] Got result: null
[vm3_v100] from org.apache.geode.test.dunit.NamedRunnable.run with 0 args on
object: runnable(tearDownVM) (took 69 ms)
[locator] [info 2017/10/03 08:46:57.445 UTC <RMI TCP Connection(9)-172.17.0.2>
tid=0x1f1] Received method:
org.apache.geode.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$42/1726440090.run
with 0 args on object:
org.apache.geode.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$42/1726440090@7e57b594
[locator] [info 2017/10/03 08:46:57.445 UTC <RMI TCP Connection(9)-172.17.0.2>
tid=0x1f1] Got result: null
[locator] from
org.apache.geode.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$42/1726440090.run
with 0 args on object:
org.apache.geode.test.dunit.internal.JUnit4DistributedTestCase$$Lambda$42/1726440090@7e57b594
(took 0 ms)
[vm0] [info 2017/10/03 08:46:57.449 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$103/909126612.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$103/909126612@69e8e9b2
[vm0] [info 2017/10/03 08:46:57.450 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: true
[vm0] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$103/909126612.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$103/909126612@69e8e9b2
(took 0 ms)
[vm1] [info 2017/10/03 08:46:57.450 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Received method:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$116/1113961088.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$116/1113961088@63f84967
[vm1] [info 2017/10/03 08:46:57.450 UTC <RMI TCP Connection(8)-172.17.0.2>
tid=0x1b] Got result: true
[vm1] from
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$116/1113961088.call
with 0 args on object:
org.apache.geode.security.ClientAuthenticationTestCase$$Lambda$116/1113961088@63f84967
(took 0 ms)
{noformat}
> CI Failure: org.apache.geode.security.ClientAuthorizationDUnitTest
> -------------------------------------------------------------------
>
> Key: GEODE-3738
> URL: https://issues.apache.org/jira/browse/GEODE-3738
> Project: Geode
> Issue Type: Bug
> Components: security, tests
> Reporter: Jared Stewart
>
> {noformat}
> Error
> org.apache.geode.test.dunit.RMIException: While invoking
> org.apache.geode.security.ClientAuthorizationDUnitTest$$Lambda$177/351125497.run
> in VM 2 running on Host 2d21656aaf6b with 4 VMs with version 120
> Stacktrace
> org.apache.geode.test.dunit.RMIException: While invoking
> org.apache.geode.security.ClientAuthorizationDUnitTest$$Lambda$177/351125497.run
> in VM 2 running on Host 2d21656aaf6b with 4 VMs with version 120
> at org.apache.geode.test.dunit.VM.invoke(VM.java:393)
> at org.apache.geode.test.dunit.VM.invoke(VM.java:363)
> at org.apache.geode.test.dunit.VM.invoke(VM.java:308)
> at
> org.apache.geode.security.ClientAuthorizationDUnitTest.testPutsGetsWithFailover(ClientAuthorizationDUnitTest.java:350)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at org.junit.runners.Suite.runChild(Suite.java:128)
> at org.junit.runners.Suite.runChild(Suite.java:27)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:114)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:57)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66)
> at
> org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
> at sun.reflect.GeneratedMethodAccessor443.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at
> org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
> at
> org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
> at sun.reflect.GeneratedMethodAccessor442.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:147)
> at
> org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:129)
> at
> org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
> at
> org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
> at
> org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:46)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.lang.AssertionError: Got unexpected exception when doing puts
> at org.apache.geode.test.dunit.Assert.fail(Assert.java:66)
> at
> org.apache.geode.security.SecurityTestUtils.doPutsP(SecurityTestUtils.java:1067)
> at
> org.apache.geode.security.SecurityTestUtils.doPutsP(SecurityTestUtils.java:1017)
> at
> org.apache.geode.security.SecurityTestUtils.doNPuts(SecurityTestUtils.java:842)
> at
> org.apache.geode.security.ClientAuthorizationDUnitTest.lambda$testPutsGetsWithFailover$bb17a952$4(ClientAuthorizationDUnitTest.java:350)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at hydra.MethExecutor.executeObject(MethExecutor.java:245)
> at
> org.apache.geode.test.dunit.standalone.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:70)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
> at sun.rmi.transport.Transport$1.run(Transport.java:200)
> at sun.rmi.transport.Transport$1.run(Transport.java:197)
> at java.security.AccessController.doPrivileged(Native Method)
> at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
> at
> sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
> ... 3 more
> Caused by: org.apache.geode.cache.client.ServerOperationException: remote
> server on 2d21656aaf6b(23621:loner):48026:67915ee1:
> org.apache.geode.security.AuthenticationRequiredException: No security
> credentials are provided
> at
> org.apache.geode.cache.client.internal.OpExecutorImpl.handleException(OpExecutorImpl.java:678)
> at
> org.apache.geode.cache.client.internal.OpExecutorImpl.handleException(OpExecutorImpl.java:754)
> at
> org.apache.geode.cache.client.internal.OpExecutorImpl.handleException(OpExecutorImpl.java:623)
> at
> org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:167)
> at
> org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:115)
> at
> org.apache.geode.cache.client.internal.PoolImpl.execute(PoolImpl.java:763)
> at org.apache.geode.cache.client.internal.PutOp.execute(PutOp.java:91)
> at
> org.apache.geode.cache.client.internal.ServerRegionProxy.put(ServerRegionProxy.java:162)
> at
> org.apache.geode.internal.cache.LocalRegion.serverPut(LocalRegion.java:3006)
> at
> org.apache.geode.internal.cache.LocalRegion.cacheWriteBeforePut(LocalRegion.java:3115)
> at
> org.apache.geode.internal.cache.AbstractRegionMap.invokeCacheWriter(AbstractRegionMap.java:3028)
> at
> org.apache.geode.internal.cache.AbstractRegionMap.basicPut(AbstractRegionMap.java:2789)
> at
> org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5628)
> at
> org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:151)
> at
> org.apache.geode.internal.cache.LocalRegion.basicPut(LocalRegion.java:5057)
> at
> org.apache.geode.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1595)
> at
> org.apache.geode.internal.cache.LocalRegion.put(LocalRegion.java:1582)
> at
> org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:325)
> at
> org.apache.geode.security.SecurityTestUtils.doPutsP(SecurityTestUtils.java:1028)
> ... 26 more
> Caused by: org.apache.geode.security.AuthenticationRequiredException: No
> security credentials are provided
> at
> org.apache.geode.internal.cache.tier.sockets.MessageIdExtractor.getUniqueIdFromMessage(MessageIdExtractor.java:27)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.getUniqueId(ServerConnection.java:1725)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.getAuthzRequest(ServerConnection.java:1745)
> at
> org.apache.geode.internal.cache.tier.sockets.command.Put65.cmdExecute(Put65.java:243)
> at
> org.apache.geode.internal.cache.tier.sockets.BaseCommand.execute(BaseCommand.java:162)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.doNormalMsg(ServerConnection.java:785)
> at
> org.apache.geode.internal.cache.tier.sockets.LegacyServerConnection.doOneMessage(LegacyServerConnection.java:85)
> at
> org.apache.geode.internal.cache.tier.sockets.ServerConnection.run(ServerConnection.java:1166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at
> org.apache.geode.internal.cache.tier.sockets.AcceptorImpl$1$1.run(AcceptorImpl.java:557)
> ... 1 more
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
