Jared Stewart created GEODE-2876: ------------------------------------ Summary: CI Failure: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest#testMultipleGfshClientToOneServer Key: GEODE-2876 URL: https://issues.apache.org/jira/browse/GEODE-2876 Project: Geode Issue Type: Bug Components: gfsh, management Reporter: Jared Stewart
ConcurrentDeployDUnitTest is failing due to a parsing error. {noformat} Error java.lang.AssertionError: An exception occurred during asynchronous invocation. Stacktrace java.lang.AssertionError: An exception occurred during asynchronous invocation. at org.apache.geode.test.dunit.AsyncInvocation.checkException(AsyncInvocation.java:148) at org.apache.geode.test.dunit.AsyncInvocation.await(AsyncInvocation.java:341) at org.apache.geode.test.dunit.AsyncInvocation.await(AsyncInvocation.java:364) at org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest.testMultipleGfshClientToOneServer(ConcurrentDeployDUnitTest.java:67) 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.RunAfters.evaluate(RunAfters.java:27) at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) 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.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.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.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.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.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.MessageHub$Handler.run(MessageHub.java:377) at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54) at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: org.junit.ComparisonFailure: expected:<[OK]> but was:<[ERROR]> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at org.apache.geode.test.dunit.rules.GfshShellConnectionRule.executeAndVerifyCommand(GfshShellConnectionRule.java:231) at org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest.loopThroughDeployAndUndeploys(ConcurrentDeployDUnitTest.java:90) at org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest.lambda$testMultipleGfshClientToOneServer$6cbf4f0f$1(ConcurrentDeployDUnitTest.java:63) 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:73) at sun.reflect.GeneratedMethodAccessor44.invoke(Unknown Source) 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:346) 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 Standard Output [vm3] [info 2017/04/30 09:25:29.042 UTC <RMI TCP Connection(15)-67.195.81.146> tid=0x1e] Received method: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@4f861772 [vm3] [info 2017/04/30 09:25:29.043 UTC <RMI TCP Connection(15)-67.195.81.146> tid=0x1e] Got result: null [vm3] from org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@4f861772 (took 0 ms) [vm2] [info 2017/04/30 09:25:29.044 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@527317cd [vm2] [info 2017/04/30 09:25:29.045 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Got result: null [vm2] from org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@527317cd (took 0 ms) [vm1] [info 2017/04/30 09:25:29.047 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@3d8e128e [vm1] [info 2017/04/30 09:25:29.048 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Got result: null [vm1] from org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@3d8e128e (took 0 ms) [vm0] [info 2017/04/30 09:25:29.049 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@3306e715 [vm0] [info 2017/04/30 09:25:29.049 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Got result: null [vm0] from org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1.run with 0 args on object: org.apache.geode.test.dunit.rules.DistributedRestoreSystemProperties$1@3306e715 (took 0 ms) [locator] [info 2017/04/30 09:25:29.082 UTC <Geode Membership View Creator> tid=0x31] View Creator is processing 4 requests for the next membership view [locator] [info 2017/04/30 09:25:29.083 UTC <Geode Membership View Creator> tid=0x31] received new view: View[asf902(10966:locator)<ec><v0>:32769|6] members: [asf902(10966:locator)<ec><v0>:32769] shutdown: [asf902(VM1:14531)<v5>:32771, asf902(Manager:14467)<v4>:32770] [locator] old view is: View[asf902(10966:locator)<ec><v0>:32769|5] members: [asf902(10966:locator)<ec><v0>:32769, asf902(Manager:14467)<v4>:32770{lead}, asf902(VM1:14531)<v5>:32771] [locator] [info 2017/04/30 09:25:29.083 UTC <Geode Membership View Creator> tid=0x31] Peer locator received new membership view: View[asf902(10966:locator)<ec><v0>:32769|6] members: [asf902(10966:locator)<ec><v0>:32769] shutdown: [asf902(VM1:14531)<v5>:32771, asf902(Manager:14467)<v4>:32770] [locator] [info 2017/04/30 09:25:29.084 UTC <Geode Membership View Creator> tid=0x31] no recipients for new view aside from myself [vm0] [info 2017/04/30 09:25:30.373 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.test.dunit.rules.LocatorServerStartupRule$$Lambda$46/1396795996.call with 0 args on object: org.apache.geode.test.dunit.rules.LocatorServerStartupRule$$Lambda$46/1396795996@49992b21 [vm1] [info 2017/04/30 09:25:30.905 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$38/1902651587.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$38/1902651587@3497f87a [vm1] Command result for <connect --locator=localhost[46165]>: [vm1] ?[34m _________________________ __ [vm1] / _____/ ______/ ______/ /____/ / [vm1] / / __/ /___ /_____ / _____ / [vm1] / /__/ / ____/ _____/ / / / / [vm1] /______/_/ /______/_/ /_/ 1.2.0-SNAPSHOT [vm1] ?[0m [vm1] ?[36mMonitor and Manage Apache Geode?[0m [vm1] Connecting to Locator at [host=localhost, port=46165] .. [vm1] Connecting to Manager at [host=asf902.gq1.ygridcore.net, port=22392] .. [vm1] Successfully connected to: [host=asf902.gq1.ygridcore.net, port=22392] [vm1] [info 2017/04/30 09:25:31.170 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Got result: null [vm1] from org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$38/1902651587.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$38/1902651587@3497f87a (took 263 ms) [vm2] [info 2017/04/30 09:25:31.183 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$51/1947212534.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$51/1947212534@29748334 [vm2] Command result for <connect --locator=localhost[46165]>: [vm2] ?[34m _________________________ __ [vm2] / _____/ ______/ ______/ /____/ / [vm2] / / __/ /___ /_____ / _____ / [vm2] / /__/ / ____/ _____/ / / / / [vm2] /______/_/ /______/_/ /_/ 1.2.0-SNAPSHOT [vm2] ?[0m [vm2] ?[36mMonitor and Manage Apache Geode?[0m [vm2] Connecting to Locator at [host=localhost, port=46165] .. [vm2] Connecting to Manager at [host=asf902.gq1.ygridcore.net, port=22392] .. [vm2] Successfully connected to: [host=asf902.gq1.ygridcore.net, port=22392] [vm2] [info 2017/04/30 09:25:31.442 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Got result: null [vm2] from org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$51/1947212534.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$51/1947212534@29748334 (took 258 ms) [vm3] [info 2017/04/30 09:25:31.452 UTC <RMI TCP Connection(15)-67.195.81.146> tid=0x1e] Received method: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$13/1429357537.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$13/1429357537@7ad8e1c3 [vm3] Command result for <connect --locator=localhost[46165]>: [vm3] ?[34m _________________________ __ [vm3] / _____/ ______/ ______/ /____/ / [vm3] / / __/ /___ /_____ / _____ / [vm3] / /__/ / ____/ _____/ / / / / [vm3] /______/_/ /______/_/ /_/ 1.2.0-SNAPSHOT [vm3] ?[0m [vm3] ?[36mMonitor and Manage Apache Geode?[0m [vm3] Connecting to Locator at [host=localhost, port=46165] .. [vm3] Connecting to Manager at [host=asf902.gq1.ygridcore.net, port=22392] .. [vm3] Successfully connected to: [host=asf902.gq1.ygridcore.net, port=22392] [vm3] [info 2017/04/30 09:25:32.540 UTC <RMI TCP Connection(15)-67.195.81.146> tid=0x1e] Got result: null [vm3] from org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$13/1429357537.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$13/1429357537@7ad8e1c3 (took 1087 ms) [vm2] [info 2017/04/30 09:25:32.556 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$61/411841575.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$61/411841575@5558005d [vm3] [info 2017/04/30 09:25:32.559 UTC <RMI TCP Connection(15)-67.195.81.146> tid=0x1e] Received method: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$29/1360279604.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$29/1360279604@39d4793e [vm1] [info 2017/04/30 09:25:32.562 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Received method: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$48/554206614.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$48/554206614@997c3f2 [vm2] Command result for <deploy --jar=/tmp/junit7686983196763397747/jar1.jar>: [vm2] Could not parse command string. deploy --jar=/tmp/junit7686983196763397747/jar1.jar [vm3] Command result for <deploy --jar=/tmp/junit7686983196763397747/jar1.jar>: [vm3] Could not parse command string. deploy --jar=/tmp/junit7686983196763397747/jar1.jar [vm1] Command result for <deploy --jar=/tmp/junit7686983196763397747/jar1.jar>: [vm1] Could not parse command string. deploy --jar=/tmp/junit7686983196763397747/jar1.jar [vm2] [info 2017/04/30 09:25:32.762 UTC <RMI TCP Connection(1)-67.195.81.146> tid=0x1b] Got result: EXCEPTION_OCCURRED [vm2] org.junit.ComparisonFailure: expected:<[OK]> but was:<[ERROR]> [vm2] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) [vm2] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) [vm2] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) [vm2] at org.apache.geode.test.dunit.rules.GfshShellConnectionRule.executeAndVerifyCommand(GfshShellConnectionRule.java:231) [vm2] at org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest.loopThroughDeployAndUndeploys(ConcurrentDeployDUnitTest.java:90) [vm2] at org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest.lambda$testMultipleGfshClientToOneServer$f4ef8eee$1(ConcurrentDeployDUnitTest.java:64) [vm2] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [vm2] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [vm2] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [vm2] at java.lang.reflect.Method.invoke(Method.java:498) [vm2] at hydra.MethExecutor.executeObject(MethExecutor.java:245) [vm2] at org.apache.geode.test.dunit.standalone.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:73) [vm2] at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source) [vm2] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [vm2] at java.lang.reflect.Method.invoke(Method.java:498) [vm2] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:346) [vm2] at sun.rmi.transport.Transport$1.run(Transport.java:200) [vm2] at sun.rmi.transport.Transport$1.run(Transport.java:197) [vm2] at java.security.AccessController.doPrivileged(Native Method) [vm2] at sun.rmi.transport.Transport.serviceCall(Transport.java:196) [vm2] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568) [vm2] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826) [vm2] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683) [vm2] at java.security.AccessController.doPrivileged(Native Method) [vm2] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682) [vm2] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [vm2] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [vm2] at java.lang.Thread.run(Thread.java:745) [vm2] from org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$61/411841575.run with 0 args on object: org.apache.geode.management.internal.cli.commands.ConcurrentDeployDUnitTest$$Lambda$61/411841575@5558005d (took 205 ms) {noformat} -- This message was sent by Atlassian JIRA (v6.3.15#6346)