ZooKeeper
  1. ZooKeeper
  2. ZOOKEEPER-1065

Possible timing issue in embedded server

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Invalid
    • Affects Version/s: 3.3.3
    • Fix Version/s: None
    • Component/s: java client, server
    • Labels:
      None
    • Environment:

      Windows 7, 32bit, Core2 Duo T9300, JDK 1.6.0_24, ZooKeeper data on 500GB hybrid Seagate HDD with 4GB SSD cache

      Description

      I have an application that uses ZooKeeper. There is an ensemble in
      production. But in order to simplify development the application will
      start an embedded ZooKeeper server when started in development mode. We
      are experiencing a timing issue with ZooKeeper 3.3.3 and I was wondering
      if this is allowed to be happen or if we did something wrong when
      starting the embedded server.

      Basically, we have a watch registered using an #exists call and watch
      code like the following.

      @Override
      public void process(final WatchedEvent event) {
        switch (event.getType()) {
          ...
          case NodeCreated:
            pathCreated(event.getPath());
            break;
          ...
        }
      }
      
      @Override
      protected void pathCreated(final String path) {
        // process events only for this node
        if (!isMyPath(path))
          return;
        try {
          loadNode(); // calls zk.getData(String, Watcher, Stat)
        } catch (final Exception e) {
          // got NoNodeException here (but not when debugging)
          log(..., e)
        }
      }
      

      From inspecting the logs we noticed a NoNodeException. When setting
      breakpoints on #loadNode and stepping through we don't get the
      exception. But when setting a breakpoint on #log only we got a hit and
      could confirm the issue this way.

      The path is actually some levels deep. All the parent paths don't exist
      either so they are created as well. However, no exception is thrown fro
      them. The sequence is as follows.

      /l1  --> watch triggered, getData, no exception
      /l1/l2  --> watch triggered, getData, no exception
      /l1/l2/l3  --> watch triggered, getData, no exception
      /l1/l2/l3/l4  --> watch triggered, getData, no exception
      /l1/l2/l3/l4/l5  --> watch triggered, getData, no exception
      /l1/l2/l3/l4/l5/l6  --> watch triggered, getData, NoNodeException
      

      The only difference is that all paths up to including l5 do not actually
      have any data. Only l6 has some data. Could there be some latency issues?

      For completeness, the embedded server is started as follows.

      // disable LOG4J JMX stuff
      System.setProperty("zookeeper.jmx.log4j.disable", Boolean.TRUE.toString());
      
      // get directories
      final File dataDir = new File(config.getDataLogDir());
      final File snapDir = new File(config.getDataDir());
      
      // clean old logs
      PurgeTxnLog.purge(dataDir, snapDir, 3);
      
      // create standalone server
      zkServer = new ZooKeeperServer();
      zkServer.setTxnLogFactory(new FileTxnSnapLog(dataDir, snapDir));
      zkServer.setTickTime(config.getTickTime());
      zkServer.setMinSessionTimeout(config.getMinSessionTimeout());
      zkServer.setMaxSessionTimeout(config.getMaxSessionTimeout());
      
      factory = new NIOServerCnxn.Factory(config.getClientPortAddress(),
      config.getMaxClientCnxns());
      
      // start server
      LOG.info("Starting ZooKeeper standalone server.");
      try {
        factory.startup(zkServer);
      } catch (final InterruptedException e) {
        LOG.warn("Interrupted during server start.", e);
        Thread.currentThread().interrupt();
      }
      
      1. zookeeper-nonode-issue.log
        85 kB
        Gunnar Wagenknecht

        Activity

        Gunnar Wagenknecht created issue -
        Gunnar Wagenknecht made changes -
        Field Original Value New Value
        Attachment zookeeper-nonode-issue.log [ 12479882 ]
        Gunnar Wagenknecht made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Resolution Invalid [ 6 ]

          People

          • Assignee:
            Unassigned
            Reporter:
            Gunnar Wagenknecht
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development