From 66d59afa66f37c2e9ef8b54b387d8ad84041cea6 Mon Sep 17 00:00:00 2001 From: Rajeshbabu Chintaguntla Date: Sat, 21 Feb 2015 12:17:44 +0530 Subject: [PATCH] HBASE-13054 Provide more tracing information for locking/latching events.(Rajeshbabu) --- .../apache/hadoop/hbase/io/hfile/HFileReaderV2.java | 3 +++ .../hadoop/hbase/regionserver/DefaultMemStore.java | 4 ++++ .../apache/hadoop/hbase/regionserver/HRegion.java | 13 +++++++++++++ 3 files changed, 20 insertions(+) diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileReaderV2.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileReaderV2.java index 250001efe25..5460cbd588f 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileReaderV2.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/io/hfile/HFileReaderV2.java @@ -402,6 +402,9 @@ public class HFileReaderV2 extends AbstractHFileReader { HFileBlock cachedBlock = getCachedBlock(cacheKey, cacheBlock, useLock, isCompaction, updateCacheMetrics, expectedBlockType, expectedDataBlockEncoding); if (cachedBlock != null) { + if (Trace.isTracing()) { + traceScope.getSpan().addTimelineAnnotation("blockCacheHit"); + } assert cachedBlock.isUnpacked() : "Packed block leak."; if (cachedBlock.getBlockType().isData()) { if (updateCacheMetrics) { diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/DefaultMemStore.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/DefaultMemStore.java index 081d7a5a1ea..d8ed1b34957 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/DefaultMemStore.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/DefaultMemStore.java @@ -47,6 +47,7 @@ import org.apache.hadoop.hbase.util.CollectionBackedScanner; import org.apache.hadoop.hbase.util.EnvironmentEdgeManager; import org.apache.hadoop.hbase.util.Pair; import org.apache.hadoop.hbase.util.ReflectionUtils; +import org.apache.htrace.Trace; /** * The MemStore holds in-memory modifications to the Store. Modifications @@ -737,6 +738,9 @@ public class DefaultMemStore implements MemStore { this.snapshotAllocatorAtCreation = snapshotAllocator; this.snapshotAllocatorAtCreation.incScannerCount(); } + if (Trace.isTracing() && Trace.currentSpan() != null) { + Trace.currentSpan().addTimelineAnnotation("Creating MemStoreScanner"); + } } /** diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java index 1c80de8cc10..9201858fd84 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java @@ -171,6 +171,8 @@ import org.apache.hadoop.hbase.wal.WALSplitter; import org.apache.hadoop.hbase.wal.WALSplitter.MutationReplay; import org.apache.hadoop.io.MultipleIOException; import org.apache.hadoop.util.StringUtils; +import org.apache.htrace.Trace; +import org.apache.htrace.TraceScope; import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Optional; @@ -4695,16 +4697,27 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver { // if (!waitForLock) { return null; } + TraceScope traceScope = null; try { + if (Trace.isTracing()) { + traceScope = Trace.startSpan("HRegion.getRowLockInternal"); + } // Row is already locked by some other thread, give up or wait for it if (!existingContext.latch.await(this.rowLockWaitDuration, TimeUnit.MILLISECONDS)) { + if(traceScope != null) { + traceScope.getSpan().addTimelineAnnotation("Failed to get row lock"); + } throw new IOException("Timed out waiting for lock for row: " + rowKey); } + if (traceScope != null) traceScope.close(); + traceScope = null; } catch (InterruptedException ie) { LOG.warn("Thread interrupted waiting for lock on row: " + rowKey); InterruptedIOException iie = new InterruptedIOException(); iie.initCause(ie); throw iie; + } finally { + if (traceScope != null) traceScope.close(); } } }