View Javadoc

1   /*
2    * Copyright 2006-2009 the original author or authors.
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 org.springframework.osgi.extender.internal.dependencies.startup;
18  
19  import java.security.AccessController;
20  import java.security.PrivilegedAction;
21  import java.util.Iterator;
22  import java.util.List;
23  import java.util.Timer;
24  import java.util.TimerTask;
25  
26  import org.apache.commons.logging.Log;
27  import org.apache.commons.logging.LogFactory;
28  import org.osgi.framework.Bundle;
29  import org.osgi.framework.Filter;
30  import org.springframework.beans.BeansException;
31  import org.springframework.context.ApplicationContextException;
32  import org.springframework.context.ConfigurableApplicationContext;
33  import org.springframework.core.task.TaskExecutor;
34  import org.springframework.osgi.context.DelegatedExecutionOsgiBundleApplicationContext;
35  import org.springframework.osgi.context.OsgiBundleApplicationContextExecutor;
36  import org.springframework.osgi.context.event.OsgiBundleApplicationContextEventMulticaster;
37  import org.springframework.osgi.context.event.OsgiBundleContextFailedEvent;
38  import org.springframework.osgi.extender.OsgiServiceDependencyFactory;
39  import org.springframework.osgi.extender.event.BootstrappingDependenciesFailedEvent;
40  import org.springframework.osgi.extender.internal.util.concurrent.Counter;
41  import org.springframework.osgi.service.importer.event.OsgiServiceDependencyEvent;
42  import org.springframework.osgi.util.OsgiFilterUtils;
43  import org.springframework.osgi.util.OsgiStringUtils;
44  import org.springframework.util.Assert;
45  
46  /**
47   * Dependency waiter executor that breaks the 'traditional' {@link ConfigurableApplicationContext#refresh()} in two
48   * pieces so that beans are not actually created unless the OSGi service imported are present.
49   * 
50   * <p/> <p/> <p/> Supports both asynch and synch behaviour.
51   * 
52   * @author Hal Hildebrand
53   * @author Costin Leau
54   */
55  public class DependencyWaiterApplicationContextExecutor implements OsgiBundleApplicationContextExecutor,
56  		ContextExecutorAccessor {
57  
58  	private static final Log log = LogFactory.getLog(DependencyWaiterApplicationContextExecutor.class);
59  
60  	/**
61  	 * this class monitor. Since multiple threads will access this object, we have to use synchronization to guarantee
62  	 * thread visibility
63  	 */
64  	private final Object monitor = new Object();
65  
66  	/** waiting timeout */
67  	private long timeout;
68  
69  	/** the timer used for executing the timeout */
70  	// NOTE: the dog is not managed by this application so do not cancel it
71  	private Timer watchdog;
72  
73  	/** watchdog task */
74  	private TimerTask watchdogTask;
75  
76  	/** OSGi service dependencyDetector used for detecting dependencies */
77  	protected DependencyServiceManager dependencyDetector;
78  
79  	protected final DelegatedExecutionOsgiBundleApplicationContext delegateContext;
80  
81  	/** State of the associated context from the executor POV. */
82  	private ContextState state = ContextState.INITIALIZED;
83  
84  	private TaskExecutor taskExecutor;
85  
86  	/**
87  	 * A synchronized counter used by the Listener to determine the number of children to wait for when shutting down.
88  	 */
89  	private Counter monitorCounter;
90  
91  	/** Should the waiting be synchrous or not ? */
92  	private final boolean synchronousWait;
93  
94  	/** Counter used when waiting for dependencies to appear */
95  	private final Counter waitBarrier = new Counter("syncCounterWait");
96  
97  	/** delegated multicaster */
98  	private OsgiBundleApplicationContextEventMulticaster delegatedMulticaster;
99  
100 	private List<OsgiServiceDependencyFactory> dependencyFactories;
101 
102 	/**
103 	 * The task for the watch dog.
104 	 * 
105 	 * @author Hal Hildebrand
106 	 */
107 	private class WatchDogTask extends TimerTask {
108 
109 		public void run() {
110 			timeout();
111 		}
112 	}
113 
114 	/**
115 	 * Create the Runnable action which will complete the context creation process. This process can be called
116 	 * synchronously or asynchronously, depending on context configuration and availability of dependencies.
117 	 * 
118 	 * @author Hal Hildebrand
119 	 * @author Costin Leau
120 	 */
121 	private class CompleteRefreshTask implements Runnable {
122 
123 		public void run() {
124 			boolean debug = log.isDebugEnabled();
125 			if (debug) {
126 				log.debug("Completing refresh for " + getDisplayName());
127 			}
128 
129 			synchronized (monitor) {
130 				if (state != ContextState.DEPENDENCIES_RESOLVED) {
131 					logWrongState(ContextState.DEPENDENCIES_RESOLVED);
132 					return;
133 				}
134 			}
135 
136 			// Continue with the refresh process...
137 			try {
138 				delegateContext.completeRefresh();
139 			} catch (Throwable th) {
140 				fail(th, true);
141 			}
142 
143 			// Once we are done, tell the world
144 			synchronized (monitor) {
145 				// Close might have been called in the meantime
146 				if (state != ContextState.DEPENDENCIES_RESOLVED) {
147 					return;
148 				}
149 				state = ContextState.STARTED;
150 			}
151 		}
152 	}
153 
154 	public DependencyWaiterApplicationContextExecutor(DelegatedExecutionOsgiBundleApplicationContext delegateContext,
155 			boolean syncWait, List<OsgiServiceDependencyFactory> dependencyFactories) {
156 		this.delegateContext = delegateContext;
157 		this.delegateContext.setExecutor(this);
158 		this.synchronousWait = syncWait;
159 		this.dependencyFactories = dependencyFactories;
160 
161 		synchronized (monitor) {
162 			watchdogTask = new WatchDogTask();
163 		}
164 	}
165 
166 	/**
167 	 * Provide a continuation like approach to the application context. Will execute just some parts of refresh and then
168 	 * leave the rest of to be executed after a number of conditions have been met.
169 	 */
170 	public void refresh() throws BeansException, IllegalStateException {
171 		if (log.isDebugEnabled())
172 			log.debug("Starting first stage of refresh for " + getDisplayName());
173 
174 		// sanity check
175 		init();
176 
177 		// start the first stage
178 		stageOne();
179 	}
180 
181 	/**
182 	 * Do some sanity checks
183 	 */
184 	protected void init() {
185 		synchronized (monitor) {
186 			Assert.notNull(watchdog, "watchdog timer required");
187 			Assert.notNull(monitorCounter, " monitorCounter required");
188 			if (state != ContextState.INTERRUPTED && state != ContextState.STOPPED)
189 				state = ContextState.INITIALIZED;
190 			else {
191 				RuntimeException ex = new IllegalStateException("cannot refresh an interrupted/closed context");
192 				log.fatal(ex);
193 				throw ex;
194 			}
195 		}
196 	}
197 
198 	/**
199 	 * Start the first stage of the application context refresh. Determines the service dependencies and if there are
200 	 * any, registers a OSGi service dependencyDetector which will continue the refresh process asynchronously. <p/>
201 	 * Based on the {@link #synchronousWait}, the current thread can simply end if there are any dependencies (the
202 	 * default) or wait to either timeout or have all its dependencies met.
203 	 */
204 	protected void stageOne() {
205 
206 		boolean debug = log.isDebugEnabled();
207 
208 		boolean skipExceptionEvent = true;
209 
210 		try {
211 			if (debug)
212 				log.debug("Calling preRefresh on " + getDisplayName());
213 
214 			synchronized (monitor) {
215 
216 				// check before kicking the pedal
217 				if (state != ContextState.INITIALIZED) {
218 					logWrongState(ContextState.INITIALIZED);
219 					return;
220 				}
221 
222 				state = ContextState.RESOLVING_DEPENDENCIES;
223 			}
224 
225 			delegateContext.startRefresh();
226 
227 			if (debug)
228 				log.debug("Pre-refresh completed; determining dependencies...");
229 
230 			Runnable task = null;
231 
232 			if (synchronousWait) {
233 				task = new Runnable() {
234 
235 					public void run() {
236 						// inform the waiting thread through the counter
237 						waitBarrier.decrement();
238 					}
239 				};
240 			} else
241 				task = new Runnable() {
242 
243 					public void run() {
244 						// no waiting involved, just call stageTwo
245 						stageTwo();
246 					}
247 				};
248 
249 			skipExceptionEvent = false;
250 
251 			DependencyServiceManager dl = createDependencyServiceListener(task);
252 			dl.findServiceDependencies();
253 
254 			skipExceptionEvent = true;
255 
256 			// all dependencies are met, just go with stageTwo
257 			if (dl.isSatisfied()) {
258 				log.info("No outstanding OSGi service dependencies, completing initialization for " + getDisplayName());
259 				stageTwo();
260 			} else {
261 				// there are dependencies not met
262 				// register a listener to look for them
263 				synchronized (monitor) {
264 					dependencyDetector = dl;
265 				}
266 
267 				if (debug)
268 					log.debug("Registering service dependency dependencyDetector for " + getDisplayName());
269 
270 				dependencyDetector.register();
271 
272 				if (synchronousWait) {
273 					waitBarrier.increment();
274 					if (debug)
275 						log.debug("Synchronous wait-for-dependencies; waiting...");
276 
277 					// if waiting times out...
278 					if (waitBarrier.waitForZero(timeout)) {
279 						timeout();
280 					} else
281 						stageTwo();
282 				} else {
283 					// start the watchdog (we're asynch)
284 					startWatchDog();
285 				}
286 			}
287 		} catch (Throwable e) {
288 			fail(e, skipExceptionEvent);
289 		}
290 
291 	}
292 
293 	protected void stageTwo() {
294 		boolean debug = log.isDebugEnabled();
295 
296 		if (debug)
297 			log.debug("Starting stage two for " + getDisplayName());
298 
299 		synchronized (monitor) {
300 
301 			if (state != ContextState.RESOLVING_DEPENDENCIES) {
302 				logWrongState(ContextState.RESOLVING_DEPENDENCIES);
303 				return;
304 			}
305 
306 			stopWatchDog();
307 			state = ContextState.DEPENDENCIES_RESOLVED;
308 		}
309 
310 		// always delegate to the taskExecutor since we might be called by the
311 		// OSGi platform listener
312 		taskExecutor.execute(new CompleteRefreshTask());
313 	}
314 
315 	/**
316 	 * The application context is being shutdown. Deregister the listener and prevent classes from being loaded since
317 	 * it's Doom's day.
318 	 */
319 	public void close() {
320 		boolean debug = log.isDebugEnabled();
321 
322 		boolean normalShutdown = false;
323 		stopWatchDog();
324 		
325 		synchronized (monitor) {
326 
327 			// no need for cleanup
328 			if (state.isDown()) {
329 				return;
330 			}
331 
332 			if (debug) {
333 				log.debug("Closing appCtx for " + getDisplayName());
334 			}
335 
336 			// It's possible for the delegateContext to already be in startRefresh() or completeRefresh().
337 			// If this is the case then its important to wait for these tasks to complete and then close normally
338 			// If we simply exit then the bundle may suddenly become invalid under our feet, e.g. if this
339 			// was triggered by a Bundle update or uninstall.
340 
341 			// Context is in stageOne(), wait until stageOne() is complete
342 			// and destroy singletons
343 			if (state == ContextState.RESOLVING_DEPENDENCIES) {
344 				if (debug)
345 					log.debug("Cleaning up appCtx " + getDisplayName());
346 				if (delegateContext.isActive()) {
347 					try {
348 						delegateContext.getBeanFactory().destroySingletons();
349 					} catch (Exception ex) {
350 						log.trace("Caught exception while interrupting context refresh ", ex);
351 					}
352 					state = ContextState.INTERRUPTED;
353 				}
354 			}
355 			// Context is in stageTwo(), wait until stageTwo() is complete and
356 			// close normally.
357 			else if (state == ContextState.DEPENDENCIES_RESOLVED) {
358 				if (debug)
359 					log.debug("Shutting down appCtx " + getDisplayName() + " once stageTwo() is complete");
360 				state = ContextState.STOPPED;
361 				normalShutdown = true;
362 			}
363 			// Context is running, shut it down
364 			else if (state == ContextState.STARTED) {
365 				if (debug)
366 					log.debug("Shutting down normally appCtx " + getDisplayName());
367 				state = ContextState.STOPPED;
368 				normalShutdown = true;
369 			}
370 			// Something else going on
371 			else {
372 				if (debug)
373 					log.debug("No need to stop context (it hasn't been started yet)");
374 				state = ContextState.INTERRUPTED;
375 			}
376 			// Clean up the detector
377 			if (dependencyDetector != null) {
378 				dependencyDetector.deregister();
379 			}
380 		}
381 		try {
382 			if (normalShutdown) {
383 				delegateContext.normalClose();
384 			}
385 		} catch (Exception ex) {
386 			log.fatal("Could not succesfully close context " + delegateContext, ex);
387 		} finally {
388 			monitorCounter.decrement();
389 		}
390 
391 	}
392 
393 	public void fail(Throwable t) {
394 		fail(t, false);
395 	}
396 
397 	/**
398 	 * Fail creating the context. Figure out unsatisfied dependencies and provide a very nice log message before closing
399 	 * the appContext.
400 	 * 
401 	 * <p/> Normally this method is called when an exception is caught.
402 	 * 
403 	 * @param t - the offending Throwable which caused our demise
404 	 */
405 	private void fail(Throwable t, boolean skipEvent) {
406 
407 		// this will not thrown any exceptions (it just logs them)
408 		close();
409 
410 		StringBuilder buf = new StringBuilder();
411 
412 		synchronized (monitor) {
413 			if (dependencyDetector == null || dependencyDetector.getUnsatisfiedDependencies().isEmpty()) {
414 				buf.append("none");
415 			} else {
416 				for (Iterator<MandatoryServiceDependency> iterator =
417 						dependencyDetector.getUnsatisfiedDependencies().keySet().iterator(); iterator.hasNext();) {
418 					MandatoryServiceDependency dependency = iterator.next();
419 					buf.append(dependency.toString());
420 					if (iterator.hasNext()) {
421 						buf.append(", ");
422 					}
423 				}
424 			}
425 		}
426 
427 		final StringBuilder message = new StringBuilder();
428 		message.append("Unable to create application context for [");
429 		if (System.getSecurityManager() != null) {
430 			AccessController.doPrivileged(new PrivilegedAction<Object>() {
431 				public Object run() {
432 					message.append(OsgiStringUtils.nullSafeSymbolicName(getBundle()));
433 					return null;
434 				}
435 			});
436 		} else {
437 			message.append(OsgiStringUtils.nullSafeSymbolicName(getBundle()));
438 		}
439 
440 		message.append("], unsatisfied dependencies: ");
441 		message.append(buf.toString());
442 
443 		log.error(message.toString(), t);
444 
445 		// send notification
446 		if (!skipEvent) {
447 			delegatedMulticaster.multicastEvent(new OsgiBundleContextFailedEvent(delegateContext, delegateContext
448 					.getBundle(), t));
449 		}
450 	}
451 
452 	/**
453 	 * Cancel waiting due to timeout.
454 	 */
455 	private void timeout() {
456 		ApplicationContextException e;
457 		List<OsgiServiceDependencyEvent> events = null;
458 		String filterAsString = null;
459 
460 		synchronized (monitor) {
461 			// deregister listener to get an accurate snapshot of the
462 			// unsatisfied dependencies.
463 
464 			if (dependencyDetector != null) {
465 				dependencyDetector.deregister();
466 				events = dependencyDetector.getUnsatisfiedDependenciesAsEvents();
467 				filterAsString = dependencyDetector.createUnsatisfiedDependencyFilter();
468 			}
469 		}
470 
471 		Filter filter = (filterAsString != null ? OsgiFilterUtils.createFilter(filterAsString) : null);
472 
473 		log.warn("Timeout occurred before finding service dependencies for [" + delegateContext.getDisplayName() + "]");
474 
475 		String bundleName = null;
476 		if (System.getSecurityManager() != null) {
477 			bundleName = AccessController.doPrivileged(new PrivilegedAction<String>() {
478 				public String run() {
479 					return OsgiStringUtils.nullSafeSymbolicName(getBundle());
480 				}
481 			});
482 		} else {
483 			bundleName = OsgiStringUtils.nullSafeSymbolicName(getBundle());
484 		}
485 
486 		// generate exception
487 		e =
488 				new ApplicationContextException("Application context " + "initialization for '" + bundleName
489 						+ "' has timed out waiting for " + filterAsString);
490 		e.fillInStackTrace();
491 
492 		// send notification
493 		delegatedMulticaster.multicastEvent(new BootstrappingDependenciesFailedEvent(delegateContext, delegateContext
494 				.getBundle(), e, events, filter));
495 
496 		fail(e, true);
497 	}
498 
499 	protected DependencyServiceManager createDependencyServiceListener(Runnable task) {
500 		return new DependencyServiceManager(this, delegateContext, dependencyFactories, task, timeout);
501 	}
502 
503 	/**
504 	 * Schedule the watchdog task.
505 	 */
506 	protected void startWatchDog() {
507 		boolean started = false;
508 		synchronized (monitor) {
509 			if (watchdogTask != null) {
510 				started = true;
511 				watchdog.schedule(watchdogTask, timeout);
512 			}
513 		}
514 
515 		boolean debug = log.isDebugEnabled();
516 		if (debug) {
517 			if (started)
518 				log.debug("Asynch wait-for-dependencies started...");
519 			else
520 				log.debug("Dependencies satisfied; no need to start a watchdog...");
521 		}
522 	}
523 
524 	protected void stopWatchDog() {
525 		boolean stopped = false;
526 		synchronized (monitor) {
527 			if (watchdogTask != null) {
528 				watchdogTask.cancel();
529 				watchdogTask = null;
530 				stopped = true;
531 			}
532 		}
533 
534 		if (stopped && log.isDebugEnabled()) {
535 			log.debug("Cancelled dependency watchdog...");
536 		}
537 	}
538 
539 	/**
540 	 * Sets the timeout (in ms) for waiting for service dependencies.
541 	 * 
542 	 * @param timeout
543 	 */
544 	public void setTimeout(long timeout) {
545 		synchronized (monitor) {
546 			this.timeout = timeout;
547 		}
548 	}
549 
550 	public void setTaskExecutor(TaskExecutor taskExec) {
551 		synchronized (monitor) {
552 			this.taskExecutor = taskExec;
553 		}
554 	}
555 
556 	private Bundle getBundle() {
557 		synchronized (monitor) {
558 			return delegateContext.getBundle();
559 		}
560 	}
561 
562 	private String getDisplayName() {
563 		synchronized (monitor) {
564 			return delegateContext.getDisplayName();
565 		}
566 
567 	}
568 
569 	public void setWatchdog(Timer watchdog) {
570 		synchronized (monitor) {
571 			this.watchdog = watchdog;
572 		}
573 	}
574 
575 	/**
576 	 * Reduce the code pollution.
577 	 * 
578 	 * @param expected the expected value for the context state.
579 	 */
580 	private void logWrongState(ContextState expected) {
581 		log.error("Expecting state (" + expected + ") not (" + state + ") for context [" + getDisplayName()
582 				+ "]; assuming an interruption and bailing out");
583 	}
584 
585 	/**
586 	 * Pass in the context counter. Used by the listener to track the number of contexts started.
587 	 * 
588 	 * @param asynchCounter
589 	 */
590 	public void setMonitoringCounter(Counter contextsStarted) {
591 		this.monitorCounter = contextsStarted;
592 	}
593 
594 	/**
595 	 * Sets the multicaster for delegating failing events.
596 	 * 
597 	 * @param multicaster
598 	 */
599 	public void setDelegatedMulticaster(OsgiBundleApplicationContextEventMulticaster multicaster) {
600 		this.delegatedMulticaster = multicaster;
601 	}
602 
603 	//
604 	// accessor interface implementations
605 	//
606 
607 	public ContextState getContextState() {
608 		synchronized (monitor) {
609 			return state;
610 		}
611 	}
612 
613 	public OsgiBundleApplicationContextEventMulticaster getEventMulticaster() {
614 		return this.delegatedMulticaster;
615 	}
616 }