zookeeper-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From fang...@apache.org
Subject [zookeeper] branch master updated: ZOOKEEPER-3323: Add TxnSnapLog metrics
Date Tue, 21 May 2019 21:34:44 GMT
This is an automated email from the ASF dual-hosted git repository.

fangmin pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/zookeeper.git


The following commit(s) were added to refs/heads/master by this push:
     new d08f51a  ZOOKEEPER-3323: Add TxnSnapLog metrics
d08f51a is described below

commit d08f51ad1514bfa512597b1ce4bbc2e8144be576
Author: Jie Huang <jiehuang@fb.com>
AuthorDate: Tue May 21 14:34:38 2019 -0700

    ZOOKEEPER-3323: Add TxnSnapLog metrics
    
    Author: Jie Huang <jiehuang@fb.com>
    
    Reviewers: anmolnar@apache.org, eolivelli@apache.org, fangmin@apache.org
    
    Closes #859 from jhuan31/ZOOKEEPER-3323
---
 .../org/apache/zookeeper/server/ServerMetrics.java |  9 +++
 .../server/persistence/FileTxnSnapLog.java         | 20 ++++-
 .../persistence/FileTxnSnapLogMetricsTest.java     | 93 ++++++++++++++++++++++
 3 files changed, 119 insertions(+), 3 deletions(-)

diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ServerMetrics.java
b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ServerMetrics.java
index 37ffee1..686aacc 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ServerMetrics.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ServerMetrics.java
@@ -197,6 +197,11 @@ public final class ServerMetrics {
          */
         LEARNER_HANDLER_QP_SIZE = metricsContext.getSummarySet("learner_handler_qp_size",
DetailLevel.BASIC);
         LEARNER_HANDLER_QP_TIME = metricsContext.getSummarySet("learner_handler_qp_time_ms",
DetailLevel.ADVANCED);
+
+        STARTUP_TXNS_LOADED = metricsContext.getSummary("startup_txns_loaded", DetailLevel.BASIC);
+        STARTUP_TXNS_LOAD_TIME = metricsContext.getSummary("startup_txns_load_time", DetailLevel.BASIC);
+        STARTUP_SNAP_LOAD_TIME = metricsContext.getSummary("startup_snap_load_time", DetailLevel.BASIC);
+
     }
 
     /**
@@ -274,6 +279,10 @@ public final class ServerMetrics {
     public final Counter LEARNER_PROPOSAL_RECEIVED_COUNT;
     public final Counter LEARNER_COMMIT_RECEIVED_COUNT;
 
+    public final Summary STARTUP_TXNS_LOADED;
+    public final Summary STARTUP_TXNS_LOAD_TIME;
+    public final Summary STARTUP_SNAP_LOAD_TIME;
+
     /**
      * Fired watcher stats.
      */
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnSnapLog.java
b/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnSnapLog.java
index 7409af8..b0df373 100644
--- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnSnapLog.java
+++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/persistence/FileTxnSnapLog.java
@@ -30,11 +30,13 @@ import org.apache.jute.Record;
 import org.apache.zookeeper.KeeperException;
 import org.apache.zookeeper.KeeperException.Code;
 import org.apache.zookeeper.ZooDefs.OpCode;
-import org.apache.zookeeper.server.DataTree;
-import org.apache.zookeeper.server.DataTree.ProcessTxnResult;
-import org.apache.zookeeper.server.Request;
+import org.apache.zookeeper.common.Time;
+import org.apache.zookeeper.server.ServerMetrics;
 import org.apache.zookeeper.server.ServerStats;
 import org.apache.zookeeper.server.ZooTrace;
+import org.apache.zookeeper.server.Request;
+import org.apache.zookeeper.server.DataTree;
+import org.apache.zookeeper.server.DataTree.ProcessTxnResult;
 import org.apache.zookeeper.server.persistence.TxnLog.TxnIterator;
 import org.apache.zookeeper.txn.CreateSessionTxn;
 import org.apache.zookeeper.txn.TxnHeader;
@@ -211,7 +213,10 @@ public class FileTxnSnapLog {
      */
     public long restore(DataTree dt, Map<Long, Integer> sessions,
                         PlayBackListener listener) throws IOException {
+        long snapLoadingStartTime = Time.currentElapsedTime();
         long deserializeResult = snapLog.deserialize(dt, sessions);
+        ServerMetrics.getMetrics().STARTUP_SNAP_LOAD_TIME.add(
+                Time.currentElapsedTime() - snapLoadingStartTime);
         FileTxnLog txnLog = new FileTxnLog(dataDir);
         boolean trustEmptyDB;
         File initFile = new File(dataDir.getParent(), "initialize");
@@ -263,6 +268,8 @@ public class FileTxnSnapLog {
         TxnIterator itr = txnLog.read(dt.lastProcessedZxid+1);
         long highestZxid = dt.lastProcessedZxid;
         TxnHeader hdr;
+        int txnLoaded = 0;
+        long startTime = Time.currentElapsedTime();
         try {
             while (true) {
                 // iterator points to
@@ -280,6 +287,7 @@ public class FileTxnSnapLog {
                 }
                 try {
                     processTransaction(hdr,dt,sessions, itr.getTxn());
+                    txnLoaded++;
                 } catch(KeeperException.NoNodeException e) {
                    throw new IOException("Failed to process transaction type: " +
                          hdr.getType() + " error: " + e.getMessage(), e);
@@ -293,6 +301,12 @@ public class FileTxnSnapLog {
                 itr.close();
             }
         }
+
+        long loadTime = Time.currentElapsedTime() - startTime;
+        LOG.info("{} txns loaded in {} ms", txnLoaded, loadTime);
+        ServerMetrics.getMetrics().STARTUP_TXNS_LOADED.add(txnLoaded);
+        ServerMetrics.getMetrics().STARTUP_TXNS_LOAD_TIME.add(loadTime);
+
         return highestZxid;
     }
 
diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/server/persistence/FileTxnSnapLogMetricsTest.java
b/zookeeper-server/src/test/java/org/apache/zookeeper/server/persistence/FileTxnSnapLogMetricsTest.java
new file mode 100644
index 0000000..4b4ef7a
--- /dev/null
+++ b/zookeeper-server/src/test/java/org/apache/zookeeper/server/persistence/FileTxnSnapLogMetricsTest.java
@@ -0,0 +1,93 @@
+/**
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements.  See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership.  The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License.  You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.apache.zookeeper.server.persistence;
+
+import org.apache.zookeeper.ZooKeeper;
+import org.apache.zookeeper.ZooDefs;
+import org.apache.zookeeper.ZKTestCase;
+import org.apache.zookeeper.Watcher;
+import org.apache.zookeeper.WatchedEvent;
+import org.apache.zookeeper.CreateMode;
+import org.apache.zookeeper.metrics.MetricsUtils;
+import org.apache.zookeeper.server.ServerMetrics;
+import org.apache.zookeeper.server.SyncRequestProcessor;
+import org.apache.zookeeper.test.ClientBase;
+import org.apache.zookeeper.test.QuorumUtil;
+import org.junit.Assert;
+import org.junit.Test;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import java.util.Map;
+import java.util.concurrent.CountDownLatch;
+
+import static org.hamcrest.number.OrderingComparison.greaterThan;
+import static org.hamcrest.number.OrderingComparison.greaterThanOrEqualTo;
+
+public class FileTxnSnapLogMetricsTest extends ZKTestCase {
+    private static final Logger LOG = LoggerFactory.getLogger(FileTxnSnapLogMetricsTest.class);
+
+    CountDownLatch allCreatedLatch;
+
+    private class MockWatcher implements Watcher {
+        @Override
+        public void process(WatchedEvent e) {
+            LOG.info("all nodes created");
+            allCreatedLatch.countDown();
+        }
+    }
+
+    @Test
+    public void testFileTxnSnapLogMetrics() throws Exception {
+        SyncRequestProcessor.setSnapCount(100);
+
+        QuorumUtil util = new QuorumUtil(1);
+        util.startAll();
+
+        allCreatedLatch = new CountDownLatch(1);
+
+        byte[] data = new byte[500];
+        // make sure a snapshot is taken and some txns are not in a snapshot
+        ZooKeeper zk = ClientBase.createZKClient(util.getConnString());
+        for (int i=0; i<150; i++){
+            zk.create("/path" + i, data, ZooDefs.Ids.OPEN_ACL_UNSAFE, CreateMode.PERSISTENT);
+        }
+
+        if (null == zk.exists("/path149", new MockWatcher())) {
+            allCreatedLatch.await();
+        }
+
+        ServerMetrics.getMetrics().resetAll();
+        int leader = util.getLeaderServer();
+        // restart a server so it will read the snapshot and the txn logs
+        util.shutdown(leader);
+        util.start(leader);
+
+        Map<String, Object> values = MetricsUtils.currentServerMetrics();
+        LOG.info("txn loaded during start up {}", values.get("max_startup_txns_loaded"));
+        Assert.assertEquals(1L, values.get("cnt_startup_txns_loaded"));
+        Assert.assertThat((long)values.get("max_startup_txns_loaded"), greaterThan(0L));
+        Assert.assertEquals(1L, values.get("cnt_startup_txns_load_time"));
+        Assert.assertThat((long)values.get("max_startup_txns_load_time"), greaterThanOrEqualTo(0L));
+        Assert.assertEquals(1L, values.get("cnt_startup_snap_load_time"));
+        Assert.assertThat((long)values.get("max_startup_snap_load_time"), greaterThan(0L));
+
+        util.shutdownAll();
+    }
+}


Mime
View raw message