You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@zookeeper.apache.org by fa...@apache.org on 2019/05/21 21:34:44 UTC
[zookeeper] branch master updated: ZOOKEEPER-3323: Add TxnSnapLog
metrics
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 <ji...@fb.com>
AuthorDate: Tue May 21 14:34:38 2019 -0700
ZOOKEEPER-3323: Add TxnSnapLog metrics
Author: Jie Huang <ji...@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();
+ }
+}