001/** 002 * Licensed to the Apache Software Foundation (ASF) under one 003 * or more contributor license agreements. See the NOTICE file 004 * distributed with this work for additional information 005 * regarding copyright ownership. The ASF licenses this file 006 * to you under the Apache License, Version 2.0 (the 007 * "License"); you may not use this file except in compliance 008 * with the License. You may obtain a copy of the License at 009 * 010 * http://www.apache.org/licenses/LICENSE-2.0 011 * 012 * Unless required by applicable law or agreed to in writing, software 013 * distributed under the License is distributed on an "AS IS" BASIS, 014 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 015 * See the License for the specific language governing permissions and 016 * limitations under the License. 017 */ 018package org.apache.hadoop.hbase.regionserver.wal; 019 020import static org.apache.hadoop.hbase.wal.AbstractFSWALProvider.WAL_FILE_NAME_DELIMITER; 021import static org.apache.hbase.thirdparty.com.google.common.base.Preconditions.checkArgument; 022import static org.apache.hbase.thirdparty.com.google.common.base.Preconditions.checkNotNull; 023 024import com.lmax.disruptor.RingBuffer; 025import java.io.FileNotFoundException; 026import java.io.IOException; 027import java.io.InterruptedIOException; 028import java.lang.management.MemoryType; 029import java.net.URLEncoder; 030import java.util.ArrayList; 031import java.util.Arrays; 032import java.util.Comparator; 033import java.util.List; 034import java.util.Map; 035import java.util.OptionalLong; 036import java.util.Set; 037import java.util.concurrent.ConcurrentHashMap; 038import java.util.concurrent.ConcurrentMap; 039import java.util.concurrent.ConcurrentNavigableMap; 040import java.util.concurrent.ConcurrentSkipListMap; 041import java.util.concurrent.CopyOnWriteArrayList; 042import java.util.concurrent.ExecutionException; 043import java.util.concurrent.TimeUnit; 044import java.util.concurrent.atomic.AtomicBoolean; 045import java.util.concurrent.atomic.AtomicInteger; 046import java.util.concurrent.atomic.AtomicLong; 047import java.util.concurrent.locks.ReentrantLock; 048import org.apache.commons.lang3.mutable.MutableLong; 049import org.apache.hadoop.conf.Configuration; 050import org.apache.hadoop.fs.FileStatus; 051import org.apache.hadoop.fs.FileSystem; 052import org.apache.hadoop.fs.Path; 053import org.apache.hadoop.fs.PathFilter; 054import org.apache.hadoop.hbase.Cell; 055import org.apache.hadoop.hbase.HBaseConfiguration; 056import org.apache.hadoop.hbase.HConstants; 057import org.apache.hadoop.hbase.PrivateCellUtil; 058import org.apache.hadoop.hbase.client.RegionInfo; 059import org.apache.hadoop.hbase.exceptions.TimeoutIOException; 060import org.apache.hadoop.hbase.io.util.MemorySizeUtil; 061import org.apache.hadoop.hbase.log.HBaseMarkers; 062import org.apache.hadoop.hbase.regionserver.MultiVersionConcurrencyControl; 063import org.apache.hadoop.hbase.trace.TraceUtil; 064import org.apache.hadoop.hbase.util.Bytes; 065import org.apache.hadoop.hbase.util.CollectionUtils; 066import org.apache.hadoop.hbase.util.CommonFSUtils; 067import org.apache.hadoop.hbase.util.EnvironmentEdgeManager; 068import org.apache.hadoop.hbase.util.FSUtils; 069import org.apache.hadoop.hbase.util.Pair; 070import org.apache.hadoop.hbase.wal.AbstractFSWALProvider; 071import org.apache.hadoop.hbase.wal.WAL; 072import org.apache.hadoop.hbase.wal.WALEdit; 073import org.apache.hadoop.hbase.wal.WALFactory; 074import org.apache.hadoop.hbase.wal.WALKeyImpl; 075import org.apache.hadoop.hbase.wal.WALPrettyPrinter; 076import org.apache.hadoop.hbase.wal.WALProvider.WriterBase; 077import org.apache.hadoop.hbase.wal.WALSplitter; 078import org.apache.hadoop.hdfs.protocol.DatanodeInfo; 079import org.apache.hadoop.util.StringUtils; 080import org.apache.htrace.core.TraceScope; 081import org.apache.yetus.audience.InterfaceAudience; 082import org.slf4j.Logger; 083import org.slf4j.LoggerFactory; 084 085import org.apache.hbase.thirdparty.com.google.common.annotations.VisibleForTesting; 086 087/** 088 * Implementation of {@link WAL} to go against {@link FileSystem}; i.e. keep WALs in HDFS. Only one 089 * WAL is ever being written at a time. When a WAL hits a configured maximum size, it is rolled. 090 * This is done internal to the implementation. 091 * <p> 092 * As data is flushed from the MemStore to other on-disk structures (files sorted by key, hfiles), a 093 * WAL becomes obsolete. We can let go of all the log edits/entries for a given HRegion-sequence id. 094 * A bunch of work in the below is done keeping account of these region sequence ids -- what is 095 * flushed out to hfiles, and what is yet in WAL and in memory only. 096 * <p> 097 * It is only practical to delete entire files. Thus, we delete an entire on-disk file 098 * <code>F</code> when all of the edits in <code>F</code> have a log-sequence-id that's older 099 * (smaller) than the most-recent flush. 100 * <p> 101 * To read an WAL, call 102 * {@link WALFactory#createReader(org.apache.hadoop.fs.FileSystem, org.apache.hadoop.fs.Path)}. * 103 * <h2>Failure Semantic</h2> If an exception on append or sync, roll the WAL because the current WAL 104 * is now a lame duck; any more appends or syncs will fail also with the same original exception. If 105 * we have made successful appends to the WAL and we then are unable to sync them, our current 106 * semantic is to return error to the client that the appends failed but also to abort the current 107 * context, usually the hosting server. We need to replay the WALs. <br> 108 * TODO: Change this semantic. A roll of WAL may be sufficient as long as we have flagged client 109 * that the append failed. <br> 110 * TODO: replication may pick up these last edits though they have been marked as failed append 111 * (Need to keep our own file lengths, not rely on HDFS). 112 */ 113@InterfaceAudience.Private 114public abstract class AbstractFSWAL<W extends WriterBase> implements WAL { 115 116 private static final Logger LOG = LoggerFactory.getLogger(AbstractFSWAL.class); 117 118 protected static final int DEFAULT_SLOW_SYNC_TIME_MS = 100; // in ms 119 120 private static final int DEFAULT_WAL_SYNC_TIMEOUT_MS = 5 * 60 * 1000; // in ms, 5min 121 122 /** 123 * file system instance 124 */ 125 protected final FileSystem fs; 126 127 /** 128 * WAL directory, where all WAL files would be placed. 129 */ 130 protected final Path walDir; 131 132 /** 133 * dir path where old logs are kept. 134 */ 135 protected final Path walArchiveDir; 136 137 /** 138 * Matches just those wal files that belong to this wal instance. 139 */ 140 protected final PathFilter ourFiles; 141 142 /** 143 * Prefix of a WAL file, usually the region server name it is hosted on. 144 */ 145 protected final String walFilePrefix; 146 147 /** 148 * Suffix included on generated wal file names 149 */ 150 protected final String walFileSuffix; 151 152 /** 153 * Prefix used when checking for wal membership. 154 */ 155 protected final String prefixPathStr; 156 157 protected final WALCoprocessorHost coprocessorHost; 158 159 /** 160 * conf object 161 */ 162 protected final Configuration conf; 163 164 /** Listeners that are called on WAL events. */ 165 protected final List<WALActionsListener> listeners = new CopyOnWriteArrayList<>(); 166 167 /** 168 * Class that does accounting of sequenceids in WAL subsystem. Holds oldest outstanding sequence 169 * id as yet not flushed as well as the most recent edit sequence id appended to the WAL. Has 170 * facility for answering questions such as "Is it safe to GC a WAL?". 171 */ 172 protected final SequenceIdAccounting sequenceIdAccounting = new SequenceIdAccounting(); 173 174 protected final long slowSyncNs; 175 176 private final long walSyncTimeoutNs; 177 178 // If > than this size, roll the log. 179 protected final long logrollsize; 180 181 /** 182 * Block size to use writing files. 183 */ 184 protected final long blocksize; 185 186 /* 187 * If more than this many logs, force flush of oldest region to oldest edit goes to disk. If too 188 * many and we crash, then will take forever replaying. Keep the number of logs tidy. 189 */ 190 protected final int maxLogs; 191 192 /** 193 * This lock makes sure only one log roll runs at a time. Should not be taken while any other lock 194 * is held. We don't just use synchronized because that results in bogus and tedious findbugs 195 * warning when it thinks synchronized controls writer thread safety. It is held when we are 196 * actually rolling the log. It is checked when we are looking to see if we should roll the log or 197 * not. 198 */ 199 protected final ReentrantLock rollWriterLock = new ReentrantLock(true); 200 201 // The timestamp (in ms) when the log file was created. 202 protected final AtomicLong filenum = new AtomicLong(-1); 203 204 // Number of transactions in the current Wal. 205 protected final AtomicInteger numEntries = new AtomicInteger(0); 206 207 /** 208 * The highest known outstanding unsync'd WALEdit transaction id. Usually, we use a queue to pass 209 * WALEdit to background consumer thread, and the transaction id is the sequence number of the 210 * corresponding entry in queue. 211 */ 212 protected volatile long highestUnsyncedTxid = -1; 213 214 /** 215 * Updated to the transaction id of the last successful sync call. This can be less than 216 * {@link #highestUnsyncedTxid} for case where we have an append where a sync has not yet come in 217 * for it. 218 */ 219 protected final AtomicLong highestSyncedTxid = new AtomicLong(0); 220 221 /** 222 * The total size of wal 223 */ 224 protected final AtomicLong totalLogSize = new AtomicLong(0); 225 /** 226 * Current log file. 227 */ 228 volatile W writer; 229 230 // Last time to check low replication on hlog's pipeline 231 private long lastTimeCheckLowReplication = EnvironmentEdgeManager.currentTime(); 232 233 protected volatile boolean closed = false; 234 235 protected final AtomicBoolean shutdown = new AtomicBoolean(false); 236 /** 237 * WAL Comparator; it compares the timestamp (log filenum), present in the log file name. Throws 238 * an IllegalArgumentException if used to compare paths from different wals. 239 */ 240 final Comparator<Path> LOG_NAME_COMPARATOR = 241 (o1, o2) -> Long.compare(getFileNumFromFileName(o1), getFileNumFromFileName(o2)); 242 243 private static final class WalProps { 244 245 /** 246 * Map the encoded region name to the highest sequence id. Contain all the regions it has 247 * entries of 248 */ 249 public final Map<byte[], Long> encodedName2HighestSequenceId; 250 251 /** 252 * The log file size. Notice that the size may not be accurate if we do asynchronous close in 253 * sub classes. 254 */ 255 public final long logSize; 256 257 public WalProps(Map<byte[], Long> encodedName2HighestSequenceId, long logSize) { 258 this.encodedName2HighestSequenceId = encodedName2HighestSequenceId; 259 this.logSize = logSize; 260 } 261 } 262 263 /** 264 * Map of WAL log file to properties. The map is sorted by the log file creation timestamp 265 * (contained in the log file name). 266 */ 267 protected ConcurrentNavigableMap<Path, WalProps> walFile2Props = 268 new ConcurrentSkipListMap<>(LOG_NAME_COMPARATOR); 269 270 /** 271 * Map of {@link SyncFuture}s keyed by Handler objects. Used so we reuse SyncFutures. 272 * <p> 273 * TODO: Reuse FSWALEntry's rather than create them anew each time as we do SyncFutures here. 274 * <p> 275 * TODO: Add a FSWalEntry and SyncFuture as thread locals on handlers rather than have them get 276 * them from this Map? 277 */ 278 private final ConcurrentMap<Thread, SyncFuture> syncFuturesByHandler; 279 280 /** 281 * The class name of the runtime implementation, used as prefix for logging/tracing. 282 * <p> 283 * Performance testing shows getClass().getSimpleName() might be a bottleneck so we store it here, 284 * refer to HBASE-17676 for more details 285 * </p> 286 */ 287 protected final String implClassName; 288 289 public long getFilenum() { 290 return this.filenum.get(); 291 } 292 293 /** 294 * A log file has a creation timestamp (in ms) in its file name ({@link #filenum}. This helper 295 * method returns the creation timestamp from a given log file. It extracts the timestamp assuming 296 * the filename is created with the {@link #computeFilename(long filenum)} method. 297 * @return timestamp, as in the log file name. 298 */ 299 protected long getFileNumFromFileName(Path fileName) { 300 checkNotNull(fileName, "file name can't be null"); 301 if (!ourFiles.accept(fileName)) { 302 throw new IllegalArgumentException( 303 "The log file " + fileName + " doesn't belong to this WAL. (" + toString() + ")"); 304 } 305 final String fileNameString = fileName.toString(); 306 String chompedPath = fileNameString.substring(prefixPathStr.length(), 307 (fileNameString.length() - walFileSuffix.length())); 308 return Long.parseLong(chompedPath); 309 } 310 311 private int calculateMaxLogFiles(Configuration conf, long logRollSize) { 312 Pair<Long, MemoryType> globalMemstoreSize = MemorySizeUtil.getGlobalMemStoreSize(conf); 313 return (int) ((globalMemstoreSize.getFirst() * 2) / logRollSize); 314 } 315 316 // must be power of 2 317 protected final int getPreallocatedEventCount() { 318 // Preallocate objects to use on the ring buffer. The way that appends and syncs work, we will 319 // be stuck and make no progress if the buffer is filled with appends only and there is no 320 // sync. If no sync, then the handlers will be outstanding just waiting on sync completion 321 // before they return. 322 int preallocatedEventCount = 323 this.conf.getInt("hbase.regionserver.wal.disruptor.event.count", 1024 * 16); 324 checkArgument(preallocatedEventCount >= 0, 325 "hbase.regionserver.wal.disruptor.event.count must > 0"); 326 int floor = Integer.highestOneBit(preallocatedEventCount); 327 if (floor == preallocatedEventCount) { 328 return floor; 329 } 330 // max capacity is 1 << 30 331 if (floor >= 1 << 29) { 332 return 1 << 30; 333 } 334 return floor << 1; 335 } 336 337 protected AbstractFSWAL(final FileSystem fs, final Path rootDir, final String logDir, 338 final String archiveDir, final Configuration conf, final List<WALActionsListener> listeners, 339 final boolean failIfWALExists, final String prefix, final String suffix) 340 throws FailedLogCloseException, IOException { 341 this.fs = fs; 342 this.walDir = new Path(rootDir, logDir); 343 this.walArchiveDir = new Path(rootDir, archiveDir); 344 this.conf = conf; 345 346 if (!fs.exists(walDir) && !fs.mkdirs(walDir)) { 347 throw new IOException("Unable to mkdir " + walDir); 348 } 349 350 if (!fs.exists(this.walArchiveDir)) { 351 if (!fs.mkdirs(this.walArchiveDir)) { 352 throw new IOException("Unable to mkdir " + this.walArchiveDir); 353 } 354 } 355 356 // If prefix is null||empty then just name it wal 357 this.walFilePrefix = 358 prefix == null || prefix.isEmpty() ? "wal" : URLEncoder.encode(prefix, "UTF8"); 359 // we only correctly differentiate suffices when numeric ones start with '.' 360 if (suffix != null && !(suffix.isEmpty()) && !(suffix.startsWith(WAL_FILE_NAME_DELIMITER))) { 361 throw new IllegalArgumentException("WAL suffix must start with '" + WAL_FILE_NAME_DELIMITER + 362 "' but instead was '" + suffix + "'"); 363 } 364 // Now that it exists, set the storage policy for the entire directory of wal files related to 365 // this FSHLog instance 366 String storagePolicy = 367 conf.get(HConstants.WAL_STORAGE_POLICY, HConstants.DEFAULT_WAL_STORAGE_POLICY); 368 CommonFSUtils.setStoragePolicy(fs, this.walDir, storagePolicy); 369 this.walFileSuffix = (suffix == null) ? "" : URLEncoder.encode(suffix, "UTF8"); 370 this.prefixPathStr = new Path(walDir, walFilePrefix + WAL_FILE_NAME_DELIMITER).toString(); 371 372 this.ourFiles = new PathFilter() { 373 @Override 374 public boolean accept(final Path fileName) { 375 // The path should start with dir/<prefix> and end with our suffix 376 final String fileNameString = fileName.toString(); 377 if (!fileNameString.startsWith(prefixPathStr)) { 378 return false; 379 } 380 if (walFileSuffix.isEmpty()) { 381 // in the case of the null suffix, we need to ensure the filename ends with a timestamp. 382 return org.apache.commons.lang3.StringUtils 383 .isNumeric(fileNameString.substring(prefixPathStr.length())); 384 } else if (!fileNameString.endsWith(walFileSuffix)) { 385 return false; 386 } 387 return true; 388 } 389 }; 390 391 if (failIfWALExists) { 392 final FileStatus[] walFiles = CommonFSUtils.listStatus(fs, walDir, ourFiles); 393 if (null != walFiles && 0 != walFiles.length) { 394 throw new IOException("Target WAL already exists within directory " + walDir); 395 } 396 } 397 398 // Register listeners. TODO: Should this exist anymore? We have CPs? 399 if (listeners != null) { 400 for (WALActionsListener i : listeners) { 401 registerWALActionsListener(i); 402 } 403 } 404 this.coprocessorHost = new WALCoprocessorHost(this, conf); 405 406 // Schedule a WAL roll when the WAL is 50% of the HDFS block size. Scheduling at 50% of block 407 // size should make it so WAL rolls before we get to the end-of-block (Block transitions cost 408 // some latency). In hbase-1 we did this differently. We scheduled a roll when we hit 95% of 409 // the block size but experience from the field has it that this was not enough time for the 410 // roll to happen before end-of-block. So the new accounting makes WALs of about the same 411 // size as those made in hbase-1 (to prevent surprise), we now have default block size as 412 // 2 times the DFS default: i.e. 2 * DFS default block size rolling at 50% full will generally 413 // make similar size logs to 1 * DFS default block size rolling at 95% full. See HBASE-19148. 414 this.blocksize = WALUtil.getWALBlockSize(this.conf, this.fs, this.walDir); 415 float multiplier = conf.getFloat("hbase.regionserver.logroll.multiplier", 0.5f); 416 this.logrollsize = (long)(this.blocksize * multiplier); 417 418 boolean maxLogsDefined = conf.get("hbase.regionserver.maxlogs") != null; 419 if (maxLogsDefined) { 420 LOG.warn("'hbase.regionserver.maxlogs' was deprecated."); 421 } 422 this.maxLogs = conf.getInt("hbase.regionserver.maxlogs", 423 Math.max(32, calculateMaxLogFiles(conf, logrollsize))); 424 425 LOG.info("WAL configuration: blocksize=" + StringUtils.byteDesc(blocksize) + ", rollsize=" + 426 StringUtils.byteDesc(this.logrollsize) + ", prefix=" + this.walFilePrefix + ", suffix=" + 427 walFileSuffix + ", logDir=" + this.walDir + ", archiveDir=" + this.walArchiveDir); 428 this.slowSyncNs = TimeUnit.MILLISECONDS 429 .toNanos(conf.getInt("hbase.regionserver.hlog.slowsync.ms", DEFAULT_SLOW_SYNC_TIME_MS)); 430 this.walSyncTimeoutNs = TimeUnit.MILLISECONDS 431 .toNanos(conf.getLong("hbase.regionserver.hlog.sync.timeout", DEFAULT_WAL_SYNC_TIMEOUT_MS)); 432 int maxHandlersCount = conf.getInt(HConstants.REGION_SERVER_HANDLER_COUNT, 200); 433 // Presize our map of SyncFutures by handler objects. 434 this.syncFuturesByHandler = new ConcurrentHashMap<>(maxHandlersCount); 435 this.implClassName = getClass().getSimpleName(); 436 } 437 438 @Override 439 public void registerWALActionsListener(WALActionsListener listener) { 440 this.listeners.add(listener); 441 } 442 443 @Override 444 public boolean unregisterWALActionsListener(WALActionsListener listener) { 445 return this.listeners.remove(listener); 446 } 447 448 @Override 449 public WALCoprocessorHost getCoprocessorHost() { 450 return coprocessorHost; 451 } 452 453 @Override 454 public Long startCacheFlush(byte[] encodedRegionName, Set<byte[]> families) { 455 return this.sequenceIdAccounting.startCacheFlush(encodedRegionName, families); 456 } 457 458 @Override 459 public Long startCacheFlush(byte[] encodedRegionName, Map<byte[], Long> familyToSeq) { 460 return this.sequenceIdAccounting.startCacheFlush(encodedRegionName, familyToSeq); 461 } 462 463 @Override 464 public void completeCacheFlush(byte[] encodedRegionName) { 465 this.sequenceIdAccounting.completeCacheFlush(encodedRegionName); 466 } 467 468 @Override 469 public void abortCacheFlush(byte[] encodedRegionName) { 470 this.sequenceIdAccounting.abortCacheFlush(encodedRegionName); 471 } 472 473 @Override 474 public long getEarliestMemStoreSeqNum(byte[] encodedRegionName) { 475 // Used by tests. Deprecated as too subtle for general usage. 476 return this.sequenceIdAccounting.getLowestSequenceId(encodedRegionName); 477 } 478 479 @Override 480 public long getEarliestMemStoreSeqNum(byte[] encodedRegionName, byte[] familyName) { 481 // This method is used by tests and for figuring if we should flush or not because our 482 // sequenceids are too old. It is also used reporting the master our oldest sequenceid for use 483 // figuring what edits can be skipped during log recovery. getEarliestMemStoreSequenceId 484 // from this.sequenceIdAccounting is looking first in flushingOldestStoreSequenceIds, the 485 // currently flushing sequence ids, and if anything found there, it is returning these. This is 486 // the right thing to do for the reporting oldest sequenceids to master; we won't skip edits if 487 // we crash during the flush. For figuring what to flush, we might get requeued if our sequence 488 // id is old even though we are currently flushing. This may mean we do too much flushing. 489 return this.sequenceIdAccounting.getLowestSequenceId(encodedRegionName, familyName); 490 } 491 492 @Override 493 public byte[][] rollWriter() throws FailedLogCloseException, IOException { 494 return rollWriter(false); 495 } 496 497 /** 498 * This is a convenience method that computes a new filename with a given file-number. 499 * @param filenum to use 500 * @return Path 501 */ 502 protected Path computeFilename(final long filenum) { 503 if (filenum < 0) { 504 throw new RuntimeException("WAL file number can't be < 0"); 505 } 506 String child = walFilePrefix + WAL_FILE_NAME_DELIMITER + filenum + walFileSuffix; 507 return new Path(walDir, child); 508 } 509 510 /** 511 * This is a convenience method that computes a new filename with a given using the current WAL 512 * file-number 513 * @return Path 514 */ 515 public Path getCurrentFileName() { 516 return computeFilename(this.filenum.get()); 517 } 518 519 /** 520 * retrieve the next path to use for writing. Increments the internal filenum. 521 */ 522 private Path getNewPath() throws IOException { 523 this.filenum.set(System.currentTimeMillis()); 524 Path newPath = getCurrentFileName(); 525 while (fs.exists(newPath)) { 526 this.filenum.incrementAndGet(); 527 newPath = getCurrentFileName(); 528 } 529 return newPath; 530 } 531 532 @VisibleForTesting 533 Path getOldPath() { 534 long currentFilenum = this.filenum.get(); 535 Path oldPath = null; 536 if (currentFilenum > 0) { 537 // ComputeFilename will take care of meta wal filename 538 oldPath = computeFilename(currentFilenum); 539 } // I presume if currentFilenum is <= 0, this is first file and null for oldPath if fine? 540 return oldPath; 541 } 542 543 /** 544 * Tell listeners about pre log roll. 545 */ 546 private void tellListenersAboutPreLogRoll(final Path oldPath, final Path newPath) 547 throws IOException { 548 coprocessorHost.preWALRoll(oldPath, newPath); 549 550 if (!this.listeners.isEmpty()) { 551 for (WALActionsListener i : this.listeners) { 552 i.preLogRoll(oldPath, newPath); 553 } 554 } 555 } 556 557 /** 558 * Tell listeners about post log roll. 559 */ 560 private void tellListenersAboutPostLogRoll(final Path oldPath, final Path newPath) 561 throws IOException { 562 if (!this.listeners.isEmpty()) { 563 for (WALActionsListener i : this.listeners) { 564 i.postLogRoll(oldPath, newPath); 565 } 566 } 567 568 coprocessorHost.postWALRoll(oldPath, newPath); 569 } 570 571 // public only until class moves to o.a.h.h.wal 572 /** @return the number of rolled log files */ 573 public int getNumRolledLogFiles() { 574 return walFile2Props.size(); 575 } 576 577 // public only until class moves to o.a.h.h.wal 578 /** @return the number of log files in use */ 579 public int getNumLogFiles() { 580 // +1 for current use log 581 return getNumRolledLogFiles() + 1; 582 } 583 584 /** 585 * If the number of un-archived WAL files is greater than maximum allowed, check the first 586 * (oldest) WAL file, and returns those regions which should be flushed so that it can be 587 * archived. 588 * @return regions (encodedRegionNames) to flush in order to archive oldest WAL file. 589 */ 590 byte[][] findRegionsToForceFlush() throws IOException { 591 byte[][] regions = null; 592 int logCount = getNumRolledLogFiles(); 593 if (logCount > this.maxLogs && logCount > 0) { 594 Map.Entry<Path, WalProps> firstWALEntry = this.walFile2Props.firstEntry(); 595 regions = 596 this.sequenceIdAccounting.findLower(firstWALEntry.getValue().encodedName2HighestSequenceId); 597 } 598 if (regions != null) { 599 StringBuilder sb = new StringBuilder(); 600 for (int i = 0; i < regions.length; i++) { 601 if (i > 0) { 602 sb.append(", "); 603 } 604 sb.append(Bytes.toStringBinary(regions[i])); 605 } 606 LOG.info("Too many WALs; count=" + logCount + ", max=" + this.maxLogs + 607 "; forcing flush of " + regions.length + " regions(s): " + sb.toString()); 608 } 609 return regions; 610 } 611 612 /** 613 * Archive old logs. A WAL is eligible for archiving if all its WALEdits have been flushed. 614 */ 615 private void cleanOldLogs() throws IOException { 616 List<Pair<Path, Long>> logsToArchive = null; 617 // For each log file, look at its Map of regions to highest sequence id; if all sequence ids 618 // are older than what is currently in memory, the WAL can be GC'd. 619 for (Map.Entry<Path, WalProps> e : this.walFile2Props.entrySet()) { 620 Path log = e.getKey(); 621 Map<byte[], Long> sequenceNums = e.getValue().encodedName2HighestSequenceId; 622 if (this.sequenceIdAccounting.areAllLower(sequenceNums)) { 623 if (logsToArchive == null) { 624 logsToArchive = new ArrayList<>(); 625 } 626 logsToArchive.add(Pair.newPair(log, e.getValue().logSize)); 627 if (LOG.isTraceEnabled()) { 628 LOG.trace("WAL file ready for archiving " + log); 629 } 630 } 631 } 632 if (logsToArchive != null) { 633 for (Pair<Path, Long> logAndSize : logsToArchive) { 634 this.totalLogSize.addAndGet(-logAndSize.getSecond()); 635 archiveLogFile(logAndSize.getFirst()); 636 this.walFile2Props.remove(logAndSize.getFirst()); 637 } 638 } 639 } 640 641 /* 642 * only public so WALSplitter can use. 643 * @return archived location of a WAL file with the given path p 644 */ 645 public static Path getWALArchivePath(Path archiveDir, Path p) { 646 return new Path(archiveDir, p.getName()); 647 } 648 649 private void archiveLogFile(final Path p) throws IOException { 650 Path newPath = getWALArchivePath(this.walArchiveDir, p); 651 // Tell our listeners that a log is going to be archived. 652 if (!this.listeners.isEmpty()) { 653 for (WALActionsListener i : this.listeners) { 654 i.preLogArchive(p, newPath); 655 } 656 } 657 LOG.info("Archiving " + p + " to " + newPath); 658 if (!CommonFSUtils.renameAndSetModifyTime(this.fs, p, newPath)) { 659 throw new IOException("Unable to rename " + p + " to " + newPath); 660 } 661 // Tell our listeners that a log has been archived. 662 if (!this.listeners.isEmpty()) { 663 for (WALActionsListener i : this.listeners) { 664 i.postLogArchive(p, newPath); 665 } 666 } 667 } 668 669 protected final void logRollAndSetupWalProps(Path oldPath, Path newPath, long oldFileLen) { 670 int oldNumEntries = this.numEntries.getAndSet(0); 671 String newPathString = newPath != null ? CommonFSUtils.getPath(newPath) : null; 672 if (oldPath != null) { 673 this.walFile2Props.put(oldPath, 674 new WalProps(this.sequenceIdAccounting.resetHighest(), oldFileLen)); 675 this.totalLogSize.addAndGet(oldFileLen); 676 LOG.info("Rolled WAL {} with entries={}, filesize={}; new WAL {}", 677 CommonFSUtils.getPath(oldPath), oldNumEntries, StringUtils.byteDesc(oldFileLen), 678 newPathString); 679 } else { 680 LOG.info("New WAL {}", newPathString); 681 } 682 } 683 684 /** 685 * <p> 686 * Cleans up current writer closing it and then puts in place the passed in 687 * <code>nextWriter</code>. 688 * </p> 689 * <p> 690 * <ul> 691 * <li>In the case of creating a new WAL, oldPath will be null.</li> 692 * <li>In the case of rolling over from one file to the next, none of the parameters will be null. 693 * </li> 694 * <li>In the case of closing out this FSHLog with no further use newPath and nextWriter will be 695 * null.</li> 696 * </ul> 697 * </p> 698 * @param oldPath may be null 699 * @param newPath may be null 700 * @param nextWriter may be null 701 * @return the passed in <code>newPath</code> 702 * @throws IOException if there is a problem flushing or closing the underlying FS 703 */ 704 @VisibleForTesting 705 Path replaceWriter(Path oldPath, Path newPath, W nextWriter) throws IOException { 706 try (TraceScope scope = TraceUtil.createTrace("FSHFile.replaceWriter")) { 707 doReplaceWriter(oldPath, newPath, nextWriter); 708 return newPath; 709 } 710 } 711 712 protected final void blockOnSync(SyncFuture syncFuture) throws IOException { 713 // Now we have published the ringbuffer, halt the current thread until we get an answer back. 714 try { 715 if (syncFuture != null) { 716 if (closed) { 717 throw new IOException("WAL has been closed"); 718 } else { 719 syncFuture.get(walSyncTimeoutNs); 720 } 721 } 722 } catch (TimeoutIOException tioe) { 723 // SyncFuture reuse by thread, if TimeoutIOException happens, ringbuffer 724 // still refer to it, so if this thread use it next time may get a wrong 725 // result. 726 this.syncFuturesByHandler.remove(Thread.currentThread()); 727 throw tioe; 728 } catch (InterruptedException ie) { 729 LOG.warn("Interrupted", ie); 730 throw convertInterruptedExceptionToIOException(ie); 731 } catch (ExecutionException e) { 732 throw ensureIOException(e.getCause()); 733 } 734 } 735 736 private static IOException ensureIOException(final Throwable t) { 737 return (t instanceof IOException) ? (IOException) t : new IOException(t); 738 } 739 740 private IOException convertInterruptedExceptionToIOException(final InterruptedException ie) { 741 Thread.currentThread().interrupt(); 742 IOException ioe = new InterruptedIOException(); 743 ioe.initCause(ie); 744 return ioe; 745 } 746 747 @Override 748 public byte[][] rollWriter(boolean force) throws FailedLogCloseException, IOException { 749 rollWriterLock.lock(); 750 try { 751 // Return if nothing to flush. 752 if (!force && this.writer != null && this.numEntries.get() <= 0) { 753 return null; 754 } 755 byte[][] regionsToFlush = null; 756 if (this.closed) { 757 LOG.debug("WAL closed. Skipping rolling of writer"); 758 return regionsToFlush; 759 } 760 try (TraceScope scope = TraceUtil.createTrace("FSHLog.rollWriter")) { 761 Path oldPath = getOldPath(); 762 Path newPath = getNewPath(); 763 // Any exception from here on is catastrophic, non-recoverable so we currently abort. 764 W nextWriter = this.createWriterInstance(newPath); 765 tellListenersAboutPreLogRoll(oldPath, newPath); 766 // NewPath could be equal to oldPath if replaceWriter fails. 767 newPath = replaceWriter(oldPath, newPath, nextWriter); 768 tellListenersAboutPostLogRoll(oldPath, newPath); 769 if (LOG.isDebugEnabled()) { 770 LOG.debug("Create new " + implClassName + " writer with pipeline: " + 771 Arrays.toString(getPipeline())); 772 } 773 // Can we delete any of the old log files? 774 if (getNumRolledLogFiles() > 0) { 775 cleanOldLogs(); 776 regionsToFlush = findRegionsToForceFlush(); 777 } 778 } catch (CommonFSUtils.StreamLacksCapabilityException exception) { 779 // If the underlying FileSystem can't do what we ask, treat as IO failure so 780 // we'll abort. 781 throw new IOException( 782 "Underlying FileSystem can't meet stream requirements. See RS log " + "for details.", 783 exception); 784 } 785 return regionsToFlush; 786 } finally { 787 rollWriterLock.unlock(); 788 } 789 } 790 791 // public only until class moves to o.a.h.h.wal 792 /** @return the size of log files in use */ 793 public long getLogFileSize() { 794 return this.totalLogSize.get(); 795 } 796 797 // public only until class moves to o.a.h.h.wal 798 public void requestLogRoll() { 799 requestLogRoll(false); 800 } 801 802 /** 803 * Get the backing files associated with this WAL. 804 * @return may be null if there are no files. 805 */ 806 @VisibleForTesting 807 FileStatus[] getFiles() throws IOException { 808 return CommonFSUtils.listStatus(fs, walDir, ourFiles); 809 } 810 811 @Override 812 public void shutdown() throws IOException { 813 if (!shutdown.compareAndSet(false, true)) { 814 return; 815 } 816 closed = true; 817 // Tell our listeners that the log is closing 818 if (!this.listeners.isEmpty()) { 819 for (WALActionsListener i : this.listeners) { 820 i.logCloseRequested(); 821 } 822 } 823 rollWriterLock.lock(); 824 try { 825 doShutdown(); 826 } finally { 827 rollWriterLock.unlock(); 828 } 829 } 830 831 @Override 832 public void close() throws IOException { 833 shutdown(); 834 final FileStatus[] files = getFiles(); 835 if (null != files && 0 != files.length) { 836 for (FileStatus file : files) { 837 Path p = getWALArchivePath(this.walArchiveDir, file.getPath()); 838 // Tell our listeners that a log is going to be archived. 839 if (!this.listeners.isEmpty()) { 840 for (WALActionsListener i : this.listeners) { 841 i.preLogArchive(file.getPath(), p); 842 } 843 } 844 845 if (!CommonFSUtils.renameAndSetModifyTime(fs, file.getPath(), p)) { 846 throw new IOException("Unable to rename " + file.getPath() + " to " + p); 847 } 848 // Tell our listeners that a log was archived. 849 if (!this.listeners.isEmpty()) { 850 for (WALActionsListener i : this.listeners) { 851 i.postLogArchive(file.getPath(), p); 852 } 853 } 854 } 855 LOG.debug( 856 "Moved " + files.length + " WAL file(s) to " + CommonFSUtils.getPath(this.walArchiveDir)); 857 } 858 LOG.info("Closed WAL: " + toString()); 859 } 860 861 /** 862 * updates the sequence number of a specific store. depending on the flag: replaces current seq 863 * number if the given seq id is bigger, or even if it is lower than existing one 864 * @param encodedRegionName 865 * @param familyName 866 * @param sequenceid 867 * @param onlyIfGreater 868 */ 869 @Override 870 public void updateStore(byte[] encodedRegionName, byte[] familyName, Long sequenceid, 871 boolean onlyIfGreater) { 872 sequenceIdAccounting.updateStore(encodedRegionName, familyName, sequenceid, onlyIfGreater); 873 } 874 875 protected final SyncFuture getSyncFuture(long sequence) { 876 return CollectionUtils 877 .computeIfAbsent(syncFuturesByHandler, Thread.currentThread(), SyncFuture::new) 878 .reset(sequence); 879 } 880 881 protected final void requestLogRoll(boolean tooFewReplicas) { 882 if (!this.listeners.isEmpty()) { 883 for (WALActionsListener i : this.listeners) { 884 i.logRollRequested(tooFewReplicas); 885 } 886 } 887 } 888 889 long getUnflushedEntriesCount() { 890 long highestSynced = this.highestSyncedTxid.get(); 891 long highestUnsynced = this.highestUnsyncedTxid; 892 return highestSynced >= highestUnsynced ? 0 : highestUnsynced - highestSynced; 893 } 894 895 boolean isUnflushedEntries() { 896 return getUnflushedEntriesCount() > 0; 897 } 898 899 /** 900 * Exposed for testing only. Use to tricks like halt the ring buffer appending. 901 */ 902 @VisibleForTesting 903 void atHeadOfRingBufferEventHandlerAppend() { 904 // Noop 905 } 906 907 protected final boolean append(W writer, FSWALEntry entry) throws IOException { 908 // TODO: WORK ON MAKING THIS APPEND FASTER. DOING WAY TOO MUCH WORK WITH CPs, PBing, etc. 909 atHeadOfRingBufferEventHandlerAppend(); 910 long start = EnvironmentEdgeManager.currentTime(); 911 byte[] encodedRegionName = entry.getKey().getEncodedRegionName(); 912 long regionSequenceId = entry.getKey().getSequenceId(); 913 914 // Edits are empty, there is nothing to append. Maybe empty when we are looking for a 915 // region sequence id only, a region edit/sequence id that is not associated with an actual 916 // edit. It has to go through all the rigmarole to be sure we have the right ordering. 917 if (entry.getEdit().isEmpty()) { 918 return false; 919 } 920 921 // Coprocessor hook. 922 coprocessorHost.preWALWrite(entry.getRegionInfo(), entry.getKey(), entry.getEdit()); 923 if (!listeners.isEmpty()) { 924 for (WALActionsListener i : listeners) { 925 i.visitLogEntryBeforeWrite(entry.getKey(), entry.getEdit()); 926 } 927 } 928 doAppend(writer, entry); 929 assert highestUnsyncedTxid < entry.getTxid(); 930 highestUnsyncedTxid = entry.getTxid(); 931 sequenceIdAccounting.update(encodedRegionName, entry.getFamilyNames(), regionSequenceId, 932 entry.isInMemStore()); 933 coprocessorHost.postWALWrite(entry.getRegionInfo(), entry.getKey(), entry.getEdit()); 934 // Update metrics. 935 postAppend(entry, EnvironmentEdgeManager.currentTime() - start); 936 numEntries.incrementAndGet(); 937 return true; 938 } 939 940 private long postAppend(final Entry e, final long elapsedTime) throws IOException { 941 long len = 0; 942 if (!listeners.isEmpty()) { 943 for (Cell cell : e.getEdit().getCells()) { 944 len += PrivateCellUtil.estimatedSerializedSizeOf(cell); 945 } 946 for (WALActionsListener listener : listeners) { 947 listener.postAppend(len, elapsedTime, e.getKey(), e.getEdit()); 948 } 949 } 950 return len; 951 } 952 953 protected final void postSync(final long timeInNanos, final int handlerSyncs) { 954 if (timeInNanos > this.slowSyncNs) { 955 String msg = new StringBuilder().append("Slow sync cost: ").append(timeInNanos / 1000000) 956 .append(" ms, current pipeline: ").append(Arrays.toString(getPipeline())).toString(); 957 TraceUtil.addTimelineAnnotation(msg); 958 LOG.info(msg); 959 } 960 if (!listeners.isEmpty()) { 961 for (WALActionsListener listener : listeners) { 962 listener.postSync(timeInNanos, handlerSyncs); 963 } 964 } 965 } 966 967 protected final long stampSequenceIdAndPublishToRingBuffer(RegionInfo hri, WALKeyImpl key, 968 WALEdit edits, boolean inMemstore, RingBuffer<RingBufferTruck> ringBuffer) 969 throws IOException { 970 if (this.closed) { 971 throw new IOException( 972 "Cannot append; log is closed, regionName = " + hri.getRegionNameAsString()); 973 } 974 MutableLong txidHolder = new MutableLong(); 975 MultiVersionConcurrencyControl.WriteEntry we = key.getMvcc().begin(() -> { 976 txidHolder.setValue(ringBuffer.next()); 977 }); 978 long txid = txidHolder.longValue(); 979 try (TraceScope scope = TraceUtil.createTrace(implClassName + ".append")) { 980 FSWALEntry entry = new FSWALEntry(txid, key, edits, hri, inMemstore); 981 entry.stampRegionSequenceId(we); 982 ringBuffer.get(txid).load(entry); 983 } finally { 984 ringBuffer.publish(txid); 985 } 986 return txid; 987 } 988 989 @Override 990 public String toString() { 991 return implClassName + " " + walFilePrefix + ":" + walFileSuffix + "(num " + filenum + ")"; 992 } 993 994 /** 995 * if the given {@code path} is being written currently, then return its length. 996 * <p> 997 * This is used by replication to prevent replicating unacked log entries. See 998 * https://issues.apache.org/jira/browse/HBASE-14004 for more details. 999 */ 1000 @Override 1001 public OptionalLong getLogFileSizeIfBeingWritten(Path path) { 1002 rollWriterLock.lock(); 1003 try { 1004 Path currentPath = getOldPath(); 1005 if (path.equals(currentPath)) { 1006 W writer = this.writer; 1007 return writer != null ? OptionalLong.of(writer.getLength()) : OptionalLong.empty(); 1008 } else { 1009 return OptionalLong.empty(); 1010 } 1011 } finally { 1012 rollWriterLock.unlock(); 1013 } 1014 } 1015 1016 /** 1017 * NOTE: This append, at a time that is usually after this call returns, starts an mvcc 1018 * transaction by calling 'begin' wherein which we assign this update a sequenceid. At assignment 1019 * time, we stamp all the passed in Cells inside WALEdit with their sequenceId. You must 1020 * 'complete' the transaction this mvcc transaction by calling 1021 * MultiVersionConcurrencyControl#complete(...) or a variant otherwise mvcc will get stuck. Do it 1022 * in the finally of a try/finally block within which this append lives and any subsequent 1023 * operations like sync or update of memstore, etc. Get the WriteEntry to pass mvcc out of the 1024 * passed in WALKey <code>walKey</code> parameter. Be warned that the WriteEntry is not 1025 * immediately available on return from this method. It WILL be available subsequent to a sync of 1026 * this append; otherwise, you will just have to wait on the WriteEntry to get filled in. 1027 */ 1028 @Override 1029 public abstract long append(RegionInfo info, WALKeyImpl key, WALEdit edits, boolean inMemstore) 1030 throws IOException; 1031 1032 protected abstract void doAppend(W writer, FSWALEntry entry) throws IOException; 1033 1034 protected abstract W createWriterInstance(Path path) 1035 throws IOException, CommonFSUtils.StreamLacksCapabilityException; 1036 1037 protected abstract void doReplaceWriter(Path oldPath, Path newPath, W nextWriter) 1038 throws IOException; 1039 1040 protected abstract void doShutdown() throws IOException; 1041 1042 protected abstract boolean doCheckLogLowReplication(); 1043 1044 public void checkLogLowReplication(long checkInterval) { 1045 long now = EnvironmentEdgeManager.currentTime(); 1046 if (now - lastTimeCheckLowReplication < checkInterval) { 1047 return; 1048 } 1049 // Will return immediately if we are in the middle of a WAL log roll currently. 1050 if (!rollWriterLock.tryLock()) { 1051 return; 1052 } 1053 try { 1054 lastTimeCheckLowReplication = now; 1055 if (doCheckLogLowReplication()) { 1056 requestLogRoll(true); 1057 } 1058 } finally { 1059 rollWriterLock.unlock(); 1060 } 1061 } 1062 1063 /** 1064 * This method gets the pipeline for the current WAL. 1065 */ 1066 @VisibleForTesting 1067 abstract DatanodeInfo[] getPipeline(); 1068 1069 /** 1070 * This method gets the datanode replication count for the current WAL. 1071 */ 1072 @VisibleForTesting 1073 abstract int getLogReplication(); 1074 1075 private static void split(final Configuration conf, final Path p) throws IOException { 1076 FileSystem fs = FSUtils.getWALFileSystem(conf); 1077 if (!fs.exists(p)) { 1078 throw new FileNotFoundException(p.toString()); 1079 } 1080 if (!fs.getFileStatus(p).isDirectory()) { 1081 throw new IOException(p + " is not a directory"); 1082 } 1083 1084 final Path baseDir = FSUtils.getWALRootDir(conf); 1085 Path archiveDir = new Path(baseDir, HConstants.HREGION_OLDLOGDIR_NAME); 1086 if (conf.getBoolean(AbstractFSWALProvider.SEPARATE_OLDLOGDIR, 1087 AbstractFSWALProvider.DEFAULT_SEPARATE_OLDLOGDIR)) { 1088 archiveDir = new Path(archiveDir, p.getName()); 1089 } 1090 WALSplitter.split(baseDir, p, archiveDir, fs, conf, WALFactory.getInstance(conf)); 1091 } 1092 1093 private static void usage() { 1094 System.err.println("Usage: AbstractFSWAL <ARGS>"); 1095 System.err.println("Arguments:"); 1096 System.err.println(" --dump Dump textual representation of passed one or more files"); 1097 System.err.println(" For example: " + 1098 "AbstractFSWAL --dump hdfs://example.com:9000/hbase/WALs/MACHINE/LOGFILE"); 1099 System.err.println(" --split Split the passed directory of WAL logs"); 1100 System.err.println( 1101 " For example: AbstractFSWAL --split hdfs://example.com:9000/hbase/WALs/DIR"); 1102 } 1103 1104 /** 1105 * Pass one or more log file names and it will either dump out a text version on 1106 * <code>stdout</code> or split the specified log files. 1107 */ 1108 public static void main(String[] args) throws IOException { 1109 if (args.length < 2) { 1110 usage(); 1111 System.exit(-1); 1112 } 1113 // either dump using the WALPrettyPrinter or split, depending on args 1114 if (args[0].compareTo("--dump") == 0) { 1115 WALPrettyPrinter.run(Arrays.copyOfRange(args, 1, args.length)); 1116 } else if (args[0].compareTo("--perf") == 0) { 1117 LOG.error(HBaseMarkers.FATAL, "Please use the WALPerformanceEvaluation tool instead. i.e.:"); 1118 LOG.error(HBaseMarkers.FATAL, 1119 "\thbase org.apache.hadoop.hbase.wal.WALPerformanceEvaluation --iterations " + args[1]); 1120 System.exit(-1); 1121 } else if (args[0].compareTo("--split") == 0) { 1122 Configuration conf = HBaseConfiguration.create(); 1123 for (int i = 1; i < args.length; i++) { 1124 try { 1125 Path logPath = new Path(args[i]); 1126 FSUtils.setFsDefault(conf, logPath); 1127 split(conf, logPath); 1128 } catch (IOException t) { 1129 t.printStackTrace(System.err); 1130 System.exit(-1); 1131 } 1132 } 1133 } else { 1134 usage(); 1135 System.exit(-1); 1136 } 1137 } 1138}