From a33e4d2168c030db3190d0d24261292728f280d7 Mon Sep 17 00:00:00 2001 From: binlijin Date: Tue, 14 Apr 2020 19:36:16 +0800 Subject: [PATCH] HBASE-24181 Add region info when log meessages in HRegion. (#1506) Signed-off-by: Reid Chan Signed-off-by: Jan Hentschel --- .../hadoop/hbase/regionserver/HRegion.java | 80 ++++++++++--------- 1 file changed, 43 insertions(+), 37 deletions(-) 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 a0aa7e644d1..f791aacece0 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 @@ -1142,7 +1142,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi try { store.close(); } catch (IOException e) { - LOG.warn("close store failed", e); + LOG.warn("close store {} failed in region {}", store.toString(), this, e); } } } @@ -1750,7 +1750,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi if (!canFlush) { decrMemStoreSize(this.memStoreSizing.getMemStoreSize()); } else if (this.memStoreSizing.getDataSize() != 0) { - LOG.error("Memstore data size is {}", this.memStoreSizing.getDataSize()); + LOG.error("Memstore data size is {} in region {}", this.memStoreSizing.getDataSize(), this); } if (coprocessorHost != null) { status.setStatus("Running coprocessor post-close hooks"); @@ -1789,7 +1789,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi writestate.wait(); } catch (InterruptedException iex) { // essentially ignore and propagate the interrupt back up - LOG.warn("Interrupted while waiting"); + LOG.warn("Interrupted while waiting in region {}", this); interrupted = true; break; } @@ -1830,7 +1830,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi writestate.wait(toWait); } catch (InterruptedException iex) { // essentially ignore and propagate the interrupt back up - LOG.warn("Interrupted while waiting"); + LOG.warn("Interrupted while waiting in region {}", this); interrupted = true; break; } finally { @@ -1842,7 +1842,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi Thread.currentThread().interrupt(); } } - LOG.debug("Waited " + duration + " ms for flush to complete"); + LOG.debug("Waited {} ms for region {} flush to complete", duration, this); return !(writestate.flushing); } } @@ -2254,7 +2254,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi requestNeedsCancellation = false; store.compact(compaction, throughputController, user); } catch (InterruptedIOException iioe) { - String msg = "compaction interrupted"; + String msg = "region " + this + " compaction interrupted"; LOG.info(msg, iioe); status.abort(msg); return false; @@ -2725,8 +2725,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi WALUtil.writeFlushMarker(wal, this.getReplicationScope(), getRegionInfo(), desc, false, mvcc); } catch (Throwable t) { - LOG.warn("Received unexpected exception trying to write ABORT_FLUSH marker to WAL:" + - StringUtils.stringifyException(t)); + LOG.warn("Received unexpected exception trying to write ABORT_FLUSH marker to WAL: {} in " + + " region {}", StringUtils.stringifyException(t), this); // ignore this since we will be aborting the RS with DSE. } // we have called wal.startCacheFlush(), now we have to abort it @@ -3312,7 +3312,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi durability = tmpDur; } } catch (NoSuchColumnFamilyException nscfe) { - final String msg = "No such column family in batch mutation. "; + final String msg = "No such column family in batch mutation in region " + this; if (observedExceptions.hasSeenNoSuchFamily()) { LOG.warn(msg + nscfe.getMessage()); } else { @@ -3325,7 +3325,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi throw nscfe; } } catch (FailedSanityCheckException fsce) { - final String msg = "Batch Mutation did not pass sanity check. "; + final String msg = "Batch Mutation did not pass sanity check in region " + this; if (observedExceptions.hasSeenFailedSanityCheck()) { LOG.warn(msg + fsce.getMessage()); } else { @@ -3338,7 +3338,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi throw fsce; } } catch (WrongRegionException we) { - final String msg = "Batch mutation had a row that does not belong to this region. "; + final String msg = "Batch mutation had a row that does not belong to this region " + this; if (observedExceptions.hasSeenWrongRegion()) { LOG.warn(msg + we.getMessage()); } else { @@ -3411,7 +3411,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi throwException = true; throw e; } catch (IOException ioe) { - LOG.warn("Failed getting lock, row=" + Bytes.toStringBinary(mutation.getRow()), ioe); + LOG.warn("Failed getting lock, row={}, in region {}", + Bytes.toStringBinary(mutation.getRow()), this, ioe); if (isAtomic()) { // fail, atomic means all or none throwException = true; throw ioe; @@ -3949,7 +3950,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi if (nonExistentList != null) { for (byte[] family : nonExistentList) { // Perhaps schema was changed between crash and replay - LOG.info("No family for " + Bytes.toString(family) + " omit from reply."); + LOG.info("No family for {} omit from reply in region {}.", Bytes.toString(family), this); familyCellMap.remove(family); } } @@ -4769,7 +4770,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi if (maxSeqId <= minSeqIdForTheRegion) { if (LOG.isDebugEnabled()) { String msg = "Maximum sequenceid for this wal is " + maxSeqId - + " and minimum sequenceid for the region is " + minSeqIdForTheRegion + + " and minimum sequenceid for the region " + this + " is " + minSeqIdForTheRegion + ", skipped the whole file, path=" + edits; LOG.debug(msg); } @@ -4863,7 +4864,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi " edits=" + editsCount); // Timeout reached if(!reporter.progress()) { - msg = "Progressable reporter failed, stopping replay"; + msg = "Progressable reporter failed, stopping replay for region " + this; LOG.warn(msg); status.abort(msg); throw new IOException(msg); @@ -4931,13 +4932,13 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi if (store == null) { // This should never happen. Perhaps schema was changed between // crash and redeploy? - LOG.warn("No family for " + cell); + LOG.warn("No family for cell {} in region {}", cell, this); skippedEdits++; continue; } if (checkRowWithinBoundary && !rowIsInRange(this.getRegionInfo(), cell.getRowArray(), cell.getRowOffset(), cell.getRowLength())) { - LOG.warn("Row of " + cell + " is not within region boundary"); + LOG.warn("Row of {} is not within region boundary for region {}", cell, this); skippedEdits++; continue; } @@ -4970,9 +4971,9 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi } } catch (EOFException eof) { Path p = WALSplitUtil.moveAsideBadEditsFile(walFS, edits); - msg = "EnLongAddered EOF. Most likely due to Master failure during " + - "wal splitting, so we have this data in another edit. " + - "Continuing, but renaming " + edits + " as " + p; + msg = "EnLongAddered EOF. Most likely due to Master failure during " + + "wal splitting, so we have this data in another edit. Continuing, but renaming " + + edits + " as " + p + " for region " + this; LOG.warn(msg, eof); status.abort(msg); } catch (IOException ioe) { @@ -6052,7 +6053,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi success = true; return result; } catch (InterruptedException ie) { - LOG.warn("Thread interrupted waiting for lock on row: " + rowKey); + LOG.warn("Thread interrupted waiting for lock on row: {}, in region {}", rowKey, + getRegionInfo().getRegionNameAsString()); InterruptedIOException iie = new InterruptedIOException(); iie.initCause(ie); TraceUtil.addTimelineAnnotation("Interrupted exception getting row lock"); @@ -6062,7 +6064,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi // The maximum lock count for read lock is 64K (hardcoded), when this maximum count // is reached, it will throw out an Error. This Error needs to be caught so it can // go ahead to process the minibatch with lock acquired. - LOG.warn("Error to get row lock for " + Bytes.toStringBinary(row) + ", cause: " + error); + LOG.warn("Error to get row lock for {}, in region {}, cause: {}", Bytes.toStringBinary(row), + getRegionInfo().getRegionNameAsString(), error); IOException ioe = new IOException(error); TraceUtil.addTimelineAnnotation("Error getting row lock"); throw ioe; @@ -6313,7 +6316,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi // validation failed because of some sort of IO problem. if (ioException != null) { - LOG.error("There was IO error when checking if the bulk load is ok.", ioException); + LOG.error("There was IO error when checking if the bulk load is ok in region {}.", this, + ioException); throw ioException; } } @@ -6325,8 +6329,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi .append(p.getSecond()); } // problem when validating - LOG.warn("There was a recoverable bulk load failure likely due to a" + - " split. These (family, HFile) pairs were not loaded: " + list); + LOG.warn("There was a recoverable bulk load failure likely due to a split. These (family," + + " HFile) pairs were not loaded: {}, in region {}", list.toString(), this); return null; } @@ -7666,7 +7670,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi prevRowLock = rowLock; } } catch (IOException ioe) { - LOG.warn("Failed getting lock, row=" + Bytes.toStringBinary(row), ioe); + LOG.warn("Failed getting lock, row={}, in region {}", Bytes.toStringBinary(row), this, + ioe); throw ioe; } } @@ -7865,8 +7870,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi } catch (IOException e) { String row = processor.getRowsToLock().isEmpty() ? "" : " on row(s):" + Bytes.toStringBinary(processor.getRowsToLock().iterator().next()) + "..."; - LOG.warn("RowProcessor:" + processor.getClass().getName() + - " throws Exception" + row, e); + LOG.warn("RowProcessor: {}, in region {}, throws Exception {}", + processor.getClass().getName(), getRegionInfo().getRegionNameAsString(), row, e); throw e; } return; @@ -7882,8 +7887,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi } catch (IOException e) { String row = processor.getRowsToLock().isEmpty() ? "" : " on row(s):" + Bytes.toStringBinary(processor.getRowsToLock().iterator().next()) + "..."; - LOG.warn("RowProcessor:" + processor.getClass().getName() + - " throws Exception" + row, e); + LOG.warn("RowProcessor: {}, in region {}, throws Exception {}", + processor.getClass().getName(), getRegionInfo().getRegionNameAsString(), row, e); throw e; } } @@ -7894,7 +7899,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi } catch (TimeoutException te) { String row = processor.getRowsToLock().isEmpty() ? "" : " on row(s):" + Bytes.toStringBinary(processor.getRowsToLock().iterator().next()) + "..."; - LOG.error("RowProcessor timeout:" + timeout + " ms" + row); + LOG.error("RowProcessor timeout: {} ms, in region {}, {}", timeout, + getRegionInfo().getRegionNameAsString(), row); throw new IOException(te); } catch (Exception e) { throw new IOException(e); @@ -8198,8 +8204,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi } int newCellSize = PrivateCellUtil.estimatedSerializedSizeOf(newCell); if (newCellSize > this.maxCellSize) { - String msg = "Cell with size " + newCellSize + " exceeds limit of " + - this.maxCellSize + " bytes"; + String msg = "Cell with size " + newCellSize + " exceeds limit of " + this.maxCellSize + + " bytes in region " + this; if (LOG.isDebugEnabled()) { LOG.debug(msg); } @@ -8369,8 +8375,8 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi com.google.protobuf.Descriptors.ServiceDescriptor serviceDesc = instance.getDescriptorForType(); String serviceName = CoprocessorRpcUtils.getServiceName(serviceDesc); if (coprocessorServiceHandlers.containsKey(serviceName)) { - LOG.error("Coprocessor service " + serviceName + - " already registered, rejecting request from " + instance); + LOG.error("Coprocessor service {} already registered, rejecting request from {} in region {}", + serviceName, instance, this); return false; } @@ -8500,7 +8506,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi try { checkRow(ret, "calculated split"); } catch (IOException e) { - LOG.error("Ignoring invalid split", e); + LOG.error("Ignoring invalid split for region {}", this, e); return null; } } @@ -8668,7 +8674,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi this.getRegionServerServices().getServerName())); } } catch (InterruptedException ie) { - LOG.info("Interrupted while waiting for a lock"); + LOG.info("Interrupted while waiting for a lock in region {}", this); InterruptedIOException iie = new InterruptedIOException(); iie.initCause(ie); throw iie;