001/**
002 * Licensed to the Apache Software Foundation (ASF) under one or more
003 * contributor license agreements.  See the NOTICE file distributed with
004 * this work for additional information regarding copyright ownership.
005 * The ASF licenses this file to You under the Apache License, Version 2.0
006 * (the "License"); you may not use this file except in compliance with
007 * the License.  You may obtain a copy of the License at
008 *
009 *      http://www.apache.org/licenses/LICENSE-2.0
010 *
011 * Unless required by applicable law or agreed to in writing, software
012 * distributed under the License is distributed on an "AS IS" BASIS,
013 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
014 * See the License for the specific language governing permissions and
015 * limitations under the License.
016 */
017package org.apache.camel.impl;
018
019import java.util.ArrayList;
020import java.util.Collection;
021import java.util.Collections;
022import java.util.Comparator;
023import java.util.HashSet;
024import java.util.LinkedHashMap;
025import java.util.LinkedHashSet;
026import java.util.List;
027import java.util.Locale;
028import java.util.Map;
029import java.util.Set;
030import java.util.concurrent.ExecutionException;
031import java.util.concurrent.ExecutorService;
032import java.util.concurrent.Future;
033import java.util.concurrent.TimeUnit;
034import java.util.concurrent.atomic.AtomicBoolean;
035
036import org.apache.camel.CamelContext;
037import org.apache.camel.CamelContextAware;
038import org.apache.camel.Consumer;
039import org.apache.camel.Route;
040import org.apache.camel.Service;
041import org.apache.camel.ShutdownRoute;
042import org.apache.camel.ShutdownRunningTask;
043import org.apache.camel.Suspendable;
044import org.apache.camel.spi.InflightRepository;
045import org.apache.camel.spi.RouteStartupOrder;
046import org.apache.camel.spi.ShutdownAware;
047import org.apache.camel.spi.ShutdownPrepared;
048import org.apache.camel.spi.ShutdownStrategy;
049import org.apache.camel.support.ServiceSupport;
050import org.apache.camel.util.CollectionStringBuffer;
051import org.apache.camel.util.EventHelper;
052import org.apache.camel.util.ObjectHelper;
053import org.apache.camel.util.ServiceHelper;
054import org.apache.camel.util.StopWatch;
055import org.slf4j.Logger;
056import org.slf4j.LoggerFactory;
057
058/**
059 * Default {@link org.apache.camel.spi.ShutdownStrategy} which uses graceful shutdown.
060 * <p/>
061 * Graceful shutdown ensures that any inflight and pending messages will be taken into account
062 * and it will wait until these exchanges has been completed.
063 * <p/>
064 * This strategy will perform graceful shutdown in two steps:
065 * <ul>
066 *     <li>Graceful - By suspending/stopping consumers, and let any in-flight exchanges complete</li>
067 *     <li>Forced - After a given period of time, a timeout occurred and if there are still pending
068 *     exchanges to complete, then a more aggressive forced strategy is performed.</li>
069 * </ul>
070 * The idea by the <tt>graceful</tt> shutdown strategy, is to stop taking in more new messages,
071 * and allow any existing inflight messages to complete. Then when there is no more inflight messages
072 * then the routes can be fully shutdown. This mean that if there is inflight messages then we will have
073 * to wait for these messages to complete. If they do not complete after a period of time, then a
074 * timeout triggers. And then a more aggressive strategy takes over.
075 * <p/>
076 * The idea by the <tt>forced</tt> shutdown strategy, is to stop continue processing messages.
077 * And force routes and its services to shutdown now. There is a risk when shutting down now,
078 * that some resources is not properly shutdown, which can cause side effects. The timeout value
079 * is by default 300 seconds, but can be customized.
080 * <p/>
081 * As this strategy will politely wait until all exchanges has been completed it can potential wait
082 * for a long time, and hence why a timeout value can be set. When the timeout triggers you can also
083 * specify whether the remainder consumers should be shutdown now or ignore.
084 * <p/>
085 * Will by default use a timeout of 300 seconds (5 minutes) by which it will shutdown now the remaining consumers.
086 * This ensures that when shutting down Camel it at some point eventually will shutdown.
087 * This behavior can of course be configured using the {@link #setTimeout(long)} and
088 * {@link #setShutdownNowOnTimeout(boolean)} methods.
089 * <p/>
090 * Routes will by default be shutdown in the reverse order of which they where started.
091 * You can customize this using the {@link #setShutdownRoutesInReverseOrder(boolean)} method.
092 * <p/>
093 * After route consumers have been shutdown, then any {@link ShutdownPrepared} services on the routes
094 * is being prepared for shutdown, by invoking {@link ShutdownPrepared#prepareShutdown(boolean,boolean)} which
095 * <tt>force=false</tt>.
096 * <p/>
097 * Then if a timeout occurred and the strategy has been configured with shutdown-now on timeout, then
098 * the strategy performs a more aggressive forced shutdown, by forcing all consumers to shutdown
099 * and then invokes {@link ShutdownPrepared#prepareShutdown(boolean,boolean)} with <tt>force=true</tt>
100 * on the services. This allows the services to know they should force shutdown now.
101 * <p/>
102 * When timeout occurred and a forced shutdown is happening, then there may be threads/tasks which are
103 * still inflight which may be rejected continued being routed. By default this can cause WARN and ERRORs
104 * to be logged. The option {@link #setSuppressLoggingOnTimeout(boolean)} can be used to suppress these
105 * logs, so they are logged at TRACE level instead.
106 * <p/>
107 * Also when a timeout occurred then information about the inflight exchanges is logged, if {@link #isLogInflightExchangesOnTimeout()}
108 * is enabled (is by default). This allows end users to known where these inflight exchanges currently are in the route(s),
109 * and how long time they have been inflight.
110 * <p/>
111 * This information can also be obtained from the {@link org.apache.camel.spi.InflightRepository}
112 * at all time during runtime.
113 *
114 * @version
115 */
116public class DefaultShutdownStrategy extends ServiceSupport implements ShutdownStrategy, CamelContextAware {
117    private static final Logger LOG = LoggerFactory.getLogger(DefaultShutdownStrategy.class);
118
119    private CamelContext camelContext;
120    private ExecutorService executor;
121    private long timeout = 5 * 60;
122    private TimeUnit timeUnit = TimeUnit.SECONDS;
123    private boolean shutdownNowOnTimeout = true;
124    private boolean shutdownRoutesInReverseOrder = true;
125    private boolean suppressLoggingOnTimeout;
126    private boolean logInflightExchangesOnTimeout = true;
127
128    private volatile boolean forceShutdown;
129    private final AtomicBoolean timeoutOccurred = new AtomicBoolean();
130    private volatile Future<?> currentShutdownTaskFuture;
131
132    public DefaultShutdownStrategy() {
133    }
134
135    public DefaultShutdownStrategy(CamelContext camelContext) {
136        this.camelContext = camelContext;
137    }
138
139    public void shutdown(CamelContext context, List<RouteStartupOrder> routes) throws Exception {
140        shutdown(context, routes, getTimeout(), getTimeUnit());
141    }
142
143    @Override
144    public void shutdownForced(CamelContext context, List<RouteStartupOrder> routes) throws Exception {
145        doShutdown(context, routes, getTimeout(), getTimeUnit(), false, false, true);
146    }
147
148    public void suspend(CamelContext context, List<RouteStartupOrder> routes) throws Exception {
149        doShutdown(context, routes, getTimeout(), getTimeUnit(), true, false, false);
150    }
151
152    public void shutdown(CamelContext context, List<RouteStartupOrder> routes, long timeout, TimeUnit timeUnit) throws Exception {
153        doShutdown(context, routes, timeout, timeUnit, false, false, false);
154    }
155
156    public boolean shutdown(CamelContext context, RouteStartupOrder route, long timeout, TimeUnit timeUnit, boolean abortAfterTimeout) throws Exception {
157        List<RouteStartupOrder> routes = new ArrayList<>(1);
158        routes.add(route);
159        return doShutdown(context, routes, timeout, timeUnit, false, abortAfterTimeout, false);
160    }
161
162    public void suspend(CamelContext context, List<RouteStartupOrder> routes, long timeout, TimeUnit timeUnit) throws Exception {
163        doShutdown(context, routes, timeout, timeUnit, true, false, false);
164    }
165
166    protected boolean doShutdown(CamelContext context, List<RouteStartupOrder> routes, long timeout, TimeUnit timeUnit,
167                                 boolean suspendOnly, boolean abortAfterTimeout, boolean forceShutdown) throws Exception {
168
169        // timeout must be a positive value
170        if (timeout <= 0) {
171            throw new IllegalArgumentException("Timeout must be a positive value");
172        }
173
174        // just return if no routes to shutdown
175        if (routes.isEmpty()) {
176            return true;
177        }
178
179        StopWatch watch = new StopWatch();
180
181        // at first sort according to route startup order
182        List<RouteStartupOrder> routesOrdered = new ArrayList<>(routes);
183        routesOrdered.sort(new Comparator<RouteStartupOrder>() {
184            public int compare(RouteStartupOrder o1, RouteStartupOrder o2) {
185                return o1.getStartupOrder() - o2.getStartupOrder();
186            }
187        });
188        if (shutdownRoutesInReverseOrder) {
189            Collections.reverse(routesOrdered);
190        }
191
192        if (suspendOnly) {
193            LOG.info("Starting to graceful suspend {} routes (timeout {} {})", routesOrdered.size(), timeout, timeUnit.toString().toLowerCase(Locale.ENGLISH));
194        } else {
195            LOG.info("Starting to graceful shutdown {} routes (timeout {} {})", routesOrdered.size(), timeout, timeUnit.toString().toLowerCase(Locale.ENGLISH));
196        }
197
198        // use another thread to perform the shutdowns so we can support timeout
199        timeoutOccurred.set(false);
200        currentShutdownTaskFuture = getExecutorService().submit(new ShutdownTask(context, routesOrdered, timeout, timeUnit, suspendOnly,
201            abortAfterTimeout, timeoutOccurred, isLogInflightExchangesOnTimeout()));
202        try {
203            currentShutdownTaskFuture.get(timeout, timeUnit);
204        } catch (ExecutionException e) {
205            // unwrap execution exception
206            throw ObjectHelper.wrapRuntimeCamelException(e.getCause());
207        } catch (Exception e) {
208            // either timeout or interrupted exception was thrown so this is okay
209            // as interrupted would mean cancel was called on the currentShutdownTaskFuture to signal a forced timeout
210
211            // we hit a timeout, so set the flag
212            timeoutOccurred.set(true);
213
214            // timeout then cancel the task
215            currentShutdownTaskFuture.cancel(true);
216
217            // signal we are forcing shutdown now, since timeout occurred
218            this.forceShutdown = forceShutdown;
219
220            // if set, stop processing and return false to indicate that the shutdown is aborting
221            if (!forceShutdown && abortAfterTimeout) {
222                LOG.warn("Timeout occurred during graceful shutdown. Aborting the shutdown now."
223                        + " Notice: some resources may still be running as graceful shutdown did not complete successfully.");
224
225                // we attempt to force shutdown so lets log the current inflight exchanges which are affected
226                logInflightExchanges(context, routes, isLogInflightExchangesOnTimeout());
227
228                return false;
229            } else {
230                if (forceShutdown || shutdownNowOnTimeout) {
231                    LOG.warn("Timeout occurred during graceful shutdown. Forcing the routes to be shutdown now."
232                            + " Notice: some resources may still be running as graceful shutdown did not complete successfully.");
233
234                    // we attempt to force shutdown so lets log the current inflight exchanges which are affected
235                    logInflightExchanges(context, routes, isLogInflightExchangesOnTimeout());
236
237                    // force the routes to shutdown now
238                    shutdownRoutesNow(routesOrdered);
239
240                    // now the route consumers has been shutdown, then prepare route services for shutdown now (forced)
241                    for (RouteStartupOrder order : routes) {
242                        for (Service service : order.getServices()) {
243                            prepareShutdown(service, false, true, true, isSuppressLoggingOnTimeout());
244                        }
245                    }
246                } else {
247                    LOG.warn("Timeout occurred during graceful shutdown. Will ignore shutting down the remainder routes."
248                            + " Notice: some resources may still be running as graceful shutdown did not complete successfully.");
249
250                    logInflightExchanges(context, routes, isLogInflightExchangesOnTimeout());
251                }
252            }
253        } finally {
254            currentShutdownTaskFuture = null;
255        }
256
257        // convert to seconds as its easier to read than a big milli seconds number
258        long seconds = TimeUnit.SECONDS.convert(watch.taken(), TimeUnit.MILLISECONDS);
259
260        LOG.info("Graceful shutdown of {} routes completed in {} seconds", routesOrdered.size(), seconds);
261        return true;
262    }
263
264    @Override
265    public boolean forceShutdown(Service service) {
266        return forceShutdown;
267    }
268
269    @Override
270    public boolean hasTimeoutOccurred() {
271        return timeoutOccurred.get();
272    }
273
274    public void setTimeout(long timeout) {
275        if (timeout <= 0) {
276            throw new IllegalArgumentException("Timeout must be a positive value");
277        }
278        this.timeout = timeout;
279    }
280
281    public long getTimeout() {
282        return timeout;
283    }
284
285    public void setTimeUnit(TimeUnit timeUnit) {
286        this.timeUnit = timeUnit;
287    }
288
289    public TimeUnit getTimeUnit() {
290        return timeUnit;
291    }
292
293    public void setShutdownNowOnTimeout(boolean shutdownNowOnTimeout) {
294        this.shutdownNowOnTimeout = shutdownNowOnTimeout;
295    }
296
297    public boolean isShutdownNowOnTimeout() {
298        return shutdownNowOnTimeout;
299    }
300
301    public boolean isShutdownRoutesInReverseOrder() {
302        return shutdownRoutesInReverseOrder;
303    }
304
305    public void setShutdownRoutesInReverseOrder(boolean shutdownRoutesInReverseOrder) {
306        this.shutdownRoutesInReverseOrder = shutdownRoutesInReverseOrder;
307    }
308
309    public boolean isSuppressLoggingOnTimeout() {
310        return suppressLoggingOnTimeout;
311    }
312
313    public void setSuppressLoggingOnTimeout(boolean suppressLoggingOnTimeout) {
314        this.suppressLoggingOnTimeout = suppressLoggingOnTimeout;
315    }
316
317    public boolean isLogInflightExchangesOnTimeout() {
318        return logInflightExchangesOnTimeout;
319    }
320
321    public void setLogInflightExchangesOnTimeout(boolean logInflightExchangesOnTimeout) {
322        this.logInflightExchangesOnTimeout = logInflightExchangesOnTimeout;
323    }
324
325    public CamelContext getCamelContext() {
326        return camelContext;
327    }
328
329    public void setCamelContext(CamelContext camelContext) {
330        this.camelContext = camelContext;
331    }
332
333    public Future<?> getCurrentShutdownTaskFuture() {
334        return currentShutdownTaskFuture;
335    }
336
337    /**
338     * Shutdown all the consumers immediately.
339     *
340     * @param routes the routes to shutdown
341     */
342    protected void shutdownRoutesNow(List<RouteStartupOrder> routes) {
343        for (RouteStartupOrder order : routes) {
344
345            // set the route to shutdown as fast as possible by stopping after
346            // it has completed its current task
347            ShutdownRunningTask current = order.getRoute().getRouteContext().getShutdownRunningTask();
348            if (current != ShutdownRunningTask.CompleteCurrentTaskOnly) {
349                LOG.debug("Changing shutdownRunningTask from {} to " +  ShutdownRunningTask.CompleteCurrentTaskOnly
350                    + " on route {} to shutdown faster", current, order.getRoute().getId());
351                order.getRoute().getRouteContext().setShutdownRunningTask(ShutdownRunningTask.CompleteCurrentTaskOnly);
352            }
353
354            for (Consumer consumer : order.getInputs()) {
355                shutdownNow(consumer);
356            }
357        }
358    }
359
360    /**
361     * Shutdown all the consumers immediately.
362     *
363     * @param consumers the consumers to shutdown
364     */
365    protected void shutdownNow(List<Consumer> consumers) {
366        for (Consumer consumer : consumers) {
367            shutdownNow(consumer);
368        }
369    }
370
371    /**
372     * Shutdown the consumer immediately.
373     *
374     * @param consumer the consumer to shutdown
375     */
376    protected static void shutdownNow(Consumer consumer) {
377        LOG.trace("Shutting down: {}", consumer);
378
379        // allow us to do custom work before delegating to service helper
380        try {
381            ServiceHelper.stopService(consumer);
382        } catch (Throwable e) {
383            LOG.warn("Error occurred while shutting down route: " + consumer + ". This exception will be ignored.", e);
384            // fire event
385            EventHelper.notifyServiceStopFailure(consumer.getEndpoint().getCamelContext(), consumer, e);
386        }
387
388        LOG.trace("Shutdown complete for: {}", consumer);
389    }
390
391    /**
392     * Suspends/stops the consumer immediately.
393     *
394     * @param consumer the consumer to suspend
395     */
396    protected static void suspendNow(Consumer consumer) {
397        LOG.trace("Suspending: {}", consumer);
398
399        // allow us to do custom work before delegating to service helper
400        try {
401            ServiceHelper.suspendService(consumer);
402        } catch (Throwable e) {
403            LOG.warn("Error occurred while suspending route: " + consumer + ". This exception will be ignored.", e);
404            // fire event
405            EventHelper.notifyServiceStopFailure(consumer.getEndpoint().getCamelContext(), consumer, e);
406        }
407
408        LOG.trace("Suspend complete for: {}", consumer);
409    }
410
411    private ExecutorService getExecutorService() {
412        if (executor == null) {
413            // use a thread pool that allow to terminate idle threads so they do not hang around forever
414            executor = camelContext.getExecutorServiceManager().newThreadPool(this, "ShutdownTask", 0, 1);
415        }
416        return executor;
417    }
418
419    @Override
420    protected void doStart() throws Exception {
421        ObjectHelper.notNull(camelContext, "CamelContext");
422        // reset option
423        forceShutdown = false;
424        timeoutOccurred.set(false);
425    }
426
427    @Override
428    protected void doStop() throws Exception {
429        // noop
430    }
431
432    @Override
433    protected void doShutdown() throws Exception {
434        if (executor != null) {
435            // force shutting down as we are shutting down Camel
436            camelContext.getExecutorServiceManager().shutdownNow(executor);
437            // should clear executor so we can restart by creating a new thread pool
438            executor = null;
439        }
440    }
441
442    /**
443     * Prepares the services for shutdown, by invoking the {@link ShutdownPrepared#prepareShutdown(boolean, boolean)} method
444     * on the service if it implement this interface.
445     *
446     * @param service the service
447     * @param forced  whether to force shutdown
448     * @param includeChildren whether to prepare the child of the service as well
449     */
450    private static void prepareShutdown(Service service, boolean suspendOnly, boolean forced, boolean includeChildren, boolean suppressLogging) {
451        Set<Service> list;
452        if (includeChildren) {
453            // include error handlers as we want to prepare them for shutdown as well
454            list = ServiceHelper.getChildServices(service, true);
455        } else {
456            list = new LinkedHashSet<>(1);
457            list.add(service);
458        }
459
460        for (Service child : list) {
461            if (child instanceof ShutdownPrepared) {
462                try {
463                    LOG.trace("Preparing {} shutdown on {}", forced ? "forced" : "", child);
464                    ((ShutdownPrepared) child).prepareShutdown(suspendOnly, forced);
465                } catch (Exception e) {
466                    if (suppressLogging) {
467                        LOG.trace("Error during prepare shutdown on " + child + ". This exception will be ignored.", e);
468                    } else {
469                        LOG.warn("Error during prepare shutdown on " + child + ". This exception will be ignored.", e);
470                    }
471                }
472            }
473        }
474    }
475
476    /**
477     * Holder for deferred consumers
478     */
479    static class ShutdownDeferredConsumer {
480        private final Route route;
481        private final Consumer consumer;
482
483        ShutdownDeferredConsumer(Route route, Consumer consumer) {
484            this.route = route;
485            this.consumer = consumer;
486        }
487
488        Route getRoute() {
489            return route;
490        }
491
492        Consumer getConsumer() {
493            return consumer;
494        }
495    }
496
497    /**
498     * Shutdown task which shutdown all the routes in a graceful manner.
499     */
500    static class ShutdownTask implements Runnable {
501
502        private final CamelContext context;
503        private final List<RouteStartupOrder> routes;
504        private final boolean suspendOnly;
505        private final boolean abortAfterTimeout;
506        private final long timeout;
507        private final TimeUnit timeUnit;
508        private final AtomicBoolean timeoutOccurred;
509        private final boolean logInflightExchangesOnTimeout;
510
511        ShutdownTask(CamelContext context, List<RouteStartupOrder> routes, long timeout, TimeUnit timeUnit,
512                            boolean suspendOnly, boolean abortAfterTimeout, AtomicBoolean timeoutOccurred, boolean logInflightExchangesOnTimeout) {
513            this.context = context;
514            this.routes = routes;
515            this.suspendOnly = suspendOnly;
516            this.abortAfterTimeout = abortAfterTimeout;
517            this.timeout = timeout;
518            this.timeUnit = timeUnit;
519            this.timeoutOccurred = timeoutOccurred;
520            this.logInflightExchangesOnTimeout = logInflightExchangesOnTimeout;
521        }
522
523        public void run() {
524            // the strategy in this run method is to
525            // 1) go over the routes and shutdown those routes which can be shutdown asap
526            //    some routes will be deferred to shutdown at the end, as they are needed
527            //    by other routes so they can complete their tasks
528            // 2) wait until all inflight and pending exchanges has been completed
529            // 3) shutdown the deferred routes
530
531            LOG.debug("There are {} routes to {}", routes.size(), suspendOnly ? "suspend" : "shutdown");
532
533            // list of deferred consumers to shutdown when all exchanges has been completed routed
534            // and thus there are no more inflight exchanges so they can be safely shutdown at that time
535            List<ShutdownDeferredConsumer> deferredConsumers = new ArrayList<>();
536            for (RouteStartupOrder order : routes) {
537
538                ShutdownRoute shutdownRoute = order.getRoute().getRouteContext().getShutdownRoute();
539                ShutdownRunningTask shutdownRunningTask = order.getRoute().getRouteContext().getShutdownRunningTask();
540
541                if (LOG.isTraceEnabled()) {
542                    LOG.trace("{}{} with options [{},{}]",
543                            new Object[]{suspendOnly ? "Suspending route: " : "Shutting down route: ",
544                                order.getRoute().getId(), shutdownRoute, shutdownRunningTask});
545                }
546
547                for (Consumer consumer : order.getInputs()) {
548
549                    boolean suspend = false;
550
551                    // assume we should shutdown if we are not deferred
552                    boolean shutdown = shutdownRoute != ShutdownRoute.Defer;
553
554                    if (shutdown) {
555                        // if we are to shutdown then check whether we can suspend instead as its a more
556                        // gentle way to graceful shutdown
557
558                        // some consumers do not support shutting down so let them decide
559                        // if a consumer is suspendable then prefer to use that and then shutdown later
560                        if (consumer instanceof ShutdownAware) {
561                            shutdown = !((ShutdownAware) consumer).deferShutdown(shutdownRunningTask);
562                        }
563                        if (shutdown && consumer instanceof Suspendable) {
564                            // we prefer to suspend over shutdown
565                            suspend = true;
566                        }
567                    }
568
569                    // log at info level when a route has been shutdown (otherwise log at debug level to not be too noisy)
570                    if (suspend) {
571                        // only suspend it and then later shutdown it
572                        suspendNow(consumer);
573                        // add it to the deferred list so the route will be shutdown later
574                        deferredConsumers.add(new ShutdownDeferredConsumer(order.getRoute(), consumer));
575                        LOG.debug("Route: {} suspended and shutdown deferred, was consuming from: {}", order.getRoute().getId(), order.getRoute().getEndpoint());
576                    } else if (shutdown) {
577                        shutdownNow(consumer);
578                        LOG.info("Route: {} shutdown complete, was consuming from: {}", order.getRoute().getId(), order.getRoute().getEndpoint());
579                    } else {
580                        // we will stop it later, but for now it must run to be able to help all inflight messages
581                        // be safely completed
582                        deferredConsumers.add(new ShutdownDeferredConsumer(order.getRoute(), consumer));
583                        LOG.debug("Route: " + order.getRoute().getId() + (suspendOnly ? " shutdown deferred." : " suspension deferred."));
584                    }
585                }
586            }
587
588            // notify the services we intend to shutdown
589            for (RouteStartupOrder order : routes) {
590                for (Service service : order.getServices()) {
591                    // skip the consumer as we handle that specially
592                    if (service instanceof Consumer) {
593                        continue;
594                    }
595                    prepareShutdown(service, suspendOnly, false, true, false);
596                }
597            }
598
599            // wait till there are no more pending and inflight messages
600            boolean done = false;
601            long loopDelaySeconds = 1;
602            long loopCount = 0;
603            while (!done && !timeoutOccurred.get()) {
604                int size = 0;
605                // number of inflights per route
606                final Map<String, Integer> routeInflight = new LinkedHashMap<>();
607
608                for (RouteStartupOrder order : routes) {
609                    int inflight = context.getInflightRepository().size(order.getRoute().getId());
610                    inflight += getPendingInflightExchanges(order);
611                    if (inflight > 0) {
612                        String routeId = order.getRoute().getId();
613                        routeInflight.put(routeId, inflight);
614                        size += inflight;
615                        LOG.trace("{} inflight and pending exchanges for route: {}", inflight, routeId);
616                    }
617                }
618                if (size > 0) {
619                    try {
620                        // build a message with inflight per route
621                        CollectionStringBuffer csb = new CollectionStringBuffer();
622                        for (Map.Entry<String, Integer> entry : routeInflight.entrySet()) {
623                            String row = String.format("%s = %s", entry.getKey(), entry.getValue());
624                            csb.append(row);
625                        }
626
627                        String msg = "Waiting as there are still " + size + " inflight and pending exchanges to complete, timeout in "
628                                + (TimeUnit.SECONDS.convert(timeout, timeUnit) - (loopCount++ * loopDelaySeconds)) + " seconds.";
629                        msg += " Inflights per route: [" + csb.toString() + "]";
630
631                        LOG.info(msg);
632
633                        // log verbose if DEBUG logging is enabled
634                        logInflightExchanges(context, routes, logInflightExchangesOnTimeout);
635
636                        Thread.sleep(loopDelaySeconds * 1000);
637                    } catch (InterruptedException e) {
638                        if (abortAfterTimeout) {
639                            LOG.warn("Interrupted while waiting during graceful shutdown, will abort.");
640                            return;
641                        } else {
642                            LOG.warn("Interrupted while waiting during graceful shutdown, will force shutdown now.");
643                            break;
644                        }
645                    }
646                } else {
647                    done = true;
648                }
649            }
650
651            // prepare for shutdown
652            for (ShutdownDeferredConsumer deferred : deferredConsumers) {
653                Consumer consumer = deferred.getConsumer();
654                if (consumer instanceof ShutdownAware) {
655                    LOG.trace("Route: {} preparing to shutdown.", deferred.getRoute().getId());
656                    boolean forced = context.getShutdownStrategy().forceShutdown(consumer);
657                    boolean suppress = context.getShutdownStrategy().isSuppressLoggingOnTimeout();
658                    prepareShutdown(consumer, suspendOnly, forced, false, suppress);
659                    LOG.debug("Route: {} preparing to shutdown complete.", deferred.getRoute().getId());
660                }
661            }
662
663            // now all messages has been completed then stop the deferred consumers
664            for (ShutdownDeferredConsumer deferred : deferredConsumers) {
665                Consumer consumer = deferred.getConsumer();
666                if (suspendOnly) {
667                    suspendNow(consumer);
668                    LOG.info("Route: {} suspend complete, was consuming from: {}", deferred.getRoute().getId(), deferred.getConsumer().getEndpoint());
669                } else {
670                    shutdownNow(consumer);
671                    LOG.info("Route: {} shutdown complete, was consuming from: {}", deferred.getRoute().getId(), deferred.getConsumer().getEndpoint());
672                }
673            }
674
675            // now the route consumers has been shutdown, then prepare route services for shutdown
676            for (RouteStartupOrder order : routes) {
677                for (Service service : order.getServices()) {
678                    boolean forced = context.getShutdownStrategy().forceShutdown(service);
679                    boolean suppress = context.getShutdownStrategy().isSuppressLoggingOnTimeout();
680                    prepareShutdown(service, suspendOnly, forced, true, suppress);
681                }
682            }
683        }
684
685    }
686
687    /**
688     * Calculates the total number of inflight exchanges for the given route
689     *
690     * @param order the route
691     * @return number of inflight exchanges
692     */
693    protected static int getPendingInflightExchanges(RouteStartupOrder order) {
694        int inflight = 0;
695
696        // the consumer is the 1st service so we always get the consumer
697        // the child services are EIPs in the routes which may also have pending
698        // inflight exchanges (such as the aggregator)
699        for (Service service : order.getServices()) {
700            Set<Service> children = ServiceHelper.getChildServices(service);
701            for (Service child : children) {
702                if (child instanceof ShutdownAware) {
703                    inflight += ((ShutdownAware) child).getPendingExchangesSize();
704                }
705            }
706        }
707
708        return inflight;
709    }
710
711    /**
712     * Logs information about the inflight exchanges
713     *
714     * @param infoLevel <tt>true</tt> to log at INFO level, <tt>false</tt> to log at DEBUG level
715     */
716    protected static void logInflightExchanges(CamelContext camelContext, List<RouteStartupOrder> routes, boolean infoLevel) {
717        // check if we need to log
718        if (!infoLevel && !LOG.isDebugEnabled()) {
719            return;
720        }
721
722        Collection<InflightRepository.InflightExchange> inflights = camelContext.getInflightRepository().browse();
723        int size = inflights.size();
724        if (size == 0) {
725            return;
726        }
727
728        // filter so inflight must start from any of the routes
729        Set<String> routeIds = new HashSet<>();
730        for (RouteStartupOrder route : routes) {
731            routeIds.add(route.getRoute().getId());
732        }
733        Collection<InflightRepository.InflightExchange> filtered = new ArrayList<>();
734        for (InflightRepository.InflightExchange inflight : inflights) {
735            String routeId = inflight.getExchange().getFromRouteId();
736            if (routeIds.contains(routeId)) {
737                filtered.add(inflight);
738            }
739        }
740
741        size = filtered.size();
742        if (size == 0) {
743            return;
744        }
745
746        StringBuilder sb = new StringBuilder("There are " + size + " inflight exchanges:");
747        for (InflightRepository.InflightExchange inflight : filtered) {
748            sb.append("\n\tInflightExchange: [exchangeId=").append(inflight.getExchange().getExchangeId())
749                    .append(", fromRouteId=").append(inflight.getExchange().getFromRouteId())
750                    .append(", routeId=").append(inflight.getRouteId())
751                    .append(", nodeId=").append(inflight.getNodeId())
752                    .append(", elapsed=").append(inflight.getElapsed())
753                    .append(", duration=").append(inflight.getDuration())
754                    .append("]");
755        }
756
757        if (infoLevel) {
758            LOG.info(sb.toString());
759        } else {
760            LOG.debug(sb.toString());
761        }
762    }
763
764}