[slf4j-dev] Tracing & Profiling... was Re: Markers... was: Re: Release of SLF4J version 1.6.0-RC0

[Joern Huxhorn]

Hi everyone.

I've added a tracing aspect to the Lilith modules.

<dependency>
    <groupId>de.huxhorn.lilith</groupId>
    <artifactId>de.huxhorn.lilith.tracing</artifactId>
</dependency>

You can find a bit of info at http://sourceforge.net/apps/trac/lilith/wiki/TracingAspect

The code is located at
http://github.com/huxi/lilith/blob/master/tracing/src/main/java/de/huxhorn/lilith/tracing/TracingAspect.java
with usage examples in
http://github.com/huxi/lilith/blob/master/tracing/src/test/java/de/huxhorn/lilith/tracing/TracingAspectTest.java
and
http://github.com/huxi/lilith/tree/master/tracing/src/test/resources/

Please let me know what you think about it.

Cheers,
Joern.

On 02.05.2010, at 06:38, Joern Huxhorn wrote:

> 
> On 01.05.2010, at 19:01, Ralph Goers wrote:
> 
>> 
>> On May 1, 2010, at 3:37 AM, Joern Huxhorn wrote:
>> 
>>> 
>>> How about only adding
>>> 
>>> logger.debug(Message)
>>> logger.debug(Message, Throwable)
>>> 
>>> leaving out the Marker?
>>> 
>>> That way the Message implementation might opt-in to add Marker-support as seen fit.
>>> 
>>> I'd like to point out, though, that I haven't thought this through, yet.
>>> 
>>> I think it would likely create rather big problems, including TurboFilters that won't properly match on Markers anymore... which would create a large amount of confusion for the user.
>>> 
>>> The main-point of Markers, for me, is the ability to use them for efficient filtering in Logback (and Lilith).
>>> 
>>> I never liked the hierarchy-aspect of them, especially since they are supposed to be global.
>> 
>> I don't mind the hierarchy. I've just found them to be awkward because you have to call add. It would have been much more natural to have one marker class extend another if you want that kind of relationship.
> 
> I definitely like hierarchical markers, I simply don't think that this hierarchy should be placed in the code.
> It's about marker-hierarchy at compile-time vs. marker-hierarchy at runtime.
> 
>> 
>>> 
>>> In my opinion, the marker-hierarchy shouldn't be created in the software but in the configuration instead. Under no circumstance should other modules be able to change my marker-hierarchy.  I once reported a bug about recursive marker-hierarchies that you fixed by preventing recursion at all. This has the effect that the module that creates the Marker first will be able to decide on the hierarchy while a module loaded later-on in the application will be stuck on the previously created hierarchy - even if it's logging is expecting an entirely different one. This is a catastrophe waiting to happen - which is why I'm not using them in that way in my code.
>> 
>> I'm not sure how you create a marker in the configuration when it is used in the code.  What would debug(MY_MARKER, msg) do if MY_MARKER wasn't defined?
>> 
> 
> No, you misunderstood me. I don't want to put the markers into the logback config file, merely the marker-hierarchy.
> I'll explain below...
> 
>>> 
>>> I'm also not sure about possible classloader-woes concerning MarkerFactory. [1][2]
>>> I haven't checked this but I suspect there could be problems with Markers comparable to those of custom java.util.logging.Level.
>>> 
>>> Beside that, I think the Markers ENTERING, EXITING and THROWING should be used without being put into a TRACING marker. The grouping of those three markers into a TRACING group should be done in the Logback config and filters could then filter on that group.
>> 
>> I disagree with this. First off, ENTERING and EXITING use a FLOW marker, not TRACING. THROWING and CATCHING extend EXCEPTION. This makes sense because it lets you filter on FLOW events as a whole or just entry events if you want.
> 
> I didn't actually refer to XLogger, I was just making an example. Sorry for the confusion, I entirely forgot that this is actually implemented in XLogger already.
> 
> I'll take the XLogger-Markers as an example, then:
> 
> The hierarchy looks like this:
> 
> FLOW_MARKER
>    ENTRY_MARKER
>    EXIT_MARKER
> 
> EXCEPTION_MARKER
>    THROWING_MARKER
>    CATCHING_MARKER
> 
> I deliberately wrote it like that, i.e. FLOW contains ENTRY and EXIT instead of the other way around.
> Your code will only ever use ENTRY, EXIT, THROWING, CATCHING, never FLOW or EXCEPTION.
> FLOW and EXCEPTION are only used for the hierarchy so it's possible to enable/disable both contained markers.
> 
> I'd put *that* hierarchy into the logback/logging -config.
> 
> I'd like to be able to define such a grouping at configuration/runtime
> For example, I, personally, would put ENTRY, EXIT, THROWING and CATCHING into a single group or a might only be interested in ENTRY, EXIT and THROWING and put those into another arbitrarily named group.
> 
> If this was (or is?) supported then the marker hierarchy based on Marker.add() would be needless.
> 
> Another problem is that different modules might use markers of the same name entirely differently. This isn't likely in the above case but there are other.
> 
> This is the reason why markers should NOT be statically defined across different modules/packages, IMHO.
> 
> With configuration of the hierarchy in the configuration one could work around such issues, I think.
> 
> Personally, I'd deprecate MarkerFactory.getMarker() (pointing to getDetachedMarker() instead) and maybe even Marker.add(Marker), Marker.remove(Marker) etc., (documenting why using this feature is probably bad).
> 
>> 
>>> But this after-the-fact discussion isn't helping anymore.
>>> One way to fix it, though, would be not caching Markers in MarkerFactory at all.
>>> 
>>> The use-case described by Gunnar could (and IMHO: should) be handled using the MDC, not Markers. He could call MDC.put("CONFIDENTIAL","true") and perform special handling that way.
>> 
>> I would only recommend the MDC be used for data that could possibly span log events. Having to set it and remove it after each logging call would be a pain. Markers work better for this.
> 
> I wouldn't be a friend of this either. :p
> 
>> 
>>> 
>>> Both ways assume that the Logging system is evaluating either Marker or MDC which isn't the wisest thing to do.
>>> Confidential info should NEVER be logged, IMHO, regardless of the logging configuration.
>> 
>> Sometimes it has to be. Trying to diagnose problems often requires this kind of information. Also, audit logs will often contain confidential or sensitive information. We have different levels of classification of data. A user's bank account number might appear in a log. A user's PIN or password will never appear.
>> 
> 
> I think it would be a good idea to use entirely separate markers in those cases, i.e.
> FOO_MARKER and CONFIDENTIAL_FOO_MARKER
> 
> If the grouping/hierarchy-configuration would allow wildcards then it would be possible to group "*FOO_MARKER" and it would also be possible to group "CONFIDENTIAL_*" to catch all confidential calls.
> The used markers are essentially scoped for modules.
> 
> I'd expect defining and documenting markers in an interface, e.g.
> public interface Slf4jExtMarkers {
>  final Marker ENTRY=LoggerFactory.getDetachedMarker("ENTRY");
>  final Marker EXIT=LoggerFactory.getDetachedMarker("EXIT");
>  final Marker THROWING=LoggerFactory.getDetachedMarker("THROWING");
>  final Marker CATCHING=LoggerFactory.getDetachedMarker("CATCHING");
> }
> 
> Problem:
> Markers aren't immutable - so it would be possible the change those static instances :p
> We could, however, implement an ImmutableMarker instead for use-cases like that, which would throw an UnsupportedOperationException in case of add() and remove().
> 
> Cheers,
> Joern.
> _______________________________________________
> slf4j-dev mailing list
> slf4j-dev at qos.ch
> http://qos.ch/mailman/listinfo/slf4j-dev