Author: mreutegg
Date: Tue Apr 14 14:36:47 2015
New Revision: 1673436
URL: http://svn.apache.org/r1673436
Log:
OAK-2766: Log time to acquire backgroundOperationLock in background operation
tasks
Added:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/BackgroundWriteStats.java
(with props)
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStore.java
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/UnsavedModifications.java
Added:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/BackgroundWriteStats.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/BackgroundWriteStats.java?rev=1673436&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/BackgroundWriteStats.java
(added)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/BackgroundWriteStats.java
Tue Apr 14 14:36:47 2015
@@ -0,0 +1,38 @@
+/*
+ * 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.jackrabbit.oak.plugins.document;
+
+/**
+ * Stats about background write operations.
+ */
+class BackgroundWriteStats {
+
+ long clean;
+ long split;
+ long lock;
+ long write;
+ long num;
+
+ @Override
+ public String toString() {
+ return "clean:" + clean +
+ ", split:" + split+
+ ", lock:" + lock +
+ ", write:" + write +
+ ", num:" + num;
+ }
+}
Propchange:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/BackgroundWriteStats.java
------------------------------------------------------------------------------
svn:eol-style = native
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStore.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStore.java?rev=1673436&r1=1673435&r2=1673436&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStore.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStore.java
Tue Apr 14 14:36:47 2015
@@ -1631,16 +1631,16 @@ public final class DocumentNodeStore
// split documents (does not create new revisions)
backgroundSplit();
long splitTime = clock.getTime() - time;
- time = clock.getTime();
// write back pending updates to _lastRev
- backgroundWrite();
- long writeTime = clock.getTime() - time;
- String msg = "Background operations stats (clean:{}, split:{},
write:{})";
+ BackgroundWriteStats stats = backgroundWrite();
+ stats.split = splitTime;
+ stats.clean = cleanTime;
+ String msg = "Background operations stats ({})";
if (clock.getTime() - start > TimeUnit.SECONDS.toMillis(10)) {
// log as info if it took more than 10 seconds
- LOG.info(msg, cleanTime, splitTime, writeTime);
+ LOG.info(msg, stats);
} else {
- LOG.debug(msg, cleanTime, splitTime, writeTime);
+ LOG.debug(msg, stats);
}
}
@@ -1778,15 +1778,18 @@ public final class DocumentNodeStore
if (!externalChanges.isEmpty()) {
// invalidate caches
stats.cacheStats = store.invalidateCache();
- stats.cacheInvalidationTime = clock.getTime() - time;
- time = clock.getTime();
// TODO only invalidate affected items
docChildrenCache.invalidateAll();
+ stats.cacheInvalidationTime = clock.getTime() - time;
+ time = clock.getTime();
// make sure update to revision comparator is atomic
// and no local commit is in progress
backgroundOperationLock.writeLock().lock();
try {
+ stats.lock = clock.getTime() - time;
+ time = clock.getTime();
+
// the latest revisions of the current cluster node
// happened before the latest revisions of other cluster nodes
revisionComparator.add(newRevision(), headSeen);
@@ -1815,6 +1818,7 @@ public final class DocumentNodeStore
CacheInvalidationStats cacheStats;
long readHead;
long cacheInvalidationTime;
+ long lock;
long dispatchChanges;
long purge;
@@ -1828,6 +1832,7 @@ public final class DocumentNodeStore
"cacheStats:" + cacheStatsMsg +
", head:" + readHead +
", cache:" + cacheInvalidationTime +
+ ", lock:" + lock +
", dispatch:" + dispatchChanges +
", purge:" + purge +
'}';
@@ -1910,8 +1915,8 @@ public final class DocumentNodeStore
}
}
- void backgroundWrite() {
- unsavedLastRevisions.persist(this,
backgroundOperationLock.writeLock());
+ BackgroundWriteStats backgroundWrite() {
+ return unsavedLastRevisions.persist(this,
backgroundOperationLock.writeLock());
}
//-----------------------------< internal
>---------------------------------
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/UnsavedModifications.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/UnsavedModifications.java?rev=1673436&r1=1673435&r2=1673436&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/UnsavedModifications.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/UnsavedModifications.java
Tue Apr 14 14:36:47 2015
@@ -29,6 +29,7 @@ import javax.annotation.Nonnull;
import org.apache.jackrabbit.oak.plugins.document.util.MapFactory;
import org.apache.jackrabbit.oak.plugins.document.util.Utils;
+import org.apache.jackrabbit.oak.stats.Clock;
import com.google.common.base.Function;
import com.google.common.base.Predicate;
@@ -131,17 +132,24 @@ class UnsavedModifications {
* @param store the document node store.
* @param lock the lock to acquire to get a consistent snapshot of the
* revisions to write back.
+ * @return stats about the write operation.
*/
- public void persist(@Nonnull DocumentNodeStore store,
- @Nonnull Lock lock) {
+ public BackgroundWriteStats persist(@Nonnull DocumentNodeStore store,
+ @Nonnull Lock lock) {
+ BackgroundWriteStats stats = new BackgroundWriteStats();
if (map.size() == 0) {
- return;
+ return stats;
}
checkNotNull(store);
checkNotNull(lock);
- // get a copy of the map while holding the lock
+ Clock clock = store.getClock();
+
+ long time = clock.getTime();
+ // get a copy of the map while holding the lock
lock.lock();
+ stats.lock = clock.getTime() - time;
+ time = clock.getTime();
Map<String, Revision> pending;
try {
pending = Maps.newTreeMap(PathComparator.INSTANCE);
@@ -149,6 +157,7 @@ class UnsavedModifications {
} finally {
lock.unlock();
}
+ stats.num = pending.size();
UpdateOp updateOp = null;
Revision lastRev = null;
PeekingIterator<String> paths = Iterators.peekingIterator(
@@ -196,6 +205,8 @@ class UnsavedModifications {
lastRev = null;
}
}
+ stats.write = clock.getTime() - time;
+ return stats;
}
@Override
