dependency injection and loggers

[Tomer]

I love the concept of dependency injection via ctor. it simplifies life and makes testing easy.
what about logger?
i usually instantiate it in private static logger = Logger.getLogger(myclass);
however this is not dependency injection, should I pass the logger into each ctor? this would look wierd... so what to do about loggers and depedency injection?

thanks

 

[markspace]

I love the concept of dependency injection via ctor. it simplifies
life and makes testing easy. what about logger? i usually instantiate
it in private static logger = Logger.getLogger(myclass); however this
is not dependency injection, should I pass the logger into each ctor?
this would look wierd... so what to do about loggers and depedency
injection?

I agree with you on both counts. Ctors are an excellent way of
implementing dependency injection, and static methods aren't.

However loggers are more of an aspect than a dependency. Absent some
other framework (AOP, for example, or some sort of annotation
processing), good old frameworks and libraries solve this problem. Have
a look at Apache logging:

<http://commons.apache.org/logging/>

 

[Kevin McMurtrie]

I agree with you on both counts. Ctors are an excellent way of
implementing dependency injection, and static methods aren't.

However loggers are more of an aspect than a dependency. Absent some
other framework (AOP, for example, or some sort of annotation
processing), good old frameworks and libraries solve this problem. Have
a look at Apache logging:

<http://commons.apache.org/logging/>

I'd say that Java's own logger (java.util.logging) is worth a look too
if you want modularity. It's easy to plug in custom formatters and
handlers. You map logging paths to handlers during app initialization
so no dependency injection is involved. My biggest peeve about most
loggers is that they don't indent multi-line log entries nicely and
they're sensitive to disk latency. It's not a problem when you plug in
your own parts. You can also do fancy logging to remote archiving
systems (JSON or XML over socket or REST, etc.) with little effort.

http://docs.oracle.com/javase/6/docs/api/java/util/logging/package-summar
y.html

 

[Daniel Pitts]

I agree with you on both counts. Ctors are an excellent way of
implementing dependency injection, and static methods aren't.

However loggers are more of an aspect than a dependency. Absent some
other framework (AOP, for example, or some sort of annotation
processing), good old frameworks and libraries solve this problem. Have
a look at Apache logging:

<http://commons.apache.org/logging/>

Loggers can generally be configured externally to their instances.
Therefor you don't usually need to inject them.

On the other hand, there generally isn't any real requirement that
loggers be static. I have had occasion to create a class which uses a
different logger depending on the context in which that class was created.

public class MySomething {
private final Logger log;

public MySomething() {
this.log = Logger.getLogger(MySomething.class);
}
public MySomething(Logger log) {
this.log = log;
}
}

 

[Lew]

On the other hand, there generally isn't any real requirement that
loggers be static. I have had occasion to create a class which uses a
different logger depending on the context in which that class was created.

public class MySomething {
private final Logger log;

public MySomething() {
this.log = Logger.getLogger(MySomething.class);
}

public MySomething(Logger log) {
this.log = log;
}
}

If I have a class hierarchy (for when despite Josh Bloch's recommendation to "prefer composition
to inheritance" I go the other way) I will often put in the parent class:

private final Logger logger = Logger.getLogger(getClass().getName());

This despite the violation of "Don't call an overrideable method during construction."

 

[Daniel Pitts]

If I have a class hierarchy (for when despite Josh Bloch's recommendation to "prefer composition
to inheritance" I go the other way) I will often put in the parent class:

private final Logger logger = Logger.getLogger(getClass().getName());

This despite the violation of "Don't call an overrideable method during construction."

getClass() is not overrideable.

 

[Arne Vajhøj]

I love the concept of dependency injection via ctor. it simplifies life and makes testing easy.
what about logger?
i usually instantiate it in private static logger = Logger.getLogger(myclass);
however this is not dependency injection, should I pass the logger into each ctor? this would look wierd... so what to do about loggers and depedency injection?

If you do not use a logger hierarchy, then DI'ing loggers would be easy.

But you typical do so DI is difficult.

Arne

 

[Arne Vajhøj]

I'd say that Java's own logger (java.util.logging) is worth a look too
if you want modularity. It's easy to plug in custom formatters and
handlers.

log4j has more than jul.

But if jul has sufficient, then it is obviously fine.

My biggest peeve about most
loggers is that they don't indent multi-line log entries nicely

I would recommend avoiding multi-line entries completely.

Arne

 

[Arne Vajhøj]

Loggers can generally be configured externally to their instances.
Therefor you don't usually need to inject them.

On the other hand, there generally isn't any real requirement that
loggers be static.

Typically non static logger refs will point to same
logger object.

Arne

 

[Arved Sandstrom]

Arne is right. Permitting multi-line log entries is a security
hazard. (It is safe to format log entries with multiple lines; but
you need to sanitize user data (e.g., strip CR/LF) before including
such data in your log messages.)

Errr, having multiline log entries is not a security hazard, not even
remotely. Splunk certainly doesn't think so - that toolset has extensive
configuration capabilities for handling multiline entries.

What *is* a hazard is if external input to a log entry, that might be
maliciously seeded with linefeeds, is not sanitized/conditioned. Which
is what you said. This is actually a CERT secure coding guideline. Point
being, if you are controlling log entry input, and *you* want a
linefeed, fill your boots. It's not insecure. Just don't let accidental
or malicious ones be supplied across a trust boundary.

I do agree with Arne that multiline should be avoided. Mainly because
it's a PITA. Not everyone is using Splunk.

AHS

 

[Kevin McMurtrie]

Errr, having multiline log entries is not a security hazard, not even
remotely. Splunk certainly doesn't think so - that toolset has extensive
configuration capabilities for handling multiline entries.

What *is* a hazard is if external input to a log entry, that might be
maliciously seeded with linefeeds, is not sanitized/conditioned. Which
is what you said. This is actually a CERT secure coding guideline. Point
being, if you are controlling log entry input, and *you* want a
linefeed, fill your boots. It's not insecure. Just don't let accidental
or malicious ones be supplied across a trust boundary.

I do agree with Arne that multiline should be avoided. Mainly because
it's a PITA. Not everyone is using Splunk.

AHS

There's absolutely nothing wrong with multi-line log messages. This
brings me around to many loggers not formatting correctly. It should be
something safe and easy to read like this:

YYYY/MM/DD META META META Log message line one
Log message line two
Log message line three
Log message line four

This makes stack traces and long diagnostic messages look good while
also preventing log spoofing. A spoof attempt would look like:

YYYY/MM/DD META META META Malicious message line one
YYYY/MM/DD META META META Malicious message line two

That second line isn't fooling anything because it starts with a TAB
character. This feature belongs in the log formatter so it's not
junking up the rest of the codebase.

 

[Arne Vajhøj]

There's absolutely nothing wrong with multi-line log messages. This
brings me around to many loggers not formatting correctly. It should be
something safe and easy to read like this:

YYYY/MM/DD META META META Log message line one
Log message line two
Log message line three
Log message line four

This makes stack traces and long diagnostic messages look good while
also preventing log spoofing. A spoof attempt would look like:

YYYY/MM/DD META META META Malicious message line one
YYYY/MM/DD META META META Malicious message line two

That second line isn't fooling anything because it starts with a TAB
character. This feature belongs in the log formatter so it's not
junking up the rest of the codebase.

Still a bad approach.

All the log reading tools out there do not understand this
format.

Arne

 

[Lew]

I would recommend avoiding multi-line entries completely.

I'm not sure which side of the debate this supports, but for log files the
single largest issue tends to be readability.

On most projects I've seen, programmers (including me) toss log statements
rather willy-nilly into the code, if we use them at all.

Many programmers (not including me) threw fancy-schmancy emphasis into their
logs, such as

logger.debug("* ====== variable not yet assigned or assigned to null ====== *!");

Note I deliberately chose 'debug' level to emphasize the point, which is that
in the morass of detail log messages, combined with the boilerplate of
date, thread ID, log level, etc., this stuff makes it deucedly hard to extract
information that is

actually useful for troubleshooting

..

No one looks at the logs until they need them, and then, OMFG crappy log
statements make life hard. "===" just distracts, and what variable? Where?

Personally I find terse, info-laden log statements with intelligent use of
the verbosity hierarchy in a consistent pattern sprinkled with low-level
stacktraces as required serve best.

Live downstream of your own effluents - use your own log output to trace and
troubleshoot your code. Make trouble for your code just so you can do that.

Getting screwed by your own log output is very instructive. I've been there..

 

[Arne Vajhøj]

There's absolutely nothing wrong with multi-line log messages. This
brings me around to many loggers not formatting correctly. It should be
something safe and easy to read like this:

YYYY/MM/DD META META META Log message line one
Log message line two
Log message line three
Log message line four

This makes stack traces and long diagnostic messages look good while
also preventing log spoofing. A spoof attempt would look like:

YYYY/MM/DD META META META Malicious message line one
YYYY/MM/DD META META META Malicious message line two

That second line isn't fooling anything because it starts with a TAB
character. This feature belongs in the log formatter so it's not
junking up the rest of the codebase.

It is indeed a formatter/layout issue.

And it is trivial to do if one want to.

import java.util.logging.LogRecord;
import java.util.logging.SimpleFormatter;

public class IndentSimpleFormatter extends SimpleFormatter {
@Override
public String format(LogRecord rec) {
return super.format(rec).replaceAll("\r\n(?!$)", "\r\n ");
}
}


or:

import org.apache.log4j.PatternLayout;
import org.apache.log4j.spi.LoggingEvent;

public class IndentPatternLayout extends PatternLayout {
@Override
public String format(LoggingEvent event) {
return super.format(event).replaceAll("\r\n(?!$)", "\r\n ");
}
}

Arne

 

[Arne Vajhøj]

I'm not sure which side of the debate this supports, but for log files the
single largest issue tends to be readability.

On most projects I've seen, programmers (including me) toss log statements
rather willy-nilly into the code, if we use them at all.

Many programmers (not including me) threw fancy-schmancy emphasis into their
logs, such as

logger.debug("* ====== variable not yet assigned or assigned to null ====== *!");

Note I deliberately chose 'debug' level to emphasize the point, which is that
in the morass of detail log messages, combined with the boilerplate of
date, thread ID, log level, etc., this stuff makes it deucedly hard to extract
information that is actually useful for troubleshooting.

No one looks at the logs until they need them, and then, OMFG crappy log
statements make life hard. "===" just distracts, and what variable? Where?

Personally I find terse, info-laden log statements with intelligent use of
the verbosity hierarchy in a consistent pattern sprinkled with low-level
stacktraces as required serve best.

True.

The content of the message is obviously very important.

Arne