Uploaded image for project: 'Red Hat Fuse'
  1. Red Hat Fuse
  2. ENTESB-5521

MDC Sift logging is not consistently produced

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • jboss-fuse-6.1-patches
    • jboss-fuse-6.1
    • Camel
    • None
    • % %
    • Hide

      Enable SIFT in org.ops4j.pax.logging.cfg as follows:

      # Root logger
      log4j.rootLogger = INFO, out, sift, osgi:VmLogAppender
      . . .
      # Sift appender
      log4j.appender.sift=org.apache.log4j.sift.MDCSiftingAppender
      #log4j.appender.sift.key=bundle.name
      log4j.appender.sift.key=camel.contextId
      log4j.appender.sift.default=servicemix
      log4j.appender.sift.appender=org.apache.log4j.FileAppender
      log4j.appender.sift.appender.layout=org.apache.log4j.PatternLayout
      log4j.appender.sift.appender.layout.ConversionPattern=%d{ABSOLUTE} | %-5.5p | %-16.16t | %-32.32c{1} | %m%n
      #log4j.appender.sift.appender.file=${karaf.data}/log/$\\{bundle.name\\}.log
      log4j.appender.sift.appender.file=${karaf.data}/log/$\\{camel.contextId\\}.log
      log4j.appender.sift.appender.append=true
      

      Start the 6.1 container.

      Extract the CamelTest.zip and please review the camel-context.xml file in the blueprint directory. Deploy the bundle into the Fuse 6.1 container, and then start the bundle. The Camel context is driven by a timer that fires off 5 messages - one at a time - that are sent and received to and from the embedded A-MQ broker.

      The Camel context and its routes generate the following (expected) INFO log statements, which are fully reflected in the fuse.log:

      14:43:35,194 | INFO  |  - timer://foo11 | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-35
      14:43:35,206 | INFO  |  - timer://foo11 | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-35
      14:43:35,260 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-35
      14:43:35,283 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-35
      14:43:35,298 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-35
      14:43:35,299 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-35
      14:43:40,182 | INFO  |  - timer://foo11 | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-40
      14:43:40,182 | INFO  |  - timer://foo11 | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-40
      14:43:40,185 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-40
      14:43:40,189 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-40
      14:43:40,191 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-40
      14:43:40,191 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-40
      14:43:45,183 | INFO  |  - timer://foo11 | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-45
      14:43:45,184 | INFO  |  - timer://foo11 | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-45
      14:43:45,187 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-45
      14:43:45,192 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-45
      14:43:45,193 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-45
      14:43:45,194 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-45
      14:43:50,184 | INFO  |  - timer://foo11 | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-50
      14:43:50,184 | INFO  |  - timer://foo11 | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-50
      14:43:50,186 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-50
      14:43:50,189 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-50
      14:43:50,191 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-50
      14:43:50,192 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-50
      14:43:55,184 | INFO  |  - timer://foo11 | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-55
      14:43:55,185 | INFO  |  - timer://foo11 | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-55
      14:43:55,187 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-55
      14:43:55,234 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-55
      14:43:55,305 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-55
      14:43:55,306 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-55
      

      However, if you look at the SIFT produced foo.bar.context.log, you'll note only partial output:

      14:43:35,194 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-35
      14:43:35,206 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-35
      14:43:35,260 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-35
      14:43:35,283 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-35
      14:43:35,298 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-35
      14:43:35,299 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-35
      14:43:40,182 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-40
      14:43:40,182 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-40
      14:43:40,185 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-40
      14:43:40,189 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-40
      14:43:45,183 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-45
      14:43:45,184 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-45
      14:43:45,187 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-45
      14:43:45,192 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-45
      14:43:50,184 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-50
      14:43:50,184 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-50
      14:43:50,186 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-50
      14:43:50,189 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-50
      14:43:55,184 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-55
      14:43:55,185 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-55
      14:43:55,187 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-55
      14:43:55,234 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-55
      

      You'll note that only the first firing has the following complete and expected set of INFO statements:

      14:43:35,194 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-35
      14:43:35,206 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-35
      14:43:35,260 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-35
      14:43:35,283 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-35
      14:43:35,298 | INFO  | r[TOOL.DEFAULT2] | sendMsg                          | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-35
      14:43:35,299 | INFO  | r[TOOL.DEFAULT2] | timer-driver                     | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-35
      

      Firings 2-5 have a partial set; take for example firing #2.

      14:43:40,182 | INFO  |  - timer://foo11 | timer-driver                     | Timer route has fired: 02-43-40
      14:43:40,182 | INFO  |  - timer://foo11 | sendMsg                          | direct:sendMsg:entered with 02-43-40
      14:43:40,185 | INFO  | r[TOOL.DEFAULT1] | rcvMsg1                          | rcvMsg1: message received = 02-43-40
      14:43:40,189 | INFO  | r[TOOL.DEFAULT2] | rcvMsg2                          | rcvMsg2: message received = [rcvMsg1] 02-43-40
      

      What's missing are those INFO statements that follow the second send; i.e.,

      <to uri="jms:TOOL.DEFAULT2" pattern="InOut" />
      
      Show
      Enable SIFT in org.ops4j.pax.logging.cfg as follows: # Root logger log4j.rootLogger = INFO, out, sift, osgi:VmLogAppender . . . # Sift appender log4j.appender.sift=org.apache.log4j.sift.MDCSiftingAppender #log4j.appender.sift.key=bundle.name log4j.appender.sift.key=camel.contextId log4j.appender.sift. default =servicemix log4j.appender.sift.appender=org.apache.log4j.FileAppender log4j.appender.sift.appender.layout=org.apache.log4j.PatternLayout log4j.appender.sift.appender.layout.ConversionPattern=%d{ABSOLUTE} | %-5.5p | %-16.16t | %-32.32c{1} | %m%n #log4j.appender.sift.appender.file=${karaf.data}/log/$\\{bundle.name\\}.log log4j.appender.sift.appender.file=${karaf.data}/log/$\\{camel.contextId\\}.log log4j.appender.sift.appender.append= true Start the 6.1 container. Extract the CamelTest.zip and please review the camel-context.xml file in the blueprint directory. Deploy the bundle into the Fuse 6.1 container, and then start the bundle. The Camel context is driven by a timer that fires off 5 messages - one at a time - that are sent and received to and from the embedded A-MQ broker. The Camel context and its routes generate the following (expected) INFO log statements, which are fully reflected in the fuse.log: 14:43:35,194 | INFO | - timer: //foo11 | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-35 14:43:35,206 | INFO | - timer: //foo11 | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-35 14:43:35,260 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-35 14:43:35,283 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-35 14:43:35,298 | INFO | r[TOOL.DEFAULT2] | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-35 14:43:35,299 | INFO | r[TOOL.DEFAULT2] | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-35 14:43:40,182 | INFO | - timer: //foo11 | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-40 14:43:40,182 | INFO | - timer: //foo11 | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-40 14:43:40,185 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-40 14:43:40,189 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-40 14:43:40,191 | INFO | r[TOOL.DEFAULT2] | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-40 14:43:40,191 | INFO | r[TOOL.DEFAULT2] | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-40 14:43:45,183 | INFO | - timer: //foo11 | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-45 14:43:45,184 | INFO | - timer: //foo11 | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-45 14:43:45,187 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-45 14:43:45,192 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-45 14:43:45,193 | INFO | r[TOOL.DEFAULT2] | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-45 14:43:45,194 | INFO | r[TOOL.DEFAULT2] | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-45 14:43:50,184 | INFO | - timer: //foo11 | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-50 14:43:50,184 | INFO | - timer: //foo11 | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-50 14:43:50,186 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-50 14:43:50,189 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-50 14:43:50,191 | INFO | r[TOOL.DEFAULT2] | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-50 14:43:50,192 | INFO | r[TOOL.DEFAULT2] | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-50 14:43:55,184 | INFO | - timer: //foo11 | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route has fired: 02-43-55 14:43:55,185 | INFO | - timer: //foo11 | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:entered with 02-43-55 14:43:55,187 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg1: message received = 02-43-55 14:43:55,234 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | rcvMsg2: message received = [rcvMsg1] 02-43-55 14:43:55,305 | INFO | r[TOOL.DEFAULT2] | sendMsg | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-55 14:43:55,306 | INFO | r[TOOL.DEFAULT2] | timer-driver | 139 - org.apache.camel.camel-core - 2.12.0.redhat-611454 | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-55 However, if you look at the SIFT produced foo.bar.context.log, you'll note only partial output: 14:43:35,194 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-35 14:43:35,206 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-35 14:43:35,260 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-35 14:43:35,283 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-35 14:43:35,298 | INFO | r[TOOL.DEFAULT2] | sendMsg | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-35 14:43:35,299 | INFO | r[TOOL.DEFAULT2] | timer-driver | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-35 14:43:40,182 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-40 14:43:40,182 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-40 14:43:40,185 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-40 14:43:40,189 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-40 14:43:45,183 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-45 14:43:45,184 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-45 14:43:45,187 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-45 14:43:45,192 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-45 14:43:50,184 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-50 14:43:50,184 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-50 14:43:50,186 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-50 14:43:50,189 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-50 14:43:55,184 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-55 14:43:55,185 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-55 14:43:55,187 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-55 14:43:55,234 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-55 You'll note that only the first firing has the following complete and expected set of INFO statements: 14:43:35,194 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-35 14:43:35,206 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-35 14:43:35,260 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-35 14:43:35,283 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-35 14:43:35,298 | INFO | r[TOOL.DEFAULT2] | sendMsg | direct:sendMsg:completed with [rcvMsg2] [rcvMsg1] 02-43-35 14:43:35,299 | INFO | r[TOOL.DEFAULT2] | timer-driver | Timer route completed: [rcvMsg2] [rcvMsg1] 02-43-35 Firings 2-5 have a partial set; take for example firing #2. 14:43:40,182 | INFO | - timer: //foo11 | timer-driver | Timer route has fired: 02-43-40 14:43:40,182 | INFO | - timer: //foo11 | sendMsg | direct:sendMsg:entered with 02-43-40 14:43:40,185 | INFO | r[TOOL.DEFAULT1] | rcvMsg1 | rcvMsg1: message received = 02-43-40 14:43:40,189 | INFO | r[TOOL.DEFAULT2] | rcvMsg2 | rcvMsg2: message received = [rcvMsg1] 02-43-40 What's missing are those INFO statements that follow the second send; i.e., <to uri= "jms:TOOL.DEFAULT2" pattern= "InOut" />

      When used within a Camel context, MDC SIFT logging exhibits inconsistent behavior

              ggrzybek Grzegorz Grzybek
              Argo_Integration Travis North (Inactive)
              Martin Basovnik Martin Basovnik (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: