[LOG4J2-1320] Custom plugins are not loaded, URL protocol vfs is not supported

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.5, 2.6.2
• Fix Version/s: 2.7
• Assignee: Gary D. Gregory
• Reporter: Paresh Varke
• Created: 17/Mar/16 10:41
• Updated: 14/Sep/16 15:26
• Resolved: 13/Sep/16 19:26

Description

The URL protocol "vfs" from using a class loader is not supported; for example within JBoss EAP 6.2 and Log4j2 version 2.5. The custom plugin packages attribute fails to be resolve and plugin are not loaded for following URLs:

vfs:/C:/jboss/jboss-eap-6.4/standalone/deployments/com.xxx.yyy.application-ear.ear/lib/com.xxx.yyy.logging.jar/com/xxx/yyy/logging/config/
vfs:/C:/jboss/jboss-eap-6.4/standalone/deployments/test-log4j2-web-standalone.war/WEB-INF/classes/org/hypik/test/jboss/eap7/logging/config/
vfs:/content/mycustomweb.war/WEB-INF/classes/org/hypik/test/jboss/log4j2/logging/pluginweb/
vfs:/content/test-log4k2-ear.ear/lib/test-log4j2-jar-plugins.jar/org/hypik/test/jboss/log4j2/pluginjar/
vfs:/content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2/

Example of configuration:

<Configuration status="INFO" name="MyConf" packages="com.logging.appender.log4j2">

It results following errors from StatusLogger:

Could not search jar file '/content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2' for classes matching criteria: annotated with @Plugin file not found java.io.FileNotFoundException: /content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2 (No such file or directory).

And related logs:

2016-03-10 07:08:41,909 INFO  [stdout] (ServerService Thread Pool -- 275) INFO Scanning for classes in [/content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2/] matching criteria: annotated with @Plugin
2016-03-10 07:08:41,910 INFO  [stdout] (ServerService Thread Pool -- 275) 2016-03-10 07:08:41,909 ServerService Thread Pool -- 275 ERROR Could not search jar file '/content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2' for classes matching criteria: annotated with @Plugin file not found java.io.FileNotFoundException: /content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2 (No such file or directory)
2016-03-10 07:08:41,910 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.io.FileInputStream.open(Native Method)
2016-03-10 07:08:41,910 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.io.FileInputStream.<init>(FileInputStream.java:146)
2016-03-10 07:08:41,910 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.plugins.util.ResolverUtil.loadImplementationsInJar(ResolverUtil.java:310)
2016-03-10 07:08:41,910 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.plugins.util.ResolverUtil.findInPackage(ResolverUtil.java:206)
2016-03-10 07:08:41,910 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.plugins.util.PluginRegistry.loadFromPackage(PluginRegistry.java:222)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.plugins.util.PluginManager.collectPlugins(PluginManager.java:152)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:180)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:209)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:492)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:246)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:232)
2016-03-10 07:08:41,911 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.core.config.Configurator.initialize(Configurator.java:140)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.web.Log4jWebInitializerImpl.initializeNonJndi(Log4jWebInitializerImpl.java:168)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.web.Log4jWebInitializerImpl.start(Log4jWebInitializerImpl.java:110)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.logging.log4j.web.Log4jServletContainerInitializer.onStartup(Log4jServletContainerInitializer.java:57)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.jboss.as.web.deployment.JBossContextConfig.lifecycleEvent(JBossContextConfig.java:181)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:115)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.apache.catalina.core.StandardContext.start(StandardContext.java:3772)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.jboss.as.web.deployment.WebDeploymentService.doStart(WebDeploymentService.java:156)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.jboss.as.web.deployment.WebDeploymentService.access$000(WebDeploymentService.java:60)
2016-03-10 07:08:41,915 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.jboss.as.web.deployment.WebDeploymentService$1.run(WebDeploymentService.java:93)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 	at java.lang.Thread.run(Thread.java:744)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 	at org.jboss.threads.JBossThread.run(JBossThread.java:122)
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 
2016-03-10 07:08:41,916 INFO  [stdout] (ServerService Thread Pool -- 275) 2016-03-10 07:08:41,916 ServerService Thread Pool -- 275 DEBUG Took 0.011828 seconds to load 0 plugins from package com.logging.appender.log4j2

By debugging I found in the method findInPackage in class ResolverUtil, class loader prepares enum of url (urls = loader.getResources(packageName)).
And gives:

/content/myapp.ear/service-app.war/WEB-INF/classes/com/logging/appender/log4j2

as the value of urlPath (which is non existing path).