Weld Tip 1 - Logging

2016-10-1   tips   Martin Kouba

This is the first article from a series of short articles covering some useful Weld features. In this article we talk about logging. The topics for the next articles include: DEVELOPMENT MODE, PERFORMANCE, NON-EE ENVIRONMENTS and TESTING.

Motivation

Logging is usually no fancy stuff. But very often it’s the best thing to start with if problems arise. Moreover, it’s the easiest form of debugging.

In this article you will find:

Under the hood

Weld is using JBoss Logging. This is an abstraction layer wchich does not "write" any log messages at all. Instead, it effectively constructs a log message and then delegates to a back-end logging framework. The supported frameworks include jboss-logmanager, Log4j, SLF4J and JDK logging.

So which logging framework is actually used to write the Weld messages? Well, it depends on the environment. In a Java EE container (e.g. WildFly) the logging configuration is under the direction of the container. You should follow the container-specific guides to change the configuration (see for example WildFly - Logging Configuration and How do I enable debug logging for Weld in a specific container?).

A web application deployed to a servlet container usually bundles a logging framework and possibly some configuration file. In this case, the configuration is in hands of the application developer. If no logging framework is bundled follow the container-specific guides to change the configuration (e.g. Logging in Tomcat).

Tip
 A system property org.jboss.logging.provider can be used to specify the logging framework directly. If not set, the JBoss Logging will attempt to find the "best match" on the classpath. See also LoggerProviders.

In Java SE the situation is very similar to servlet containers except the class loading is usually even less complicated (see also How do I enable debug logging for Weld SE?).

Set the log level and use categories to filter messages

The default log level is usually INFO. Weld does not log that much information with this level. You will have to set the log level to DEBUG (or even TRACE) to see what’s going on in your application. If you set the level globally (for all frameworks and libraries), the log files will be bloated and it will be very hard to get some relevant info from there. If you set the level for Weld only (i.e. for org.jboss.weld), it should be better. Moreover, it’s possible to use categories to filter messages from a particular "domain". Weld log messages are grouped into several categories:

  • org.jboss.weld.Bootstrap

  • org.jboss.weld.Validator

  • org.jboss.weld.Bean

  • org.jboss.weld.Context

  • org.jboss.weld.El

  • and others (see also org.jboss.weld.logging.Category)

So for example, if you’re only interested in log messages related to EL resolution set the log level for the org.jboss.weld.El category to TRACE (or level with corresponding priority). Another useful example is the check of Weld configuration. Simply set the log level to DEBUG and filter the org.jboss.weld.Configuration category:

DEBUG [Configuration] WELD-001907: Reading properties file: test.war/WEB-INF/classes/weld.properties
DEBUG [Configuration] WELD-001903: Configuration key RESOLUTION_CACHE_SIZE already set to 1 000 in a source with higher priority, value 500 from system properties is ignored
DEBUG [Configuration] WELD-001904: Unsupported configuration key found and ignored: com.foo.bar
DEBUG [Configuration] WELD-001902: Configuration initialized: {CONCURRENT_DEPLOYMENT=false, RESOLUTION_CACHE_SIZE=1000, RELAXED_CONSTRUCTION=true}

Monitoring bootstrap

CDI is designed to fail fast. An extensive validation is performed during application initialization in order to avoid malicious errors at runtime. Container usually also logs a lot of interesting info during bootstrap. Let’s try to set the log level to DEBUG for the org.jboss.weld.Bootstrap category and see what we get.

Registered beans

As simple as it looks - Weld logs all the beans found in the application, e.g.:

DEBUG [Bootstrap] WELD-000106: Bean: Managed Bean [class org.jboss.cdi.tck.tests.lookup.dependency.resolution.broken.unsatisfied.Vanilla] with qualifiers [@Any @Default]
DEBUG [Bootstrap] WELD-000106: Bean: Producer Method [String[]] with qualifiers [@BatchProperty @Any] declared as [[UnbackedAnnotatedMethod] @Produces @BatchProperty public org.jberet.creation.BatchBeanProducer.getStringArray(InjectionPoint)]

Actions performed by extensions

There is no doubt that portable extensions are really powerful. They can change almost anything. That’s great for framework/libraries developers. On the other hand, this may cause problems when looking for a bug. There is an application class provided by a developer but what does the CDI container actually see? Well, it depends…​ because portable extensions are allowed to redefine this. And that’s why Weld logs all the "modification" operations performed by extensions, such as ProcessAnnotatedType.veto():

DEBUG [Bootstrap] WELD-000148: ProcessAnnotatedType.veto() called by com.foo.MyExtension@50fed5b1 for [BackedAnnotatedType] public class com.foo.Foo
Tip
 If your application deploys successfully, you can use Development Tools to inspect the runtime info (will be covered in one of the follow-up articles).