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;
20
21 import com.google.common.annotations.VisibleForTesting;
22 import com.google.common.base.Preconditions;
23
24 import java.io.IOException;
25 import java.io.InputStream;
26 import java.io.OutputStream;
27 import java.util.ArrayList;
28 import java.util.Arrays;
29 import java.util.Collections;
30 import java.util.Iterator;
31 import java.util.List;
32 import java.util.Map;
33 import java.util.HashSet;
34 import java.util.concurrent.atomic.AtomicBoolean;
35 import java.util.concurrent.atomic.AtomicInteger;
36 import java.util.concurrent.atomic.AtomicLong;
37 import java.util.concurrent.locks.ReentrantLock;
38 import java.util.concurrent.ConcurrentHashMap;
39 import java.util.concurrent.CopyOnWriteArrayList;
40 import java.util.concurrent.TimeUnit;
41
42 import org.apache.commons.logging.Log;
43 import org.apache.commons.logging.LogFactory;
44 import org.apache.hadoop.conf.Configuration;
45 import org.apache.hadoop.hbase.HConstants;
46 import org.apache.hadoop.hbase.ProcedureInfo;
47 import org.apache.hadoop.hbase.classification.InterfaceAudience;
48 import org.apache.hadoop.hbase.classification.InterfaceStability;
49 import org.apache.hadoop.hbase.exceptions.IllegalArgumentIOException;
50 import org.apache.hadoop.hbase.procedure2.store.ProcedureStore;
51 import org.apache.hadoop.hbase.procedure2.store.ProcedureStore.ProcedureIterator;
52 import org.apache.hadoop.hbase.procedure2.util.StringUtils;
53 import org.apache.hadoop.hbase.procedure2.util.TimeoutBlockingQueue;
54 import org.apache.hadoop.hbase.procedure2.util.TimeoutBlockingQueue.TimeoutRetriever;
55 import org.apache.hadoop.hbase.protobuf.generated.ProcedureProtos.ProcedureState;
56 import org.apache.hadoop.hbase.security.User;
57 import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
58 import org.apache.hadoop.hbase.util.ForeignExceptionUtil;
59 import org.apache.hadoop.hbase.util.NonceKey;
60 import org.apache.hadoop.hbase.util.Pair;
61 import org.apache.hadoop.hbase.util.Threads;
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76 @InterfaceAudience.Private
77 @InterfaceStability.Evolving
78 public class ProcedureExecutor<TEnvironment> {
79 private static final Log LOG = LogFactory.getLog(ProcedureExecutor.class);
80
81 Testing testing = null;
82 public static class Testing {
83 protected boolean killBeforeStoreUpdate = false;
84 protected boolean toggleKillBeforeStoreUpdate = false;
85
86 protected boolean shouldKillBeforeStoreUpdate() {
87 final boolean kill = this.killBeforeStoreUpdate;
88 if (this.toggleKillBeforeStoreUpdate) {
89 this.killBeforeStoreUpdate = !kill;
90 LOG.warn("Toggle Kill before store update to: " + this.killBeforeStoreUpdate);
91 }
92 return kill;
93 }
94 }
95
96 public interface ProcedureExecutorListener {
97 void procedureLoaded(long procId);
98 void procedureAdded(long procId);
99 void procedureFinished(long procId);
100 }
101
102
103
104
105 private static class ProcedureTimeoutRetriever implements TimeoutRetriever<Procedure> {
106 @Override
107 public long getTimeout(Procedure proc) {
108 return proc.getTimeRemaining();
109 }
110
111 @Override
112 public TimeUnit getTimeUnit(Procedure proc) {
113 return TimeUnit.MILLISECONDS;
114 }
115 }
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132 private static class CompletedProcedureCleaner<TEnvironment> extends Procedure<TEnvironment> {
133 private static final Log LOG = LogFactory.getLog(CompletedProcedureCleaner.class);
134
135 private static final String CLEANER_INTERVAL_CONF_KEY = "hbase.procedure.cleaner.interval";
136 private static final int DEFAULT_CLEANER_INTERVAL = 30 * 1000;
137
138 private static final String EVICT_TTL_CONF_KEY = "hbase.procedure.cleaner.evict.ttl";
139 private static final int DEFAULT_EVICT_TTL = 15 * 60000;
140
141 private static final String EVICT_ACKED_TTL_CONF_KEY ="hbase.procedure.cleaner.acked.evict.ttl";
142 private static final int DEFAULT_ACKED_EVICT_TTL = 5 * 60000;
143
144 private final Map<Long, ProcedureInfo> completed;
145 private final Map<NonceKey, Long> nonceKeysToProcIdsMap;
146 private final ProcedureStore store;
147 private final Configuration conf;
148
149 public CompletedProcedureCleaner(final Configuration conf, final ProcedureStore store,
150 final Map<Long, ProcedureInfo> completedMap,
151 final Map<NonceKey, Long> nonceKeysToProcIdsMap) {
152
153 setTimeout(conf.getInt(CLEANER_INTERVAL_CONF_KEY, DEFAULT_CLEANER_INTERVAL));
154 this.completed = completedMap;
155 this.nonceKeysToProcIdsMap = nonceKeysToProcIdsMap;
156 this.store = store;
157 this.conf = conf;
158 }
159
160 public void periodicExecute(final TEnvironment env) {
161 if (completed.isEmpty()) {
162 if (LOG.isTraceEnabled()) {
163 LOG.trace("No completed procedures to cleanup.");
164 }
165 return;
166 }
167
168 final long evictTtl = conf.getInt(EVICT_TTL_CONF_KEY, DEFAULT_EVICT_TTL);
169 final long evictAckTtl = conf.getInt(EVICT_ACKED_TTL_CONF_KEY, DEFAULT_ACKED_EVICT_TTL);
170
171 final long now = EnvironmentEdgeManager.currentTime();
172 final Iterator<Map.Entry<Long, ProcedureInfo>> it = completed.entrySet().iterator();
173 final boolean isDebugEnabled = LOG.isDebugEnabled();
174 while (it.hasNext() && store.isRunning()) {
175 final Map.Entry<Long, ProcedureInfo> entry = it.next();
176 final ProcedureInfo procInfo = entry.getValue();
177
178
179 if ((procInfo.hasClientAckTime() && (now - procInfo.getClientAckTime()) >= evictAckTtl) ||
180 (now - procInfo.getLastUpdate()) >= evictTtl) {
181 if (isDebugEnabled) {
182 LOG.debug("Evict completed procedure: " + procInfo);
183 }
184 store.delete(entry.getKey());
185 it.remove();
186
187 NonceKey nonceKey = procInfo.getNonceKey();
188 if (nonceKey != null) {
189 nonceKeysToProcIdsMap.remove(nonceKey);
190 }
191 }
192 }
193 }
194
195 @Override
196 protected Procedure[] execute(final TEnvironment env) {
197 throw new UnsupportedOperationException();
198 }
199
200 @Override
201 protected void rollback(final TEnvironment env) {
202 throw new UnsupportedOperationException();
203 }
204
205 @Override
206 protected boolean abort(final TEnvironment env) {
207 throw new UnsupportedOperationException();
208 }
209
210 @Override
211 public void serializeStateData(final OutputStream stream) {
212 throw new UnsupportedOperationException();
213 }
214
215 @Override
216 public void deserializeStateData(final InputStream stream) {
217 throw new UnsupportedOperationException();
218 }
219 }
220
221
222
223
224
225
226 private final ConcurrentHashMap<Long, ProcedureInfo> completed =
227 new ConcurrentHashMap<Long, ProcedureInfo>();
228
229
230
231
232
233
234 private final ConcurrentHashMap<Long, RootProcedureState> rollbackStack =
235 new ConcurrentHashMap<Long, RootProcedureState>();
236
237
238
239
240
241 private final ConcurrentHashMap<Long, Procedure> procedures =
242 new ConcurrentHashMap<Long, Procedure>();
243
244
245
246
247
248 private ConcurrentHashMap<NonceKey, Long> nonceKeysToProcIdsMap =
249 new ConcurrentHashMap<NonceKey, Long>();
250
251
252
253
254
255 private final TimeoutBlockingQueue<Procedure> waitingTimeout =
256 new TimeoutBlockingQueue<Procedure>(new ProcedureTimeoutRetriever());
257
258
259
260
261 private final ProcedureRunnableSet runnables;
262
263
264 private final ReentrantLock submitLock = new ReentrantLock();
265 private final AtomicLong lastProcId = new AtomicLong(-1);
266
267 private final CopyOnWriteArrayList<ProcedureExecutorListener> listeners =
268 new CopyOnWriteArrayList<ProcedureExecutorListener>();
269
270 private final AtomicInteger activeExecutorCount = new AtomicInteger(0);
271 private final AtomicBoolean running = new AtomicBoolean(false);
272 private final TEnvironment environment;
273 private final ProcedureStore store;
274 private final Configuration conf;
275
276 private Thread[] threads;
277
278 public ProcedureExecutor(final Configuration conf, final TEnvironment environment,
279 final ProcedureStore store) {
280 this(conf, environment, store, new ProcedureSimpleRunQueue());
281 }
282
283 public ProcedureExecutor(final Configuration conf, final TEnvironment environment,
284 final ProcedureStore store, final ProcedureRunnableSet runqueue) {
285 this.environment = environment;
286 this.runnables = runqueue;
287 this.store = store;
288 this.conf = conf;
289 }
290
291 private void load(final boolean abortOnCorruption) throws IOException {
292 Preconditions.checkArgument(completed.isEmpty());
293 Preconditions.checkArgument(rollbackStack.isEmpty());
294 Preconditions.checkArgument(procedures.isEmpty());
295 Preconditions.checkArgument(waitingTimeout.isEmpty());
296 Preconditions.checkArgument(runnables.size() == 0);
297
298 store.load(new ProcedureStore.ProcedureLoader() {
299 @Override
300 public void setMaxProcId(long maxProcId) {
301 assert lastProcId.get() < 0 : "expected only one call to setMaxProcId()";
302 LOG.debug("load procedures maxProcId=" + maxProcId);
303 lastProcId.set(maxProcId);
304 }
305
306 @Override
307 public void load(ProcedureIterator procIter) throws IOException {
308 loadProcedures(procIter, abortOnCorruption);
309 }
310
311 @Override
312 public void handleCorrupted(ProcedureIterator procIter) throws IOException {
313 int corruptedCount = 0;
314 while (procIter.hasNext()) {
315 ProcedureInfo proc = procIter.nextAsProcedureInfo();
316 LOG.error("corrupted procedure: " + proc);
317 corruptedCount++;
318 }
319 if (abortOnCorruption && corruptedCount > 0) {
320 throw new IOException("found " + corruptedCount + " procedures on replay");
321 }
322 }
323 });
324 }
325
326 private void loadProcedures(final ProcedureIterator procIter,
327 final boolean abortOnCorruption) throws IOException {
328 final boolean isDebugEnabled = LOG.isDebugEnabled();
329
330
331 int runnablesCount = 0;
332 while (procIter.hasNext()) {
333 final NonceKey nonceKey;
334 final long procId;
335
336 if (procIter.isNextCompleted()) {
337 ProcedureInfo proc = procIter.nextAsProcedureInfo();
338 nonceKey = proc.getNonceKey();
339 procId = proc.getProcId();
340 completed.put(proc.getProcId(), proc);
341 if (isDebugEnabled) {
342 LOG.debug("The procedure is completed: " + proc);
343 }
344 } else {
345 Procedure proc = procIter.nextAsProcedure();
346 nonceKey = proc.getNonceKey();
347 procId = proc.getProcId();
348
349 if (!proc.hasParent()) {
350 assert !proc.isFinished() : "unexpected finished procedure";
351 rollbackStack.put(proc.getProcId(), new RootProcedureState());
352 }
353
354
355 proc.beforeReplay(getEnvironment());
356 procedures.put(proc.getProcId(), proc);
357
358 if (proc.getState() == ProcedureState.RUNNABLE) {
359 runnablesCount++;
360 }
361 }
362
363
364 if (nonceKey != null) {
365 nonceKeysToProcIdsMap.put(nonceKey, procId);
366 }
367 }
368
369
370 ArrayList<Procedure> runnableList = new ArrayList(runnablesCount);
371 HashSet<Procedure> waitingSet = null;
372 procIter.reset();
373 while (procIter.hasNext()) {
374 if (procIter.isNextCompleted()) {
375 procIter.skipNext();
376 continue;
377 }
378
379 Procedure proc = procIter.nextAsProcedure();
380 assert !(proc.isFinished() && !proc.hasParent()) : "unexpected completed proc=" + proc;
381
382 if (isDebugEnabled) {
383 LOG.debug(String.format("Loading procedure state=%s isFailed=%s: %s",
384 proc.getState(), proc.hasException(), proc));
385 }
386
387 Long rootProcId = getRootProcedureId(proc);
388 if (rootProcId == null) {
389
390 runnables.addBack(proc);
391 continue;
392 }
393
394 if (proc.hasParent() && !proc.isFinished()) {
395 Procedure parent = procedures.get(proc.getParentProcId());
396
397 if (parent != null) {
398 parent.incChildrenLatch();
399 }
400 }
401
402 RootProcedureState procStack = rollbackStack.get(rootProcId);
403 procStack.loadStack(proc);
404
405 switch (proc.getState()) {
406 case RUNNABLE:
407 runnableList.add(proc);
408 break;
409 case WAITING_TIMEOUT:
410 if (waitingSet == null) {
411 waitingSet = new HashSet<Procedure>();
412 }
413 waitingSet.add(proc);
414 break;
415 case FINISHED:
416 if (proc.hasException()) {
417
418 runnables.addBack(proc);
419 break;
420 }
421 case ROLLEDBACK:
422 case INITIALIZING:
423 String msg = "Unexpected " + proc.getState() + " state for " + proc;
424 LOG.error(msg);
425 throw new UnsupportedOperationException(msg);
426 default:
427 break;
428 }
429 }
430
431
432 int corruptedCount = 0;
433 Iterator<Map.Entry<Long, RootProcedureState>> itStack = rollbackStack.entrySet().iterator();
434 while (itStack.hasNext()) {
435 Map.Entry<Long, RootProcedureState> entry = itStack.next();
436 RootProcedureState procStack = entry.getValue();
437 if (procStack.isValid()) continue;
438
439 for (Procedure proc: procStack.getSubprocedures()) {
440 LOG.error("corrupted procedure: " + proc);
441 procedures.remove(proc.getProcId());
442 runnableList.remove(proc);
443 if (waitingSet != null) waitingSet.remove(proc);
444 corruptedCount++;
445 }
446 itStack.remove();
447 }
448
449 if (abortOnCorruption && corruptedCount > 0) {
450 throw new IOException("found " + corruptedCount + " procedures on replay");
451 }
452
453
454 if (!runnableList.isEmpty()) {
455
456
457 for (int i = runnableList.size() - 1; i >= 0; --i) {
458 Procedure proc = runnableList.get(i);
459 if (!proc.hasParent()) {
460 sendProcedureLoadedNotification(proc.getProcId());
461 }
462 if (proc.wasExecuted()) {
463 runnables.addFront(proc);
464 } else {
465
466 runnables.addBack(proc);
467 }
468 }
469 }
470 }
471
472
473
474
475
476
477
478
479
480
481
482 public void start(int numThreads, boolean abortOnCorruption) throws IOException {
483 if (running.getAndSet(true)) {
484 LOG.warn("Already running");
485 return;
486 }
487
488
489
490 threads = new Thread[numThreads + 1];
491 LOG.info("Starting procedure executor threads=" + threads.length);
492
493
494 for (int i = 0; i < numThreads; ++i) {
495 threads[i] = new Thread("ProcedureExecutor-" + i) {
496 @Override
497 public void run() {
498 execLoop();
499 }
500 };
501 }
502
503
504 threads[numThreads] = new Thread("ProcedureExecutorTimeout") {
505 @Override
506 public void run() {
507 timeoutLoop();
508 }
509 };
510
511
512 store.recoverLease();
513
514
515
516
517
518
519 load(abortOnCorruption);
520
521
522 for (int i = 0; i < threads.length; ++i) {
523 threads[i].start();
524 }
525
526
527 waitingTimeout.add(
528 new CompletedProcedureCleaner(conf, store, completed, nonceKeysToProcIdsMap));
529 }
530
531 public void stop() {
532 if (!running.getAndSet(false)) {
533 return;
534 }
535
536 LOG.info("Stopping the procedure executor");
537 runnables.signalAll();
538 waitingTimeout.signalAll();
539 }
540
541 public void join() {
542 boolean interrupted = false;
543
544 for (int i = 0; i < threads.length; ++i) {
545 try {
546 threads[i].join();
547 } catch (InterruptedException ex) {
548 interrupted = true;
549 }
550 }
551
552 if (interrupted) {
553 Thread.currentThread().interrupt();
554 }
555
556 completed.clear();
557 rollbackStack.clear();
558 procedures.clear();
559 nonceKeysToProcIdsMap.clear();
560 waitingTimeout.clear();
561 runnables.clear();
562 lastProcId.set(-1);
563 }
564
565 public boolean isRunning() {
566 return running.get();
567 }
568
569
570
571
572 public int getNumThreads() {
573 return threads == null ? 0 : (threads.length - 1);
574 }
575
576 public int getActiveExecutorCount() {
577 return activeExecutorCount.get();
578 }
579
580 public TEnvironment getEnvironment() {
581 return this.environment;
582 }
583
584 public ProcedureStore getStore() {
585 return this.store;
586 }
587
588 public void registerListener(ProcedureExecutorListener listener) {
589 this.listeners.add(listener);
590 }
591
592 public boolean unregisterListener(ProcedureExecutorListener listener) {
593 return this.listeners.remove(listener);
594 }
595
596
597
598
599
600 public List<ProcedureInfo> listProcedures() {
601 List<ProcedureInfo> procedureLists =
602 new ArrayList<ProcedureInfo>(procedures.size() + completed.size());
603 for (java.util.Map.Entry<Long, Procedure> p: procedures.entrySet()) {
604 procedureLists.add(Procedure.createProcedureInfo(p.getValue(), null));
605 }
606 for (java.util.Map.Entry<Long, ProcedureInfo> e: completed.entrySet()) {
607
608
609
610
611 procedureLists.add(e.getValue());
612 }
613 return procedureLists;
614 }
615
616
617
618
619
620
621
622
623
624
625 public NonceKey createNonceKey(final long nonceGroup, final long nonce) {
626 return (nonce == HConstants.NO_NONCE) ? null : new NonceKey(nonceGroup, nonce);
627 }
628
629
630
631
632
633
634
635
636
637
638
639
640 public long registerNonce(final NonceKey nonceKey) {
641 if (nonceKey == null) return -1;
642
643
644 Long oldProcId = nonceKeysToProcIdsMap.get(nonceKey);
645 if (oldProcId == null) {
646
647
648 final long newProcId = nextProcId();
649 oldProcId = nonceKeysToProcIdsMap.putIfAbsent(nonceKey, newProcId);
650 if (oldProcId == null) return -1;
651 }
652
653
654
655 final boolean isTraceEnabled = LOG.isTraceEnabled();
656 while (isRunning() &&
657 !(procedures.containsKey(oldProcId) || completed.containsKey(oldProcId)) &&
658 nonceKeysToProcIdsMap.containsKey(nonceKey)) {
659 if (isTraceEnabled) {
660 LOG.trace("waiting for procId=" + oldProcId.longValue() + " to be submitted");
661 }
662 Threads.sleep(100);
663 }
664 return oldProcId.longValue();
665 }
666
667
668
669
670
671 public void unregisterNonceIfProcedureWasNotSubmitted(final NonceKey nonceKey) {
672 if (nonceKey == null) return;
673
674 final Long procId = nonceKeysToProcIdsMap.get(nonceKey);
675 if (procId == null) return;
676
677
678 if (!(procedures.containsKey(procId) || completed.containsKey(procId))) {
679 nonceKeysToProcIdsMap.remove(nonceKey);
680 }
681 }
682
683
684
685
686
687
688
689
690
691
692 public void setFailureResultForNonce(final NonceKey nonceKey, final String procName,
693 final User procOwner, final IOException exception) {
694 if (nonceKey == null) return;
695
696 final Long procId = nonceKeysToProcIdsMap.get(nonceKey);
697 if (procId == null || completed.containsKey(procId)) return;
698
699 final long currentTime = EnvironmentEdgeManager.currentTime();
700 final ProcedureInfo result = new ProcedureInfo(
701 procId.longValue(),
702 procName,
703 procOwner != null ? procOwner.getShortName() : null,
704 ProcedureState.ROLLEDBACK,
705 -1,
706 nonceKey,
707 ForeignExceptionUtil.toProtoForeignException("ProcedureExecutor", exception),
708 currentTime,
709 currentTime,
710 null);
711 completed.putIfAbsent(procId, result);
712 }
713
714
715
716
717
718
719
720
721
722
723 public long submitProcedure(final Procedure proc) {
724 return submitProcedure(proc, null);
725 }
726
727
728
729
730
731
732
733 @edu.umd.cs.findbugs.annotations.SuppressWarnings(value="NP_NULL_ON_SOME_PATH",
734 justification = "FindBugs is blind to the check-for-null")
735 public long submitProcedure(final Procedure proc, final NonceKey nonceKey) {
736 Preconditions.checkArgument(proc.getState() == ProcedureState.INITIALIZING);
737 Preconditions.checkArgument(isRunning(), "executor not running");
738 Preconditions.checkArgument(lastProcId.get() >= 0);
739 Preconditions.checkArgument(!proc.hasParent(), "unexpected parent", proc);
740
741 final Long currentProcId;
742 if (nonceKey != null) {
743 currentProcId = nonceKeysToProcIdsMap.get(nonceKey);
744 Preconditions.checkArgument(currentProcId != null,
745 "expected nonceKey=" + nonceKey + " to be reserved, use registerNonce()");
746 } else {
747 currentProcId = nextProcId();
748 }
749
750
751 proc.setNonceKey(nonceKey);
752 proc.setProcId(currentProcId.longValue());
753
754
755 store.insert(proc, null);
756 if (LOG.isDebugEnabled()) {
757 LOG.debug("Procedure " + proc + " added to the store.");
758 }
759
760
761 RootProcedureState stack = new RootProcedureState();
762 rollbackStack.put(currentProcId, stack);
763
764
765 assert !procedures.containsKey(currentProcId);
766 procedures.put(currentProcId, proc);
767 sendProcedureAddedNotification(currentProcId);
768 runnables.addBack(proc);
769 return currentProcId;
770 }
771
772 public ProcedureInfo getResult(final long procId) {
773 return completed.get(procId);
774 }
775
776
777
778
779
780
781
782
783 public boolean isFinished(final long procId) {
784 return completed.containsKey(procId);
785 }
786
787
788
789
790
791
792 public boolean isStarted(final long procId) {
793 Procedure proc = procedures.get(procId);
794 if (proc == null) {
795 return completed.get(procId) != null;
796 }
797 return proc.wasExecuted();
798 }
799
800
801
802
803
804 public void removeResult(final long procId) {
805 ProcedureInfo result = completed.get(procId);
806 if (result == null) {
807 assert !procedures.containsKey(procId) : "procId=" + procId + " is still running";
808 if (LOG.isDebugEnabled()) {
809 LOG.debug("Procedure procId=" + procId + " already removed by the cleaner.");
810 }
811 return;
812 }
813
814
815 result.setClientAckTime(EnvironmentEdgeManager.currentTime());
816 }
817
818
819
820
821
822
823
824 public boolean abort(final long procId) {
825 return abort(procId, true);
826 }
827
828
829
830
831
832
833
834
835 public boolean abort(final long procId, final boolean mayInterruptIfRunning) {
836 Procedure proc = procedures.get(procId);
837 if (proc != null) {
838 if (!mayInterruptIfRunning && proc.wasExecuted()) {
839 return false;
840 } else {
841 return proc.abort(getEnvironment());
842 }
843 }
844 return false;
845 }
846
847
848
849
850
851
852
853
854 public boolean isProcedureOwner(final long procId, final User user) {
855 if (user == null) {
856 return false;
857 }
858
859 Procedure proc = procedures.get(procId);
860 if (proc != null) {
861 return proc.getOwner().equals(user.getShortName());
862 }
863 ProcedureInfo procInfo = completed.get(procId);
864 if (procInfo == null) {
865
866
867 return false;
868 }
869 return ProcedureInfo.isProcedureOwner(procInfo, user);
870 }
871
872 public Map<Long, ProcedureInfo> getResults() {
873 return Collections.unmodifiableMap(completed);
874 }
875
876 public Procedure getProcedure(final long procId) {
877 return procedures.get(procId);
878 }
879
880 protected ProcedureRunnableSet getRunnableSet() {
881 return runnables;
882 }
883
884
885
886
887
888
889 private void execLoop() {
890 while (isRunning()) {
891 Procedure proc = runnables.poll();
892 if (proc == null) continue;
893
894 try {
895 activeExecutorCount.incrementAndGet();
896 execLoop(proc);
897 } finally {
898 activeExecutorCount.decrementAndGet();
899 }
900 }
901 }
902
903 private void execLoop(Procedure proc) {
904 if (LOG.isTraceEnabled()) {
905 LOG.trace("Trying to start the execution of " + proc);
906 }
907
908 Long rootProcId = getRootProcedureId(proc);
909 if (rootProcId == null) {
910
911 executeRollback(proc);
912 return;
913 }
914
915 RootProcedureState procStack = rollbackStack.get(rootProcId);
916 if (procStack == null) return;
917
918 do {
919
920 if (!procStack.acquire(proc)) {
921 if (procStack.setRollback()) {
922
923 if (!executeRollback(rootProcId, procStack)) {
924 procStack.unsetRollback();
925 runnables.yield(proc);
926 }
927 } else {
928
929
930
931 if (!proc.wasExecuted()) {
932 if (!executeRollback(proc)) {
933 runnables.yield(proc);
934 }
935 }
936 }
937 break;
938 }
939
940
941 assert proc.getState() == ProcedureState.RUNNABLE;
942 if (proc.acquireLock(getEnvironment())) {
943 execProcedure(procStack, proc);
944 proc.releaseLock(getEnvironment());
945 } else {
946 runnables.yield(proc);
947 }
948 procStack.release(proc);
949
950
951
952 if (testing != null && !isRunning()) {
953 break;
954 }
955
956 if (proc.isSuccess()) {
957 if (LOG.isDebugEnabled()) {
958 LOG.debug("Procedure completed in " +
959 StringUtils.humanTimeDiff(proc.elapsedTime()) + ": " + proc);
960 }
961
962 if (proc.getProcId() == rootProcId) {
963 procedureFinished(proc);
964 }
965 break;
966 }
967 } while (procStack.isFailed());
968 }
969
970 private void timeoutLoop() {
971 while (isRunning()) {
972 Procedure proc = waitingTimeout.poll();
973 if (proc == null) continue;
974
975 if (proc.getTimeRemaining() > 100) {
976
977
978 waitingTimeout.add(proc);
979 continue;
980 }
981
982
983
984
985
986
987
988
989
990
991
992
993 if (proc instanceof CompletedProcedureCleaner) {
994 try {
995 ((CompletedProcedureCleaner)proc).periodicExecute(getEnvironment());
996 } catch (Throwable e) {
997 LOG.error("Ignoring CompletedProcedureCleaner exception: " + e.getMessage(), e);
998 }
999 proc.setStartTime(EnvironmentEdgeManager.currentTime());
1000 waitingTimeout.add(proc);
1001 continue;
1002 }
1003
1004
1005
1006 if (proc.setTimeoutFailure()) {
1007 long rootProcId = Procedure.getRootProcedureId(procedures, proc);
1008 RootProcedureState procStack = rollbackStack.get(rootProcId);
1009 procStack.abort();
1010 store.update(proc);
1011 runnables.addFront(proc);
1012 continue;
1013 }
1014 }
1015 }
1016
1017
1018
1019
1020
1021
1022 private boolean executeRollback(final long rootProcId, final RootProcedureState procStack) {
1023 Procedure rootProc = procedures.get(rootProcId);
1024 RemoteProcedureException exception = rootProc.getException();
1025 if (exception == null) {
1026 exception = procStack.getException();
1027 rootProc.setFailure(exception);
1028 store.update(rootProc);
1029 }
1030
1031 List<Procedure> subprocStack = procStack.getSubprocedures();
1032 assert subprocStack != null : "Called rollback with no steps executed rootProc=" + rootProc;
1033
1034 int stackTail = subprocStack.size();
1035 boolean reuseLock = false;
1036 while (stackTail --> 0) {
1037 final Procedure proc = subprocStack.get(stackTail);
1038
1039 if (!reuseLock && !proc.acquireLock(getEnvironment())) {
1040
1041
1042 return false;
1043 }
1044
1045 boolean abortRollback = !executeRollback(proc);
1046 abortRollback |= !isRunning() || !store.isRunning();
1047
1048
1049
1050
1051 reuseLock = stackTail > 0 && (subprocStack.get(stackTail - 1) == proc) && !abortRollback;
1052 if (!reuseLock) {
1053 proc.releaseLock(getEnvironment());
1054 }
1055
1056
1057
1058 if (abortRollback) {
1059 return false;
1060 }
1061
1062 subprocStack.remove(stackTail);
1063
1064
1065 if (proc.isYieldAfterExecutionStep(getEnvironment())) {
1066 return false;
1067 }
1068 }
1069
1070
1071 LOG.info("Rolledback procedure " + rootProc +
1072 " exec-time=" + StringUtils.humanTimeDiff(rootProc.elapsedTime()) +
1073 " exception=" + exception.getMessage());
1074 procedureFinished(rootProc);
1075 return true;
1076 }
1077
1078
1079
1080
1081
1082
1083 private boolean executeRollback(final Procedure proc) {
1084 try {
1085 proc.doRollback(getEnvironment());
1086 } catch (IOException e) {
1087 if (LOG.isDebugEnabled()) {
1088 LOG.debug("rollback attempt failed for " + proc, e);
1089 }
1090 return false;
1091 } catch (InterruptedException e) {
1092 handleInterruptedException(proc, e);
1093 return false;
1094 } catch (Throwable e) {
1095
1096 LOG.fatal("CODE-BUG: Uncatched runtime exception for procedure: " + proc, e);
1097 }
1098
1099
1100
1101 if (testing != null && testing.shouldKillBeforeStoreUpdate()) {
1102 LOG.debug("TESTING: Kill before store update");
1103 stop();
1104 return false;
1105 }
1106
1107 if (proc.removeStackIndex()) {
1108 proc.setState(ProcedureState.ROLLEDBACK);
1109 if (proc.hasParent()) {
1110 store.delete(proc.getProcId());
1111 procedures.remove(proc.getProcId());
1112 } else {
1113 store.update(proc);
1114 }
1115 } else {
1116 store.update(proc);
1117 }
1118
1119 return true;
1120 }
1121
1122
1123
1124
1125
1126
1127
1128
1129
1130
1131
1132
1133
1134
1135
1136
1137
1138
1139 private void execProcedure(final RootProcedureState procStack, final Procedure procedure) {
1140 Preconditions.checkArgument(procedure.getState() == ProcedureState.RUNNABLE);
1141
1142
1143 boolean reExecute = false;
1144 Procedure[] subprocs = null;
1145 do {
1146 reExecute = false;
1147 try {
1148 subprocs = procedure.doExecute(getEnvironment());
1149 if (subprocs != null && subprocs.length == 0) {
1150 subprocs = null;
1151 }
1152 } catch (ProcedureYieldException e) {
1153 if (LOG.isTraceEnabled()) {
1154 LOG.trace("Yield procedure: " + procedure + ": " + e.getMessage());
1155 }
1156 runnables.yield(procedure);
1157 return;
1158 } catch (InterruptedException e) {
1159 handleInterruptedException(procedure, e);
1160 runnables.yield(procedure);
1161 return;
1162 } catch (Throwable e) {
1163
1164 String msg = "CODE-BUG: Uncatched runtime exception for procedure: " + procedure;
1165 LOG.error(msg, e);
1166 procedure.setFailure(new RemoteProcedureException(msg, e));
1167 }
1168
1169 if (!procedure.isFailed()) {
1170 if (subprocs != null) {
1171 if (subprocs.length == 1 && subprocs[0] == procedure) {
1172
1173 subprocs = null;
1174 reExecute = true;
1175 } else {
1176
1177 for (int i = 0; i < subprocs.length; ++i) {
1178 Procedure subproc = subprocs[i];
1179 if (subproc == null) {
1180 String msg = "subproc[" + i + "] is null, aborting the procedure";
1181 procedure.setFailure(new RemoteProcedureException(msg,
1182 new IllegalArgumentIOException(msg)));
1183 subprocs = null;
1184 break;
1185 }
1186
1187 assert subproc.getState() == ProcedureState.INITIALIZING;
1188 subproc.setParentProcId(procedure.getProcId());
1189 subproc.setProcId(nextProcId());
1190 }
1191
1192 if (!procedure.isFailed()) {
1193 procedure.setChildrenLatch(subprocs.length);
1194 switch (procedure.getState()) {
1195 case RUNNABLE:
1196 procedure.setState(ProcedureState.WAITING);
1197 break;
1198 case WAITING_TIMEOUT:
1199 waitingTimeout.add(procedure);
1200 break;
1201 default:
1202 break;
1203 }
1204 }
1205 }
1206 } else if (procedure.getState() == ProcedureState.WAITING_TIMEOUT) {
1207 waitingTimeout.add(procedure);
1208 } else {
1209
1210 procedure.setState(ProcedureState.FINISHED);
1211 }
1212 }
1213
1214
1215 procStack.addRollbackStep(procedure);
1216
1217
1218
1219 if (testing != null && testing.shouldKillBeforeStoreUpdate()) {
1220 LOG.debug("TESTING: Kill before store update");
1221 stop();
1222 return;
1223 }
1224
1225
1226 if (subprocs != null && !procedure.isFailed()) {
1227 if (LOG.isTraceEnabled()) {
1228 LOG.trace("Store add " + procedure + " children " + Arrays.toString(subprocs));
1229 }
1230 store.insert(procedure, subprocs);
1231 } else {
1232 if (LOG.isTraceEnabled()) {
1233 LOG.trace("Store update " + procedure);
1234 }
1235 store.update(procedure);
1236 }
1237
1238
1239 if (!store.isRunning()) {
1240 return;
1241 }
1242
1243
1244 if (procedure.getState() == ProcedureState.RUNNABLE &&
1245 procedure.isYieldAfterExecutionStep(getEnvironment())) {
1246 runnables.yield(procedure);
1247 return;
1248 }
1249
1250 assert (reExecute && subprocs == null) || !reExecute;
1251 } while (reExecute);
1252
1253
1254 if (subprocs != null && !procedure.isFailed()) {
1255 for (int i = 0; i < subprocs.length; ++i) {
1256 Procedure subproc = subprocs[i];
1257 assert !procedures.containsKey(subproc.getProcId());
1258 procedures.put(subproc.getProcId(), subproc);
1259 runnables.addFront(subproc);
1260 }
1261 }
1262
1263 if (procedure.isFinished() && procedure.hasParent()) {
1264 Procedure parent = procedures.get(procedure.getParentProcId());
1265 if (parent == null) {
1266 assert procStack.isRollingback();
1267 return;
1268 }
1269
1270
1271 if (LOG.isTraceEnabled()) {
1272 LOG.trace(parent + " child is done: " + procedure);
1273 }
1274 if (parent.childrenCountDown() && parent.getState() == ProcedureState.WAITING) {
1275 parent.setState(ProcedureState.RUNNABLE);
1276 store.update(parent);
1277 runnables.addFront(parent);
1278 if (LOG.isTraceEnabled()) {
1279 LOG.trace(parent + " all the children finished their work, resume.");
1280 }
1281 return;
1282 }
1283 }
1284 }
1285
1286 private void handleInterruptedException(final Procedure proc, final InterruptedException e) {
1287 if (LOG.isTraceEnabled()) {
1288 LOG.trace("got an interrupt during " + proc + ". suspend and retry it later.", e);
1289 }
1290
1291
1292
1293
1294
1295
1296 }
1297
1298 private void sendProcedureLoadedNotification(final long procId) {
1299 if (!this.listeners.isEmpty()) {
1300 for (ProcedureExecutorListener listener: this.listeners) {
1301 try {
1302 listener.procedureLoaded(procId);
1303 } catch (Throwable e) {
1304 LOG.error("The listener " + listener + " had an error: " + e.getMessage(), e);
1305 }
1306 }
1307 }
1308 }
1309
1310 private void sendProcedureAddedNotification(final long procId) {
1311 if (!this.listeners.isEmpty()) {
1312 for (ProcedureExecutorListener listener: this.listeners) {
1313 try {
1314 listener.procedureAdded(procId);
1315 } catch (Throwable e) {
1316 LOG.error("The listener " + listener + " had an error: " + e.getMessage(), e);
1317 }
1318 }
1319 }
1320 }
1321
1322 private void sendProcedureFinishedNotification(final long procId) {
1323 if (!this.listeners.isEmpty()) {
1324 for (ProcedureExecutorListener listener: this.listeners) {
1325 try {
1326 listener.procedureFinished(procId);
1327 } catch (Throwable e) {
1328 LOG.error("The listener " + listener + " had an error: " + e.getMessage(), e);
1329 }
1330 }
1331 }
1332 }
1333
1334 private long nextProcId() {
1335 long procId = lastProcId.incrementAndGet();
1336 if (procId < 0) {
1337 while (!lastProcId.compareAndSet(procId, 0)) {
1338 procId = lastProcId.get();
1339 if (procId >= 0)
1340 break;
1341 }
1342 while (procedures.containsKey(procId)) {
1343 procId = lastProcId.incrementAndGet();
1344 }
1345 }
1346 return procId;
1347 }
1348
1349 @VisibleForTesting
1350 protected long getLastProcId() {
1351 return lastProcId.get();
1352 }
1353
1354 private Long getRootProcedureId(Procedure proc) {
1355 return Procedure.getRootProcedureId(procedures, proc);
1356 }
1357
1358 private void procedureFinished(final Procedure proc) {
1359
1360 try {
1361 proc.completionCleanup(getEnvironment());
1362 } catch (Throwable e) {
1363
1364 LOG.error("CODE-BUG: uncatched runtime exception for procedure: " + proc, e);
1365 }
1366
1367
1368 ProcedureInfo procInfo = Procedure.createProcedureInfo(proc, proc.getNonceKey());
1369 if (!proc.shouldWaitClientAck(getEnvironment())) {
1370 procInfo.setClientAckTime(0);
1371 }
1372
1373 completed.put(procInfo.getProcId(), procInfo);
1374 rollbackStack.remove(proc.getProcId());
1375 procedures.remove(proc.getProcId());
1376
1377
1378 try {
1379 runnables.completionCleanup(proc);
1380 } catch (Throwable e) {
1381
1382 LOG.error("CODE-BUG: uncatched runtime exception for runnableSet: " + runnables, e);
1383 }
1384
1385
1386 sendProcedureFinishedNotification(proc.getProcId());
1387 }
1388
1389 public Pair<ProcedureInfo, Procedure> getResultOrProcedure(final long procId) {
1390 ProcedureInfo result = completed.get(procId);
1391 Procedure proc = null;
1392 if (result == null) {
1393 proc = procedures.get(procId);
1394 if (proc == null) {
1395 result = completed.get(procId);
1396 }
1397 }
1398 return new Pair(result, proc);
1399 }
1400 }