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.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
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125 @InterfaceAudience.Private
126 public class FSHLog implements WAL {
127
128
129
130
131
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 private static final Log LOG = LogFactory.getLog(FSHLog.class);
162
163 private static final int DEFAULT_SLOW_SYNC_TIME_MS = 100;
164
165 private static final int DEFAULT_WAL_SYNC_TIMEOUT_MS = 5 * 60 * 1000;
166
167
168
169
170
171
172
173
174
175 private final Disruptor<RingBufferTruck> disruptor;
176
177
178
179
180 private final ExecutorService appendExecutor;
181
182
183
184
185
186
187
188 private final RingBufferEventHandler ringBufferEventHandler;
189
190
191
192
193
194
195 private final ThreadLocal<SyncFuture> cachedSyncFutures;
196
197
198
199
200
201 private volatile long highestUnsyncedSequence = -1;
202
203
204
205
206
207
208 private final AtomicLong highestSyncedSequence = new AtomicLong(0);
209
210
211
212
213 protected final FileSystem fs;
214
215
216
217
218 private final Path fullPathLogDir;
219
220
221
222
223 private final Path fullPathArchiveDir;
224
225
226
227
228 private final PathFilter ourFiles;
229
230
231
232
233 private final String logFilePrefix;
234
235
236
237
238 private final String logFileSuffix;
239
240
241
242
243 private final String prefixPathStr;
244
245 private final WALCoprocessorHost coprocessorHost;
246
247
248
249
250 protected final Configuration conf;
251
252
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
273
274 private FSDataOutputStream hdfs_out;
275
276
277
278
279 private final int minTolerableReplication;
280
281 private final int slowSyncNs;
282
283 private final long walSyncTimeout;
284
285
286
287
288
289 private final AtomicInteger consecutiveLogRolls = new AtomicInteger(0);
290
291 private final int lowReplicationRollLimit;
292
293
294
295
296 private volatile boolean lowReplicationRollEnabled = true;
297
298
299
300
301
302
303 private SequenceIdAccounting sequenceIdAccounting = new SequenceIdAccounting();
304
305
306
307
308 volatile Writer writer;
309
310
311 private final DrainBarrier closeBarrier = new DrainBarrier();
312
313
314
315
316
317
318
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
326 private final AtomicLong filenum = new AtomicLong(-1);
327
328
329 private final AtomicInteger numEntries = new AtomicInteger(0);
330
331
332 private final long logrollsize;
333
334
335
336
337 private AtomicLong totalLogSize = new AtomicLong(0);
338
339
340
341
342
343
344 private final int maxLogs;
345
346
347 private final int closeErrorsTolerated;
348
349 private final AtomicInteger closeErrorCount = new AtomicInteger();
350
351
352 private volatile long lastTimeCheckLowReplication = EnvironmentEdgeManager.currentTime();
353
354
355
356
357
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
371
372
373 private NavigableMap<Path, Map<byte[], Long>> byWalRegionSequenceIds =
374 new ConcurrentSkipListMap<Path, Map<byte[], Long>>(LOG_NAME_COMPARATOR);
375
376
377
378
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
402
403
404
405
406
407
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
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
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
459 this.logFilePrefix =
460 prefix == null || prefix.isEmpty() ? "wal" : URLEncoder.encode(prefix, "UTF8");
461
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
467
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
478 final String fileNameString = fileName.toString();
479 if (!fileNameString.startsWith(prefixPathStr)) {
480 return false;
481 }
482 if (logFileSuffix.isEmpty()) {
483
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
501 if (listeners != null) {
502 for (WALActionsListener i: listeners) {
503 registerWALActionsListener(i);
504 }
505 }
506 this.coprocessorHost = new WALCoprocessorHost(this, conf);
507
508
509
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
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
546
547 String hostingThreadName = Thread.currentThread().getName();
548 this.appendExecutor = Executors.
549 newSingleThreadExecutor(Threads.getNamedThreadFactory(hostingThreadName + ".append"));
550
551
552
553
554 final int preallocatedEventCount =
555 this.conf.getInt("hbase.regionserver.wal.disruptor.event.count", 1024 * 16);
556
557
558 this.disruptor =
559 new Disruptor<RingBufferTruck>(RingBufferTruck.EVENT_FACTORY, preallocatedEventCount,
560 this.appendExecutor, ProducerType.MULTI, new BlockingWaitStrategy());
561
562
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
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
591
592
593 protected FileStatus[] getFiles() throws IOException {
594 return FSUtils.listStatus(fs, fullPathLogDir, ourFiles);
595 }
596
597
598
599
600
601
602
603
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
619
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
636 oldPath = computeFilename(currentFilenum);
637 }
638 return oldPath;
639 }
640
641
642
643
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
658
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
673
674
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
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
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
707 Writer nextWriter = this.createWriterInstance(newPath);
708 FSDataOutputStream nextHdfsOut = null;
709 if (nextWriter instanceof ProtobufLogWriter) {
710 nextHdfsOut = ((ProtobufLogWriter)nextWriter).getStream();
711
712
713 preemptiveSync((ProtobufLogWriter)nextWriter);
714 }
715 tellListenersAboutPreLogRoll(oldPath, newPath);
716
717 newPath = replaceWriter(oldPath, newPath, nextWriter, nextHdfsOut);
718 tellListenersAboutPostLogRoll(oldPath, newPath);
719
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
737
738
739
740
741 protected Writer createWriterInstance(final Path path) throws IOException {
742 return DefaultWALProvider.createWriter(conf, fs, path, false);
743 }
744
745
746
747
748
749 private void cleanOldLogs() throws IOException {
750 List<Path> logsToArchive = null;
751
752
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
773
774
775
776
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
800
801
802 @VisibleForTesting
803 protected void afterCreatingZigZagLatch() {}
804
805
806
807
808 @VisibleForTesting
809 protected void beforeWaitOnSafePoint() {};
810
811
812
813
814
815
816
817
818
819
820
821
822
823
824
825
826
827
828
829 Path replaceWriter(final Path oldPath, final Path newPath, Writer nextWriter,
830 final FSDataOutputStream nextHdfsOut)
831 throws IOException {
832
833
834
835
836
837 SyncFuture syncFuture = null;
838 SafePointZigZagLatch zigzagLatch = null;
839 long sequence = -1L;
840 if (this.ringBufferEventHandler != null) {
841
842
843
844
845
846
847
848
849 sequence = getSequenceOnRingBuffer();
850 zigzagLatch = this.ringBufferEventHandler.attainSafePoint();
851 }
852 afterCreatingZigZagLatch();
853 TraceScope scope = Trace.startSpan("FSHFile.replaceWriter");
854 try {
855
856
857
858
859
860 try {
861 if (zigzagLatch != null) {
862
863
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
870 if (isUnflushedEntries()) throw e;
871 LOG.warn("Failed sync-before-close but no outstanding appends; closing WAL: " +
872 e.getMessage());
873 }
874
875
876
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
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
919 if (zigzagLatch != null) {
920 zigzagLatch.releaseSafePoint();
921
922
923
924
925
926
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
954
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
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
973 if (!this.listeners.isEmpty()) {
974 for (WALActionsListener i : this.listeners) {
975 i.postLogArchive(p, newPath);
976 }
977 }
978 }
979
980
981
982
983
984
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
996
997
998
999 public Path getCurrentFileName() {
1000 return computeFilename(this.filenum.get());
1001 }
1002
1003
1004
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
1017
1018
1019
1020
1021
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
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
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
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
1077
1078
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
1091 if (this.appendExecutor != null) this.appendExecutor.shutdown();
1092
1093
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
1117
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
1139
1140
1141
1142
1143
1144
1145
1146
1147
1148
1149
1150
1151
1152 private class SyncRunner extends HasThread {
1153 private volatile long sequence;
1154
1155 private final BlockingQueue<SyncFuture> syncFutures;
1156 private volatile SyncFuture takeSyncFuture = null;
1157
1158
1159
1160
1161
1162
1163
1164
1165
1166
1167
1168 SyncRunner(final String name, final int maxHandlersCount) {
1169 super(name);
1170
1171
1172
1173
1174
1175
1176
1177
1178
1179
1180
1181
1182
1183 this.syncFutures = new LinkedBlockingQueue<SyncFuture>(maxHandlersCount * 3);
1184 }
1185
1186 void offer(final long sequence, final SyncFuture [] syncFutures, final int syncFutureCount) {
1187
1188 this.sequence = sequence;
1189 for (int i = 0; i < syncFutureCount; ++i) {
1190 this.syncFutures.add(syncFutures[i]);
1191 }
1192 }
1193
1194
1195
1196
1197
1198
1199
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
1205 return 1;
1206 }
1207
1208
1209
1210
1211
1212
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
1229
1230
1231 private long updateHighestSyncedSequence(long sequence) {
1232 long currentHighestSyncedSequence;
1233
1234 do {
1235 currentHighestSyncedSequence = highestSyncedSequence.get();
1236 if (currentHighestSyncedSequence >= sequence) {
1237
1238
1239 sequence = currentHighestSyncedSequence;
1240 break;
1241 }
1242 } while (!highestSyncedSequence.compareAndSet(currentHighestSyncedSequence, sequence));
1243 return sequence;
1244 }
1245
1246 boolean areSyncFuturesReleased() {
1247
1248
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
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
1271 long currentHighestSyncedSequence = highestSyncedSequence.get();
1272 if (currentSequence < currentHighestSyncedSequence) {
1273 syncCount += releaseSyncFuture(takeSyncFuture, currentHighestSyncedSequence, null);
1274
1275 continue;
1276 }
1277 break;
1278 }
1279
1280
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
1297 takeSyncFuture.setSpan(scope.detach());
1298
1299 syncCount += releaseSyncFuture(takeSyncFuture, currentSequence, lastException);
1300
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
1308 Thread.currentThread().interrupt();
1309 } catch (Throwable t) {
1310 LOG.warn("UNEXPECTED, continuing", t);
1311 }
1312 }
1313 }
1314 }
1315
1316
1317
1318
1319 public void checkLogRoll() {
1320
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
1339
1340 private boolean checkLowReplication() {
1341 boolean logRollNeeded = false;
1342 this.lastTimeCheckLowReplication = EnvironmentEdgeManager.currentTime();
1343
1344
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
1357
1358
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
1370
1371
1372 if (this.numEntries.get() <= 1) {
1373 return logRollNeeded;
1374 }
1375
1376
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
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
1419 try {
1420 syncFuture.get(walSyncTimeout);
1421 return syncFuture.getSpan();
1422 } catch (TimeoutIOException tioe) {
1423
1424
1425
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
1479
1480
1481
1482
1483
1484
1485
1486
1487
1488
1489 @VisibleForTesting
1490 int getLogReplication() {
1491 try {
1492
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
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
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
1542
1543 public int getNumRolledLogFiles() {
1544 return byWalRegionSequenceIds.size();
1545 }
1546
1547
1548
1549 public int getNumLogFiles() {
1550
1551 return getNumRolledLogFiles() + 1;
1552 }
1553
1554
1555
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
1609 return this.sequenceIdAccounting.getLowestSequenceId(encodedRegionName);
1610 }
1611
1612 @Override
1613 public long getEarliestMemstoreSeqNum(byte[] encodedRegionName, byte[] familyName) {
1614
1615
1616
1617
1618
1619
1620
1621
1622 return this.sequenceIdAccounting.getLowestSequenceId(encodedRegionName, familyName);
1623 }
1624
1625
1626
1627
1628
1629
1630
1631
1632
1633
1634
1635
1636
1637
1638
1639
1640
1641
1642
1643
1644
1645
1646
1647
1648
1649
1650
1651 static class SafePointZigZagLatch {
1652
1653
1654
1655 private volatile CountDownLatch safePointAttainedLatch = new CountDownLatch(1);
1656
1657
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
1669
1670
1671
1672
1673
1674
1675
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
1688
1689
1690
1691
1692 void safePointAttained() throws InterruptedException {
1693 this.safePointAttainedLatch.countDown();
1694 this.safePointReleasedLatch.await();
1695 }
1696
1697
1698
1699
1700
1701 void releaseSafePoint() {
1702 this.safePointReleasedLatch.countDown();
1703 }
1704
1705
1706
1707
1708 boolean isCocked() {
1709 return this.safePointAttainedLatch.getCount() > 0 &&
1710 this.safePointReleasedLatch.getCount() > 0;
1711 }
1712 }
1713
1714
1715
1716
1717
1718
1719
1720
1721
1722
1723
1724
1725
1726
1727
1728
1729
1730
1731
1732
1733
1734
1735
1736
1737 class RingBufferEventHandler implements EventHandler<RingBufferTruck>, LifecycleAware {
1738 private final SyncRunner [] syncRunners;
1739 private final SyncFuture [] syncFutures;
1740
1741
1742 private volatile int syncFuturesCount = 0;
1743 private volatile SafePointZigZagLatch zigzagLatch;
1744
1745
1746
1747
1748 private Exception exception = null;
1749
1750
1751
1752 private final Object safePointWaiter = new Object();
1753 private volatile boolean shutdown = false;
1754
1755
1756
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
1770 for (int i = 0; i < this.syncFuturesCount; i++) this.syncFutures[i].done(sequence, e);
1771 this.syncFuturesCount = 0;
1772 }
1773
1774
1775
1776
1777 private boolean isOutstandingSyncs() {
1778
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
1788 for (SyncRunner syncRunner: syncRunners) {
1789 if(syncRunner.isAlive() && !syncRunner.areSyncFuturesReleased()) {
1790 return true;
1791 }
1792 }
1793 return false;
1794 }
1795
1796 @Override
1797
1798 public void onEvent(final RingBufferTruck truck, final long sequence, boolean endOfBatch)
1799 throws Exception {
1800
1801
1802
1803
1804
1805
1806
1807
1808 try {
1809 if (truck.hasSyncFuturePayload()) {
1810 this.syncFutures[this.syncFuturesCount++] = truck.unloadSyncFuturePayload();
1811
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
1819 return;
1820 }
1821 append(entry);
1822 } catch (Exception e) {
1823
1824 this.exception = e;
1825
1826
1827
1828 cleanupOutstandingSyncsOnException(sequence,
1829 this.exception instanceof DamagedWALException ? this.exception
1830 : new DamagedWALException("On sync", this.exception));
1831
1832 return;
1833 } finally {
1834 assert scope == NullScope.INSTANCE || !scope.isDetached();
1835 scope.close();
1836 }
1837 } else {
1838
1839 cleanupOutstandingSyncsOnException(sequence,
1840 new IllegalStateException("Neither append nor sync"));
1841
1842 return;
1843 }
1844
1845
1846
1847 if (this.exception == null) {
1848
1849
1850 if (!endOfBatch || this.syncFuturesCount <= 0) return;
1851
1852
1853
1854
1855
1856
1857
1858
1859
1860 this.syncRunnerIndex = (this.syncRunnerIndex + 1) % this.syncRunners.length;
1861 try {
1862
1863
1864 this.syncRunners[this.syncRunnerIndex].offer(sequence, this.syncFutures,
1865 this.syncFuturesCount);
1866 } catch (Exception e) {
1867
1868 requestLogRoll();
1869 this.exception = new DamagedWALException("Failed offering sync", e);
1870 }
1871 }
1872
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
1893
1894
1895 private void attainSafePoint(final long currentSequence) {
1896 if (this.zigzagLatch == null || !this.zigzagLatch.isCocked()) return;
1897
1898 beforeWaitOnSafePoint();
1899 try {
1900
1901
1902
1903 while ((!this.shutdown && this.zigzagLatch.isCocked()
1904 && highestSyncedSequence.get() < currentSequence &&
1905
1906
1907 isOutstandingSyncs())
1908
1909 || isOutstandingSyncsFromRunners()) {
1910 synchronized (this.safePointWaiter) {
1911 this.safePointWaiter.wait(0, 1);
1912 }
1913 }
1914
1915
1916
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
1927
1928
1929
1930 void append(final FSWALEntry entry) throws Exception {
1931
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
1941
1942
1943 if (entry.getEdit().isEmpty()) {
1944 return;
1945 }
1946
1947
1948 if (!coprocessorHost.preWALWrite(entry.getHRegionInfo(), entry.getKey(),
1949 entry.getEdit())) {
1950 if (entry.getEdit().isReplay()) {
1951
1952 entry.getKey().setScopes(null);
1953 }
1954 }
1955 if (!listeners.isEmpty()) {
1956 for (WALActionsListener i: listeners) {
1957
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
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
1993
1994 @VisibleForTesting
1995 void atHeadOfRingBufferEventHandlerAppend() {
1996
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
2016
2017
2018
2019
2020
2021 public static void main(String[] args) throws IOException {
2022 if (args.length < 2) {
2023 usage();
2024 System.exit(-1);
2025 }
2026
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
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
2068
2069 public long getLastTimeCheckLowReplication() {
2070 return this.lastTimeCheckLowReplication;
2071 }
2072 }