0

I am setting up the spring-data-gemfire in my project at my workplace. However, it takes a long time to connect to a GemFire server and retrieve the data from my application. 

2020-Mar-13 09:00:10 | TRACE | annotation.ScheduledAnnotationPostProcessor | No @Scheduled annotations found on bean class: class org.springframework.gemfire.client.CLientCacheFactoryBean
2020-Mar-13 09:00:10 | TRACE | support.DefaultListableBeanFactory |Finished creating instance of bean 'gemfireCache'
2020-Mar-13 09:00:42 | TRACE | internal.ClassPathLoader | getResource(gemfire.properties)
2020-Mar-13 09:00:42 | TRACE | internal.ClassPathLoader | getResource trying: sun.misc.Launcher$AppClassLoader@73d16e93
2020-Mar-13 09:00:42 | TRACE | internal.ClassPathLoader | getResource trying: java.net.Launcher$AppClassLoader@73d16e93
.....

May I know why it takes more than 40 secs from "Finished creating instance of bean.." to "getResource.." ?

Current Versions

  1. Spring Data GemFire 2.2.1.RELEASE
  2. Spring Boot 2.2.1.RELEASE
  3. 3 Server and 2 Locator (Installed at virtual Machine)
  4. Private Local Network
  5. Using Java Serialization
  6. Using Caching Proxy for my client

When i try a simple gemfire application at my home, it took around 5 seconds. 

[TRACE] 2020-03-14 16:54:58.623 [main] CachedIntrospectionResults - Found bean property 'propertiesPersister' of type [org.springframework.util.PropertiesPersister]
[TRACE] 2020-03-14 16:54:58.623 [main] CachedIntrospectionResults - Found bean property 'singleton' of type [boolean]
[TRACE] 2020-03-14 16:54:58.626 [main] TypeConverterDelegate - Converting String to [class [Lorg.springframework.core.io.Resource;] using property editor [org.springframework.core.io.support.ResourceArrayPropertyEditor@669253b7
[TRACE] 2020-03-14 16:54:58.627 [main] PathMatchingResourcePatternResolver - Resolved classpath location [META-INF/gemfire-named-queries.properties] to resources []
[TRACE] 2020-03-14 16:54:58.627 [main] DefaultListableBeanFactory - Invoking afterPropertiesSet() on bean with name '(inner bean)#6cc0bcf6'
[TRACE] 2020-03-14 16:54:58.628 [main] DefaultListableBeanFactory - Finished creating instance of bean '(inner bean)#6cc0bcf6'
[TRACE] 2020-03-14 16:54:58.630 [main] DefaultListableBeanFactory - Finished creating instance of bean '(inner bean)#1a6f5124'
[TRACE] 2020-03-14 16:54:58.631 [main] DefaultListableBeanFactory - Creating instance of bean '(inner bean)#49a64d82'
[TRACE] 2020-03-14 16:54:58.635 [main] DefaultListableBeanFactory - Invoking afterPropertiesSet() on bean with name '(inner bean)#49a64d82'
[TRACE] 2020-03-14 16:54:58.635 [main] DefaultListableBeanFactory - Finished creating instance of bean '(inner bean)#49a64d82'
[TRACE] 2020-03-14 16:54:58.636 [main] DefaultListableBeanFactory - Returning cached instance of singleton bean 'gemfireCache'
[TRACE] 2020-03-14 16:55:03.415 [main] ClassPathLoader - getResource(gemfire.properties)
[TRACE] 2020-03-14 16:55:03.418 [main] ClassPathLoader - getResource trying: sun.misc.Launcher$AppClassLoader@73d16e93
[TRACE] 2020-03-14 16:55:03.418 [main] ClassPathLoader - getResource trying: java.net.URLClassLoader@1500e009
[TRACE] 2020-03-14 16:55:03.418 [main] ClassPathLoader - getResource(gfsecurity.properties)
[TRACE] 2020-03-14 16:55:03.419 [main] ClassPathLoader - getResource trying: sun.misc.Launcher$AppClassLoader@73d16e93
[TRACE] 2020-03-14 16:55:03.419 [main] ClassPathLoader - getResource trying: java.net.URLClassLoader@1500e009
[TRACE] 2020-03-14 16:55:03.429 [main] ClassPathLoader - forName(org.apache.logging.log4j.core.impl.Log4jContextFactory)
[TRACE] 2020-03-14 16:55:03.429 [main] ClassPathLoader - forName trying: sun.misc.Launcher$AppClassLoader@73d16e93
[TRACE] 2020-03-14 16:55:03.429 [main] ClassPathLoader - forName found by: sun.misc.Launcher$AppClassLoader@73d16e93 2020-03-14 16:55:03,432 main INFO Log4j Core is available and using Log4jProvider
[TRACE] 2020-03-14 16:55:03.434 [main] ClassPathLoader - forName(org.apache.geode.internal.logging.log4j.Log4jAgent)
[TRACE] 2020-03-14 16:55:03.434 [main] ClassPathLoader - forName trying: sun.misc.Launcher$AppClassLoader@73d16e93
[TRACE] 2020-03-14 16:55:03.435 [main] ClassPathLoader - forName found by: sun.misc.Launcher$AppClassLoader@73d16e93 020-03-14 16:55:03,436 main INFO Using org.apache.geode.internal.logging.log4j.Log4jAgent by default for service org.apache.geode.internal.logging.ProviderAgent
[TRACE] 2020-03-14 16:55:03.848 [main] ThreadContext - get() - in thread [main]
[DEBUG] 2020-03-14 16:55:03.854 [main] geode - LogWriter is created.
[DEBUG] 2020-03-14 16:55:03.854 [main] security - SecurityLogWriter is created.
[TRACE] 2020-03-14 16:55:03.858 [main] ClassPathLoader - getResource(org/apache/geode/internal/GemFireVersion.properties)
[TRACE] 2020-03-14 16:55:03.858 [main] ClassPathLoader - getResource trying: sun.misc.Launcher$AppClassLoader@73d16e93
[TRACE] 2020-03-14 16:55:03.858 [main] ClassPathLoader - getResource found by: sun.misc.Launcher$AppClassLoader@73d16e93

My Simple gemfire application

@SpringBootApplication
@ClientCacheApplication(locators = {@ClientCacheApplication.Locator(host = "192.167.0.5", port = 10311) }, socketBufferSize = 90000, subscriptionEnabled = true)
@EnableEntityDefinedRegions(basePackageClasses = Person.class, clientRegionShortcut = ClientRegionShortcut.CACHING_PROXY)
@EnableGemfireRepositories(basePackageClasses = PersonRepository.class)
public class Application {
Jack
  • 89
  • 6

2 Answers2

0

Well, this is a loaded question.

There are many things that transpire both before and after a client (cache) connects to a cluster (or server). Many questions come to mind since your description is less than descriptive in this case.

  1. You mention you are connecting to a server, so that implies your Spring Boot, Spring Data for Pivotal GemFire (SDG) application is a client, and specifically a ClientCache? If so, what sort of network are you going over (localhost, private internal network, VPN, cloud network, etc)?

  2. Is there a firewall, proxy, NAT (e.g. Router, Switch), or other network appliance involved? If you are noticing latency, then there is a good chance of a network problem.

  3. How have you configured the Pool between the client and server? For example, are you connecting to 1 or more Locators, or a single Locator. Are you connecting directly to a server?

  4. How large is your cluster? Is there more than 1 server? Do you have single-hop enabled?

  5. What sort of data access operation are you performing? How large is the result set (i.e. how many objects)? How large are the objects?

  6. What form of serialization are you using (e.g. do you are application domain model types implement java.io.Serializable? Are you using PDX by chance? Are you using GemFire Deltas and DataSerialization?

  7. Have you tried running the same application in different contexts?

  8. Do you have your application publicly accessible somewhere, such as in GitHub?

  9. Can you share your configuration, full log files for both client and server, Thread dumps for both client and server, etc?

  10. Is the Region in which you are accessing data from your application a PARTITION Region? Is persistence enabled? If a multi-node (server) cluster, are all the members hosting the PR up?

  11. etc, etc, etc...

The small snippet of log content you did share...

2020-Mar-13 09:00:42 | TRACE | internal.ClassPathLoader | getResource(gemfire.properties)
2020-Mar-13 09:00:42 | TRACE | internal.ClassPathLoader | getResource trying: sun.misc.Launcher$AppClassLoader@73d16e93
2020-Mar-13 09:00:42 | TRACE | internal.ClassPathLoader | getResource trying: java.net.Launcher$AppClassLoader@73d16e93

Seems to suggest that it is trying to resolve a gemfire.properties file. Have you configured a gemfire.properties? If so, it might be better to define a Spring Boot application.properties resource and use the corresponding, equivalent spring.data.gemfire.* properties instead.

If your filesystem in good health?

The ClassPathLoader class is a Pivotal GemFire internal class, so whatever is happening, is outside of the control of Spring (Data GemFire) and entirely to do with GemFire itself.

You should also be aware that just because the GemFireCache (e.g. a ClientCache) instance has been created, it does not necessarily mean the cache, or the GemFire System in general, has been fully initialized yet. There are many asynchronous tasks (e.g. such as Pool min size creation) that happen in the background after certain GemFire objects (e.g. cache, then Regions, then Indexes and DiskStores, etc) are created.

Also, the cache (e.g. ClientCache) instance that is created is just a container to hold all the other GemFire objects, such as Regions, which actually hold the data. Regions must be created and initialized before any data access operations can occur. However, in order to create Regions, you need a cache (i.e. a ClientCache instance in the first place).

What type is your client Regions (e.g. ClientRegionShortcut.PROXY or ClientRegionShortcut.CACHING_PROXY)?

There are too many blanks in your details to give you a more precise answer.

John Blum
  • 7,381
  • 1
  • 20
  • 30
  • 1. Yes. I am using Spring Boot and Spring Data for Pivotal GemFire (SDG) application (Client). My network is a private local network. 2. There is a switch and router involved. However, there is no latency in the network. I check using the ping test. 3. I configured using a list of locators (2 locators). I did not connect directly to the server. 4. My Gemfire cluster has 3 server and 2 locator. I did not enable single hop. – Jack Mar 14 '20 at 08:24
  • 5. Writing and saving records to the Gemfire. Also, perform some cache listening event. 6. I am using java serialization. 7. The issue is only occurred at my staging environment. However, the delay does no occurred in my development environment. The delay is only 2 seconds. – Jack Mar 14 '20 at 08:25
  • Some of my regions are PERSISTENT-PARTITION. All my server and locators are up. My client is using ClientREgionShortcut.CACHING_PROXY. – Jack Mar 14 '20 at 08:27
  • Just a curious question. What is the program doing during "Finished creating instance of bean gemfireCache'" to getResource(gemfire.properties)? I try at my home and it took 5 seconds – Jack Mar 14 '20 at 09:13
  • After reviewing your revised log output, it is apparent you are logging at DEBUG. The only thing that stood out in your output was `ClassPathLoader - getResource(org/apache/geode/internal/GemFireVersion.properties)`, which SDG would log here (https://github.com/spring-projects/spring-data-geode/blob/master/spring-data-geode/src/main/java/org/springframework/data/gemfire/CacheFactoryBean.java#L280-L281). Adjusting the log level (e.g. > INFO) should suppress this output if this is causing an issue. However... – John Blum Mar 16 '20 at 17:35
  • The true culprit is the Apache Geode/Pivotal GemFire `ClassPathLoader` class, which is used to resolve the either `gemfire.properties` (hence `ClassPathLoader - getResource(gemfire.properties)`), *security properties* (hence `ClassPathLoader - getResource(gfsecurity.properties)`) as well as the *version properties* (hence `ClassPathLoader - getResource(org/apache/geode/internal/GemFireVersion.properties)`). So... – John Blum Mar 16 '20 at 17:38
  • You can review the GemFire/Geode source code for `ClassPathLoader` here (https://github.com/apache/geode/blob/rel/v1.11.0/geode-core/src/main/java/org/apache/geode/internal/ClassPathLoader.java). However, this Geode class is simply a delegate to JRE `ClassLoaders`, for example... `ClassPathLoader - getResource trying: java.net.URLClassLoader@1500e009` (Network ClassLoad. Given that it is taking 5 seconds "at home" or the results vary between your DEV and STAGING environment, then it is highly likely the network is the problem. – John Blum Mar 16 '20 at 17:43
  • My advice it to 1) Get some Thread dumps when the delay is happening so we know exactly what the program Threads are doing at that exact moment, 2) to use some sort of profiler to find out exactly which calls are the hot ones and 3) follow **Jens D** advice below. – John Blum Mar 16 '20 at 17:45
0

In some cases it may simply be that you're having DNS lookup issues - especially since performance seems to be different between your home and other location(s).

You can try this:

Get your hostname using the hostname command. Add this as an alias to your /etc/hosts file for 127.0.0.1. For example if your hostname looks something like foobar.local then your /etc/hosts should be adjusted to include this:

127.0.0.1   localhost  foobar foobar.local

Notice that I added both the FQDN (including .local as returned by hostname) as well as the shorter version.

Jens D
  • 4,229
  • 3
  • 16
  • 19
  • My client is running in Window OS. how to add in the host file? Is the host file located in WIndow/System32/drivers/etc/hosts ? – Jack Mar 17 '20 at 01:54
  • Yes, I believe so. I haven't tried this on Windows before - just Mac and Linux. – Jens D Mar 18 '20 at 13:55