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. 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