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 <ktur...@apache.org>
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

Reply via email to