View Javadoc

1   /**
2    *  Copyright 2003-2007 Greg Luck
3    *
4    *  Licensed under the Apache License, Version 2.0 (the "License");
5    *  you may not use this file except in compliance with the License.
6    *  You may obtain a copy of the License at
7    *
8    *      http://www.apache.org/licenses/LICENSE-2.0
9    *
10   *  Unless required by applicable law or agreed to in writing, software
11   *  distributed under the License is distributed on an "AS IS" BASIS,
12   *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13   *  See the License for the specific language governing permissions and
14   *  limitations under the License.
15   */
16  
17  package net.sf.ehcache.constructs.asynchronous;
18  
19  import net.sf.ehcache.CacheException;
20  import net.sf.ehcache.CacheManager;
21  import net.sf.ehcache.Ehcache;
22  import net.sf.ehcache.Element;
23  import org.apache.commons.logging.Log;
24  import org.apache.commons.logging.LogFactory;
25  
26  import java.io.Serializable;
27  import java.rmi.dgc.VMID;
28  import java.util.Date;
29  import java.util.Stack;
30  
31  import edu.emory.mathcs.backport.java.util.Queue;
32  import edu.emory.mathcs.backport.java.util.concurrent.ConcurrentLinkedQueue;
33  
34  /**
35   * Handles the asynchronous execution of commands. This class contains subtle threading interactions and should
36   * not be modified without comprehensive multi-threaded tests.
37   * <p/>
38   * AsynchronousCommandExecutor is a singleton. Multiple clients may use it. It will execute commands in the order they were
39   * added per client. To preserve order, if a command cannot be executed, all commands will wait behind it.
40   * <p/>
41   * This code requires JDK1.5 at present.
42   * @author <a href="mailto:gluck@thoughtworks.com">Greg Luck</a>
43   * @version $Id: AsynchronousCommandExecutor.java 512 2007-07-10 09:18:45Z gregluck $
44   */
45  public final class AsynchronousCommandExecutor {
46      /**
47       * The name of the message cache in the ehcache.xml configuration file.
48       */
49      public static final String MESSAGE_CACHE = "net.sf.ehcache.constructs.asynchronous.MessageCache";
50  
51      /**
52       * The command completed successfully
53       */
54      public static final String SUCCESSFUL_EXECUTION = "Successful execution";
55  
56      /**
57       * The dispatcher thread interval. It wakes up the dispatcher thread and attempts to process commands in the cache.
58       * Commands will ignore the execution request if they have a set time between retries. New messages dispatched, will
59       * also cause commands to be attempted immediately.
60       * <p/>
61       * Setting this to a low value will cause high cpu load. The recommended value is the amount of time between failed
62       * message retries, which by default is 1 minute.
63       */
64      public static final int DEFAULT_DISPATCHER_THREAD_INTERVAL_SECONDS = 60;
65  
66      /**
67       * Minimum setting for the dispatcher thread interval.
68       *
69       * @see #DEFAULT_DISPATCHER_THREAD_INTERVAL_SECONDS
70       */
71      public static final int MINIMUM_SAFE_DISPATCHER_THREAD_INTERVAL = 30;
72  
73      /**
74       * The messageCache contains {@link Command} element values, and a queue that maintains their order.
75       * This is the key of the queue element.
76       */
77      public static final String QUEUE_KEY = "QueueKey";
78  
79      private static final long WAIT_FOR_THREAD_INITIALIZATION = 5;    
80  
81      private static final Log LOG = LogFactory.getLog(AsynchronousCommandExecutor.class.getName());
82      private static final int MS_PER_SECOND = 1000;
83      private static AsynchronousCommandExecutor singleton;
84      private static CacheManager cacheManager;
85      private boolean active;
86      private Thread dispatcherThread;
87  
88      /**
89       * The thread interval in seconds. Do not set this to 0 or too small a value or CPU usage will skyrocket.
90       */
91      private long dispatcherThreadIntervalSeconds;
92  
93  
94      private AsynchronousCommandExecutor() throws CacheException {
95          cacheManager = CacheManager.getInstance();
96          addShutdownHook();
97          active = true;
98          dispatcherThreadIntervalSeconds = DEFAULT_DISPATCHER_THREAD_INTERVAL_SECONDS;
99          dispatcherThread = new DispatcherThread();
100         dispatcherThread.start();
101         //wait for all the threads to initialize. Without this, if a command is immediately queued the notifyAll
102         //on queueForExecution, the despatcher thread is not ready to receive it.
103         try {
104             Thread.sleep(WAIT_FOR_THREAD_INITIALIZATION);
105         } catch (InterruptedException e) {
106             LOG.warn("Interrupted while initiliazing", e);
107         }
108 
109     }
110 
111     /**
112      * Factory method to get an instance of MessageDispatcher.
113      *
114      * @return a fully initialized reference to the singleton.
115      * @throws AsynchronousCommandException
116      */
117     public static synchronized AsynchronousCommandExecutor getInstance() throws AsynchronousCommandException {
118         if (singleton == null) {
119             try {
120                 singleton = new AsynchronousCommandExecutor();
121             } catch (CacheException e) {
122                 throw new AsynchronousCommandException("Cannot create CacheManager. Detailed message is: "
123                         + e.getMessage(), e);
124             }
125 
126         }
127         return singleton;
128     }
129 
130     /**
131      * Must be synchronized as potentially two threads could create new queues at the same time, with the result
132      * that one element would be lost.
133      *
134      * @return the queue of messages, or if none existed, a new queue
135      * @throws AsynchronousCommandException
136      */
137     synchronized Queue getQueue() throws AsynchronousCommandException {
138         Queue queue;
139         Ehcache cache = getMessageCache();
140         Element element;
141         try {
142             element = cache.get(QUEUE_KEY);
143         } catch (CacheException e) {
144             throw new AsynchronousCommandException("Unable to retrieve queue.", e);
145         }
146         if (element == null) {
147             queue = new ConcurrentLinkedQueue();
148             Element queueElement = new Element(QUEUE_KEY, queue);
149             cache.put(queueElement);
150         } else {
151             queue = (Queue) element.getValue();
152         }
153         return queue;
154     }
155 
156     /**
157      * Gets the message cache
158      *
159      * @return the {@link #MESSAGE_CACHE} cache
160      * @throws AsynchronousCommandException if the {@link #MESSAGE_CACHE} is null
161      */
162     public Ehcache getMessageCache() throws AsynchronousCommandException {
163         Ehcache cache = cacheManager.getEhcache(MESSAGE_CACHE);
164         if (cache == null) {
165             throw new AsynchronousCommandException(
166                     "ehcache.xml with a configuration entry for " +
167                             MESSAGE_CACHE + " was not found in the classpath.");
168         }
169         return cache;
170     }
171 
172     /**
173      * Stores parameters in the {@link #MESSAGE_CACHE} for later execution. A unique id is assigned to the
174      * PublisherCommand and that id is enqueued. Values stored will persist across VM restarts, provided the
175      * VM shutdown hooks have a chance to run.
176      * <p/>
177      * This method is synchronized because the underlying Queue implementation is not threadsafe.
178      *
179      * @param command the {@link Command} which will be called on to publish the message
180      * @return the unique identifier for the command
181      * @throws AsynchronousCommandException
182      */
183     public synchronized String queueForExecution(Command command) throws AsynchronousCommandException {
184         InstrumentedCommand instrumentedCommand = new InstrumentedCommand(command);
185         String uid = storeCommandToCache(instrumentedCommand);
186         enqueue(uid);
187         notifyAll();
188         return uid;
189     }
190 
191     private void enqueue(String uid) throws AsynchronousCommandException {
192         Queue queue;
193         queue = getQueue();
194         queue.add(uid);
195     }
196 
197     /**
198      * Gets the number of attempts for the command so far
199      *
200      * @param uid - the unique id for the command returned from {@link #queueForExecution(Command)}
201      * @return the number of times the command was executed
202      * @throws CommandNotFoundInCacheException
203      *                                      if the command was not found in the cache.
204      * @throws AsynchronousCommandException if their is a problem accessing the cache.
205      */
206     public synchronized int getExecuteAttemptsForCommand(String uid) throws CommandNotFoundInCacheException,
207             AsynchronousCommandException {
208         InstrumentedCommand instrumentedCommand = retrieveInstrumentedCommandFromCache(uid);
209         if (instrumentedCommand == null) {
210             throw new CommandNotFoundInCacheException("Command " + uid + " + was not found in the messageCache");
211         }
212         return instrumentedCommand.getExecuteAttempts();
213     }
214 
215     /**
216      * A background thread that executes commands
217      */
218     private class DispatcherThread extends Thread {
219         public DispatcherThread() {
220             super("Message Dispatcher Thread");
221             //allow VM to exit with this thread running
222             setDaemon(true);
223         }
224 
225         /**
226          * RemoteDebugger thread method.
227          */
228         public void run() {
229             dispatcherThreadMain();
230         }
231     }
232 
233     /**
234      * The main method for the expiry thread.
235      * <p/>
236      * Will run while the cache is active. After the cache shuts down
237      * it will take the expiryThreadInterval to wake up and complete.
238      * <p/>
239      * Any exceptions are logged.
240      */
241     private synchronized void dispatcherThreadMain() {
242         while (true) {
243             try {
244                 //wait for new messages or retry interval.
245                 if (LOG.isDebugEnabled()) {
246                     LOG.debug("dispatcherThreadIntervalSeconds: " + dispatcherThreadIntervalSeconds);
247                 }
248                 wait(dispatcherThreadIntervalSeconds * MS_PER_SECOND);
249             } catch (InterruptedException e) {
250                 if (LOG.isDebugEnabled()) {
251                     LOG.debug("messageCache: Dispatcher thread interrupted on Disk Store.");
252                 }
253                 //Should only happen on dispose.
254                 return;
255             }
256             if (!active) {
257                 return;
258             }
259             executeCommands();
260         }
261     }
262 
263     /**
264      * Dequeues messages and sends thems until a failure occurs, in which case, we wait until next time
265      * to try again.
266      * <p/>
267      * Each message in the queue is tried. There are many many reasons why a message can fail. It may be unique to the message
268      * such as a MessageFormatException, a non-serializable message and so on, in which case it may only affect that
269      * message. Or it could be that the service is down. Attempts are made to itentify messages that can never be
270      * delivered so that they can be deleted and hold up the queue. No messages can be sent out of order, or the queue
271      * rules will be broken. Subscribers may also be reliant on getting the messages in the right order. e.g. a delete
272      * or update can only happen after an insert for a given domain object.
273      * <p/>
274      * This method is synchronized so that it will always complete before a dispose occurs.
275      */
276     private synchronized void executeCommands() {
277         if (LOG.isDebugEnabled()) {
278             LOG.debug("executeCommands invoked. " + countCachedPublishCommands() + " messages to be sent.");
279         }
280         Queue queue = null;
281         InstrumentedCommand instrumentedCommand = null;
282         try {
283             queue = getQueue();
284         } catch (AsynchronousCommandException e) {
285             LOG.fatal("Unable to access the cache to retrieve commands. ", e);
286         }
287         Object object = null;
288         while (true) {
289             object = queue.peek();
290             if (object == null) {
291                 break;
292             }
293             String uid = (String) object;
294             try {
295                 try {
296                     instrumentedCommand = retrieveInstrumentedCommandFromCache(uid);
297                     instrumentedCommand.attemptExecution();
298                     remove(queue, uid, SUCCESSFUL_EXECUTION);
299                 } catch (RetryAttemptTooSoonException e) {
300                     if (LOG.isDebugEnabled()) {
301                         LOG.debug(e.getMessage(), e);
302                     }
303                     break;
304                 } catch (TooManyRetriesException e) {
305                     remove(queue, uid, e.getMessage());
306                 } catch (CommandNotFoundInCacheException e) {
307                     remove(queue, uid, e.getMessage());
308                 }
309             } catch (Throwable throwable) {
310                 boolean match = checkIfRetryOnThrowable(throwable, instrumentedCommand);
311                 if (!match) {
312                     remove(queue, uid, throwable.getMessage());
313                 } else {
314                     //retry
315                     if (LOG.isInfoEnabled()) {
316                      LOG.info("Publishing attempt number " + instrumentedCommand.getExecuteAttempts()
317                                 + " failed. " + throwable.getMessage(), throwable);
318                     }
319                     break;
320                 }
321             }
322         }
323     }
324 
325 
326     private boolean checkIfRetryOnThrowable(Throwable throwable, InstrumentedCommand instrumentedCommand) {
327         Command command = instrumentedCommand.command;
328         Class[] retryThrowables = command.getThrowablesToRetryOn();
329         if (retryThrowables == null) {
330             return false;
331         }
332         boolean match = false;
333         for (int i = 0; i < retryThrowables.length; i++) {
334             Class retryThrowable = retryThrowables[i];
335             if (retryThrowable.isInstance(throwable)) {
336                 match = true;
337             }
338 
339         }
340         return match;
341     }
342 
343     private void remove(Queue queue, String uid, String reason) {
344         queue.remove();
345         Ehcache cache = null;
346         try {
347             cache = getMessageCache();
348         } catch (AsynchronousCommandException e) {
349             LOG.fatal("Unable to get cache + " + e.getMessage(), e);
350         }
351         cache.remove(uid);
352         if (reason.equals(SUCCESSFUL_EXECUTION)) {
353             if (LOG.isDebugEnabled()) {
354                 LOG.debug("Deleting command with uid " + uid + ". " + reason);
355             }
356         } else {
357             LOG.error("Deleting command with uid " + uid + ".  " + reason);
358         }
359     }
360 
361 
362     private InstrumentedCommand retrieveInstrumentedCommandFromCache(String uid)
363             throws CommandNotFoundInCacheException {
364         Element element = null;
365         try {
366             //Cache not alive here. Why?
367             Ehcache cache = getMessageCache();
368             element = cache.get(uid);
369         } catch (Exception e) {
370             throw new CommandNotFoundInCacheException("Cache error while retrieving command", e);
371         }
372 
373         if (element == null) {
374             throw new CommandNotFoundInCacheException("Command " + uid + " not found in cache.");
375         }
376         return (InstrumentedCommand) element.getValue();
377     }
378 
379     /**
380      * Some caches might be persistent, so we want to add a shutdown hook if that is the
381      * case, so that the data and index can be written to disk.
382      */
383     private void addShutdownHook() {
384         Runtime.getRuntime().addShutdownHook(new Thread() {
385             public void run() {
386                 synchronized (this) {
387                     if (active) {
388                         LOG.info("VM shutting down with the MessageDispatcher active. There are "
389                                 + countCachedPublishCommands() +
390                                 " messages which will be cached to disk for delivery on VM restart.");
391                         dispose();
392                     }
393                 }
394             }
395         });
396     }
397 
398     /**
399      * @return the approximate number of PublishCommands stored in the cache
400      */
401     public synchronized int countCachedPublishCommands() {
402         int messageCount = 0;
403         try {
404             Ehcache cache = getMessageCache();
405             messageCount = cache.getSize();
406         } catch (Exception e) {
407             LOG.info("Unable to determine the number"
408                     + " of messages in the messageCache.", e);
409         }
410         if (messageCount != 0) {
411             //don't count queue, which should always be there.
412             messageCount--;
413         }
414         return messageCount;
415     }
416 
417     /**
418      * ehcache also has a shutdown hook, so it will save all to disk.
419      * <p/>
420      * Shuts down the disk store in preparation for cache shutdown
421      * <p/>
422      * If a VM crash happens, the shutdown hook will not run. The data file and the index file
423      * will be out of synchronisation. At initialisation we always delete the index file
424      * after we have read the elements, so that it has a zero length. On a dirty restart, it still will have
425      * and the data file will automatically be deleted, thus preserving safety.
426      */
427     public synchronized void dispose() {
428         int messages = countCachedPublishCommands();
429         LOG.info("Shutting down Message Dispatcher. " + messages + " messages remaining.");
430 
431         if (!active) {
432             return;
433         }
434         try {
435             if (dispatcherThread != null) {
436                 dispatcherThread.interrupt();
437             }
438 
439         } catch (Exception e) {
440             LOG.error("Could not shut down MessageDispatcher", e);
441         } finally {
442             active = false;
443             notifyAll();
444         }
445     }
446 
447     /**
448      * @param instrumentedCommand
449      * @return A unique id which acts as a handle to the message
450      * @throws AsynchronousCommandException
451      */
452     String storeCommandToCache(InstrumentedCommand instrumentedCommand) throws AsynchronousCommandException {
453         String uid = generateUniqueIdentifier();
454         Element element = new Element(uid, instrumentedCommand);
455         Ehcache messageCache = getMessageCache();
456         messageCache.put(element);
457         return uid;
458     }
459 
460 
461     /**
462      * Generates an ID that is guaranteed to be unique for all VM invocations on a machine with a
463      * given IP address.
464      *
465      * @return A String representation of the unique identifier.
466      */
467     String generateUniqueIdentifier() {
468         VMID guid = new VMID();
469         return guid.toString();
470     }
471 
472     /**
473      * Sets the interval between runs of the dispatch thread, when no new dispatch invocations have occurred.
474      *
475      * @param dispatcherThreadIntervalSeconds
476      *         the time in seconds
477      * @throws IllegalArgumentException if the argument is less than 30
478      * @see #DEFAULT_DISPATCHER_THREAD_INTERVAL_SECONDS for more information.
479      */
480     public void setDispatcherThreadIntervalSeconds(long dispatcherThreadIntervalSeconds)
481             throws IllegalArgumentException {
482         if (dispatcherThreadIntervalSeconds < MINIMUM_SAFE_DISPATCHER_THREAD_INTERVAL) {
483             throw new IllegalArgumentException("Must be greater than 30 seconds to avoid high cpu load");
484         }
485         setUnsafeDispatcherThreadIntervalSeconds(dispatcherThreadIntervalSeconds);
486     }
487 
488     /**
489      * Sets the interval between runs of the dispatch thread, when no new dispatch invocations have occurred.
490      * <p/>
491      * Provided with package local access to permit testing
492      *
493      * @param dispatcherThreadIntervalSeconds
494      *         the time in seconds
495      * @see #DEFAULT_DISPATCHER_THREAD_INTERVAL_SECONDS for more information.
496      */
497     public void setUnsafeDispatcherThreadIntervalSeconds(long dispatcherThreadIntervalSeconds) {
498         this.dispatcherThreadIntervalSeconds = dispatcherThreadIntervalSeconds;
499     }
500 
501     /**
502      * A <code>Command</code> instrumented with information about retry attempts
503      */
504     private final static class InstrumentedCommand implements Serializable {
505         private Command command;
506 
507         /**
508          * A record of the attempts to execute this command
509          */
510         private Stack executeAttempts;
511 
512 
513         private InstrumentedCommand(Command command) {
514             this.command = command;
515             executeAttempts = new Stack();
516         }
517 
518         /**
519          * Records the data and time an execution attempt was made
520          */
521         private void registerExecutionAttempt() {
522             Date date = new Date();
523             executeAttempts.add(date);
524         }
525 
526         private void attemptExecution() throws Throwable, TooManyRetriesException, RetryAttemptTooSoonException {
527             checkAttemptNotTooSoon();
528             checkNotTooManyAttempts();
529             command.execute();
530         }
531 
532         /**
533          * Checks that enough time has elapsed to attempt an execution
534          *
535          * @throws RetryAttemptTooSoonException if sufficient time has not elapsed
536          */
537         private void checkAttemptNotTooSoon() throws RetryAttemptTooSoonException {
538             //must guard against this because of the design of stack
539             if (!executeAttempts.empty()) {
540                 Date lastAttempt = (Date) executeAttempts.peek();
541                 long delay = command.getDelayBetweenAttemptsInSeconds() * MS_PER_SECOND;
542                 Date nextAttemptDue = new Date(lastAttempt.getTime() + (delay));
543                 Date now = new Date();
544                 if (now.before(nextAttemptDue)) {
545                     throw new RetryAttemptTooSoonException("Attempt to execute command before it is due is being ignored.");
546                 }
547             }
548         }
549 
550         /**
551          * Checks that the number of attempts does not exceed the number of attempts defined in the command
552          *
553          * @throws TooManyRetriesException
554          */
555         private void checkNotTooManyAttempts() throws TooManyRetriesException {
556             registerExecutionAttempt();
557             if (getExecuteAttempts() > command.getNumberOfAttempts()) {
558                 throw new TooManyRetriesException("Retry attempt number " + getExecuteAttempts() + " is greater than "
559                         + " the number permitted of " + command.getNumberOfAttempts()
560                         + ".\n" + this);
561             }
562         }
563 
564         private int getExecuteAttempts() {
565             //must guard against this because of the design of stack
566             if (executeAttempts.empty()) {
567                 return 0;
568             } else {
569                 return executeAttempts.size();
570             }
571         }
572 
573 
574         /**
575          * @return a string representation of the object.
576          */
577         public String toString() {
578             StringBuffer buffer = new StringBuffer();
579             buffer.append("InstrumentedCommand: \n")
580                     .append(super.toString())
581                     .append("Previous Execution Attempts: \n");
582 
583             if (getExecuteAttempts() > 0) {
584                 for (int i = 0; i < getExecuteAttempts(); i++) {
585                     Date date = (Date) executeAttempts.get(i);
586                     buffer.append(date).append(" ");
587                 }
588             }
589 
590             buffer.append("Command: \n") .append(command);
591             return buffer.toString();
592         }
593 
594 
595     }
596 
597 
598 }
599 
600 
601