Visible Workings > Trace.java User's Guide |
The Trace.Java
User's Guide |
Definitions |
What does trace output look like?
How, in general, is trace output produced?
=== 1997/09/22 13:52:09.342 (Incoming.Parcel:Parcel.java:126) EVN
comm: PROBE message detected from IP address 123.44.53.12
Let me explain this output piece by piece.
=== 1997/09/22 13:52:09.342 (Incoming.Parcel:Parcel.java:126) EVN
comm: PROBE message detected from IP address 123.44.53.12
Each trace message is timestamped in a YYYY/MM/DD HH:MM:SS.mmm format. Dates are in local time. Note that the format makes logs sortable by date and avoids confusion about whether 07/08/97 is a date in July or August.
=== 1997/09/22 13:52:09.342 (Incoming.Parcel:Parcel.java:126) EVN
comm: PROBE message detected from IP address 123.44.53.12
This message came from the Parcel
method in package Incoming
. Specifically, it came
from line 126 of file Parcel.java. Only the last component of a
package name is printed to reduce clutter. (That is, "com.visibleworkings.trace.Trace.myMethod"
is printed as "Trace.myMethod".)
In some cases (optimizing compilers), Trace.java can't find location information. If it can't find the line number, it prints it as "line?". If it can't find the filename, it prints it as "file?". If it can't find the method name, it prints it as "method?".
=== 1997/09/22 13:52:09.342 (Incoming.Parcel:Parcel.java:126) EVN
comm: PROBE message detected from IP address 123.44.53.12
The next tag shows the level of the message. This message is an Event message. You can control at runtime or launch time which message levels are printed.
=== 1997/09/22 13:52:09.342 (Incoming.Parcel:Parcel.java:126) EVN
comm: PROBE message detected from IP address 123.44.53.12
The first item on the second line is the subsystem the message came from. Subsystems are user-defined groupings of code, typically larger than a class. You can control tracing by subsystem. For example, you might want great detail from the "comm" subsystem, but less detail from all others.
=== 1997/09/22 13:52:09.342 (Incoming.Parcel:Parcel.java:126) EVN
comm: PROBE message detected from IP address 123.44.53.12
And, finally, the message is printed.
Each class that uses Trace.java will have a static private Trace object. This trace object is shared with other classes in the same subsystem. The Trace object has several different methods; each posts a trace message at a different level. Here is an example:
subsystemTrace.eventm("message");
That method posts a Event message, but only if the threshold allows. For more details, see the programmer's guide.
Trace messages have several levels. Lower levels provide more detail. You can control at launch time or runtime which level of messages you want to see. Different subsystems can be controlled independently.
These level abbreviations are used in the trace output:
ERR | Error |
WRN | Warning |
WLD | World |
USE | Usage |
EVN | Event |
DBG | Debug |
VRB | Verbose |
If every single Debug level message were printed for a whole system, you'd be swamped with output. Therefore, you can adjust the threshold at launch time or runtime. If you set the threshold to Usage, you will only see Error, Warning, World, and Usage messages. Messages at a lower level will be discarded.
Each subsystem can have a different threshold. You might want to look at Debug messages for the "comm" subsystem, but only Error messages for the rest of the system.
Trace.java provides two different destinations for trace messages. They have separate thresholds that can be controlled independently. The threshold can never be set so high that Error messages don't appear.
Here are some examples of how changing the threshold might help:
Trace.java assumes that the whole system can be roughly partitioned into independent subsystems. A subsystem is usually bigger than a class. For example, all the GUI code might be part of one subsystem, as might be the network interface code, or the database interface code, or the resource management code, etc. Subsystems will often have relatively stable APIs.
Trace.java doesn't assume that there's some central authority doling out subsystem names. Any programmer can create her own. However, a central authority may have predefined some for you. Check with the person who installed Trace.java.
Tracing messages have two possible destinations: the log or the transient buffer. The log is usually a disk file. It can also be standard (terminal) output. The transient buffer is a fixed size ring buffer. Its contents are normally invisible. However, it can be dumped into the log.
The same message can go to both the log and the transient buffer. Typically, the transient buffer contains more detail than the log. The log by default has a World threshold, so it gets Error, Warning, and World messages. The transient buffer gets all those by default, plus Usage messages.
Unless the transient buffer is dumped into the log, its extra detail never bothers anyone and goes away when the buffer fills up. Unlike the log, older messages in the transient buffer are thrown away to make room for new ones.
However, suppose an error happens. The system's error handling code can arrange to dump the transient buffer into the log. That records the last 500 (or so) user actions. That can be of great help to customer service.
Definitions |
Copyright © 2000 by Brian Marick. This material may be distributed only subject to the terms and conditions set forth in the Open Publication License, draft v1.0 or later (the latest version is presently available at http://www.opencontent.org/openpub).
Please send comments on this document to marick@visibleworkings.com.