Is this taking the discussion further off topic or bringing it back
towards it's starting point? ;-) Frank's comments below go more to the
heart of what logging should or shouldn't be used for, which has been a
bug-bear of mine for a while...
The key thing is to remember, when writing log statements, who will be
*reading* them. There are three groups to consider: the developer, the
'end user admin' (i.e. your customer's admin guy, etc.) and, when
something breaks in an unexpected way, the tech support staff.
The log should be 99% things that make sense to the 'end user admin' guy
-- in other words, it should contain logging messages that tell them
things they need to know, either to verify the system is working
correctly or to figure out how to fix it w/out calling tech support.
Anything that's only meaningful to someone who has the source code to
look at should be debug/trace level, and shouldn't be enabled by
default. Those logs are for the developer during the code/test cycle, or
during post-production diagnostic exercises. That can be an important
thing to be able to turn on in production if you can't reproduce a
problem in a test environment, but they're only interesting to someone
responsible for diagnosing and/or fixing a problem.
The third group, tech support staff, is sort of a cross-cutting concern
;-) I generally use 'info' level logging for this sort of thing. Stuff
like logging life-cycle events and key changes in overall system state.
The goal is to allow someone with sufficient familiarity with how the
app should be running to spot why it's not behaving in an expected way
*assuming the problem is not a bug*. In other words, it lets first level
technical support figure out that feature X isn't working because config
options Y has the wrong value. Debug and trace level logging shouldn't
come into it until tech support has escalated the problem to engineering
and the dev team, after examining all the logs, realizes that they can't
tell what's gone wrong ;-)
Of course in Mailreader, all three roles collapse into one (more or
less). And, since the logging is there mainly to let someone correlate
the code with what happens when they run it, it's mostly there as trace
I suspect (not having looked at the code...)
L.
Frank W. Zammetti wrote:
My tact has always been that trace statement should only be used to
trace entry, and perhaps exit, from a method. Anything within a method
is either debug or info as appropriate, with error and fatal being
self-explanatory.
My reasoning is simply that if I have a particularly thorny issue I'm
trying to work out, I like having a complete trace where the code went,
and especially when its in log format I can print it out and take it to
lunch to trace through if need be. Frequently you only really need the
debug messages though.
Don's comment about leaving "Action was called"-type statements to the
framework is reasonable. I would typically have a trace message as the
first thing in an Action, just because I don't want to absolutely trust
that the Action was actually called, i.e., maybe the log message where
the framework says Action A is being called has three lines between it
and the actual call, in which case it could be misleading. I wouldn't
go nuts if I didn't see such a trace message though. Should it be
considered a "best practice" to have such a message? I could argue that
a user of a framework doesn't necessarily know what logging the
framework itself will put it and therefore they shouldn't assume they
will get what they need. It's a debatable point though.
My other tact is that I put a debug message in before and sometimes
after a statement that I know could fail, or more importantly that might
not itself fail but that could blow something up down the line. Many
times this isn't just "about to do something dangerous"... for instance,
in the call to doGetUser() below, assuming that might fail if session
was null, I might put:
log.debug("Getting user from session " + session):
...before it, and then:
log.debug("user = " + user);
...after it.
In fact, the second one I might put at info level... when an app is in
production, nothing is more annoying than when a problem occurs and you
realize you aren't logging enough to get anywhere in solving it! Of
course your going to try and replicate it in a dev/QA environment with
full logging on, but how many times does a user complain about something
and you can't replicate it? Then, whatever logging the app does at
production level is all you have. Naturally, prudency is important though.
Frank
Ted Husted wrote:
On 12/9/05, Don Brown <[EMAIL PROTECTED]> wrote:
I'd like to see the logging taken down a notch, but perhaps not
completely out.
IMO, Mailreader is there to demonstrate Struts best practices and
the logging
statements everywhere make one wonder :) Besides, it gives a false
impression
Actions need to be long and detailed. I'd rather see if we can get
those
Actions down under 10 lines each. Leave "*Action was called"-type
statements to
the framework.
As of this week, most of them are, and we're using real Dispatch
actions. Here's the Edit method from RegistrationAction, for example.
public ActionForward Edit(
ActionMapping mapping,
ActionForm form,
HttpServletRequest request,
HttpServletResponse response)
throws Exception {
final String method = Constants.EDIT;
doLogProcess(mapping,method);
HttpSession session = request.getSession();
User user = doGetUser(session);
boolean updating = (user!=null);
if (updating) {
doPopulate(form,user);
}
doSaveToken(request);
return doFindSuccess(mapping);
}
The logging is pushed back into helper methods, but some of the
helpers are more logging than logic:
protected void doSaveToken(HttpServletRequest request) {
if (log.isTraceEnabled()) {
log.trace(Constants.LOG_TOKEN);
}
saveToken(request);
}
I'm thinking we should do things like log the complete stack trace for
exceptions we catch, and such, but retaining all the tracing
statements we now have, just makes it harder to see the trees. I don't
know if I would leave a trace statement for creating a transactional
token in a production application.
-Ted.
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
