[slf4j-dev] Re: TRACE level

[Jens Elkner]

'Ceki =?iso-8859-1?Q?G=FClc=FC?= wrote:'
> 
Hello Ceki,
..
> Before adding TRACE, I would like to make sure that the TRACE level is
> needed, because once it is added, it can't be taken back. Greg floated
> the idea  of adding  trace() printing methods  in deprecated  mode, to
> mitigate the  pain of migration  from JCL (for those  already invoking
> the trace()  method). However, I think  it would be wiser  that we add
> it, once and for all,

Yes, plz do it :)

> after we have convincingly established the need
> for it.

Well, other logging frameworks have usually a trace() (sometimes it
is called fine(), finer(), finest() ... ;-)), but I can't believe,
that those developers implemented it just for fun or because of beeing
a freak. I think, they have done their "homework" and implemented them
on purpose.

But ok, even if all people are jumping out of the plain, nobody
says, that this is the right way to get back to the ground ;-)
  
..
> There are two questions on my mind.
> 
> 1) Is TRACE being used for good reasons?

Yes. Simple scenario - application support. 1st level ask DAU questions
like "Is the cable plugged in ?" ... "What says the output ... (i.e.
INFO, WARN, ...). The 2nd level support ask the customer to enable
debug statements, which are usually sufficient to identify or even 
solve the problem. But if it can't find the cause, it escalates to the 3rd
level, which requires the trace() to find out, what's going on. C people
would say here, something like give me a core or memory dump ...

A use case. Hmmm - an application reads third-party data from 
DOS-CSV-Files and this worked for many years without any problem.
But suddenly some data gets lost? Why? E.g. log.debug() could  tell me, 
which file has a problem or which line/record. Might be sufficient to
identify the problem. But what, if not? What, if you are reading from a
Socket or in general an OutputStream, which cannot simply sent to the
helpdesk? Than a trace would be helpful, which hexdumps the processed data.
Here e.g. one could see, that a smart guy inserted a linefeed into a cell,
and thus the BufferedReader assumes an EOF instead of reading until the
DOS-EOF aka CRLF is found ...

Or - if you are using SAOP and have some problems, it might be quite useful,
to trace messages, i.e. dump the whole request or response incl. http
headers...

So in general trace() would be very useful for getting the real/tiny
details, if needed ...

> 2) Is TRACE being used because the existing APIs do not offer enough
> expressive power?

No, we do NOT need a dinosaur. We need a hummingbird!
I think, 99% of all log-using developers would be happy with the
perfect-5 and perhaps 50% of them would be happier getting a hint,
how to use logging in a more or less intelligent/deterministic way ;-)

The 1% which needs some more sophisticated stuff (a fat biddy), are
probably able to breed it themselves (e.g. by injecting some chromosomes).

IMHO a dinosaur would probably killed because of the fear, that it eats
too much/can not be handled ...
  
> As I am familiar with hibernate, let me quote you:
> 
> <jens>
>    Or hibernate - almost the same thing, but they are even mixing
>    developer info and end user infos into one level (info). So usually, an
>    application programmatically disables the hibernate info/debug stuff,
>    since the stuff is usually totally superfluous for the end user but also
>    losses some "interesting" messages.
> </jens>
> 
> In log4j, you can disable logging per class. What is preventing the
> end user from disabling logs of level DEBUG in certain hibernate
> classes and let other hibernate classes with "interesting" information
> log at level DEBUG?

Yes, and spending hours to studdy the source (or doing it by try and error)
to get to know, what to en/disable and having at the end a logconfig bible,
which is hard to maintain ... and will probably never touched by team
mates, since nobody knows, why the stuff is there ?

A snipplet of source code I use ...
---schnipp---
	private static final void printChannels() {
		Logger log = Logger.getLogger("org.hibernate.cfg");
		Level level = log.getLevel();
		log.setLevel(Level.FATAL);
		List<A_Sender> list = Dao.getInstance().getAllChannels();
		log.setLevel(level);
		...
	}
---schnapp---

Actually, something what not should be done by the application, but what
should one do, to not overflood the enduser with for him needless 
gobbledegook ...
My experience is, that all, what the enduser cares about is, that the
application works. And each message, which gets printed to the 
output, makes him feel, that something is not working correct (since
he cannot understand/interprete the stuff). BTW: Have you ever seen
pages of blafahsel in a terminal, where you started e.g. Star/OpenOffice
or MS Word ?

So, hibernate is IMHO a "bad logging "strategy"" usage example.

> In the JBoss project, they use the TRACE level to *by* *default*
> silence logs generated by certain classes.

Hmm, don't know, but probably an outcome of bad log usage as well.
So give us the trace, and people will perhaps start to make their
message strategies a little bit more fine grained ... ;-)

> As by default log4j logs at
> level DEBUG (its most verbose level), messages of level TRACE are
> turned off by default. As I wrote in a previous message, the JBoss
> developers could have logged their debug messages at level DEBUG (as
> if DEBUG and TRACE were merged into DEBUG), and let the end user
> disable DEBUG logs for the classes the user found uninteresting or too
> chatty. Assuming what the end user finds chatty is similar to what the
> JBoss developers find chatty, the end result would have been very
> similar.

Well, my JBoss installations are all set to INFO, and even with INFO,
it is usually even for a developer hard/very timeconsuming to find the
cause of a problem ...
(IMHO, on problems a more or less meaningful warn/error message,
which could be a simple e.getlocalizedMessage(), would be sufficient 
and easy to spot. If one enables debug, than and only than a stacktrace
should be logged, since this usually spans dueto the nature of the AS
several pages). But this is perhaps another playground.

> I would love to see code samples backing up your case. Do any pop up
> to your mind in common-httpclient? Maybe in hibernate?  You mention
> common-httpclient and hibernate as bad examples. Do you have example
> of projects using the TRACE level as positive examples (examples to
> follow)?

Are the mentioned cases/example enough for you (actually, I don't wanna
dive into the stuff right now, since I'm a little bit short on time
and if I look deeper into a "framework" this usually leads to a new
"localized" version, I don't wanna maintain at the moment - and merging
it back to the head is usually too timeconsuming and halfhearted :( ...) ?
  
Regards,
jens.
-- 
+---[ Jens Elkner ]--------------------------------------------------------+
| Walther-Rathenau-Str. 58                 elkner at linofee.org              |
| 39104 Magdeburg   GERMANY           http://www.linofee.org/~jel/         |
+--------------------------------------------------------------------------+