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