1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19 package org.apache.hadoop.hbase.replication.regionserver;
20
21 import java.io.EOFException;
22 import java.io.FileNotFoundException;
23 import java.io.IOException;
24 import java.util.ArrayList;
25 import java.util.Collection;
26 import java.util.Comparator;
27 import java.util.HashMap;
28 import java.util.List;
29 import java.util.Map;
30 import java.util.UUID;
31 import java.util.concurrent.ConcurrentHashMap;
32 import java.util.concurrent.PriorityBlockingQueue;
33 import java.util.concurrent.TimeUnit;
34 import java.util.concurrent.atomic.AtomicLong;
35
36 import org.apache.commons.lang.StringUtils;
37 import org.apache.commons.logging.Log;
38 import org.apache.commons.logging.LogFactory;
39 import org.apache.hadoop.conf.Configuration;
40 import org.apache.hadoop.fs.FileStatus;
41 import org.apache.hadoop.fs.FileSystem;
42 import org.apache.hadoop.fs.Path;
43 import org.apache.hadoop.hbase.Cell;
44 import org.apache.hadoop.hbase.CellUtil;
45 import org.apache.hadoop.hbase.HBaseConfiguration;
46 import org.apache.hadoop.hbase.HConstants;
47 import org.apache.hadoop.hbase.Stoppable;
48 import org.apache.hadoop.hbase.TableName;
49 import org.apache.hadoop.hbase.classification.InterfaceAudience;
50 import org.apache.hadoop.hbase.protobuf.generated.WALProtos.BulkLoadDescriptor;
51 import org.apache.hadoop.hbase.protobuf.generated.WALProtos.StoreDescriptor;
52 import org.apache.hadoop.hbase.regionserver.RSRpcServices;
53 import org.apache.hadoop.hbase.regionserver.wal.WALEdit;
54 import org.apache.hadoop.hbase.replication.ChainWALEntryFilter;
55 import org.apache.hadoop.hbase.replication.ReplicationEndpoint;
56 import org.apache.hadoop.hbase.replication.ReplicationException;
57 import org.apache.hadoop.hbase.replication.ReplicationPeers;
58 import org.apache.hadoop.hbase.replication.ReplicationQueueInfo;
59 import org.apache.hadoop.hbase.replication.ReplicationQueues;
60 import org.apache.hadoop.hbase.replication.SystemTableWALEntryFilter;
61 import org.apache.hadoop.hbase.replication.WALEntryFilter;
62 import org.apache.hadoop.hbase.util.Bytes;
63 import org.apache.hadoop.hbase.util.CancelableProgressable;
64 import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
65 import org.apache.hadoop.hbase.util.FSUtils;
66 import org.apache.hadoop.hbase.util.LeaseNotRecoveredException;
67 import org.apache.hadoop.hbase.util.Threads;
68 import org.apache.hadoop.hbase.wal.DefaultWALProvider;
69 import org.apache.hadoop.hbase.wal.WAL;
70 import org.apache.hadoop.hbase.wal.WALKey;
71
72 import com.google.common.collect.Lists;
73 import com.google.common.util.concurrent.ListenableFuture;
74 import com.google.common.util.concurrent.Service;
75
76
77
78
79
80
81
82
83
84
85
86
87
88 @InterfaceAudience.Private
89 public class ReplicationSource extends Thread
90 implements ReplicationSourceInterface {
91
92 private static final Log LOG = LogFactory.getLog(ReplicationSource.class);
93
94
95 private Map<String, PriorityBlockingQueue<Path>> queues =
96 new HashMap<String, PriorityBlockingQueue<Path>>();
97
98 private int queueSizePerGroup;
99 private ReplicationQueues replicationQueues;
100 private ReplicationPeers replicationPeers;
101
102 private Configuration conf;
103 private ReplicationQueueInfo replicationQueueInfo;
104
105 private String peerId;
106
107 private ReplicationSourceManager manager;
108
109 private Stoppable stopper;
110
111 private long sleepForRetries;
112
113 private long replicationQueueSizeCapacity;
114
115 private int replicationQueueNbCapacity;
116 private FileSystem fs;
117
118 private UUID clusterId;
119
120 private UUID peerClusterId;
121
122 private AtomicLong totalReplicatedEdits = new AtomicLong(0);
123
124 private AtomicLong totalReplicatedOperations = new AtomicLong(0);
125
126 private String peerClusterZnode;
127
128 private int maxRetriesMultiplier;
129
130 private volatile boolean sourceRunning = false;
131
132 private MetricsSource metrics;
133
134 private int logQueueWarnThreshold;
135
136 private ReplicationEndpoint replicationEndpoint;
137
138 private WALEntryFilter walEntryFilter;
139
140 private ReplicationThrottler throttler;
141 private ConcurrentHashMap<String, ReplicationSourceWorkerThread> workerThreads =
142 new ConcurrentHashMap<String, ReplicationSourceWorkerThread>();
143
144 public enum WorkerState {
145 RUNNING,
146 STOPPED,
147 FINISHED
148 }
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163 @Override
164 public void init(final Configuration conf, final FileSystem fs,
165 final ReplicationSourceManager manager, final ReplicationQueues replicationQueues,
166 final ReplicationPeers replicationPeers, final Stoppable stopper,
167 final String peerClusterZnode, final UUID clusterId, ReplicationEndpoint replicationEndpoint,
168 final MetricsSource metrics)
169 throws IOException {
170 this.stopper = stopper;
171 this.conf = HBaseConfiguration.create(conf);
172 decorateConf();
173 this.replicationQueueSizeCapacity =
174 this.conf.getLong("replication.source.size.capacity", 1024*1024*64);
175 this.replicationQueueNbCapacity =
176 this.conf.getInt("replication.source.nb.capacity", 25000);
177 this.sleepForRetries =
178 this.conf.getLong("replication.source.sleepforretries", 1000);
179 this.maxRetriesMultiplier =
180 this.conf.getInt("replication.source.maxretriesmultiplier", 300);
181 this.queueSizePerGroup = this.conf.getInt("hbase.regionserver.maxlogs", 32);
182 long bandwidth = this.conf.getLong("replication.source.per.peer.node.bandwidth", 0);
183 this.throttler = new ReplicationThrottler((double)bandwidth/10.0);
184 this.replicationQueues = replicationQueues;
185 this.replicationPeers = replicationPeers;
186 this.manager = manager;
187 this.fs = fs;
188 this.metrics = metrics;
189 this.clusterId = clusterId;
190
191 this.peerClusterZnode = peerClusterZnode;
192 this.replicationQueueInfo = new ReplicationQueueInfo(peerClusterZnode);
193
194 this.peerId = this.replicationQueueInfo.getPeerId();
195 this.logQueueWarnThreshold = this.conf.getInt("replication.source.log.queue.warn", 2);
196 this.replicationEndpoint = replicationEndpoint;
197 }
198
199 private void decorateConf() {
200 String replicationCodec = this.conf.get(HConstants.REPLICATION_CODEC_CONF_KEY);
201 if (StringUtils.isNotEmpty(replicationCodec)) {
202 this.conf.set(HConstants.RPC_CODEC_CONF_KEY, replicationCodec);
203 }
204 }
205
206 @Override
207 public void enqueueLog(Path log) {
208 String logPrefix = DefaultWALProvider.getWALPrefixFromWALName(log.getName());
209 PriorityBlockingQueue<Path> queue = queues.get(logPrefix);
210 if (queue == null) {
211 queue = new PriorityBlockingQueue<Path>(queueSizePerGroup, new LogsComparator());
212 queues.put(logPrefix, queue);
213 if (this.sourceRunning) {
214
215
216
217 final ReplicationSourceWorkerThread worker =
218 new ReplicationSourceWorkerThread(logPrefix, queue, replicationQueueInfo, this);
219 ReplicationSourceWorkerThread extant = workerThreads.putIfAbsent(logPrefix, worker);
220 if (extant != null) {
221 LOG.debug("Someone has beat us to start a worker thread for wal group " + logPrefix);
222 } else {
223 LOG.debug("Starting up worker for wal group " + logPrefix);
224 worker.startup();
225 }
226 }
227 }
228 queue.put(log);
229 this.metrics.incrSizeOfLogQueue();
230
231 int queueSize = queue.size();
232 if (queueSize > this.logQueueWarnThreshold) {
233 LOG.warn("WAL group " + logPrefix + " queue size: " + queueSize
234 + " exceeds value of replication.source.log.queue.warn: " + logQueueWarnThreshold);
235 }
236 }
237
238 @Override
239 public void addHFileRefs(TableName tableName, byte[] family, List<String> files)
240 throws ReplicationException {
241 String peerId = peerClusterZnode;
242 if (peerId.contains("-")) {
243
244
245 peerId = peerClusterZnode.split("-")[0];
246 }
247 Map<TableName, List<String>> tableCFMap = replicationPeers.getPeer(peerId).getTableCFs();
248 if (tableCFMap != null) {
249 List<String> tableCfs = tableCFMap.get(tableName);
250 if (tableCFMap.containsKey(tableName)
251 && (tableCfs == null || tableCfs.contains(Bytes.toString(family)))) {
252 this.replicationQueues.addHFileRefs(peerId, files);
253 metrics.incrSizeOfHFileRefsQueue(files.size());
254 } else {
255 LOG.debug("HFiles will not be replicated belonging to the table " + tableName + " family "
256 + Bytes.toString(family) + " to peer id " + peerId);
257 }
258 } else {
259
260
261 this.replicationQueues.addHFileRefs(peerId, files);
262 metrics.incrSizeOfHFileRefsQueue(files.size());
263 }
264 }
265
266 private void uninitialize() {
267 LOG.debug("Source exiting " + this.peerId);
268 metrics.clear();
269 if (replicationEndpoint.state() == Service.State.STARTING
270 || replicationEndpoint.state() == Service.State.RUNNING) {
271 replicationEndpoint.stopAndWait();
272 }
273 }
274
275 @Override
276 public void run() {
277
278 this.sourceRunning = true;
279 try {
280
281 Service.State state = replicationEndpoint.start().get();
282 if (state != Service.State.RUNNING) {
283 LOG.warn("ReplicationEndpoint was not started. Exiting");
284 uninitialize();
285 return;
286 }
287 } catch (Exception ex) {
288 LOG.warn("Error starting ReplicationEndpoint, exiting", ex);
289 throw new RuntimeException(ex);
290 }
291
292
293 ArrayList<WALEntryFilter> filters = Lists.newArrayList(
294 (WALEntryFilter)new SystemTableWALEntryFilter());
295 WALEntryFilter filterFromEndpoint = this.replicationEndpoint.getWALEntryfilter();
296 if (filterFromEndpoint != null) {
297 filters.add(filterFromEndpoint);
298 }
299 this.walEntryFilter = new ChainWALEntryFilter(filters);
300
301 int sleepMultiplier = 1;
302
303 while (this.isSourceActive() && this.peerClusterId == null) {
304 this.peerClusterId = replicationEndpoint.getPeerUUID();
305 if (this.isSourceActive() && this.peerClusterId == null) {
306 if (sleepForRetries("Cannot contact the peer's zk ensemble", sleepMultiplier)) {
307 sleepMultiplier++;
308 }
309 }
310 }
311
312
313
314 if (clusterId.equals(peerClusterId) && !replicationEndpoint.canReplicateToSameCluster()) {
315 this.terminate("ClusterId " + clusterId + " is replicating to itself: peerClusterId "
316 + peerClusterId + " which is not allowed by ReplicationEndpoint:"
317 + replicationEndpoint.getClass().getName(), null, false);
318 this.manager.closeQueue(this);
319 return;
320 }
321 LOG.info("Replicating " + clusterId + " -> " + peerClusterId);
322
323 for (Map.Entry<String, PriorityBlockingQueue<Path>> entry : queues.entrySet()) {
324 String walGroupId = entry.getKey();
325 PriorityBlockingQueue<Path> queue = entry.getValue();
326 final ReplicationSourceWorkerThread worker =
327 new ReplicationSourceWorkerThread(walGroupId, queue, replicationQueueInfo, this);
328 ReplicationSourceWorkerThread extant = workerThreads.putIfAbsent(walGroupId, worker);
329 if (extant != null) {
330 LOG.debug("Someone has beat us to start a worker thread for wal group " + walGroupId);
331 } else {
332 LOG.debug("Starting up worker for wal group " + walGroupId);
333 worker.startup();
334 }
335 }
336 }
337
338
339
340
341
342
343
344 protected boolean sleepForRetries(String msg, int sleepMultiplier) {
345 try {
346 if (LOG.isTraceEnabled()) {
347 LOG.trace(msg + ", sleeping " + sleepForRetries + " times " + sleepMultiplier);
348 }
349 Thread.sleep(this.sleepForRetries * sleepMultiplier);
350 } catch (InterruptedException e) {
351 LOG.debug("Interrupted while sleeping between retries");
352 Thread.currentThread().interrupt();
353 }
354 return sleepMultiplier < maxRetriesMultiplier;
355 }
356
357
358
359
360
361
362 protected boolean isPeerEnabled() {
363 return this.replicationPeers.getStatusOfPeer(this.peerId);
364 }
365
366 @Override
367 public void startup() {
368 String n = Thread.currentThread().getName();
369 Thread.UncaughtExceptionHandler handler = new Thread.UncaughtExceptionHandler() {
370 @Override
371 public void uncaughtException(final Thread t, final Throwable e) {
372 LOG.error("Unexpected exception in ReplicationSource", e);
373 }
374 };
375 Threads
376 .setDaemonThreadRunning(this, n + ".replicationSource," + this.peerClusterZnode, handler);
377 }
378
379 @Override
380 public void terminate(String reason) {
381 terminate(reason, null);
382 }
383
384 @Override
385 public void terminate(String reason, Exception cause) {
386 terminate(reason, cause, true);
387 }
388
389 public void terminate(String reason, Exception cause, boolean join) {
390 if (cause == null) {
391 LOG.info("Closing source "
392 + this.peerClusterZnode + " because: " + reason);
393
394 } else {
395 LOG.error("Closing source " + this.peerClusterZnode
396 + " because an error occurred: " + reason, cause);
397 }
398 this.sourceRunning = false;
399 Collection<ReplicationSourceWorkerThread> workers = workerThreads.values();
400 for (ReplicationSourceWorkerThread worker : workers) {
401 worker.setWorkerState(WorkerState.STOPPED);
402 worker.interrupt();
403 }
404 ListenableFuture<Service.State> future = null;
405 if (this.replicationEndpoint != null) {
406 future = this.replicationEndpoint.stop();
407 }
408 if (join) {
409 for (ReplicationSourceWorkerThread worker : workers) {
410 Threads.shutdown(worker, this.sleepForRetries);
411 LOG.info("ReplicationSourceWorker " + worker.getName() + " terminated");
412 }
413 if (future != null) {
414 try {
415 future.get(sleepForRetries * maxRetriesMultiplier, TimeUnit.MILLISECONDS);
416 } catch (Exception e) {
417 LOG.warn("Got exception while waiting for endpoint to shutdown for replication source :"
418 + this.peerClusterZnode,
419 e);
420 }
421 }
422 }
423 }
424
425 @Override
426 public String getPeerClusterZnode() {
427 return this.peerClusterZnode;
428 }
429
430 @Override
431 public String getPeerClusterId() {
432 return this.peerId;
433 }
434
435 @Override
436 public Path getCurrentPath() {
437
438 for (ReplicationSourceWorkerThread worker : workerThreads.values()) {
439 if (worker.getCurrentPath() != null) return worker.getCurrentPath();
440 }
441 return null;
442 }
443
444 private boolean isSourceActive() {
445 return !this.stopper.isStopped() && this.sourceRunning;
446 }
447
448
449
450
451 public static class LogsComparator implements Comparator<Path> {
452
453 @Override
454 public int compare(Path o1, Path o2) {
455 return Long.compare(getTS(o1), getTS(o2));
456 }
457
458
459
460
461
462
463
464 private static long getTS(Path p) {
465 int tsIndex = p.getName().lastIndexOf('.') + 1;
466 return Long.parseLong(p.getName().substring(tsIndex));
467 }
468 }
469
470 @Override
471 public String getStats() {
472 StringBuilder sb = new StringBuilder();
473 sb.append("Total replicated edits: ").append(totalReplicatedEdits)
474 .append(", current progress: \n");
475 for (Map.Entry<String, ReplicationSourceWorkerThread> entry : workerThreads.entrySet()) {
476 String walGroupId = entry.getKey();
477 ReplicationSourceWorkerThread worker = entry.getValue();
478 long position = worker.getCurrentPosition();
479 Path currentPath = worker.getCurrentPath();
480 sb.append("walGroup [").append(walGroupId).append("]: ");
481 if (currentPath != null) {
482 sb.append("currently replicating from: ").append(currentPath).append(" at position: ")
483 .append(position).append("\n");
484 } else {
485 sb.append("no replication ongoing, waiting for new log");
486 }
487 }
488 return sb.toString();
489 }
490
491 @Override
492 public MetricsSource getSourceMetrics() {
493 return this.metrics;
494 }
495
496 public class ReplicationSourceWorkerThread extends Thread {
497 private ReplicationSource source;
498 private String walGroupId;
499 private PriorityBlockingQueue<Path> queue;
500 private ReplicationQueueInfo replicationQueueInfo;
501
502 private WAL.Reader reader;
503
504 private long lastLoggedPosition = -1;
505
506 private volatile Path currentPath;
507
508 private ReplicationWALReaderManager repLogReader;
509
510 private int currentNbOperations = 0;
511
512 private int currentSize = 0;
513
514 private WorkerState state;
515
516 private long currentNbHFiles = 0;
517
518
519 public ReplicationSourceWorkerThread(String walGroupId, PriorityBlockingQueue<Path> queue,
520 ReplicationQueueInfo replicationQueueInfo, ReplicationSource source) {
521 this.walGroupId = walGroupId;
522 this.queue = queue;
523 this.replicationQueueInfo = replicationQueueInfo;
524 this.repLogReader = new ReplicationWALReaderManager(fs, conf);
525 this.source = source;
526 }
527
528 @Override
529 public void run() {
530 setWorkerState(WorkerState.RUNNING);
531
532
533 if (this.replicationQueueInfo.isQueueRecovered()) {
534 try {
535 this.repLogReader.setPosition(replicationQueues.getLogPosition(peerClusterZnode,
536 this.queue.peek().getName()));
537 if (LOG.isTraceEnabled()) {
538 LOG.trace("Recovered queue started with log " + this.queue.peek() + " at position "
539 + this.repLogReader.getPosition());
540 }
541 } catch (ReplicationException e) {
542 terminate("Couldn't get the position of this recovered queue " + peerClusterZnode, e);
543 }
544 }
545 int sleepMultiplier = 1;
546
547 while (isWorkerActive()) {
548
549 if (!isPeerEnabled()) {
550 if (sleepForRetries("Replication is disabled", sleepMultiplier)) {
551 sleepMultiplier++;
552 }
553 continue;
554 }
555 Path oldPath = getCurrentPath();
556
557
558
559 boolean hasCurrentPath = getNextPath();
560 if (getCurrentPath() != null && oldPath == null) {
561 sleepMultiplier = 1;
562 }
563 if (!hasCurrentPath) {
564 if (sleepForRetries("No log to process", sleepMultiplier)) {
565 sleepMultiplier++;
566 }
567 continue;
568 }
569 boolean currentWALisBeingWrittenTo = false;
570
571
572
573
574
575
576
577
578 if (!this.replicationQueueInfo.isQueueRecovered() && queue.size() == 0) {
579 currentWALisBeingWrittenTo = true;
580 }
581
582 if (!openReader(sleepMultiplier)) {
583
584 sleepMultiplier = 1;
585 continue;
586 }
587
588
589 if (this.reader == null) {
590 if (sleepForRetries("Unable to open a reader", sleepMultiplier)) {
591 sleepMultiplier++;
592 }
593 continue;
594 }
595
596 boolean gotIOE = false;
597 currentNbOperations = 0;
598 currentNbHFiles = 0;
599 List<WAL.Entry> entries = new ArrayList<WAL.Entry>(1);
600 currentSize = 0;
601 try {
602 if (readAllEntriesToReplicateOrNextFile(currentWALisBeingWrittenTo, entries)) {
603 continue;
604 }
605 } catch (IOException ioe) {
606 LOG.warn(peerClusterZnode + " Got: ", ioe);
607 gotIOE = true;
608 if (ioe.getCause() instanceof EOFException) {
609
610 boolean considerDumping = false;
611 if (this.replicationQueueInfo.isQueueRecovered()) {
612 try {
613 FileStatus stat = fs.getFileStatus(this.currentPath);
614 if (stat.getLen() == 0) {
615 LOG.warn(peerClusterZnode + " Got EOF and the file was empty");
616 }
617 considerDumping = true;
618 } catch (IOException e) {
619 LOG.warn(peerClusterZnode + " Got while getting file size: ", e);
620 }
621 }
622
623 if (considerDumping &&
624 sleepMultiplier == maxRetriesMultiplier &&
625 processEndOfFile(false)) {
626 continue;
627 }
628 }
629 } finally {
630 try {
631 this.reader = null;
632 this.repLogReader.closeReader();
633 } catch (IOException e) {
634 gotIOE = true;
635 LOG.warn("Unable to finalize the tailing of a file", e);
636 }
637 }
638
639
640
641
642 if (isWorkerActive() && (gotIOE || entries.isEmpty())) {
643 if (this.lastLoggedPosition != this.repLogReader.getPosition()) {
644 manager.logPositionAndCleanOldLogs(this.currentPath,
645 peerClusterZnode, this.repLogReader.getPosition(),
646 this.replicationQueueInfo.isQueueRecovered(), currentWALisBeingWrittenTo);
647 this.lastLoggedPosition = this.repLogReader.getPosition();
648 }
649
650 if (!gotIOE) {
651 sleepMultiplier = 1;
652
653
654 metrics.setAgeOfLastShippedOp(EnvironmentEdgeManager.currentTime(), walGroupId);
655 }
656 if (sleepForRetries("Nothing to replicate", sleepMultiplier)) {
657 sleepMultiplier++;
658 }
659 continue;
660 }
661 sleepMultiplier = 1;
662 shipEdits(currentWALisBeingWrittenTo, entries);
663 }
664 if (replicationQueueInfo.isQueueRecovered() && getWorkerState() == WorkerState.FINISHED) {
665
666 synchronized (workerThreads) {
667 Threads.sleep(100);
668 boolean allOtherTaskDone = true;
669 for (ReplicationSourceWorkerThread worker : workerThreads.values()) {
670 if (!worker.equals(this) && worker.getWorkerState() != WorkerState.FINISHED) {
671 allOtherTaskDone = false;
672 break;
673 }
674 }
675 if (allOtherTaskDone) {
676 manager.closeRecoveredQueue(this.source);
677 LOG.info("Finished recovering queue " + peerClusterZnode
678 + " with the following stats: " + getStats());
679 }
680 }
681 }
682
683 if (state != WorkerState.FINISHED) {
684 setWorkerState(WorkerState.STOPPED);
685 }
686 }
687
688
689
690
691
692
693
694
695
696 protected boolean readAllEntriesToReplicateOrNextFile(boolean currentWALisBeingWrittenTo,
697 List<WAL.Entry> entries) throws IOException {
698 long seenEntries = 0;
699 if (LOG.isTraceEnabled()) {
700 LOG.trace("Seeking in " + this.currentPath + " at position "
701 + this.repLogReader.getPosition());
702 }
703 this.repLogReader.seek();
704 long positionBeforeRead = this.repLogReader.getPosition();
705 WAL.Entry entry = this.repLogReader.readNextAndSetPosition();
706 while (entry != null) {
707 metrics.incrLogEditsRead();
708 seenEntries++;
709
710
711 if (replicationEndpoint.canReplicateToSameCluster()
712 || !entry.getKey().getClusterIds().contains(peerClusterId)) {
713
714 entry = walEntryFilter.filter(entry);
715 WALEdit edit = null;
716 WALKey logKey = null;
717 if (entry != null) {
718 edit = entry.getEdit();
719 logKey = entry.getKey();
720 }
721
722 if (edit != null && edit.size() != 0) {
723
724 logKey.addClusterId(clusterId);
725 currentNbOperations += countDistinctRowKeys(edit);
726 entries.add(entry);
727 currentSize += entry.getEdit().heapSize();
728 currentSize += calculateTotalSizeOfStoreFiles(edit);
729 } else {
730 metrics.incrLogEditsFiltered();
731 }
732 }
733
734
735 if (currentSize >= replicationQueueSizeCapacity
736 || entries.size() >= replicationQueueNbCapacity) {
737 break;
738 }
739 try {
740 entry = this.repLogReader.readNextAndSetPosition();
741 } catch (IOException ie) {
742 LOG.debug("Break on IOE: " + ie.getMessage());
743 break;
744 }
745 }
746 metrics.incrLogReadInBytes(this.repLogReader.getPosition() - positionBeforeRead);
747 if (currentWALisBeingWrittenTo) {
748 return false;
749 }
750
751
752 return seenEntries == 0 && processEndOfFile(false);
753 }
754
755
756
757
758
759
760 private int calculateTotalSizeOfStoreFiles(WALEdit edit) {
761 List<Cell> cells = edit.getCells();
762 int totalStoreFilesSize = 0;
763
764 int totalCells = edit.size();
765 for (int i = 0; i < totalCells; i++) {
766 if (CellUtil.matchingQualifier(cells.get(i), WALEdit.BULK_LOAD)) {
767 try {
768 BulkLoadDescriptor bld = WALEdit.getBulkLoadDescriptor(cells.get(i));
769 List<StoreDescriptor> stores = bld.getStoresList();
770 int totalStores = stores.size();
771 for (int j = 0; j < totalStores; j++) {
772 totalStoreFilesSize += stores.get(j).getStoreFileSizeBytes();
773 }
774 } catch (IOException e) {
775 LOG.error("Failed to deserialize bulk load entry from wal edit. "
776 + "Size of HFiles part of cell will not be considered in replication "
777 + "request size calculation.", e);
778 }
779 }
780 }
781 return totalStoreFilesSize;
782 }
783
784 private void cleanUpHFileRefs(WALEdit edit) throws IOException {
785 String peerId = peerClusterZnode;
786 if (peerId.contains("-")) {
787
788
789 peerId = peerClusterZnode.split("-")[0];
790 }
791 List<Cell> cells = edit.getCells();
792 int totalCells = cells.size();
793 for (int i = 0; i < totalCells; i++) {
794 Cell cell = cells.get(i);
795 if (CellUtil.matchingQualifier(cell, WALEdit.BULK_LOAD)) {
796 BulkLoadDescriptor bld = WALEdit.getBulkLoadDescriptor(cell);
797 List<StoreDescriptor> stores = bld.getStoresList();
798 int totalStores = stores.size();
799 for (int j = 0; j < totalStores; j++) {
800 List<String> storeFileList = stores.get(j).getStoreFileList();
801 manager.cleanUpHFileRefs(peerId, storeFileList);
802 metrics.decrSizeOfHFileRefsQueue(storeFileList.size());
803 }
804 }
805 }
806 }
807
808
809
810
811
812 protected boolean getNextPath() {
813 try {
814 if (this.currentPath == null) {
815 this.currentPath = queue.poll(sleepForRetries, TimeUnit.MILLISECONDS);
816 metrics.decrSizeOfLogQueue();
817 if (this.currentPath != null) {
818
819 manager.cleanOldLogs(this.currentPath.getName(), peerClusterZnode,
820 this.replicationQueueInfo.isQueueRecovered());
821 if (LOG.isTraceEnabled()) {
822 LOG.trace("New log: " + this.currentPath);
823 }
824 }
825 }
826 } catch (InterruptedException e) {
827 LOG.warn("Interrupted while reading edits", e);
828 }
829 return this.currentPath != null;
830 }
831
832
833
834
835
836
837
838 protected boolean openReader(int sleepMultiplier) {
839 try {
840 try {
841 if (LOG.isTraceEnabled()) {
842 LOG.trace("Opening log " + this.currentPath);
843 }
844 this.reader = repLogReader.openReader(this.currentPath);
845 } catch (FileNotFoundException fnfe) {
846 if (this.replicationQueueInfo.isQueueRecovered()) {
847
848
849
850 List<String> deadRegionServers = this.replicationQueueInfo.getDeadRegionServers();
851 LOG.info("NB dead servers : " + deadRegionServers.size());
852 final Path walDir = FSUtils.getWALRootDir(conf);
853 for (String curDeadServerName : deadRegionServers) {
854 final Path deadRsDirectory = new Path(walDir,
855 DefaultWALProvider.getWALDirectoryName(curDeadServerName));
856 Path[] locs = new Path[] {
857 new Path(deadRsDirectory, currentPath.getName()),
858 new Path(deadRsDirectory.suffix(DefaultWALProvider.SPLITTING_EXT),
859 currentPath.getName()),
860 };
861 for (Path possibleLogLocation : locs) {
862 LOG.info("Possible location " + possibleLogLocation.toUri().toString());
863 if (manager.getFs().exists(possibleLogLocation)) {
864
865 LOG.info("Log " + this.currentPath + " still exists at " +
866 possibleLogLocation);
867
868
869 if (stopper instanceof ReplicationSyncUp.DummyServer) {
870
871 this.currentPath = possibleLogLocation;
872 this.openReader(sleepMultiplier);
873 }
874 return true;
875 }
876 }
877 }
878
879
880 if (stopper instanceof ReplicationSyncUp.DummyServer) {
881
882
883 FileStatus[] rss = fs.listStatus(manager.getLogDir());
884 for (FileStatus rs : rss) {
885 Path p = rs.getPath();
886 FileStatus[] logs = fs.listStatus(p);
887 for (FileStatus log : logs) {
888 p = new Path(p, log.getPath().getName());
889 if (p.getName().equals(currentPath.getName())) {
890 currentPath = p;
891 LOG.info("Log " + currentPath.getName() + " found at " + currentPath);
892
893 this.openReader(sleepMultiplier);
894 return true;
895 }
896 }
897 }
898 }
899
900
901
902
903
904
905
906
907 throw new IOException("File from recovered queue is " +
908 "nowhere to be found", fnfe);
909 } else {
910
911 Path archivedLogLocation =
912 new Path(manager.getOldLogDir(), currentPath.getName());
913 if (manager.getFs().exists(archivedLogLocation)) {
914 currentPath = archivedLogLocation;
915 LOG.info("Log " + this.currentPath + " was moved to " +
916 archivedLogLocation);
917
918 this.openReader(sleepMultiplier);
919
920 }
921
922 }
923 }
924 } catch (LeaseNotRecoveredException lnre) {
925
926 LOG.warn(peerClusterZnode + " Try to recover the WAL lease " + currentPath, lnre);
927 recoverLease(conf, currentPath);
928 this.reader = null;
929 } catch (IOException ioe) {
930 if (ioe instanceof EOFException && isCurrentLogEmpty()) return true;
931 LOG.warn(peerClusterZnode + " Got: ", ioe);
932 this.reader = null;
933 if (ioe.getCause() instanceof NullPointerException) {
934
935
936
937 LOG.warn("Got NPE opening reader, will retry.");
938 } else if (sleepMultiplier >= maxRetriesMultiplier
939 && conf.getBoolean("replication.source.eof.autorecovery", false)) {
940
941
942 LOG.warn("Waited too long for this file, considering dumping");
943 return !processEndOfFile(true);
944 }
945 }
946 return true;
947 }
948
949 private void recoverLease(final Configuration conf, final Path path) {
950 try {
951 final FileSystem dfs = FSUtils.getCurrentFileSystem(conf);
952 FSUtils fsUtils = FSUtils.getInstance(dfs, conf);
953 fsUtils.recoverFileLease(dfs, path, conf, new CancelableProgressable() {
954 @Override
955 public boolean progress() {
956 LOG.debug("recover WAL lease: " + path);
957 return isWorkerActive();
958 }
959 });
960 } catch (IOException e) {
961 LOG.warn("unable to recover lease for WAL: " + path, e);
962 }
963 }
964
965
966
967
968
969
970
971 private boolean isCurrentLogEmpty() {
972 return (this.repLogReader.getPosition() == 0 &&
973 !this.replicationQueueInfo.isQueueRecovered() && queue.size() == 0);
974 }
975
976
977
978
979
980
981
982 private int countDistinctRowKeys(WALEdit edit) {
983 List<Cell> cells = edit.getCells();
984 int distinctRowKeys = 1;
985 int totalHFileEntries = 0;
986 Cell lastCell = cells.get(0);
987
988 int totalCells = edit.size();
989 for (int i = 0; i < totalCells; i++) {
990
991 if (CellUtil.matchingQualifier(cells.get(i), WALEdit.BULK_LOAD)) {
992 try {
993 BulkLoadDescriptor bld = WALEdit.getBulkLoadDescriptor(cells.get(i));
994 List<StoreDescriptor> stores = bld.getStoresList();
995 int totalStores = stores.size();
996 for (int j = 0; j < totalStores; j++) {
997 totalHFileEntries += stores.get(j).getStoreFileList().size();
998 }
999 } catch (IOException e) {
1000 LOG.error("Failed to deserialize bulk load entry from wal edit. "
1001 + "Then its hfiles count will not be added into metric.");
1002 }
1003 }
1004
1005 if (!CellUtil.matchingRow(cells.get(i), lastCell)) {
1006 distinctRowKeys++;
1007 }
1008 lastCell = cells.get(i);
1009 }
1010 currentNbHFiles += totalHFileEntries;
1011 return distinctRowKeys + totalHFileEntries;
1012 }
1013
1014
1015
1016
1017
1018
1019 protected void shipEdits(boolean currentWALisBeingWrittenTo, List<WAL.Entry> entries) {
1020 int sleepMultiplier = 0;
1021 if (entries.isEmpty()) {
1022 LOG.warn("Was given 0 edits to ship");
1023 return;
1024 }
1025 while (isWorkerActive()) {
1026 try {
1027 if (throttler.isEnabled()) {
1028 long sleepTicks = throttler.getNextSleepInterval(currentSize);
1029 if (sleepTicks > 0) {
1030 try {
1031 if (LOG.isTraceEnabled()) {
1032 LOG.trace("To sleep " + sleepTicks + "ms for throttling control");
1033 }
1034 Thread.sleep(sleepTicks);
1035 } catch (InterruptedException e) {
1036 LOG.debug("Interrupted while sleeping for throttling control");
1037 Thread.currentThread().interrupt();
1038
1039
1040 continue;
1041 }
1042
1043 throttler.resetStartTick();
1044 }
1045 }
1046
1047
1048 ReplicationEndpoint.ReplicateContext replicateContext =
1049 new ReplicationEndpoint.ReplicateContext();
1050 replicateContext.setEntries(entries).setSize(currentSize);
1051 replicateContext.setWalGroupId(walGroupId);
1052
1053 long startTimeNs = System.nanoTime();
1054
1055 boolean replicated = replicationEndpoint.replicate(replicateContext);
1056 long endTimeNs = System.nanoTime();
1057
1058 if (!replicated) {
1059 continue;
1060 } else {
1061 sleepMultiplier = Math.max(sleepMultiplier - 1, 0);
1062 }
1063
1064 if (this.lastLoggedPosition != this.repLogReader.getPosition()) {
1065
1066 int size = entries.size();
1067 for (int i = 0; i < size; i++) {
1068 cleanUpHFileRefs(entries.get(i).getEdit());
1069
1070 TableName tableName = entries.get(i).getKey().getTablename();
1071 source.getSourceMetrics().setAgeOfLastShippedOpByTable(
1072 entries.get(i).getKey().getWriteTime(),
1073 tableName.getNameAsString());
1074 }
1075
1076 manager.logPositionAndCleanOldLogs(this.currentPath, peerClusterZnode,
1077 this.repLogReader.getPosition(), this.replicationQueueInfo.isQueueRecovered(),
1078 currentWALisBeingWrittenTo);
1079 this.lastLoggedPosition = this.repLogReader.getPosition();
1080 }
1081 if (throttler.isEnabled()) {
1082 throttler.addPushSize(currentSize);
1083 }
1084 totalReplicatedEdits.addAndGet(entries.size());
1085 totalReplicatedOperations.addAndGet(currentNbOperations);
1086
1087 metrics.shipBatch(currentNbOperations, currentSize, currentNbHFiles);
1088 metrics.setAgeOfLastShippedOp(entries.get(entries.size() - 1).getKey().getWriteTime(),
1089 walGroupId);
1090 if (LOG.isTraceEnabled()) {
1091 LOG.trace("Replicated " + totalReplicatedEdits + " entries in total, or "
1092 + totalReplicatedOperations + " operations in "
1093 + ((endTimeNs - startTimeNs) / 1000000) + " ms");
1094 }
1095 break;
1096 } catch (Exception ex) {
1097 LOG.warn(replicationEndpoint.getClass().getName() + " threw unknown exception:"
1098 + org.apache.hadoop.util.StringUtils.stringifyException(ex));
1099 if (sleepForRetries("ReplicationEndpoint threw exception", sleepMultiplier)) {
1100 sleepMultiplier++;
1101 }
1102 }
1103 }
1104 }
1105
1106
1107
1108
1109
1110
1111
1112 @edu.umd.cs.findbugs.annotations.SuppressWarnings(value = "DE_MIGHT_IGNORE",
1113 justification = "Yeah, this is how it works")
1114 protected boolean processEndOfFile(boolean dumpOnlyIfZeroLength) {
1115
1116 if (this.queue.size() != 0) {
1117
1118 final long trailerSize = this.repLogReader.currentTrailerSize();
1119 final long currentPosition = this.repLogReader.getPosition();
1120 FileStatus stat = null;
1121 try {
1122 stat = fs.getFileStatus(this.currentPath);
1123 } catch (IOException exception) {
1124 LOG.warn("Couldn't get file length information about log " + this.currentPath + ", it " + (trailerSize < 0 ? "was not" : "was") + " closed cleanly"
1125 + ", stats: " + getStats());
1126 metrics.incrUnknownFileLengthForClosedWAL();
1127 }
1128 if (stat != null) {
1129 if (trailerSize < 0) {
1130 if (currentPosition < stat.getLen()) {
1131 final long skippedBytes = stat.getLen() - currentPosition;
1132 LOG.info("Reached the end of WAL file '" + currentPath + "'. It was not closed cleanly, so we did not parse " + skippedBytes + " bytes of data.");
1133 metrics.incrUncleanlyClosedWALs();
1134 metrics.incrBytesSkippedInUncleanlyClosedWALs(skippedBytes);
1135 }
1136 } else if (currentPosition + trailerSize < stat.getLen()){
1137 LOG.warn("Processing end of WAL file '" + currentPath + "'. At position " + currentPosition + ", which is too far away from reported file length " + stat.getLen() +
1138 ". Restarting WAL reading (see HBASE-15983 for details). stats: " + getStats());
1139 repLogReader.setPosition(0);
1140 metrics.incrRestartedWALReading();
1141 metrics.incrRepeatedFileBytes(currentPosition);
1142 return false;
1143 }
1144 }
1145 if (LOG.isTraceEnabled()) {
1146 LOG.trace("Reached the end of log " + this.currentPath + ", stats: " + getStats()
1147 + ", and the length of the file is " + (stat == null ? "N/A" : stat.getLen()));
1148 }
1149 if (dumpOnlyIfZeroLength && stat.getLen() != 0) {
1150 return false;
1151 }
1152 this.currentPath = null;
1153 this.repLogReader.finishCurrentFile();
1154 this.reader = null;
1155 metrics.incrCompletedWAL();
1156 return true;
1157 } else if (this.replicationQueueInfo.isQueueRecovered()) {
1158 LOG.debug("Finished recovering queue for group " + walGroupId + " of peer "
1159 + peerClusterZnode);
1160 metrics.incrCompletedRecoveryQueue();
1161 setWorkerState(WorkerState.FINISHED);
1162 return true;
1163 }
1164 return false;
1165 }
1166
1167 public void startup() {
1168 String n = Thread.currentThread().getName();
1169 Thread.UncaughtExceptionHandler handler = new Thread.UncaughtExceptionHandler() {
1170 @Override
1171 public void uncaughtException(final Thread t, final Throwable e) {
1172 RSRpcServices.exitIfOOME(e);
1173 LOG.error("Unexpected exception in ReplicationSourceWorkerThread," + " currentPath="
1174 + getCurrentPath(), e);
1175 stopper.stop("Unexpected exception in ReplicationSourceWorkerThread");
1176 }
1177 };
1178 Threads.setDaemonThreadRunning(this, n + ".replicationSource." + walGroupId + ","
1179 + peerClusterZnode, handler);
1180 workerThreads.put(walGroupId, this);
1181 }
1182
1183 public Path getCurrentPath() {
1184 return this.currentPath;
1185 }
1186
1187 public long getCurrentPosition() {
1188 return this.repLogReader.getPosition();
1189 }
1190
1191 private boolean isWorkerActive() {
1192 return !stopper.isStopped() && state == WorkerState.RUNNING && !isInterrupted();
1193 }
1194
1195 private void terminate(String reason, Exception cause) {
1196 if (cause == null) {
1197 LOG.info("Closing worker for wal group " + this.walGroupId + " because: " + reason);
1198
1199 } else {
1200 LOG.error("Closing worker for wal group " + this.walGroupId
1201 + " because an error occurred: " + reason, cause);
1202 }
1203 setWorkerState(WorkerState.STOPPED);
1204 this.interrupt();
1205 Threads.shutdown(this, sleepForRetries);
1206 LOG.info("ReplicationSourceWorker " + this.getName() + " terminated");
1207 }
1208
1209
1210
1211
1212
1213 public void setWorkerState(WorkerState state) {
1214 this.state = state;
1215 }
1216
1217
1218
1219
1220
1221 public WorkerState getWorkerState() {
1222 return state;
1223 }
1224 }
1225 }