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.processor.interceptor;
018
019import java.util.Collections;
020import java.util.List;
021
022import org.apache.camel.AsyncCallback;
023import org.apache.camel.Exchange;
024import org.apache.camel.Processor;
025import org.apache.camel.impl.AggregateRouteNode;
026import org.apache.camel.impl.DefaultRouteNode;
027import org.apache.camel.impl.DoCatchRouteNode;
028import org.apache.camel.impl.DoFinallyRouteNode;
029import org.apache.camel.impl.OnCompletionRouteNode;
030import org.apache.camel.impl.OnExceptionRouteNode;
031import org.apache.camel.model.AggregateDefinition;
032import org.apache.camel.model.CatchDefinition;
033import org.apache.camel.model.Constants;
034import org.apache.camel.model.FinallyDefinition;
035import org.apache.camel.model.InterceptDefinition;
036import org.apache.camel.model.OnCompletionDefinition;
037import org.apache.camel.model.OnExceptionDefinition;
038import org.apache.camel.model.ProcessorDefinition;
039import org.apache.camel.model.ProcessorDefinitionHelper;
040import org.apache.camel.processor.CamelLogProcessor;
041import org.apache.camel.processor.DefaultMaskingFormatter;
042import org.apache.camel.processor.DelegateAsyncProcessor;
043import org.apache.camel.spi.ExchangeFormatter;
044import org.apache.camel.spi.InterceptStrategy;
045import org.apache.camel.spi.MaskingFormatter;
046import org.apache.camel.spi.RouteContext;
047import org.apache.camel.spi.TracedRouteNodes;
048import org.apache.camel.util.ServiceHelper;
049import org.slf4j.Logger;
050import org.slf4j.LoggerFactory;
051
052/**
053 * An interceptor for debugging and tracing routes
054 *
055 * @version 
056 */
057@Deprecated
058public class TraceInterceptor extends DelegateAsyncProcessor implements ExchangeFormatter {
059    private static final Logger LOG = LoggerFactory.getLogger(TraceInterceptor.class);
060
061    private CamelLogProcessor logger;
062
063    private final ProcessorDefinition<?> node;
064    private final Tracer tracer;
065    private TraceFormatter formatter;
066
067    private RouteContext routeContext;
068    private List<TraceEventHandler> traceHandlers;
069
070    public TraceInterceptor(ProcessorDefinition<?> node, Processor target, TraceFormatter formatter, Tracer tracer) {
071        super(target);
072        this.tracer = tracer;
073        this.node = node;
074        this.formatter = formatter;
075        this.logger = tracer.getLogger(this);
076        if (tracer.getFormatter() != null) {
077            this.formatter = tracer.getFormatter();
078        }
079        this.traceHandlers = tracer.getTraceHandlers();
080    }
081
082    @Override
083    public String toString() {
084        return "TraceInterceptor[" + node + "]";
085    }
086
087    public void setRouteContext(RouteContext routeContext) {
088        this.routeContext = routeContext;
089        prepareMaskingFormatter(routeContext);
090    }
091
092    private void prepareMaskingFormatter(RouteContext routeContext) {
093        if (routeContext.isLogMask()) {
094            MaskingFormatter formatter = routeContext.getCamelContext().getRegistry().lookupByNameAndType(Constants.CUSTOM_LOG_MASK_REF, MaskingFormatter.class);
095            if (formatter == null) {
096                formatter = new DefaultMaskingFormatter();
097            }
098            logger.setMaskingFormatter(formatter);
099        }
100    }
101
102    @Override
103    public boolean process(final Exchange exchange, final AsyncCallback callback) {
104        // do not trace if tracing is disabled
105        if (!tracer.isEnabled() || (routeContext != null && !routeContext.isTracing())) {
106            return processor.process(exchange, callback);
107        }
108
109        // interceptor will also trace routes supposed only for TraceEvents so we need to skip
110        // logging TraceEvents to avoid infinite looping
111        if (exchange.getProperty(Exchange.TRACE_EVENT, false, Boolean.class)) {
112            // but we must still process to allow routing of TraceEvents to eg a JPA endpoint
113            return processor.process(exchange, callback);
114        }
115
116        final boolean shouldLog = shouldLogNode(node) && shouldLogExchange(exchange);
117
118        // whether we should trace it or not, some nodes should be skipped as they are abstract
119        // intermediate steps for instance related to on completion
120        boolean trace = true;
121        boolean sync = true;
122
123        // okay this is a regular exchange being routed we might need to log and trace
124        try {
125            // before
126            if (shouldLog) {
127                // traced holds the information about the current traced route path
128                if (exchange.getUnitOfWork() != null) {
129                    TracedRouteNodes traced = exchange.getUnitOfWork().getTracedRouteNodes();
130                    if (traced != null) {
131                        if (node instanceof OnCompletionDefinition || node instanceof OnExceptionDefinition) {
132                            // skip any of these as its just a marker definition
133                            trace = false;
134                        } else if (ProcessorDefinitionHelper.isFirstChildOfType(OnCompletionDefinition.class, node)) {
135                            // special for on completion tracing
136                            traceOnCompletion(traced, exchange);
137                        } else if (ProcessorDefinitionHelper.isFirstChildOfType(OnExceptionDefinition.class, node)) {
138                            // special for on exception
139                            traceOnException(traced, exchange);
140                        } else if (ProcessorDefinitionHelper.isFirstChildOfType(CatchDefinition.class, node)) {
141                            // special for do catch
142                            traceDoCatch(traced, exchange);
143                        } else if (ProcessorDefinitionHelper.isFirstChildOfType(FinallyDefinition.class, node)) {
144                            // special for do finally
145                            traceDoFinally(traced, exchange);
146                        } else if (ProcessorDefinitionHelper.isFirstChildOfType(AggregateDefinition.class, node)) {
147                            // special for aggregate
148                            traceAggregate(traced, exchange);
149                        } else {
150                            // regular so just add it
151                            traced.addTraced(new DefaultRouteNode(node, super.getProcessor()));
152                        }
153                    }
154                } else {
155                    LOG.trace("Cannot trace as this Exchange does not have an UnitOfWork: {}", exchange);
156                }
157            }
158
159            // log and trace the processor
160            Object state = null;
161            if (shouldLog && trace) {
162                logExchange(exchange);
163                // either call the in or generic trace method depending on OUT has been enabled or not
164                if (tracer.isTraceOutExchanges()) {
165                    state = traceExchangeIn(exchange);
166                } else {
167                    traceExchange(exchange);
168                }
169            }
170            final Object traceState = state;
171
172            // special for interceptor where we need to keep booking how far we have routed in the intercepted processors
173            if (node.getParent() instanceof InterceptDefinition && exchange.getUnitOfWork() != null) {
174                TracedRouteNodes traced = exchange.getUnitOfWork().getTracedRouteNodes();
175                if (traced != null) {
176                    traceIntercept((InterceptDefinition) node.getParent(), traced, exchange);
177                }
178            }
179
180            // process the exchange
181            sync = processor.process(exchange, new AsyncCallback() {
182                @Override
183                public void done(boolean doneSync) {
184                    try {
185                        // after (trace out)
186                        if (shouldLog && tracer.isTraceOutExchanges()) {
187                            logExchange(exchange);
188                            traceExchangeOut(exchange, traceState);
189                        }
190                    } catch (Throwable e) {
191                        // some exception occurred in trace logic
192                        if (shouldLogException(exchange)) {
193                            logException(exchange, e);
194                        }
195                        exchange.setException(e);
196                    } finally {
197                        // ensure callback is always invoked
198                        callback.done(doneSync);
199                    }
200                }
201            });
202
203        } catch (Throwable e) {
204            // some exception occurred in trace logic
205            if (shouldLogException(exchange)) {
206                logException(exchange, e);
207            }
208            exchange.setException(e);
209        }
210
211        return sync;
212    }
213
214    private void traceOnCompletion(TracedRouteNodes traced, Exchange exchange) {
215        traced.addTraced(new OnCompletionRouteNode());
216        // do not log and trace as onCompletion should be a new event on its own
217        // add the next step as well so we have onCompletion -> new step
218        traced.addTraced(new DefaultRouteNode(node, super.getProcessor()));
219    }
220
221    private void traceOnException(TracedRouteNodes traced, Exchange exchange) throws Exception {
222        if (traced.getLastNode() != null) {
223            traced.addTraced(new DefaultRouteNode(traced.getLastNode().getProcessorDefinition(), traced.getLastNode().getProcessor()));
224        }
225        traced.addTraced(new OnExceptionRouteNode());
226        // log and trace so we have the from -> onException event as well
227        logExchange(exchange);
228        traceExchange(exchange);
229        traced.addTraced(new DefaultRouteNode(node, super.getProcessor()));
230    }
231
232    private void traceDoCatch(TracedRouteNodes traced, Exchange exchange) throws Exception {
233        if (traced.getLastNode() != null) {
234            traced.addTraced(new DefaultRouteNode(traced.getLastNode().getProcessorDefinition(), traced.getLastNode().getProcessor()));
235        }
236        traced.addTraced(new DoCatchRouteNode());
237        // log and trace so we have the from -> doCatch event as well
238        logExchange(exchange);
239        traceExchange(exchange);
240        traced.addTraced(new DefaultRouteNode(node, super.getProcessor()));
241    }
242
243    private void traceDoFinally(TracedRouteNodes traced, Exchange exchange) throws Exception {
244        if (traced.getLastNode() != null) {
245            traced.addTraced(new DefaultRouteNode(traced.getLastNode().getProcessorDefinition(), traced.getLastNode().getProcessor()));
246        }
247        traced.addTraced(new DoFinallyRouteNode());
248        // log and trace so we have the from -> doFinally event as well
249        logExchange(exchange);
250        traceExchange(exchange);
251        traced.addTraced(new DefaultRouteNode(node, super.getProcessor()));
252    }
253
254    private void traceAggregate(TracedRouteNodes traced, Exchange exchange) {
255        traced.addTraced(new AggregateRouteNode((AggregateDefinition) node.getParent()));
256        traced.addTraced(new DefaultRouteNode(node, super.getProcessor()));
257    }
258
259    protected void traceIntercept(InterceptDefinition intercept, TracedRouteNodes traced, Exchange exchange) throws Exception {
260        // use the counter to get the index of the intercepted processor to be traced
261        Processor last = intercept.getInterceptedProcessor(traced.getAndIncrementCounter(intercept));
262        // skip doing any double tracing of interceptors, so the last must not be a TraceInterceptor instance
263        if (last != null && !(last instanceof TraceInterceptor)) {
264            traced.addTraced(new DefaultRouteNode(node, last));
265
266            boolean shouldLog = shouldLogNode(node) && shouldLogExchange(exchange);
267            if (shouldLog) {
268                // log and trace the processor that was intercepted so we can see it
269                logExchange(exchange);
270                traceExchange(exchange);
271            }
272        }
273    }
274
275    public String format(Exchange exchange) {
276        Object msg = formatter.format(this, this.getNode(), exchange);
277        if (msg != null) {
278            return msg.toString();
279        } else {
280            return null;
281        }
282    }
283
284    // Properties
285    //-------------------------------------------------------------------------
286    public ProcessorDefinition<?> getNode() {
287        return node;
288    }
289
290    public CamelLogProcessor getLogger() {
291        return logger;
292    }
293
294    public TraceFormatter getFormatter() {
295        return formatter;
296    }
297
298    public Tracer getTracer() {
299        return tracer;
300    }
301
302    protected void logExchange(Exchange exchange) throws Exception {
303        // process the exchange that formats and logs it
304        logger.process(exchange);
305    }
306
307    protected void traceExchange(Exchange exchange) throws Exception {
308        for (TraceEventHandler traceHandler : traceHandlers) {
309            traceHandler.traceExchange(node, processor, this, exchange);
310        }
311    }
312
313    protected Object traceExchangeIn(Exchange exchange) throws Exception {
314        Object result = null;
315        for (TraceEventHandler traceHandler : traceHandlers) {
316            Object result1 = traceHandler.traceExchangeIn(node, processor, this, exchange);
317            if (result1 != null) {
318                result = result1;
319            }
320        }
321        return result;
322    }
323
324    protected void traceExchangeOut(Exchange exchange, Object traceState) throws Exception {
325        for (TraceEventHandler traceHandler : traceHandlers) {
326            traceHandler.traceExchangeOut(node, processor, this, exchange, traceState);
327        }
328    }
329
330    protected void logException(Exchange exchange, Throwable throwable) {
331        if (tracer.isTraceExceptions()) {
332            if (tracer.isLogStackTrace()) {
333                logger.process(exchange, throwable);
334            } else {
335                logger.process(exchange, ", Exception: " + throwable.toString());
336            }
337        }
338    }
339
340    /**
341     * Returns true if the given exchange should be logged in the trace list
342     */
343    protected boolean shouldLogExchange(Exchange exchange) {
344        return tracer.isEnabled() && (tracer.getTraceFilter() == null || tracer.getTraceFilter().matches(exchange));
345    }
346
347    /**
348     * Returns true if the given exchange should be logged when an exception was thrown
349     */
350    protected boolean shouldLogException(Exchange exchange) {
351        return tracer.isTraceExceptions();
352    }
353
354    /**
355     * Returns whether exchanges coming out of processors should be traced
356     */
357    public boolean shouldTraceOutExchanges() {
358        return tracer.isTraceOutExchanges();
359    }
360
361    /**
362     * Returns true if the given node should be logged in the trace list
363     */
364    protected boolean shouldLogNode(ProcessorDefinition<?> node) {
365        if (node == null) {
366            return false;
367        }
368        if (!tracer.isTraceInterceptors() && (node instanceof InterceptStrategy)) {
369            return false;
370        }
371        return true;
372    }
373
374    @Override
375    protected void doStart() throws Exception {
376        super.doStart();
377        ServiceHelper.startService(traceHandlers);
378    }
379
380    @Override
381    protected void doStop() throws Exception {
382        super.doStop();
383        ServiceHelper.stopService(traceHandlers);
384    }
385
386    @Deprecated
387    public void setTraceHandler(TraceEventHandler traceHandler) {
388        traceHandlers = Collections.singletonList(traceHandler);
389    }
390}