views:

484

answers:

7

For some reason my Eclipse console no longer displays Log4j INFO and DEBUG statements when I run JUnit tests. In terms of code there hasn't been any change, so it must something to do with the Eclipse configuration.

All I do in my Unit test is the following and for some reason ONLY the ERROR statement is displayed in the Eclipse console. Why? Where shall I look for clues?

public class SampleTest
{
   private static final Logger LOGGER = Logger.getLogger(SampleTest.class);

   @Before
   public void init() throws Exception
   {
       // Log4J junit configuration.
       BasicConfigurator.configure();

       LOGGER.info("INFO TEST");
       LOGGER.debug("DEBUG TEST");
       LOGGER.error("ERROR TEST");
   }
}

Details:

  • log4j-1.2.6.jar
  • junit-4.6.jar Eclipse
  • IDE for Java Developers, Version: Helios Release, Build id: 20100617-1415
+3  A: 

Look in the log4j.properties or log4j.xml file for the log level. It's probably set to ERROR instead of DEBUG

Aaron Digulla
Thanks for the reply Aaron. I have checked the log4.properties and it was set on INFO. I have now changed it to DEBUG, but it doesn't make any difference. Any other idea?log4j.rootLogger=DEBUG, stdoutlog4j.appender.stdout=org.apache.log4j.ConsoleAppenderlog4j.appender.stdout.layout=org.apache.log4j.PatternLayoutlog4j.appender.stdout.layout.ConversionPattern=%t:%d{ddMMMyy HH:mm:ss.SSS} %-5p (%F:%L) %m%n
javaExpert
add `-Dlog4j.debug` to your VM environment startup properties to have log4j print out it's debugging info - perhaps a different log4j configuration file is being picked up on the classpath (such as one bundled inside a JAR) than the one you intend
matt b
@javaExpert: In that case, it find a different log4j.properties somewhere on the classpath. Look into your JARs, too!
Aaron Digulla
+3  A: 

One thing to note, if you have a log4j.properties file on your classpath you do not need to call BasicConfigurator. A description of how to configure the properties file is here.

You could pinpoint whether your IDE is causing the issue by trying to run this class from the command line with log4j.jar and log4j.properties on your classpath.

Jon Freedman
A: 

Configuring with BasicConfigurator.configure(); sets up a basic console appender set at debug. A project with the setup above and no other code (except for a test) should produce three lines of logging in the console. I cannot say anything else than "it works for me".

Have you tried creating an empty project with just log4j and junit, with only the code above and ran it?

Also, in order to get the @Beforemethod running:

@Test
public void testname() throws Exception {
    assertTrue(true);
}

EDIT:

If you run more than one test at one time, each of them will call init before running.

In this case, if you had two tests, the first would have one logger and the second test would call init again, making it log twice (try it) - you should get 9 lines of logging in console with two tests.

You might want to use a static init method annotated with @BeforeClass to avoid this. Though this also happens across files, you might want to have a look at documentation on TestSuites in JUnit 4. And/or call BasicConfigurator.resetConfiguration(); in an @AfterClass annotated class, to remove all loggers after each test class / test suite.

Also, the root logger is reused, so that if you set the root logger's level in a test method that runs early, it will keep this setting for all other tests that are run later, even if they are in different files. (will not happen when resetting configuration).

Testcase - this will cause 9 lines of logging:

import static org.junit.Assert.assertTrue;

import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.Logger;
import org.junit.Before;
import org.junit.Test;

public class SampleTest
{
   private static final Logger LOGGER = Logger.getLogger(SampleTest.class);

   @Before
   public void init() throws Exception
   {
       // Log4J junit configuration.
       BasicConfigurator.configure();
   }

   @Test
    public void testOne() throws Exception {
       LOGGER.info("INFO TEST");
       LOGGER.debug("DEBUG TEST");
       LOGGER.error("ERROR TEST");

       assertTrue(true);
    }

   @Test
   public void testTwo() throws Exception {
       LOGGER.info("INFO TEST");
       LOGGER.debug("DEBUG TEST");
       LOGGER.error("ERROR TEST");

       assertTrue(true);
   }
}

Changing the init method reduces to the excepted six lines:

@BeforeClass
public static void init() throws Exception
{
    // Log4J junit configuration.
    BasicConfigurator.configure();
}

Your problem is probably caused in some other test class or test suite where the logging level of the root logger is set to ERROR, and not reset.

You could also test this out by resetting in the @BeforeClass method, before setting logging up.

Be advised that these changes might break expected logging for other test cases until it is fixed at all places. I suggest trying out how this works in a separate workspace/project to get a feel for how it works.

Tormod
I've tried to create an empty project with only log4j, junit and the code above and it works perfectly i.e. prints all 3 statements.Is there some Eclipse project level setting that overrides the BasicConfigurator?
javaExpert
No, I'm pretty sure Eclipse does it's best not to affect the project directly in any way; suggested source of problem in edited answer.It is normal to keep a different `log4j.properties` file for tests in the test source folder, in order to let the classes under test log differently than the application.
Tormod
A: 

Check that your log4j.properties or log4j.xml are copied to your IDE classpath and loads when calling BasicConfigurator.configure()

Bivas
Putting an empty log4j.properties in the test folder worked for me.
javaExpert
A: 

Sounds like log4j picks up another configuration file than the one you think it does.

Put a breakpoint in log4j where the file is opened and have a look at the files getAbsolutePath().

Thorbjørn Ravn Andersen
A: 

Check for log4j configuration files in your output (i.e. bin or target/classes) directory or within generated project artifacts (.jar/.war/.ear). If this is on your classpath it gets picked up by log4j.

Adriaan Koster
+1  A: 

Go to Run configurations in your eclipse then -VM arguments add this: -Dlog4j.configuration=log4j-config_folder/log4j.xml

replace log4j-config_folder with your folder structure where you have your log4j.xml file

Huzi--- Javiator
Thanks for the suggestion. This way it worked!Although I'm still a bit annoyed for two reasons:1) I thought if I used the BasicConfigurator.configure() I didn't have to bother having the log4j.properties2) When I run a simple JUnit test I just want to right clik and "run", not having to define a configurationI've tried again my original test, but adding the following line to see if it was using some variable defined somewhere in Eclipse:System.out.println(System.getProperty("log4j.configuration"));But it prints out "null"
javaExpert
hmmm.. interesting.. k ll get back to yu
Huzi--- Javiator