1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19 package org.apache.hadoop.hbase.procedure2.store.wal;
20
21 import java.io.IOException;
22 import java.io.FileNotFoundException;
23 import java.util.concurrent.atomic.AtomicBoolean;
24 import java.util.concurrent.atomic.AtomicLong;
25 import java.util.concurrent.atomic.AtomicReference;
26 import java.util.concurrent.locks.Condition;
27 import java.util.concurrent.locks.ReentrantLock;
28 import java.util.concurrent.LinkedTransferQueue;
29 import java.util.concurrent.CopyOnWriteArrayList;
30 import java.util.concurrent.TimeUnit;
31 import java.util.Arrays;
32 import java.util.ArrayList;
33 import java.util.Collections;
34 import java.util.HashSet;
35 import java.util.Iterator;
36 import java.util.LinkedList;
37 import java.util.Set;
38
39 import org.apache.commons.logging.Log;
40 import org.apache.commons.logging.LogFactory;
41 import org.apache.hadoop.conf.Configuration;
42 import org.apache.hadoop.fs.FSDataOutputStream;
43 import org.apache.hadoop.fs.FileAlreadyExistsException;
44 import org.apache.hadoop.fs.FileStatus;
45 import org.apache.hadoop.fs.FileSystem;
46 import org.apache.hadoop.fs.Path;
47 import org.apache.hadoop.fs.PathFilter;
48 import org.apache.hadoop.hbase.classification.InterfaceAudience;
49 import org.apache.hadoop.hbase.classification.InterfaceStability;
50 import org.apache.hadoop.hbase.procedure2.Procedure;
51 import org.apache.hadoop.hbase.procedure2.store.ProcedureStore;
52 import org.apache.hadoop.hbase.procedure2.store.ProcedureStoreTracker;
53 import org.apache.hadoop.hbase.procedure2.util.ByteSlot;
54 import org.apache.hadoop.hbase.procedure2.util.StringUtils;
55 import org.apache.hadoop.hbase.protobuf.generated.ProcedureProtos.ProcedureWALHeader;
56 import org.apache.hadoop.hbase.util.Threads;
57 import org.apache.hadoop.ipc.RemoteException;
58
59 import com.google.common.annotations.VisibleForTesting;
60
61
62
63
64 @InterfaceAudience.Private
65 @InterfaceStability.Evolving
66 public class WALProcedureStore implements ProcedureStore {
67 private static final Log LOG = LogFactory.getLog(WALProcedureStore.class);
68
69 public interface LeaseRecovery {
70 void recoverFileLease(FileSystem fs, Path path) throws IOException;
71 }
72
73 private static final String MAX_RETRIES_BEFORE_ROLL_CONF_KEY =
74 "hbase.procedure.store.wal.max.retries.before.roll";
75 private static final int DEFAULT_MAX_RETRIES_BEFORE_ROLL = 3;
76
77 private static final String WAIT_BEFORE_ROLL_CONF_KEY =
78 "hbase.procedure.store.wal.wait.before.roll";
79 private static final int DEFAULT_WAIT_BEFORE_ROLL = 500;
80
81 private static final String ROLL_RETRIES_CONF_KEY =
82 "hbase.procedure.store.wal.max.roll.retries";
83 private static final int DEFAULT_ROLL_RETRIES = 3;
84
85 private static final String MAX_SYNC_FAILURE_ROLL_CONF_KEY =
86 "hbase.procedure.store.wal.sync.failure.roll.max";
87 private static final int DEFAULT_MAX_SYNC_FAILURE_ROLL = 3;
88
89 private static final String PERIODIC_ROLL_CONF_KEY =
90 "hbase.procedure.store.wal.periodic.roll.msec";
91 private static final int DEFAULT_PERIODIC_ROLL = 60 * 60 * 1000;
92
93 private static final String SYNC_WAIT_MSEC_CONF_KEY = "hbase.procedure.store.wal.sync.wait.msec";
94 private static final int DEFAULT_SYNC_WAIT_MSEC = 100;
95
96 private static final String USE_HSYNC_CONF_KEY = "hbase.procedure.store.wal.use.hsync";
97 private static final boolean DEFAULT_USE_HSYNC = true;
98
99 private static final String ROLL_THRESHOLD_CONF_KEY = "hbase.procedure.store.wal.roll.threshold";
100 private static final long DEFAULT_ROLL_THRESHOLD = 32 * 1024 * 1024;
101
102 private final CopyOnWriteArrayList<ProcedureStoreListener> listeners =
103 new CopyOnWriteArrayList<ProcedureStoreListener>();
104
105 private final LinkedList<ProcedureWALFile> logs = new LinkedList<ProcedureWALFile>();
106 private final ProcedureStoreTracker storeTracker = new ProcedureStoreTracker();
107 private final AtomicBoolean running = new AtomicBoolean(false);
108
109 private final ReentrantLock lock = new ReentrantLock();
110 private final Condition waitCond = lock.newCondition();
111 private final Condition slotCond = lock.newCondition();
112 private final Condition syncCond = lock.newCondition();
113
114 private final LeaseRecovery leaseRecovery;
115 private final Configuration conf;
116 private final FileSystem fs;
117 private final Path logDir;
118
119 private final AtomicReference<Throwable> syncException = new AtomicReference<Throwable>();
120 private final AtomicBoolean loading = new AtomicBoolean(true);
121 private final AtomicBoolean inSync = new AtomicBoolean(false);
122 private final AtomicLong totalSynced = new AtomicLong(0);
123 private final AtomicLong lastRollTs = new AtomicLong(0);
124
125 private LinkedTransferQueue<ByteSlot> slotsCache = null;
126 private Set<ProcedureWALFile> corruptedLogs = null;
127 private FSDataOutputStream stream = null;
128 private long flushLogId = 0;
129 private int slotIndex = 0;
130 private Thread syncThread;
131 private ByteSlot[] slots;
132
133 private int maxRetriesBeforeRoll;
134 private int maxSyncFailureRoll;
135 private int waitBeforeRoll;
136 private int rollRetries;
137 private int periodicRollMsec;
138 private long rollThreshold;
139 private boolean useHsync;
140 private int syncWaitMsec;
141
142 public WALProcedureStore(final Configuration conf, final FileSystem fs, final Path logDir,
143 final LeaseRecovery leaseRecovery) {
144 this.fs = fs;
145 this.conf = conf;
146 this.logDir = logDir;
147 this.leaseRecovery = leaseRecovery;
148 }
149
150 @Override
151 public void start(int numSlots) throws IOException {
152 if (running.getAndSet(true)) {
153 return;
154 }
155
156
157 loading.set(true);
158 slots = new ByteSlot[numSlots];
159 slotsCache = new LinkedTransferQueue();
160 while (slotsCache.size() < numSlots) {
161 slotsCache.offer(new ByteSlot());
162 }
163
164
165 maxRetriesBeforeRoll =
166 conf.getInt(MAX_RETRIES_BEFORE_ROLL_CONF_KEY, DEFAULT_MAX_RETRIES_BEFORE_ROLL);
167 maxSyncFailureRoll = conf.getInt(MAX_SYNC_FAILURE_ROLL_CONF_KEY, DEFAULT_MAX_SYNC_FAILURE_ROLL);
168 waitBeforeRoll = conf.getInt(WAIT_BEFORE_ROLL_CONF_KEY, DEFAULT_WAIT_BEFORE_ROLL);
169 rollRetries = conf.getInt(ROLL_RETRIES_CONF_KEY, DEFAULT_ROLL_RETRIES);
170 rollThreshold = conf.getLong(ROLL_THRESHOLD_CONF_KEY, DEFAULT_ROLL_THRESHOLD);
171 periodicRollMsec = conf.getInt(PERIODIC_ROLL_CONF_KEY, DEFAULT_PERIODIC_ROLL);
172 syncWaitMsec = conf.getInt(SYNC_WAIT_MSEC_CONF_KEY, DEFAULT_SYNC_WAIT_MSEC);
173 useHsync = conf.getBoolean(USE_HSYNC_CONF_KEY, DEFAULT_USE_HSYNC);
174
175
176 syncThread = new Thread("WALProcedureStoreSyncThread") {
177 @Override
178 public void run() {
179 try {
180 syncLoop();
181 } catch (Throwable e) {
182 LOG.error("Got an exception from the sync-loop", e);
183 if (!isSyncAborted()) {
184 sendAbortProcessSignal();
185 }
186 }
187 }
188 };
189 syncThread.start();
190 }
191
192 @Override
193 public void stop(boolean abort) {
194 if (!running.getAndSet(false)) {
195 return;
196 }
197
198 LOG.info("Stopping the WAL Procedure Store");
199 sendStopSignal();
200
201 if (!abort) {
202 try {
203 while (syncThread.isAlive()) {
204 sendStopSignal();
205 syncThread.join(250);
206 }
207 } catch (InterruptedException e) {
208 LOG.warn("join interrupted", e);
209 Thread.currentThread().interrupt();
210 }
211 }
212
213
214 closeStream();
215
216
217
218
219 for (ProcedureWALFile log: logs) {
220 log.close();
221 }
222 logs.clear();
223 }
224
225 private void sendStopSignal() {
226 if (lock.tryLock()) {
227 try {
228 waitCond.signalAll();
229 syncCond.signalAll();
230 } finally {
231 lock.unlock();
232 }
233 }
234 }
235
236 @Override
237 public boolean isRunning() {
238 return running.get();
239 }
240
241 @Override
242 public int getNumThreads() {
243 return slots == null ? 0 : slots.length;
244 }
245
246 public ProcedureStoreTracker getStoreTracker() {
247 return storeTracker;
248 }
249
250 public LinkedList<ProcedureWALFile> getActiveLogs() {
251 return logs;
252 }
253
254 public Set<ProcedureWALFile> getCorruptedLogs() {
255 return corruptedLogs;
256 }
257
258 @Override
259 public void registerListener(ProcedureStoreListener listener) {
260 this.listeners.add(listener);
261 }
262
263 @Override
264 public boolean unregisterListener(ProcedureStoreListener listener) {
265 return this.listeners.remove(listener);
266 }
267
268 @Override
269 public void recoverLease() throws IOException {
270 lock.lock();
271 try {
272 LOG.info("Starting WAL Procedure Store lease recovery");
273 FileStatus[] oldLogs = getLogFiles();
274 while (isRunning()) {
275
276 flushLogId = initOldLogs(oldLogs);
277
278
279 if (!rollWriter(flushLogId + 1)) {
280
281 LOG.debug("someone else has already created log " + flushLogId);
282 continue;
283 }
284
285
286 oldLogs = getLogFiles();
287 if (getMaxLogId(oldLogs) > flushLogId) {
288 if (LOG.isDebugEnabled()) {
289 LOG.debug("Someone else created new logs. Expected maxLogId < " + flushLogId);
290 }
291 logs.getLast().removeFile();
292 continue;
293 }
294
295 LOG.info("Lease acquired for flushLogId: " + flushLogId);
296 break;
297 }
298 } finally {
299 lock.unlock();
300 }
301 }
302
303 @Override
304 public Iterator<Procedure> load() throws IOException {
305 if (logs.isEmpty()) {
306 throw new RuntimeException("recoverLease() must be called before loading data");
307 }
308
309
310 if (logs.size() == 1) {
311 if (LOG.isDebugEnabled()) {
312 LOG.debug("No state logs to replay.");
313 }
314 loading.set(false);
315 return null;
316 }
317
318
319 final ArrayList<ProcedureWALFile> toRemove = new ArrayList<ProcedureWALFile>();
320 Iterator<ProcedureWALFile> it = logs.descendingIterator();
321 it.next();
322 try {
323 return ProcedureWALFormat.load(it, storeTracker, new ProcedureWALFormat.Loader() {
324 @Override
325 public void removeLog(ProcedureWALFile log) {
326 toRemove.add(log);
327 }
328
329 @Override
330 public void markCorruptedWAL(ProcedureWALFile log, IOException e) {
331 if (corruptedLogs == null) {
332 corruptedLogs = new HashSet<ProcedureWALFile>();
333 }
334 corruptedLogs.add(log);
335
336 }
337 });
338 } finally {
339 if (!toRemove.isEmpty()) {
340 for (ProcedureWALFile log: toRemove) {
341 removeLogFile(log);
342 }
343 }
344 loading.set(false);
345 }
346 }
347
348 @Override
349 public void insert(final Procedure proc, final Procedure[] subprocs) {
350 if (LOG.isTraceEnabled()) {
351 LOG.trace("Insert " + proc + ", subproc=" + Arrays.toString(subprocs));
352 }
353
354 ByteSlot slot = acquireSlot();
355 try {
356
357 long[] subProcIds = null;
358 if (subprocs != null) {
359 ProcedureWALFormat.writeInsert(slot, proc, subprocs);
360 subProcIds = new long[subprocs.length];
361 for (int i = 0; i < subprocs.length; ++i) {
362 subProcIds[i] = subprocs[i].getProcId();
363 }
364 } else {
365 assert !proc.hasParent();
366 ProcedureWALFormat.writeInsert(slot, proc);
367 }
368
369
370 pushData(PushType.INSERT, slot, proc.getProcId(), subProcIds);
371 } catch (IOException e) {
372
373
374 LOG.fatal("Unable to serialize one of the procedure: proc=" + proc +
375 ", subprocs=" + Arrays.toString(subprocs), e);
376 throw new RuntimeException(e);
377 } finally {
378 releaseSlot(slot);
379 }
380 }
381
382 @Override
383 public void update(final Procedure proc) {
384 if (LOG.isTraceEnabled()) {
385 LOG.trace("Update " + proc);
386 }
387
388 ByteSlot slot = acquireSlot();
389 try {
390
391 ProcedureWALFormat.writeUpdate(slot, proc);
392
393
394 pushData(PushType.UPDATE, slot, proc.getProcId(), null);
395 } catch (IOException e) {
396
397
398 LOG.fatal("Unable to serialize the procedure: " + proc, e);
399 throw new RuntimeException(e);
400 } finally {
401 releaseSlot(slot);
402 }
403 }
404
405 @Override
406 public void delete(final long procId) {
407 if (LOG.isTraceEnabled()) {
408 LOG.trace("Delete " + procId);
409 }
410
411 ByteSlot slot = acquireSlot();
412 try {
413
414 ProcedureWALFormat.writeDelete(slot, procId);
415
416
417 pushData(PushType.DELETE, slot, procId, null);
418 } catch (IOException e) {
419
420
421 LOG.fatal("Unable to serialize the procedure: " + procId, e);
422 throw new RuntimeException(e);
423 } finally {
424 releaseSlot(slot);
425 }
426 }
427
428 private ByteSlot acquireSlot() {
429 ByteSlot slot = slotsCache.poll();
430 return slot != null ? slot : new ByteSlot();
431 }
432
433 private void releaseSlot(final ByteSlot slot) {
434 slot.reset();
435 slotsCache.offer(slot);
436 }
437
438 private enum PushType { INSERT, UPDATE, DELETE };
439
440 private long pushData(final PushType type, final ByteSlot slot,
441 final long procId, final long[] subProcIds) {
442 if (!isRunning()) {
443 throw new RuntimeException("the store must be running before inserting data");
444 }
445 if (logs.isEmpty()) {
446 throw new RuntimeException("recoverLease() must be called before inserting data");
447 }
448
449 long logId = -1;
450 lock.lock();
451 try {
452
453 while (true) {
454 if (!isRunning()) {
455 throw new RuntimeException("store no longer running");
456 } else if (isSyncAborted()) {
457 throw new RuntimeException("sync aborted", syncException.get());
458 } else if (inSync.get()) {
459 syncCond.await();
460 } else if (slotIndex == slots.length) {
461 slotCond.signal();
462 syncCond.await();
463 } else {
464 break;
465 }
466 }
467
468 updateStoreTracker(type, procId, subProcIds);
469 slots[slotIndex++] = slot;
470 logId = flushLogId;
471
472
473 if (slotIndex == 1) {
474 waitCond.signal();
475 }
476
477
478 if (slotIndex == slots.length) {
479 waitCond.signal();
480 slotCond.signal();
481 }
482
483 syncCond.await();
484 } catch (InterruptedException e) {
485 Thread.currentThread().interrupt();
486 sendAbortProcessSignal();
487 throw new RuntimeException(e);
488 } finally {
489 lock.unlock();
490 if (isSyncAborted()) {
491 throw new RuntimeException("sync aborted", syncException.get());
492 }
493 }
494 return logId;
495 }
496
497 private void updateStoreTracker(final PushType type,
498 final long procId, final long[] subProcIds) {
499 switch (type) {
500 case INSERT:
501 if (subProcIds == null) {
502 storeTracker.insert(procId);
503 } else {
504 storeTracker.insert(procId, subProcIds);
505 }
506 break;
507 case UPDATE:
508 storeTracker.update(procId);
509 break;
510 case DELETE:
511 storeTracker.delete(procId);
512 break;
513 default:
514 throw new RuntimeException("invalid push type " + type);
515 }
516 }
517
518 private boolean isSyncAborted() {
519 return syncException.get() != null;
520 }
521
522 private void syncLoop() throws Throwable {
523 inSync.set(false);
524 lock.lock();
525 try {
526 while (isRunning()) {
527 try {
528
529 if (slotIndex == 0) {
530 if (!loading.get()) {
531 periodicRoll();
532 }
533
534 if (LOG.isTraceEnabled()) {
535 float rollTsSec = getMillisFromLastRoll() / 1000.0f;
536 LOG.trace(String.format("Waiting for data. flushed=%s (%s/sec)",
537 StringUtils.humanSize(totalSynced.get()),
538 StringUtils.humanSize(totalSynced.get() / rollTsSec)));
539 }
540
541 waitCond.await(getMillisToNextPeriodicRoll(), TimeUnit.MILLISECONDS);
542 if (slotIndex == 0) {
543
544 continue;
545 }
546 }
547
548
549 long syncWaitSt = System.currentTimeMillis();
550 if (slotIndex != slots.length) {
551 slotCond.await(syncWaitMsec, TimeUnit.MILLISECONDS);
552 }
553 long syncWaitMs = System.currentTimeMillis() - syncWaitSt;
554 if (LOG.isTraceEnabled() && (syncWaitMs > 10 || slotIndex < slots.length)) {
555 float rollSec = getMillisFromLastRoll() / 1000.0f;
556 LOG.trace(String.format("Sync wait %s, slotIndex=%s , totalSynced=%s (%s/sec)",
557 StringUtils.humanTimeDiff(syncWaitMs), slotIndex,
558 StringUtils.humanSize(totalSynced.get()),
559 StringUtils.humanSize(totalSynced.get() / rollSec)));
560 }
561
562 inSync.set(true);
563 totalSynced.addAndGet(syncSlots());
564 slotIndex = 0;
565 inSync.set(false);
566 } catch (InterruptedException e) {
567 Thread.currentThread().interrupt();
568 sendAbortProcessSignal();
569 syncException.compareAndSet(null, e);
570 throw e;
571 } catch (Throwable t) {
572 syncException.compareAndSet(null, t);
573 throw t;
574 } finally {
575 syncCond.signalAll();
576 }
577 }
578 } finally {
579 lock.unlock();
580 }
581 }
582
583 private long syncSlots() throws Throwable {
584 int retry = 0;
585 int logRolled = 0;
586 long totalSynced = 0;
587 do {
588 try {
589 totalSynced = syncSlots(stream, slots, 0, slotIndex);
590 break;
591 } catch (Throwable e) {
592 if (++retry >= maxRetriesBeforeRoll) {
593 if (logRolled >= maxSyncFailureRoll) {
594 LOG.error("Sync slots after log roll failed, abort.", e);
595 sendAbortProcessSignal();
596 throw e;
597 }
598
599 if (!rollWriterOrDie()) {
600 throw e;
601 }
602
603 logRolled++;
604 retry = 0;
605 }
606 }
607 } while (running.get());
608 return totalSynced;
609 }
610
611 protected long syncSlots(FSDataOutputStream stream, ByteSlot[] slots, int offset, int count)
612 throws IOException {
613 long totalSynced = 0;
614 for (int i = 0; i < count; ++i) {
615 ByteSlot data = slots[offset + i];
616 data.writeTo(stream);
617 totalSynced += data.size();
618 }
619
620 if (useHsync) {
621 stream.hsync();
622 } else {
623 stream.hflush();
624 }
625 sendPostSyncSignal();
626
627 if (LOG.isTraceEnabled()) {
628 LOG.trace("Sync slots=" + count + '/' + slots.length +
629 ", flushed=" + StringUtils.humanSize(totalSynced));
630 }
631 return totalSynced;
632 }
633
634 protected void sendPostSyncSignal() {
635 if (!this.listeners.isEmpty()) {
636 for (ProcedureStoreListener listener : this.listeners) {
637 listener.postSync();
638 }
639 }
640 }
641
642 private void sendAbortProcessSignal() {
643 if (!this.listeners.isEmpty()) {
644 for (ProcedureStoreListener listener : this.listeners) {
645 listener.abortProcess();
646 }
647 }
648 }
649
650 private boolean rollWriterOrDie() {
651 for (int i = 1; i <= rollRetries; ++i) {
652 try {
653 if (rollWriter()) {
654 return true;
655 }
656 } catch (IOException e) {
657 LOG.warn("Unable to roll the log, attempt=" + i, e);
658 Threads.sleepWithoutInterrupt(waitBeforeRoll);
659 }
660 }
661 LOG.fatal("Unable to roll the log");
662 sendAbortProcessSignal();
663 throw new RuntimeException("unable to roll the log");
664 }
665
666 private boolean tryRollWriter() {
667 try {
668 return rollWriter();
669 } catch (IOException e) {
670 LOG.warn("Unable to roll the log", e);
671 return false;
672 }
673 }
674
675 private long getMillisToNextPeriodicRoll() {
676 if (lastRollTs.get() > 0 && periodicRollMsec > 0) {
677 return periodicRollMsec - getMillisFromLastRoll();
678 }
679 return Long.MAX_VALUE;
680 }
681
682 private long getMillisFromLastRoll() {
683 return (System.currentTimeMillis() - lastRollTs.get());
684 }
685
686 @VisibleForTesting
687 protected void periodicRollForTesting() throws IOException {
688 lock.lock();
689 try {
690 periodicRoll();
691 } finally {
692 lock.unlock();
693 }
694 }
695
696 @VisibleForTesting
697 protected boolean rollWriterForTesting() throws IOException {
698 lock.lock();
699 try {
700 return rollWriter();
701 } finally {
702 lock.unlock();
703 }
704 }
705
706 private void periodicRoll() throws IOException {
707 if (storeTracker.isEmpty()) {
708 if (LOG.isTraceEnabled()) {
709 LOG.trace("no active procedures");
710 }
711 tryRollWriter();
712 removeAllLogs(flushLogId - 1);
713 } else {
714 if (storeTracker.isUpdated()) {
715 if (LOG.isTraceEnabled()) {
716 LOG.trace("all the active procedures are in the latest log");
717 }
718 removeAllLogs(flushLogId - 1);
719 }
720
721
722
723 if (totalSynced.get() > rollThreshold || getMillisToNextPeriodicRoll() <= 0) {
724 tryRollWriter();
725 }
726
727 removeInactiveLogs();
728 }
729 }
730
731 private boolean rollWriter() throws IOException {
732
733 if (!rollWriter(flushLogId + 1)) {
734 LOG.warn("someone else has already created log " + flushLogId);
735 return false;
736 }
737
738
739
740 if (getMaxLogId(getLogFiles()) > flushLogId) {
741 LOG.warn("Someone else created new logs. Expected maxLogId < " + flushLogId);
742 logs.getLast().removeFile();
743 return false;
744 }
745
746
747 return true;
748 }
749
750 private boolean rollWriter(final long logId) throws IOException {
751 assert logId > flushLogId : "logId=" + logId + " flushLogId=" + flushLogId;
752 assert lock.isHeldByCurrentThread() : "expected to be the lock owner. " + lock.isLocked();
753
754 ProcedureWALHeader header = ProcedureWALHeader.newBuilder()
755 .setVersion(ProcedureWALFormat.HEADER_VERSION)
756 .setType(ProcedureWALFormat.LOG_TYPE_STREAM)
757 .setMinProcId(storeTracker.getMinProcId())
758 .setLogId(logId)
759 .build();
760
761 FSDataOutputStream newStream = null;
762 Path newLogFile = null;
763 long startPos = -1;
764 newLogFile = getLogFilePath(logId);
765 try {
766 newStream = fs.create(newLogFile, false);
767 } catch (FileAlreadyExistsException e) {
768 LOG.error("Log file with id=" + logId + " already exists", e);
769 return false;
770 } catch (RemoteException re) {
771 LOG.warn("failed to create log file with id=" + logId, re);
772 return false;
773 }
774 try {
775 ProcedureWALFormat.writeHeader(newStream, header);
776 startPos = newStream.getPos();
777 } catch (IOException ioe) {
778 LOG.warn("Encountered exception writing header", ioe);
779 newStream.close();
780 return false;
781 }
782
783 closeStream();
784
785 storeTracker.resetUpdates();
786 stream = newStream;
787 flushLogId = logId;
788 totalSynced.set(0);
789 lastRollTs.set(System.currentTimeMillis());
790 logs.add(new ProcedureWALFile(fs, newLogFile, header, startPos));
791
792 if (LOG.isDebugEnabled()) {
793 LOG.debug("Roll new state log: " + logId);
794 }
795 return true;
796 }
797
798 private void closeStream() {
799 try {
800 if (stream != null) {
801 try {
802 ProcedureWALFile log = logs.getLast();
803 log.setProcIds(storeTracker.getUpdatedMinProcId(), storeTracker.getUpdatedMaxProcId());
804 ProcedureWALFormat.writeTrailer(stream, storeTracker);
805 } catch (IOException e) {
806 LOG.warn("Unable to write the trailer: " + e.getMessage());
807 }
808 stream.close();
809 }
810 } catch (IOException e) {
811 LOG.error("Unable to close the stream", e);
812 } finally {
813 stream = null;
814 }
815 }
816
817
818
819
820 private void removeInactiveLogs() {
821
822 while (logs.size() > 1) {
823 ProcedureWALFile log = logs.getFirst();
824 if (storeTracker.isTracking(log.getMinProcId(), log.getMaxProcId())) {
825 break;
826 }
827 removeLogFile(log);
828 }
829 }
830
831 private void removeAllLogs(long lastLogId) {
832 if (logs.size() <= 1) return;
833
834 if (LOG.isDebugEnabled()) {
835 LOG.debug("Remove all state logs with ID less than " + lastLogId);
836 }
837 while (logs.size() > 1) {
838 ProcedureWALFile log = logs.getFirst();
839 if (lastLogId < log.getLogId()) {
840 break;
841 }
842 removeLogFile(log);
843 }
844 }
845
846 private boolean removeLogFile(final ProcedureWALFile log) {
847 try {
848 if (LOG.isDebugEnabled()) {
849 LOG.debug("Remove log: " + log);
850 }
851 log.removeFile();
852 logs.remove(log);
853 LOG.info("Remove log: " + log);
854 LOG.info("Removed logs: " + logs);
855 if (logs.size() == 0) { LOG.error("Expected at least one log"); }
856 assert logs.size() > 0 : "expected at least one log";
857 } catch (IOException e) {
858 LOG.error("Unable to remove log: " + log, e);
859 return false;
860 }
861 return true;
862 }
863
864
865
866
867 public Path getLogDir() {
868 return this.logDir;
869 }
870
871 public FileSystem getFileSystem() {
872 return this.fs;
873 }
874
875 protected Path getLogFilePath(final long logId) throws IOException {
876 return new Path(logDir, String.format("state-%020d.log", logId));
877 }
878
879 private static long getLogIdFromName(final String name) {
880 int end = name.lastIndexOf(".log");
881 int start = name.lastIndexOf('-') + 1;
882 while (start < end) {
883 if (name.charAt(start) != '0')
884 break;
885 start++;
886 }
887 return Long.parseLong(name.substring(start, end));
888 }
889
890 private FileStatus[] getLogFiles() throws IOException {
891 try {
892 return fs.listStatus(logDir, new PathFilter() {
893 @Override
894 public boolean accept(Path path) {
895 String name = path.getName();
896 return name.startsWith("state-") && name.endsWith(".log");
897 }
898 });
899 } catch (FileNotFoundException e) {
900 LOG.warn("Log directory not found: " + e.getMessage());
901 return null;
902 }
903 }
904
905 private long getMaxLogId(final FileStatus[] logFiles) {
906 long maxLogId = 0;
907 if (logFiles != null && logFiles.length > 0) {
908 for (int i = 0; i < logFiles.length; ++i) {
909 maxLogId = Math.max(maxLogId, getLogIdFromName(logFiles[i].getPath().getName()));
910 }
911 }
912 return maxLogId;
913 }
914
915
916
917
918 private long initOldLogs(final FileStatus[] logFiles) throws IOException {
919 this.logs.clear();
920
921 long maxLogId = 0;
922 if (logFiles != null && logFiles.length > 0) {
923 for (int i = 0; i < logFiles.length; ++i) {
924 final Path logPath = logFiles[i].getPath();
925 leaseRecovery.recoverFileLease(fs, logPath);
926 maxLogId = Math.max(maxLogId, getLogIdFromName(logPath.getName()));
927
928 ProcedureWALFile log = initOldLog(logFiles[i]);
929 if (log != null) {
930 this.logs.add(log);
931 }
932 }
933 Collections.sort(this.logs);
934 initTrackerFromOldLogs();
935 }
936 return maxLogId;
937 }
938
939 private void initTrackerFromOldLogs() {
940
941 if (!logs.isEmpty()) {
942 ProcedureWALFile log = logs.getLast();
943 try {
944 log.readTracker(storeTracker);
945 } catch (IOException e) {
946 LOG.warn("Unable to read tracker for " + log + " - " + e.getMessage());
947
948 storeTracker.clear();
949 storeTracker.setPartialFlag(true);
950 }
951 }
952 }
953
954 private ProcedureWALFile initOldLog(final FileStatus logFile) throws IOException {
955 ProcedureWALFile log = new ProcedureWALFile(fs, logFile);
956 if (logFile.getLen() == 0) {
957 LOG.warn("Remove uninitialized log: " + logFile);
958 log.removeFile();
959 return null;
960 }
961 if (LOG.isDebugEnabled()) {
962 LOG.debug("Opening state-log: " + logFile);
963 }
964 try {
965 log.open();
966 } catch (ProcedureWALFormat.InvalidWALDataException e) {
967 LOG.warn("Remove uninitialized log: " + logFile, e);
968 log.removeFile();
969 return null;
970 } catch (IOException e) {
971 String msg = "Unable to read state log: " + logFile;
972 LOG.error(msg, e);
973 throw new IOException(msg, e);
974 }
975
976 if (log.isCompacted()) {
977 try {
978 log.readTrailer();
979 } catch (IOException e) {
980 LOG.warn("Unfinished compacted log: " + logFile, e);
981 log.removeFile();
982 return null;
983 }
984 }
985 return log;
986 }
987 }