Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OpenTracing: Intercept log messages to record against any available a… #1559

Closed
wants to merge 1 commit into from

Conversation

objectiser
Copy link
Contributor

…ctive span

@objectiser
Copy link
Contributor Author

@davsclaus Attempt at a mechanism for intercepting log messages to associate with an active Span. Happy to change approach if you have better suggestions, as not sure if this approach may lead to issues:

  • Relies on proxying Registry based on use of DefaultCamelContext - is this the only implementation that gets used?
  • Log component output not currently recorded, as the active span is detached from the exchange at the point where the log component is executed - initial aim was to get the log DSL messages so this can be addressed at a later date
  • The name becomes "opentracing", even for Log component output, e.g. the opentracing example service2 with an additional log component:

[INFO] Mar 22, 2017 2:39:11 PM io.opentracing.contrib.global.GlobalTracer lazyTracer
[INFO] INFO: Using GlobalTracer: sample.opentracing.logging.LoggingTracer@57d9165c.
[INFO] 2017-03-22 14:39:11,343 [XNIO-1 task-1 ] INFO opentracing - Service2 request: Service1-1
[INFO] 2017-03-22 14:39:12,939 [XNIO-1 task-1 ] INFO opentracing - Exchange[ExchangePattern: InOnly, BodyType: String, Body: Service2-Service1-1]
[INFO] SPAN FINISHED: traceId=1 spanId=2 parentId=1 operation=log tags={component=camel-log, span.kind=client, camel.uri=log://com.mycompany.order?level=INFO} logs=[]
[INFO] 2017-03-22 14:39:12,940 [XNIO-1 task-1 ] INFO opentracing - Service2 response: Service2-Service1-1
[INFO] SPAN FINISHED: traceId=1 spanId=1 parentId=2 operation=POST tags={http.url=http://0.0.0.0:7070/service2, component=camel-http, span.kind=server, http.method=POST, camel.uri=http://0.0.0.0:7070/service2} logs=[{message= Service2 request: Service1-1}{message=Service2 response: Service2-Service1-1}]

@davsclaus
Copy link
Contributor

Is there an use case for this? I think this is very invasive on users to just trap all logs.
I would have assume zipkin/opentracin is about small breadcrumbs to track a business transaction across systems. Not to do centralized logging and be a big brother. Sorry for the drama.

If there is some kind of opentracing logger trap, then I would rather see this hooked into the logger APIs. There is a logger API for MDC and I think its called Marker in slf4j where you can associate some custom key/values that the logger can output if instructed to do so.

@objectiser
Copy link
Contributor Author

For use case, there is something on the opentracing website: http://opentracing.io/documentation/pages/instrumentation/common-use-cases.html - see "Logging Events" section near the end.

This log event capability in opentracing is not intended to be a replacement for a general logging mechanism, or a centralised logging solution - but to enable significant events to be logged that occur in the context of a span (unit of work) and therefore an overall trace instance.

There are two ways this can be achieved - one is by annotating the logs generated by the application with a trace/span correlation id - this is being discussed in opentracing/specification#24 which appears to be coming to agreement. However to support users who identify a particular trace/span and want to then investigate further details (i.e. the logs) this requires some level of backend integration between the tracing system and the aggregated logging mechanism - otherwise this will be a manual process.

Second approach (where supported by the tracing solution - as not all will support the recording of events) is to capture these logged events in the context of the trace/span. Where visible via the tracing tool, it provides easy access to more detailed information (for diagnostic purposes) in the absence of linked aggregated logs.

For this particular case, I thought the log DSL within a route is most likely used to identify relevant milestones within the route execution - which may be useful events in the context of a trace/span.

I'll investigate whether hooking into individual loggers would provide a cleaner solution.

If beneficial, I could ask the OpenTracing authors to provide their perspective on the log event capability? Or feel free to raise an issue in the https://github.com/opentracing/opentracing.io repo - especially if you don't feel the use case description is compelling enough.

@davsclaus
Copy link
Contributor

Okay so you want to allow using the Log EIP (eg .log or in Camel route) to make those user messages logged with span details. Then that is a better understanding.

If so I think maybe we should look at a better way to the hooks and do this more directly in the Log EIP itself and not "trap all slf4j logger".

So it may be that we need some improvements to LogDefinition and the CamelLogger that it end up using that calls the logger

https://github.com/apache/camel/blob/master/camel-core/src/main/java/org/apache/camel/model/LogDefinition.java

https://github.com/apache/camel/blob/master/camel-core/src/main/java/org/apache/camel/util/CamelLogger.java

I think maybe its cleaner and more nicer to provide some kind of SPI in camel-core that 3rd party components can implement and register which allows them to have callbacks in the LogEIP and then enrich/influence the logging, so opentracing can do that.

Then we are not 'playing' with slf4j logger.

@objectiser
Copy link
Contributor Author

That sounds good to me. Is this something you would implement, as it is part of camel-core?

https://issues.apache.org/jira/browse/CAMEL-11054

@davsclaus
Copy link
Contributor

@objectiser I have asked @igarashitm to help with this as he is already doing some related work on the Log EIP. I am also on PTO this week doing some writing on my Camel book. So only have limited time in this community.

@igarashitm
Copy link
Contributor

Yep, I'll look into soon after I finish the mask stuff!

@objectiser
Copy link
Contributor Author

@davsclaus Ok thanks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants