View Javadoc

1   /**
2    * Licensed to the Apache Software Foundation (ASF) under one
3    * or more contributor license agreements.  See the NOTICE file
4    * distributed with this work for additional information
5    * regarding copyright ownership.  The ASF licenses this file
6    * to you under the Apache License, Version 2.0 (the
7    * "License"); you may not use this file except in compliance
8    * with the License.  You may obtain a copy of the License at
9    *
10   *     http://www.apache.org/licenses/LICENSE-2.0
11   *
12   * Unless required by applicable law or agreed to in writing, software
13   * distributed under the License is distributed on an "AS IS" BASIS,
14   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15   * See the License for the specific language governing permissions and
16   * limitations under the License.
17   */
18  package org.apache.hadoop.hbase.regionserver.wal;
19  
20  import static org.apache.hadoop.hbase.wal.DefaultWALProvider.WAL_FILE_NAME_DELIMITER;
21  
22  import java.io.FileNotFoundException;
23  import java.io.IOException;
24  import java.io.InterruptedIOException;
25  import java.io.OutputStream;
26  import java.lang.management.MemoryUsage;
27  import java.lang.reflect.InvocationTargetException;
28  import java.net.URLEncoder;
29  import java.util.ArrayList;
30  import java.util.Arrays;
31  import java.util.Comparator;
32  import java.util.List;
33  import java.util.Map;
34  import java.util.NavigableMap;
35  import java.util.Set;
36  import java.util.concurrent.BlockingQueue;
37  import java.util.concurrent.ConcurrentHashMap;
38  import java.util.concurrent.ConcurrentSkipListMap;
39  import java.util.concurrent.CopyOnWriteArrayList;
40  import java.util.concurrent.CountDownLatch;
41  import java.util.concurrent.ExecutionException;
42  import java.util.concurrent.ExecutorService;
43  import java.util.concurrent.Executors;
44  import java.util.concurrent.LinkedBlockingQueue;
45  import java.util.concurrent.TimeUnit;
46  import java.util.concurrent.atomic.AtomicBoolean;
47  import java.util.concurrent.atomic.AtomicInteger;
48  import java.util.concurrent.atomic.AtomicLong;
49  import java.util.concurrent.locks.ReentrantLock;
50  
51  import com.lmax.disruptor.*;
52  import org.apache.commons.lang.mutable.MutableLong;
53  import org.apache.commons.logging.Log;
54  import org.apache.commons.logging.LogFactory;
55  import org.apache.hadoop.conf.Configuration;
56  import org.apache.hadoop.fs.FSDataOutputStream;
57  import org.apache.hadoop.fs.FileStatus;
58  import org.apache.hadoop.fs.FileSystem;
59  import org.apache.hadoop.fs.Path;
60  import org.apache.hadoop.fs.PathFilter;
61  import org.apache.hadoop.hbase.Cell;
62  import org.apache.hadoop.hbase.CellUtil;
63  import org.apache.hadoop.hbase.HBaseConfiguration;
64  import org.apache.hadoop.hbase.HConstants;
65  import org.apache.hadoop.hbase.HRegionInfo;
66  import org.apache.hadoop.hbase.HTableDescriptor;
67  import org.apache.hadoop.hbase.classification.InterfaceAudience;
68  import org.apache.hadoop.hbase.exceptions.TimeoutIOException;
69  import org.apache.hadoop.hbase.io.util.HeapMemorySizeUtil;
70  import org.apache.hadoop.hbase.regionserver.MultiVersionConcurrencyControl;
71  import org.apache.hadoop.hbase.util.Bytes;
72  import org.apache.hadoop.hbase.util.ClassSize;
73  import org.apache.hadoop.hbase.util.DrainBarrier;
74  import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
75  import org.apache.hadoop.hbase.util.FSUtils;
76  import org.apache.hadoop.hbase.util.HasThread;
77  import org.apache.hadoop.hbase.util.Threads;
78  import org.apache.hadoop.hbase.wal.DefaultWALProvider;
79  import org.apache.hadoop.hbase.wal.WAL;
80  import org.apache.hadoop.hbase.wal.WALFactory;
81  import org.apache.hadoop.hbase.wal.WALKey;
82  import org.apache.hadoop.hbase.wal.WALPrettyPrinter;
83  import org.apache.hadoop.hbase.wal.WALProvider.Writer;
84  import org.apache.hadoop.hbase.wal.WALSplitter;
85  import org.apache.hadoop.hdfs.DFSOutputStream;
86  import org.apache.hadoop.hdfs.client.HdfsDataOutputStream;
87  import org.apache.hadoop.hdfs.protocol.DatanodeInfo;
88  import org.apache.hadoop.util.StringUtils;
89  import org.apache.htrace.NullScope;
90  import org.apache.htrace.Span;
91  import org.apache.htrace.Trace;
92  import org.apache.htrace.TraceScope;
93  
94  import com.google.common.annotations.VisibleForTesting;
95  import com.lmax.disruptor.dsl.Disruptor;
96  import com.lmax.disruptor.dsl.ProducerType;
97  
98  /**
99   * Implementation of {@link WAL} to go against {@link FileSystem}; i.e. keep WALs in HDFS.
100  * Only one WAL is ever being written at a time.  When a WAL hits a configured maximum size,
101  * it is rolled.  This is done internal to the implementation.
102  *
103  * <p>As data is flushed from the MemStore to other on-disk structures (files sorted by
104  * key, hfiles), a WAL becomes obsolete. We can let go of all the log edits/entries for a given
105  * HRegion-sequence id.  A bunch of work in the below is done keeping account of these region
106  * sequence ids -- what is flushed out to hfiles, and what is yet in WAL and in memory only.
107  *
108  * <p>It is only practical to delete entire files. Thus, we delete an entire on-disk file
109  * <code>F</code> when all of the edits in <code>F</code> have a log-sequence-id that's older
110  * (smaller) than the most-recent flush.
111  *
112  * <p>To read an WAL, call {@link WALFactory#createReader(org.apache.hadoop.fs.FileSystem,
113  * org.apache.hadoop.fs.Path)}.
114  *
115  * <h2>Failure Semantic</h2>
116  * If an exception on append or sync, roll the WAL because the current WAL is now a lame duck;
117  * any more appends or syncs will fail also with the same original exception. If we have made
118  * successful appends to the WAL and we then are unable to sync them, our current semantic is to
119  * return error to the client that the appends failed but also to abort the current context,
120  * usually the hosting server. We need to replay the WALs. TODO: Change this semantic. A roll of
121  * WAL may be sufficient as long as we have flagged client that the append failed. TODO:
122  * replication may pick up these last edits though they have been marked as failed append (Need to
123  * keep our own file lengths, not rely on HDFS).
124  */
125 @InterfaceAudience.Private
126 public class FSHLog implements WAL {
127   // IMPLEMENTATION NOTES:
128   //
129   // At the core is a ring buffer.  Our ring buffer is the LMAX Disruptor.  It tries to
130   // minimize synchronizations and volatile writes when multiple contending threads as is the case
131   // here appending and syncing on a single WAL.  The Disruptor is configured to handle multiple
132   // producers but it has one consumer only (the producers in HBase are IPC Handlers calling append
133   // and then sync).  The single consumer/writer pulls the appends and syncs off the ring buffer.
134   // When a handler calls sync, it is given back a future. The producer 'blocks' on the future so
135   // it does not return until the sync completes.  The future is passed over the ring buffer from
136   // the producer/handler to the consumer thread where it does its best to batch up the producer
137   // syncs so one WAL sync actually spans multiple producer sync invocations.  How well the
138   // batching works depends on the write rate; i.e. we tend to batch more in times of
139   // high writes/syncs.
140   //
141   // Calls to append now also wait until the append has been done on the consumer side of the
142   // disruptor.  We used to not wait but it makes the implemenation easier to grok if we have
143   // the region edit/sequence id after the append returns.
144   //
145   // TODO: Handlers need to coordinate appending AND syncing.  Can we have the threads contend
146   // once only?  Probably hard given syncs take way longer than an append.
147   //
148   // The consumer threads pass the syncs off to multiple syncing threads in a round robin fashion
149   // to ensure we keep up back-to-back FS sync calls (FS sync calls are the long poll writing the
150   // WAL).  The consumer thread passes the futures to the sync threads for it to complete
151   // the futures when done.
152   //
153   // The 'sequence' in the below is the sequence of the append/sync on the ringbuffer.  It
154   // acts as a sort-of transaction id.  It is always incrementing.
155   //
156   // The RingBufferEventHandler class hosts the ring buffer consuming code.  The threads that
157   // do the actual FS sync are implementations of SyncRunner.  SafePointZigZagLatch is a
158   // synchronization class used to halt the consumer at a safe point --  just after all outstanding
159   // syncs and appends have completed -- so the log roller can swap the WAL out under it.
160 
161   private static final Log LOG = LogFactory.getLog(FSHLog.class);
162 
163   private static final int DEFAULT_SLOW_SYNC_TIME_MS = 100; // in ms
164 
165   private static final int DEFAULT_WAL_SYNC_TIMEOUT_MS = 5 * 60 * 1000; // in ms, 5min
166 
167   /**
168    * The nexus at which all incoming handlers meet.  Does appends and sync with an ordering.
169    * Appends and syncs are each put on the ring which means handlers need to
170    * smash up against the ring twice (can we make it once only? ... maybe not since time to append
171    * is so different from time to sync and sometimes we don't want to sync or we want to async
172    * the sync).  The ring is where we make sure of our ordering and it is also where we do
173    * batching up of handler sync calls.
174    */
175   private final Disruptor<RingBufferTruck> disruptor;
176 
177   /**
178    * An executorservice that runs the disruptor AppendEventHandler append executor.
179    */
180   private final ExecutorService appendExecutor;
181 
182   /**
183    * This fellow is run by the above appendExecutor service but it is all about batching up appends
184    * and syncs; it may shutdown without cleaning out the last few appends or syncs.  To guard
185    * against this, keep a reference to this handler and do explicit close on way out to make sure
186    * all flushed out before we exit.
187    */
188   private final RingBufferEventHandler ringBufferEventHandler;
189 
190   /**
191    * Map of {@link SyncFuture}s owned by Thread objects. Used so we reuse SyncFutures.
192    * Thread local is used so JVM can GC the terminated thread for us. See HBASE-21228
193    * <p>
194    */
195   private final ThreadLocal<SyncFuture> cachedSyncFutures;
196 
197   /**
198    * The highest known outstanding unsync'd WALEdit sequence number where sequence number is the
199    * ring buffer sequence.  Maintained by the ring buffer consumer.
200    */
201   private volatile long highestUnsyncedSequence = -1;
202 
203   /**
204    * Updated to the ring buffer sequence of the last successful sync call.  This can be less than
205    * {@link #highestUnsyncedSequence} for case where we have an append where a sync has not yet
206    * come in for it.  Maintained by the syncing threads.
207    */
208   private final AtomicLong highestSyncedSequence = new AtomicLong(0);
209 
210   /**
211    * file system instance
212    */
213   protected final FileSystem fs;
214 
215   /**
216    * WAL directory, where all WAL files would be placed.
217    */
218   private final Path fullPathLogDir;
219 
220   /**
221    * dir path where old logs are kept.
222    */
223   private final Path fullPathArchiveDir;
224 
225   /**
226    * Matches just those wal files that belong to this wal instance.
227    */
228   private final PathFilter ourFiles;
229 
230   /**
231    * Prefix of a WAL file, usually the region server name it is hosted on.
232    */
233   private final String logFilePrefix;
234 
235   /**
236    * Suffix included on generated wal file names
237    */
238   private final String logFileSuffix;
239 
240   /**
241    * Prefix used when checking for wal membership.
242    */
243   private final String prefixPathStr;
244 
245   private final WALCoprocessorHost coprocessorHost;
246 
247   /**
248    * conf object
249    */
250   protected final Configuration conf;
251 
252   /** Listeners that are called on WAL events. */
253   private final List<WALActionsListener> listeners =
254     new CopyOnWriteArrayList<WALActionsListener>();
255 
256   @Override
257   public void registerWALActionsListener(final WALActionsListener listener) {
258     this.listeners.add(listener);
259   }
260 
261   @Override
262   public boolean unregisterWALActionsListener(final WALActionsListener listener) {
263     return this.listeners.remove(listener);
264   }
265 
266   @Override
267   public WALCoprocessorHost getCoprocessorHost() {
268     return coprocessorHost;
269   }
270 
271   /**
272    * FSDataOutputStream associated with the current SequenceFile.writer
273    */
274   private FSDataOutputStream hdfs_out;
275 
276   // All about log rolling if not enough replicas outstanding.
277 
278   // Minimum tolerable replicas, if the actual value is lower than it, rollWriter will be triggered
279   private final int minTolerableReplication;
280 
281   private final int slowSyncNs;
282 
283   private final long walSyncTimeout;
284 
285   // If live datanode count is lower than the default replicas value,
286   // RollWriter will be triggered in each sync(So the RollWriter will be
287   // triggered one by one in a short time). Using it as a workaround to slow
288   // down the roll frequency triggered by checkLowReplication().
289   private final AtomicInteger consecutiveLogRolls = new AtomicInteger(0);
290 
291   private final int lowReplicationRollLimit;
292 
293   // If consecutiveLogRolls is larger than lowReplicationRollLimit,
294   // then disable the rolling in checkLowReplication().
295   // Enable it if the replications recover.
296   private volatile boolean lowReplicationRollEnabled = true;
297 
298   /**
299    * Class that does accounting of sequenceids in WAL subsystem. Holds oldest outstanding
300    * sequence id as yet not flushed as well as the most recent edit sequence id appended to the
301    * WAL. Has facility for answering questions such as "Is it safe to GC a WAL?".
302    */
303   private SequenceIdAccounting sequenceIdAccounting = new SequenceIdAccounting();
304 
305   /**
306    * Current log file.
307    */
308   volatile Writer writer;
309 
310   /** The barrier used to ensure that close() waits for all log rolls and flushes to finish. */
311   private final DrainBarrier closeBarrier = new DrainBarrier();
312 
313   /**
314    * This lock makes sure only one log roll runs at a time. Should not be taken while any other
315    * lock is held. We don't just use synchronized because that results in bogus and tedious
316    * findbugs warning when it thinks synchronized controls writer thread safety.  It is held when
317    * we are actually rolling the log.  It is checked when we are looking to see if we should roll
318    * the log or not.
319    */
320   private final ReentrantLock rollWriterLock = new ReentrantLock(true);
321 
322   private volatile boolean closed = false;
323   private final AtomicBoolean shutdown = new AtomicBoolean(false);
324 
325   // The timestamp (in ms) when the log file was created.
326   private final AtomicLong filenum = new AtomicLong(-1);
327 
328   // Number of transactions in the current Wal.
329   private final AtomicInteger numEntries = new AtomicInteger(0);
330 
331   // If > than this size, roll the log.
332   private final long logrollsize;
333 
334   /**
335    * The total size of wal
336    */
337   private AtomicLong totalLogSize = new AtomicLong(0);
338 
339   /*
340    * If more than this many logs, force flush of oldest region to oldest edit
341    * goes to disk.  If too many and we crash, then will take forever replaying.
342    * Keep the number of logs tidy.
343    */
344   private final int maxLogs;
345 
346   /** Number of log close errors tolerated before we abort */
347   private final int closeErrorsTolerated;
348 
349   private final AtomicInteger closeErrorCount = new AtomicInteger();
350 
351   // Last time to check low replication on hlog's pipeline
352   private volatile long lastTimeCheckLowReplication = EnvironmentEdgeManager.currentTime();
353 
354 
355   /**
356    * WAL Comparator; it compares the timestamp (log filenum), present in the log file name.
357    * Throws an IllegalArgumentException if used to compare paths from different wals.
358    */
359   final Comparator<Path> LOG_NAME_COMPARATOR = new Comparator<Path>() {
360     @Override
361     public int compare(Path o1, Path o2) {
362       long t1 = getFileNumFromFileName(o1);
363       long t2 = getFileNumFromFileName(o2);
364       if (t1 == t2) return 0;
365       return (t1 > t2) ? 1 : -1;
366     }
367   };
368 
369   /**
370    * Map of WAL log file to the latest sequence ids of all regions it has entries of.
371    * The map is sorted by the log file creation timestamp (contained in the log file name).
372    */
373   private NavigableMap<Path, Map<byte[], Long>> byWalRegionSequenceIds =
374     new ConcurrentSkipListMap<Path, Map<byte[], Long>>(LOG_NAME_COMPARATOR);
375 
376   /**
377    * Exception handler to pass the disruptor ringbuffer.  Same as native implementation only it
378    * logs using our logger instead of java native logger.
379    */
380   static class RingBufferExceptionHandler implements ExceptionHandler {
381     @Override
382     public void handleEventException(Throwable ex, long sequence, Object event) {
383       LOG.error("Sequence=" + sequence + ", event=" + event, ex);
384       throw new RuntimeException(ex);
385     }
386 
387     @Override
388     public void handleOnStartException(Throwable ex) {
389       LOG.error(ex);
390       throw new RuntimeException(ex);
391     }
392 
393     @Override
394     public void handleOnShutdownException(Throwable ex) {
395       LOG.error(ex);
396       throw new RuntimeException(ex);
397     }
398   }
399 
400   /**
401    * Constructor.
402    *
403    * @param fs filesystem handle
404    * @param root path for stored and archived wals
405    * @param logDir dir where wals are stored
406    * @param conf configuration to use
407    * @throws IOException
408    */
409   public FSHLog(final FileSystem fs, final Path root, final String logDir, final Configuration conf)
410       throws IOException {
411     this(fs, root, logDir, HConstants.HREGION_OLDLOGDIR_NAME, conf, null, true, null, null);
412   }
413 
414   /**
415    * Create an edit log at the given <code>dir</code> location.
416    *
417    * You should never have to load an existing log. If there is a log at
418    * startup, it should have already been processed and deleted by the time the
419    * WAL object is started up.
420    *
421    * @param fs filesystem handle
422    * @param rootDir path to where logs and oldlogs
423    * @param logDir dir where wals are stored
424    * @param archiveDir dir where wals are archived
425    * @param conf configuration to use
426    * @param listeners Listeners on WAL events. Listeners passed here will
427    * be registered before we do anything else; e.g. the
428    * Constructor {@link #rollWriter()}.
429    * @param failIfWALExists If true IOException will be thrown if files related to this wal
430    *        already exist.
431    * @param prefix should always be hostname and port in distributed env and
432    *        it will be URL encoded before being used.
433    *        If prefix is null, "wal" will be used
434    * @param suffix will be url encoded. null is treated as empty. non-empty must start with
435    *        {@link DefaultWALProvider#WAL_FILE_NAME_DELIMITER}
436    * @throws IOException
437    */
438   public FSHLog(final FileSystem fs, final Path rootDir, final String logDir,
439       final String archiveDir, final Configuration conf,
440       final List<WALActionsListener> listeners,
441       final boolean failIfWALExists, final String prefix, final String suffix)
442       throws IOException {
443     this.fs = fs;
444     this.fullPathLogDir = new Path(rootDir, logDir);
445     this.fullPathArchiveDir = new Path(rootDir, archiveDir);
446     this.conf = conf;
447 
448     if (!fs.exists(fullPathLogDir) && !fs.mkdirs(fullPathLogDir)) {
449       throw new IOException("Unable to mkdir " + fullPathLogDir);
450     }
451 
452     if (!fs.exists(this.fullPathArchiveDir)) {
453       if (!fs.mkdirs(this.fullPathArchiveDir)) {
454         throw new IOException("Unable to mkdir " + this.fullPathArchiveDir);
455       }
456     }
457 
458     // If prefix is null||empty then just name it wal
459     this.logFilePrefix =
460       prefix == null || prefix.isEmpty() ? "wal" : URLEncoder.encode(prefix, "UTF8");
461     // we only correctly differentiate suffices when numeric ones start with '.'
462     if (suffix != null && !(suffix.isEmpty()) && !(suffix.startsWith(WAL_FILE_NAME_DELIMITER))) {
463       throw new IllegalArgumentException("WAL suffix must start with '" + WAL_FILE_NAME_DELIMITER +
464           "' but instead was '" + suffix + "'");
465     }
466     // Now that it exists, set the storage policy for the entire directory of wal files related to
467     // this FSHLog instance
468     FSUtils.setStoragePolicy(fs, conf, this.fullPathLogDir, HConstants.WAL_STORAGE_POLICY,
469       HConstants.DEFAULT_WAL_STORAGE_POLICY);
470     this.logFileSuffix = (suffix == null) ? "" : URLEncoder.encode(suffix, "UTF8");
471     this.prefixPathStr = new Path(fullPathLogDir,
472         logFilePrefix + WAL_FILE_NAME_DELIMITER).toString();
473 
474     this.ourFiles = new PathFilter() {
475       @Override
476       public boolean accept(final Path fileName) {
477         // The path should start with dir/<prefix> and end with our suffix
478         final String fileNameString = fileName.toString();
479         if (!fileNameString.startsWith(prefixPathStr)) {
480           return false;
481         }
482         if (logFileSuffix.isEmpty()) {
483           // in the case of the null suffix, we need to ensure the filename ends with a timestamp.
484           return org.apache.commons.lang.StringUtils.isNumeric(
485               fileNameString.substring(prefixPathStr.length()));
486         } else if (!fileNameString.endsWith(logFileSuffix)) {
487           return false;
488         }
489         return true;
490       }
491     };
492 
493     if (failIfWALExists) {
494       final FileStatus[] walFiles = FSUtils.listStatus(fs, fullPathLogDir, ourFiles);
495       if (null != walFiles && 0 != walFiles.length) {
496         throw new IOException("Target WAL already exists within directory " + fullPathLogDir);
497       }
498     }
499 
500     // Register listeners.  TODO: Should this exist anymore?  We have CPs?
501     if (listeners != null) {
502       for (WALActionsListener i: listeners) {
503         registerWALActionsListener(i);
504       }
505     }
506     this.coprocessorHost = new WALCoprocessorHost(this, conf);
507 
508     // Get size to roll log at. Roll at 95% of HDFS block size so we avoid crossing HDFS blocks
509     // (it costs a little x'ing bocks)
510     final long blocksize = this.conf.getLong("hbase.regionserver.hlog.blocksize",
511         FSUtils.getDefaultBlockSize(this.fs, this.fullPathLogDir));
512     this.logrollsize =
513       (long)(blocksize * conf.getFloat("hbase.regionserver.logroll.multiplier", 0.95f));
514 
515     float memstoreRatio = conf.getFloat(HeapMemorySizeUtil.MEMSTORE_SIZE_KEY,
516       conf.getFloat(HeapMemorySizeUtil.MEMSTORE_SIZE_OLD_KEY,
517         HeapMemorySizeUtil.DEFAULT_MEMSTORE_SIZE));
518     boolean maxLogsDefined = conf.get("hbase.regionserver.maxlogs") != null;
519     if(maxLogsDefined){
520       LOG.warn("'hbase.regionserver.maxlogs' was deprecated.");
521     }
522     this.maxLogs = conf.getInt("hbase.regionserver.maxlogs",
523         Math.max(32, calculateMaxLogFiles(memstoreRatio, logrollsize)));
524     this.minTolerableReplication = conf.getInt("hbase.regionserver.hlog.tolerable.lowreplication",
525         FSUtils.getDefaultReplication(fs, this.fullPathLogDir));
526     this.lowReplicationRollLimit =
527       conf.getInt("hbase.regionserver.hlog.lowreplication.rolllimit", 5);
528     this.closeErrorsTolerated = conf.getInt("hbase.regionserver.logroll.errors.tolerated", 0);
529     int maxHandlersCount = conf.getInt(HConstants.REGION_SERVER_HANDLER_COUNT, 200);
530 
531     LOG.info("WAL configuration: blocksize=" + StringUtils.byteDesc(blocksize) +
532       ", rollsize=" + StringUtils.byteDesc(this.logrollsize) +
533       ", prefix=" + this.logFilePrefix + ", suffix=" + logFileSuffix + ", logDir=" +
534       this.fullPathLogDir + ", archiveDir=" + this.fullPathArchiveDir);
535 
536     // rollWriter sets this.hdfs_out if it can.
537     rollWriter();
538 
539     this.slowSyncNs =
540         1000000 * conf.getInt("hbase.regionserver.hlog.slowsync.ms",
541           DEFAULT_SLOW_SYNC_TIME_MS);
542     this.walSyncTimeout = conf.getLong("hbase.regionserver.hlog.sync.timeout",
543         DEFAULT_WAL_SYNC_TIMEOUT_MS);
544 
545     // This is the 'writer' -- a single threaded executor.  This single thread 'consumes' what is
546     // put on the ring buffer.
547     String hostingThreadName = Thread.currentThread().getName();
548     this.appendExecutor = Executors.
549       newSingleThreadExecutor(Threads.getNamedThreadFactory(hostingThreadName + ".append"));
550     // Preallocate objects to use on the ring buffer.  The way that appends and syncs work, we will
551     // be stuck and make no progress if the buffer is filled with appends only and there is no
552     // sync. If no sync, then the handlers will be outstanding just waiting on sync completion
553     // before they return.
554     final int preallocatedEventCount =
555       this.conf.getInt("hbase.regionserver.wal.disruptor.event.count", 1024 * 16);
556     // Using BlockingWaitStrategy.  Stuff that is going on here takes so long it makes no sense
557     // spinning as other strategies do.
558     this.disruptor =
559       new Disruptor<RingBufferTruck>(RingBufferTruck.EVENT_FACTORY, preallocatedEventCount,
560         this.appendExecutor, ProducerType.MULTI, new BlockingWaitStrategy());
561     // Advance the ring buffer sequence so that it starts from 1 instead of 0,
562     // because SyncFuture.NOT_DONE = 0.
563     this.disruptor.getRingBuffer().next();
564     this.ringBufferEventHandler =
565       new RingBufferEventHandler(conf.getInt("hbase.regionserver.hlog.syncer.count", 5),
566         maxHandlersCount);
567     this.disruptor.handleExceptionsWith(new RingBufferExceptionHandler());
568     this.disruptor.handleEventsWith(new RingBufferEventHandler [] {this.ringBufferEventHandler});
569     this.cachedSyncFutures = new ThreadLocal<SyncFuture>() {
570       @Override
571       protected SyncFuture initialValue() {
572         return new SyncFuture();
573       }
574     };
575     // Starting up threads in constructor is a no no; Interface should have an init call.
576     this.disruptor.start();
577   }
578 
579   private int calculateMaxLogFiles(float memstoreSizeRatio, long logRollSize) {
580     long max = -1L;
581     final MemoryUsage usage = HeapMemorySizeUtil.safeGetHeapMemoryUsage();
582     if (usage != null) {
583       max = usage.getMax();
584     }
585     int maxLogs = Math.round(max * memstoreSizeRatio * 2 / logRollSize);
586     return maxLogs;
587   }
588 
589   /**
590    * Get the backing files associated with this WAL.
591    * @return may be null if there are no files.
592    */
593   protected FileStatus[] getFiles() throws IOException {
594     return FSUtils.listStatus(fs, fullPathLogDir, ourFiles);
595   }
596 
597   /**
598    * Currently, we need to expose the writer's OutputStream to tests so that they can manipulate
599    * the default behavior (such as setting the maxRecoveryErrorCount value for example (see
600    * {@link TestWALReplay#testReplayEditsWrittenIntoWAL()}). This is done using reflection on the
601    * underlying HDFS OutputStream.
602    * NOTE: This could be removed once Hadoop1 support is removed.
603    * @return null if underlying stream is not ready.
604    */
605   @VisibleForTesting
606   OutputStream getOutputStream() {
607     FSDataOutputStream fsdos = this.hdfs_out;
608     if (fsdos == null) return null;
609     return fsdos.getWrappedStream();
610   }
611 
612   @Override
613   public byte [][] rollWriter() throws FailedLogCloseException, IOException {
614     return rollWriter(false);
615   }
616 
617   /**
618    * retrieve the next path to use for writing.
619    * Increments the internal filenum.
620    */
621   private Path getNewPath() throws IOException {
622     this.filenum.set(System.currentTimeMillis());
623     Path newPath = getCurrentFileName();
624     while (fs.exists(newPath)) {
625       this.filenum.incrementAndGet();
626       newPath = getCurrentFileName();
627     }
628     return newPath;
629   }
630 
631   Path getOldPath() {
632     long currentFilenum = this.filenum.get();
633     Path oldPath = null;
634     if (currentFilenum > 0) {
635       // ComputeFilename  will take care of meta wal filename
636       oldPath = computeFilename(currentFilenum);
637     } // I presume if currentFilenum is <= 0, this is first file and null for oldPath if fine?
638     return oldPath;
639   }
640 
641   /**
642    * Tell listeners about pre log roll.
643    * @throws IOException
644    */
645   private void tellListenersAboutPreLogRoll(final Path oldPath, final Path newPath)
646   throws IOException {
647     coprocessorHost.preWALRoll(oldPath, newPath);
648 
649     if (!this.listeners.isEmpty()) {
650       for (WALActionsListener i : this.listeners) {
651         i.preLogRoll(oldPath, newPath);
652       }
653     }
654   }
655 
656   /**
657    * Tell listeners about post log roll.
658    * @throws IOException
659    */
660   private void tellListenersAboutPostLogRoll(final Path oldPath, final Path newPath)
661   throws IOException {
662     if (!this.listeners.isEmpty()) {
663       for (WALActionsListener i : this.listeners) {
664         i.postLogRoll(oldPath, newPath);
665       }
666     }
667 
668     coprocessorHost.postWALRoll(oldPath, newPath);
669   }
670 
671   /**
672    * Run a sync after opening to set up the pipeline.
673    * @param nextWriter
674    * @param startTimeNanos
675    */
676   private void preemptiveSync(final ProtobufLogWriter nextWriter) {
677     long startTimeNanos = System.nanoTime();
678     try {
679       nextWriter.sync();
680       postSync(System.nanoTime() - startTimeNanos, 0);
681     } catch (IOException e) {
682       // optimization failed, no need to abort here.
683       LOG.warn("pre-sync failed but an optimization so keep going", e);
684     }
685   }
686 
687   @Override
688   public byte [][] rollWriter(boolean force) throws FailedLogCloseException, IOException {
689     rollWriterLock.lock();
690     try {
691       // Return if nothing to flush.
692       if (!force && (this.writer != null && this.numEntries.get() <= 0)) return null;
693       byte [][] regionsToFlush = null;
694       if (this.closed) {
695         LOG.debug("WAL closed. Skipping rolling of writer");
696         return regionsToFlush;
697       }
698       if (!closeBarrier.beginOp()) {
699         LOG.debug("WAL closing. Skipping rolling of writer");
700         return regionsToFlush;
701       }
702       TraceScope scope = Trace.startSpan("FSHLog.rollWriter");
703       try {
704         Path oldPath = getOldPath();
705         Path newPath = getNewPath();
706         // Any exception from here on is catastrophic, non-recoverable so we currently abort.
707         Writer nextWriter = this.createWriterInstance(newPath);
708         FSDataOutputStream nextHdfsOut = null;
709         if (nextWriter instanceof ProtobufLogWriter) {
710           nextHdfsOut = ((ProtobufLogWriter)nextWriter).getStream();
711           // If a ProtobufLogWriter, go ahead and try and sync to force setup of pipeline.
712           // If this fails, we just keep going.... it is an optimization, not the end of the world.
713           preemptiveSync((ProtobufLogWriter)nextWriter);
714         }
715         tellListenersAboutPreLogRoll(oldPath, newPath);
716         // NewPath could be equal to oldPath if replaceWriter fails.
717         newPath = replaceWriter(oldPath, newPath, nextWriter, nextHdfsOut);
718         tellListenersAboutPostLogRoll(oldPath, newPath);
719         // Can we delete any of the old log files?
720         if (getNumRolledLogFiles() > 0) {
721           cleanOldLogs();
722           regionsToFlush = findRegionsToForceFlush();
723         }
724       } finally {
725         closeBarrier.endOp();
726         assert scope == NullScope.INSTANCE || !scope.isDetached();
727         scope.close();
728       }
729       return regionsToFlush;
730     } finally {
731       rollWriterLock.unlock();
732     }
733   }
734 
735   /**
736    * This method allows subclasses to inject different writers without having to
737    * extend other methods like rollWriter().
738    *
739    * @return Writer instance
740    */
741   protected Writer createWriterInstance(final Path path) throws IOException {
742     return DefaultWALProvider.createWriter(conf, fs, path, false);
743   }
744 
745   /**
746    * Archive old logs. A WAL is eligible for archiving if all its WALEdits have been flushed.
747    * @throws IOException
748    */
749   private void cleanOldLogs() throws IOException {
750     List<Path> logsToArchive = null;
751     // For each log file, look at its Map of regions to highest sequence id; if all sequence ids
752     // are older than what is currently in memory, the WAL can be GC'd.
753     for (Map.Entry<Path, Map<byte[], Long>> e : this.byWalRegionSequenceIds.entrySet()) {
754       Path log = e.getKey();
755       Map<byte[], Long> sequenceNums = e.getValue();
756       if (this.sequenceIdAccounting.areAllLower(sequenceNums)) {
757         if (logsToArchive == null) logsToArchive = new ArrayList<Path>();
758         logsToArchive.add(log);
759         if (LOG.isTraceEnabled()) LOG.trace("WAL file ready for archiving " + log);
760       }
761     }
762     if (logsToArchive != null) {
763       for (Path p : logsToArchive) {
764         this.totalLogSize.addAndGet(-this.fs.getFileStatus(p).getLen());
765         archiveLogFile(p);
766         this.byWalRegionSequenceIds.remove(p);
767       }
768     }
769   }
770 
771   /**
772    * If the number of un-archived WAL files is greater than maximum allowed, check the first
773    * (oldest) WAL file, and returns those regions which should be flushed so that it can
774    * be archived.
775    * @return regions (encodedRegionNames) to flush in order to archive oldest WAL file.
776    * @throws IOException
777    */
778   byte[][] findRegionsToForceFlush() throws IOException {
779     byte [][] regions = null;
780     int logCount = getNumRolledLogFiles();
781     if (logCount > this.maxLogs && logCount > 0) {
782       Map.Entry<Path, Map<byte[], Long>> firstWALEntry =
783         this.byWalRegionSequenceIds.firstEntry();
784       regions = this.sequenceIdAccounting.findLower(firstWALEntry.getValue());
785     }
786     if (regions != null) {
787       StringBuilder sb = new StringBuilder();
788       for (int i = 0; i < regions.length; i++) {
789         if (i > 0) sb.append(", ");
790         sb.append(Bytes.toStringBinary(regions[i]));
791       }
792       LOG.info("Too many WALs; count=" + logCount + ", max=" + this.maxLogs +
793         "; forcing flush of " + regions.length + " regions(s): " + sb.toString());
794     }
795     return regions;
796   }
797 
798   /**
799    * Used to manufacture race condition reliably. For testing only.
800    * @see #beforeWaitOnSafePoint()
801    */
802   @VisibleForTesting
803   protected void afterCreatingZigZagLatch() {}
804 
805   /**
806    * @see #afterCreatingZigZagLatch()
807    */
808   @VisibleForTesting
809   protected void beforeWaitOnSafePoint() {};
810 
811   /**
812    * Cleans up current writer closing it and then puts in place the passed in
813    * <code>nextWriter</code>.
814    *
815    * In the case of creating a new WAL, oldPath will be null.
816    *
817    * In the case of rolling over from one file to the next, none of the params will be null.
818    *
819    * In the case of closing out this FSHLog with no further use newPath, nextWriter, and
820    * nextHdfsOut will be null.
821    *
822    * @param oldPath may be null
823    * @param newPath may be null
824    * @param nextWriter may be null
825    * @param nextHdfsOut may be null
826    * @return the passed in <code>newPath</code>
827    * @throws IOException if there is a problem flushing or closing the underlying FS
828    */
829   Path replaceWriter(final Path oldPath, final Path newPath, Writer nextWriter,
830       final FSDataOutputStream nextHdfsOut)
831   throws IOException {
832     // Ask the ring buffer writer to pause at a safe point.  Once we do this, the writer
833     // thread will eventually pause. An error hereafter needs to release the writer thread
834     // regardless -- hence the finally block below.  Note, this method is called from the FSHLog
835     // constructor BEFORE the ring buffer is set running so it is null on first time through
836     // here; allow for that.
837     SyncFuture syncFuture = null;
838     SafePointZigZagLatch zigzagLatch = null;
839     long sequence = -1L;
840     if (this.ringBufferEventHandler != null) {
841       // Get sequence first to avoid dead lock when ring buffer is full
842       // Considering below sequence
843       // 1. replaceWriter is called and zigzagLatch is initialized
844       // 2. ringBufferEventHandler#onEvent is called and arrives at #attainSafePoint(long) then wait
845       // on safePointReleasedLatch
846       // 3. Since ring buffer is full, if we get sequence when publish sync, the replaceWriter
847       // thread will wait for the ring buffer to be consumed, but the only consumer is waiting
848       // replaceWriter thread to release safePointReleasedLatch, which causes a deadlock
849       sequence = getSequenceOnRingBuffer();
850       zigzagLatch = this.ringBufferEventHandler.attainSafePoint();
851     }
852     afterCreatingZigZagLatch();
853     TraceScope scope = Trace.startSpan("FSHFile.replaceWriter");
854     try {
855       // Wait on the safe point to be achieved.  Send in a sync in case nothing has hit the
856       // ring buffer between the above notification of writer that we want it to go to
857       // 'safe point' and then here where we are waiting on it to attain safe point.  Use
858       // 'sendSync' instead of 'sync' because we do not want this thread to block waiting on it
859       // to come back.  Cleanup this syncFuture down below after we are ready to run again.
860       try {
861         if (zigzagLatch != null) {
862           // use assert to make sure no change breaks the logic that
863           // sequence and zigzagLatch will be set together
864           assert sequence > 0L : "Failed to get sequence from ring buffer";
865           Trace.addTimelineAnnotation("awaiting safepoint");
866           syncFuture = zigzagLatch.waitSafePoint(publishSyncOnRingBuffer(sequence));
867         }
868       } catch (FailedSyncBeforeLogCloseException e) {
869         // If unflushed/unsynced entries on close, it is reason to abort.
870         if (isUnflushedEntries()) throw e;
871         LOG.warn("Failed sync-before-close but no outstanding appends; closing WAL: " +
872           e.getMessage());
873       }
874 
875       // It is at the safe point.  Swap out writer from under the blocked writer thread.
876       // TODO: This is close is inline with critical section.  Should happen in background?
877       try {
878         if (this.writer != null) {
879           Trace.addTimelineAnnotation("closing writer");
880           this.writer.close();
881           Trace.addTimelineAnnotation("writer closed");
882         }
883         this.closeErrorCount.set(0);
884       } catch (IOException ioe) {
885         int errors = closeErrorCount.incrementAndGet();
886         if (!isUnflushedEntries() && (errors <= this.closeErrorsTolerated)) {
887           LOG.warn("Riding over failed WAL close of " + oldPath + ", cause=\"" +
888             ioe.getMessage() + "\", errors=" + errors +
889             "; THIS FILE WAS NOT CLOSED BUT ALL EDITS SYNCED SO SHOULD BE OK");
890         } else {
891           throw ioe;
892         }
893       }
894       this.writer = nextWriter;
895       this.hdfs_out = nextHdfsOut;
896       int oldNumEntries = this.numEntries.get();
897       this.numEntries.set(0);
898       final String newPathString = (null == newPath ? null : FSUtils.getPath(newPath));
899       if (oldPath != null) {
900         this.byWalRegionSequenceIds.put(oldPath, this.sequenceIdAccounting.resetHighest());
901         long oldFileLen = this.fs.getFileStatus(oldPath).getLen();
902         this.totalLogSize.addAndGet(oldFileLen);
903         LOG.info("Rolled WAL " + FSUtils.getPath(oldPath) + " with entries=" + oldNumEntries +
904           ", filesize=" + StringUtils.byteDesc(oldFileLen) + "; new WAL " +
905           newPathString);
906       } else {
907         LOG.info("New WAL " + newPathString);
908       }
909     } catch (InterruptedException ie) {
910       // Perpetuate the interrupt
911       Thread.currentThread().interrupt();
912     } catch (IOException e) {
913       long count = getUnflushedEntriesCount();
914       LOG.error("Failed close of WAL writer " + oldPath + ", unflushedEntries=" + count, e);
915       throw new FailedLogCloseException(oldPath + ", unflushedEntries=" + count, e);
916     } finally {
917       try {
918         // Let the writer thread go regardless, whether error or not.
919         if (zigzagLatch != null) {
920           zigzagLatch.releaseSafePoint();
921           // syncFuture will be null if we failed our wait on safe point above. Otherwise, if
922           // latch was obtained successfully, the sync we threw in either trigger the latch or it
923           // got stamped with an exception because the WAL was damaged and we could not sync. Now
924           // the write pipeline has been opened up again by releasing the safe point, process the
925           // syncFuture we got above. This is probably a noop but it may be stale exception from
926           // when old WAL was in place. Catch it if so.
927           if (syncFuture != null) {
928             try {
929               blockOnSync(syncFuture);
930             } catch (IOException ioe) {
931               if (LOG.isTraceEnabled()) LOG.trace("Stale sync exception", ioe);
932             }
933           }
934         }
935       } finally {
936         scope.close();
937       }
938     }
939     return newPath;
940   }
941 
942   long getUnflushedEntriesCount() {
943     long highestSynced = this.highestSyncedSequence.get();
944     return highestSynced > this.highestUnsyncedSequence?
945       0: this.highestUnsyncedSequence - highestSynced;
946   }
947 
948   boolean isUnflushedEntries() {
949     return getUnflushedEntriesCount() > 0;
950   }
951 
952   /*
953    * only public so WALSplitter can use.
954    * @return archived location of a WAL file with the given path p
955    */
956   public static Path getWALArchivePath(Path archiveDir, Path p) {
957     return new Path(archiveDir, p.getName());
958   }
959 
960   private void archiveLogFile(final Path p) throws IOException {
961     Path newPath = getWALArchivePath(this.fullPathArchiveDir, p);
962     // Tell our listeners that a log is going to be archived.
963     if (!this.listeners.isEmpty()) {
964       for (WALActionsListener i : this.listeners) {
965         i.preLogArchive(p, newPath);
966       }
967     }
968     LOG.info("Archiving " + p + " to " + newPath);
969     if (!FSUtils.renameAndSetModifyTime(this.fs, p, newPath)) {
970       throw new IOException("Unable to rename " + p + " to " + newPath);
971     }
972     // Tell our listeners that a log has been archived.
973     if (!this.listeners.isEmpty()) {
974       for (WALActionsListener i : this.listeners) {
975         i.postLogArchive(p, newPath);
976       }
977     }
978   }
979 
980   /**
981    * This is a convenience method that computes a new filename with a given
982    * file-number.
983    * @param filenum to use
984    * @return Path
985    */
986   protected Path computeFilename(final long filenum) {
987     if (filenum < 0) {
988       throw new RuntimeException("WAL file number can't be < 0");
989     }
990     String child = logFilePrefix + WAL_FILE_NAME_DELIMITER + filenum + logFileSuffix;
991     return new Path(fullPathLogDir, child);
992   }
993 
994   /**
995    * This is a convenience method that computes a new filename with a given
996    * using the current WAL file-number
997    * @return Path
998    */
999   public Path getCurrentFileName() {
1000     return computeFilename(this.filenum.get());
1001   }
1002 
1003   /**
1004    * @return current file number (timestamp)
1005    */
1006   public long getFilenum() {
1007     return filenum.get();
1008   }
1009   
1010   @Override
1011   public String toString() {
1012     return "FSHLog " + logFilePrefix + ":" + logFileSuffix + "(num " + filenum + ")";
1013   }
1014 
1015 /**
1016  * A log file has a creation timestamp (in ms) in its file name ({@link #filenum}.
1017  * This helper method returns the creation timestamp from a given log file.
1018  * It extracts the timestamp assuming the filename is created with the
1019  * {@link #computeFilename(long filenum)} method.
1020  * @param fileName
1021  * @return timestamp, as in the log file name.
1022  */
1023   protected long getFileNumFromFileName(Path fileName) {
1024     if (fileName == null) throw new IllegalArgumentException("file name can't be null");
1025     if (!ourFiles.accept(fileName)) {
1026       throw new IllegalArgumentException("The log file " + fileName +
1027           " doesn't belong to this WAL. (" + toString() + ")");
1028     }
1029     final String fileNameString = fileName.toString();
1030     String chompedPath = fileNameString.substring(prefixPathStr.length(),
1031         (fileNameString.length() - logFileSuffix.length()));
1032     return Long.parseLong(chompedPath);
1033   }
1034 
1035   @Override
1036   public void close() throws IOException {
1037     shutdown();
1038     final FileStatus[] files = getFiles();
1039     if (null != files && 0 != files.length) {
1040       for (FileStatus file : files) {
1041         Path p = getWALArchivePath(this.fullPathArchiveDir, file.getPath());
1042         // Tell our listeners that a log is going to be archived.
1043         if (!this.listeners.isEmpty()) {
1044           for (WALActionsListener i : this.listeners) {
1045             i.preLogArchive(file.getPath(), p);
1046           }
1047         }
1048 
1049         if (!FSUtils.renameAndSetModifyTime(fs, file.getPath(), p)) {
1050           throw new IOException("Unable to rename " + file.getPath() + " to " + p);
1051         }
1052         // Tell our listeners that a log was archived.
1053         if (!this.listeners.isEmpty()) {
1054           for (WALActionsListener i : this.listeners) {
1055             i.postLogArchive(file.getPath(), p);
1056           }
1057         }
1058       }
1059       LOG.debug("Moved " + files.length + " WAL file(s) to " +
1060         FSUtils.getPath(this.fullPathArchiveDir));
1061     }
1062     LOG.info("Closed WAL: " + toString());
1063   }
1064 
1065   @Override
1066   public void shutdown() throws IOException {
1067     if (shutdown.compareAndSet(false, true)) {
1068       try {
1069         // Prevent all further flushing and rolling.
1070         closeBarrier.stopAndDrainOps();
1071       } catch (InterruptedException e) {
1072         LOG.error("Exception while waiting for cache flushes and log rolls", e);
1073         Thread.currentThread().interrupt();
1074       }
1075 
1076       // Shutdown the disruptor.  Will stop after all entries have been processed.  Make sure we
1077       // have stopped incoming appends before calling this else it will not shutdown.  We are
1078       // conservative below waiting a long time and if not elapsed, then halting.
1079       if (this.disruptor != null) {
1080         long timeoutms = conf.getLong("hbase.wal.disruptor.shutdown.timeout.ms", 60000);
1081         try {
1082           this.disruptor.shutdown(timeoutms, TimeUnit.MILLISECONDS);
1083         } catch (TimeoutException e) {
1084           LOG.warn("Timed out bringing down disruptor after " + timeoutms + "ms; forcing halt " +
1085             "(It is a problem if this is NOT an ABORT! -- DATALOSS!!!!)");
1086           this.disruptor.halt();
1087           this.disruptor.shutdown();
1088         }
1089       }
1090       // With disruptor down, this is safe to let go.
1091       if (this.appendExecutor !=  null) this.appendExecutor.shutdown();
1092 
1093       // Tell our listeners that the log is closing
1094       if (!this.listeners.isEmpty()) {
1095         for (WALActionsListener i : this.listeners) {
1096           i.logCloseRequested();
1097         }
1098       }
1099       this.closed = true;
1100       if (LOG.isDebugEnabled()) {
1101         LOG.debug("Closing WAL writer in " + FSUtils.getPath(fullPathLogDir));
1102       }
1103       if (this.writer != null) {
1104         this.writer.close();
1105         this.writer = null;
1106       }
1107     }
1108   }
1109 
1110   @edu.umd.cs.findbugs.annotations.SuppressWarnings(value="NP_NULL_ON_SOME_PATH_EXCEPTION",
1111       justification="Will never be null")
1112   @Override
1113   public long append(final HTableDescriptor htd, final HRegionInfo hri, final WALKey key,
1114       final WALEdit edits, final boolean inMemstore) throws IOException {
1115     if (this.closed) throw new IOException("Cannot append; log is closed");
1116     // Make a trace scope for the append.  It is closed on other side of the ring buffer by the
1117     // single consuming thread.  Don't have to worry about it.
1118     TraceScope scope = Trace.startSpan("FSHLog.append");
1119     final MutableLong txidHolder = new MutableLong();
1120     final RingBuffer<RingBufferTruck> ringBuffer = disruptor.getRingBuffer();
1121     MultiVersionConcurrencyControl.WriteEntry we = key.getMvcc().begin(new Runnable() {
1122       @Override public void run() {
1123         txidHolder.setValue(ringBuffer.next());
1124       }
1125     });
1126     long txid = txidHolder.longValue();
1127     try {
1128       FSWALEntry entry = new FSWALEntry(txid, key, edits, htd, hri, inMemstore);
1129       entry.stampRegionSequenceId(we);
1130       ringBuffer.get(txid).loadPayload(entry, scope.detach());
1131     } finally {
1132       ringBuffer.publish(txid);
1133     }
1134     return txid;
1135   }
1136 
1137   /**
1138    * Thread to runs the hdfs sync call. This call takes a while to complete.  This is the longest
1139    * pole adding edits to the WAL and this must complete to be sure all edits persisted.  We run
1140    * multiple threads sync'ng rather than one that just syncs in series so we have better
1141    * latencies; otherwise, an edit that arrived just after a sync started, might have to wait
1142    * almost the length of two sync invocations before it is marked done.
1143    * <p>When the sync completes, it marks all the passed in futures done.  On the other end of the
1144    * sync future is a blocked thread, usually a regionserver Handler.  There may be more than one
1145    * future passed in the case where a few threads arrive at about the same time and all invoke
1146    * 'sync'.  In this case we'll batch up the invocations and run one filesystem sync only for a
1147    * batch of Handler sync invocations.  Do not confuse these Handler SyncFutures with the futures
1148    * an ExecutorService returns when you call submit. We have no use for these in this model. These
1149    * SyncFutures are 'artificial', something to hold the Handler until the filesystem sync
1150    * completes.
1151    */
1152   private class SyncRunner extends HasThread {
1153     private volatile long sequence;
1154     // Keep around last exception thrown. Clear on successful sync.
1155     private final BlockingQueue<SyncFuture> syncFutures;
1156     private volatile SyncFuture takeSyncFuture = null;
1157 
1158     /**
1159      * UPDATE!
1160      * @param syncs the batch of calls to sync that arrived as this thread was starting; when done,
1161      * we will put the result of the actual hdfs sync call as the result.
1162      * @param sequence The sequence number on the ring buffer when this thread was set running.
1163      * If this actual writer sync completes then all appends up this point have been
1164      * flushed/synced/pushed to datanodes.  If we fail, then the passed in <code>syncs</code>
1165      * futures will return the exception to their clients; some of the edits may have made it out
1166      * to data nodes but we will report all that were part of this session as failed.
1167      */
1168     SyncRunner(final String name, final int maxHandlersCount) {
1169       super(name);
1170       // LinkedBlockingQueue because of
1171       // http://www.javacodegeeks.com/2010/09/java-best-practices-queue-battle-and.html
1172       // Could use other blockingqueues here or concurrent queues.
1173       //
1174       // We could let the capacity be 'open' but bound it so we get alerted in pathological case
1175       // where we cannot sync and we have a bunch of threads all backed up waiting on their syncs
1176       // to come in.  LinkedBlockingQueue actually shrinks when you remove elements so Q should
1177       // stay neat and tidy in usual case.  Let the max size be three times the maximum handlers.
1178       // The passed in maxHandlerCount is the user-level handlers which is what we put up most of
1179       // but HBase has other handlers running too -- opening region handlers which want to write
1180       // the meta table when succesful (i.e. sync), closing handlers -- etc.  These are usually
1181       // much fewer in number than the user-space handlers so Q-size should be user handlers plus
1182       // some space for these other handlers.  Lets multiply by 3 for good-measure.
1183       this.syncFutures = new LinkedBlockingQueue<SyncFuture>(maxHandlersCount * 3);
1184     }
1185 
1186     void offer(final long sequence, final SyncFuture [] syncFutures, final int syncFutureCount) {
1187       // Set sequence first because the add to the queue will wake the thread if sleeping.
1188       this.sequence = sequence;
1189       for (int i = 0; i < syncFutureCount; ++i) {
1190         this.syncFutures.add(syncFutures[i]);
1191       }
1192     }
1193 
1194     /**
1195      * Release the passed <code>syncFuture</code>
1196      * @param syncFuture
1197      * @param currentSequence
1198      * @param t
1199      * @return Returns 1.
1200      */
1201     private int releaseSyncFuture(final SyncFuture syncFuture, final long currentSequence,
1202         final Throwable t) {
1203       if (!syncFuture.done(currentSequence, t)) throw new IllegalStateException();
1204       // This function releases one sync future only.
1205       return 1;
1206     }
1207 
1208     /**
1209      * Release all SyncFutures whose sequence is <= <code>currentSequence</code>.
1210      * @param currentSequence
1211      * @param t May be non-null if we are processing SyncFutures because an exception was thrown.
1212      * @return Count of SyncFutures we let go.
1213      */
1214     private int releaseSyncFutures(final long currentSequence, final Throwable t) {
1215       int syncCount = 0;
1216       for (SyncFuture syncFuture; (syncFuture = this.syncFutures.peek()) != null;) {
1217         if (syncFuture.getRingBufferSequence() > currentSequence) break;
1218         releaseSyncFuture(syncFuture, currentSequence, t);
1219         if (!this.syncFutures.remove(syncFuture)) {
1220           throw new IllegalStateException(syncFuture.toString());
1221         }
1222         syncCount++;
1223       }
1224       return syncCount;
1225     }
1226 
1227     /**
1228      * @param sequence The sequence we ran the filesystem sync against.
1229      * @return Current highest synced sequence.
1230      */
1231     private long updateHighestSyncedSequence(long sequence) {
1232       long currentHighestSyncedSequence;
1233       // Set the highestSyncedSequence IFF our current sequence id is the 'highest'.
1234       do {
1235         currentHighestSyncedSequence = highestSyncedSequence.get();
1236         if (currentHighestSyncedSequence >= sequence) {
1237           // Set the sync number to current highwater mark; might be able to let go more
1238           // queued sync futures
1239           sequence = currentHighestSyncedSequence;
1240           break;
1241         }
1242       } while (!highestSyncedSequence.compareAndSet(currentHighestSyncedSequence, sequence));
1243       return sequence;
1244     }
1245 
1246     boolean areSyncFuturesReleased() {
1247       // check whether there is no sync futures offered, and no in-flight sync futures that is being
1248       // processed.
1249       return syncFutures.size() <= 0
1250           && takeSyncFuture == null;
1251     }
1252 
1253     @Override
1254     public void run() {
1255       long currentSequence;
1256       while (!isInterrupted()) {
1257         int syncCount = 0;
1258 
1259         try {
1260           while (true) {
1261             takeSyncFuture = null;
1262             // We have to process what we 'take' from the queue
1263             takeSyncFuture = this.syncFutures.take();
1264             currentSequence = this.sequence;
1265             long syncFutureSequence = takeSyncFuture.getRingBufferSequence();
1266             if (syncFutureSequence > currentSequence) {
1267               throw new IllegalStateException("currentSequence=" + currentSequence +
1268                 ", syncFutureSequence=" + syncFutureSequence);
1269             }
1270             // See if we can process any syncfutures BEFORE we go sync.
1271             long currentHighestSyncedSequence = highestSyncedSequence.get();
1272             if (currentSequence < currentHighestSyncedSequence) {
1273               syncCount += releaseSyncFuture(takeSyncFuture, currentHighestSyncedSequence, null);
1274               // Done with the 'take'.  Go around again and do a new 'take'.
1275               continue;
1276             }
1277             break;
1278           }
1279           // I got something.  Lets run.  Save off current sequence number in case it changes
1280           // while we run.
1281           TraceScope scope = Trace.continueSpan(takeSyncFuture.getSpan());
1282           long start = System.nanoTime();
1283           Throwable lastException = null;
1284           try {
1285             Trace.addTimelineAnnotation("syncing writer");
1286             writer.sync();
1287             Trace.addTimelineAnnotation("writer synced");
1288             currentSequence = updateHighestSyncedSequence(currentSequence);
1289           } catch (IOException e) {
1290             LOG.error("Error syncing, request close of WAL", e);
1291             lastException = e;
1292           } catch (Exception e) {
1293             LOG.warn("UNEXPECTED", e);
1294             lastException = e;
1295           } finally {
1296             // reattach the span to the future before releasing.
1297             takeSyncFuture.setSpan(scope.detach());
1298             // First release what we 'took' from the queue.
1299             syncCount += releaseSyncFuture(takeSyncFuture, currentSequence, lastException);
1300             // Can we release other syncs?
1301             syncCount += releaseSyncFutures(currentSequence, lastException);
1302             if (lastException != null) requestLogRoll();
1303             else checkLogRoll();
1304           }
1305           postSync(System.nanoTime() - start, syncCount);
1306         } catch (InterruptedException e) {
1307           // Presume legit interrupt.
1308           Thread.currentThread().interrupt();
1309         } catch (Throwable t) {
1310           LOG.warn("UNEXPECTED, continuing", t);
1311         }
1312       }
1313     }
1314   }
1315 
1316   /**
1317    * Schedule a log roll if needed.
1318    */
1319   public void checkLogRoll() {
1320     // Will return immediately if we are in the middle of a WAL log roll currently.
1321     if (!rollWriterLock.tryLock()) return;
1322     boolean lowReplication;
1323     try {
1324       lowReplication = checkLowReplication();
1325     } finally {
1326       rollWriterLock.unlock();
1327     }
1328     try {
1329       if (lowReplication || (writer != null && writer.getLength() > logrollsize)) {
1330         requestLogRoll(lowReplication);
1331       }
1332     } catch (IOException e) {
1333       LOG.warn("Writer.getLength() failed; continuing", e);
1334     }
1335   }
1336 
1337   /*
1338    * @return true if number of replicas for the WAL is lower than threshold
1339    */
1340   private boolean checkLowReplication() {
1341     boolean logRollNeeded = false;
1342     this.lastTimeCheckLowReplication = EnvironmentEdgeManager.currentTime();
1343     // if the number of replicas in HDFS has fallen below the configured
1344     // value, then roll logs.
1345     try {
1346       int numCurrentReplicas = getLogReplication();
1347       if (numCurrentReplicas != 0 && numCurrentReplicas < this.minTolerableReplication) {
1348         if (this.lowReplicationRollEnabled) {
1349           if (this.consecutiveLogRolls.get() < this.lowReplicationRollLimit) {
1350             LOG.warn("HDFS pipeline error detected. " + "Found "
1351                 + numCurrentReplicas + " replicas but expecting no less than "
1352                 + this.minTolerableReplication + " replicas. "
1353                 + " Requesting close of WAL. current pipeline: "
1354                 + Arrays.toString(getPipeLine()));
1355             logRollNeeded = true;
1356             // If rollWriter is requested, increase consecutiveLogRolls. Once it
1357             // is larger than lowReplicationRollLimit, disable the
1358             // LowReplication-Roller
1359             this.consecutiveLogRolls.getAndIncrement();
1360           } else {
1361             LOG.warn("Too many consecutive RollWriter requests, it's a sign of "
1362                 + "the total number of live datanodes is lower than the tolerable replicas.");
1363             this.consecutiveLogRolls.set(0);
1364             this.lowReplicationRollEnabled = false;
1365           }
1366         }
1367       } else if (numCurrentReplicas >= this.minTolerableReplication) {
1368         if (!this.lowReplicationRollEnabled) {
1369           // The new writer's log replicas is always the default value.
1370           // So we should not enable LowReplication-Roller. If numEntries
1371           // is lower than or equals 1, we consider it as a new writer.
1372           if (this.numEntries.get() <= 1) {
1373             return logRollNeeded;
1374           }
1375           // Once the live datanode number and the replicas return to normal,
1376           // enable the LowReplication-Roller.
1377           this.lowReplicationRollEnabled = true;
1378           LOG.info("LowReplication-Roller was enabled.");
1379         }
1380       }
1381     } catch (Exception e) {
1382       LOG.warn("DFSOutputStream.getNumCurrentReplicas failed because of " + e +
1383         ", continuing...");
1384     }
1385     return logRollNeeded;
1386   }
1387 
1388   private SyncFuture publishSyncOnRingBuffer(long sequence) {
1389     return publishSyncOnRingBuffer(sequence, null);
1390   }
1391 
1392   private long getSequenceOnRingBuffer() {
1393     return this.disruptor.getRingBuffer().next();
1394   }
1395 
1396   private SyncFuture publishSyncOnRingBuffer(Span span) {
1397     long sequence = this.disruptor.getRingBuffer().next();
1398     return publishSyncOnRingBuffer(sequence, span);
1399   }
1400 
1401   private SyncFuture publishSyncOnRingBuffer(long sequence, Span span) {
1402     SyncFuture syncFuture = getSyncFuture(sequence, span);
1403     try {
1404       RingBufferTruck truck = this.disruptor.getRingBuffer().get(sequence);
1405       truck.loadPayload(syncFuture);
1406     } finally {
1407       this.disruptor.getRingBuffer().publish(sequence);
1408     }
1409     return syncFuture;
1410   }
1411 
1412   // Sync all known transactions
1413   private Span publishSyncThenBlockOnCompletion(Span span) throws IOException {
1414     return blockOnSync(publishSyncOnRingBuffer(span));
1415   }
1416 
1417   private Span blockOnSync(final SyncFuture syncFuture) throws IOException {
1418     // Now we have published the ringbuffer, halt the current thread until we get an answer back.
1419     try {
1420       syncFuture.get(walSyncTimeout);
1421       return syncFuture.getSpan();
1422     } catch (TimeoutIOException tioe) {
1423       // SyncFuture reuse by thread, if TimeoutIOException happens, ringbuffer
1424       // still refer to it, so if this thread use it next time may get a wrong
1425       // result.
1426       this.cachedSyncFutures.remove();
1427       throw tioe;
1428     } catch (InterruptedException ie) {
1429       LOG.warn("Interrupted", ie);
1430       throw convertInterruptedExceptionToIOException(ie);
1431     } catch (ExecutionException e) {
1432       throw ensureIOException(e.getCause());
1433     }
1434   }
1435 
1436   private IOException convertInterruptedExceptionToIOException(final InterruptedException ie) {
1437     Thread.currentThread().interrupt();
1438     IOException ioe = new InterruptedIOException();
1439     ioe.initCause(ie);
1440     return ioe;
1441   }
1442 
1443   private SyncFuture getSyncFuture(final long sequence, Span span) {
1444     return cachedSyncFutures.get().reset(sequence);
1445   }
1446 
1447   private void postSync(final long timeInNanos, final int handlerSyncs) {
1448     if (timeInNanos > this.slowSyncNs) {
1449       String msg =
1450           new StringBuilder().append("Slow sync cost: ")
1451               .append(timeInNanos / 1000000).append(" ms, current pipeline: ")
1452               .append(Arrays.toString(getPipeLine())).toString();
1453       Trace.addTimelineAnnotation(msg);
1454       LOG.info(msg);
1455     }
1456     if (!listeners.isEmpty()) {
1457       for (WALActionsListener listener : listeners) {
1458         listener.postSync(timeInNanos, handlerSyncs);
1459       }
1460     }
1461   }
1462 
1463   private long postAppend(final Entry e, final long elapsedTime) throws IOException {
1464     long len = 0;
1465     if (!listeners.isEmpty()) {
1466       for (Cell cell : e.getEdit().getCells()) {
1467         len += CellUtil.estimatedSerializedSizeOf(cell);
1468       }
1469       for (WALActionsListener listener : listeners) {
1470         listener.postAppend(len, elapsedTime, e.getKey(), e.getEdit());
1471       }
1472     }
1473     return len;
1474   }
1475 
1476 
1477   /**
1478    * This method gets the datanode replication count for the current WAL.
1479    *
1480    * If the pipeline isn't started yet or is empty, you will get the default
1481    * replication factor.  Therefore, if this function returns 0, it means you
1482    * are not properly running with the HDFS-826 patch.
1483    * @throws InvocationTargetException
1484    * @throws IllegalAccessException
1485    * @throws IllegalArgumentException
1486    *
1487    * @throws Exception
1488    */
1489   @VisibleForTesting
1490   int getLogReplication() {
1491     try {
1492       //in standalone mode, it will return 0
1493       if (this.hdfs_out instanceof HdfsDataOutputStream) {
1494         return ((HdfsDataOutputStream) this.hdfs_out).getCurrentBlockReplication();
1495       }
1496     } catch (IOException e) {
1497       LOG.info("", e);
1498     }
1499     return 0;
1500   }
1501 
1502   @Override
1503   public void sync() throws IOException {
1504     TraceScope scope = Trace.startSpan("FSHLog.sync");
1505     try {
1506       scope = Trace.continueSpan(publishSyncThenBlockOnCompletion(scope.detach()));
1507     } finally {
1508       assert scope == NullScope.INSTANCE || !scope.isDetached();
1509       scope.close();
1510     }
1511   }
1512 
1513   @Override
1514   public void sync(long txid) throws IOException {
1515     if (this.highestSyncedSequence.get() >= txid){
1516       // Already sync'd.
1517       return;
1518     }
1519     TraceScope scope = Trace.startSpan("FSHLog.sync");
1520     try {
1521       scope = Trace.continueSpan(publishSyncThenBlockOnCompletion(scope.detach()));
1522     } finally {
1523       assert scope == NullScope.INSTANCE || !scope.isDetached();
1524       scope.close();
1525     }
1526   }
1527 
1528   // public only until class moves to o.a.h.h.wal
1529   public void requestLogRoll() {
1530     requestLogRoll(false);
1531   }
1532 
1533   private void requestLogRoll(boolean tooFewReplicas) {
1534     if (!this.listeners.isEmpty()) {
1535       for (WALActionsListener i: this.listeners) {
1536         i.logRollRequested(tooFewReplicas);
1537       }
1538     }
1539   }
1540 
1541   // public only until class moves to o.a.h.h.wal
1542   /** @return the number of rolled log files */
1543   public int getNumRolledLogFiles() {
1544     return byWalRegionSequenceIds.size();
1545   }
1546 
1547   // public only until class moves to o.a.h.h.wal
1548   /** @return the number of log files in use */
1549   public int getNumLogFiles() {
1550     // +1 for current use log
1551     return getNumRolledLogFiles() + 1;
1552   }
1553 
1554   // public only until class moves to o.a.h.h.wal
1555   /** @return the size of log files in use */
1556   public long getLogFileSize() {
1557     return this.totalLogSize.get();
1558   }
1559 
1560   @Override
1561   public Long startCacheFlush(final byte[] encodedRegionName, Set<byte[]> families) {
1562     if (!closeBarrier.beginOp()) {
1563       LOG.info("Flush not started for " + Bytes.toString(encodedRegionName) + "; server closing.");
1564       return null;
1565     }
1566     return this.sequenceIdAccounting.startCacheFlush(encodedRegionName, families);
1567   }
1568 
1569   @Override
1570   public void completeCacheFlush(final byte [] encodedRegionName) {
1571     this.sequenceIdAccounting.completeCacheFlush(encodedRegionName);
1572     closeBarrier.endOp();
1573   }
1574 
1575   @Override
1576   public void abortCacheFlush(byte[] encodedRegionName) {
1577     this.sequenceIdAccounting.abortCacheFlush(encodedRegionName);
1578     closeBarrier.endOp();
1579   }
1580 
1581   @VisibleForTesting
1582   boolean isLowReplicationRollEnabled() {
1583       return lowReplicationRollEnabled;
1584   }
1585 
1586   public static final long FIXED_OVERHEAD = ClassSize.align(
1587     ClassSize.OBJECT + (5 * ClassSize.REFERENCE) +
1588     ClassSize.ATOMIC_INTEGER + Bytes.SIZEOF_INT + (3 * Bytes.SIZEOF_LONG));
1589 
1590 
1591   private static void split(final Configuration conf, final Path p) throws IOException {
1592     FileSystem fs = FSUtils.getWALFileSystem(conf);
1593     if (!fs.exists(p)) {
1594       throw new FileNotFoundException(p.toString());
1595     }
1596     if (!fs.getFileStatus(p).isDirectory()) {
1597       throw new IOException(p + " is not a directory");
1598     }
1599 
1600     final Path baseDir = FSUtils.getWALRootDir(conf);
1601     final Path archiveDir = new Path(baseDir, HConstants.HREGION_OLDLOGDIR_NAME);
1602     WALSplitter.split(baseDir, p, archiveDir, fs, conf, WALFactory.getInstance(conf));
1603   }
1604 
1605 
1606   @Override
1607   public long getEarliestMemstoreSeqNum(byte[] encodedRegionName) {
1608     // Used by tests. Deprecated as too subtle for general usage.
1609     return this.sequenceIdAccounting.getLowestSequenceId(encodedRegionName);
1610   }
1611 
1612   @Override
1613   public long getEarliestMemstoreSeqNum(byte[] encodedRegionName, byte[] familyName) {
1614     // This method is used by tests and for figuring if we should flush or not because our
1615     // sequenceids are too old. It is also used reporting the master our oldest sequenceid for use
1616     // figuring what edits can be skipped during log recovery. getEarliestMemStoreSequenceId
1617     // from this.sequenceIdAccounting is looking first in flushingOldestStoreSequenceIds, the
1618     // currently flushing sequence ids, and if anything found there, it is returning these. This is
1619     // the right thing to do for the reporting oldest sequenceids to master; we won't skip edits if
1620     // we crash during the flush. For figuring what to flush, we might get requeued if our sequence
1621     // id is old even though we are currently flushing. This may mean we do too much flushing.
1622     return this.sequenceIdAccounting.getLowestSequenceId(encodedRegionName, familyName);
1623   }
1624 
1625   /**
1626    * This class is used coordinating two threads holding one thread at a
1627    * 'safe point' while the orchestrating thread does some work that requires the first thread
1628    * paused: e.g. holding the WAL writer while its WAL is swapped out from under it by another
1629    * thread.
1630    *
1631    * <p>Thread A signals Thread B to hold when it gets to a 'safe point'.  Thread A wait until
1632    * Thread B gets there. When the 'safe point' has been attained, Thread B signals Thread A.
1633    * Thread B then holds at the 'safe point'.  Thread A on notification that Thread B is paused,
1634    * goes ahead and does the work it needs to do while Thread B is holding.  When Thread A is done,
1635    * it flags B and then Thread A and Thread B continue along on their merry way.  Pause and
1636    * signalling 'zigzags' between the two participating threads.  We use two latches -- one the
1637    * inverse of the other -- pausing and signaling when states are achieved.
1638    *
1639    * <p>To start up the drama, Thread A creates an instance of this class each time it would do
1640    * this zigzag dance and passes it to Thread B (these classes use Latches so it is one shot
1641    * only). Thread B notices the new instance (via reading a volatile reference or how ever) and it
1642    * starts to work toward the 'safe point'.  Thread A calls {@link #waitSafePoint()} when it
1643    * cannot proceed until the Thread B 'safe point' is attained. Thread A will be held inside in
1644    * {@link #waitSafePoint()} until Thread B reaches the 'safe point'.  Once there, Thread B
1645    * frees Thread A by calling {@link #safePointAttained()}.  Thread A now knows Thread B
1646    * is at the 'safe point' and that it is holding there (When Thread B calls
1647    * {@link #safePointAttained()} it blocks here until Thread A calls {@link #releaseSafePoint()}).
1648    * Thread A proceeds to do what it needs to do while Thread B is paused.  When finished,
1649    * it lets Thread B lose by calling {@link #releaseSafePoint()} and away go both Threads again.
1650    */
1651   static class SafePointZigZagLatch {
1652     /**
1653      * Count down this latch when safe point attained.
1654      */
1655     private volatile CountDownLatch safePointAttainedLatch = new CountDownLatch(1);
1656     /**
1657      * Latch to wait on.  Will be released when we can proceed.
1658      */
1659     private volatile CountDownLatch safePointReleasedLatch = new CountDownLatch(1);
1660 
1661     private void checkIfSyncFailed(SyncFuture syncFuture) throws FailedSyncBeforeLogCloseException {
1662       if (syncFuture.isThrowable()) {
1663         throw new FailedSyncBeforeLogCloseException(syncFuture.getThrowable());
1664       }
1665     }
1666 
1667     /**
1668      * For Thread A to call when it is ready to wait on the 'safe point' to be attained.
1669      * Thread A will be held in here until Thread B calls {@link #safePointAttained()}
1670      * @param syncFuture We need this as barometer on outstanding syncs.  If it comes home with
1671      * an exception, then something is up w/ our syncing.
1672      * @throws InterruptedException
1673      * @throws ExecutionException
1674      * @return The passed <code>syncFuture</code>
1675      * @throws FailedSyncBeforeLogCloseException
1676      */
1677     SyncFuture waitSafePoint(SyncFuture syncFuture) throws InterruptedException,
1678         FailedSyncBeforeLogCloseException {
1679       while (!this.safePointAttainedLatch.await(1, TimeUnit.MILLISECONDS)) {
1680         checkIfSyncFailed(syncFuture);
1681       }
1682       checkIfSyncFailed(syncFuture);
1683       return syncFuture;
1684     }
1685 
1686     /**
1687      * Called by Thread B when it attains the 'safe point'.  In this method, Thread B signals
1688      * Thread A it can proceed. Thread B will be held in here until {@link #releaseSafePoint()}
1689      * is called by Thread A.
1690      * @throws InterruptedException
1691      */
1692     void safePointAttained() throws InterruptedException {
1693       this.safePointAttainedLatch.countDown();
1694       this.safePointReleasedLatch.await();
1695     }
1696 
1697     /**
1698      * Called by Thread A when it is done with the work it needs to do while Thread B is
1699      * halted.  This will release the Thread B held in a call to {@link #safePointAttained()}
1700      */
1701     void releaseSafePoint() {
1702       this.safePointReleasedLatch.countDown();
1703     }
1704 
1705     /**
1706      * @return True is this is a 'cocked', fresh instance, and not one that has already fired.
1707      */
1708     boolean isCocked() {
1709       return this.safePointAttainedLatch.getCount() > 0 &&
1710         this.safePointReleasedLatch.getCount() > 0;
1711     }
1712   }
1713 
1714   /**
1715    * Handler that is run by the disruptor ringbuffer consumer. Consumer is a SINGLE
1716    * 'writer/appender' thread.  Appends edits and starts up sync runs.  Tries its best to batch up
1717    * syncs.  There is no discernible benefit batching appends so we just append as they come in
1718    * because it simplifies the below implementation.  See metrics for batching effectiveness
1719    * (In measurement, at 100 concurrent handlers writing 1k, we are batching > 10 appends and 10
1720    * handler sync invocations for every actual dfsclient sync call; at 10 concurrent handlers,
1721    * YMMV).
1722    * <p>Herein, we have an array into which we store the sync futures as they come in.  When we
1723    * have a 'batch', we'll then pass what we have collected to a SyncRunner thread to do the
1724    * filesystem sync.  When it completes, it will then call
1725    * {@link SyncFuture#done(long, Throwable)} on each of SyncFutures in the batch to release
1726    * blocked Handler threads.
1727    * <p>I've tried various effects to try and make latencies low while keeping throughput high.
1728    * I've tried keeping a single Queue of SyncFutures in this class appending to its tail as the
1729    * syncs coming and having sync runner threads poll off the head to 'finish' completed
1730    * SyncFutures.  I've tried linkedlist, and various from concurrent utils whether
1731    * LinkedBlockingQueue or ArrayBlockingQueue, etc.  The more points of synchronization, the
1732    * more 'work' (according to 'perf stats') that has to be done; small increases in stall
1733    * percentages seem to have a big impact on throughput/latencies.  The below model where we have
1734    * an array into which we stash the syncs and then hand them off to the sync thread seemed like
1735    * a decent compromise.  See HBASE-8755 for more detail.
1736    */
1737   class RingBufferEventHandler implements EventHandler<RingBufferTruck>, LifecycleAware {
1738     private final SyncRunner [] syncRunners;
1739     private final SyncFuture [] syncFutures;
1740     // Had 'interesting' issues when this was non-volatile.  On occasion, we'd not pass all
1741     // syncFutures to the next sync'ing thread.
1742     private volatile int syncFuturesCount = 0;
1743     private volatile SafePointZigZagLatch zigzagLatch;
1744     /**
1745      * Set if we get an exception appending or syncing so that all subsequence appends and syncs
1746      * on this WAL fail until WAL is replaced.
1747      */
1748     private Exception exception = null;
1749     /**
1750      * Object to block on while waiting on safe point.
1751      */
1752     private final Object safePointWaiter = new Object();
1753     private volatile boolean shutdown = false;
1754 
1755     /**
1756      * Which syncrunner to use next.
1757      */
1758     private int syncRunnerIndex;
1759 
1760     RingBufferEventHandler(final int syncRunnerCount, final int maxHandlersCount) {
1761       this.syncFutures = new SyncFuture[maxHandlersCount];
1762       this.syncRunners = new SyncRunner[syncRunnerCount];
1763       for (int i = 0; i < syncRunnerCount; i++) {
1764         this.syncRunners[i] = new SyncRunner("sync." + i, maxHandlersCount);
1765       }
1766     }
1767 
1768     private void cleanupOutstandingSyncsOnException(final long sequence, final Exception e) {
1769       // There could be handler-count syncFutures outstanding.
1770       for (int i = 0; i < this.syncFuturesCount; i++) this.syncFutures[i].done(sequence, e);
1771       this.syncFuturesCount = 0;
1772     }
1773 
1774     /**
1775      * @return True if outstanding sync futures still
1776      */
1777     private boolean isOutstandingSyncs() {
1778       // Look at SyncFutures in the EventHandler
1779       for (int i = 0; i < this.syncFuturesCount; i++) {
1780         if (!this.syncFutures[i].isDone()) return true;
1781       }
1782 
1783       return false;
1784     }
1785 
1786     private boolean isOutstandingSyncsFromRunners() {
1787       // Look at SyncFutures in the SyncRunners
1788       for (SyncRunner syncRunner: syncRunners) {
1789         if(syncRunner.isAlive() && !syncRunner.areSyncFuturesReleased()) {
1790           return true;
1791         }
1792       }
1793       return false;
1794     }
1795 
1796     @Override
1797     // We can set endOfBatch in the below method if at end of our this.syncFutures array
1798     public void onEvent(final RingBufferTruck truck, final long sequence, boolean endOfBatch)
1799     throws Exception {
1800       // Appends and syncs are coming in order off the ringbuffer.  We depend on this fact.  We'll
1801       // add appends to dfsclient as they come in.  Batching appends doesn't give any significant
1802       // benefit on measurement.  Handler sync calls we will batch up. If we get an exception
1803       // appending an edit, we fail all subsequent appends and syncs with the same exception until
1804       // the WAL is reset. It is important that we not short-circuit and exit early this method.
1805       // It is important that we always go through the attainSafePoint on the end. Another thread,
1806       // the log roller may be waiting on a signal from us here and will just hang without it.
1807 
1808       try {
1809         if (truck.hasSyncFuturePayload()) {
1810           this.syncFutures[this.syncFuturesCount++] = truck.unloadSyncFuturePayload();
1811           // Force flush of syncs if we are carrying a full complement of syncFutures.
1812           if (this.syncFuturesCount == this.syncFutures.length) endOfBatch = true;
1813         } else if (truck.hasFSWALEntryPayload()) {
1814           TraceScope scope = Trace.continueSpan(truck.unloadSpanPayload());
1815           try {
1816             FSWALEntry entry = truck.unloadFSWALEntryPayload();
1817             if (this.exception != null) {
1818               // Return to keep processing events coming off the ringbuffer
1819               return;
1820             }
1821             append(entry);
1822           } catch (Exception e) {
1823             // Failed append. Record the exception.
1824             this.exception = e;
1825             // invoking cleanupOutstandingSyncsOnException when append failed with exception,
1826             // it will cleanup existing sync requests recorded in syncFutures but not offered to SyncRunner yet,
1827             // so there won't be any sync future left over if no further truck published to disruptor.
1828             cleanupOutstandingSyncsOnException(sequence,
1829                 this.exception instanceof DamagedWALException ? this.exception
1830                     : new DamagedWALException("On sync", this.exception));
1831             // Return to keep processing events coming off the ringbuffer
1832             return;
1833           } finally {
1834             assert scope == NullScope.INSTANCE || !scope.isDetached();
1835             scope.close(); // append scope is complete
1836           }
1837         } else {
1838           // What is this if not an append or sync. Fail all up to this!!!
1839           cleanupOutstandingSyncsOnException(sequence,
1840             new IllegalStateException("Neither append nor sync"));
1841           // Return to keep processing.
1842           return;
1843         }
1844 
1845         // TODO: Check size and if big go ahead and call a sync if we have enough data.
1846         // This is a sync. If existing exception, fall through. Else look to see if batch.
1847         if (this.exception == null) {
1848           // If not a batch, return to consume more events from the ring buffer before proceeding;
1849           // we want to get up a batch of syncs and appends before we go do a filesystem sync.
1850           if (!endOfBatch || this.syncFuturesCount <= 0) return;
1851           // syncRunnerIndex is bound to the range [0, Integer.MAX_INT - 1] as follows:
1852           //   * The maximum value possible for syncRunners.length is Integer.MAX_INT
1853           //   * syncRunnerIndex starts at 0 and is incremented only here
1854           //   * after the increment, the value is bounded by the '%' operator to [0, syncRunners.length),
1855           //     presuming the value was positive prior to the '%' operator.
1856           //   * after being bound to [0, Integer.MAX_INT - 1], the new value is stored in syncRunnerIndex
1857           //     ensuring that it can't grow without bound and overflow.
1858           //   * note that the value after the increment must be positive, because the most it could have
1859           //     been prior was Integer.MAX_INT - 1 and we only increment by 1.
1860           this.syncRunnerIndex = (this.syncRunnerIndex + 1) % this.syncRunners.length;
1861           try {
1862             // Below expects that the offer 'transfers' responsibility for the outstanding syncs to
1863             // the syncRunner. We should never get an exception in here.
1864             this.syncRunners[this.syncRunnerIndex].offer(sequence, this.syncFutures,
1865               this.syncFuturesCount);
1866           } catch (Exception e) {
1867             // Should NEVER get here.
1868             requestLogRoll();
1869             this.exception = new DamagedWALException("Failed offering sync", e);
1870           }
1871         }
1872         // We may have picked up an exception above trying to offer sync
1873         if (this.exception != null) {
1874           cleanupOutstandingSyncsOnException(sequence,
1875             this.exception instanceof DamagedWALException?
1876               this.exception:
1877               new DamagedWALException("On sync", this.exception));
1878         }
1879         attainSafePoint(sequence);
1880         this.syncFuturesCount = 0;
1881       } catch (Throwable t) {
1882         LOG.error("UNEXPECTED!!! syncFutures.length=" + this.syncFutures.length, t);
1883       }
1884     }
1885 
1886     SafePointZigZagLatch attainSafePoint() {
1887       this.zigzagLatch = new SafePointZigZagLatch();
1888       return this.zigzagLatch;
1889     }
1890 
1891     /**
1892      * Check if we should attain safe point.  If so, go there and then wait till signalled before
1893      * we proceeding.
1894      */
1895     private void attainSafePoint(final long currentSequence) {
1896       if (this.zigzagLatch == null || !this.zigzagLatch.isCocked()) return;
1897       // If here, another thread is waiting on us to get to safe point.  Don't leave it hanging.
1898       beforeWaitOnSafePoint();
1899       try {
1900         // Wait on outstanding syncers; wait for them to finish syncing (unless we've been
1901         // shutdown or unless our latch has been thrown because we have been aborted or unless
1902         // this WAL is broken and we can't get a sync/append to complete).
1903         while ((!this.shutdown && this.zigzagLatch.isCocked()
1904             && highestSyncedSequence.get() < currentSequence &&
1905             // We could be in here and all syncs are failing or failed. Check for this. Otherwise
1906             // we'll just be stuck here for ever. In other words, ensure there syncs running.
1907             isOutstandingSyncs())
1908             // Wait for all SyncRunners to finish their work so that we can replace the writer
1909             || isOutstandingSyncsFromRunners()) {
1910           synchronized (this.safePointWaiter) {
1911             this.safePointWaiter.wait(0, 1);
1912           }
1913         }
1914         // Tell waiting thread we've attained safe point. Can clear this.throwable if set here
1915         // because we know that next event through the ringbuffer will be going to a new WAL
1916         // after we do the zigzaglatch dance.
1917         this.exception = null;
1918         this.zigzagLatch.safePointAttained();
1919       } catch (InterruptedException e) {
1920         LOG.warn("Interrupted ", e);
1921         Thread.currentThread().interrupt();
1922       }
1923     }
1924 
1925     /**
1926      * Append to the WAL.  Does all CP and WAL listener calls.
1927      * @param entry
1928      * @throws Exception
1929      */
1930     void append(final FSWALEntry entry) throws Exception {
1931       // TODO: WORK ON MAKING THIS APPEND FASTER. DOING WAY TOO MUCH WORK WITH CPs, PBing, etc.
1932       atHeadOfRingBufferEventHandlerAppend();
1933 
1934       long start = EnvironmentEdgeManager.currentTime();
1935       byte [] encodedRegionName = entry.getKey().getEncodedRegionName();
1936       long regionSequenceId = WALKey.NO_SEQUENCE_ID;
1937       try {
1938 
1939         regionSequenceId = entry.getKey().getSequenceId();
1940         // Edits are empty, there is nothing to append.  Maybe empty when we are looking for a
1941         // region sequence id only, a region edit/sequence id that is not associated with an actual
1942         // edit. It has to go through all the rigmarole to be sure we have the right ordering.
1943         if (entry.getEdit().isEmpty()) {
1944           return;
1945         }
1946 
1947         // Coprocessor hook.
1948         if (!coprocessorHost.preWALWrite(entry.getHRegionInfo(), entry.getKey(),
1949             entry.getEdit())) {
1950           if (entry.getEdit().isReplay()) {
1951             // Set replication scope null so that this won't be replicated
1952             entry.getKey().setScopes(null);
1953           }
1954         }
1955         if (!listeners.isEmpty()) {
1956           for (WALActionsListener i: listeners) {
1957             // TODO: Why does listener take a table description and CPs take a regioninfo?  Fix.
1958             i.visitLogEntryBeforeWrite(entry.getHTableDescriptor(), entry.getKey(),
1959               entry.getEdit());
1960           }
1961         }
1962 
1963         writer.append(entry);
1964         assert highestUnsyncedSequence < entry.getSequence();
1965         highestUnsyncedSequence = entry.getSequence();
1966         sequenceIdAccounting.update(encodedRegionName, entry.getFamilyNames(), regionSequenceId,
1967           entry.isInMemstore());
1968         coprocessorHost.postWALWrite(entry.getHRegionInfo(), entry.getKey(), entry.getEdit());
1969         // Update metrics.
1970         postAppend(entry, EnvironmentEdgeManager.currentTime() - start);
1971       } catch (Exception e) {
1972         String msg = "Append sequenceId=" + regionSequenceId + ", requesting roll of WAL";
1973         LOG.warn(msg, e);
1974         requestLogRoll();
1975         throw new DamagedWALException(msg, e);
1976       }
1977       numEntries.incrementAndGet();
1978     }
1979 
1980     @Override
1981     public void onStart() {
1982       for (SyncRunner syncRunner: this.syncRunners) syncRunner.start();
1983     }
1984 
1985     @Override
1986     public void onShutdown() {
1987       for (SyncRunner syncRunner: this.syncRunners) syncRunner.interrupt();
1988     }
1989   }
1990 
1991   /**
1992    * Exposed for testing only.  Use to tricks like halt the ring buffer appending.
1993    */
1994   @VisibleForTesting
1995   void atHeadOfRingBufferEventHandlerAppend() {
1996     // Noop
1997   }
1998 
1999   private static IOException ensureIOException(final Throwable t) {
2000     return (t instanceof IOException)? (IOException)t: new IOException(t);
2001   }
2002 
2003   private static void usage() {
2004     System.err.println("Usage: FSHLog <ARGS>");
2005     System.err.println("Arguments:");
2006     System.err.println(" --dump  Dump textual representation of passed one or more files");
2007     System.err.println("         For example: " +
2008       "FSHLog --dump hdfs://example.com:9000/hbase/.logs/MACHINE/LOGFILE");
2009     System.err.println(" --split Split the passed directory of WAL logs");
2010     System.err.println("         For example: " +
2011       "FSHLog --split hdfs://example.com:9000/hbase/.logs/DIR");
2012   }
2013 
2014   /**
2015    * Pass one or more log file names and it will either dump out a text version
2016    * on <code>stdout</code> or split the specified log files.
2017    *
2018    * @param args
2019    * @throws IOException
2020    */
2021   public static void main(String[] args) throws IOException {
2022     if (args.length < 2) {
2023       usage();
2024       System.exit(-1);
2025     }
2026     // either dump using the WALPrettyPrinter or split, depending on args
2027     if (args[0].compareTo("--dump") == 0) {
2028       WALPrettyPrinter.run(Arrays.copyOfRange(args, 1, args.length));
2029     } else if (args[0].compareTo("--perf") == 0) {
2030       LOG.fatal("Please use the WALPerformanceEvaluation tool instead. i.e.:");
2031       LOG.fatal("\thbase org.apache.hadoop.hbase.wal.WALPerformanceEvaluation --iterations " +
2032           args[1]);
2033       System.exit(-1);
2034     } else if (args[0].compareTo("--split") == 0) {
2035       Configuration conf = HBaseConfiguration.create();
2036       for (int i = 1; i < args.length; i++) {
2037         try {
2038           Path logPath = new Path(args[i]);
2039           FSUtils.setFsDefault(conf, logPath);
2040           split(conf, logPath);
2041         } catch (IOException t) {
2042           t.printStackTrace(System.err);
2043           System.exit(-1);
2044         }
2045       }
2046     } else {
2047       usage();
2048       System.exit(-1);
2049     }
2050   }
2051 
2052   /**
2053    * This method gets the pipeline for the current WAL.
2054    */
2055   @VisibleForTesting
2056   DatanodeInfo[] getPipeLine() {
2057     if (this.hdfs_out != null) {
2058       if (this.hdfs_out.getWrappedStream() instanceof DFSOutputStream) {
2059         return ((DFSOutputStream) this.hdfs_out.getWrappedStream()).getPipeline();
2060       }
2061     }
2062     return new DatanodeInfo[0];
2063   }
2064 
2065   /**
2066    *
2067    * @return last time on checking low replication
2068    */
2069   public long getLastTimeCheckLowReplication() {
2070     return this.lastTimeCheckLowReplication;
2071   }
2072 }