From 397e7f359df0f78eb2e0e9bb8a84c9bdec2e38d5 Mon Sep 17 00:00:00 2001 From: haxiaolin Date: Fri, 2 Apr 2021 14:35:41 +0800 Subject: [PATCH 1/3] HBASE-25720 Sync WAL stuck when prepare flush cache will prevent flush cache and cause OOM --- .../hadoop/hbase/regionserver/HRegion.java | 42 ++++++++++++------- .../hbase/regionserver/TestHRegion.java | 3 -- 2 files changed, 26 insertions(+), 19 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 ece85fcbce86..fa8e148c8788 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 @@ -2846,7 +2846,13 @@ protected PrepareFlushResult internalPrepareFlushCache(WAL wal, long myseqid, String s = "Finished memstore snapshotting " + this + ", syncing WAL and waiting on mvcc, " + "flushsize=" + totalSizeOfFlushableStores; status.setStatus(s); - doSyncOfUnflushedWALChanges(wal, getRegionInfo()); + + try { + doSyncOfUnflushedWALChanges(wal, getRegionInfo()); + } catch (Throwable t) { + status.abort("Sync unflushed WAL changes failed: " + StringUtils.stringifyException(t)); + fatalForFlushCache(t); + } return new PrepareFlushResult(storeFlushCtxs, committedFiles, storeFlushableSize, startTime, flushOpSeqId, flushedSeqId, totalSizeOfFlushableStores); } @@ -3036,22 +3042,8 @@ FlushResultImpl internalFlushCacheAndCommit(WAL wal, MonitoredTask status, } wal.abortCacheFlush(this.getRegionInfo().getEncodedNameAsBytes()); } - DroppedSnapshotException dse = new DroppedSnapshotException("region: " + - Bytes.toStringBinary(getRegionInfo().getRegionName()), t); status.abort("Flush failed: " + StringUtils.stringifyException(t)); - - // Callers for flushcache() should catch DroppedSnapshotException and abort the region server. - // However, since we may have the region read lock, we cannot call close(true) here since - // we cannot promote to a write lock. Instead we are setting closing so that all other region - // operations except for close will be rejected. - this.closing.set(true); - - if (rsServices != null) { - // This is a safeguard against the case where the caller fails to explicitly handle aborting - rsServices.abort("Replay of WAL required. Forcing server shutdown", dse); - } - - throw dse; + fatalForFlushCache(t); } // If we get to here, the HStores have been written. @@ -3097,6 +3089,24 @@ FlushResultImpl internalFlushCacheAndCommit(WAL wal, MonitoredTask status, FlushResult.Result.FLUSHED_NO_COMPACTION_NEEDED, flushOpSeqId); } + private void fatalForFlushCache(Throwable t) throws DroppedSnapshotException { + DroppedSnapshotException dse = new DroppedSnapshotException("region: " + + Bytes.toStringBinary(getRegionInfo().getRegionName()), t); + + // Callers for flushcache() should catch DroppedSnapshotException and abort the region server. + // However, since we may have the region read lock, we cannot call close(true) here since + // we cannot promote to a write lock. Instead we are setting closing so that all other region + // operations except for close will be rejected. + this.closing.set(true); + + if (rsServices != null) { + // This is a safeguard against the case where the caller fails to explicitly handle aborting + rsServices.abort("Replay of WAL required. Forcing server shutdown", dse); + } + + throw dse; + } + /** * Method to safely get the next sequence number. * @return Next sequence number unassociated with any actual edit. diff --git a/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java b/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java index ac26242f6b61..19dbe152f921 100644 --- a/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java +++ b/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java @@ -1276,9 +1276,6 @@ public long getSyncedLength() { try { region.flush(true); fail("This should have thrown exception"); - } catch (DroppedSnapshotException unexpected) { - // this should not be a dropped snapshot exception. Meaning that RS will not abort - throw unexpected; } catch (IOException expected) { // expected } From cbbd8eb3bf6dd961f2d114cc1a05f2201597a820 Mon Sep 17 00:00:00 2001 From: haxiaolin Date: Fri, 2 Apr 2021 14:35:41 +0800 Subject: [PATCH 2/3] HBASE-25720 Sync WAL stuck when prepare flush cache will prevent flush cache and cause OOM --- .../hbase/regionserver/wal/TestLogRolling.java | 14 -------------- 1 file changed, 14 deletions(-) diff --git a/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/wal/TestLogRolling.java b/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/wal/TestLogRolling.java index 0712b594c34d..f7083b7d4b2c 100644 --- a/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/wal/TestLogRolling.java +++ b/hbase-server/src/test/java/org/apache/hadoop/hbase/regionserver/wal/TestLogRolling.java @@ -535,20 +535,6 @@ public void postLogRoll(Path oldFile, Path newFile) { assertTrue(loggedRows.contains("row1004")); assertTrue(loggedRows.contains("row1005")); - // flush all regions - for (HRegion r : server.getOnlineRegionsLocalContext()) { - try { - r.flush(true); - } catch (Exception e) { - // This try/catch was added by HBASE-14317. It is needed - // because this issue tightened up the semantic such that - // a failed append could not be followed by a successful - // sync. What is coming out here is a failed sync, a sync - // that used to 'pass'. - LOG.info(e.toString(), e); - } - } - ResultScanner scanner = table.getScanner(new Scan()); try { for (int i = 2; i <= 5; i++) { From 2d6576ad00ec7d84e03fd9a2a6a1bfd410815743 Mon Sep 17 00:00:00 2001 From: haxiaolin Date: Wed, 26 May 2021 20:57:02 +0800 Subject: [PATCH 3/3] add retry wait for aborting RS by preparing flush cache --- .../hadoop/hbase/regionserver/HRegion.java | 33 +++++++++++-------- 1 file changed, 19 insertions(+), 14 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 fa8e148c8788..8e67ffc34495 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 @@ -2847,12 +2847,7 @@ protected PrepareFlushResult internalPrepareFlushCache(WAL wal, long myseqid, "flushsize=" + totalSizeOfFlushableStores; status.setStatus(s); - try { - doSyncOfUnflushedWALChanges(wal, getRegionInfo()); - } catch (Throwable t) { - status.abort("Sync unflushed WAL changes failed: " + StringUtils.stringifyException(t)); - fatalForFlushCache(t); - } + doSyncOfUnflushedWALChanges(status, wal, getRegionInfo()); return new PrepareFlushResult(storeFlushCtxs, committedFiles, storeFlushableSize, startTime, flushOpSeqId, flushedSeqId, totalSizeOfFlushableStores); } @@ -2909,17 +2904,27 @@ private void doAbortFlushToWAL(final WAL wal, final long flushOpSeqId, /** * Sync unflushed WAL changes. See HBASE-8208 for details */ - private static void doSyncOfUnflushedWALChanges(final WAL wal, final RegionInfo hri) - throws IOException { + private void doSyncOfUnflushedWALChanges(MonitoredTask status, final WAL wal, + final RegionInfo hri) throws IOException { if (wal == null) { return; } - try { - wal.sync(); // ensure that flush marker is sync'ed - } catch (IOException ioe) { - wal.abortCacheFlush(hri.getEncodedNameAsBytes()); - throw ioe; - } + int retry = 0; + int maxRetry = 3; + IOException lastIOE = null; + do { + try { + wal.sync(); // ensure that flush marker is sync'ed + return; + } catch (IOException ioe) { + retry++; + LOG.warn("Sync region " + hri + " unflushed WAL changes failed, retry time " + retry, ioe); + lastIOE = ioe; + } + } while (retry < maxRetry); + status.abort("Sync region " + hri + " unflushed WAL changes failed: " + StringUtils + .stringifyException(lastIOE)); + fatalForFlushCache(lastIOE); } /**