You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@camel.apache.org by da...@apache.org on 2016/11/11 14:57:27 UTC
camel git commit: CAMEL-10462: Improve MDC Logging in
DefaultCamelContext and RouteService
Repository: camel
Updated Branches:
refs/heads/master ff6c512da -> aecd383d7
CAMEL-10462: Improve MDC Logging in DefaultCamelContext and RouteService
Project: http://git-wip-us.apache.org/repos/asf/camel/repo
Commit: http://git-wip-us.apache.org/repos/asf/camel/commit/aecd383d
Tree: http://git-wip-us.apache.org/repos/asf/camel/tree/aecd383d
Diff: http://git-wip-us.apache.org/repos/asf/camel/diff/aecd383d
Branch: refs/heads/master
Commit: aecd383d727ea5067d74ee56a1148c3eda15d62b
Parents: ff6c512
Author: Quinn Stevenson <qu...@pronoia-solutions.com>
Authored: Thu Nov 10 09:01:31 2016 -0700
Committer: Claus Ibsen <da...@apache.org>
Committed: Fri Nov 11 15:14:02 2016 +0100
----------------------------------------------------------------------
.../apache/camel/impl/DefaultCamelContext.java | 141 +++++++++----
.../org/apache/camel/impl/RouteService.java | 196 +++++++++++--------
2 files changed, 219 insertions(+), 118 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/camel/blob/aecd383d/camel-core/src/main/java/org/apache/camel/impl/DefaultCamelContext.java
----------------------------------------------------------------------
diff --git a/camel-core/src/main/java/org/apache/camel/impl/DefaultCamelContext.java b/camel-core/src/main/java/org/apache/camel/impl/DefaultCamelContext.java
index 3e023df..12295bf 100644
--- a/camel-core/src/main/java/org/apache/camel/impl/DefaultCamelContext.java
+++ b/camel-core/src/main/java/org/apache/camel/impl/DefaultCamelContext.java
@@ -172,6 +172,9 @@ import org.apache.camel.util.TimeUtils;
import org.apache.camel.util.URISupport;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
+
+import static org.apache.camel.impl.MDCUnitOfWork.MDC_CAMEL_CONTEXT_ID;
/**
* Represents the context used to configure routes and the policies to use.
@@ -2896,56 +2899,87 @@ public class DefaultCamelContext extends ServiceSupport implements ModelCamelCon
}
}
+ @Override
public void start() throws Exception {
- vetoStated.set(false);
- startDate = new Date();
- stopWatch.restart();
- log.info("Apache Camel " + getVersion() + " (CamelContext: " + getName() + ") is starting");
+ try (MDCHelper mdcHelper = new MDCHelper()) {
+ vetoStated.set(false);
+ startDate = new Date();
+ stopWatch.restart();
+ log.info("Apache Camel " + getVersion() + " (CamelContext: " + getName() + ") is starting");
+
+ // Note: This is done on context start as we want to avoid doing it during object construction
+ // where we could be dealing with CDI proxied camel contexts which may never be started (CAMEL-9657)
+ // [TODO] Remove in 3.0
+ Container.Instance.manage(this);
+
+ doNotStartRoutesOnFirstStart = !firstStartDone && !isAutoStartup();
+
+ // if the context was configured with auto startup = false, and we are already started,
+ // then we may need to start the routes on the 2nd start call
+ if (firstStartDone && !isAutoStartup() && isStarted()) {
+ // invoke this logic to warm up the routes and if possible also start the routes
+ doStartOrResumeRoutes(routeServices, true, true, false, true);
+ }
- // Note: This is done on context start as we want to avoid doing it during object construction
- // where we could be dealing with CDI proxied camel contexts which may never be started (CAMEL-9657)
- // [TODO] Remove in 3.0
- Container.Instance.manage(this);
+ // super will invoke doStart which will prepare internal services and start routes etc.
+ try {
+ firstStartDone = true;
+ super.start();
+ } catch (VetoCamelContextStartException e) {
+ // mark we veto against starting Camel
+ vetoStated.set(true);
+ if (e.isRethrowException()) {
+ throw e;
+ } else {
+ log.info("CamelContext ({}) vetoed to not start due {}", getName(), e.getMessage());
+ // swallow exception and change state of this camel context to stopped
+ stop();
+ return;
+ }
+ }
- doNotStartRoutesOnFirstStart = !firstStartDone && !isAutoStartup();
+ stopWatch.stop();
+ if (log.isInfoEnabled()) {
+ // count how many routes are actually started
+ int started = 0;
+ for (Route route : getRoutes()) {
+ if (getRouteStatus(route.getId()).isStarted()) {
+ started++;
+ }
+ }
+ log.info("Total " + getRoutes().size() + " routes, of which " + started + " are started.");
+ log.info("Apache Camel " + getVersion() + " (CamelContext: " + getName() + ") started in " + TimeUtils.printDuration(stopWatch.taken()));
+ }
+ EventHelper.notifyCamelContextStarted(this);
+ }
+ }
- // if the context was configured with auto startup = false, and we are already started,
- // then we may need to start the routes on the 2nd start call
- if (firstStartDone && !isAutoStartup() && isStarted()) {
- // invoke this logic to warm up the routes and if possible also start the routes
- doStartOrResumeRoutes(routeServices, true, true, false, true);
+ @Override
+ public void stop() throws Exception {
+ try (MDCHelper mdcHelper = new MDCHelper()) {
+ super.stop();
}
+ }
- // super will invoke doStart which will prepare internal services and start routes etc.
- try {
- firstStartDone = true;
- super.start();
- } catch (VetoCamelContextStartException e) {
- // mark we veto against starting Camel
- vetoStated.set(true);
- if (e.isRethrowException()) {
- throw e;
- } else {
- log.info("CamelContext ({}) vetoed to not start due {}", getName(), e.getMessage());
- // swallow exception and change state of this camel context to stopped
- stop();
- return;
- }
+ @Override
+ public void suspend() throws Exception {
+ try (MDCHelper mdcHelper = new MDCHelper()) {
+ super.suspend();
}
+ }
- stopWatch.stop();
- if (log.isInfoEnabled()) {
- // count how many routes are actually started
- int started = 0;
- for (Route route : getRoutes()) {
- if (getRouteStatus(route.getId()).isStarted()) {
- started++;
- }
- }
- log.info("Total " + getRoutes().size() + " routes, of which " + started + " are started.");
- log.info("Apache Camel " + getVersion() + " (CamelContext: " + getName() + ") started in " + TimeUtils.printDuration(stopWatch.taken()));
+ @Override
+ public void resume() throws Exception {
+ try (MDCHelper mdcHelper = new MDCHelper()) {
+ super.resume();
+ }
+ }
+
+ @Override
+ public void shutdown() throws Exception {
+ try (MDCHelper mdcHelper = new MDCHelper()) {
+ super.shutdown();
}
- EventHelper.notifyCamelContextStarted(this);
}
// Implementation methods
@@ -4266,4 +4300,29 @@ public class DefaultCamelContext extends ServiceSupport implements ModelCamelCon
public String toString() {
return "CamelContext(" + getName() + ")";
}
+
+ class MDCHelper implements AutoCloseable {
+ final Map<String, String> originalContextMap;
+
+ MDCHelper() {
+ if (isUseMDCLogging()) {
+ originalContextMap = MDC.getCopyOfContextMap();
+ MDC.put(MDC_CAMEL_CONTEXT_ID, getName());
+ } else {
+ originalContextMap = null;
+ }
+ }
+
+ @Override
+ public void close() {
+ if (isUseMDCLogging()) {
+ if (originalContextMap != null) {
+ MDC.setContextMap(originalContextMap);
+ } else {
+ MDC.clear();
+ }
+ }
+ }
+
+ }
}
http://git-wip-us.apache.org/repos/asf/camel/blob/aecd383d/camel-core/src/main/java/org/apache/camel/impl/RouteService.java
----------------------------------------------------------------------
diff --git a/camel-core/src/main/java/org/apache/camel/impl/RouteService.java b/camel-core/src/main/java/org/apache/camel/impl/RouteService.java
index d0ff6d0..a39ffd8 100644
--- a/camel-core/src/main/java/org/apache/camel/impl/RouteService.java
+++ b/camel-core/src/main/java/org/apache/camel/impl/RouteService.java
@@ -48,6 +48,10 @@ import org.apache.camel.util.EventHelper;
import org.apache.camel.util.ServiceHelper;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
+
+import static org.apache.camel.impl.MDCUnitOfWork.MDC_CAMEL_CONTEXT_ID;
+import static org.apache.camel.impl.MDCUnitOfWork.MDC_ROUTE_ID;
/**
* Represents the runtime objects for a given {@link RouteDefinition} so that it can be stopped independently
@@ -157,41 +161,43 @@ public class RouteService extends ChildServiceSupport {
if (warmUpDone.compareAndSet(false, true)) {
for (Route route : routes) {
- // warm up the route first
- route.warmUp();
-
- LOG.debug("Starting services on route: {}", route.getId());
- List<Service> services = route.getServices();
+ try (MDCHelper mdcHelper = new MDCHelper(route.getId())) {
+ // warm up the route first
+ route.warmUp();
- // callback that we are staring these services
- route.onStartingServices(services);
+ LOG.debug("Starting services on route: {}", route.getId());
+ List<Service> services = route.getServices();
- // gather list of services to start as we need to start child services as well
- Set<Service> list = new LinkedHashSet<Service>();
- for (Service service : services) {
- list.addAll(ServiceHelper.getChildServices(service));
- }
+ // callback that we are staring these services
+ route.onStartingServices(services);
- // split into consumers and child services as we need to start the consumers
- // afterwards to avoid them being active while the others start
- List<Service> childServices = new ArrayList<Service>();
- for (Service service : list) {
-
- // inject the route
- if (service instanceof RouteAware) {
- ((RouteAware) service).setRoute(route);
+ // gather list of services to start as we need to start child services as well
+ Set<Service> list = new LinkedHashSet<Service>();
+ for (Service service : services) {
+ list.addAll(ServiceHelper.getChildServices(service));
}
- if (service instanceof Consumer) {
- inputs.put(route, (Consumer) service);
- } else {
- childServices.add(service);
+ // split into consumers and child services as we need to start the consumers
+ // afterwards to avoid them being active while the others start
+ List<Service> childServices = new ArrayList<Service>();
+ for (Service service : list) {
+
+ // inject the route
+ if (service instanceof RouteAware) {
+ ((RouteAware) service).setRoute(route);
+ }
+
+ if (service instanceof Consumer) {
+ inputs.put(route, (Consumer) service);
+ } else {
+ childServices.add(service);
+ }
}
- }
- startChildService(route, childServices);
+ startChildService(route, childServices);
- // fire event
- EventHelper.notifyRouteAdded(camelContext, route);
+ // fire event
+ EventHelper.notifyRouteAdded(camelContext, route);
+ }
}
// ensure lifecycle strategy is invoked which among others enlist the route in JMX
@@ -208,18 +214,20 @@ public class RouteService extends ChildServiceSupport {
warmUp();
for (Route route : routes) {
- // start the route itself
- ServiceHelper.startService(route);
-
- // invoke callbacks on route policy
- if (route.getRouteContext().getRoutePolicyList() != null) {
- for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
- routePolicy.onStart(route);
+ try (MDCHelper mdcHelper = new MDCHelper(route.getId())) {
+ // start the route itself
+ ServiceHelper.startService(route);
+
+ // invoke callbacks on route policy
+ if (route.getRouteContext().getRoutePolicyList() != null) {
+ for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
+ routePolicy.onStart(route);
+ }
}
- }
- // fire event
- EventHelper.notifyRouteStarted(camelContext, route);
+ // fire event
+ EventHelper.notifyRouteStarted(camelContext, route);
+ }
}
}
@@ -236,29 +244,31 @@ public class RouteService extends ChildServiceSupport {
}
for (Route route : routes) {
- LOG.debug("Stopping services on route: {}", route.getId());
+ try (MDCHelper mdcHelper = new MDCHelper(route.getId())) {
+ LOG.debug("Stopping services on route: {}", route.getId());
- // gather list of services to stop as we need to start child services as well
- Set<Service> services = gatherChildServices(route, true);
+ // gather list of services to stop as we need to start child services as well
+ Set<Service> services = gatherChildServices(route, true);
- // stop services
- stopChildService(route, services, isShutdownCamelContext);
+ // stop services
+ stopChildService(route, services, isShutdownCamelContext);
- // stop the route itself
- if (isShutdownCamelContext) {
- ServiceHelper.stopAndShutdownServices(route);
- } else {
- ServiceHelper.stopServices(route);
- }
+ // stop the route itself
+ if (isShutdownCamelContext) {
+ ServiceHelper.stopAndShutdownServices(route);
+ } else {
+ ServiceHelper.stopServices(route);
+ }
- // invoke callbacks on route policy
- if (route.getRouteContext().getRoutePolicyList() != null) {
- for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
- routePolicy.onStop(route);
+ // invoke callbacks on route policy
+ if (route.getRouteContext().getRoutePolicyList() != null) {
+ for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
+ routePolicy.onStop(route);
+ }
}
+ // fire event
+ EventHelper.notifyRouteStopped(camelContext, route);
}
- // fire event
- EventHelper.notifyRouteStopped(camelContext, route);
}
if (isRemovingRoutes()) {
camelContext.removeRouteCollection(routes);
@@ -270,28 +280,30 @@ public class RouteService extends ChildServiceSupport {
@Override
protected void doShutdown() throws Exception {
for (Route route : routes) {
- LOG.debug("Shutting down services on route: {}", route.getId());
+ try (MDCHelper mdcHelper = new MDCHelper(route.getId())) {
+ LOG.debug("Shutting down services on route: {}", route.getId());
- // gather list of services to stop as we need to start child services as well
- Set<Service> services = gatherChildServices(route, true);
+ // gather list of services to stop as we need to start child services as well
+ Set<Service> services = gatherChildServices(route, true);
- // shutdown services
- stopChildService(route, services, true);
+ // shutdown services
+ stopChildService(route, services, true);
- // shutdown the route itself
- ServiceHelper.stopAndShutdownServices(route);
+ // shutdown the route itself
+ ServiceHelper.stopAndShutdownServices(route);
- // endpoints should only be stopped when Camel is shutting down
- // see more details in the warmUp method
- ServiceHelper.stopAndShutdownServices(route.getEndpoint());
- // invoke callbacks on route policy
- if (route.getRouteContext().getRoutePolicyList() != null) {
- for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
- routePolicy.onRemove(route);
+ // endpoints should only be stopped when Camel is shutting down
+ // see more details in the warmUp method
+ ServiceHelper.stopAndShutdownServices(route.getEndpoint());
+ // invoke callbacks on route policy
+ if (route.getRouteContext().getRoutePolicyList() != null) {
+ for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
+ routePolicy.onRemove(route);
+ }
}
+ // fire event
+ EventHelper.notifyRouteRemoved(camelContext, route);
}
- // fire event
- EventHelper.notifyRouteRemoved(camelContext, route);
}
// need to call onRoutesRemove when the CamelContext is shutting down or Route is shutdown
@@ -318,9 +330,11 @@ public class RouteService extends ChildServiceSupport {
// suspend and resume logic is provided by DefaultCamelContext which leverages ShutdownStrategy
// to safely suspend and resume
for (Route route : routes) {
- if (route.getRouteContext().getRoutePolicyList() != null) {
- for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
- routePolicy.onSuspend(route);
+ try (MDCHelper mdcHelper = new MDCHelper(route.getId())) {
+ if (route.getRouteContext().getRoutePolicyList() != null) {
+ for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
+ routePolicy.onSuspend(route);
+ }
}
}
}
@@ -331,9 +345,11 @@ public class RouteService extends ChildServiceSupport {
// suspend and resume logic is provided by DefaultCamelContext which leverages ShutdownStrategy
// to safely suspend and resume
for (Route route : routes) {
- if (route.getRouteContext().getRoutePolicyList() != null) {
- for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
- routePolicy.onResume(route);
+ try (MDCHelper mdcHelper = new MDCHelper(route.getId())) {
+ if (route.getRouteContext().getRoutePolicyList() != null) {
+ for (RoutePolicy routePolicy : route.getRouteContext().getRoutePolicyList()) {
+ routePolicy.onResume(route);
+ }
}
}
}
@@ -441,4 +457,30 @@ public class RouteService extends ChildServiceSupport {
}
}
+ class MDCHelper implements AutoCloseable {
+ final Map<String, String> originalContextMap;
+
+ MDCHelper(String routeId) {
+ if (getCamelContext().isUseMDCLogging()) {
+ originalContextMap = MDC.getCopyOfContextMap();
+ MDC.put(MDC_CAMEL_CONTEXT_ID, getCamelContext().getName());
+ MDC.put(MDC_ROUTE_ID, routeId);
+ } else {
+ originalContextMap = null;
+ }
+ }
+
+ @Override
+ public void close() {
+ if (getCamelContext().isUseMDCLogging()) {
+ if (originalContextMap != null) {
+ MDC.setContextMap(originalContextMap);
+ } else {
+ MDC.clear();
+ }
+ }
+ }
+
+ }
+
}