You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Juan José Ramos Cassella (JIRA)" <ji...@apache.org> on 2018/04/03 14:43:00 UTC

[jira] [Created] (GEODE-4990) Race Condition When Using Cluster Configuration Service

Juan José Ramos Cassella created GEODE-4990:
-----------------------------------------------

             Summary: Race Condition When Using Cluster Configuration Service
                 Key: GEODE-4990
                 URL: https://issues.apache.org/jira/browse/GEODE-4990
             Project: Geode
          Issue Type: Bug
          Components: configuration, locator
            Reporter: Juan José Ramos Cassella


There's a small window of time on which the locator ({{enable-cluster-configuration=true}}) is receiving TCP requests from starting up servers ({{use-cluster-configuration=true}}) but the cluster configuration service is not yet fully loaded, because of this the servers fail to startup and throw the following exception:

{noformat}
Exception in thread "main" org.apache.geode.cache.execute.FunctionException: java.lang.NullPointerException
	at org.apache.geode.internal.cache.execute.FunctionStreamingResultCollector.getResult(FunctionStreamingResultCollector.java:232)
	at org.apache.geode.internal.cache.ClusterConfigurationLoader.requestConfigurationFromLocators(ClusterConfigurationLoader.java:285)
	at org.apache.geode.internal.cache.GemFireCacheImpl.requestSharedConfiguration(GemFireCacheImpl.java:1036)
	at org.apache.geode.internal.cache.GemFireCacheImpl.<init>(GemFireCacheImpl.java:835)
	at org.apache.geode.internal.cache.GemFireCacheImpl.basicCreate(GemFireCacheImpl.java:775)
	at org.apache.geode.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:764)
	at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:175)
	at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:222)
	at org.apache.geode.distributed.internal.DefaultServerLauncherCacheProvider.createCache(DefaultServerLauncherCacheProvider.java:52)
	at org.apache.geode.distributed.ServerLauncher.createCache(ServerLauncher.java:844)
	at org.apache.geode.distributed.ServerLauncher.start(ServerLauncher.java:762)
	at org.apache.geode.distributed.ServerLauncher.run(ServerLauncher.java:692)
	at org.apache.geode.distributed.ServerLauncher.main(ServerLauncher.java:226)
Caused by: java.lang.NullPointerException
	at org.apache.geode.management.internal.configuration.functions.GetClusterConfigurationFunction.execute(GetClusterConfigurationFunction.java:55)
	at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:186)
	at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:382)
	at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:448)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.geode.distributed.internal.DistributionManager.runUntilShutdown(DistributionManager.java:1099)
	at org.apache.geode.distributed.internal.DistributionManager.access$000(DistributionManager.java:108)
	at org.apache.geode.distributed.internal.DistributionManager$9$1.run(DistributionManager.java:970)
	at java.lang.Thread.run(Thread.java:748)
{noformat}

The logs from the locator, when using {{log-level=fine}} show the following:

{noformat}
[fine 2018/04/03 15:24:40.501 IST locator1 <Function Execution Processor1> tid=0x51] Exception occurred on remote member while executing Function: org.apache.geode.management.internal.configuration.functions.GetClusterConfigurationFunction
java.lang.NullPointerException
	at org.apache.geode.management.internal.configuration.functions.GetClusterConfigurationFunction.execute(GetClusterConfigurationFunction.java:55)
	at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:186)
	at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:382)
	at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:448)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.geode.distributed.internal.DistributionManager.runUntilShutdown(DistributionManager.java:1099)
	at org.apache.geode.distributed.internal.DistributionManager.access$000(DistributionManager.java:108)
	at org.apache.geode.distributed.internal.DistributionManager$9$1.run(DistributionManager.java:970)
	at java.lang.Thread.run(Thread.java:748)

[fine 2018/04/03 15:24:40.502 IST locator1 <Function Execution Processor1> tid=0x51] Replying with exception: ReplyMessage processorId=2 from null with exception org.apache.geode.distributed.internal.ReplyException: java.lang.NullPointerException
org.apache.geode.distributed.internal.ReplyException: java.lang.NullPointerException
	at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:216)
	at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:382)
	at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:448)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.geode.distributed.internal.DistributionManager.runUntilShutdown(DistributionManager.java:1099)
	at org.apache.geode.distributed.internal.DistributionManager.access$000(DistributionManager.java:108)
	at org.apache.geode.distributed.internal.DistributionManager$9$1.run(DistributionManager.java:970)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at org.apache.geode.management.internal.configuration.functions.GetClusterConfigurationFunction.execute(GetClusterConfigurationFunction.java:55)
	at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:186)
	... 8 more
{noformat}

It doesn't matter wether the user has configured a value for the parameter {{locator-wait-time}} or not, the value is only used when establishing the TCP connection and, since the locator is already running, the server continues the startup process and tries to get the cluster configuration service, failing afterwards due to the {{NullPointerException}}.
The problematic code can be seen below:

{code:title=GetClusterConfigurationFunction.java|borderStyle=solid}
public class GetClusterConfigurationFunction implements InternalFunction {
  private static final Logger logger = LogService.getLogger();

  @Override
  public void execute(FunctionContext context) {
    InternalClusterConfigurationService clusterConfigurationService =
        InternalLocator.getLocator().getSharedConfiguration();

    Set<String> groups = (Set<String>) context.getArguments();

    logger.info("Received request for configuration  : {}", groups);

    try {
    // [XXXXX]: clusterConfigurationService is null as it hasn't been loaded yet.
      ConfigurationResponse response =
          clusterConfigurationService.createConfigurationResponse(groups);
      context.getResultSender().lastResult(response);
    } catch (IOException e) {
      logger.error("Unable to retrieve the cluster configuration", e);
      context.getResultSender().lastResult(e);
    }
  }
}
{code}

The servers, on the other hand, already have the logic in place to wait and retry the retrieval of the cluster configuration service when the response is {{null}}:

{code:title=ClusterConfigurationLoader.java|borderStyle=solid}
public ConfigurationResponse requestConfigurationFromLocators(String groupList,
      Set<InternalDistributedMember> locatorList)
      throws ClusterConfigurationNotAvailableException, UnknownHostException {

    Set<String> groups = getGroups(groupList);
    GetClusterConfigurationFunction function = new GetClusterConfigurationFunction();

    ConfigurationResponse response = null;

    int attempts = 6;
    OUTER: while (attempts > 0) {
      for (InternalDistributedMember locator : locatorList) {
        logger.info("Attempting to retrieve cluster configuration from {} - {} attempts remaining",
            locator.getName(), attempts);
        response = requestConfigurationFromOneLocator(locator, groups);
        if (response != null) {
          break OUTER;
        }
      }

      try {
        Thread.sleep(10000);
      } catch (InterruptedException ex) {
        break;
      }

      attempts--;
    }

    // if the response is null
    if (response == null) {
      throw new ClusterConfigurationNotAvailableException(
          "Unable to retrieve cluster configuration from the locator.");
    }

    return response;
  }
{code}

That said, the fix seems to be quite simple and it implies modifying {{GetClusterConfigurationFunction}} to return {{null}} whenever the cluster configuration is enabled but not fully loaded yet, and throw an exception whenever the cluster configuration service is not enabled on the locator (allowing us to fail fast when the server is requesting the cluster configuration from a locator that doesn't have it enabled).



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)