Aspect questions?

[Lew]

What are other good ways to do logging?

log4j is my favorite.

Right now, the two main programs in my current project each create their
own logger and then pass it to the classes they call in their parameters.

I don't think that's a good pattern. Which logging library are you using?

I have each class create its own logger (log4j style shown:

package eegee;
import org.apache.log4j.Logger;
import static org.apache.log4j.Logger.getLogger;
public class Foo
{
final Logger logger = getLogger(getClass());

public void foo()
{
logger.debug("");
// do the fooey stuff
try
{
// do the trying stuff
}
catch (FooException exc)
{
String msg = "trying stuff failed. "+ exc.getLocalizedMessage();
logger.error(msg, exc);
throw new IllegalStateException(msg, exc);
}
}
}

This boilerplate is what aspects aim to remove from the code and I espouse
retaining.

Either way the logger should be tied to the actual class emitting log
messages, not some common class.

The called classes write their messages to that logger. I've created a
method that does the logger creation and put it in a utility class in my
Common project so that my programs only need to execute that method
(passing in a few parameters of course) and get an appropriate logger
back. Each of the classes instantiated by the main programs gets a logger
passed among their parameters. The newly instantiated class then verifies
that the logger is not null and throws an IllegalArgumentException if it
is. Each class writes to the log when it seems appropriate. Sometimes,
that is to log an Exception. Other times, I log things that are more
diagnostic in nature. If a method isn't 100% right yet, I will log
calculations that it is doing, such as calculating the width of a column
in a JTable or whatever.

Did you reinvent the logging wheel? If so, does your logging framework feature
log levels, infinitely flexible log formats, logging to screen or (rolling)
file logs, virtual elimination of logging overhead at levels finer than
configured, automatic if slow retrieval of class and method and line where the
logging happens, XML configuration, portability, a large body of online
literature describing its use, standardization, widespread adoption, and a
body of top developers contributing to the project?

This works okay but it seems to me that it might be more elegant to put
the logging in aspects, especially the diagnostic stuff that I am using
to verify that the suspect methods are doing their jobs correctly.

What is "elegant"?

Personally I promote "useful" as the useful metric.

I'm not sure yet if all the logging code, including the creation of the
log itself, should go into aspects though. It probably makes more sense
to create the logger the way I am doing it and continue to do the actual

Not from your description of it.

writes to the logs in my existing classes when it involves Exception
handling. The diagnostic logging, though, seems like a prime candidate
for the aspects. I could write pointcuts that specify the methods that
are a little dubious and log them in as much detail as I need. Methods
that are already working to my satisfaction could be left alone with only
their Exception logging.

Logging is logging is logging, to misquote Gertrude Stein. Suddenly now you've
created two logging aspects. That's not elegant.

Logging shouldn't be added to and removed from code. That's not the purpose of
logging. Logging is to remain in the code forever.

Logging is not for the developer. That's an all-too-common misconception.
Logging is for the sysop.

Have you ever tried to suss out a production issue from the logs?

The sort of dynamic granularity you describe is built in to the logging
framework. You use levels - DEBUG for debug purposes (or FINE if you're using
java.util.logging), WARNING for warnings, ERROR (SEVERE) for errors, and so
forth.

By removing logging to AspectJ, you eliminate the flexibility, visibility and
granularity of control logging should support.

What do you mean when you say "framework"? That term puts me in mind of
things like Spring - which I know of but have never used - but I'm not
using any formal frameworks like that and know very little about them.
I'm getting the impression that you are thinking of my work as being sort
of a homegrown framework. Maybe it is; I really don't know.

A deployment or code base that handles some part of the project under the hood
for you, and gives you a public interface for control of its behavior. In your
case I'm referring to the AspectJ framework. Logging is also a framework, one
apparently you are not using.

Use log4j or java.util.logging (or both). Those are (both) foundational and
you should learn (both of) them very early in your Java career.

Remember - logging is meant to be there in production, for benefit of sysops
and system reliability engineers. Code is not the be-all and end-all of
programming.

 

[Lew]

Another thing to consider is that every extra layer of bytecode
manipulation you add is another source of conflict. You might have
EclipseLink JPA doing weaving. AspectJ might be weaving. You might be
using AgitarOne for generating JUnit tests for legacy code. You might be
using Emma or Cobertura for code coverage, both of which instrument with
weaving. JRebel also does class rewriting.

I've run into situations many times - since I have used all of the above
- where one had to be careful about what order to have these bits weave.
Sometimes you can't control that, and you hope the combo works. In a
number of cases you simply cannot use two weavers together (I've found
it impossible to combine JRebel and EclipseLink with lazy weaving for
example).

I have no problem with bytecode rewriting, but the developer needs to be
aware of what's already there (maybe they are using EclipseLink JPA as
part of their Java EE) before they start adding extra layers of it.

Thank you, Arved. This exactly illustrates what I was trying to say about
frameworks adding deployment complexity.

It's not just the code that counts. Things have to actually run on actual
computers. Check it out - you'll discover that ops personnel are smarter than
we programmers.

 

[Novice]

log4j is my favorite.


I don't think that's a good pattern. Which logging library are you
using?

I'm using Java Logging. Does that answer your question or are you asking
something else?

I have each class create its own logger (log4j style shown:

package eegee;
import org.apache.log4j.Logger;
import static org.apache.log4j.Logger.getLogger;
public class Foo
{
final Logger logger = getLogger(getClass());

public void foo()
{
logger.debug("");
// do the fooey stuff
try
{
// do the trying stuff
}
catch (FooException exc)
{
String msg = "trying stuff failed. "+
exc.getLocalizedMessage(); logger.error(msg, exc);
throw new IllegalStateException(msg, exc);
}
}
}

This boilerplate is what aspects aim to remove from the code and I
espouse retaining.

My code is not terribly different than that.

Here's the actual code minus the Javadoc comment:

================================================================
public static Logger configureLogger(String className, String
logFilePath, String logFileName, Locale locale, Formatter formatter,
Level loggingLevel) {

String METHOD_NAME = "configureLogger()"; //$NON-NLS-1$

/* Ensure that the mandatory parameters have all been specified. */
if (className == null) {
throw new IllegalArgumentException("The name of the class must
be provided."); //$NON-NLS-1$
}

if (logFilePath == null) {
throw new IllegalArgumentException("The log file path must be
provided."); //$NON-NLS-1$
}

if (logFileName == null) {
throw new IllegalArgumentException("The log file name must be
provided."); //$NON-NLS-1$
}

if (locale == null) {
throw new IllegalArgumentException("The locale must be
provided."); //$NON-NLS-1$
}


/* Create the logger. */
Logger logger = Logger.getLogger(className);

/* Create path identified by logFilePath if it does not exist. */
File path = new File(logFilePath);
if (!path.exists()) {
path.mkdir();
}

/* If the invoking class has specified a logging level, use it.
Otherwise, set a default level. */
if (loggingLevel != null) {
logger.setLevel(loggingLevel);
}
else {
logger.setLevel(Level.INFO);
}

/* Create a file handler for the logger. The log file name does NOT
need to exist prior to the execution of this method. */
String logFile = logFilePath + File.separator + logFileName;
Handler logFileHandler = null;
try {
logFileHandler = new FileHandler(logFile);
}
catch (IOException io_excp) {
String msg = CLASS_NAME + "." + METHOD_NAME + " - Couldn't
create FileHandler using file " + logFile + ".\n Details: " + io_excp +
". The stackTrace from this event has been written to the console."; //
$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ //$NON-NLS-4$
io_excp.printStackTrace();
JOptionPane.showMessageDialog(null, msg, CLASS_NAME,
JOptionPane.ERROR_MESSAGE);
return logger;
}

logger.addHandler(logFileHandler);

/* If the invoking class has specified a formatter, use it.
Otherwise, don't add a formatter. */
if (formatter != null) {
Handler[] handlers = logger.getHandlers();
for (Handler oneHandler : handlers) {
if (oneHandler.getClass().getName().equals
("java.util.logging.FileHandler")) { //$NON-NLS-1$
oneHandler.setFormatter(formatter);
}
}
}


return logger;
}
================================================================

I put that in a utility class in my Common project. Then any program that
wants a logger just executes this one method passing the appropriate
parameters.

Either way the logger should be tied to the actual class emitting log
messages, not some common class.

I'm not sure what you mean. The main program creates the logger and
passes a reference to it to each class that it instantiates (well, not
all of them but I am gradually retrofitting the classes so that all of
them get an instance of the logger as a parameter).

Is that not the right thing to do?

I realize that I could have each class create its own logger and log but
would seem to guarantee a proliferation of logs that would be a pain to
find. It seems reasonable to me that if I have a bunch of programs,
including Foo and Bar, and any of them could call one of my common date
routines or my AboutDialog, that any log messages arising from those
classes should be in the log for Foo or Bar, not in separate logs for
each class. Then I'd end up having to look in the AboutDialog log for
messages from that class, a DateUtils log for messages from that class,
etc. etc.

Did you reinvent the logging wheel? If so, does your logging framework
feature log levels, infinitely flexible log formats, logging to screen
or (rolling) file logs, virtual elimination of logging overhead at
levels finer than configured, automatic if slow retrieval of class and
method and line where the logging happens, XML configuration,
portability, a large body of online literature describing its use,
standardization, widespread adoption, and a body of top developers
contributing to the project?

Goodness no! I am using the Java Logging classes to do my logging. Sorry
if that wasn't clear.

What is "elegant"?

Personally I promote "useful" as the useful metric.

Fair enough. I have a great deal of respect for useful and would
certainly put it above elegant! But I'm the kind of guy who likes to have
his cake and eat it too. If I can make it useful AND elegant, that trumps
just useful in my book ;-)

Not from your description of it.


Logging is logging is logging, to misquote Gertrude Stein. Suddenly
now you've created two logging aspects. That's not elegant.

Logging shouldn't be added to and removed from code. That's not the
purpose of logging. Logging is to remain in the code forever.

I think it depends on what kind of logging you're doing. I agree that
logging of Exceptions should probably be in the classes themselves as
long as the Exception can occur. (Mind you, from what I'm seeing in the
AspectJ manual, it seems as if aspects are designed to handle that too.)
But aspects seem more likely to be beneficial in tracking down wonky code
at development time. It's not that unusual for me to write a method that
does something and find that it works pretty well for most cases but then
do odd or unexpected things in some cases. For example, the method that
calculates column widths might do a reasonable job in most cases but
sometimes calculate widths that are noticeably too large or too small.
For something like that, I can see aspects being useful for digging out
what is actually going on in the method without having to recode the
method itself. And once the problem is found, if the debugging is
happening in an aspect, I just delete it from the aspect and leave my
original method nice and tidy rather than having to yank out the
statements I added.

Of course, the Eclipse debugger can make a lot of the logging unnecessary
in the first place so that you don't have to add code to either the
method or an aspect. I don't want to start writing reams of
System.out.println() statements when the debugger can often tell me
what's going on much better.

Logging is not for the developer. That's an all-too-common
misconception. Logging is for the sysop.

I agree. Mind you, I still tend to use them regularly to help with
debugging wonky code but the ultimate user of the log is the sysop.

Have you ever tried to suss out a production issue from the logs?

Frankly, no. I aspire to write very useful messages that would be helpful
in that regard but I won't know how useful they really are until I have
some major systems in production.

The sort of dynamic granularity you describe is built in to the
logging framework. You use levels - DEBUG for debug purposes (or FINE
if you're using java.util.logging), WARNING for warnings, ERROR
(SEVERE) for errors, and so forth.

Yes, I'm using those levels.

By removing logging to AspectJ, you eliminate the flexibility,
visibility and granularity of control logging should support.


A deployment or code base that handles some part of the project under
the hood for you, and gives you a public interface for control of its
behavior. In your case I'm referring to the AspectJ framework. Logging
is also a framework, one apparently you are not using.

Not true, as mentioned above. But it's my fault; I apparently wasn't
clear enough about what I am doing.

Use log4j or java.util.logging (or both). Those are (both)
foundational and you should learn (both of) them very early in your
Java career.

Both would seem like overkill ;-) But I am indeed using
java.util.logging.

Remember - logging is meant to be there in production, for benefit of
sysops and system reliability engineers. Code is not the be-all and
end-all of programming.

Agreed.

 

[Lew]

I'm using Java Logging. Does that answer your question or are you asking
something else?

My code is not terribly different than that.

Actually, what you do is different and some of that difference is terrible.

Why aren't you logging the exceptions?

And what you are doing here is radically different from what I proposed,
hardly at all similar in any respect. I don't understand why you think it's
similar.

Here's the actual code minus the Javadoc comment:

================================================================
public static Logger configureLogger(String className, String
logFilePath, String logFileName, Locale locale, Formatter formatter,
Level loggingLevel) {

My goodness, don't use TABs! Especially not in Usenet posts!

This use of a separate logger factory that takes over what the logging
framework already does is, well, curious.

String METHOD_NAME = "configureLogger()"; //$NON-NLS-1$

You don't need this, and if you did it should be 'final' and named according
to the Java coding conventions.

/* Ensure that the mandatory parameters have all been specified. */
if (className == null) {
throw new IllegalArgumentException("The name of the class must
be provided."); //$NON-NLS-1$

You didn't log this!

And those "$NON-NLS-1$" comments are highly distracting.

}

if (logFilePath == null) {
throw new IllegalArgumentException("The log file path must be
provided."); //$NON-NLS-1$
}

if (logFileName == null) {
throw new IllegalArgumentException("The log file name must be
provided."); //$NON-NLS-1$
}

if (locale == null) {
throw new IllegalArgumentException("The locale must be
provided."); //$NON-NLS-1$
}


/* Create the logger. */
Logger logger = Logger.getLogger(className);

/* Create path identified by logFilePath if it does not exist. */
File path = new File(logFilePath);

Really?

I can't go on. It's too painful.

I put that in a utility class in my Common project. Then any program that
wants a logger just executes this one method passing the appropriate
parameters.

But, splutter, but, ... that's what the existing 'Logger.getLogger()' method
does!

You're doing everything by hand that the framework does for you!

I realize that I could have each class create its own logger and log but
Huh?

No!

would seem to guarantee a proliferation of logs that would be a pain to
find. It seems reasonable to me that if I have a bunch of programs,

No, no, no, no.

You don't create multiple log files, one per class. Where did you get that notion?

You set up the logging in the configuration file. Done. Simple.

You are re-inventing the logging wheel. You said,

Goodness no! I am using the Java Logging classes to do my logging. Sorry
if that wasn't clear.

but you aren't using it correctly. What you are doing is defeating the
built-in features and reinventing everything. Don't do that.

And when I said you should know both ju.logging and log4j, somehow you
inferred that to mean that you should use both in the same program. Such leaps
you make! Settle back and stick with inferences that actually follow from what
I say.

 

[Roedy Green]

Hey, I'm just making sure this is an appropriate place to ask before I
take the time to lay out my problem. This seems like a reasonable place
to ask but the rest of the group may not agree....

see http://mindprod.com/jgloss/newsgroups.html

for the possibilities and some hints on dealing with the denizens.

 

[Arved Sandstrom]

[snip]

[ SNIP ]

I think you just saved me a fair bit of time ;-) I was curious to see
whether I could use aspects to do what I'll call diagnostic logging. I
have some methods that do "calculations" of one kind or another, like the
best width for a column in a JTable given the width of the values in each
column, and it would be neat if I could remove all of that logging code
from the method itself and put it in aspects. Then, when the method is
working 100% to my satisfaction, I can discard that aspect and leave the
method uncluttered.

From what you're saying, I may not be able to capture the values of all
the variables that are being juggled in the suspect method. I had
wondered about that and was going to try it myself to see. I probably
still will but I'll be less surprised/disappointed if I can't access the
information I want.

I'd recommend your own experimentation in any case. The available join
points in AspectJ, as I mentioned before, do provide a lot of power, and
it may well be that you can live with what they give you, for your own code.

I'll point at something that I remember trying out a few years back,
albeit maybe a different version, I dunno. You can find it at

http://www.eclipse.org/aspectj/doc/released/faq.php#q:seeingjoinpoints

Make the modifications as noted to run it on your code, and select your
own entry point. The output XML will show all of the join points in
detail that you could use "within" that entry point.

Actually, I already have logging in place for most of classes and am
retrofitting it to the rest. I use the Java Logging classes, as opposed
to Log4j, but I'm not fanatical about it. I'm hearing more and more to
the effect that Log4j is better so maybe I'll make the switch. The better
I design my logging, the less painful that is going to be ;-)

I've used java.util.logging (JUL) quite a lot, log4j considerably more.
My main objection to JUL is that it is/was a lightweight framework. I
always have had this suspicion that the Sun developers that wrote it got
bored after designing the interfaces and skimped on the real
implementation classes. log4j out of the box has considerably more
options, and extras offer even more choices.

It does, Arved. Thanks!

So what do you use aspects for, besides the occasional need to add
logging into poorly-logged classes?

Nothing. I try to stay aware of AOP developments, just in case
something comes up in the real world that could use it. As others have
stated, AOP doesn't really figure for general application programming,
it's more for infrastructure code like frameworks.

From a software engineering standpoint, not restricting to AspectJ or
even Java, aspect oriented programming and software engineering is not
going away. Crosscutting concerns do exist and will always exist. We
have barely scratched the surface of how to handle them. I like work
that is being done (has been done) on Design by Contract in relation to
aspects (aspect oriented design or AOD), and just as a few other
examples I think there is serious potential for talking about security
and transactionality from the cross-cutting perspective. But again this
is more infrastructure oriented work and research.

AHS

 

[Arne Vajhøj]

Actually, I already have logging in place for most of classes and am
retrofitting it to the rest. I use the Java Logging classes, as opposed
to Log4j, but I'm not fanatical about it. I'm hearing more and more to
the effect that Log4j is better so maybe I'll make the switch. The better
I design my logging, the less painful that is going to be ;-)

As a rule of thumb I would go for:
SE => jul
EE => log4j
(based on sophistication needed and deployment context)

Arne

 

[Arne Vajhøj]

log4j is my favorite.


I don't think that's a good pattern. Which logging library are you
using?

I'm using Java Logging. Does that answer your question or are you asking
something else?

I have each class create its own logger (log4j style shown:

package eegee;
import org.apache.log4j.Logger;
import static org.apache.log4j.Logger.getLogger;
public class Foo
{
final Logger logger = getLogger(getClass());

public void foo()
{
logger.debug("");
// do the fooey stuff
try
{
// do the trying stuff
}
catch (FooException exc)
{
String msg = "trying stuff failed. "+
exc.getLocalizedMessage(); logger.error(msg, exc);
throw new IllegalStateException(msg, exc);
}
}
}

This boilerplate is what aspects aim to remove from the code and I
espouse retaining.

My code is not terribly different than that.

Here's the actual code minus the Javadoc comment:

================================================================
public static Logger configureLogger(String className, String
logFilePath, String logFileName, Locale locale, Formatter formatter,
Level loggingLevel) {

String METHOD_NAME = "configureLogger()"; //$NON-NLS-1$

/* Ensure that the mandatory parameters have all been specified. */
if (className == null) {
throw new IllegalArgumentException("The name of the class must
be provided."); //$NON-NLS-1$
}

if (logFilePath == null) {
throw new IllegalArgumentException("The log file path must be
provided."); //$NON-NLS-1$
}

if (logFileName == null) {
throw new IllegalArgumentException("The log file name must be
provided."); //$NON-NLS-1$
}

if (locale == null) {
throw new IllegalArgumentException("The locale must be
provided."); //$NON-NLS-1$
}


/* Create the logger. */
Logger logger = Logger.getLogger(className);

/* Create path identified by logFilePath if it does not exist. */
File path = new File(logFilePath);
if (!path.exists()) {
path.mkdir();
}

/* If the invoking class has specified a logging level, use it.
Otherwise, set a default level. */
if (loggingLevel != null) {
logger.setLevel(loggingLevel);
}
else {
logger.setLevel(Level.INFO);
}

/* Create a file handler for the logger. The log file name does NOT
need to exist prior to the execution of this method. */
String logFile = logFilePath + File.separator + logFileName;
Handler logFileHandler = null;
try {
logFileHandler = new FileHandler(logFile);
}
catch (IOException io_excp) {
String msg = CLASS_NAME + "." + METHOD_NAME + " - Couldn't
create FileHandler using file " + logFile + ".\n Details: " + io_excp +
". The stackTrace from this event has been written to the console."; //
$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ //$NON-NLS-4$
io_excp.printStackTrace();
JOptionPane.showMessageDialog(null, msg, CLASS_NAME,
JOptionPane.ERROR_MESSAGE);
return logger;
}

logger.addHandler(logFileHandler);

/* If the invoking class has specified a formatter, use it.
Otherwise, don't add a formatter. */
if (formatter != null) {
Handler[] handlers = logger.getHandlers();
for (Handler oneHandler : handlers) {
if (oneHandler.getClass().getName().equals
("java.util.logging.FileHandler")) { //$NON-NLS-1$
oneHandler.setFormatter(formatter);
}
}
}


return logger;
}
================================================================

I put that in a utility class in my Common project. Then any program that
wants a logger just executes this one method passing the appropriate
parameters.

????

That looks as if you are almost building your own logging framework
on top of a logging framework.

That does not make much sense to me.

Arne

 

[Novice]

Actually, what you do is different and some of that difference is
terrible.

Why aren't you logging the exceptions?

Because this is the code that creates the logger. If it fails to create
the logger, where would you like me to log the exception?

And what you are doing here is radically different from what I
proposed, hardly at all similar in any respect. I don't understand why
you think it's similar.

Okay, maybe it's completely different then. I thought it was the same
spirit.

My goodness, don't use TABs! Especially not in Usenet posts!
Sorry.

This use of a separate logger factory that takes over what the logging
framework already does is, well, curious.


You don't need this, and if you did it should be 'final' and named
according to the Java coding conventions.

I thought final was irrelevant in a method and only made a difference for
instance variables?

You're right about the case of the name. That should be methodName for a
method variable....

You didn't log this!

Where would you like me to log this?

And those "$NON-NLS-1$" comments are highly distracting.

Sorry, I should have stripped them and the tabs out of the code first.

Really?

I can't go on. It's too painful.

Why? Telling me it's awful without saying why doesn't teach me anything.

But, splutter, but, ... that's what the existing 'Logger.getLogger()'
method does!

You're doing everything by hand that the framework does for you!

So I just execute Logger.getLogger() and a logger will be magically
created that is exactly where I want it to be with exactly the file name
I want to ensure that it is in the right format, XML in my case and with
exactly the right logging level and handlers? I thought I had to do SOME
of the work to ensure I got what I wanted.

No, no, no, no.

You don't create multiple log files, one per class. Where did you get
that notion?

Huh? You seem to be contradicting yourself. Are you saying I should
create one logging file per class or not? And why have a separate logging
file for each class? Isn't it more logical to have all the messages that
come from one program, say Foo, appear in the same log? Isn't the poor
Sysop going to be excessively busy if he has to check a separate log for
each and every one of the - hundreds? thousands? - of classes in the
system? Wouldn't it be more logical to group logs on the basis of which
application is invoking the class? Therefore, if method
getCurrentWeekdayName had problems while executing program Foo, the Foo
log would contain the information? Wouldn't the person running Foo be the
one that's notifying the SysOp that something screwy just happened while
running Foo? Then the name of the application would be a huge head start
in finding the problem: just look in the Foo log and all will be
revealed. Or at least enough to get started.

You set up the logging in the configuration file. Done. Simple.

What configuration file? I'm not sure what you mean. First, I'm not sure
what you mean by a configuration file. Second, are you saying that all
applications will normally have a configuration file? I don't remember
coming across those in the Java Tutorial, for example, or even seeing
them mentioned in this newsgroup.

If this is some routine thing that professional developers do, great. I
obviously need to know about it. Can you point me to a tutorial or
whatever that will explain what they are and how to create them?

You are re-inventing the logging wheel. You said,

but you aren't using it correctly. What you are doing is defeating the
built-in features and reinventing everything. Don't do that.

That was not my intention. I'm off to look at the logging classes again
and see how I can avoid reinventing the wheel. I'm really not seeing why
you say that yet. I'm using the standard Java Logging classes. I've
tweaked the properties file that governs logging a little bit to get the
effect that I wanted and I created my own variant on the XMLFormatter
that is only very slightly different. Aside from that, I'm using the
vanilla logging classes. I'm not sure how that constitutes reinventing
the framework. But, as I said, I'm going to review the logging classes
now and see if I'm overcomplicating the creation of the logger as you
say. Perhaps I am....

And when I said you should know both ju.logging and log4j, somehow you
inferred that to mean that you should use both in the same program.
Such leaps you make! Settle back and stick with inferences that
actually follow from what I say.

Well, here's the exact quote:

"Use log4j or java.util.logging (OR BOTH)". [emphasis added]

I don't think it's completely unreasonable to take that as a suggestion
to use both within a single program. Which is why I asked you about it.
Hey, I'm just trying to learn and I'm prepared to hear things that
surprise me. There might be some case to be made for logging redundantly
to two separate loggers that I hadn't considered. It seems farfetched to
me but it seemed like what you were saying.

Did you ever hear that old saying, attributed to various ancient
personages?

“He who knows not and knows not he knows not: he is a fool - shun him. He
who knows not and knows he knows not: he is simple - teach him. He who
knows and knows not he knows: he is asleep - wake him. He who knows and
knows he knows: he is wise - follow him.”

In that context, I consider myself "simple": I know that there are a
bunch of things I don't know. I'm looking at the people in this newsgroup
as being in the 'wise' category and am trying to learn from you.

As I've said, I'm a one man Java shop in a town that doesn't seem to do
much Java. I don't work in a professional Java shop so I have no
professional Java code to look at or peers to learn from. So I'm
floundering. That's why this newsgroup is important to me. I _AM_ trying
to get better at this....

 

[Arne Vajhøj]

Did you ever hear that old saying, attributed to various ancient
personages?

“He who knows not and knows not he knows not: he is a fool - shun him. He
who knows not and knows he knows not: he is simple - teach him. He who
knows and knows not he knows: he is asleep - wake him. He who knows and
knows he knows: he is wise - follow him.”

Wise words.

In that context, I consider myself "simple": I know that there are a
bunch of things I don't know. I'm looking at the people in this newsgroup
as being in the 'wise' category and am trying to learn from you.

As I've said, I'm a one man Java shop in a town that doesn't seem to do
much Java. I don't work in a professional Java shop so I have no
professional Java code to look at or peers to learn from. So I'm
floundering. That's why this newsgroup is important to me. I _AM_ trying
to get better at this....

You may be able to download and look at some open source code that
uses logging.

Arne

 

[Lew]

Because this is the code that creates the logger. If it fails to create
the logger, where would you like me to log the exception?

Yeah, I figured that out after the fact. You were doing a weird thing by
creating a factory method to call the factory method to create the logger.

Okay, maybe it's completely different then. I thought it was the same
spirit.

No. The difference is that I put the logger code in each class, and don't have
a centralized factory factory. That's because the logging framework already
provides a factory and a way to configure it, so I don't try to reinvent that
entire mechanism.

I thought final was irrelevant in a method and only made a difference for
instance variables?

It's not irrelevant, depending on what you think is relevant. It prevents
reassignment of the reference, and as a comment lets maintainers know the
intent is to have an immutable reference.

But you are correct that is actually wasn't so necessary here.

You're right about the case of the name. That should be methodName for a
method variable....

Where would you like me to log this?

'logger.severe()' right at the point, just before the throw.

Sorry, I should have stripped them and the tabs out of the code first.

Actually, you should indent with spaces not TABs routinely. And strip out the
superfluous comments in your own code, too - that is, if they're actually
superfluous.

Why? Telling me it's awful without saying why doesn't teach me anything.

I didn't stop there. I did say why.

You don't need that. You just call 'Logger.getLogger()'. The utility class is
a whole lot of weird complication that you don't need.

So I just execute Logger.getLogger() and a logger will be magically
created that is exactly where I want it to be with exactly the file name
I want to ensure that it is in the right format, XML in my case and with
exactly the right logging level and handlers? I thought I had to do SOME
of the work to ensure I got what I wanted.

Yes, that is correct.

Huh? You seem to be contradicting yourself. Are you saying I should
create one logging file per class or not? And why have a separate logging

No. I never said nor implied that you should have one logging file per class.
That one's on you, brother.

file for each class? Isn't it more logical to have all the messages that
come from one program, say Foo, appear in the same log? Isn't the poor

Yes, but why are you arguing a point not in dispute?

Sysop going to be excessively busy if he has to check a separate log for
each and every one of the - hundreds? thousands? - of classes in the
system? Wouldn't it be more logical to group logs on the basis of which
application is invoking the class? Therefore, if method
getCurrentWeekdayName had problems while executing program Foo, the Foo
log would contain the information? Wouldn't the person running Foo be the
one that's notifying the SysOp that something screwy just happened while
running Foo? Then the name of the application would be a huge head start
in finding the problem: just look in the Foo log and all will be
revealed. Or at least enough to get started.

How you do go on.

No one is suggesting anything like that scenario. so cool your jets, Cadet!

Wow.

What configuration file? I'm not sure what you mean. First, I'm not sure
what you mean by a configuration file. Second, are you saying that all
applications will normally have a configuration file? I don't remember
coming across those in the Java Tutorial, for example, or even seeing
them mentioned in this newsgroup.

A configuration file is a file that contains configuration information.

As far as what you don't remember, if you follow the link from the API docs
for java.util.logging:
<http://docs.oracle.com/javase/7/docs/api/java/util/logging/package-summary.html>

You come across a recommendation to read the introduction to Java logging,
which I sure hope you followed:
"Related Documentation
For an overview of control flow, please refer to the Java Logging Overview."
which links you to
<http://docs.oracle.com/javase/7/docs/technotes/guides/logging/overview.html>
wherein you would have read, had you read it,
<http://docs.oracle.com/javase/7/docs/technotes/guides/logging/overview.html#a1.15>
"The APIs are structured so that an initial set of configuration information
is read as properties from a configuration file."

As for the tutorials, you have
<http://lmgtfy.com/?q=Java+logging+tutorial>
which among other links will find you

If this is some routine thing that professional developers do, great. I
obviously need to know about it. Can you point me to a tutorial or
whatever that will explain what they are and how to create them?

GIYF, dude.

That was not my intention. I'm off to look at the logging classes again
and see how I can avoid reinventing the wheel. I'm really not seeing why
you say that yet. I'm using the standard Java Logging classes. I've
Abusing

tweaked the properties file that governs logging a little bit to get the

Huh. That's the configuration file, dude.

effect that I wanted and I created my own variant on the XMLFormatter
that is only very slightly different. Aside from that, I'm using the
vanilla logging classes. I'm not sure how that constitutes reinventing
the framework. But, as I said, I'm going to review the logging classes
now and see if I'm overcomplicating the creation of the logger as you
say. Perhaps I am....

The properties file specifies the log file, the log level (by type if you so
choose), the output format, whether you report the class and method being
logged - all the things you did manually in your utility class.

And when I said you should know both ju.logging and log4j, somehow you
inferred that to mean that you should use both in the same program.
Such leaps you make! Settle back and stick with inferences that
actually follow from what I say.

Well, here's the exact quote:

"Use log4j or java.util.logging (OR BOTH)". [emphasis added]

Not in the same code! Yeesh.

....

As I've said, I'm a one man Java shop in a town that doesn't seem to do
much Java. I don't work in a professional Java shop so I have no
professional Java code to look at or peers to learn from. So I'm
floundering. That's why this newsgroup is important to me. I _AM_ trying
to get better at this....

Of course, hence the detailed feedback.

 

[markspace]

That looks as if you are almost building your own logging framework
on top of a logging framework.

That does not make much sense to me.

I can think of a use case for it though. Let's say you haven't decided
which logging framework to use, or you want to be flexible as to which
one to use. (Different customers of yours prefer different loggers.)

(Not syntax checked or tested.)

abstract class MyLogger {

public static MyLogger getLogger( String name ) {
MyLogger logger = Class.forName(
System.getProperty("me.mystuff.MyLogger.logImpl",
"me.mystuff.MyDefaultLogger" ).newInstance());
return logger;
}

public abstract void logStuff(Object...);
}


So the idea is that you wrap the logging framework in your own, and then
you're free to provide an implementation that matches whatever logging
framework you choose to use in the future. Maybe this is not for
everyone, but I could see its advantages. Some folks might like
java.util.Logger, some folks like log4j. And some might like things
that I don't know about yet.

A couple of other things.

Lew wrote:

public class Foo
{
final Logger logger = getLogger(getClass());
[...]
}

This requires that a logger is instantiated for each object as it is
created. Potentially this is a lot of work, and each logger may not be
used. (Even declaring the logger to be static still requires a logger
per class loaded.)

Whereas this:

...
try {
... some stuff...
} catch (Exception ex) {
getLogger(getClass()).log( ... );
}

creates the logger lazily and therefore doesn't spend any resources if
logging happens to be never required.

Lastly, I don't know about log4j, but I don't think the
java.util.logging package uses threads when logging. Any IO operations
the logger makes will block the calling thread. I've heard this is
undesirable in most cases. So rolling your own framework also gives you
control over threading issues too, which again might be important for
some customers.

 

[Lew]

I can think of a use case for it though. Let's say you haven't decided which
logging framework to use, or you want to be flexible as to which one to use.
(Different customers of yours prefer different loggers.)

That's what Apache Commons logging is for.

(Not syntax checked or tested.)

abstract class MyLogger {

public static MyLogger getLogger( String name ) {
MyLogger logger = Class.forName(
System.getProperty("me.mystuff.MyLogger.logImpl",
"me.mystuff.MyDefaultLogger" ).newInstance());
return logger;
}

public abstract void logStuff(Object...);
}

It's actually common for libraries to use either ju.logging or log4j without
regard for your preference, with the result that both frameworks wind up in
the same program.

So the idea is that you wrap the logging framework in your own, and then
you're free to provide an implementation that matches whatever logging
framework you choose to use in the future. Maybe this is not for everyone, but
I could see its advantages. Some folks might like java.util.Logger, some folks
like log4j. And some might like things that I don't know about yet.

I think in Java those two pretty much have it sewn up.

In any event, there's already

A couple of other things.

Lew wrote:

public class Foo
{
final Logger logger = getLogger(getClass());
[...]
}

This requires that a logger is instantiated for each object as it is created.

No, it doesn't.

It only creates one per class.

Potentially this is a lot of work, and each logger may not be used. (Even
declaring the logger to be static still requires a logger per class loaded.)

That's not important overhead at all. It's a feature, not a bug.

The logger being tied to the class (or its name) gives you class-level control
over the logger behavior at deployment time by adjustment of the logging
properties (or XML) configuration file. This is desirable.

The logging object size pays for itself in spades with its functionality.

Whereas this:

...
try {
... some stuff...
} catch (Exception ex) {
getLogger(getClass()).log( ... );
}

creates the logger lazily and therefore doesn't spend any resources if logging
happens to be never required.

Lazy initialization is waaay overrated.

First prove you have an optimization problem before you present an
optimization solution.

Lastly, I don't know about log4j, but I don't think the java.util.logging
package uses threads when logging. Any IO operations the logger makes will
block the calling thread. I've heard this is undesirable in most cases. So

Loggers are designed to be very fast unless used. So calls below the logging
threshold add very, very little overhead.

Calls above the threshold are usually warning or error logging, so the
overhead there is masked by the exception mechanism and the fact that things
are crashing.

First prove you have an optimization problem before you present an
optimization solution.

rolling your own framework also gives you control over threading issues too,
which again might be important for some customers.

Unlikely, but remotely possible.

That doesn't apply to the OP's situation, of course.

But your analysis ignores the care that goes into those two logging frameworks
to minimize the overhead of logging calls, and the substantial functionality
that you either sacrifice or spend a fortune recreating in a roll-your-own. It
also ignores the difficulty of beating their performance. You'd be
hard-pressed to exceed the efficiency of these frameworks.

Think long and hard before deciding to forego these two logging frameworks,
then stick with them anyway.

If you really, really, really, really, really, really need to spawn a thread
to make logging faster, which you don't, you can do that over a regular
ju.logging or log4j call. You don't have to throw out the baby with the bath
water.

 

[markspace]

That's what Apache Commons logging is for.

Back when I was playing with applets, I discovered by default that the
jul logger creates a log file in your home directory. (There's a
default logging.properties file created with every Java desktop
installation and that's what it does). With unsigned applets, this
means even trying to instantiate any part of the jul logging system will
throw an exception, because the applet has no permissions for creating
files.

There might be ways around that, but it spooked me and I decided that
since I didn't have direct control over a user's system, I couldn't rely
on any defaults in the JRE installation. So I made a shell logging
system that wrapped the jul logger and allowed me control, in case I had
to use something besides jul entirely.

BTW, I wasn't aware that Apache Commons logging was different than
JULI/log4j. Thanks for pointing that out.

No, it doesn't.

It only creates one per class.

OK, assuming loggers are cached and reused, fair point.

Lazy initialization is waaay overrated.

First prove you have an optimization problem before you present an
optimization solution.

Well, that "optimization" is code that my IDE writes by default. It
costs me nothing, so I'd rather prove that it's a problem before messing
with it.

If you really, really, really, really, really, really need to spawn a
thread to make logging faster, which you don't, you can do that over a
regular ju.logging or log4j call. You don't have to throw out the baby
with the bath water.

I've never had to spawn threads for logging, and the idea was something
I've only seen presented once, so I'm not sure how useful the concept
is. However, I keep it in mind as something that might have to happen
someday.

 

[Lew]

Back when I was playing with applets, I discovered by default that the jul
logger creates a log file in your home directory. (There's a default
logging.properties file created with every Java desktop installation and
that's what it does). With unsigned applets, this means even trying to
instantiate any part of the jul logging system will throw an exception,
because the applet has no permissions for creating files.

There might be ways around that, but it spooked me and I decided that since I
didn't have direct control over a user's system, I couldn't rely on any
defaults in the JRE installation. So I made a shell logging system that
wrapped the jul logger and allowed me control, in case I had to use something
besides jul entirely.

BTW, I wasn't aware that Apache Commons logging was different than JULI/log4j.
Thanks for pointing that out.





OK, assuming loggers are cached and reused, fair point.

It's not really a cache. The logger factory method is simply guaranteed to
return the same instance of the same-identified logger, just as say
'Integer.valueOf(5)' is guaranteed to return the same 'Integer' instance each
time within the program.

<http://docs.oracle.com/javase/7/docs/api/java/util/logging/Logger.html#getLogger(java.lang.String)>
"Find or create a logger for a named subsystem. If a logger has already been
created with the given name it is returned. Otherwise a new logger is created."

<http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/Logger.html#getLogger(java.lang.String)>
"Retrieve a logger named according to the value of the name parameter. If the
named logger already exists, then the existing instance will be returned.
Otherwise, a new instance is created."

It's important to know what the system promises, and the Javadocs tell you.

The logging frameworks are foundational and should be part of the early
education of the Java programmer, along with the collections framework.
Knowledge of things like that all same-named loggers point to the same logger
instance is useful.

Well, that "optimization" is code that my IDE writes by default. It costs me
nothing, so I'd rather prove that it's a problem before messing with it.

You mean the IDE generates lazy instantiation for you? It's a problem in that
it is additional code that resists best-practice idioms without benefit. The
fact that you have accepted someone else's default doesn't make it a great idea.

Your lazy acceptance of a lazy initialization idiom is not good for the code,
however much it may appear to you to save you the minute to change your IDE's
default to a saner approach.

I'm sensitive to habits, especially ones that lead to trouble. Maybe your
classes by default aren't meant for concurrent programs, for example, but I
never assume my classes won't be used that way. I also believe that if you
practice safe idioms you don't accidentally forget to use one when you need it.

Lazy instantiation has proven dangers and it causes things to be initialized
in an unpredictable way and out of the normal class sequence for eagerly
initialized items. Whether those dangers apply in this case or that case, it
costs nothing to do things the safe way and not have to shift gears when you
suspect danger.

I've never had to spawn threads for logging, and the idea was something I've
only seen presented once, so I'm not sure how useful the concept is. However,
I keep it in mind as something that might have to happen someday.

It was the idea you suggested, though.

I was just responding with a way to follow your suggestion, with which I
disagree BTW, that didn't involve having to reinvent the whole logging
framework thing.

 

[Lew]

You mean the IDE generates lazy instantiation for you? It's a problem in that
it is additional code that resists best-practice idioms without benefit. The
fact that you have accepted someone else's default doesn't make it a great idea.

Your lazy acceptance of a lazy initialization idiom is not good for the code,
however much it may appear to you to save you the minute to change your IDE's
default to a saner approach.

I'm sensitive to habits, especially ones that lead to trouble. Maybe your
classes by default aren't meant for concurrent programs, for example, but I
never assume my classes won't be used that way. I also believe that if you
practice safe idioms you don't accidentally forget to use one when you need it.

Lazy instantiation has proven dangers and it causes things to be initialized
in an unpredictable way and out of the normal class sequence for eagerly
initialized items. Whether those dangers apply in this case or that case, it
costs nothing to do things the safe way and not have to shift gears when you
suspect danger.

That said, the logging frameworks themselves do lazy instantiation.

Also, my comments here were meant to be very, very broad. Regular readers of
my posts know that I usually point out that programming rules are not
religions and there are times when they do or do not apply.

For loggers, I instantiate according to scope needed, pure and simple, without
regard for whether instantiation is lazy or eager. Since I use loggers
heavily, typically with 'logger.debug("");' at the head of every method, it
makes sense to have a 'private transient final Logger logger' class member
most of the time.

If I have a logger used only inside a particular block, it's instantiated
inside that block the way you showed.

This is in line with the best practice of minimizing variable scope.

I don't just accept the IDE authors' default blindly, though.

 

[Martin Gregorie]

The logger being tied to the class (or its name) gives you class-level
control over the logger behavior at deployment time by adjustment of the
logging properties (or XML) configuration file. This is desirable.

That's an interesting approach, though not one that I use. I tend to
prefer a single logger per process with an associated level attribute,
and to sprinkle classes with logger calls specifying different levels so
I can vary the logged detail depending on what I need to see. The minimal
level may correspond to nothing more than reporting overall run
statistics. Next level will log method exits and show call arguments plus
return value. The level above that shows method entry and beyond that
anything that might be relevant in the method internals: both of these
are omitted unless the method is complex enough to require them.

The logging object size pays for itself in spades with its
functionality.

Agreed. I recently added the ability to cache logger messages in a
circular buffer to mine: if enabled, anything that's not an error is
merely added to the buffer, which is dumped ahead of outputting an error
message. This can be a big help if you need to diagnose a rarely
occurring problem in a long-running process - it beats scanning through a
multi-megabyte log hands down.

 

[Arved Sandstrom]

That's what Apache Commons logging is for.

As soon as a mention of commons logging comes up, I feel bound to
mention SLF4J.

For the OP, if you're genuinely researching Java logging, check out
SLF4J (http://www.slf4j.org/). This is a facade for other logging
frameworks, so you'd actually implement using JUL or log4j or logback.
Note that the same fellow who is responsible for log4j also drives slf4j
and logback.

Also while we are at it, I recommend
http://www.javacodegeeks.com/2011/01/10-tips-proper-application-logging.html
as a good list of tips for application logging.

[ SNIP ]

It's actually common for libraries to use either ju.logging or log4j
without regard for your preference, with the result that both frameworks
wind up in the same program.

Yes. There are a few different situations that arise here. In one case,
the 3rd party library uses the *same* logging framework as you do. In
which case, depending on overall environment and various classloaders,
don't be surprised if your logging configuration also applies to that
3rd party library. You may start out with an unexpected spew of log
statements in your log files until you finetune your loggers.

From my standpoint I always see that extra flow of info with gratitude.
I'll usually set first logging configuration to DEBUG for the packages
in 3rd party libraries, just to see what I get. If the external parties
also wrote good logging statements then the result is a major bonus, to
again be filtered and directed as needed.

In the other major case, the 3rd party library uses something different.
Pay attention to that; hunt down its logging configuration file. You're
not just using that library's Java API, you're also using its ability to
log what's happening. Avoid having it be a black box that you can only
debug into with decompiling to try to figure out what it's doing.

I think in Java those two pretty much have it sewn up.

See above wrt slf4j and logback.

[ SNIP ]
AHS

 

[Novice]

Wise words.


You may be able to download and look at some open source code that
uses logging.

Can you suggest any specific projects/products that you think are
particularly well-written? I had thought of looking at such code before
but I'm not sure I'd necessarily recognize well-written code if I found
it. It might look strange to me but actually be brilliant or viceversa.

If I start looking at code that is written by someone who knows less than
I do, I'll go backwards, not forwards, in my learning.

 

[Arne Vajhøj]

I can think of a use case for it though. Let's say you haven't decided
which logging framework to use, or you want to be flexible as to which
one to use. (Different customers of yours prefer different loggers.)

Commons Logging already exist to handle that!

Arne