CODEWITHSUNDEEP
javalogginglog4jmethod-names
eagertoLearn
eagertoLearn

Reputation: 10142

method name not printing correctly in log4j logger in Java

My log happens in getParam() method. but it is logged as main method. And I have three objects, but I do not see any information as to which object is logging. I want that information too.

Here is the output:

INFO  [main]: info
INFO  [main]: debug
INFO  [main]: trace

here is the code:

import org.apache.log4j.Level;
import org.apache.log4j.Logger;

class Log4jTest {

    private static Logger log=Logger.getLogger(Log4jTest.class);
    private String param;

    public Log4jTest(String param){
        this.param=param;
    }

    public String getParam(){
        log.info(param);
        return param;
    }

}

public class Log4j_testing {
    public static void main(String[] args) throws FileNotFoundException{
        Log4jTest l1= new Log4jTest("info");
        l1.getParam();
        Log4jTest l2= new Log4jTest("debug");
        l2.getParam();
        Log4jTest l3= new Log4jTest("trace");
        l3.getParam();
    }
}

my log4j.properties:

log4j.rootLogger=INFO, stdout

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
#log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n
log4j.appender.stdout.layout.ConversionPattern=%-5p [%t]: %m%n

On a different note: if I have the above commented line uncommented and the last line commented out, I get 

11:19:41,586  INFO Log4jTest:19 - info
11:19:41,589  INFO Log4jTest:19 - debug
11:19:41,589  INFO Log4jTest:19 - trace

It gives the correct line number(19) that is being logged, but not the correct method.

Upvotes: 2

Views: 19091

Answers (3)

lmiguelmh
lmiguelmh

Reputation: 3202

There are some cases when some patterns are ignored or never logged (%C, %F, %l, %L, %M). This is true when using asynchronous loggers and asynchronous appenders. Here is what the user guide for Log4j 2.x has to said about this (see page 217-218):

If one of the layouts is configured with a location-related attribute like HTML locationInfo, or one of the patterns %C or %class, %F or %file, %l or %location, %L or %line, %M or %method, Log4j will take a snapshot of the stack, and walk the stack trace to find the location information.

This is an expensive operation: 1.3 - 5 times slower for synchronous loggers. Synchronous loggers wait as long as possible before they take this stack snapshot. If no location is required, the snapshot will never be taken.

However, asynchronous loggers need to make this decision before passing the log message to another thread; the location information will be lost after that point. The performance impact of taking a stack trace snapshot is even higher for asynchronous loggers: logging with location is 30-100 times slower than without location. For this reason, asynchronous loggers and asynchronous appenders do not include location information by default.

You can override the default behaviour in your logger or asynchronous appender configuration by specifying includeLocation="true".

Upvotes: 6

ubiquibacon
ubiquibacon

Reputation: 10667

The doc for PatteryLayout tells us that %M will provide the method name where the logging request was made, but I have not ever been able to get it to work and ended up putting the method name in the log message.

Upvotes: 0

Peter Keller
Peter Keller

Reputation: 7636

Add %M to your pattern. However, as it is stated in the JavaDoc: "Generating caller location information is extremely slow and should be avoided unless execution speed is not an issue. "

Upvotes: 12

Related Questions