Source code

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.Collection;
020import java.util.Collections;
021import java.util.LinkedList;
022import java.util.Map;
023import java.util.concurrent.ConcurrentHashMap;
024import java.util.concurrent.CountDownLatch;
025import java.util.concurrent.RejectedExecutionException;
026import java.util.concurrent.atomic.AtomicLong;
027
028import org.apache.camel.Exchange;
029import org.apache.camel.MessageHistory;
030import org.apache.camel.NamedNode;
031import org.apache.camel.processor.DefaultExchangeFormatter;
032import org.apache.camel.spi.AsyncProcessorAwaitManager;
033import org.apache.camel.spi.ExchangeFormatter;
034import org.apache.camel.support.ServiceSupport;
035import org.apache.camel.util.MessageHelper;
036import org.apache.camel.util.ObjectHelper;
037import org.slf4j.Logger;
038import org.slf4j.LoggerFactory;
039
040public class DefaultAsyncProcessorAwaitManager extends ServiceSupport implements AsyncProcessorAwaitManager {
041
042    private static final Logger LOG = LoggerFactory.getLogger(DefaultAsyncProcessorAwaitManager.class);
043
044    private final AsyncProcessorAwaitManager.Statistics statistics = new UtilizationStatistics();
045    private final AtomicLong blockedCounter = new AtomicLong();
046    private final AtomicLong interruptedCounter = new AtomicLong();
047    private final AtomicLong totalDuration = new AtomicLong();
048    private final AtomicLong minDuration = new AtomicLong();
049    private final AtomicLong maxDuration = new AtomicLong();
050    private final AtomicLong meanDuration = new AtomicLong();
051
052    private final Map<Exchange, AwaitThread> inflight = new ConcurrentHashMap<>();
053    private final ExchangeFormatter exchangeFormatter;
054    private boolean interruptThreadsWhileStopping = true;
055
056    public DefaultAsyncProcessorAwaitManager() {
057        // setup exchange formatter to be used for message history dump
058        DefaultExchangeFormatter formatter = new DefaultExchangeFormatter();
059        formatter.setShowExchangeId(true);
060        formatter.setMultiline(true);
061        formatter.setShowHeaders(true);
062        formatter.setStyle(DefaultExchangeFormatter.OutputStyle.Fixed);
063        this.exchangeFormatter = formatter;
064    }
065
066    @Override
067    public void await(Exchange exchange, CountDownLatch latch) {
068        LOG.trace("Waiting for asynchronous callback before continuing for exchangeId: {} -> {}",
069                exchange.getExchangeId(), exchange);
070        try {
071            if (statistics.isStatisticsEnabled()) {
072                blockedCounter.incrementAndGet();
073            }
074            inflight.put(exchange, new AwaitThreadEntry(Thread.currentThread(), exchange, latch));
075            latch.await();
076            LOG.trace("Asynchronous callback received, will continue routing exchangeId: {} -> {}",
077                    exchange.getExchangeId(), exchange);
078
079        } catch (InterruptedException e) {
080            LOG.trace("Interrupted while waiting for callback, will continue routing exchangeId: {} -> {}",
081                    exchange.getExchangeId(), exchange);
082            exchange.setException(e);
083        } finally {
084            AwaitThread thread = inflight.remove(exchange);
085
086            if (statistics.isStatisticsEnabled() && thread != null) {
087                long time = thread.getWaitDuration();
088                long total = totalDuration.get() + time;
089                totalDuration.set(total);
090
091                if (time < minDuration.get()) {
092                    minDuration.set(time);
093                } else if (time > maxDuration.get()) {
094                    maxDuration.set(time);
095                }
096
097                // update mean
098                long count = blockedCounter.get();
099                long mean = count > 0 ? total / count : 0;
100                meanDuration.set(mean);
101            }
102        }
103    }
104
105    @Override
106    public void countDown(Exchange exchange, CountDownLatch latch) {
107        LOG.trace("Asynchronous callback received for exchangeId: {}", exchange.getExchangeId());
108        latch.countDown();
109    }
110
111    @Override
112    public int size() {
113        return inflight.size();
114    }
115
116    @Override
117    public Collection<AwaitThread> browse() {
118        return Collections.unmodifiableCollection(inflight.values());
119    }
120
121    @Override
122    public void interrupt(String exchangeId) {
123        // need to find the exchange with the given exchange id
124        Exchange found = null;
125        for (AsyncProcessorAwaitManager.AwaitThread entry : browse()) {
126            Exchange exchange = entry.getExchange();
127            if (exchangeId.equals(exchange.getExchangeId())) {
128                found = exchange;
129                break;
130            }
131        }
132
133        if (found != null) {
134            interrupt(found);
135        }
136    }
137
138    @Override
139    public void interrupt(Exchange exchange) {
140        AwaitThreadEntry entry = (AwaitThreadEntry) inflight.get(exchange);
141        if (entry != null) {
142            try {
143                StringBuilder sb = new StringBuilder();
144                sb.append("Interrupted while waiting for asynchronous callback, will release the following blocked thread which was waiting for exchange to finish processing with exchangeId: ");
145                sb.append(exchange.getExchangeId());
146                sb.append("\n");
147
148                sb.append(dumpBlockedThread(entry));
149
150                // dump a route stack trace of the exchange
151                String routeStackTrace = MessageHelper.dumpMessageHistoryStacktrace(exchange, exchangeFormatter, false);
152                if (routeStackTrace != null) {
153                    sb.append(routeStackTrace);
154                }
155                LOG.warn(sb.toString());
156
157            } catch (Exception e) {
158                throw ObjectHelper.wrapRuntimeCamelException(e);
159            } finally {
160                if (statistics.isStatisticsEnabled()) {
161                    interruptedCounter.incrementAndGet();
162                }
163                exchange.setException(new RejectedExecutionException("Interrupted while waiting for asynchronous callback for exchangeId: " + exchange.getExchangeId()));
164                exchange.setProperty(Exchange.INTERRUPTED, Boolean.TRUE);
165                entry.getLatch().countDown();
166            }
167        }
168    }
169
170    public boolean isInterruptThreadsWhileStopping() {
171        return interruptThreadsWhileStopping;
172    }
173
174    public void setInterruptThreadsWhileStopping(boolean interruptThreadsWhileStopping) {
175        this.interruptThreadsWhileStopping = interruptThreadsWhileStopping;
176    }
177
178    public Statistics getStatistics() {
179        return statistics;
180    }
181
182    @Override
183    protected void doStart() throws Exception {
184        // noop
185    }
186
187    @Override
188    protected void doStop() throws Exception {
189        Collection<AwaitThread> threads = browse();
190        int count = threads.size();
191        if (count > 0) {
192            LOG.warn("Shutting down while there are still {} inflight threads currently blocked.", count);
193
194            StringBuilder sb = new StringBuilder();
195            for (AwaitThread entry : threads) {
196                sb.append(dumpBlockedThread(entry));
197            }
198
199            if (isInterruptThreadsWhileStopping()) {
200                LOG.warn("The following threads are blocked and will be interrupted so the threads are released:\n" + sb.toString());
201                for (AwaitThread entry : threads) {
202                    try {
203                        interrupt(entry.getExchange());
204                    } catch (Throwable e) {
205                        LOG.warn("Error while interrupting thread: " + entry.getBlockedThread().getName() + ". This exception is ignored.", e);
206                    }
207                }
208            } else {
209                LOG.warn("The following threads are blocked, and may reside in the JVM:\n" + sb.toString());
210            }
211        } else {
212            LOG.debug("Shutting down with no inflight threads.");
213        }
214
215        inflight.clear();
216    }
217
218    private static String dumpBlockedThread(AwaitThread entry) {
219        StringBuilder sb = new StringBuilder();
220        sb.append("\n");
221        sb.append("Blocked Thread\n");
222        sb.append("---------------------------------------------------------------------------------------------------------------------------------------\n");
223
224        sb.append(style("Id:")).append(entry.getBlockedThread().getId()).append("\n");
225        sb.append(style("Name:")).append(entry.getBlockedThread().getName()).append("\n");
226        sb.append(style("RouteId:")).append(safeNull(entry.getRouteId())).append("\n");
227        sb.append(style("NodeId:")).append(safeNull(entry.getNodeId())).append("\n");
228        sb.append(style("Duration:")).append(entry.getWaitDuration()).append(" msec.\n");
229        return sb.toString();
230    }
231
232    private static String style(String label) {
233        return String.format("\t%-20s", label);
234    }
235
236    private static String safeNull(Object value) {
237        return value != null ? value.toString() : "";
238    }
239
240    private static final class AwaitThreadEntry implements AwaitThread {
241        private final Thread thread;
242        private final Exchange exchange;
243        private final CountDownLatch latch;
244        private final long start;
245
246        private AwaitThreadEntry(Thread thread, Exchange exchange, CountDownLatch latch) {
247            this.thread = thread;
248            this.exchange = exchange;
249            this.latch = latch;
250            this.start = System.currentTimeMillis();
251        }
252
253        @Override
254        public Thread getBlockedThread() {
255            return thread;
256        }
257
258        @Override
259        public Exchange getExchange() {
260            return exchange;
261        }
262
263        @Override
264        public long getWaitDuration() {
265            return System.currentTimeMillis() - start;
266        }
267
268        @Override
269        public String getRouteId() {
270            MessageHistory lastMessageHistory = getLastMessageHistory();
271            if (lastMessageHistory == null) {
272                return null;
273            }
274            return lastMessageHistory.getRouteId();
275        }
276
277        @Override
278        public String getNodeId() {
279            NamedNode node = getNode();
280            if (node == null) {
281                return null;
282            }
283            return node.getId();
284        }
285
286        public CountDownLatch getLatch() {
287            return latch;
288        }
289
290        private NamedNode getNode() {
291            MessageHistory lastMessageHistory = getLastMessageHistory();
292            if (lastMessageHistory == null) {
293                return null;
294            }
295            return lastMessageHistory.getNode();
296        }
297
298        private MessageHistory getLastMessageHistory() {
299            LinkedList<MessageHistory> list = getMessageHistories();
300            if (list == null || list.isEmpty()) {
301                return null;
302            }
303            return list.getLast();
304        }
305
306        private LinkedList<MessageHistory> getMessageHistories() {
307            return exchange.getProperty(Exchange.MESSAGE_HISTORY, LinkedList.class);
308        }
309
310        @Override
311        public String toString() {
312            return "AwaitThreadEntry[name=" + thread.getName() + ", exchangeId=" + exchange.getExchangeId() + "]";
313        }
314    }
315
316    /**
317     * Represents utilization statistics
318     */
319    private final class UtilizationStatistics implements AsyncProcessorAwaitManager.Statistics {
320
321        private boolean statisticsEnabled;
322
323        @Override
324        public long getThreadsBlocked() {
325            return blockedCounter.get();
326        }
327
328        @Override
329        public long getThreadsInterrupted() {
330            return interruptedCounter.get();
331        }
332
333        @Override
334        public long getTotalDuration() {
335            return totalDuration.get();
336        }
337
338        @Override
339        public long getMinDuration() {
340            return minDuration.get();
341        }
342
343        @Override
344        public long getMaxDuration() {
345            return maxDuration.get();
346        }
347
348        @Override
349        public long getMeanDuration() {
350            return meanDuration.get();
351        }
352
353        @Override
354        public void reset() {
355            blockedCounter.set(0);
356            interruptedCounter.set(0);
357            totalDuration.set(0);
358            minDuration.set(0);
359            maxDuration.set(0);
360            meanDuration.set(0);
361        }
362
363        @Override
364        public boolean isStatisticsEnabled() {
365            return statisticsEnabled;
366        }
367
368        @Override
369        public void setStatisticsEnabled(boolean statisticsEnabled) {
370            this.statisticsEnabled = statisticsEnabled;
371        }
372
373        @Override
374        public String toString() {
375            return String.format("AsyncProcessAwaitManager utilization[blocked=%s, interrupted=%s, total=%s min=%s, max=%s, mean=%s]",
376                    getThreadsBlocked(), getThreadsInterrupted(), getTotalDuration(), getMinDuration(), getMaxDuration(), getMeanDuration());
377        }
378    }
379
380}