This is an automated email from the ASF dual-hosted git repository.
kturner pushed a commit to branch 2.1
in repository https://gitbox.apache.org/repos/asf/accumulo.git
The following commit(s) were added to refs/heads/2.1 by this push:
new e981057599 adds detailed trace logging for block caches (#4872)
e981057599 is described below
commit e981057599647085069083453f519a817806827d
Author: Keith Turner <[email protected]>
AuthorDate: Fri Sep 13 13:47:43 2024 -0400
adds detailed trace logging for block caches (#4872)
Adds detailed trace logging for the accumulo block caches that can be
used for scans.
With the following log4j config
```
logger.cache.name = org.apache.accumulo.cache
logger.cache.level = trace
```
can see output like the following with these changes when running a few
scans.
```
2024-09-10T23:08:47,821 [accumulo.cache] TRACE: INDEX loader:299585732
getDependencies() returned
[hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rf!RootData]
2024-09-10T23:08:47,828 [accumulo.cache] TRACE: INDEX loader:299585732
load(201326592,{hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rf!RootData=65})
returned 113 bytes in 823μs
2024-09-10T23:08:47,828 [accumulo.cache] TRACE: INDEX
getBlock(hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rfMRFile.index,
loader:299585732) returned 113 bytes in 6924μs
2024-09-10T23:08:47,829 [accumulo.cache] TRACE: DATA
getBlock(hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rfR16,
loader:1259534108) returned 101125 bytes in 865μs
2024-09-10T23:09:00,692 [accumulo.cache] TRACE: DATA
getBlock(hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rfR16,
loader:161430432) returned 101125 bytes in 5μs
2024-09-10T23:09:01,579 [accumulo.cache] TRACE: DATA
getBlock(hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rfR16,
loader:1386294126) returned 101125 bytes in 8μs
2024-09-10T23:09:02,323 [accumulo.cache] TRACE: DATA
getBlock(hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rfR16,
loader:740950152) returned 101125 bytes in 9μs
2024-09-10T23:09:03,011 [accumulo.cache] TRACE: DATA
getBlock(hdfs://localhost:8020/accumulo/tables/1/default_tablet/A000003t.rfR16,
loader:1766289486) returned 101125 bytes in 9μs
```
---
.../file/blockfile/impl/ScanCacheProvider.java | 19 +--
.../accumulo/core/logging/LoggingBlockCache.java | 131 +++++++++++++++++++++
.../accumulo/core/summary/SummaryReader.java | 6 +-
src/build/ci/find-unapproved-chars.sh | 2 +-
4 files changed, 149 insertions(+), 9 deletions(-)
diff --git
a/core/src/main/java/org/apache/accumulo/core/file/blockfile/impl/ScanCacheProvider.java
b/core/src/main/java/org/apache/accumulo/core/file/blockfile/impl/ScanCacheProvider.java
index f82f534cf5..78b8600b37 100644
---
a/core/src/main/java/org/apache/accumulo/core/file/blockfile/impl/ScanCacheProvider.java
+++
b/core/src/main/java/org/apache/accumulo/core/file/blockfile/impl/ScanCacheProvider.java
@@ -20,7 +20,9 @@ package org.apache.accumulo.core.file.blockfile.impl;
import org.apache.accumulo.core.conf.AccumuloConfiguration;
import org.apache.accumulo.core.conf.Property;
+import org.apache.accumulo.core.logging.LoggingBlockCache;
import org.apache.accumulo.core.spi.cache.BlockCache;
+import org.apache.accumulo.core.spi.cache.CacheType;
import org.apache.accumulo.core.spi.scan.ScanDispatch;
public class ScanCacheProvider implements CacheProvider {
@@ -30,19 +32,23 @@ public class ScanCacheProvider implements CacheProvider {
public ScanCacheProvider(AccumuloConfiguration tableConfig, ScanDispatch
dispatch,
BlockCache indexCache, BlockCache dataCache) {
+
+ var loggingIndexCache = LoggingBlockCache.wrap(CacheType.INDEX,
indexCache);
+ var loggingDataCache = LoggingBlockCache.wrap(CacheType.DATA, dataCache);
+
switch (dispatch.getIndexCacheUsage()) {
case ENABLED:
- this.indexCache = indexCache;
+ this.indexCache = loggingIndexCache;
break;
case DISABLED:
this.indexCache = null;
break;
case OPPORTUNISTIC:
- this.indexCache = new OpportunisticBlockCache(indexCache);
+ this.indexCache = new OpportunisticBlockCache(loggingIndexCache);
break;
case TABLE:
this.indexCache =
- tableConfig.getBoolean(Property.TABLE_INDEXCACHE_ENABLED) ?
indexCache : null;
+ tableConfig.getBoolean(Property.TABLE_INDEXCACHE_ENABLED) ?
loggingIndexCache : null;
break;
default:
throw new IllegalStateException();
@@ -50,22 +56,21 @@ public class ScanCacheProvider implements CacheProvider {
switch (dispatch.getDataCacheUsage()) {
case ENABLED:
- this.dataCache = dataCache;
+ this.dataCache = loggingDataCache;
break;
case DISABLED:
this.dataCache = null;
break;
case OPPORTUNISTIC:
- this.dataCache = new OpportunisticBlockCache(dataCache);
+ this.dataCache = new OpportunisticBlockCache(loggingDataCache);
break;
case TABLE:
this.dataCache =
- tableConfig.getBoolean(Property.TABLE_BLOCKCACHE_ENABLED) ?
dataCache : null;
+ tableConfig.getBoolean(Property.TABLE_BLOCKCACHE_ENABLED) ?
loggingDataCache : null;
break;
default:
throw new IllegalStateException();
}
-
}
@Override
diff --git
a/core/src/main/java/org/apache/accumulo/core/logging/LoggingBlockCache.java
b/core/src/main/java/org/apache/accumulo/core/logging/LoggingBlockCache.java
new file mode 100644
index 0000000000..d1239493ce
--- /dev/null
+++ b/core/src/main/java/org/apache/accumulo/core/logging/LoggingBlockCache.java
@@ -0,0 +1,131 @@
+/*
+ * 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
+ *
+ * https://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.accumulo.core.logging;
+
+import java.util.Map;
+import java.util.concurrent.TimeUnit;
+
+import org.apache.accumulo.core.spi.cache.BlockCache;
+import org.apache.accumulo.core.spi.cache.CacheEntry;
+import org.apache.accumulo.core.spi.cache.CacheType;
+import org.apache.accumulo.core.util.Timer;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import com.google.common.collect.Maps;
+
+/**
+ * Provides trace level logging of block cache activity.
+ */
+public class LoggingBlockCache implements BlockCache {
+
+ private final BlockCache blockCache;
+ private static final Logger log = LoggerFactory.getLogger(Logging.PREFIX +
"cache");
+ private final CacheType type;
+
+ private LoggingBlockCache(CacheType type, BlockCache blockCache) {
+ this.type = type;
+ this.blockCache = blockCache;
+ }
+
+ private static String toString(CacheEntry ce) {
+ return ce == null ? null : ce.getBuffer().length + " bytes";
+ }
+
+ @Override
+ public CacheEntry cacheBlock(String blockName, byte[] buf) {
+ var timer = Timer.startNew();
+ var ce = blockCache.cacheBlock(blockName, buf);
+ var elapsed = timer.elapsed(TimeUnit.MICROSECONDS);
+ log.trace("{} cacheBlock({},{} bytes) returned {} in {}μs", type,
blockName, buf.length,
+ toString(ce), elapsed);
+ return ce;
+ }
+
+ @Override
+ public CacheEntry getBlock(String blockName) {
+ var timer = Timer.startNew();
+ var ce = blockCache.getBlock(blockName);
+ var elapsed = timer.elapsed(TimeUnit.MICROSECONDS);
+ log.trace("{} getBlock({}) returned {} in {}μs", type, blockName,
toString(ce), elapsed);
+ return ce;
+
+ }
+
+ private final class LoggingLoader implements Loader {
+ private final Loader loader;
+
+ private LoggingLoader(Loader loader) {
+ this.loader = loader;
+ }
+
+ @Override
+ public Map<String,Loader> getDependencies() {
+ var deps = loader.getDependencies();
+ log.trace("{} loader:{} getDependencies() returned {}", type,
loader.hashCode(),
+ deps.keySet());
+ return Maps.transformValues(deps, secondLoader -> new
LoggingLoader(secondLoader));
+ }
+
+ @Override
+ public byte[] load(int maxSize, Map<String,byte[]> dependencies) {
+ var timer = Timer.startNew();
+ byte[] data = loader.load(maxSize, dependencies);
+ var elapsed = timer.elapsed(TimeUnit.MICROSECONDS);
+ Map<String,Integer> logDeps =
+ Maps.transformValues(dependencies, bytes -> bytes == null ? null :
bytes.length);
+ log.trace("{} loader:{} load({},{}) returned {} in {}μs", type,
loader.hashCode(), maxSize,
+ logDeps, data == null ? null : data.length + " bytes", elapsed);
+ return data;
+ }
+ }
+
+ @Override
+ public CacheEntry getBlock(String blockName, Loader loader) {
+ var timer = Timer.startNew();
+ var ce = blockCache.getBlock(blockName, new LoggingLoader(loader));
+ var elapsed = timer.elapsed(TimeUnit.MICROSECONDS);
+ log.trace("{} getBlock({}, loader:{}) returned {} in {}μs", type,
blockName, loader.hashCode(),
+ toString(ce), elapsed);
+ return ce;
+ }
+
+ @Override
+ public long getMaxHeapSize() {
+ return blockCache.getMaxHeapSize();
+ }
+
+ @Override
+ public long getMaxSize() {
+ return blockCache.getMaxSize();
+ }
+
+ @Override
+ public Stats getStats() {
+ return blockCache.getStats();
+ }
+
+ public static BlockCache wrap(CacheType type, BlockCache blockCache) {
+ if (blockCache != null && log.isTraceEnabled() && !(blockCache instanceof
LoggingBlockCache)) {
+ return new LoggingBlockCache(type, blockCache);
+ } else {
+ return blockCache;
+ }
+ }
+}
diff --git
a/core/src/main/java/org/apache/accumulo/core/summary/SummaryReader.java
b/core/src/main/java/org/apache/accumulo/core/summary/SummaryReader.java
index 3a645c21dd..cce1044e65 100644
--- a/core/src/main/java/org/apache/accumulo/core/summary/SummaryReader.java
+++ b/core/src/main/java/org/apache/accumulo/core/summary/SummaryReader.java
@@ -37,8 +37,10 @@ import
org.apache.accumulo.core.file.blockfile.impl.CachableBlockFile;
import
org.apache.accumulo.core.file.blockfile.impl.CachableBlockFile.CachableBuilder;
import org.apache.accumulo.core.file.rfile.RFile.Reader;
import org.apache.accumulo.core.file.rfile.bcfile.MetaBlockDoesNotExist;
+import org.apache.accumulo.core.logging.LoggingBlockCache;
import org.apache.accumulo.core.spi.cache.BlockCache;
import org.apache.accumulo.core.spi.cache.CacheEntry;
+import org.apache.accumulo.core.spi.cache.CacheType;
import org.apache.accumulo.core.spi.crypto.CryptoService;
import org.apache.accumulo.core.summary.Gatherer.RowRange;
import org.apache.hadoop.conf.Configuration;
@@ -191,7 +193,9 @@ public class SummaryReader {
try {
// the reason BCFile is used instead of RFile is to avoid reading in the
RFile meta block when
// only summary data is wanted.
- CompositeCache compositeCache = new CompositeCache(summaryCache,
indexCache);
+ CompositeCache compositeCache =
+ new CompositeCache(LoggingBlockCache.wrap(CacheType.SUMMARY,
summaryCache),
+ LoggingBlockCache.wrap(CacheType.INDEX, indexCache));
CachableBuilder cb = new CachableBuilder().fsPath(fs,
file).conf(conf).fileLen(fileLenCache)
.cacheProvider(new BasicCacheProvider(compositeCache,
null)).cryptoService(cryptoService);
bcReader = new CachableBlockFile.Reader(cb);
diff --git a/src/build/ci/find-unapproved-chars.sh
b/src/build/ci/find-unapproved-chars.sh
index 5f7c7b0efa..bb017badcb 100755
--- a/src/build/ci/find-unapproved-chars.sh
+++ b/src/build/ci/find-unapproved-chars.sh
@@ -22,7 +22,7 @@
# unintentionally, or maliciously, add any new non-ASCII characters unless they
# are preapproved on the ALLOWED list or in known binary or resource files
NUM_EXPECTED=0
-ALLOWED='©èö🐈三四五六八九十'
+ALLOWED='©èö🐈三四五六八九十μ'
function findallnonascii() {
# -P for perl matching, -o for only showing the match for counting
occurrences not lines