|
The Java Specialists' Newsletter
Issue 003 2000-12-14
Category:
Language
Java version: Logging part 1by Dr. Heinz M. Kabutz
Welcome to the third "The Java(tm) Specialists' Newsletter",
a low-volume newsletter that is aimed at Java programmers who
are facing the real world every day. I hope you are enjoying
reading this information and that it will help you to be more
productive in your work. I want to thank Java-Guru-In-The-Making
Dr. Christoph Jung for volunteering to write a piece on
dynamic proxies in an upcoming newsletter. Please let me
know if there are topics that you would like discussed or
if you would like to share some of your own experiences
through this newsletter. This newsletter is distributed
free of charge to anyone interested, so please forward it
to friends and colleagues who might find the information
in this newsletter useful.
I drew some fire from respectable quarters that some of the
code I presented in the last newsletter was a little bit on
the obscure side. The Thread example was meant to illustrate
the concept of making an anonymous inner class and immediately
putting it to use, as opposed to just using it as a parameter.
The most probable place you would find code as shown in the
last newsletter would be in the unit tests of my code. If you
have a method that requires as a parameter a Vector, you can
use the example from the previous newsletter to succintly
pass it test data. Even though the examples might seem a bit
obscure at first glance, I believe that once you've seen the
"Anonymous Inner Class Init Block" example, you will begin to
recognise it easily enough so it will lose most of its obscurity.
If you are not writing unit test for your code, why not?
There are two good books that contain information on unit
tests, Refactoring by Martin Fowler and eXtreme Programming by
Kent Beck. Unit tests have saved my butt a number of times,
because I am not a very "good" programmer, in that I make
mistakes all the time and end up messing up old working code
in the process - does that sound familiar? (So, if you let
me work on some of your code and you don't have unit tests,
BEWARE!) When people ask me what my job is I tell them I am
a professional bug writer, because that's what I'm best at.
Unit tests only work if the whole development team is using
the concept, much like CASE tools such as Rational Rose.
I fought a losing battle 2 years ago when most of the team,
on a project I was on, stopped using Rational Rose and I spent
most of my time updating other developers' diagrams.
Talking of unit tests, it is possible to use the Robot
(java.awt.Robot) to write unit tests for GUI's.
Upcoming Java Specialist Master Courses:
- please click here to sign up.
As from May 2010, we are also offering this course on the island of Crete. We
only accept 6 students per class in Crete, due to the size of our conference
room. Please book early to avoid disappointment!
San Jose CA, Mar 16-19 2010, $3500 Ottawa, Canada, Mar 22-25 2010, $3500 Oslo, Norway, Apr 13-16 2010, Kr 24500 Montreal, Canada, Apr 20-23 2010, $3500 Toronto, Canada, May 17-20 2010, $3500 Chania, Crete, May 25-28, Jun 29-Jul 2 or Aug 24-27 2010, €2500
In-house courses if these dates or locations do not suit you - click here for more information. Logging Part 1 of ... (haven't decided yet ;-)
While we are on the topic of things going wrong, we should always
expect things to go wrong in the field and it is very important
to be able to remotely figure out what went wrong and to prevent
it from going wrong in future. An example of a remote fix
was the Mars bug that had to be debugged and repaired remotely
(not by me ;-) - the Risks digest had some interesting articles
on that. With the internet being so widely accessible, we have
a great challenge because our programs might fail somewhere in
a remote part of this planet that might not be very pleasant
for a support team to visit, for example amongst a man-eating
pygmy tribe in Java (non-tm). Preferably we would ask them to
email us a log of what went wrong so that we can look at the
log and determine what the problem was.
When you start with a new project it is very easy to give
logging too little thought, with unpleasant consequences.
It is also possible to give it too much thought and design such
a complex logging system that the rest of the programming team
cannot wait and starts writing their own logging functions
(System.out.println springs to mind). In that case you are
back to the first problem of too little thought, because each
developer develops his method as he goes along. This newsletter
is not going to tell you which way is best, you have to decide
for yourself, but it will show you some tricks and gotcha's
that I've seen several times.
In designing a logging system, there are several questions we
have to face:
- How do we show when the event happened?
- What if the log size gets too big?
- How do you switch off logging?
- Are we willing to make the client code messy to improve performance?
The combination of these factors can sway your logging system
in various ways, which is why I will not say which is best.
I will now present the first of a series of case studies of
logging systems that one might want to write:
Case Study 1:
Frank the Unix hacker has been writing a 3-tier application
server that uses several third-party libraries which output
logging information such as "Connected to ISAP" or "Disconnected
from AISN" or "State changed to TLA". Since Frank is a hacker,
he knows about JAD.EXE and is forever grateful to Pavel for
making all CLASS files open-source, but he is a bit worried
about rewriting the third-party code to output to his logging
system because of something called "copyright law", whatever
that is. The problem is that he needs to know exactly in which
order things happen in respect to his own application server,
so perferably the log should show all output to the console
in the same order in which it appeared. Since Frank is a UNIX
hacker, he remembers a little utility called "tee" that would
represent a t-piece in a pipe of output so that you could send
piping to two destinations.
For example:
echo hello world | tee output > output2
would send the string "hello world" to two output files,
"output" and "output2".
Frank decides to write an IO stream decorator that behaves as a
TeeOutputStream. (Disclaimer: I wrote my first TeePrintStream in
the middle of 1997 - I have since seen the same thing published
in a magazine.) If you don't understand decorators, have a
look at the IO chapter of the excellent book "Thinking in Java"
by Bruce Eckel or visit a good Java course.
The TeeOutputStream would look something like this:
// TeeOutputStream
import java.io.*;
public class TeeOutputStream extends FilterOutputStream {
private final OutputStream out2;
public TeeOutputStream(OutputStream out1, OutputStream out2) {
super(out1);
this.out2 = out2;
}
public void write(int b) throws IOException {
super.write(b);
out2.write(b);
}
public void flush() throws IOException {
super.flush();
out2.flush();
}
public void close() throws IOException {
super.close();
out2.close();
}
}
The TeeOutputStream would now be able to take two output streams
and send the same information to both of them as shown in the
main method.
// ... the main class that starts up the application server
public static void main(String[] args) {
PrintStream out1 = System.out;
OutputStream out2 = new BufferedOutputStream(
new FileOutputStream("LOG"));
TeeOutputStream newOut = new TeeOutputStream(out1, out2);
System.setOut(new PrintStream(newOut, true));
out1 = System.err;
newOut = new TeeOutputStream(out1, out2);
System.setErr(new PrintStream(newOut, true));
// ... some more code...
}
My personal preferance would be to re-write those lines as
follows, but you should do what is most comfortable to you:
// ... the main class that starts up the application server
public static void main(String[] args) {
OutputStream log = new BufferedOutputStream(
new FileOutputStream("LOG"));
System.setOut(
new PrintStream(new TeeOutputStream(System.out,log),true));
System.setErr(
new PrintStream(new TeeOutputStream(System.err,log),true));
// ... some more code...
}
The astute among you should now be jumping up and down pointing
at the glaringly obvious mistake in the above code. There is no
provision for the log file growing and filling up the hard disk.
Frank (correctly) assumes that his program is never going to run
for a long enough period that the size of the log file would be
bigger than 10 KB, but once all his bugs are removed, something
should be done to prevent the big log file. The biggest log
file that an advanced support man sent me was 1.1 GB in size
when I used Frank's TeeOutputStream system.
Anyway, the beauty with Frank's approach is that whenever he
wants to print to the log he just does a "System.out.println()"
or exception.printStackTrace(). Anything that goes to the
console also goes to his log in the same order in which it
appeared to the user. He can also switch off logging to a file
by not setting the System.out PrintStream to print to the tee,
or he can set his program to only print to the log.
If we look back at the questions we face with the logging system,
we see that we don't have a default way of showing WHEN the event
occured, although that could be added by changing the write()
method of the FileOutputStream to print the date/time after
each newline. The size of the log file can be monitored by
implementing a different FileOutputStream. The logging to file
can be switched off easily. The client code is very simple -
System.out.println("Changed to state TLA");
That's the end of Frank's logging system. As you have seen,
there is a lot of scope for changing it, depending on your
requirements, but there is no right answer that fits all
scenarios. Next week I will present another scenario with
different advantages...
Please remember to forward this free newsletter to whoever you
think may be interested.
With regards
Heinz
Language Articles
Related Java Course
|