You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Stig Døssing <st...@systematic.com> on 2019/09/05 12:22:58 UTC

Logging integration entry and exit with breadcrumbs

Hi,

We'd like to log when our integrations start and finish processing of a message, along with an identifier for the message and derived exchanges. We'd prefer if this could be done globally for all integrations in some common configuration, rather than having to remind our developers to put log statements in at the start and end of routes that receive messages from outside Camel (e.g. via JMS or REST endpoints).

Basically we'd like to only log "at the edge" of Camel, i.e. when a message is picked up by Camel from an external source. We don't want to log exchanges that are created internally, as part of processing another exchange.

For instance given

From("jms:queue:someQueue")
  .routeId("jmsRoute")
  .enrich("direct:endpoint1")

From("direct:endpoint1")
  .routeId("helloRoute")
  .setBody("hello")

We would like to only log when a message starts going through "jmsRoute" as well as when such an exchange is completed, but not when an exchange is created for "helloRoute".

We've enabled breadcrumb ids to help us track which log messages belong to which message, and have implemented an EventNotifierSupport which receives ExchangeCreatedEvent and ExchangeCompletedEvent.

It seems to us that the ExchangeCreatedEvent is sent before the MDC with the breadcrumb is set, so our logging of ExchangeCreatedEvent does not contain the breadcrumb. We are also having a bit of trouble deciding how to filter out exchange events we don't want to log. We're currently looking at the exchange getFromRouteId, and the unit of work route context to filter out created/completed events.

Is there a better mechanism for achieving this than using EventNotifier and exchange events? Is it intended that ExchangeCreatedEvent is processed before the MDC is populated?

RE: Logging integration entry and exit with breadcrumbs

Posted by Stig Døssing <st...@systematic.com>.
Yes, that's what I mean by "created outside Camel". Some external system sending a message into Camel. 

Okay thanks, we'll see if we can figure out a method for deciding when to log.

-----Original Message-----
From: Claus Ibsen <cl...@gmail.com> 
Sent: 6. september 2019 10:31
To: users@camel.apache.org
Subject: Re: Logging integration entry and exit with breadcrumbs

Yeah just look for that existing breadcrumb in the header

There are sending events too, when Camel sends it to endpoints (can be internal or external depending on component - eg direct vs http).
An exchange is always created by Camel as its a Camel holder.
The message on the other hand is the holder of the payload and metadata (eg headers).

So by created outside Camel I assume its some external system that sends a message to Camel eg via JMS or HTTP. As opposed to a Camel timer that is created internally by Camel.
And no you would have to see this per component how they "operate".


On Fri, Sep 6, 2019 at 10:16 AM Stig Døssing <st...@systematic.com> wrote:
>
> Thanks for the quick response.
>
> We sometimes receive messages with the breadcrumb id already set, so we can track messages across the entire system and not just inside Camel, so printing the exchange id would be misleading. Maybe we can extract the breadcrumb id from the exchange in the notifier manually.
>
> Is there a better way to only log when a message crosses the boundary in/out of Camel than to use EventNotifier and ExchangeCreated/CompletedEvent? Is it reasonable to look at the exchange getFromRouteId and unit of work route context (we check these for null) to decide whether the exchange was created due to a message from outside Camel, or is there another way to decide this?
>
>
>
> -----Original Message-----
> From: Claus Ibsen <cl...@gmail.com>
> Sent: 5. september 2019 14:43
> To: users@camel.apache.org
> Subject: Re: Logging integration entry and exit with breadcrumbs
>
> The created event is happening when the exchange is created and before routing and unit of work is setup, and therefore also before mdc unit of work. And yes its intended.
>
> The breadcrumb id is just the exchange id, so you can just get and use 
> that
>
>
> On Thu, Sep 5, 2019 at 2:23 PM Stig Døssing <st...@systematic.com> wrote:
> >
> > Hi,
> >
> > We'd like to log when our integrations start and finish processing of a message, along with an identifier for the message and derived exchanges. We'd prefer if this could be done globally for all integrations in some common configuration, rather than having to remind our developers to put log statements in at the start and end of routes that receive messages from outside Camel (e.g. via JMS or REST endpoints).
> >
> > Basically we'd like to only log "at the edge" of Camel, i.e. when a message is picked up by Camel from an external source. We don't want to log exchanges that are created internally, as part of processing another exchange.
> >
> > For instance given
> >
> > From("jms:queue:someQueue")
> >   .routeId("jmsRoute")
> >   .enrich("direct:endpoint1")
> >
> > From("direct:endpoint1")
> >   .routeId("helloRoute")
> >   .setBody("hello")
> >
> > We would like to only log when a message starts going through "jmsRoute" as well as when such an exchange is completed, but not when an exchange is created for "helloRoute".
> >
> > We've enabled breadcrumb ids to help us track which log messages belong to which message, and have implemented an EventNotifierSupport which receives ExchangeCreatedEvent and ExchangeCompletedEvent.
> >
> > It seems to us that the ExchangeCreatedEvent is sent before the MDC with the breadcrumb is set, so our logging of ExchangeCreatedEvent does not contain the breadcrumb. We are also having a bit of trouble deciding how to filter out exchange events we don't want to log. We're currently looking at the exchange getFromRouteId, and the unit of work route context to filter out created/completed events.
> >
> > Is there a better mechanism for achieving this than using EventNotifier and exchange events? Is it intended that ExchangeCreatedEvent is processed before the MDC is populated?
>
>
>
> --
> Claus Ibsen
> -----------------
> http://davsclaus.com @davsclaus
> Camel in Action 2: https://www.manning.com/ibsen2



--
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2

Re: Logging integration entry and exit with breadcrumbs

Posted by Claus Ibsen <cl...@gmail.com>.
Yeah just look for that existing breadcrumb in the header

There are sending events too, when Camel sends it to endpoints (can be
internal or external depending on component - eg direct vs http).
An exchange is always created by Camel as its a Camel holder.
The message on the other hand is the holder of the payload and
metadata (eg headers).

So by created outside Camel I assume its some external system that
sends a message to Camel eg via JMS or HTTP. As opposed to a Camel
timer that is created internally by Camel.
And no you would have to see this per component how they "operate".


On Fri, Sep 6, 2019 at 10:16 AM Stig Døssing
<st...@systematic.com> wrote:
>
> Thanks for the quick response.
>
> We sometimes receive messages with the breadcrumb id already set, so we can track messages across the entire system and not just inside Camel, so printing the exchange id would be misleading. Maybe we can extract the breadcrumb id from the exchange in the notifier manually.
>
> Is there a better way to only log when a message crosses the boundary in/out of Camel than to use EventNotifier and ExchangeCreated/CompletedEvent? Is it reasonable to look at the exchange getFromRouteId and unit of work route context (we check these for null) to decide whether the exchange was created due to a message from outside Camel, or is there another way to decide this?
>
>
>
> -----Original Message-----
> From: Claus Ibsen <cl...@gmail.com>
> Sent: 5. september 2019 14:43
> To: users@camel.apache.org
> Subject: Re: Logging integration entry and exit with breadcrumbs
>
> The created event is happening when the exchange is created and before routing and unit of work is setup, and therefore also before mdc unit of work. And yes its intended.
>
> The breadcrumb id is just the exchange id, so you can just get and use that
>
>
> On Thu, Sep 5, 2019 at 2:23 PM Stig Døssing <st...@systematic.com> wrote:
> >
> > Hi,
> >
> > We'd like to log when our integrations start and finish processing of a message, along with an identifier for the message and derived exchanges. We'd prefer if this could be done globally for all integrations in some common configuration, rather than having to remind our developers to put log statements in at the start and end of routes that receive messages from outside Camel (e.g. via JMS or REST endpoints).
> >
> > Basically we'd like to only log "at the edge" of Camel, i.e. when a message is picked up by Camel from an external source. We don't want to log exchanges that are created internally, as part of processing another exchange.
> >
> > For instance given
> >
> > From("jms:queue:someQueue")
> >   .routeId("jmsRoute")
> >   .enrich("direct:endpoint1")
> >
> > From("direct:endpoint1")
> >   .routeId("helloRoute")
> >   .setBody("hello")
> >
> > We would like to only log when a message starts going through "jmsRoute" as well as when such an exchange is completed, but not when an exchange is created for "helloRoute".
> >
> > We've enabled breadcrumb ids to help us track which log messages belong to which message, and have implemented an EventNotifierSupport which receives ExchangeCreatedEvent and ExchangeCompletedEvent.
> >
> > It seems to us that the ExchangeCreatedEvent is sent before the MDC with the breadcrumb is set, so our logging of ExchangeCreatedEvent does not contain the breadcrumb. We are also having a bit of trouble deciding how to filter out exchange events we don't want to log. We're currently looking at the exchange getFromRouteId, and the unit of work route context to filter out created/completed events.
> >
> > Is there a better mechanism for achieving this than using EventNotifier and exchange events? Is it intended that ExchangeCreatedEvent is processed before the MDC is populated?
>
>
>
> --
> Claus Ibsen
> -----------------
> http://davsclaus.com @davsclaus
> Camel in Action 2: https://www.manning.com/ibsen2



-- 
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2

RE: Logging integration entry and exit with breadcrumbs

Posted by Stig Døssing <st...@systematic.com>.
Thanks for the quick response.

We sometimes receive messages with the breadcrumb id already set, so we can track messages across the entire system and not just inside Camel, so printing the exchange id would be misleading. Maybe we can extract the breadcrumb id from the exchange in the notifier manually. 

Is there a better way to only log when a message crosses the boundary in/out of Camel than to use EventNotifier and ExchangeCreated/CompletedEvent? Is it reasonable to look at the exchange getFromRouteId and unit of work route context (we check these for null) to decide whether the exchange was created due to a message from outside Camel, or is there another way to decide this?



-----Original Message-----
From: Claus Ibsen <cl...@gmail.com> 
Sent: 5. september 2019 14:43
To: users@camel.apache.org
Subject: Re: Logging integration entry and exit with breadcrumbs

The created event is happening when the exchange is created and before routing and unit of work is setup, and therefore also before mdc unit of work. And yes its intended.

The breadcrumb id is just the exchange id, so you can just get and use that


On Thu, Sep 5, 2019 at 2:23 PM Stig Døssing <st...@systematic.com> wrote:
>
> Hi,
>
> We'd like to log when our integrations start and finish processing of a message, along with an identifier for the message and derived exchanges. We'd prefer if this could be done globally for all integrations in some common configuration, rather than having to remind our developers to put log statements in at the start and end of routes that receive messages from outside Camel (e.g. via JMS or REST endpoints).
>
> Basically we'd like to only log "at the edge" of Camel, i.e. when a message is picked up by Camel from an external source. We don't want to log exchanges that are created internally, as part of processing another exchange.
>
> For instance given
>
> From("jms:queue:someQueue")
>   .routeId("jmsRoute")
>   .enrich("direct:endpoint1")
>
> From("direct:endpoint1")
>   .routeId("helloRoute")
>   .setBody("hello")
>
> We would like to only log when a message starts going through "jmsRoute" as well as when such an exchange is completed, but not when an exchange is created for "helloRoute".
>
> We've enabled breadcrumb ids to help us track which log messages belong to which message, and have implemented an EventNotifierSupport which receives ExchangeCreatedEvent and ExchangeCompletedEvent.
>
> It seems to us that the ExchangeCreatedEvent is sent before the MDC with the breadcrumb is set, so our logging of ExchangeCreatedEvent does not contain the breadcrumb. We are also having a bit of trouble deciding how to filter out exchange events we don't want to log. We're currently looking at the exchange getFromRouteId, and the unit of work route context to filter out created/completed events.
>
> Is there a better mechanism for achieving this than using EventNotifier and exchange events? Is it intended that ExchangeCreatedEvent is processed before the MDC is populated?



--
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2

Re: Logging integration entry and exit with breadcrumbs

Posted by Claus Ibsen <cl...@gmail.com>.
The created event is happening when the exchange is created and before
routing and unit of work is setup, and therefore also before mdc unit
of work. And yes its intended.

The breadcrumb id is just the exchange id, so you can just get and use that


On Thu, Sep 5, 2019 at 2:23 PM Stig Døssing <st...@systematic.com> wrote:
>
> Hi,
>
> We'd like to log when our integrations start and finish processing of a message, along with an identifier for the message and derived exchanges. We'd prefer if this could be done globally for all integrations in some common configuration, rather than having to remind our developers to put log statements in at the start and end of routes that receive messages from outside Camel (e.g. via JMS or REST endpoints).
>
> Basically we'd like to only log "at the edge" of Camel, i.e. when a message is picked up by Camel from an external source. We don't want to log exchanges that are created internally, as part of processing another exchange.
>
> For instance given
>
> From("jms:queue:someQueue")
>   .routeId("jmsRoute")
>   .enrich("direct:endpoint1")
>
> From("direct:endpoint1")
>   .routeId("helloRoute")
>   .setBody("hello")
>
> We would like to only log when a message starts going through "jmsRoute" as well as when such an exchange is completed, but not when an exchange is created for "helloRoute".
>
> We've enabled breadcrumb ids to help us track which log messages belong to which message, and have implemented an EventNotifierSupport which receives ExchangeCreatedEvent and ExchangeCompletedEvent.
>
> It seems to us that the ExchangeCreatedEvent is sent before the MDC with the breadcrumb is set, so our logging of ExchangeCreatedEvent does not contain the breadcrumb. We are also having a bit of trouble deciding how to filter out exchange events we don't want to log. We're currently looking at the exchange getFromRouteId, and the unit of work route context to filter out created/completed events.
>
> Is there a better mechanism for achieving this than using EventNotifier and exchange events? Is it intended that ExchangeCreatedEvent is processed before the MDC is populated?



-- 
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2