Re: [hibernate-dev] Context-based Logging

On Tuesday, October 19, 2010, at 11:07 am, John Verhaeg wrote: > I'm currently going through the codebase trying to convert our use of slf4j > for logging to jboss-logging. In doing so, I've noticed that all of the > current loggers are named using the package-qualified name of the > enclosing class that define them. JBoss-logging offers a similar concept > in that loggers are associated with category names, but with the > difference that multiple loggers can be associated with the same category. > > I'm still fairly new to working with the Hibernate codebase, but based on > other projects I've worked on, I was thinking that maybe we should > *additionally* introduce some type of context-based logging moving > forward, where we'd supply logging contexts that represent the processes > in play, as opposed to the structural organization of loggers that names / > categories typically represent. To fully realize the power of these > contexts, you'd want to support the idea of sub-contexts that could be > active within other contexts (capturing when sub-processes are executed > within higher-level processes). > > Just to clarify via an example, consider the code involved with making a > query using hql. From what I can see in the existing code, one of the > sub-processes involved with such a query involves copying the result set > so that a pristine copy can be maintained and cached by the session, such > that it won't be impacted by local changes to those results by the user > between commits. So let's assume there's some issue a developer > encounters while creating a query, and the underlying problem has > something to do with copy sub-process. Using contexts, the developer > would be able to configure his underlying logging framework to enable, > say, the "query" context and set the logging level to debug or trace. This is a bit of a misnomer I think. First, I think we need to say that the "context logging" is NDC/MDC based. I do not know of a framework that has built in support for specifying log levels/granularity based on NDC/MDC that is the realm of the category in every framework of which I am aware. What you suggest is possible by, for example, cranking up logging all the way and then using the framework's notion of a filter. But the "problem there" is stuff like logger.isDebugEnabled(), etc will return true there all the time if they go that route. And as I have said all along, basing category names on this "context" is not feasible.

> Ideally, he'd get enough information from these logs to determine that > things begin to go awry after the results are copied. This, of course, > presumes a message is logged in the "query" context indicating when the > "copy results" sub-process is triggered, possibly even specifying in! that > message the sub-context associated with that sub-process. Now the > developer knows to enable this new context and run through the scenario > again to isolate the problem. He doesn't have to care or know which or > how many classes are involved in either the outer hql process or the > subprocess responsible for copying results. > > So one intended benefit of using contexts would be to make it easier for > developers, and possibly even developers' end-users, to determine which > log messages to enable/filter related to some problem their trying to hunt > down, while minimizing their need to understand the structure of code > internal to the Hibernate libraries. This approach should also help > decouple the logging and coding concerns such that, for instance, if a > method is moved to a different class, there is no impact on how messages > are logged (assuming the same contexts are still applicable). > > While we certainly could specify category names that more represent > processes or logical structure rather than simple package and class names > (physical structure), I'd still be concerned about code that happens to be > reused within multiple processes or services. Assuming it's important for > a significant amount of this type of "utility" code to log messages (this > might be a big assumption), which category of logger would you choose? > You could pass in the logger, but that would require changes to any > existing APIs. You could also just provide a separate category for this > type of code, but then you'd blurring what it means for a category to > represent a "process". > > So I'm thinking that using the jboss-logging NDC facility might be a good > way to support process-based contexts. This facility allows us to push > and pop contexts on and off a global stack (maintained by the > jboss-logging framework) at the boundaries of these processes. Of course, > we'd have to document the contexts that we use and the processes that > they're tied to. The disadvantage here would be the discipline we'd have > to exercise to do this properly. Pushing and popping contexts would need > to be treated similarly to beginning and ending a transaction, where > contexts that are popped off of the NDC stack would reside within finally > blocks. One other thing to consider is we'd probably want to provide some > documentation about how to support NDC using simple JDK logging, since > this isn't supported out-of-the-box. > > So is any of this worth the effort? Are my concerns valid? Is using > category names to represent logical structure enough? Thoughts? > > JPAV > > > > > > _______________________________________________ > hibernate-dev mailing list > hibernate-dev(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/hibernate-dev --- Steve Ebersole <steve(a)hibernate.org&gt; http://hibernate.org _______________________________________________ hibernate-dev mailing list hibernate-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/hibernate-dev