spring-projects / spring-session

Spring Session
https://spring.io/projects/spring-session
Apache License 2.0
1.86k stars 1.11k forks source link

GemFire sample integration test fails with JAVA_TOOL_OPTIONS env variable #669

Closed vpavic closed 7 years ago

vpavic commented 7 years ago

This consequently causes the project build to fail. If I don't export the JAVA_TOOL_OPTIONS environment variable then everything runs fine.

I guess this is related to that fact that JVM prints information about special variable, such as JAVA_TOOL_OPTIONS or _JAVA_OPTIONS, to stderr. For example:

$ JAVA_TOOL_OPTIONS="-Dtest" java -version
Picked up JAVA_TOOL_OPTIONS: -Dtest
java version "1.8.0_111"
Java(TM) SE Runtime Environment (build 1.8.0_111-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.111-b14, mixed mode)

/cc @jxblum since this is GemFire related you might want to take a look.

Here's the relevant build output:

:samples:httpsession-gemfire-clientserver:runGemFireServer
STARTING GEMFIRE SERVER...
:samples:httpsession-gemfire-clientserver:integrationTomcatRun
[warn 2016/11/12 15:37:36.199 CET <poolTimer-DEFAULT-2> tid=0x187] Could not connect to: localhost:39359
java.net.ConnectException: Connection refused (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 com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:88)
    at com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:60)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:1011)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:946)
    at com.gemstone.gemfire.internal.SocketCreator.connectForClient(SocketCreator.java:915)
    at com.gemstone.gemfire.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:113)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:114)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:231)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.prefillConnection(ConnectionManagerImpl.java:794)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.prefill(ConnectionManagerImpl.java:737)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl$PrefillConnectionsTask.run2(ConnectionManagerImpl.java:888)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1258)
    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)

[warn 2016/11/12 15:37:36.199 CET <localhost-startStop-1> tid=0x17a] Could not connect to: localhost:39359
java.net.ConnectException: Connection refused (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 com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:88)
    at com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:60)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:1011)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:946)
    at com.gemstone.gemfire.internal.SocketCreator.connectForClient(SocketCreator.java:915)
    at com.gemstone.gemfire.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:113)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:114)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:231)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.borrowConnection(ConnectionManagerImpl.java:214)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.acquireConnection(PoolImpl.java:834)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.checkConnected(PoolImpl.java:848)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.findQueueServers(QueueManagerImpl.java:799)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.initializeConnections(QueueManagerImpl.java:427)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.start(QueueManagerImpl.java:302)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.start(PoolImpl.java:322)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.finishCreate(PoolImpl.java:150)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.create(PoolImpl.java:136)
    at com.gemstone.gemfire.internal.cache.PoolFactoryImpl.create(PoolFactoryImpl.java:448)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.determineDefaultPool(GemFireCacheImpl.java:2803)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.initializeDeclarativeCache(GemFireCacheImpl.java:1154)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.init(GemFireCacheImpl.java:1018)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:678)
    at com.gemstone.gemfire.cache.client.ClientCacheFactory.basicCreate(ClientCacheFactory.java:207)
    at com.gemstone.gemfire.cache.client.ClientCacheFactory.create(ClientCacheFactory.java:162)
    at org.springframework.data.gemfire.client.ClientCacheFactoryBean.createCache(ClientCacheFactoryBean.java:335)
    at org.springframework.data.gemfire.CacheFactoryBean.resolveCache(CacheFactoryBean.java:250)
    at org.springframework.data.gemfire.CacheFactoryBean.init(CacheFactoryBean.java:191)
    at org.springframework.data.gemfire.CacheFactoryBean.getObject(CacheFactoryBean.java:178)
    at org.springframework.data.gemfire.CacheFactoryBean.getObject(CacheFactoryBean.java:88)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:168)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:103)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1606)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:317)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:207)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1131)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1059)
    at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:835)
    at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:741)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:467)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1128)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1022)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:512)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:296)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:754)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:866)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:542)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5014)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5524)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
    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)

[warn 2016/11/12 15:37:36.212 CET <localhost-startStop-1> tid=0x17a] Could not create a queue. No queue servers available.

[warn 2016/11/12 15:37:36.220 CET <poolTimer-DEFAULT-2> tid=0x187] Could not connect to: localhost:39359
java.net.ConnectException: Connection refused (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 com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:88)
    at com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:60)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:1011)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:946)
    at com.gemstone.gemfire.internal.SocketCreator.connectForClient(SocketCreator.java:915)
    at com.gemstone.gemfire.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:113)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:114)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:231)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.prefillConnection(ConnectionManagerImpl.java:794)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.prefill(ConnectionManagerImpl.java:737)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl$PrefillConnectionsTask.run2(ConnectionManagerImpl.java:888)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1258)
    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)

[warn 2016/11/12 15:37:36.242 CET <poolTimer-DEFAULT-2> tid=0x187] Could not connect to: localhost:39359
java.net.ConnectException: Connection refused (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 com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:88)
    at com.gemstone.gemfire.internal.SocketUtils.connect(SocketUtils.java:60)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:1011)
    at com.gemstone.gemfire.internal.SocketCreator.connect(SocketCreator.java:946)
    at com.gemstone.gemfire.internal.SocketCreator.connectForClient(SocketCreator.java:915)
    at com.gemstone.gemfire.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:113)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:114)
    at com.gemstone.gemfire.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:231)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.prefillConnection(ConnectionManagerImpl.java:794)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl.prefill(ConnectionManagerImpl.java:737)
    at com.gemstone.gemfire.cache.client.internal.pooling.ConnectionManagerImpl$PrefillConnectionsTask.run2(ConnectionManagerImpl.java:888)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1258)
    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)

No bean named 'DEFAULT' available
Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ClusteredSpringSessions' defined in org.springframework.session.data.gemfire.config.annotation.web.http.GemFireHttpSessionConfiguration: Invocation of init method failed; nested exception is com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ClusteredSpringSessions' defined in org.springframework.session.data.gemfire.config.annotation.web.http.GemFireHttpSessionConfiguration: Invocation of init method failed; nested exception is com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1583)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:296)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:754)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:866)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:542)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5014)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5524)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
    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: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.getAllConnections(QueueManagerImpl.java:188)
    at com.gemstone.gemfire.cache.client.internal.OpExecutorImpl.executeOnQueuesAndReturnPrimaryResult(OpExecutorImpl.java:522)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.executeOnQueuesAndReturnPrimaryResult(PoolImpl.java:765)
    at com.gemstone.gemfire.cache.client.internal.RegisterInterestOp.execute(RegisterInterestOp.java:55)
    at com.gemstone.gemfire.cache.client.internal.ServerRegionProxy.registerInterest(ServerRegionProxy.java:397)
    at com.gemstone.gemfire.internal.cache.LocalRegion.processSingleInterest(LocalRegion.java:3834)
    at com.gemstone.gemfire.internal.cache.LocalRegion.registerInterest(LocalRegion.java:3924)
    at org.springframework.data.gemfire.client.ClientRegionFactoryBean.registerInterests(ClientRegionFactoryBean.java:312)
    at org.springframework.data.gemfire.client.ClientRegionFactoryBean.postProcess(ClientRegionFactoryBean.java:299)
    at org.springframework.data.gemfire.client.ClientRegionFactoryBean.afterPropertiesSet(ClientRegionFactoryBean.java:102)
    at org.springframework.session.data.gemfire.config.annotation.web.http.support.GemFireCacheTypeAwareRegionFactoryBean.newClientRegion(GemFireCacheTypeAwareRegionFactoryBean.java:163)
    at org.springframework.session.data.gemfire.config.annotation.web.http.support.GemFireCacheTypeAwareRegionFactoryBean.afterPropertiesSet(GemFireCacheTypeAwareRegionFactoryBean.java:98)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1642)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1579)
    ... 23 more
Caused by: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl$ConnectionList.setPrimaryDiscoveryFailed(QueueManagerImpl.java:1310)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.initializeConnections(QueueManagerImpl.java:434)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.start(QueueManagerImpl.java:302)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.start(PoolImpl.java:322)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.finishCreate(PoolImpl.java:150)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.create(PoolImpl.java:136)
    at com.gemstone.gemfire.internal.cache.PoolFactoryImpl.create(PoolFactoryImpl.java:448)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.determineDefaultPool(GemFireCacheImpl.java:2803)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.initializeDeclarativeCache(GemFireCacheImpl.java:1154)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.init(GemFireCacheImpl.java:1018)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:678)
    at com.gemstone.gemfire.cache.client.ClientCacheFactory.basicCreate(ClientCacheFactory.java:207)
    at com.gemstone.gemfire.cache.client.ClientCacheFactory.create(ClientCacheFactory.java:162)
    at org.springframework.data.gemfire.client.ClientCacheFactoryBean.createCache(ClientCacheFactoryBean.java:335)
    at org.springframework.data.gemfire.CacheFactoryBean.resolveCache(CacheFactoryBean.java:250)
    at org.springframework.data.gemfire.CacheFactoryBean.init(CacheFactoryBean.java:191)
    at org.springframework.data.gemfire.CacheFactoryBean.getObject(CacheFactoryBean.java:178)
    at org.springframework.data.gemfire.CacheFactoryBean.getObject(CacheFactoryBean.java:88)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:168)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:103)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1606)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:317)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:207)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1131)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1059)
    at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:835)
    at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:741)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:467)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1128)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1022)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:512)
    ... 22 more
Exception sending context initialized event to listener instance of class org.springframework.web.context.ContextLoaderListener
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ClusteredSpringSessions' defined in org.springframework.session.data.gemfire.config.annotation.web.http.GemFireHttpSessionConfiguration: Invocation of init method failed; nested exception is com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1583)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:296)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:754)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:866)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:542)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5014)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5524)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
    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: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.getAllConnections(QueueManagerImpl.java:188)
    at com.gemstone.gemfire.cache.client.internal.OpExecutorImpl.executeOnQueuesAndReturnPrimaryResult(OpExecutorImpl.java:522)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.executeOnQueuesAndReturnPrimaryResult(PoolImpl.java:765)
    at com.gemstone.gemfire.cache.client.internal.RegisterInterestOp.execute(RegisterInterestOp.java:55)
    at com.gemstone.gemfire.cache.client.internal.ServerRegionProxy.registerInterest(ServerRegionProxy.java:397)
    at com.gemstone.gemfire.internal.cache.LocalRegion.processSingleInterest(LocalRegion.java:3834)
    at com.gemstone.gemfire.internal.cache.LocalRegion.registerInterest(LocalRegion.java:3924)
    at org.springframework.data.gemfire.client.ClientRegionFactoryBean.registerInterests(ClientRegionFactoryBean.java:312)
    at org.springframework.data.gemfire.client.ClientRegionFactoryBean.postProcess(ClientRegionFactoryBean.java:299)
    at org.springframework.data.gemfire.client.ClientRegionFactoryBean.afterPropertiesSet(ClientRegionFactoryBean.java:102)
    at org.springframework.session.data.gemfire.config.annotation.web.http.support.GemFireCacheTypeAwareRegionFactoryBean.newClientRegion(GemFireCacheTypeAwareRegionFactoryBean.java:163)
    at org.springframework.session.data.gemfire.config.annotation.web.http.support.GemFireCacheTypeAwareRegionFactoryBean.afterPropertiesSet(GemFireCacheTypeAwareRegionFactoryBean.java:98)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1642)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1579)
    ... 23 more
Caused by: com.gemstone.gemfire.cache.NoSubscriptionServersAvailableException: Primary discovery failed.
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl$ConnectionList.setPrimaryDiscoveryFailed(QueueManagerImpl.java:1310)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.initializeConnections(QueueManagerImpl.java:434)
    at com.gemstone.gemfire.cache.client.internal.QueueManagerImpl.start(QueueManagerImpl.java:302)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.start(PoolImpl.java:322)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.finishCreate(PoolImpl.java:150)
    at com.gemstone.gemfire.cache.client.internal.PoolImpl.create(PoolImpl.java:136)
    at com.gemstone.gemfire.internal.cache.PoolFactoryImpl.create(PoolFactoryImpl.java:448)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.determineDefaultPool(GemFireCacheImpl.java:2803)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.initializeDeclarativeCache(GemFireCacheImpl.java:1154)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.init(GemFireCacheImpl.java:1018)
    at com.gemstone.gemfire.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:678)
    at com.gemstone.gemfire.cache.client.ClientCacheFactory.basicCreate(ClientCacheFactory.java:207)
    at com.gemstone.gemfire.cache.client.ClientCacheFactory.create(ClientCacheFactory.java:162)
    at org.springframework.data.gemfire.client.ClientCacheFactoryBean.createCache(ClientCacheFactoryBean.java:335)
    at org.springframework.data.gemfire.CacheFactoryBean.resolveCache(CacheFactoryBean.java:250)
    at org.springframework.data.gemfire.CacheFactoryBean.init(CacheFactoryBean.java:191)
    at org.springframework.data.gemfire.CacheFactoryBean.getObject(CacheFactoryBean.java:178)
    at org.springframework.data.gemfire.CacheFactoryBean.getObject(CacheFactoryBean.java:88)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:168)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:103)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1606)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:317)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:207)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1131)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1059)
    at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:835)
    at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:741)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:467)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1128)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1022)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:512)
    ... 22 more
Error listenerStart
Context [] startup failed due to previous errors
The web application [] created a ThreadLocal with key of type [com.gemstone.gemfire.internal.cache.EventID$1] (value [com.gemstone.gemfire.internal.cache.EventID$1@4fd8fb41]) and a value of type [com.gemstone.gemfire.internal.cache.EventID.ThreadAndSequenceIDWrapper] (value [com.gemstone.gemfire.internal.cache.EventID$ThreadAndSequenceIDWrapper@70603153]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@249a5e98]) and a value of type [com.gemstone.gemfire.internal.stats50.Atomic50StatisticsImpl.ThreadStorage] (value [com.gemstone.gemfire.internal.stats50.Atomic50StatisticsImpl$ThreadStorage@12cf4e54]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@6bdefd1d]) and a value of type [com.gemstone.gemfire.internal.stats50.Atomic50StatisticsImpl.ThreadStorage] (value [com.gemstone.gemfire.internal.stats50.Atomic50StatisticsImpl$ThreadStorage@1dc61060]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
Started Tomcat Server
The Server is running at http://localhost:45971
:samples:httpsession-gemfire-clientserver:integrationTest
Picked up JAVA_TOOL_OPTIONS: -Dhttp.proxyHost=localhost -Dhttp.proxyPort=3128 -Dhttps.proxyHost=localhost -Dhttps.proxyPort=3128

sample.AttributeTests > first visit no attributes FAILED
    org.codehaus.groovy.runtime.powerassert.PowerAssertionError at AttributeTests.groovy:33

2 tests completed, 1 failed, 1 skipped
:samples:httpsession-gemfire-clientserver:integrationTest FAILED
:samples:httpsession-gemfire-clientserver:integrationTomcatStop

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':samples:httpsession-gemfire-clientserver:integrationTest'.
> There were failing tests. See the report at: file:///home/vedran/dev/projects/spring-session/samples/httpsession-gemfire-clientserver/build/reports/integration-tests/index.html

* Try:
Run with --stacktrace option to get the stack trace. Run with --info or --debug option to get more log output.

BUILD FAILED

Total time: 7 mins 48.229 secs

Other relevant information about environment:

$ cat /etc/os-release 
NAME="Ubuntu"
VERSION="16.10 (Yakkety Yak)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 16.10"
VERSION_ID="16.10"
HOME_URL="http://www.ubuntu.com/"
SUPPORT_URL="http://help.ubuntu.com/"
BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="http://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=yakkety
UBUNTU_CODENAME=yakkety
$ uname -a
Linux vpavic-nb 4.8.0-27-generic #29-Ubuntu SMP Thu Oct 20 21:03:13 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
vpavic commented 7 years ago

@jxblum Do you have any idea on this one?

jxblum commented 7 years ago

@vpavic (cc'ing @rwinch) - I think it is safe to say the JAVA_TOOL_OPTIONS environment variable had nothing to do with this failure. It is a mere coincidence that you set this env. var and 1 of the GemFire sample integration tests (:samples:httpsession-gemfire-clientserver) failed.

In fact, this (GemFire "client/server") test is susceptible to same failure as the :samples:httpsession-gemfire-boot sample integration test (also a "client/server" based test) that I have been trying to resolve in #672.

Recently, I posted the exact same Stack Trace here.

I am closing this as a duplicate!

vpavic commented 7 years ago

@jxblum I wouldn't agree with your assesment.

I've got a machine that's got JAVA_TOOL_OPTIONS exported via /etc/environment (due to the fact it's mostly used behind a network proxy) and Spring Session build has never passed for me on that machine unless I remove export of JAVA_TOOL_OPTIONS from /etc/environment and reboot.

So that's 100% reproducibility.

jxblum commented 7 years ago

@vpavic - Right, agreed/understood.

For some reason (which is not apparent with the details you provided above) your environment configuration is definitely leading to the same failure and "cause" captured in #672. So while you are able to reproduce this problem 100% of the time with "seemingly" only the following Java System properties set (-Dhttp.proxyHost=localhost -Dhttp.proxyPort=3128 -Dhttps.proxyHost=localhost -Dhttps.proxyPort=3128), these errors (and more specifically, the "cause", as captured in #672) are still likely to occur even when these Java System properties are not set.

Having said that, let me shed more light on what might possibly be causing your problems.

First, understand that in no way does GemFire use the HTTP protocol between cache clients and servers (much less for any other type of communications... membership, P2P, WAN, etc); hopefully, the reason for this is obvious.

GemFire exclusively uses TCP/IP-based Socket connections between client and servers in a GemFire client/server topology.

This is not to say you won't find components in GemFire (e.g. Gfsh or Pulse) that do use HTTP and are affected by these Java HTTP proxy System properties, but these components are independent of the client/server infrastructure and protocols (i.e. these tools have and use their own communications infrastructure).

According to... http://docs.oracle.com/javase/8/docs/technotes/guides/net/proxies.html

In order for the HTTP proxy configuration settings to have any effect, an "HTTP" connection would need to be made, which in turn would summon the HTTP protocol handler that would take these HTTP proxy configuration settings into account. The only Java class I am aware of that handles the HTTP protocol/scheme is URL. Perhaps some SocketFactory "provider implementations" do as well, but we'll get back to this in a minute.

GemFire does not use URLs to make connections, nor does it explicitly construct (TCP/IP, or otherwise... UDP) Sockets with Proxy objects.

In fact, GemFire does all of its Socket creation (for client/servers, etc) using it's own SocketCreator class, which is not something GemFire even exposes. Thus, the only way to affect it is by System properties GemFire recognizes (PROXY settings are not one of them).

Under-the-hood, GemFire's SocketCreator class does use a javax.net.SocketFactory to create Sockets, but this is primarily used to handle SSL, not PROXY settings.

So, what does this mean?

Well, I just tested locally using the :spring-session-samples-javaconfig-gemfire-clientserver sample integrationTest, and all works as expected.

Specifically, I set the http[s].proxyHost and http[s].proxyPort Java System properties for both the GemFire client and server used in this sample integration test. I even ensured that both the GemFire client and server JVM processes got these Java System properties on startup...

  ...
  Build-Date: 2016-12-15 21:30:03 +0000
  Build-Id: root 8
  Build-Java-Version: 1.8.0_111
  Build-Platform: Linux 3.19.0-64-generic amd64
  GemFire-Source-Date: 2016-12-05 21:18:08 +0000
  GemFire-Source-Repository: HEAD
  GemFire-Source-Revision: dafe5e7bbb94f2f8f0ee06c5b8582382084cb2cc
  Product-Name: Pivotal GemFire
  Product-Version: 9.0.1
  Source-Date: 2016-12-15 18:19:41 +0000
  Source-Repository: support/9.0
  Source-Revision: 1af9c8f38f2e16bdb4d5887e34e48568fc93c161
  Native version: native code unavailable
  Running on: /10.99.199.11, 8 cpu(s), x86_64 Mac OS X 10.10.5 
  Process ID: 10381
  User: jblum
  Current dir: /Users/jblum/pivdev/spring-session
...
  Command Line Parameters:
    -XX:MaxPermSize=256m
    -XX:+HeapDumpOnOutOfMemoryError
    -Xmx1024m
    -Dfile.encoding=UTF-8
    -Duser.country=US
    -Duser.language=en
    -Duser.variant
  Class Path:
    /Users/jblum/.gradle/wrapper/dists/gradle-3.3-bin/64bhckfm0iuu9gap9hg3r7ev2/gradle-3.3/lib/gradle-launcher-3.3.jar
  Library Path:
    /Users/jblum/Library/Java/Extensions
    /Library/Java/Extensions
    /Network/Library/Java/Extensions
    /System/Library/Java/Extensions
    /usr/lib/java
    .
  System Properties:
      ...
      file.separator = /
      ftp.nonProxyHosts = local|*.local|169.254/16|*.169.254/16
      gopherProxySet = false
      http.nonProxyHosts = local|*.local|169.254/16|*.169.254/16
      http.proxyHost = dummy.example.com
      http.proxyPort = 3128
      https.proxyHost = dummy.example.com
      https.proxyPort = 3128
      ...
      path.separator = :
      socksNonProxyHosts = local|*.local|169.254/16|*.169.254/16
      socksProxyHost = dummy.example.com
      socksProxyPort = 3128
      ...

NOTE: to get this output, I needed to turn up GemFire logging (to "config") and send the log entries to a file. I have created a branch (gh-669) in my Spring Session clone with the necessary build configuration and class file changes.

Now, you will notice that I have additionally set the socksProxyHost and socksProxyPort Java System properties as well, which are more likely to have an effect than the HTTP proxy configuration settings, given that GemFire creates TCP/IP Socket connections between clients and servers.

Additionally, you will notice that the ftp.nonProxyHosts, http.nonProxyHosts and socksNonProxyHosts are all set to handle "localhost" based connections between network applications (like GemFire clients and servers) running locally. I did NOT explicitly set those; the Java Runtime Environment did; i.e. the JRE provides it's own defaults when not explicitly set! This is also the reason why I changed the PROXY host to dummy.example.com. I wanted it to deliberately fail if these settings were in fact in effect. I cannot fix the problem if I cannot REPRODUCE it 100%, locally.

As it turns out, these settings had NO effect whatsoever! The :spring-session-samples-javaconfig-gemfire-clientserver integration test ran and PASSED as expected.

So, how would GemFire take PROXY configuration settings into account?

A user would have to specifically provide a SocketFactory provider implementation that acknowledges these Java System properties, custom System properties the provider exposes, or perhaps configuration from a Properties file, or something. Here is one example.

This provider could have been installed in the JDK/JRE (libs/ext) in this environment, I don't know.

Either way, I am convinced this is not a problem with the sample or GemFire in this case.

vpavic commented 7 years ago

Thank you for the detailed write up @jxblum.

I'd like to stress one more time that my issues are not due to proxy related JVM system properties, but rather to the presence of JAVA_TOOL_OPTIONS environment variable which is exported via /etc/environment.

Proxy is the reason I need to use JAVA_TOOL_OPTIONS environment variable, but the build for GemFire based client-server samples fails regardless of the value assigned to the variable. That's why I used JAVA_TOOL_OPTIONS="-Dtest" as an example in my opening comment. When I remove export from /etc/environment and reboot the build runs just fine.

I'll try to gather more information about what actually happens in these two scenarios.

jxblum commented 7 years ago

Thanks @vpavic for the additional feedback/clarification.

Proxy is the reason I need to use JAVA_TOOL_OPTIONS environment variable, but the build for GemFire based client-server samples fails regardless of the value assigned to the variable. That's why I used JAVA_TOOL_OPTIONS="-Dtest" as an example in my opening comment. When I remove export from /etc/environment and reboot the build runs just fine.

That is bizarre.

While the java launcher (and other JDK tools I am sure) use the JAVA_TOOL_OPTIONS environment variable to affect the JRE and specifically, configure the JVM, I don't know why this would adversely affect the GemFire client and server JVM processes, especially with such a benign System property (i.e. -Dtest).

GemFire does care about "gemfire." prefixed Java System properties (i.e. it will fail if you specify a gemfire.<non-existing-property>). But, GemFire does not give hoot about any other non-GemFire, Java System property.

I'd like to stress one more time that my issues are not due to proxy related JVM system properties, but rather to the presence of JAVA_TOOL_OPTIONS environment variable which is exported via /etc/environment.

Right, my apologies for the misunderstanding. I incorrectly assumed the (HTTP) Proxy settings were causing an issue when I saw the client/server communication problems, and specifically, the darn NoSubscriptionServersAvailableException caused by the race condition I noted in #672, and have yet to figure out exactly how to effectively workaround without introducing a mess.

So, I just set the JAVA_TOOL_OPTIONS env var and kicked off an updated Spring Session master build...

$ export JAVA_TOOL_OPTIONS=-Dtest
$ echo $JAVA_TOOL_OPTIONS
-Dtest
$ gradlew clean build install
Picked up JAVA_TOOL_OPTIONS: -Dtest
Starting a Gradle Daemon, 2 incompatible and 1 stopped Daemons could not be reused, use --status for details
:clean
...

And, whaddya know... BOOM!

:spring-session-samples-boot-gemfire:runGemFireServer
STARTING GEMFIRE SERVER...
:spring-session-samples-boot-gemfire:integrationTest
Picked up JAVA_TOOL_OPTIONS: -Dtest

sample.AttributeTests > createAttribute FAILED
    java.lang.IllegalStateException
        Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException
            Caused by: org.springframework.beans.factory.BeanCreationException
                Caused by: java.lang.IllegalStateException

sample.AttributeTests > noAttributes FAILED
    java.lang.IllegalStateException
        Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException
            Caused by: org.springframework.beans.factory.BeanCreationException
                Caused by: java.lang.IllegalStateException

2 tests completed, 2 failed
:spring-session-samples-boot-gemfire:integrationTest FAILED

FAILURE: Build failed with an exception.

I'll have a look.

Thanks @vpavic.

jxblum commented 7 years ago

@vpavic (cc'ing @rwinch) -

So, looking at the output from the test...

sample.AttributeTests > createAttribute FAILED
    java.lang.IllegalStateException
        Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException
            Caused by: org.springframework.beans.factory.BeanCreationException
                Caused by: java.lang.IllegalStateException

It is clearly tripping on the IllegalStateException that I throw in the Spring BPP if the GemFire Server does not start and notify the client within the specified timeout. The integrationTest is noticeably waiting for a duration of "60 seconds".

So, I turned on logging and tried to get both the GemFire client and server to spit out log files (at log-level, "config") to see what I could see. As it turns out, only the client ever generated log files. For whatever reason, the GemFire Server does not actually start at all!

So, I then tried to run the spring-session/samples/boot/gemfire/src/main/java/sample/server/GemFireSever in my IDE (IJ) with the JAVA_TOOL_OPTIONS environment variable set, thinking, well, if GemFire is blowing up, then I should at least see a Java Exception/Error from the JRE/JVM. Nope! The GemFire Server started just fine...

/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/bin/java -server -ea -Didea.launcher.port=7532 "-Didea.launcher.bin.path=/Applications/IntelliJ IDEA CE.app/Contents/bin" -Dfile.encoding=UTF-8 -classpath "/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/packager.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/lib/tools.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/jaccess.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Users/jblum/pivdev/spring-session/samples/boot/gemfire/build/classes/main:/Users/jblum/pivdev/spring-session/samples/boot/gemfire/build/resources/main:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot-starter-thymeleaf/2.0.0.BUILD-SNAPSHOT/98388881cb04ec9a49b2a6fc553667071057eea1/spring-boot-starter-thymeleaf-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot-starter-web/2.0.0.BUILD-SNAPSHOT/461fd11c3a262056d7b462878fbd0b47f000ae85/spring-boot-starter-web-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.webjars/bootstrap/2.3.2/5c0106448aeeac9186879ef385cd1606aec9dc69/bootstrap-2.3.2.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.webjars/webjars-locator/0.32/950f7362dc70736b80681037b81df1148a64a04a/webjars-locator-0.32.jar:/Users/jblum/pivdev/spring-session/spring-session/build/classes/main:/Users/jblum/pivdev/spring-session/spring-session/build/resources/main:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.data/spring-data-gemfire/2.0.0.BUILD-SNAPSHOT/7442c088d05c2254b69f8fc0704383e3f2583666/spring-data-gemfire-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot-starter/2.0.0.BUILD-SNAPSHOT/1cfb1132b8ed09229ceb7a3bd67050eb16339bcb/spring-boot-starter-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.shell/spring-shell/1.1.0.RELEASE/32fcf5aacf7bd5d997dbf2f8f95ed9369d81d9c0/spring-shell-1.1.0.RELEASE.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.thymeleaf/thymeleaf-spring4/2.1.5.RELEASE/74cb9028e99597b5d71a98e919fd531a7fc290b4/thymeleaf-spring4-2.1.5.RELEASE.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/nz.net.ultraq.thymeleaf/thymeleaf-layout-dialect/1.4.0/8d7810c069ed1534b9631fb1e85c35973546086/thymeleaf-layout-dialect-1.4.0.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot-starter-tomcat/2.0.0.BUILD-SNAPSHOT/7cb810645f98b5ebd4718c266e49930349293f99/spring-boot-starter-tomcat-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.hibernate/hibernate-validator/5.3.4.Final/2f6c8c0b646afe18e3ad205726729d3c4a85fe2e/hibernate-validator-5.3.4.Final.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-databind/2.8.6/c43de61f74ecc61322ef8f402837ba65b0aa2bf4/jackson-databind-2.8.6.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-web/5.0.0.M3/2d97eb3abc64dd94052f9d2c62231269092cae4e/spring-web-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-webmvc/5.0.0.M3/6dd5e061e24384a3281446a2be55855628026980/spring-webmvc-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.webjars/jquery/1.9.0/b17a8a51561058eae4199a5d7d835144a03a3aeb/jquery-1.9.0.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.webjars/webjars-locator-core/0.30/e2ae00945e98c8c429471d2d643ad2030ba90e19/webjars-locator-core-0.30.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-context-support/5.0.0.M3/4a205caee2e236d11263449fa5a68b661cc8cc2e/spring-context-support-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-tx/5.0.0.M3/418b8dc5bd6678e85c56698639ab9574105f95a9/spring-tx-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.data/spring-data-commons/2.0.0.BUILD-SNAPSHOT/ce905a55efb947892d47c83ffc2e5b02b0c3712b/spring-data-commons-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/io.pivotal.gemfire/geode-core/9.0.1/20f9bfd931d7495ac597e58ec1bd68057743cf3/geode-core-9.0.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/jline/jline/2.11/9504d5e2da5d78237239c5226e8200ec21182040/jline-2.11.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/io.pivotal.gemfire/geode-cq/9.0.1/8bf1be745459753fbfa2187a8bc8e1b0f798055a/geode-cq-9.0.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/com.google.guava/guava/15.0/ed727a8d9f247e2050281cb083f1c77b09dcb5cd/guava-15.0.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/io.pivotal.gemfire/geode-wan/9.0.1/cb3054614fef0009b51b430f4b22d6b544085cdd/geode-wan-9.0.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/cglib/cglib/2.2.2/a47a971686474124562bdd4a7ccbd8ac8c3e8b11/cglib-2.2.2.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/antlr/antlr/2.7.7/83cd2cd674a217ade95a4bb83a8a14f351f48bd0/antlr-2.7.7.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.aspectj/aspectjweaver/1.8.9/db28774f477f07220eac18d5ec9c4e01f48589d7/aspectjweaver-1.8.9.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-annotations/2.8.0/45b426f7796b741035581a176744d91090e2e6fb/jackson-annotations-2.8.0.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot/2.0.0.BUILD-SNAPSHOT/40020c34e30c2db5d74d385d3b38d8a736555fdc/spring-boot-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot-autoconfigure/2.0.0.BUILD-SNAPSHOT/dbb28f50aaa704e13ca48058e7a0382b5047d1e7/spring-boot-autoconfigure-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework.boot/spring-boot-starter-logging/2.0.0.BUILD-SNAPSHOT/bc2abac2af919501f8f511e899d92151dcfb0b70/spring-boot-starter-logging-2.0.0.BUILD-SNAPSHOT.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-core/5.0.0.M3/bbac2fd12b22fa0e243766890ac97ee051c62c25/spring-core-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.yaml/snakeyaml/1.17/7a27ea250c5130b2922b86dea63cbb1cc10a660c/snakeyaml-1.17.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.thymeleaf/thymeleaf/2.1.5.RELEASE/513bffa3daaac277460c1a0a2dccb228fa40569e/thymeleaf-2.1.5.RELEASE.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-api/1.7.22/a1c83373863cec7ae8d89dc1c5722d8cb6ec0309/slf4j-api-1.7.22.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.codehaus.groovy/groovy/2.4.7/10870e6511f544ce45152d0ad08d7514a00c8201/groovy-2.4.7.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.tomcat.embed/tomcat-embed-core/8.5.6/960834b5abc6b2135250487abf6c060a0fa5a22e/tomcat-embed-core-8.5.6.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.tomcat.embed/tomcat-embed-el/8.5.6/a102298d8dc72f4065533d5962953d753b172602/tomcat-embed-el-8.5.6.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.tomcat.embed/tomcat-embed-websocket/8.5.6/6f6940a216b380ea8506530c374fcfeef820ba54/tomcat-embed-websocket-8.5.6.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/javax.validation/validation-api/1.1.0.Final/8613ae82954779d518631e05daa73a6a954817d5/validation-api-1.1.0.Final.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.jboss.logging/jboss-logging/3.3.0.Final/3616bb87707910296e2c195dc016287080bba5af/jboss-logging-3.3.0.Final.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/com.fasterxml/classmate/1.3.3/864c8e370a691e343210cc7c532fc198cee460d8/classmate-1.3.3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-core/2.8.6/2ef7b1cc34de149600f5e75bc2d5bf40de894e60/jackson-core-2.8.6.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-aop/5.0.0.M3/93f5a4f999dd8e94182eb5d08ef56d9e8710c8a0/spring-aop-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-beans/5.0.0.M3/cb9832eb0a43abe4b04fe6de8eed0120aa62c5f5/spring-beans-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-context/5.0.0.M3/f8451deb0a14c6a28e06d610781c99d169e27ded/spring-context-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.springframework/spring-expression/5.0.0.M3/b7f7181aedae41aef6d12d58212f2c9b5a0b1709/spring-expression-5.0.0.M3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.commons/commons-lang3/3.1/905075e6c80f206bbe6cf1e809d2caa69f420c76/commons-lang3-3.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.commons/commons-compress/1.9/cc18955ff1e36d5abd39a14bfe82b19154330a34/commons-compress-1.9.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/com.github.stephenc.findbugs/findbugs-annotations/1.3.9-1/a6b11447635d80757d64b355bed3c00786d86801/findbugs-annotations-1.3.9-1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.jgroups/jgroups/3.6.10.Final/fc0ff5a8a9de27ab62939956f705c2909bf86bc2/jgroups-3.6.10.Final.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/commons-io/commons-io/2.3/cd8d6ffc833cc63c30d712a180f4663d8f55799b/commons-io-2.3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/commons-lang/commons-lang/2.5/b0236b252e86419eef20c31a44579d2aee2f0a69/commons-lang-2.5.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/it.unimi.dsi/fastutil/7.0.2/20876232e2cd12563507e4c9e85bd7948bc0656f/fastutil-7.0.2.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/javax.resource/javax.resource-api/1.7/ae40e0864eb1e92c48bf82a2a3399cbbf523fb79/javax.resource-api-1.7.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/net.java.dev.jna/jna/4.2.2/5012450aee579c3118ff09461d5ce210e0cdc2a9/jna-4.2.2.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/asm/asm/3.3.1/1d5f20b4ea675e6fab6ab79f1cd60ec268ddc015/asm-3.3.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/net.sf.jopt-simple/jopt-simple/5.0.1/20f7d76f9d06033d68f1b8e58666e7c542e91f08/jopt-simple-5.0.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-api/2.7/8de00e382a817981b737be84cb8def687d392963/log4j-api-2.7.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.logging.log4j/log4j-core/2.7/a3f2b4e64c61a7fc1ed8f1e5ba371933404ed98a/log4j-core-2.7.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.apache.shiro/shiro-core/1.3.1/7edd30cd5b1b3293a40256b40b05bd8b8cbaa2df/shiro-core-1.3.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/io.pivotal.gemfire/geode-common/9.0.1/af9508e7bbf109cf33a642ddf2a1751390e51441/geode-common-9.0.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/io.pivotal.gemfire/geode-json/9.0.1/c83db4ec9b82bf9d7051e64a367f4634838fb81b/geode-json-9.0.1.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/ch.qos.logback/logback-classic/1.1.8/e54f49a227611976642f81cf2106b81c1ece8bf5/logback-classic-1.1.8.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.slf4j/jcl-over-slf4j/1.7.22/86ceac14535af5a42c8fb0d06d79b925dd3cb263/jcl-over-slf4j-1.7.22.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.slf4j/jul-to-slf4j/1.7.22/b0429e950b3d2bc2c39c1bacafac753edbe3781c/jul-to-slf4j-1.7.22.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.slf4j/log4j-over-slf4j/1.7.22/a527c37e9ca6c3d19ba298edd4aa344ca751a203/log4j-over-slf4j-1.7.22.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/ognl/ognl/3.0.8/37e1aebfde7eb7baebc9ad4f85116ef9009c5fc5/ognl-3.0.8.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.javassist/javassist/3.21.0-GA/598244f595db5c5fb713731eddbb1c91a58d959b/javassist-3.21.0-GA.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/org.unbescape/unbescape/1.1.0.RELEASE/ab0db4fe0a6fa89fb8da2a40008a4e63a7f3f5b9/unbescape-1.1.0.RELEASE.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/javax.transaction/javax.transaction-api/1.2/d81aff979d603edd90dcd8db2abc1f4ce6479e3e/javax.transaction-api-1.2.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/commons-beanutils/commons-beanutils/1.9.3/c845703de334ddc6b4b3cd26835458cb1cba1f3d/commons-beanutils-1.9.3.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/ch.qos.logback/logback-core/1.1.8/b4d1c3dea91727faf8b3d19cf4b9b972d6c0b89/logback-core-1.1.8.jar:/Users/jblum/.gradle/caches/modules-2/files-2.1/commons-collections/commons-collections/3.2.2/8ad72fe39fa8c91eaaf12aadb21e0c3661fe26d5/commons-collections-3.2.2.jar:/Applications/IntelliJ IDEA CE.app/Contents/lib/idea_rt.jar" com.intellij.rt.execution.application.AppMain sample.server.GemFireServer
Picked up JAVA_TOOL_OPTIONS: -Dtest

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v2.0.0.BUILD-SNAPSHOT)

2017-01-18 18:15:42.086  INFO 17133 --- [           main] sample.server.GemFireServer              : Starting GemFireServer on jblum-mbpro-2.local with PID 17133 (/Users/jblum/pivdev/spring-session/samples/boot/gemfire/build/classes/main started by jblum in /Users/jblum/pivdev/spring-session/build)
2017-01-18 18:15:42.091  INFO 17133 --- [           main] sample.server.GemFireServer              : No active profile set, falling back to default profiles: default
2017-01-18 18:15:42.469  INFO 17133 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@42a48628: startup date [Wed Jan 18 18:15:42 PST 2017]; root of context hierarchy
2017-01-18 18:15:43.089  INFO 17133 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration' of type [class org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2017-01-18 18:15:43.105  INFO 17133 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'validator' of type [class org.springframework.validation.beanvalidation.LocalValidatorFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
[info 2017/01/18 18:15:44.203 PST <main> tid=0x1] 
---------------------------------------------------------------------------

  Licensed to the Apache Software Foundation (ASF) under one or more...

...

Build-Date: 2016-12-15 21:30:03 +0000
Build-Id: root 8
Build-Java-Version: 1.8.0_111
Build-Platform: Linux 3.19.0-64-generic amd64
GemFire-Source-Date: 2016-12-05 21:18:08 +0000
GemFire-Source-Repository: HEAD
GemFire-Source-Revision: dafe5e7bbb94f2f8f0ee06c5b8582382084cb2cc
Product-Name: Pivotal GemFire
Product-Version: 9.0.1
Source-Date: 2016-12-15 18:19:41 +0000
Source-Repository: support/9.0
Source-Revision: 1af9c8f38f2e16bdb4d5887e34e48568fc93c161
Native version: native code unavailable
Running on: /10.99.199.11, 8 cpu(s), x86_64 Mac OS X 10.10.5 
Process ID: 17133
User: jblum
Current dir: /Users/jblum/pivdev/spring-session/build

...

[info 2017/01/18 18:15:44.279 PST <main> tid=0x1] Running in local mode since no locators were specified.

[info 2017/01/18 18:15:44.453 PST <main> tid=0x1] Initializing region _monitoringRegion_10.99.199.11<v-1>0

[info 2017/01/18 18:15:44.459 PST <main> tid=0x1] Initialization of region _monitoringRegion_10.99.199.11<v-1>0 completed

2017-01-18 18:15:45.081  INFO 17133 --- [           main] o.s.data.gemfire.CacheFactoryBean        : Connected to Distributed System [spring-session-data-gemfire-boot-sample:GemFireServer$$EnhancerBySpringCGLIB$$42cced60] as Member [10.99.199.11(spring-session-data-gemfire-boot-sample:GemFireServer$$EnhancerBySpringCGLIB$$42cced60:17133:loner):0:5b2182b4:spring-session-data-gemfire-boot-sample:GemFireServer$$EnhancerBySpringCGLIB$$42cced60]in Group(s) [[]] with Role(s) [[]] on Host [10.99.199.11] having PID [17133].
2017-01-18 18:15:45.081  INFO 17133 --- [           main] o.s.data.gemfire.CacheFactoryBean        : Created new GemFire v.9.0.1 Cache [spring-session-data-gemfire-boot-sample:GemFireServer$$EnhancerBySpringCGLIB$$42cced60].
2017-01-18 18:15:45.102  INFO 17133 --- [           main] o.s.d.gemfire.GenericRegionFactoryBean   : Falling back to creating Region [ClusteredSpringSessions] in Cache [spring-session-data-gemfire-boot-sample:GemFireServer$$EnhancerBySpringCGLIB$$42cced60]

...

[info 2017/01/18 18:15:45.821 PST <main> tid=0x1] Cache server connection listener bound to address localhost/127.0.0.1:12480 with backlog 1,000.

[info 2017/01/18 18:15:45.826 PST <main> tid=0x1] ClientHealthMonitorThread maximum allowed time between pings: 60,000

[info 2017/01/18 18:15:45.830 PST <main> tid=0x1] CacheServer Configuration:   port=12480 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

2017-01-18 18:15:45.843  INFO 17133 --- [           main] sample.server.GemFireServer              : Started GemFireServer in 4.533 seconds (JVM running for 4.865)

So, this tells me there is something wrong with Gradle (Groovy?) and specifically with the way in which the GemFire Server is forked.

I.e. perhaps there is something funky about commandLine.execute() (with Groovy/Gradle) when launching JVM processes using the java launcher in this way. It simply never starts the GemFire Server, at all. That makes no sense!

I also verify by commenting out this line in the build.gradle file, to prevent the GemFire Server JVM process from being terminated after test completion. No GemFire Server JVM process was found using either jps or ps -aux | grep "java" on my Mac after the test run fails and completes...

$ jps
Picked up JAVA_TOOL_OPTIONS: -Dtest
17252 Jps
15959 
17247 GradleDaemon

Why (how) do I always seem uncover the damnedest problems? GAH!!!

jxblum commented 7 years ago

Argh, it also does not seem to let go of the JAVA_TOOL_OPTIONS environment variable once set, even after you attempt to unset it, the GemFire Server still won't start and the tests, of course, continue to fail!

Is there no way to avoid this other than a reboot?

jxblum commented 7 years ago

Another update...

Seems to be just a problem with forking and launching a (Spring Boot-based) GemFire Server. I just tested with a simple Java class...

package sample.server;

import java.io.BufferedWriter;
import java.io.FileWriter;
import java.io.PrintWriter;

public class HelloWorld {

    public static void main(String[] args) throws Exception {
        System.out.println("HELLO WORLD!");

        PrintWriter fileWriter = null;

        try {
            fileWriter = new PrintWriter(new BufferedWriter(new FileWriter("hello.txt", false)), true);
            fileWriter.println("I was here!");
            fileWriter.flush();
        }
        finally {
            if (fileWriter != null) {
                fileWriter.close();
            }
        }
    }
}

... and it runs HelloWorld with no problem.

I could not get it to print out "HELLO WORLD!" at the command-line, but it did write out the hello.txt file, so I guess that debunks any potential problem with Groovy's String[].execute(..) scripting method.

I suspect all that Groovy's String[].execute(..) does under-the-hood is call Runtime.exec(..) anyway. I tried using Java's ProcessBuilder class, but that did not work either.

Next, I am going to try to fork and launch a GemFire Server just using the GemFire API in a simple Java main class.

jxblum commented 7 years ago

Yet another update...

After creating a Java class that uses GemFire's native Java API to launch a GemFire Server, and getting :spring-session-samples-boot-gemfire:integraionTest to run and pass successfully, I then proceeded to reset (export) the JAVA_TOOL_OPTIONS environment variable. Again, the GemFire Server JVM process would not start and thus could not create a log file with any log output (not helpful; damn it).

Another thing...

Actually, I was WRONG about forking and launching the simple HelloWorld class. I must've nuked my environment (unset the env var and killed all processes before proceeding) before when HelloWorld seemingly worked and the GemFire Server didn't... so not true.

It does NOT run when the JAVA_TOOL_OPTIONS env var is set. Therefore, I DO suspect this IS A PROBLEM with Groovy's String[].execute(..) method.

See here...

:spring-session-samples-boot-gemfire:runGemFireServer
STARTING GEMFIRE SERVER...
[java, -server, -ea, -classpath, ...
...
.../files-2.1/commons-collections/commons-collections/3.2.2/8ad72fe39fa8c91eaaf12aadb21e0c3661fe26d5/commons-collections-3.2.2.jar, 
-Dgemfire.log-file=gemfire-server.log, 
-Dgemfire.log-level=config, 
-Dspring-session-data-gemfire.cache.server.port=59121, 
-Dspring-session-data-gemfire.log.level=config, 
sample.server.HelloWorld]
:spring-session-samples-boot-gemfire:integrationTest
Picked up JAVA_TOOL_OPTIONS: -Dtest
...

Then...

$ jps
Picked up JAVA_TOOL_OPTIONS: -Dtest
17392 
18608 GradleDaemon
18746 Jps

$ find . -name "*log"
./samples/boot/gemfire/gemfire-client-01-01.log
./samples/boot/gemfire/gemfire-client.log

NOTE: I renamed the "hello.txt" file to "HelloWorld.log".

No "HelloWorld.log" file was written to the file system!

I then unset JAVA_TOOL_OPTIONS and be sure to kill any GradleDaemon processes (very key to making sure Gradle and the Java tooling does not remember the JAVA_TOOL_OPTIONS env var export; POS!), then I rerun the test...

$ unset JAVA_TOOL_OPTIONS
$ echo $JAVA_TOOL_OPTIONS

$ rm -f `find . -name "*log"`
$ find . -name "*log"
$
$ jps
17392 
18608 GradleDaemon
18857 Jps
$
$ kill -KILL `jps | grep "[GemFire|Gradle|Launcher]" | awk '{print $1}'`
$
$ jps
17392 
18870 Jps

$ gradlew --info :spring-session-samples-boot-gemfire:integrationTest 
...
// build fails, blah blah blah

$ find . -name "*log"
./HelloWorld.log
./samples/boot/gemfire/gemfire-client-01-01.log
./samples/boot/gemfire/gemfire-client.log
$
$ cat HelloWorld.log 
I was here!

Hah! Hello... "HelloWorld.log" file!

Note, in every run I was careful to cleanup any processes and log files.

If you are not careful to kill the GradleDaemon process on the machine where you have set the JAVA_TOOL_OPTIONS environment variable, then I suspect this is why you have to reboot your machine. I.e. I think if you simply clear the /etc/environment of any JAVA_TOOL_OPTIONS exports and kill the GradleDaemon then you should be in business the next time your run the Spring Session Gradle build without having to reboot.

I would have been seriously pissed if I had to reboot my machine just to clear that crap out!

Unfortunately, I haven't been able to get (\<BEEP>, \<BEEPIN>, \<BEEP>) Gradle/Groovy to log anything useful, yet. (errrrr!)

jxblum commented 7 years ago

Hi @rwinch, @vpavic -

Well, I am currently at a loss! It's 0 to 10 and Groovy/Gradle is winning. I need to go drink, errr, I mean sleep this one off.

If either of you fancy to take a stab at this, I put my changes on my gh-669 branch.

I will probably pick this up tomorrow along with wrapping up #714 (I hope).

Cheers, @jxblum

jxblum commented 7 years ago

Yay! I finally figured this one out!

Turns out the process handling logic I had in the Gradle build scripts for the GemFire samples (e.g. spring-session-samples-boot-gemfire) was causing this problem.

I created a separate project (groovy-gradle-examples) containing a similar Gradle build script to run an integration test (client) against a server process forked by my Gradle build script.

By simply not closing the input, output and error streams of the Process object when setting the JAVA_TOOL_OPTIONS environment variable, everything runs as expected. Therefore, I suspect by setting the JAVA_TOOL_OPTIONS environment variable, writes to the Process's standard out. After all, we do see...

Picked up JAVA_TOOL_OPTIONS: -Dtest

Get spit out on the command-line when the JAVA_TOOL_OPTIONS environment variable is set.

I will be checking in a fix for this problem shortly.

vpavic commented 7 years ago

That's great news @jxblum! :+1:

The special variable info (i.e. the "Picked up" message) is printed to stderr, check the very beginning of my opening comment. I've seen that cause issues several times.

I would have been seriously pissed if I had to reboot my machine just to clear that crap out!

:smile:

Well, I actually need that environment variable available to all processes hence the export via /etc/environment. Technically the reboot isn't required to apply changes to /etc/environment, logging out the parent shell and logging in again should suffice, I just used reboot to put emphasis on environment re-initialization.

jxblum commented 7 years ago

Thanks @vpavic.

The special variable info (i.e. the "Picked up" message) is printed to stderr, check the very beginning of my opening comment. I've seen that cause issues several times.

Right. I also noticed that it prints red in my IDE, which is only the case for stderr output.

I would say it is questionable (arguable) whether "that" should have caused the entire process to fail though. Not retaining resources where they are not needed (used) is valid (particularly in In-Memory based Distributed Systems) and IMO, this is not any different than setting Log Level to OFF, well for some logging frameworks anyway.

Anyhow, I have seen dumber things I reckon.

vpavic commented 7 years ago

I've tested the master branch build on my machine that uses JAVA_TOOL_OPTIONS variable and can confirm that it works now - thanks for fixing this @jxblum! :+1:

I've also opened #727 to backport this to 1.4.x.

jxblum commented 7 years ago

That is awesome! Thanks for the feedback @vpavic; much appreciated. Glad to lay this issue to rest.