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