1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
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.reflect.InvocationTargetException;
27 import java.lang.reflect.Method;
28 import java.net.URLEncoder;
29 import java.util.ArrayList;
30 import java.util.Arrays;
31 import java.util.Collections;
32 import java.util.Comparator;
33 import java.util.HashMap;
34 import java.util.List;
35 import java.util.Map;
36 import java.util.NavigableMap;
37 import java.util.Set;
38 import java.util.TreeMap;
39 import java.util.UUID;
40 import java.util.concurrent.BlockingQueue;
41 import java.util.concurrent.ConcurrentHashMap;
42 import java.util.concurrent.ConcurrentMap;
43 import java.util.concurrent.ConcurrentSkipListMap;
44 import java.util.concurrent.CopyOnWriteArrayList;
45 import java.util.concurrent.CountDownLatch;
46 import java.util.concurrent.ExecutionException;
47 import java.util.concurrent.ExecutorService;
48 import java.util.concurrent.Executors;
49 import java.util.concurrent.LinkedBlockingQueue;
50 import java.util.concurrent.TimeUnit;
51 import java.util.concurrent.atomic.AtomicBoolean;
52 import java.util.concurrent.atomic.AtomicInteger;
53 import java.util.concurrent.atomic.AtomicLong;
54 import java.util.concurrent.locks.ReentrantLock;
55
56 import org.apache.commons.logging.Log;
57 import org.apache.commons.logging.LogFactory;
58 import org.apache.hadoop.conf.Configuration;
59 import org.apache.hadoop.fs.FSDataOutputStream;
60 import org.apache.hadoop.fs.FileStatus;
61 import org.apache.hadoop.fs.FileSystem;
62 import org.apache.hadoop.fs.Path;
63 import org.apache.hadoop.fs.PathFilter;
64 import org.apache.hadoop.hbase.Cell;
65 import org.apache.hadoop.hbase.CellUtil;
66 import org.apache.hadoop.hbase.HBaseConfiguration;
67 import org.apache.hadoop.hbase.HConstants;
68 import org.apache.hadoop.hbase.HRegionInfo;
69 import org.apache.hadoop.hbase.HTableDescriptor;
70 import org.apache.hadoop.hbase.TableName;
71 import org.apache.hadoop.hbase.classification.InterfaceAudience;
72 import org.apache.hadoop.hbase.util.Bytes;
73 import org.apache.hadoop.hbase.util.ClassSize;
74 import org.apache.hadoop.hbase.util.DrainBarrier;
75 import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
76 import org.apache.hadoop.hbase.util.FSUtils;
77 import org.apache.hadoop.hbase.util.HasThread;
78 import org.apache.hadoop.hbase.util.Threads;
79 import org.apache.hadoop.hbase.wal.DefaultWALProvider;
80 import org.apache.hadoop.hbase.wal.WAL;
81 import org.apache.hadoop.hbase.wal.WALFactory;
82 import org.apache.hadoop.hbase.wal.WALKey;
83 import org.apache.hadoop.hbase.wal.WALPrettyPrinter;
84 import org.apache.hadoop.hbase.wal.WALProvider.Writer;
85 import org.apache.hadoop.hbase.wal.WALSplitter;
86 import org.apache.hadoop.hdfs.protocol.DatanodeInfo;
87 import org.apache.hadoop.util.StringUtils;
88 import org.apache.htrace.NullScope;
89 import org.apache.htrace.Span;
90 import org.apache.htrace.Trace;
91 import org.apache.htrace.TraceScope;
92
93 import com.google.common.annotations.VisibleForTesting;
94 import com.google.common.collect.Maps;
95 import com.lmax.disruptor.BlockingWaitStrategy;
96 import com.lmax.disruptor.EventHandler;
97 import com.lmax.disruptor.ExceptionHandler;
98 import com.lmax.disruptor.LifecycleAware;
99 import com.lmax.disruptor.TimeoutException;
100 import com.lmax.disruptor.dsl.Disruptor;
101 import com.lmax.disruptor.dsl.ProducerType;
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130 @InterfaceAudience.Private
131 public class FSHLog implements WAL {
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166 static final Log LOG = LogFactory.getLog(FSHLog.class);
167
168 private static final int DEFAULT_SLOW_SYNC_TIME_MS = 100;
169
170
171
172
173
174
175
176
177
178 private final Disruptor<RingBufferTruck> disruptor;
179
180
181
182
183 private final ExecutorService appendExecutor;
184
185
186
187
188
189
190
191 private final RingBufferEventHandler ringBufferEventHandler;
192
193
194
195
196
197
198
199 private final Map<Thread, SyncFuture> syncFuturesByHandler;
200
201
202
203
204
205 private volatile long highestUnsyncedSequence = -1;
206
207
208
209
210
211
212 private final AtomicLong highestSyncedSequence = new AtomicLong(0);
213
214
215
216
217 protected final FileSystem fs;
218
219
220
221
222 private final Path fullPathLogDir;
223
224
225
226 private final Path fullPathArchiveDir;
227
228
229
230
231 private final PathFilter ourFiles;
232
233
234
235
236 private final String logFilePrefix;
237
238
239
240
241 private final String logFileSuffix;
242
243
244
245
246 private final String prefixPathStr;
247
248 private final WALCoprocessorHost coprocessorHost;
249
250
251
252
253 protected final Configuration conf;
254
255 private final List<WALActionsListener> listeners = new CopyOnWriteArrayList<WALActionsListener>();
256
257 @Override
258 public void registerWALActionsListener(final WALActionsListener listener) {
259 this.listeners.add(listener);
260 }
261
262 @Override
263 public boolean unregisterWALActionsListener(final WALActionsListener listener) {
264 return this.listeners.remove(listener);
265 }
266
267 @Override
268 public WALCoprocessorHost getCoprocessorHost() {
269 return coprocessorHost;
270 }
271
272
273
274 private FSDataOutputStream hdfs_out;
275
276
277
278
279 private final int minTolerableReplication;
280
281
282 private final Method getNumCurrentReplicas;
283 private final Method getPipeLine;
284 private final int slowSyncNs;
285
286 private final static Object [] NO_ARGS = new Object []{};
287
288
289
290
291
292 private final AtomicInteger consecutiveLogRolls = new AtomicInteger(0);
293
294 private final int lowReplicationRollLimit;
295
296
297
298
299 private volatile boolean lowReplicationRollEnabled = true;
300
301
302
303
304 volatile Writer writer;
305
306
307 private final DrainBarrier closeBarrier = new DrainBarrier();
308
309
310
311
312
313
314
315
316 private final ReentrantLock rollWriterLock = new ReentrantLock(true);
317
318 private volatile boolean closed = false;
319 private final AtomicBoolean shutdown = new AtomicBoolean(false);
320
321
322 private final AtomicLong filenum = new AtomicLong(-1);
323
324
325 private final AtomicInteger numEntries = new AtomicInteger(0);
326
327
328 private final long logrollsize;
329
330
331
332
333 private AtomicLong totalLogSize = new AtomicLong(0);
334
335
336
337
338
339
340 private final int maxLogs;
341
342
343 private final int closeErrorsTolerated;
344
345 private final AtomicInteger closeErrorCount = new AtomicInteger();
346
347
348
349
350
351
352
353
354
355
356
357 private final Object regionSequenceIdLock = new Object();
358
359
360
361
362
363
364
365
366 private final ConcurrentMap<byte[], ConcurrentMap<byte[], Long>> oldestUnflushedStoreSequenceIds
367 = new ConcurrentSkipListMap<byte[], ConcurrentMap<byte[], Long>>(
368 Bytes.BYTES_COMPARATOR);
369
370
371
372
373
374
375
376
377
378 private final Map<byte[], Map<byte[], Long>> lowestFlushingStoreSequenceIds =
379 new TreeMap<byte[], Map<byte[], Long>>(Bytes.BYTES_COMPARATOR);
380
381
382
383
384
385
386
387
388
389
390
391
392 private Map<byte[], Long> highestRegionSequenceIds = new HashMap<byte[], Long>();
393
394
395
396
397
398 final Comparator<Path> LOG_NAME_COMPARATOR = new Comparator<Path>() {
399 @Override
400 public int compare(Path o1, Path o2) {
401 long t1 = getFileNumFromFileName(o1);
402 long t2 = getFileNumFromFileName(o2);
403 if (t1 == t2) return 0;
404 return (t1 > t2) ? 1 : -1;
405 }
406 };
407
408
409
410
411
412 private NavigableMap<Path, Map<byte[], Long>> byWalRegionSequenceIds =
413 new ConcurrentSkipListMap<Path, Map<byte[], Long>>(LOG_NAME_COMPARATOR);
414
415
416
417
418
419 static class RingBufferExceptionHandler implements ExceptionHandler {
420 @Override
421 public void handleEventException(Throwable ex, long sequence, Object event) {
422 LOG.error("Sequence=" + sequence + ", event=" + event, ex);
423 throw new RuntimeException(ex);
424 }
425
426 @Override
427 public void handleOnStartException(Throwable ex) {
428 LOG.error(ex);
429 throw new RuntimeException(ex);
430 }
431
432 @Override
433 public void handleOnShutdownException(Throwable ex) {
434 LOG.error(ex);
435 throw new RuntimeException(ex);
436 }
437 }
438
439
440
441
442
443
444
445
446
447
448 public FSHLog(final FileSystem fs, final Path root, final String logDir, final Configuration conf)
449 throws IOException {
450 this(fs, root, logDir, HConstants.HREGION_OLDLOGDIR_NAME, conf, null, true, null, null);
451 }
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477 public FSHLog(final FileSystem fs, final Path rootDir, final String logDir,
478 final String archiveDir, final Configuration conf,
479 final List<WALActionsListener> listeners,
480 final boolean failIfWALExists, final String prefix, final String suffix)
481 throws IOException {
482 this.fs = fs;
483 this.fullPathLogDir = new Path(rootDir, logDir);
484 this.fullPathArchiveDir = new Path(rootDir, archiveDir);
485 this.conf = conf;
486
487 if (!fs.exists(fullPathLogDir) && !fs.mkdirs(fullPathLogDir)) {
488 throw new IOException("Unable to mkdir " + fullPathLogDir);
489 }
490
491 if (!fs.exists(this.fullPathArchiveDir)) {
492 if (!fs.mkdirs(this.fullPathArchiveDir)) {
493 throw new IOException("Unable to mkdir " + this.fullPathArchiveDir);
494 }
495 }
496
497
498 this.logFilePrefix =
499 prefix == null || prefix.isEmpty() ? "wal" : URLEncoder.encode(prefix, "UTF8");
500
501 if (suffix != null && !(suffix.isEmpty()) && !(suffix.startsWith(WAL_FILE_NAME_DELIMITER))) {
502 throw new IllegalArgumentException("WAL suffix must start with '" + WAL_FILE_NAME_DELIMITER +
503 "' but instead was '" + suffix + "'");
504 }
505
506
507 FSUtils.setStoragePolicy(fs, conf, this.fullPathLogDir, HConstants.WAL_STORAGE_POLICY,
508 HConstants.DEFAULT_WAL_STORAGE_POLICY);
509 this.logFileSuffix = (suffix == null) ? "" : URLEncoder.encode(suffix, "UTF8");
510 this.prefixPathStr = new Path(fullPathLogDir,
511 logFilePrefix + WAL_FILE_NAME_DELIMITER).toString();
512
513 this.ourFiles = new PathFilter() {
514 @Override
515 public boolean accept(final Path fileName) {
516
517 final String fileNameString = fileName.toString();
518 if (!fileNameString.startsWith(prefixPathStr)) {
519 return false;
520 }
521 if (logFileSuffix.isEmpty()) {
522
523 return org.apache.commons.lang.StringUtils.isNumeric(
524 fileNameString.substring(prefixPathStr.length()));
525 } else if (!fileNameString.endsWith(logFileSuffix)) {
526 return false;
527 }
528 return true;
529 }
530 };
531
532 if (failIfWALExists) {
533 final FileStatus[] walFiles = FSUtils.listStatus(fs, fullPathLogDir, ourFiles);
534 if (null != walFiles && 0 != walFiles.length) {
535 throw new IOException("Target WAL already exists within directory " + fullPathLogDir);
536 }
537 }
538
539
540 if (listeners != null) {
541 for (WALActionsListener i: listeners) {
542 registerWALActionsListener(i);
543 }
544 }
545 this.coprocessorHost = new WALCoprocessorHost(this, conf);
546
547
548
549 final long blocksize = this.conf.getLong("hbase.regionserver.hlog.blocksize",
550 FSUtils.getDefaultBlockSize(this.fs, this.fullPathLogDir));
551 this.logrollsize =
552 (long)(blocksize * conf.getFloat("hbase.regionserver.logroll.multiplier", 0.95f));
553
554 this.maxLogs = conf.getInt("hbase.regionserver.maxlogs", 32);
555 this.minTolerableReplication = conf.getInt( "hbase.regionserver.hlog.tolerable.lowreplication",
556 FSUtils.getDefaultReplication(fs, this.fullPathLogDir));
557 this.lowReplicationRollLimit =
558 conf.getInt("hbase.regionserver.hlog.lowreplication.rolllimit", 5);
559 this.closeErrorsTolerated = conf.getInt("hbase.regionserver.logroll.errors.tolerated", 0);
560 int maxHandlersCount = conf.getInt(HConstants.REGION_SERVER_HANDLER_COUNT, 200);
561
562 LOG.info("WAL configuration: blocksize=" + StringUtils.byteDesc(blocksize) +
563 ", rollsize=" + StringUtils.byteDesc(this.logrollsize) +
564 ", prefix=" + this.logFilePrefix + ", suffix=" + logFileSuffix + ", logDir=" +
565 this.fullPathLogDir + ", archiveDir=" + this.fullPathArchiveDir);
566
567
568 rollWriter();
569
570 this.slowSyncNs =
571 1000000 * conf.getInt("hbase.regionserver.hlog.slowsync.ms",
572 DEFAULT_SLOW_SYNC_TIME_MS);
573
574
575 this.getNumCurrentReplicas = getGetNumCurrentReplicas(this.hdfs_out);
576 this.getPipeLine = getGetPipeline(this.hdfs_out);
577
578
579
580 String hostingThreadName = Thread.currentThread().getName();
581 this.appendExecutor = Executors.
582 newSingleThreadExecutor(Threads.getNamedThreadFactory(hostingThreadName + ".append"));
583
584
585
586
587 final int preallocatedEventCount =
588 this.conf.getInt("hbase.regionserver.wal.disruptor.event.count", 1024 * 16);
589
590
591 this.disruptor =
592 new Disruptor<RingBufferTruck>(RingBufferTruck.EVENT_FACTORY, preallocatedEventCount,
593 this.appendExecutor, ProducerType.MULTI, new BlockingWaitStrategy());
594
595
596 this.disruptor.getRingBuffer().next();
597 this.ringBufferEventHandler =
598 new RingBufferEventHandler(conf.getInt("hbase.regionserver.hlog.syncer.count", 5),
599 maxHandlersCount);
600 this.disruptor.handleExceptionsWith(new RingBufferExceptionHandler());
601 this.disruptor.handleEventsWith(new RingBufferEventHandler [] {this.ringBufferEventHandler});
602
603 this.syncFuturesByHandler = new ConcurrentHashMap<Thread, SyncFuture>(maxHandlersCount);
604
605 this.disruptor.start();
606 }
607
608
609
610
611
612 protected FileStatus[] getFiles() throws IOException {
613 return FSUtils.listStatus(fs, fullPathLogDir, ourFiles);
614 }
615
616
617
618
619
620
621
622
623
624 @VisibleForTesting
625 OutputStream getOutputStream() {
626 FSDataOutputStream fsdos = this.hdfs_out;
627 if (fsdos == null) return null;
628 return fsdos.getWrappedStream();
629 }
630
631 @Override
632 public byte [][] rollWriter() throws FailedLogCloseException, IOException {
633 return rollWriter(false);
634 }
635
636
637
638
639
640 private Path getNewPath() throws IOException {
641 this.filenum.set(System.currentTimeMillis());
642 Path newPath = getCurrentFileName();
643 while (fs.exists(newPath)) {
644 this.filenum.incrementAndGet();
645 newPath = getCurrentFileName();
646 }
647 return newPath;
648 }
649
650 Path getOldPath() {
651 long currentFilenum = this.filenum.get();
652 Path oldPath = null;
653 if (currentFilenum > 0) {
654
655 oldPath = computeFilename(currentFilenum);
656 }
657 return oldPath;
658 }
659
660
661
662
663
664 private void tellListenersAboutPreLogRoll(final Path oldPath, final Path newPath)
665 throws IOException {
666 if (!this.listeners.isEmpty()) {
667 for (WALActionsListener i : this.listeners) {
668 i.preLogRoll(oldPath, newPath);
669 }
670 }
671 }
672
673
674
675
676
677 private void tellListenersAboutPostLogRoll(final Path oldPath, final Path newPath)
678 throws IOException {
679 if (!this.listeners.isEmpty()) {
680 for (WALActionsListener i : this.listeners) {
681 i.postLogRoll(oldPath, newPath);
682 }
683 }
684 }
685
686
687
688
689
690
691 private void preemptiveSync(final ProtobufLogWriter nextWriter) {
692 long startTimeNanos = System.nanoTime();
693 try {
694 nextWriter.sync();
695 postSync(System.nanoTime() - startTimeNanos, 0);
696 } catch (IOException e) {
697
698 LOG.warn("pre-sync failed but an optimization so keep going", e);
699 }
700 }
701
702 @Override
703 public byte [][] rollWriter(boolean force) throws FailedLogCloseException, IOException {
704 rollWriterLock.lock();
705 try {
706
707 if (!force && (this.writer != null && this.numEntries.get() <= 0)) return null;
708 byte [][] regionsToFlush = null;
709 if (this.closed) {
710 LOG.debug("WAL closed. Skipping rolling of writer");
711 return regionsToFlush;
712 }
713 if (!closeBarrier.beginOp()) {
714 LOG.debug("WAL closing. Skipping rolling of writer");
715 return regionsToFlush;
716 }
717 TraceScope scope = Trace.startSpan("FSHLog.rollWriter");
718 try {
719 Path oldPath = getOldPath();
720 Path newPath = getNewPath();
721
722 Writer nextWriter = this.createWriterInstance(newPath);
723 FSDataOutputStream nextHdfsOut = null;
724 if (nextWriter instanceof ProtobufLogWriter) {
725 nextHdfsOut = ((ProtobufLogWriter)nextWriter).getStream();
726
727
728 preemptiveSync((ProtobufLogWriter)nextWriter);
729 }
730 tellListenersAboutPreLogRoll(oldPath, newPath);
731
732 newPath = replaceWriter(oldPath, newPath, nextWriter, nextHdfsOut);
733 tellListenersAboutPostLogRoll(oldPath, newPath);
734
735 if (getNumRolledLogFiles() > 0) {
736 cleanOldLogs();
737 regionsToFlush = findRegionsToForceFlush();
738 }
739 } finally {
740 closeBarrier.endOp();
741 assert scope == NullScope.INSTANCE || !scope.isDetached();
742 scope.close();
743 }
744 return regionsToFlush;
745 } finally {
746 rollWriterLock.unlock();
747 }
748 }
749
750
751
752
753
754
755
756 protected Writer createWriterInstance(final Path path) throws IOException {
757 return DefaultWALProvider.createWriter(conf, fs, path, false);
758 }
759
760 private long getLowestSeqId(Map<byte[], Long> seqIdMap) {
761 long result = HConstants.NO_SEQNUM;
762 for (Long seqNum: seqIdMap.values()) {
763 if (result == HConstants.NO_SEQNUM || seqNum.longValue() < result) {
764 result = seqNum.longValue();
765 }
766 }
767 return result;
768 }
769
770 private <T extends Map<byte[], Long>> Map<byte[], Long> copyMapWithLowestSeqId(
771 Map<byte[], T> mapToCopy) {
772 Map<byte[], Long> copied = Maps.newHashMap();
773 for (Map.Entry<byte[], T> entry: mapToCopy.entrySet()) {
774 long lowestSeqId = getLowestSeqId(entry.getValue());
775 if (lowestSeqId != HConstants.NO_SEQNUM) {
776 copied.put(entry.getKey(), lowestSeqId);
777 }
778 }
779 return copied;
780 }
781
782
783
784
785
786
787
788
789
790
791
792
793 private void cleanOldLogs() throws IOException {
794 Map<byte[], Long> lowestFlushingRegionSequenceIdsLocal = null;
795 Map<byte[], Long> oldestUnflushedRegionSequenceIdsLocal = null;
796 List<Path> logsToArchive = new ArrayList<Path>();
797
798 synchronized (regionSequenceIdLock) {
799 lowestFlushingRegionSequenceIdsLocal =
800 copyMapWithLowestSeqId(this.lowestFlushingStoreSequenceIds);
801 oldestUnflushedRegionSequenceIdsLocal =
802 copyMapWithLowestSeqId(this.oldestUnflushedStoreSequenceIds);
803 }
804 for (Map.Entry<Path, Map<byte[], Long>> e : byWalRegionSequenceIds.entrySet()) {
805
806 Path log = e.getKey();
807 Map<byte[], Long> sequenceNums = e.getValue();
808
809 if (areAllRegionsFlushed(sequenceNums, lowestFlushingRegionSequenceIdsLocal,
810 oldestUnflushedRegionSequenceIdsLocal)) {
811 logsToArchive.add(log);
812 LOG.debug("WAL file ready for archiving " + log);
813 }
814 }
815 for (Path p : logsToArchive) {
816 this.totalLogSize.addAndGet(-this.fs.getFileStatus(p).getLen());
817 archiveLogFile(p);
818 this.byWalRegionSequenceIds.remove(p);
819 }
820 }
821
822
823
824
825
826
827
828
829
830
831
832
833 static boolean areAllRegionsFlushed(Map<byte[], Long> sequenceNums,
834 Map<byte[], Long> oldestFlushingMap, Map<byte[], Long> oldestUnflushedMap) {
835 for (Map.Entry<byte[], Long> regionSeqIdEntry : sequenceNums.entrySet()) {
836
837
838 long oldestFlushing = oldestFlushingMap.containsKey(regionSeqIdEntry.getKey()) ?
839 oldestFlushingMap.get(regionSeqIdEntry.getKey()) : Long.MAX_VALUE;
840 long oldestUnFlushed = oldestUnflushedMap.containsKey(regionSeqIdEntry.getKey()) ?
841 oldestUnflushedMap.get(regionSeqIdEntry.getKey()) : Long.MAX_VALUE;
842
843 long minSeqNum = Math.min(oldestFlushing, oldestUnFlushed);
844 if (minSeqNum <= regionSeqIdEntry.getValue()) return false;
845 }
846 return true;
847 }
848
849
850
851
852
853
854
855
856
857
858
859
860 private byte[][] findEligibleMemstoresToFlush(Map<byte[], Long> regionsSequenceNums) {
861 List<byte[]> regionsToFlush = null;
862
863 synchronized (regionSequenceIdLock) {
864 for (Map.Entry<byte[], Long> e: regionsSequenceNums.entrySet()) {
865 ConcurrentMap<byte[], Long> m =
866 this.oldestUnflushedStoreSequenceIds.get(e.getKey());
867 if (m == null) {
868 continue;
869 }
870 long unFlushedVal = Collections.min(m.values());
871 if (unFlushedVal != HConstants.NO_SEQNUM && unFlushedVal <= e.getValue()) {
872 if (regionsToFlush == null)
873 regionsToFlush = new ArrayList<byte[]>();
874 regionsToFlush.add(e.getKey());
875 }
876 }
877 }
878 return regionsToFlush == null ? null : regionsToFlush
879 .toArray(new byte[][] { HConstants.EMPTY_BYTE_ARRAY });
880 }
881
882
883
884
885
886
887
888
889 byte[][] findRegionsToForceFlush() throws IOException {
890 byte [][] regions = null;
891 int logCount = getNumRolledLogFiles();
892 if (logCount > this.maxLogs && logCount > 0) {
893 Map.Entry<Path, Map<byte[], Long>> firstWALEntry =
894 this.byWalRegionSequenceIds.firstEntry();
895 regions = findEligibleMemstoresToFlush(firstWALEntry.getValue());
896 }
897 if (regions != null) {
898 StringBuilder sb = new StringBuilder();
899 for (int i = 0; i < regions.length; i++) {
900 if (i > 0) sb.append(", ");
901 sb.append(Bytes.toStringBinary(regions[i]));
902 }
903 LOG.info("Too many wals: logs=" + logCount + ", maxlogs=" +
904 this.maxLogs + "; forcing flush of " + regions.length + " regions(s): " +
905 sb.toString());
906 }
907 return regions;
908 }
909
910
911
912
913
914 @VisibleForTesting
915 protected void afterCreatingZigZagLatch() {}
916
917
918
919
920 @VisibleForTesting
921 protected void beforeWaitOnSafePoint() {};
922
923
924
925
926
927
928
929
930
931
932
933
934
935
936
937
938
939
940
941 Path replaceWriter(final Path oldPath, final Path newPath, Writer nextWriter,
942 final FSDataOutputStream nextHdfsOut)
943 throws IOException {
944
945
946
947
948
949 SyncFuture syncFuture = null;
950 SafePointZigZagLatch zigzagLatch = (this.ringBufferEventHandler == null)?
951 null: this.ringBufferEventHandler.attainSafePoint();
952 afterCreatingZigZagLatch();
953 TraceScope scope = Trace.startSpan("FSHFile.replaceWriter");
954 try {
955
956
957
958
959
960 try {
961 if (zigzagLatch != null) {
962 Trace.addTimelineAnnotation("awaiting safepoint");
963 syncFuture = zigzagLatch.waitSafePoint(publishSyncOnRingBuffer());
964 }
965 } catch (FailedSyncBeforeLogCloseException e) {
966
967 if (isUnflushedEntries()) throw e;
968 LOG.warn("Failed sync-before-close but no outstanding appends; closing WAL: " +
969 e.getMessage());
970 }
971
972
973
974 try {
975 if (this.writer != null) {
976 Trace.addTimelineAnnotation("closing writer");
977 this.writer.close();
978 Trace.addTimelineAnnotation("writer closed");
979 }
980 this.closeErrorCount.set(0);
981 } catch (IOException ioe) {
982 int errors = closeErrorCount.incrementAndGet();
983 if (!isUnflushedEntries() && (errors <= this.closeErrorsTolerated)) {
984 LOG.warn("Riding over failed WAL close of " + oldPath + ", cause=\"" +
985 ioe.getMessage() + "\", errors=" + errors +
986 "; THIS FILE WAS NOT CLOSED BUT ALL EDITS SYNCED SO SHOULD BE OK");
987 } else {
988 throw ioe;
989 }
990 }
991 this.writer = nextWriter;
992 this.hdfs_out = nextHdfsOut;
993 int oldNumEntries = this.numEntries.get();
994 this.numEntries.set(0);
995 final String newPathString = (null == newPath ? null : FSUtils.getPath(newPath));
996 if (oldPath != null) {
997 this.byWalRegionSequenceIds.put(oldPath, this.highestRegionSequenceIds);
998 this.highestRegionSequenceIds = new HashMap<byte[], Long>();
999 long oldFileLen = this.fs.getFileStatus(oldPath).getLen();
1000 this.totalLogSize.addAndGet(oldFileLen);
1001 LOG.info("Rolled WAL " + FSUtils.getPath(oldPath) + " with entries=" + oldNumEntries +
1002 ", filesize=" + StringUtils.byteDesc(oldFileLen) + "; new WAL " +
1003 newPathString);
1004 } else {
1005 LOG.info("New WAL " + newPathString);
1006 }
1007 } catch (InterruptedException ie) {
1008
1009 Thread.currentThread().interrupt();
1010 } catch (IOException e) {
1011 long count = getUnflushedEntriesCount();
1012 LOG.error("Failed close of WAL writer " + oldPath + ", unflushedEntries=" + count, e);
1013 throw new FailedLogCloseException(oldPath + ", unflushedEntries=" + count, e);
1014 } finally {
1015 try {
1016
1017 if (zigzagLatch != null) {
1018 zigzagLatch.releaseSafePoint();
1019
1020
1021
1022
1023
1024
1025 if (syncFuture != null) {
1026 try {
1027 blockOnSync(syncFuture);
1028 } catch (IOException ioe) {
1029 if (LOG.isTraceEnabled()) LOG.trace("Stale sync exception", ioe);
1030 }
1031 }
1032 }
1033 } finally {
1034 scope.close();
1035 }
1036 }
1037 return newPath;
1038 }
1039
1040 long getUnflushedEntriesCount() {
1041 long highestSynced = this.highestSyncedSequence.get();
1042 return highestSynced > this.highestUnsyncedSequence?
1043 0: this.highestUnsyncedSequence - highestSynced;
1044 }
1045
1046 boolean isUnflushedEntries() {
1047 return getUnflushedEntriesCount() > 0;
1048 }
1049
1050
1051
1052
1053
1054 public static Path getWALArchivePath(Path archiveDir, Path p) {
1055 return new Path(archiveDir, p.getName());
1056 }
1057
1058 private void archiveLogFile(final Path p) throws IOException {
1059 Path newPath = getWALArchivePath(this.fullPathArchiveDir, p);
1060
1061 if (!this.listeners.isEmpty()) {
1062 for (WALActionsListener i : this.listeners) {
1063 i.preLogArchive(p, newPath);
1064 }
1065 }
1066 LOG.info("Archiving " + p + " to " + newPath);
1067 if (!FSUtils.renameAndSetModifyTime(this.fs, p, newPath)) {
1068 throw new IOException("Unable to rename " + p + " to " + newPath);
1069 }
1070
1071 if (!this.listeners.isEmpty()) {
1072 for (WALActionsListener i : this.listeners) {
1073 i.postLogArchive(p, newPath);
1074 }
1075 }
1076 }
1077
1078
1079
1080
1081
1082
1083
1084 protected Path computeFilename(final long filenum) {
1085 if (filenum < 0) {
1086 throw new RuntimeException("WAL file number can't be < 0");
1087 }
1088 String child = logFilePrefix + WAL_FILE_NAME_DELIMITER + filenum + logFileSuffix;
1089 return new Path(fullPathLogDir, child);
1090 }
1091
1092
1093
1094
1095
1096
1097 public Path getCurrentFileName() {
1098 return computeFilename(this.filenum.get());
1099 }
1100
1101 @Override
1102 public String toString() {
1103 return "FSHLog " + logFilePrefix + ":" + logFileSuffix + "(num " + filenum + ")";
1104 }
1105
1106
1107
1108
1109
1110
1111
1112
1113
1114 protected long getFileNumFromFileName(Path fileName) {
1115 if (fileName == null) throw new IllegalArgumentException("file name can't be null");
1116 if (!ourFiles.accept(fileName)) {
1117 throw new IllegalArgumentException("The log file " + fileName +
1118 " doesn't belong to this WAL. (" + toString() + ")");
1119 }
1120 final String fileNameString = fileName.toString();
1121 String chompedPath = fileNameString.substring(prefixPathStr.length(),
1122 (fileNameString.length() - logFileSuffix.length()));
1123 return Long.parseLong(chompedPath);
1124 }
1125
1126 @Override
1127 public void close() throws IOException {
1128 shutdown();
1129 final FileStatus[] files = getFiles();
1130 if (null != files && 0 != files.length) {
1131 for (FileStatus file : files) {
1132 Path p = getWALArchivePath(this.fullPathArchiveDir, file.getPath());
1133
1134 if (!this.listeners.isEmpty()) {
1135 for (WALActionsListener i : this.listeners) {
1136 i.preLogArchive(file.getPath(), p);
1137 }
1138 }
1139
1140 if (!FSUtils.renameAndSetModifyTime(fs, file.getPath(), p)) {
1141 throw new IOException("Unable to rename " + file.getPath() + " to " + p);
1142 }
1143
1144 if (!this.listeners.isEmpty()) {
1145 for (WALActionsListener i : this.listeners) {
1146 i.postLogArchive(file.getPath(), p);
1147 }
1148 }
1149 }
1150 LOG.debug("Moved " + files.length + " WAL file(s) to " +
1151 FSUtils.getPath(this.fullPathArchiveDir));
1152 }
1153 LOG.info("Closed WAL: " + toString() );
1154 }
1155
1156 @Override
1157 public void shutdown() throws IOException {
1158 if (shutdown.compareAndSet(false, true)) {
1159 try {
1160
1161 closeBarrier.stopAndDrainOps();
1162 } catch (InterruptedException e) {
1163 LOG.error("Exception while waiting for cache flushes and log rolls", e);
1164 Thread.currentThread().interrupt();
1165 }
1166
1167
1168
1169
1170 if (this.disruptor != null) {
1171 long timeoutms = conf.getLong("hbase.wal.disruptor.shutdown.timeout.ms", 60000);
1172 try {
1173 this.disruptor.shutdown(timeoutms, TimeUnit.MILLISECONDS);
1174 } catch (TimeoutException e) {
1175 LOG.warn("Timed out bringing down disruptor after " + timeoutms + "ms; forcing halt " +
1176 "(It is a problem if this is NOT an ABORT! -- DATALOSS!!!!)");
1177 this.disruptor.halt();
1178 this.disruptor.shutdown();
1179 }
1180 }
1181
1182 if (this.appendExecutor != null) this.appendExecutor.shutdown();
1183
1184
1185 if (!this.listeners.isEmpty()) {
1186 for (WALActionsListener i : this.listeners) {
1187 i.logCloseRequested();
1188 }
1189 }
1190 this.closed = true;
1191 if (LOG.isDebugEnabled()) {
1192 LOG.debug("Closing WAL writer in " + FSUtils.getPath(fullPathLogDir));
1193 }
1194 if (this.writer != null) {
1195 this.writer.close();
1196 this.writer = null;
1197 }
1198 }
1199 }
1200
1201
1202
1203
1204
1205
1206
1207
1208
1209 @SuppressWarnings("deprecation")
1210 protected WALKey makeKey(byte[] encodedRegionName, TableName tableName, long seqnum,
1211 long now, List<UUID> clusterIds, long nonceGroup, long nonce) {
1212
1213 return new HLogKey(encodedRegionName, tableName, seqnum, now, clusterIds, nonceGroup, nonce);
1214 }
1215
1216 @edu.umd.cs.findbugs.annotations.SuppressWarnings(value="NP_NULL_ON_SOME_PATH_EXCEPTION",
1217 justification="Will never be null")
1218 @Override
1219 public long append(final HTableDescriptor htd, final HRegionInfo hri, final WALKey key,
1220 final WALEdit edits, final AtomicLong sequenceId, final boolean inMemstore,
1221 final List<Cell> memstoreCells) throws IOException {
1222 if (this.closed) throw new IOException("Cannot append; log is closed");
1223
1224
1225 TraceScope scope = Trace.startSpan("FSHLog.append");
1226
1227
1228
1229
1230 FSWALEntry entry = null;
1231 long sequence = this.disruptor.getRingBuffer().next();
1232 try {
1233 RingBufferTruck truck = this.disruptor.getRingBuffer().get(sequence);
1234
1235
1236
1237 entry = new FSWALEntry(sequence, key, edits, sequenceId, inMemstore, htd, hri,
1238
1239 (memstoreCells != null)? memstoreCells: edits == null? null: edits.getCells());
1240 truck.loadPayload(entry, scope.detach());
1241 } finally {
1242 this.disruptor.getRingBuffer().publish(sequence);
1243 }
1244 return sequence;
1245 }
1246
1247
1248
1249
1250
1251
1252
1253
1254
1255
1256
1257
1258
1259
1260
1261
1262 private class SyncRunner extends HasThread {
1263 private volatile long sequence;
1264
1265 private final BlockingQueue<SyncFuture> syncFutures;
1266
1267
1268
1269
1270
1271
1272
1273
1274
1275
1276
1277 SyncRunner(final String name, final int maxHandlersCount) {
1278 super(name);
1279
1280
1281
1282
1283
1284
1285
1286
1287
1288
1289
1290
1291
1292 this.syncFutures = new LinkedBlockingQueue<SyncFuture>(maxHandlersCount * 3);
1293 }
1294
1295 void offer(final long sequence, final SyncFuture [] syncFutures, final int syncFutureCount) {
1296
1297 this.sequence = sequence;
1298 for (int i = 0; i < syncFutureCount; ++i) {
1299 this.syncFutures.add(syncFutures[i]);
1300 }
1301 }
1302
1303
1304
1305
1306
1307
1308
1309
1310 private int releaseSyncFuture(final SyncFuture syncFuture, final long currentSequence,
1311 final Throwable t) {
1312 if (!syncFuture.done(currentSequence, t)) throw new IllegalStateException();
1313
1314 return 1;
1315 }
1316
1317
1318
1319
1320
1321
1322
1323 private int releaseSyncFutures(final long currentSequence, final Throwable t) {
1324 int syncCount = 0;
1325 for (SyncFuture syncFuture; (syncFuture = this.syncFutures.peek()) != null;) {
1326 if (syncFuture.getRingBufferSequence() > currentSequence) break;
1327 releaseSyncFuture(syncFuture, currentSequence, t);
1328 if (!this.syncFutures.remove(syncFuture)) {
1329 throw new IllegalStateException(syncFuture.toString());
1330 }
1331 syncCount++;
1332 }
1333 return syncCount;
1334 }
1335
1336
1337
1338
1339
1340 private long updateHighestSyncedSequence(long sequence) {
1341 long currentHighestSyncedSequence;
1342
1343 do {
1344 currentHighestSyncedSequence = highestSyncedSequence.get();
1345 if (currentHighestSyncedSequence >= sequence) {
1346
1347
1348 sequence = currentHighestSyncedSequence;
1349 break;
1350 }
1351 } while (!highestSyncedSequence.compareAndSet(currentHighestSyncedSequence, sequence));
1352 return sequence;
1353 }
1354
1355 public void run() {
1356 long currentSequence;
1357 while (!isInterrupted()) {
1358 int syncCount = 0;
1359 SyncFuture takeSyncFuture;
1360 try {
1361 while (true) {
1362
1363 takeSyncFuture = this.syncFutures.take();
1364 currentSequence = this.sequence;
1365 long syncFutureSequence = takeSyncFuture.getRingBufferSequence();
1366 if (syncFutureSequence > currentSequence) {
1367 throw new IllegalStateException("currentSequence=" + syncFutureSequence +
1368 ", syncFutureSequence=" + syncFutureSequence);
1369 }
1370
1371 long currentHighestSyncedSequence = highestSyncedSequence.get();
1372 if (currentSequence < currentHighestSyncedSequence) {
1373 syncCount += releaseSyncFuture(takeSyncFuture, currentHighestSyncedSequence, null);
1374
1375 continue;
1376 }
1377 break;
1378 }
1379
1380
1381 TraceScope scope = Trace.continueSpan(takeSyncFuture.getSpan());
1382 long start = System.nanoTime();
1383 Throwable lastException = null;
1384 try {
1385 Trace.addTimelineAnnotation("syncing writer");
1386 writer.sync();
1387 Trace.addTimelineAnnotation("writer synced");
1388 currentSequence = updateHighestSyncedSequence(currentSequence);
1389 } catch (IOException e) {
1390 LOG.error("Error syncing, request close of WAL", e);
1391 lastException = e;
1392 } catch (Exception e) {
1393 LOG.warn("UNEXPECTED", e);
1394 lastException = e;
1395 } finally {
1396
1397 takeSyncFuture.setSpan(scope.detach());
1398
1399 syncCount += releaseSyncFuture(takeSyncFuture, currentSequence, lastException);
1400
1401 syncCount += releaseSyncFutures(currentSequence, lastException);
1402 if (lastException != null) requestLogRoll();
1403 else checkLogRoll();
1404 }
1405 postSync(System.nanoTime() - start, syncCount);
1406 } catch (InterruptedException e) {
1407
1408 Thread.currentThread().interrupt();
1409 } catch (Throwable t) {
1410 LOG.warn("UNEXPECTED, continuing", t);
1411 }
1412 }
1413 }
1414 }
1415
1416
1417
1418
1419 void checkLogRoll() {
1420
1421 if (!rollWriterLock.tryLock()) return;
1422 boolean lowReplication;
1423 try {
1424 lowReplication = checkLowReplication();
1425 } finally {
1426 rollWriterLock.unlock();
1427 }
1428 try {
1429 if (lowReplication || writer != null && writer.getLength() > logrollsize) {
1430 requestLogRoll(lowReplication);
1431 }
1432 } catch (IOException e) {
1433 LOG.warn("Writer.getLength() failed; continuing", e);
1434 }
1435 }
1436
1437
1438
1439
1440 private boolean checkLowReplication() {
1441 boolean logRollNeeded = false;
1442
1443
1444 try {
1445 int numCurrentReplicas = getLogReplication();
1446 if (numCurrentReplicas != 0 && numCurrentReplicas < this.minTolerableReplication) {
1447 if (this.lowReplicationRollEnabled) {
1448 if (this.consecutiveLogRolls.get() < this.lowReplicationRollLimit) {
1449 LOG.warn("HDFS pipeline error detected. " + "Found "
1450 + numCurrentReplicas + " replicas but expecting no less than "
1451 + this.minTolerableReplication + " replicas. "
1452 + " Requesting close of WAL. current pipeline: "
1453 + Arrays.toString(getPipeLine()));
1454 logRollNeeded = true;
1455
1456
1457
1458 this.consecutiveLogRolls.getAndIncrement();
1459 } else {
1460 LOG.warn("Too many consecutive RollWriter requests, it's a sign of "
1461 + "the total number of live datanodes is lower than the tolerable replicas.");
1462 this.consecutiveLogRolls.set(0);
1463 this.lowReplicationRollEnabled = false;
1464 }
1465 }
1466 } else if (numCurrentReplicas >= this.minTolerableReplication) {
1467 if (!this.lowReplicationRollEnabled) {
1468
1469
1470
1471 if (this.numEntries.get() <= 1) {
1472 return logRollNeeded;
1473 }
1474
1475
1476 this.lowReplicationRollEnabled = true;
1477 LOG.info("LowReplication-Roller was enabled.");
1478 }
1479 }
1480 } catch (Exception e) {
1481 LOG.warn("DFSOutputStream.getNumCurrentReplicas failed because of " + e +
1482 ", continuing...");
1483 }
1484 return logRollNeeded;
1485 }
1486
1487 private SyncFuture publishSyncOnRingBuffer() {
1488 return publishSyncOnRingBuffer(null);
1489 }
1490
1491 private SyncFuture publishSyncOnRingBuffer(Span span) {
1492 long sequence = this.disruptor.getRingBuffer().next();
1493 SyncFuture syncFuture = getSyncFuture(sequence, span);
1494 try {
1495 RingBufferTruck truck = this.disruptor.getRingBuffer().get(sequence);
1496 truck.loadPayload(syncFuture);
1497 } finally {
1498 this.disruptor.getRingBuffer().publish(sequence);
1499 }
1500 return syncFuture;
1501 }
1502
1503
1504 private Span publishSyncThenBlockOnCompletion(Span span) throws IOException {
1505 return blockOnSync(publishSyncOnRingBuffer(span));
1506 }
1507
1508 private Span blockOnSync(final SyncFuture syncFuture) throws IOException {
1509
1510 try {
1511 syncFuture.get();
1512 return syncFuture.getSpan();
1513 } catch (InterruptedException ie) {
1514 LOG.warn("Interrupted", ie);
1515 throw convertInterruptedExceptionToIOException(ie);
1516 } catch (ExecutionException e) {
1517 throw ensureIOException(e.getCause());
1518 }
1519 }
1520
1521 private IOException convertInterruptedExceptionToIOException(final InterruptedException ie) {
1522 Thread.currentThread().interrupt();
1523 IOException ioe = new InterruptedIOException();
1524 ioe.initCause(ie);
1525 return ioe;
1526 }
1527
1528 private SyncFuture getSyncFuture(final long sequence, Span span) {
1529 SyncFuture syncFuture = this.syncFuturesByHandler.get(Thread.currentThread());
1530 if (syncFuture == null) {
1531 syncFuture = new SyncFuture();
1532 this.syncFuturesByHandler.put(Thread.currentThread(), syncFuture);
1533 }
1534 return syncFuture.reset(sequence, span);
1535 }
1536
1537 private void postSync(final long timeInNanos, final int handlerSyncs) {
1538 if (timeInNanos > this.slowSyncNs) {
1539 String msg =
1540 new StringBuilder().append("Slow sync cost: ")
1541 .append(timeInNanos / 1000000).append(" ms, current pipeline: ")
1542 .append(Arrays.toString(getPipeLine())).toString();
1543 Trace.addTimelineAnnotation(msg);
1544 LOG.info(msg);
1545 }
1546 if (!listeners.isEmpty()) {
1547 for (WALActionsListener listener : listeners) {
1548 listener.postSync(timeInNanos, handlerSyncs);
1549 }
1550 }
1551 }
1552
1553 private long postAppend(final Entry e, final long elapsedTime) {
1554 long len = 0;
1555 if (!listeners.isEmpty()) {
1556 for (Cell cell : e.getEdit().getCells()) {
1557 len += CellUtil.estimatedSerializedSizeOf(cell);
1558 }
1559 for (WALActionsListener listener : listeners) {
1560 listener.postAppend(len, elapsedTime);
1561 }
1562 }
1563 return len;
1564 }
1565
1566
1567
1568
1569
1570
1571 private Method getGetNumCurrentReplicas(final FSDataOutputStream os) {
1572
1573
1574 Method m = null;
1575 if (os != null) {
1576 Class<? extends OutputStream> wrappedStreamClass = os.getWrappedStream().getClass();
1577 try {
1578 m = wrappedStreamClass.getDeclaredMethod("getNumCurrentReplicas", new Class<?>[] {});
1579 m.setAccessible(true);
1580 } catch (NoSuchMethodException e) {
1581 LOG.info("FileSystem's output stream doesn't support getNumCurrentReplicas; " +
1582 "HDFS-826 not available; fsOut=" + wrappedStreamClass.getName());
1583 } catch (SecurityException e) {
1584 LOG.info("No access to getNumCurrentReplicas on FileSystems's output stream; HDFS-826 " +
1585 "not available; fsOut=" + wrappedStreamClass.getName(), e);
1586 m = null;
1587 }
1588 }
1589 if (m != null) {
1590 if (LOG.isTraceEnabled()) LOG.trace("Using getNumCurrentReplicas");
1591 }
1592 return m;
1593 }
1594
1595
1596
1597
1598
1599
1600
1601
1602
1603
1604
1605
1606
1607 @VisibleForTesting
1608 int getLogReplication()
1609 throws IllegalArgumentException, IllegalAccessException, InvocationTargetException {
1610 final OutputStream stream = getOutputStream();
1611 if (this.getNumCurrentReplicas != null && stream != null) {
1612 Object repl = this.getNumCurrentReplicas.invoke(stream, NO_ARGS);
1613 if (repl instanceof Integer) {
1614 return ((Integer)repl).intValue();
1615 }
1616 }
1617 return 0;
1618 }
1619
1620 @Override
1621 public void sync() throws IOException {
1622 TraceScope scope = Trace.startSpan("FSHLog.sync");
1623 try {
1624 scope = Trace.continueSpan(publishSyncThenBlockOnCompletion(scope.detach()));
1625 } finally {
1626 assert scope == NullScope.INSTANCE || !scope.isDetached();
1627 scope.close();
1628 }
1629 }
1630
1631 @Override
1632 public void sync(long txid) throws IOException {
1633 if (this.highestSyncedSequence.get() >= txid){
1634
1635 return;
1636 }
1637 TraceScope scope = Trace.startSpan("FSHLog.sync");
1638 try {
1639 scope = Trace.continueSpan(publishSyncThenBlockOnCompletion(scope.detach()));
1640 } finally {
1641 assert scope == NullScope.INSTANCE || !scope.isDetached();
1642 scope.close();
1643 }
1644 }
1645
1646
1647 public void requestLogRoll() {
1648 requestLogRoll(false);
1649 }
1650
1651 private void requestLogRoll(boolean tooFewReplicas) {
1652 if (!this.listeners.isEmpty()) {
1653 for (WALActionsListener i: this.listeners) {
1654 i.logRollRequested(tooFewReplicas);
1655 }
1656 }
1657 }
1658
1659
1660
1661 public int getNumRolledLogFiles() {
1662 return byWalRegionSequenceIds.size();
1663 }
1664
1665
1666
1667 public int getNumLogFiles() {
1668
1669 return getNumRolledLogFiles() + 1;
1670 }
1671
1672
1673
1674 public long getLogFileSize() {
1675 return this.totalLogSize.get();
1676 }
1677
1678 @Override
1679 public Long startCacheFlush(final byte[] encodedRegionName,
1680 Set<byte[]> flushedFamilyNames) {
1681 Map<byte[], Long> oldStoreSeqNum = Maps.newTreeMap(Bytes.BYTES_COMPARATOR);
1682 if (!closeBarrier.beginOp()) {
1683 LOG.info("Flush will not be started for " + Bytes.toString(encodedRegionName) +
1684 " - because the server is closing.");
1685 return null;
1686 }
1687 long oldestUnflushedSequenceId = HConstants.NO_SEQNUM;
1688 synchronized (regionSequenceIdLock) {
1689 ConcurrentMap<byte[], Long> oldestUnflushedStoreSequenceIdsOfRegion =
1690 oldestUnflushedStoreSequenceIds.get(encodedRegionName);
1691 if (oldestUnflushedStoreSequenceIdsOfRegion != null) {
1692 for (byte[] familyName: flushedFamilyNames) {
1693 Long seqId = oldestUnflushedStoreSequenceIdsOfRegion.remove(familyName);
1694 if (seqId != null) {
1695 oldStoreSeqNum.put(familyName, seqId);
1696 }
1697 }
1698 if (!oldStoreSeqNum.isEmpty()) {
1699 Map<byte[], Long> oldValue = this.lowestFlushingStoreSequenceIds.put(
1700 encodedRegionName, oldStoreSeqNum);
1701 assert oldValue == null: "Flushing map not cleaned up for "
1702 + Bytes.toString(encodedRegionName);
1703 }
1704 if (oldestUnflushedStoreSequenceIdsOfRegion.isEmpty()) {
1705
1706
1707
1708
1709 oldestUnflushedStoreSequenceIds.remove(encodedRegionName);
1710 } else {
1711 oldestUnflushedSequenceId =
1712 Collections.min(oldestUnflushedStoreSequenceIdsOfRegion.values());
1713 }
1714 }
1715 }
1716 if (oldStoreSeqNum.isEmpty()) {
1717
1718
1719
1720
1721
1722 LOG.warn("Couldn't find oldest seqNum for the region we are about to flush: ["
1723 + Bytes.toString(encodedRegionName) + "]");
1724 }
1725 return oldestUnflushedSequenceId;
1726 }
1727
1728 @Override
1729 public void completeCacheFlush(final byte [] encodedRegionName) {
1730 synchronized (regionSequenceIdLock) {
1731 this.lowestFlushingStoreSequenceIds.remove(encodedRegionName);
1732 }
1733 closeBarrier.endOp();
1734 }
1735
1736 private ConcurrentMap<byte[], Long> getOrCreateOldestUnflushedStoreSequenceIdsOfRegion(
1737 byte[] encodedRegionName) {
1738 ConcurrentMap<byte[], Long> oldestUnflushedStoreSequenceIdsOfRegion =
1739 oldestUnflushedStoreSequenceIds.get(encodedRegionName);
1740 if (oldestUnflushedStoreSequenceIdsOfRegion != null) {
1741 return oldestUnflushedStoreSequenceIdsOfRegion;
1742 }
1743 oldestUnflushedStoreSequenceIdsOfRegion =
1744 new ConcurrentSkipListMap<byte[], Long>(Bytes.BYTES_COMPARATOR);
1745 ConcurrentMap<byte[], Long> alreadyPut =
1746 oldestUnflushedStoreSequenceIds.putIfAbsent(encodedRegionName,
1747 oldestUnflushedStoreSequenceIdsOfRegion);
1748 return alreadyPut == null ? oldestUnflushedStoreSequenceIdsOfRegion : alreadyPut;
1749 }
1750
1751 @Override
1752 public void abortCacheFlush(byte[] encodedRegionName) {
1753 Map<byte[], Long> storeSeqNumsBeforeFlushStarts;
1754 Map<byte[], Long> currentStoreSeqNums = new TreeMap<byte[], Long>(Bytes.BYTES_COMPARATOR);
1755 synchronized (regionSequenceIdLock) {
1756 storeSeqNumsBeforeFlushStarts = this.lowestFlushingStoreSequenceIds.remove(
1757 encodedRegionName);
1758 if (storeSeqNumsBeforeFlushStarts != null) {
1759 ConcurrentMap<byte[], Long> oldestUnflushedStoreSequenceIdsOfRegion =
1760 getOrCreateOldestUnflushedStoreSequenceIdsOfRegion(encodedRegionName);
1761 for (Map.Entry<byte[], Long> familyNameAndSeqId: storeSeqNumsBeforeFlushStarts
1762 .entrySet()) {
1763 currentStoreSeqNums.put(familyNameAndSeqId.getKey(),
1764 oldestUnflushedStoreSequenceIdsOfRegion.put(familyNameAndSeqId.getKey(),
1765 familyNameAndSeqId.getValue()));
1766 }
1767 }
1768 }
1769 closeBarrier.endOp();
1770 if (storeSeqNumsBeforeFlushStarts != null) {
1771 for (Map.Entry<byte[], Long> familyNameAndSeqId : storeSeqNumsBeforeFlushStarts.entrySet()) {
1772 Long currentSeqNum = currentStoreSeqNums.get(familyNameAndSeqId.getKey());
1773 if (currentSeqNum != null
1774 && currentSeqNum.longValue() <= familyNameAndSeqId.getValue().longValue()) {
1775 String errorStr =
1776 "Region " + Bytes.toString(encodedRegionName) + " family "
1777 + Bytes.toString(familyNameAndSeqId.getKey())
1778 + " acquired edits out of order current memstore seq=" + currentSeqNum
1779 + ", previous oldest unflushed id=" + familyNameAndSeqId.getValue();
1780 LOG.error(errorStr);
1781 Runtime.getRuntime().halt(1);
1782 }
1783 }
1784 }
1785 }
1786
1787 @VisibleForTesting
1788 boolean isLowReplicationRollEnabled() {
1789 return lowReplicationRollEnabled;
1790 }
1791
1792 public static final long FIXED_OVERHEAD = ClassSize.align(
1793 ClassSize.OBJECT + (5 * ClassSize.REFERENCE) +
1794 ClassSize.ATOMIC_INTEGER + Bytes.SIZEOF_INT + (3 * Bytes.SIZEOF_LONG));
1795
1796 private static void split(final Configuration conf, final Path p)
1797 throws IOException {
1798 FileSystem fs = FileSystem.get(conf);
1799 if (!fs.exists(p)) {
1800 throw new FileNotFoundException(p.toString());
1801 }
1802 if (!fs.getFileStatus(p).isDirectory()) {
1803 throw new IOException(p + " is not a directory");
1804 }
1805
1806 final Path baseDir = FSUtils.getRootDir(conf);
1807 final Path archiveDir = new Path(baseDir, HConstants.HREGION_OLDLOGDIR_NAME);
1808 WALSplitter.split(baseDir, p, archiveDir, fs, conf, WALFactory.getInstance(conf));
1809 }
1810
1811 @Override
1812 public long getEarliestMemstoreSeqNum(byte[] encodedRegionName) {
1813 ConcurrentMap<byte[], Long> oldestUnflushedStoreSequenceIdsOfRegion =
1814 this.oldestUnflushedStoreSequenceIds.get(encodedRegionName);
1815 return oldestUnflushedStoreSequenceIdsOfRegion != null ?
1816 getLowestSeqId(oldestUnflushedStoreSequenceIdsOfRegion) : HConstants.NO_SEQNUM;
1817 }
1818
1819 @Override
1820 public long getEarliestMemstoreSeqNum(byte[] encodedRegionName,
1821 byte[] familyName) {
1822 synchronized (regionSequenceIdLock) {
1823 Map<byte[], Long> m = this.lowestFlushingStoreSequenceIds.get(encodedRegionName);
1824 if (m != null) {
1825 Long earlist = m.get(familyName);
1826 if (earlist != null) {
1827 return earlist;
1828 }
1829 }
1830 m = this.oldestUnflushedStoreSequenceIds.get(encodedRegionName);
1831 if (m != null) {
1832 Long earlist = m.get(familyName);
1833 if (earlist != null) {
1834 return earlist;
1835 }
1836 }
1837 }
1838 return HConstants.NO_SEQNUM;
1839 }
1840
1841
1842
1843
1844
1845
1846
1847
1848
1849
1850
1851
1852
1853
1854
1855
1856
1857
1858
1859
1860
1861
1862
1863
1864
1865
1866
1867 static class SafePointZigZagLatch {
1868
1869
1870
1871 private volatile CountDownLatch safePointAttainedLatch = new CountDownLatch(1);
1872
1873
1874
1875 private volatile CountDownLatch safePointReleasedLatch = new CountDownLatch(1);
1876
1877
1878
1879
1880
1881
1882
1883
1884
1885
1886
1887 SyncFuture waitSafePoint(final SyncFuture syncFuture)
1888 throws InterruptedException, FailedSyncBeforeLogCloseException {
1889 while (true) {
1890 if (this.safePointAttainedLatch.await(1, TimeUnit.NANOSECONDS)) break;
1891 if (syncFuture.isThrowable()) {
1892 throw new FailedSyncBeforeLogCloseException(syncFuture.getThrowable());
1893 }
1894 }
1895 return syncFuture;
1896 }
1897
1898
1899
1900
1901
1902
1903
1904 void safePointAttained() throws InterruptedException {
1905 this.safePointAttainedLatch.countDown();
1906 this.safePointReleasedLatch.await();
1907 }
1908
1909
1910
1911
1912
1913 void releaseSafePoint() {
1914 this.safePointReleasedLatch.countDown();
1915 }
1916
1917
1918
1919
1920 boolean isCocked() {
1921 return this.safePointAttainedLatch.getCount() > 0 &&
1922 this.safePointReleasedLatch.getCount() > 0;
1923 }
1924 }
1925
1926
1927
1928
1929
1930
1931
1932
1933
1934
1935
1936
1937
1938
1939
1940
1941
1942
1943
1944
1945
1946
1947
1948
1949 class RingBufferEventHandler implements EventHandler<RingBufferTruck>, LifecycleAware {
1950 private final SyncRunner [] syncRunners;
1951 private final SyncFuture [] syncFutures;
1952
1953
1954 private volatile int syncFuturesCount = 0;
1955 private volatile SafePointZigZagLatch zigzagLatch;
1956
1957
1958
1959
1960 private Exception exception = null;
1961
1962
1963
1964 private final Object safePointWaiter = new Object();
1965 private volatile boolean shutdown = false;
1966
1967
1968
1969
1970 private int syncRunnerIndex;
1971
1972 RingBufferEventHandler(final int syncRunnerCount, final int maxHandlersCount) {
1973 this.syncFutures = new SyncFuture[maxHandlersCount];
1974 this.syncRunners = new SyncRunner[syncRunnerCount];
1975 for (int i = 0; i < syncRunnerCount; i++) {
1976 this.syncRunners[i] = new SyncRunner("sync." + i, maxHandlersCount);
1977 }
1978 }
1979
1980 private void cleanupOutstandingSyncsOnException(final long sequence, final Exception e) {
1981
1982 for (int i = 0; i < this.syncFuturesCount; i++) this.syncFutures[i].done(sequence, e);
1983 this.syncFuturesCount = 0;
1984 }
1985
1986
1987
1988
1989 private boolean isOutstandingSyncs() {
1990 for (int i = 0; i < this.syncFuturesCount; i++) {
1991 if (!this.syncFutures[i].isDone()) return true;
1992 }
1993 return false;
1994 }
1995
1996 @Override
1997
1998 public void onEvent(final RingBufferTruck truck, final long sequence, boolean endOfBatch)
1999 throws Exception {
2000
2001
2002
2003
2004
2005
2006
2007
2008 try {
2009 if (truck.hasSyncFuturePayload()) {
2010 this.syncFutures[this.syncFuturesCount++] = truck.unloadSyncFuturePayload();
2011
2012 if (this.syncFuturesCount == this.syncFutures.length) endOfBatch = true;
2013 } else if (truck.hasFSWALEntryPayload()) {
2014 TraceScope scope = Trace.continueSpan(truck.unloadSpanPayload());
2015 try {
2016 FSWALEntry entry = truck.unloadFSWALEntryPayload();
2017 if (this.exception != null) {
2018
2019
2020
2021
2022
2023 entry.stampRegionSequenceId();
2024
2025 return;
2026 }
2027 append(entry);
2028 } catch (Exception e) {
2029
2030 this.exception = e;
2031
2032 return;
2033 } finally {
2034 assert scope == NullScope.INSTANCE || !scope.isDetached();
2035 scope.close();
2036 }
2037 } else {
2038
2039 cleanupOutstandingSyncsOnException(sequence,
2040 new IllegalStateException("Neither append nor sync"));
2041
2042 return;
2043 }
2044
2045
2046
2047
2048
2049 if (!endOfBatch || this.syncFuturesCount <= 0) return;
2050
2051
2052
2053 if (LOG.isTraceEnabled()) {
2054 LOG.trace("Sequence=" + sequence + ", syncCount=" + this.syncFuturesCount);
2055 }
2056
2057 if (this.exception == null) {
2058
2059
2060 this.syncRunnerIndex = (this.syncRunnerIndex + 1) % this.syncRunners.length;
2061 try {
2062 this.syncRunners[this.syncRunnerIndex].offer(sequence, this.syncFutures,
2063 this.syncFuturesCount);
2064 } catch (Exception e) {
2065
2066 requestLogRoll();
2067 this.exception = new DamagedWALException("Failed offering sync", e);
2068 }
2069 }
2070
2071 if (this.exception != null) {
2072 cleanupOutstandingSyncsOnException(sequence,
2073 new DamagedWALException("On sync", this.exception));
2074 }
2075 attainSafePoint(sequence);
2076 this.syncFuturesCount = 0;
2077 } catch (Throwable t) {
2078 LOG.error("UNEXPECTED!!! syncFutures.length=" + this.syncFutures.length, t);
2079 }
2080 }
2081
2082 SafePointZigZagLatch attainSafePoint() {
2083 this.zigzagLatch = new SafePointZigZagLatch();
2084 return this.zigzagLatch;
2085 }
2086
2087
2088
2089
2090
2091 private void attainSafePoint(final long currentSequence) {
2092 if (this.zigzagLatch == null || !this.zigzagLatch.isCocked()) return;
2093
2094 beforeWaitOnSafePoint();
2095 try {
2096
2097
2098
2099 while (!this.shutdown && this.zigzagLatch.isCocked() &&
2100 highestSyncedSequence.get() < currentSequence &&
2101
2102
2103 isOutstandingSyncs()) {
2104 synchronized (this.safePointWaiter) {
2105 this.safePointWaiter.wait(0, 1);
2106 }
2107 }
2108
2109
2110
2111 this.exception = null;
2112 this.zigzagLatch.safePointAttained();
2113 } catch (InterruptedException e) {
2114 LOG.warn("Interrupted ", e);
2115 Thread.currentThread().interrupt();
2116 }
2117 }
2118
2119 private void updateOldestUnflushedSequenceIds(byte[] encodedRegionName,
2120 Set<byte[]> familyNameSet, Long lRegionSequenceId) {
2121 ConcurrentMap<byte[], Long> oldestUnflushedStoreSequenceIdsOfRegion =
2122 getOrCreateOldestUnflushedStoreSequenceIdsOfRegion(encodedRegionName);
2123 for (byte[] familyName : familyNameSet) {
2124 oldestUnflushedStoreSequenceIdsOfRegion.putIfAbsent(familyName, lRegionSequenceId);
2125 }
2126 }
2127
2128
2129
2130
2131
2132
2133 void append(final FSWALEntry entry) throws Exception {
2134
2135 atHeadOfRingBufferEventHandlerAppend();
2136
2137 long start = EnvironmentEdgeManager.currentTime();
2138 byte [] encodedRegionName = entry.getKey().getEncodedRegionName();
2139 long regionSequenceId = WALKey.NO_SEQUENCE_ID;
2140 try {
2141
2142
2143
2144 regionSequenceId = entry.stampRegionSequenceId();
2145
2146
2147
2148
2149 if (entry.getEdit().isEmpty()) {
2150 return;
2151 }
2152
2153
2154 if (!coprocessorHost.preWALWrite(entry.getHRegionInfo(), entry.getKey(),
2155 entry.getEdit())) {
2156 if (entry.getEdit().isReplay()) {
2157
2158 entry.getKey().setScopes(null);
2159 }
2160 }
2161 if (!listeners.isEmpty()) {
2162 for (WALActionsListener i: listeners) {
2163
2164 i.visitLogEntryBeforeWrite(entry.getHTableDescriptor(), entry.getKey(),
2165 entry.getEdit());
2166 }
2167 }
2168
2169 writer.append(entry);
2170 assert highestUnsyncedSequence < entry.getSequence();
2171 highestUnsyncedSequence = entry.getSequence();
2172 Long lRegionSequenceId = Long.valueOf(regionSequenceId);
2173 highestRegionSequenceIds.put(encodedRegionName, lRegionSequenceId);
2174 if (entry.isInMemstore()) {
2175 updateOldestUnflushedSequenceIds(encodedRegionName,
2176 entry.getFamilyNames(), lRegionSequenceId);
2177 }
2178
2179 coprocessorHost.postWALWrite(entry.getHRegionInfo(), entry.getKey(), entry.getEdit());
2180
2181 postAppend(entry, EnvironmentEdgeManager.currentTime() - start);
2182 } catch (Exception e) {
2183 String msg = "Failed appending " + regionSequenceId + ", requesting roll of WAL";
2184 LOG.warn(msg, e);
2185 requestLogRoll();
2186 throw new DamagedWALException(msg, e);
2187 }
2188 numEntries.incrementAndGet();
2189 }
2190
2191 @Override
2192 public void onStart() {
2193 for (SyncRunner syncRunner: this.syncRunners) syncRunner.start();
2194 }
2195
2196 @Override
2197 public void onShutdown() {
2198 for (SyncRunner syncRunner: this.syncRunners) syncRunner.interrupt();
2199 }
2200 }
2201
2202
2203
2204
2205 @VisibleForTesting
2206 void atHeadOfRingBufferEventHandlerAppend() {
2207
2208 }
2209
2210 private static IOException ensureIOException(final Throwable t) {
2211 return (t instanceof IOException)? (IOException)t: new IOException(t);
2212 }
2213
2214 private static void usage() {
2215 System.err.println("Usage: FSHLog <ARGS>");
2216 System.err.println("Arguments:");
2217 System.err.println(" --dump Dump textual representation of passed one or more files");
2218 System.err.println(" For example: " +
2219 "FSHLog --dump hdfs://example.com:9000/hbase/.logs/MACHINE/LOGFILE");
2220 System.err.println(" --split Split the passed directory of WAL logs");
2221 System.err.println(" For example: " +
2222 "FSHLog --split hdfs://example.com:9000/hbase/.logs/DIR");
2223 }
2224
2225
2226
2227
2228
2229
2230
2231
2232 public static void main(String[] args) throws IOException {
2233 if (args.length < 2) {
2234 usage();
2235 System.exit(-1);
2236 }
2237
2238 if (args[0].compareTo("--dump") == 0) {
2239 WALPrettyPrinter.run(Arrays.copyOfRange(args, 1, args.length));
2240 } else if (args[0].compareTo("--perf") == 0) {
2241 LOG.fatal("Please use the WALPerformanceEvaluation tool instead. i.e.:");
2242 LOG.fatal("\thbase org.apache.hadoop.hbase.wal.WALPerformanceEvaluation --iterations " +
2243 args[1]);
2244 System.exit(-1);
2245 } else if (args[0].compareTo("--split") == 0) {
2246 Configuration conf = HBaseConfiguration.create();
2247 for (int i = 1; i < args.length; i++) {
2248 try {
2249 Path logPath = new Path(args[i]);
2250 FSUtils.setFsDefault(conf, logPath);
2251 split(conf, logPath);
2252 } catch (IOException t) {
2253 t.printStackTrace(System.err);
2254 System.exit(-1);
2255 }
2256 }
2257 } else {
2258 usage();
2259 System.exit(-1);
2260 }
2261 }
2262
2263
2264
2265
2266
2267 private Method getGetPipeline(final FSDataOutputStream os) {
2268 Method m = null;
2269 if (os != null) {
2270 Class<? extends OutputStream> wrappedStreamClass = os.getWrappedStream()
2271 .getClass();
2272 try {
2273 m = wrappedStreamClass.getDeclaredMethod("getPipeline",
2274 new Class<?>[] {});
2275 m.setAccessible(true);
2276 } catch (NoSuchMethodException e) {
2277 LOG.info("FileSystem's output stream doesn't support"
2278 + " getPipeline; not available; fsOut="
2279 + wrappedStreamClass.getName());
2280 } catch (SecurityException e) {
2281 LOG.info(
2282 "Doesn't have access to getPipeline on "
2283 + "FileSystems's output stream ; fsOut="
2284 + wrappedStreamClass.getName(), e);
2285 m = null;
2286 }
2287 }
2288 return m;
2289 }
2290
2291
2292
2293
2294 @VisibleForTesting
2295 DatanodeInfo[] getPipeLine() {
2296 if (this.getPipeLine != null && this.hdfs_out != null) {
2297 Object repl;
2298 try {
2299 repl = this.getPipeLine.invoke(getOutputStream(), NO_ARGS);
2300 if (repl instanceof DatanodeInfo[]) {
2301 return ((DatanodeInfo[]) repl);
2302 }
2303 } catch (Exception e) {
2304 LOG.info("Get pipeline failed", e);
2305 }
2306 }
2307 return new DatanodeInfo[0];
2308 }
2309 }