Oops. Correction on #3: Looks like the caller of ManagementAdapter#handleCacheCreation(InternalCache) DOES log any caught exceptions. But because the test uses a log-file that lives in a JUnit TemporaryFolder, we have no visibility of the logged exception after the test completes. This is one time when turning off stdout when a log-file is specified hurts debugging of a CI failure.
On Thu, Jul 20, 2017 at 11:33 AM, Kirk Lund <kl...@apache.org> wrote: > We found the cause of DiskStoreMXBeanSecurityJUnitTest failing in CI: > https://issues.apache.org/jira/browse/GEODE-3251. > > I think we should avoid setting or clearing any standard Java System > properties during runtime (even in tests). These are the properties that > JVM automatically sets: https://docs.oracle.com/javase/tutorial/essential/ > environment/sysprop.html. > > The alternative to swizzling something like "user.dir" at runtime is to > always fork a JVM for any test that needs "user.dir" to point somewhere > special. > > Hope this helps someone else to avoid a similar bug! > > GEODE-3251 is caused by: > > 1) The MemberStarterRule is swizzling the user.dir System property. Jinmei > has a pending change to not change the user.dir. In general, we should > avoid changing that System property at runtime and only fork JVMs for tests > that need processes to run in a specific user.dir. > > 2) FastClasspathScanner throws NoSuchFileException because > System.getProperty("user.dir") returns null. It's null because > MemberStarterRule set it to null. > > 3) The call stack for ManagementAdapter#handleCacheCreation(InternalCache) > catches the NoSuchFileException and swallows it without logging it.. The > ManagementAgent then closes itself in the finally block of > #handleCacheCreation. > > 4) When MBeanServerConnectionRule tries to connect to JMX RMI, it fails > because JMX RMI was closed in #3 above. This throws IOException "Failed to > retrieve RMIServer stub". > > Here's the Exception stack trace that the Management Agent code was > swallowing: > > java.lang.RuntimeException: java.lang.RuntimeException: > java.nio.file.NoSuchFileException: > /var/folders/28/m__9dv1906n60kmz7t71wm680000gn/T/junit7797861898628691451 > at io.github.lukehutch.fastclasspathscanner.FastClasspathScanner.scan( > FastClasspathScanner.java:1115) > at io.github.lukehutch.fastclasspathscanner.FastClasspathScanner.scan( > FastClasspathScanner.java:1143) > at io.github.lukehutch.fastclasspathscanner.FastClasspathScanner.scan( > FastClasspathScanner.java:1166) > at org.apache.geode.management.internal.cli.util.ClasspathScanLoadHelper. > scanPackageForClassesImplementing(ClasspathScanLoadHelper.java:35) > at org.apache.geode.management.internal.cli.CommandManager. > loadGeodeCommands(CommandManager.java:223) > at org.apache.geode.management.internal.cli.CommandManager. > loadCommands(CommandManager.java:176) > at org.apache.geode.management.internal.cli.CommandManager.< > init>(CommandManager.java:83) > at org.apache.geode.management.internal.cli.remote. > CommandProcessor.<init>(CommandProcessor.java:61) > at org.apache.geode.management.internal.cli.remote. > MemberCommandService.<init>(MemberCommandService.java:36) > at org.apache.geode.management.cli.CommandService. > createLocalCommandService(CommandService.java:128) > at org.apache.geode.management.internal.beans.MemberMBeanBridge.<init>( > MemberMBeanBridge.java:348) > at org.apache.geode.management.internal.beans.ManagementAdapter. > handleCacheCreation(ManagementAdapter.java:142) > at org.apache.geode.management.internal.beans.ManagementListener. > handleEvent(ManagementListener.java:106) > at org.apache.geode.distributed.internal.InternalDistributedSystem. > notifyResourceEventListeners(InternalDistributedSystem.java:2198) > at org.apache.geode.distributed.internal.InternalDistributedSystem. > handleResourceEvent(InternalDistributedSystem.java:585) > at org.apache.geode.internal.cache.GemFireCacheImpl. > initialize(GemFireCacheImpl.java:1198) > at org.apache.geode.internal.cache.GemFireCacheImpl. > basicCreate(GemFireCacheImpl.java:763) > at org.apache.geode.internal.cache.GemFireCacheImpl.create( > GemFireCacheImpl.java:750) > at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:175) > at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:222) > at org.apache.geode.test.dunit.rules.ServerStarterRule. > startServer(ServerStarterRule.java:175) > at org.apache.geode.test.dunit.rules.ServerStarterRule. > before(ServerStarterRule.java:91) > at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:46) > 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.runner.JUnitCore.run(JUnitCore.java:137) > at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs( > JUnit4IdeaTestRunner.java:68) > at com.intellij.rt.execution.junit.IdeaTestRunner$Repeater. > startRunnerWithArgs(IdeaTestRunner.java:51) > at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart( > JUnitStarter.java:242) > at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:70) > Caused by: java.lang.RuntimeException: java.nio.file.NoSuchFileException: > /var/folders/28/m__9dv1906n60kmz7t71wm680000gn/T/junit7797861898628691451 > at io.github.lukehutch.fastclasspathscanner.scanner. > Scanner.call(Scanner.java:217) > at io.github.lukehutch.fastclasspathscanner.scanner. > Scanner.call(Scanner.java:61) > at java.util.concurrent.FutureTask.run(FutureTask.java:266) > 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: java.nio.file.NoSuchFileException: /var/folders/28/m__ > 9dv1906n60kmz7t71wm680000gn/T/junit7797861898628691451 > at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86) > at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102) > at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107) > at sun.nio.fs.UnixPath.toRealPath(UnixPath.java:876) > at io.github.lukehutch.fastclasspathscanner.scanner. > Scanner.call(Scanner.java:215) > ... 5 more > java.io.IOException: Failed to retrieve RMIServer stub: > javax.naming.ServiceUnavailableException > [Root exception is java.rmi.ConnectException: Connection refused to host: > 10.118.33.235; nested exception is: > java.net.ConnectException: Connection refused] > at javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:369) > at javax.management.remote.JMXConnectorFactory.connect( > JMXConnectorFactory.java:270) > at org.apache.geode.test.dunit.rules.MBeanServerConnectionRule. > lambda$connect$0(MBeanServerConnectionRule.java:166) > at org.awaitility.core.CallableCondition$ConditionEvaluationWrapper. > eval(CallableCondition.java:100) > at org.awaitility.core.ConditionAwaiter$ConditionPoller.run( > ConditionAwaiter.java:215) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) > at java.util.concurrent.FutureTask.run(FutureTask.java:266) > 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: javax.naming.ServiceUnavailableException [Root exception is > java.rmi.ConnectException: Connection refused to host: 10.118.33.235; > nested exception is: > java.net.ConnectException: Connection refused] > at com.sun.jndi.rmi.registry.RegistryContext.lookup( > RegistryContext.java:122) > at com.sun.jndi.toolkit.url.GenericURLContext.lookup( > GenericURLContext.java:205) > at javax.naming.InitialContext.lookup(InitialContext.java:417) > at javax.management.remote.rmi.RMIConnector.findRMIServerJNDI( > RMIConnector.java:1957) > at javax.management.remote.rmi.RMIConnector.findRMIServer( > RMIConnector.java:1924) > at javax.management.remote.rmi.RMIConnector.connect(RMIConnector.java:287) > ... 9 more > Caused by: java.rmi.ConnectException: Connection refused to host: > 10.118.33.235; nested exception is: > java.net.ConnectException: Connection refused > at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:619) > at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:216) > at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:202) > at sun.rmi.server.UnicastRef.newCall(UnicastRef.java:342) > at sun.rmi.registry.RegistryImpl_Stub.lookup(Unknown Source) > at com.sun.jndi.rmi.registry.RegistryContext.lookup( > RegistryContext.java:118) > ... 14 more > Caused by: java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at java.net.AbstractPlainSocketImpl.doConnect( > AbstractPlainSocketImpl.java:350) > at java.net.AbstractPlainSocketImpl.connectToAddress( > AbstractPlainSocketImpl.java:206) > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java: > 188) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > at java.net.Socket.connect(Socket.java:589) > at java.net.Socket.connect(Socket.java:538) > at java.net.Socket.<init>(Socket.java:434) > at java.net.Socket.<init>(Socket.java:211) > at sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket( > RMIDirectSocketFactory.java:40) > at sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket( > RMIMasterSocketFactory.java:148) > at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:613) > ... 19 more > >
