patternjavaMinor
Overloading various logging methods
Viewed 0 times
methodsloggingvariousoverloading
Problem
I got really tired of having this code in all of my classes and methods:
... so I created the following utility class which would allow me to just call
This was the first iteration. I put it here so you could understand the general concept. Before you mention that the
Now I wanted to add on to this basic framework and make it more powerful/dynamic by overloading the method and allowing the user to pass in a
Normally, I would chain the methods like the following:
```
private static final Level DEFAULT_LOGGING_LEVEL = Level.DEBUG;
public static void logMethodEntrance() {
logMethodEntrance(DEFAULT_LOGGING_LEVEL);
}
public static void logMethodEntrance(Priority level) {
if(LOGGER.isEnabledFor(level)) {
LOGGER.log(level, "Entering " + ge
public class SomeClass {
private static final Logger LOGGER = Logger.getLogger(SomeClass.class);
//...
public int someMethod() {
final String methodName = "someMethod()";
LOGGER.debug("Entering " + methodName);
int returnValue = 0;
//...
LOGGER.debug("Exiting " + methodName + +", returning " + returnValue);
return returnValue;
}
}... so I created the following utility class which would allow me to just call
LoggingUtil.logMethodEntrance():public class LoggingUtil {
private static final Logger LOGGER = Logger.getLogger(LoggingUtil.class);
private static final int GET_CALLING_METHOD_NAME_DEPTH = 3;
public static void logMethodEntrance() {
if(LOGGER.isDebugEnabled()) {
LOGGER.debug("Entering " + getCallingMethodName());
}
}
private static String getCallingMethodName() {
return Thread.currentThread().getStackTrace()[GET_CALLING_METHOD_NAME_DEPTH].getMethodName() + "()";
}
}This was the first iteration. I put it here so you could understand the general concept. Before you mention that the
isDebugEnabled() call isn't necessary to prevent the logging, the reason it's there is because the getStackTrace() method has notoriously poor performance and I don't want it called unless it's actually going to be used.Now I wanted to add on to this basic framework and make it more powerful/dynamic by overloading the method and allowing the user to pass in a
Priority if they don't want it to be DEBUG.Normally, I would chain the methods like the following:
```
private static final Level DEFAULT_LOGGING_LEVEL = Level.DEBUG;
public static void logMethodEntrance() {
logMethodEntrance(DEFAULT_LOGGING_LEVEL);
}
public static void logMethodEntrance(Priority level) {
if(LOGGER.isEnabledFor(level)) {
LOGGER.log(level, "Entering " + ge
Solution
I have been through this loop (quite recently, actually), for a rather large project in a very commercial environment.
Frankly, it's not sustainable.
Let me run through some of the issues:
To put things in perspective, on a 64-core computer (128 hardware threads), a program that was able to run at 80% CPU (i.e. 100 hardward-threads running at 100%) was reduced to about 3% CPU when about 1000 traces were taken each second.
This sort of performance is highly dependant on the JVM version, and the vendor. Stack traces are considered to be part of exception handling, and building the trace is not supposed to be fast.
Questions about Trace versions (FYI, this may, or may not help you):
Frankly, it's not sustainable.
Let me run through some of the issues:
- getStackTrace() is not just slow, it is molasses, and it affects all threads on the JVM, not just the current one.
- Different versions of Java (same vendor, different versions, or different vendors, etc.) will need to have a different value for GET_CALLING_METHOD_NAME_DEPTH
- did I mention that getStackTrace was slow?
- You will be logging the method name, but the class used for the Log output will be
LoggingUtil, not the class the method was called on.
- did I mention that getStackTrace was slow?
- the performance of getStackTrace is proportional to the depth of the stack. Testing with shallow stacks is pointless if someone then uses your code in a GUI, or Tomcat, or whatever... which have traces a mile long.... god forbid you do recursion!!!
To put things in perspective, on a 64-core computer (128 hardware threads), a program that was able to run at 80% CPU (i.e. 100 hardward-threads running at 100%) was reduced to about 3% CPU when about 1000 traces were taken each second.
This sort of performance is highly dependant on the JVM version, and the vendor. Stack traces are considered to be part of exception handling, and building the trace is not supposed to be fast.
Questions about Trace versions (FYI, this may, or may not help you):
echo && cat STrace.java && java -version && java STrace
public class STrace {
public static void main(String[] args) {
for (StackTraceElement ste : Thread.currentThread().getStackTrace()) {
System.out.println(ste);
}
}
}
java version "1.7.0"
Java(TM) SE Runtime Environment (build pxp6470_27-20131115_04)
IBM J9 VM (build 2.7, JRE 1.7.0 Linux ppc64-64 Compressed References 20131114_175264 (JIT enabled, AOT enabled)
J9VM - R27_Java727_GA_20131114_0833_B175264
JIT - tr.r13.java_20131113_50523
GC - R27_Java727_GA_20131114_0833_B175264_CMPRSS
J9CL - 20131114_175264)
JCL - 20131113_01 based on Oracle 7u45-b18
java.lang.Thread.getStackTraceImpl(Native Method)
java.lang.Thread.getStackTrace(Thread.java:1203)
STrace.main(STrace.java:3)Code Snippets
echo && cat STrace.java && java -version && java STrace
public class STrace {
public static void main(String[] args) {
for (StackTraceElement ste : Thread.currentThread().getStackTrace()) {
System.out.println(ste);
}
}
}
java version "1.7.0"
Java(TM) SE Runtime Environment (build pxp6470_27-20131115_04)
IBM J9 VM (build 2.7, JRE 1.7.0 Linux ppc64-64 Compressed References 20131114_175264 (JIT enabled, AOT enabled)
J9VM - R27_Java727_GA_20131114_0833_B175264
JIT - tr.r13.java_20131113_50523
GC - R27_Java727_GA_20131114_0833_B175264_CMPRSS
J9CL - 20131114_175264)
JCL - 20131113_01 based on Oracle 7u45-b18
java.lang.Thread.getStackTraceImpl(Native Method)
java.lang.Thread.getStackTrace(Thread.java:1203)
STrace.main(STrace.java:3)Context
StackExchange Code Review Q#43106, answer score: 6
Revisions (0)
No revisions yet.