log4j2wildfly-10jboss-wildfly-11wildfly-11

Log4J2 in Wildfly 11- causing ERROR Unable to locate plugin


Wrote a simple web app that uses programmatic configuration of Log4J2 . ( no log4j2.xml )

The configurator snippet looks like below

ConfigurationBuilder<BuiltConfiguration> builder = ConfigurationBuilderFactory.newConfigurationBuilder();
builder.setStatusLevel(Level.ERROR);
builder.setConfigurationName("LogicLoggerConfigurations");
builder.setPackages("main.logging.config");

AppenderComponentBuilder appenderBuilderConsole = builder.newAppender("Stdout", "CONSOLE").addAttribute("target",
        ConsoleAppender.Target.SYSTEM_OUT);
AppenderComponentBuilder appenderBuilderFile = builder.newAppender("toFile", "FILE").addAttribute("fileName",
        "/pathto/logtest.log");
appenderBuilderConsole.add(builder.newLayout("PatternLayout")
        .addAttribute("pattern", "%d [%t] %-5level: %msg%n%throwable"));
appenderBuilderFile.add(builder.newLayout("PatternLayout")
        .addAttribute("pattern", "%d [%t] %-5level: %msg%n%throwable"));
AppenderComponentBuilder appenderBuilder = builder.newAppender("lacmem", "LogicMemoryAppender");
appenderBuilder.add(builder.newLayout("PatternLayout")
        .addAttribute("pattern", "%d [%t] %-5level: %msg%n%throwable"));
builder.add(appenderBuilder);
builder.add(appenderBuilderConsole);
builder.add(appenderBuilderFile);
builder.add(builder.newLogger("main", Level.TRACE)
        .add(builder.newAppenderRef("lacmem")).addAttribute("additivity", true));
builder.add(builder.newRootLogger(Level.ERROR).add(builder.newAppenderRef("Stdout"))
        .add(builder.newAppenderRef("toFile")));
logicLoggerContext = Configurator.initialize(builder.build());
logicLoggerContext.updateLoggers();

There is a custom appender (plugin) under packages main.logging.config that looks like below

@Plugin(name = "LogicMemoryAppender", category = "Core", elementType = "appender", printObject = true)
public class LogicMemoryAppender extends AbstractAppender {

    List<Map<String, Object>> logs = new CopyOnWriteArrayList<>();

    protected LogicMemoryAppender(String name, Filter filter, Layout<? extends Serializable> layout, boolean ignoreExceptions) {
        super(name, filter, layout, ignoreExceptions);
    }

    /*
     *
     * @see
     * org.apache.logging.log4j.core.Appender#append(org.apache.logging.log4j.
     * core.LogEvent)
     */
    public void append(LogEvent event) {
        Map<String, Object> logEntry = new HashMap<String, Object>();
        logEntry.put("logger", event.getLoggerName());
        if (null != event.getLevel())
            logEntry.put("level", event.getLevel());

        long millis = event.getTimeMillis();
        logEntry.put("ts", millis);
        logEntry.put("timestamp", "timestamp");

        String exceptionText = "";
        if (null != event.getThrown()) {
            exceptionText = event.getThrown().getMessage();
        }

        String msg = event.getMessage().toString();
        if (!msg.isEmpty()) {
            msg = msg.replace("\"", "\\\"");
            msg = msg.replace("\n", "\\n");
            if (!exceptionText.isEmpty()) {
                logEntry.put("message", msg + " : " + exceptionText);
            } else {
                logEntry.put("message", msg);
            }
        } else {
            logEntry.put("message", exceptionText);
        }
System.out.println("Log entry added "+logEntry);
        logs.add(logEntry);

    }


    /**
     * Factory method called by Log4j2 to initialize this appender.
     * @param name
     * @param layout
     * @param filter
     * @return
     */
    @PluginFactory
    public static LogicMemoryAppender createAppender(
            @PluginAttribute("name") String name,
            @PluginElement("Layout") Layout<? extends Serializable> layout,
            @PluginElement("Filter") final Filter filter) {
        if (name == null) {
            LOGGER.error("No name provided for LogicMemoryAppender");
            return null;
        }
        if (layout == null) {
            layout = PatternLayout.createDefaultLayout();
        }
        return new LogicMemoryAppender(name, filter, layout, true);
    }

}

The application is a servlet based app that has a single logging statement under doGet()

soloLogger = LogManager.getLogger();
soloLogger.trace("What is up");

I also disable the logging subsystem by adding the below config to Web-Inf

<jboss-deployment-structure xmlns="urn:jboss:deployment-structure:1.2">
    <deployment>
        <exclude-subsystems>
            <subsystem name="logging"/>
        </exclude-subsystems>
    </deployment>
</jboss-deployment-structure>

The application is deployed as a WAR file and uploaded to WildFly via the admin console.

Once i visit the URL, I see the below error in Wildfly console. The code works as expected for Tomcat8x and Weblogic 12.2.1.3 but not Jboss. :(

5:12:45,204 INFO  [stdout] (default task-1) 2017-10-30 15:12:45,203 default task-1 ERROR Unable to locate plugin type for LogicMemoryAppender
15:12:45,237 INFO  [stdout] (default task-1) 2017-10-30 15:12:45,237 default task-1 ERROR Unable to locate plugin for LogicMemoryAppender
15:12:45,247 INFO  [stdout] (default task-1) 2017-10-30 15:12:45,246 default task-1 ERROR Unable to invoke factory method in class org.apache.logging.log4j.core.config.AppendersPlugin for element Appenders: java.lang.NullPointerException java.lang.NullPointerException
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.plugins.visitors.PluginElementVisitor.visit(PluginElementVisitor.java:52)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.generateParameters(PluginBuilder.java:248)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:135)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:958)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:898)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:513)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:237)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:204)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:161)
15:12:45,247 INFO  [stdout] (default task-1)    at org.apache.logging.log4j.core.config.builder.impl.DefaultConfigurationBuilder.build(DefaultConfigurationBuilder.java:57)
15:12:45,247 INFO  [stdout] (default task-1)    at main.test.HanSolo.initConfig(HanSolo.java:63)
15:12:45,248 INFO  [stdout] (default task-1)    at main.test.HanSolo.<clinit>(HanSolo.java:23)
15:12:45,248 INFO  [stdout] (default task-1)    at main.test.TestLogging.doGet(TestLogging.java:31)
15:12:45,248 INFO  [stdout] (default task-1)    at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
15:12:45,248 INFO  [stdout] (default task-1)    at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
15:12:45,248 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
15:12:45,248 INFO  [stdout] (default task-1)    at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
15:12:45,249 INFO  [stdout] (default task-1)    at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
15:12:45,249 INFO  [stdout] (default task-1)    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:326)
15:12:45,250 INFO  [stdout] (default task-1)    at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812)
15:12:45,250 INFO  [stdout] (default task-1)    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
15:12:45,250 INFO  [stdout] (default task-1)    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
15:12:45,250 INFO  [stdout] (default task-1)    at java.lang.Thread.run(Thread.java:745)
15:12:45,250 INFO  [stdout] (default task-1) 
15:12:45,250 INFO  [stdout] (default task-1) 2017-10-30 15:12:45,250 default task-1 ERROR Unable to locate appender "Stdout" for logger config "root"
15:12:45,250 INFO  [stdout] (default task-1) 2017-10-30 15:12:45,250 default task-1 ERROR Unable to locate appender "toFile" for logger config "root"
15:12:45,251 INFO  [stdout] (default task-1) 2017-10-30 15:12:45,251 default task-1 ERROR Unable to locate appender "lacmem" for logger config "main"

Log4j2 does not seem to recognize the annotated plugin in WildFly. Not sure if this is a problem with log4j2 or WildFly. JVM is Java 8x112

EDIT: Same error on WildFly 10 Final.


Solution

  • I could not find the solution for the problem referred above but i did find a workaround.

    Instead of doing configuration programmatically, i combined it with an XML configuration file (log4j2.xml). Inside the XML, I initialized all the loggers that i use in the code.

    Check out the official doc for more information on how to combine.

    Then for the programmatic configuration 1. Create your own ConfigurationFactory that 2. returns an instance of your own XMLConfiguration ->Create a class that extends XMLConfiguration that manipulates and adds appenders to the above loggers ( LoggerConfig).

    Once i am done changing the configuration, i called myloggercontext.updateLoggers() to load the changes. One thing to note here is that, to get your ConfigurationFactory registered, you will have to add a property file called log4j2.component.properties to the classpath. The content of my property file is as below

    log4j.configurationFactory=main.logging.config.LogConfigurationFactory
    

    This would make sure that your ConfigurationFactory gets loaded before any calls to the logger inside your app.

    The above changes worked for JBoss as it was able to load the plugins as expected.