Uploaded image for project: 'Apache Curator'
  1. Apache Curator
  2. CURATOR-157

Avoid stack traces closing PathChildrenCache followed by closing CuratorFramework

    XMLWordPrintableJSON

Details

    • Improvement
    • Status: Open
    • Major
    • Resolution: Unresolved
    • None
    • None
    • None
    • None

    Description

      When closing PathChildrenCache, and immediately afterwards closing CuratorFramework, some ERROR-level stack traces are logged.

      This was previously reported on the mailing list: http://curator.markmail.org/thread/bmfr62ekx5p2vv7f

      The cause is that the BackgroundCallback defined in PathChildrenCache.refresh() will, when triggered, perform some more ZooKeeper operations.

      Thus one can get in sequences such as:

      • operation with BackgroundCallback is submitted
      • processResult of the BackgroundCallback is called
      • PathChildrenCache is closed
      • CuratorFramework is closed
      • processResult, which is running on another thread, comes to the point it does operations on ZooKeeper, which fail because ZooKeeper is closed.

      There is no real impact on the application, it is just for log-esthetical reasons that I'd like to avoid it.

      In the more common case, the processResult will receive an IllegalStateException, which could be easily catched and ignored in PathChildrenCache if the PathChildrenCache is closed:

      14/10/30 11:24:51 ERROR org.apache.curator.framework.imps.CuratorFrameworkImpl: Background exception was not retry-able or retry gave up
      java.lang.IllegalStateException: instance must be started before calling this method
      	at com.google.common.base.Preconditions.checkState(Preconditions.java:149)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.getData(CuratorFrameworkImpl.java:360)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache.getDataAndStat(PathChildrenCache.java:545)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache.processChildren(PathChildrenCache.java:668)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache.access$200(PathChildrenCache.java:68)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache$4.processResult(PathChildrenCache.java:490)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.sendToBackgroundCallback(CuratorFrameworkImpl.java:715)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.processBackgroundOperation(CuratorFrameworkImpl.java:502)
      	at org.apache.curator.framework.imps.GetChildrenBuilderImpl$2.processResult(GetChildrenBuilderImpl.java:166)
      	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:590)
      	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
      

      But sometimes it also fails with other async operations deeper down:

      14/10/30 11:24:51 ERROR org.apache.curator.framework.imps.CuratorFrameworkImpl: Background exception was not retry-able or retry gave up
      java.lang.IllegalStateException: Client is not started
      	at com.google.common.base.Preconditions.checkState(Preconditions.java:149)
      	at org.apache.curator.CuratorZookeeperClient.getZooKeeper(CuratorZookeeperClient.java:113)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.getZooKeeper(CuratorFrameworkImpl.java:474)
      	at org.apache.curator.framework.imps.GetDataBuilderImpl.performBackgroundOperation(GetDataBuilderImpl.java:263)
      	at org.apache.curator.framework.imps.OperationAndData.callPerformBackgroundOperation(OperationAndData.java:65)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.performBackgroundOperation(CuratorFrameworkImpl.java:789)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.processBackgroundOperation(CuratorFrameworkImpl.java:487)
      	at org.apache.curator.framework.imps.GetDataBuilderImpl.forPath(GetDataBuilderImpl.java:275)
      	at org.apache.curator.framework.imps.GetDataBuilderImpl.forPath(GetDataBuilderImpl.java:41)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache.getDataAndStat(PathChildrenCache.java:545)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache.processChildren(PathChildrenCache.java:668)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache.access$200(PathChildrenCache.java:68)
      	at org.apache.curator.framework.recipes.cache.PathChildrenCache$4.processResult(PathChildrenCache.java:490)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.sendToBackgroundCallback(CuratorFrameworkImpl.java:715)
      	at org.apache.curator.framework.imps.CuratorFrameworkImpl.processBackgroundOperation(CuratorFrameworkImpl.java:502)
      	at org.apache.curator.framework.imps.GetChildrenBuilderImpl$2.processResult(GetChildrenBuilderImpl.java:166)
      	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:590)
      	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
      

      Therefore I have created a patch where PathChildrenCache.close() will wait until the possibly running BackgroundCallback is finished.

      I will also attach a small class that illustrates the problem.

      Attachments

        1. LogProblemIllustration.java
          2 kB
          Bruno Dumon

        Activity

          People

            randgalt Jordan Zimmerman
            bruno Bruno Dumon
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:

              Time Tracking

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0h
                0h
                Logged:
                Time Spent - 50m
                50m