How to configure OpenEJB logging?

Question

How can I configure OpenEJB logging format? This is what what I see now in logs:

[...]
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.011 sec
Running com.XXX.FooTest
Apache OpenEJB 3.1.3    build: 20101015-05:42
http://openejb.apache.org/
INFO - openejb.home = /code/XXX
INFO - openejb.base = /code/XXX
INFO - Configuring Service(id=Default Security Serv...
[...]

I would like to disable INFO messages, and change formatting of others. Changes in log4j.properties have no effect.

Microclimate

Answer 1

This is what I did to make things work properly (in pom.xml):

<plugin>
  <groupId>org.apache.maven.plugins</groupId>
  <artifactId>maven-surefire-plugin</artifactId>
  <version>2.5</version>
  <configuration>
    <systemPropertyVariables>
      <openejb.logger.external>true</openejb.logger.external>
    </systemPropertyVariables>
  </configuration>
</plugin>

Works fine now. This is my test/resources/jndi.properties:

openejb.validation.output.level=VERBOSE
openejb.nobanner=false

This is test/resources/log4j.properties:

log4j.rootLogger=INFO, CONSOLE
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern = [%-5p] %c: %m\n
# OpenEJB levels
log4j.logger.OpenEJB=INFO
log4j.logger.OpenEJB.options=INFO
log4j.logger.OpenEJB.server=INFO
log4j.logger.OpenEJB.startup=INFO
log4j.logger.OpenEJB.startup.service=INFO
log4j.logger.OpenEJB.startup.config=INFO
log4j.logger.OpenEJB.hsql=INFO
log4j.logger.CORBA-Adapter=INFO
log4j.logger.Transaction=INFO
log4j.logger.org.apache.activemq=INFO
log4j.logger.org.apache.geronimo=INFO
# OpenJPA logging levels
log4j.logger.openjpa.Tool=WARN
log4j.logger.openjpa.Runtime=WARN
log4j.logger.openjpa.Remote=WARN
log4j.logger.openjpa.DataCache=WARN
log4j.logger.openjpa.MetaData=WARN
log4j.logger.openjpa.Enhance=WARN
log4j.logger.openjpa.Query=WARN
log4j.logger.openjpa.jdbc.SQL=WARN
log4j.logger.openjpa.jdbc.SQLDiag=WARN
log4j.logger.openjpa.jdbc.JDBC=WARN
log4j.logger.openjpa.jdbc.Schema=WARN

Now I can fine-tune logging of OpenEJB during testing, thanks to David's support :)

Microclimate

If you can update the answer with the log4j.properties contents, that would be fantastic. Note of caution to any future readers that using the 'openejb.logger.external' without actively replacing the log4j config will result in no logging at at all. – Felting

@David I updated the answer. Now I'm absolutely happy with OpenEJB since I can control its behavior and understand what is happening. I really doesn't know why OpenEJB official documentation doesn't have one simple straight-forward example about how to use it with Maven for unit testing. Maybe it's good to write one? – Microclimate

The "why" is pretty simple -- there's no budget :) It's a volunteer project. We get what we get. More than happy to set you up with wiki access if you want to start contributing. Just shoot a note off to the [email protected] list and we can take it from there. – Felting

Thanks for the hint to set openejb.nobanner=false. - Those banner messages were polluting the output of cuke4duke when running scenarios. – Service

Answer 2

Keep in mind that the overriding ability you get with the OpenEJB logger works with system properties as well as InitialContext properties.

The openejb.logger.external property is really aimed at servers integrating OpenEJB, such as Geronimo, who are using different logging systems and need advanced control over logging. It is not designed for common use as with this option enabled and no other steps taken, you get no logging of any kind, not even ERROR, and no info on failed deployments. Even correct usage will still disable all options discussed below.

If the desire is to get the logging configuration in or out of the test there are many ways to do it without losing any logging functionality OpenEJB provides.

Option 1: in code via InitialContext properties

In the test case itself via InitialContext properties

Properties p = new Properties();
p.put(Context.INITIAL_CONTEXT_FACTORY, "org.apache.openejb.client.LocalInitialContextFactory");

p.put("log4j.rootLogger", "fatal,C");
p.put("log4j.category.OpenEJB", "warn");
p.put("log4j.category.OpenEJB.options", "warn");
p.put("log4j.category.OpenEJB.server", "warn");
p.put("log4j.category.OpenEJB.startup", "warn");
p.put("log4j.category.OpenEJB.startup.service", "warn");
p.put("log4j.category.OpenEJB.startup.config", "warn");
p.put("log4j.category.OpenEJB.hsql", "warn");
p.put("log4j.category.CORBA-Adapter", "warn");
p.put("log4j.category.Transaction", "warn");
p.put("log4j.category.org.apache.activemq", "error");
p.put("log4j.category.org.apache.geronimo", "error");
p.put("log4j.category.openjpa", "warn");
p.put("log4j.appender.C", "org.apache.log4j.ConsoleAppender");
p.put("log4j.appender.C.layout", "org.apache.log4j.SimpleLayout");
p.put("openejb.nobanner", "false");

Context context = new InitialContext(p);

Option 2: a jndi.properties file

File must be in the classpath at any path that evaluates to "/jndi.properties", so not "/META-INF/jndi.properties"

In Maven this can be done by placing the file at src/test/resources/jndi.properties

log4j.rootLogger                   = fatal,C
log4j.category.OpenEJB             = warn
log4j.category.OpenEJB.options     = warn
log4j.category.OpenEJB.server      = warn
log4j.category.OpenEJB.startup     = warn
log4j.category.OpenEJB.startup.service = warn
log4j.category.OpenEJB.startup.config = warn
log4j.category.OpenEJB.hsql        = warn
log4j.category.CORBA-Adapter       = warn
log4j.category.Transaction         = warn
log4j.category.org.apache.activemq = error
log4j.category.org.apache.geronimo = error
log4j.category.openjpa             = warn
log4j.appender.C                   = org.apache.log4j.ConsoleAppender
log4j.appender.C.layout            = org.apache.log4j.SimpleLayout
openejb.nobanner = false

Here is a short video of the above option in action.

Note that finding and reading the jndi.properties file is a functionality of the java vm so if it doesn't work, it is more likely to be a configuration issue rather than a vm bug.

Option 3: Maven Surefire config

<plugin>
  <groupId>org.apache.maven.plugins</groupId>
  <artifactId>maven-surefire-plugin</artifactId>
  <version>2.5</version>
  <configuration>
    <systemPropertyVariables>
      <log4j.rootLogger>fatal,C</log4j.rootLogger>
      <log4j.category.OpenEJB>warn</log4j.category.OpenEJB>
      <log4j.category.OpenEJB.options>warn</log4j.category.OpenEJB.options>
      <log4j.category.OpenEJB.server>warn</log4j.category.OpenEJB.server>
      <log4j.category.OpenEJB.startup>warn</log4j.category.OpenEJB.startup>
      <log4j.category.OpenEJB.startup.service>warn</log4j.category.OpenEJB.startup.service>
      <log4j.category.OpenEJB.startup.config>warn</log4j.category.OpenEJB.startup.config>
      <log4j.category.OpenEJB.hsql>warn</log4j.category.OpenEJB.hsql>
      <log4j.category.CORBA-Adapter>warn</log4j.category.CORBA-Adapter>
      <log4j.category.Transaction>warn</log4j.category.Transaction>
      <log4j.category.org.apache.activemq>error</log4j.category.org.apache.activemq>
      <log4j.category.org.apache.geronimo>error</log4j.category.org.apache.geronimo>
      <log4j.category.openjpa>warn</log4j.category.openjpa>
      <log4j.appender.C>org.apache.log4j.ConsoleAppender</log4j.appender.C>
      <log4j.appender.C.layout>org.apache.log4j.SimpleLayout</log4j.appender.C.layout>
      <openejb.nobanner>false</openejb.nobanner>
    </systemPropertyVariables>
  </configuration>
</plugin>

Option 4: any combination

Also note that all of the above techniques can be used at once, including any overrides you wish to put in individual test cases. The order of precedence is as follows:

1. InitialContext properties
2. jndi.properties in classpath
3. system propertes (in this case, setup via surefire)
4. embedded.logging.properties in classpath

Option 5: Request a feature

As always we are very happy to make things easier in any way we can. If you have a specific need or idea, we're happy to try and work it in or help you do it should you want to contribute.

Felting

Hm... I appreciate your comments, but none of them work :( Logging configuration in jdni.properties is just ignored. And providing logging config in pom.xml is an anti-pattern, as for me. Anyway, I found a solution (see my answer), which is neat and easy. – Microclimate

@Vincenzo The only thing I can imagine that would prevent the jndi.properties approach from working is that the file is not in the classpath at the expected place. As mentioned its the jvm that reads that file in and hands us a java.util.Properties object with the InitialContext properties overlaid. So anything that works via InitialContext properties will also work via jndi.properties. I made a short video for you and updated the answer with a link in hopes that might fix the "doesn't work" :) – Felting

Answer 3

According to Configuring Logging in Tests, you can override the default logging configuration:

• by putting specific properties at InitialContext creation time ~or~
• by providing a embedded.logging.properties on the classpath

That's the recommended approach.

As an alternative, you can disable the entire default configuration and provide your own:

you can set "openejb.logger.external" to "true" as a system property (will not work as an InitialContext property). Then OpenEJB will not attempt to configure logging at all and you can configure logging with Log4j directly using any of its APIs; xml, properties, or code.

Katz

None of the approaches work :( Where exactly I can "set openejb.logger.external to true"? In what file? I'm using jndi.properties. No effect :( – Microclimate

@Vincenzo: Hmm, indeed, I can't get things to work as I expected. Maybe I misunderstood something. Will need to dig that a bit. – Katz

@Pascal You will do me a big favor, since I'm digging for the last 3 weeks. No luck :( – Microclimate

@Vincenzo This is one of those tricky situations were "doesn't work" is hard to support. There are so many ways to skin the cat, if by chance you are trying them all at once, then nothing will work. Can you try the InitialContext override approach (not via jndi.properties file) and update the question to show your setup and log output? – Felting

@David InitialContext-override approach works fine, except one thing. OpenEJB destroys previous configuration of log4j, overriding it with its own configuration. I understand that I should tell OpenEJB to use external logging configuration, but how can I do it from Maven? – Microclimate

@Vincenzo Keep in mind that the overriding ability you get with the OpenEJB logger works with system properties as well as InitialContext properties. If the desire is to get the logging configuration out of the test there are many ways to do it. If you update your question to show your InitialContext based overriding code, I can post a reply with an equivalent maven approach. – Felting

Answer 4

If you don't mind using another logging framework, these links might be useful.

http://hwellmann.blogspot.fi/2012/11/logging-with-slf4j-and-logback-in.html

JUL to SLF4J Bridge

Don't use openejb.logger.external=true with this approach. See http://grepcode.com/file/repo1.maven.org/maven2/org.apache.openejb/openejb-core/3.0/org/apache/openejb/util/JuliLogStreamFactory.java

Methodology