問題與分析
在使用Log4j2時，雖然可以正確讀取配置文件並生成log文件，但偶然發現控制台打印了異常信息如下：
2018-12-31 17:28:14,282 Log4j2-TF-19-ConfiguratonFileWatcher-6 ERROR Unable to invoke factory method in class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile: java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.appender.RollingFileAppender java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.appender.RollingFileAppender
at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.findFactoryMethod(PluginBuilder.java:235)
at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:135)
at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:959)
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:899)
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:891)
at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:514)
at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:238)
at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:250)
at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:547)
at org.apache.logging.log4j.core.LoggerContext.onChange(LoggerContext.java:670)
at org.apache.logging.log4j.core.config.ConfiguratonFileWatcher$ReconfigurationRunnable.run(ConfiguratonFileWatcher.java:68)
at java.lang.Thread.run(Thread.java:748)
將控制台的所有信息都復制出來，仔細查找，又發現了相關的異常信息：
2018-12-31 17:28:14,241 Log4j2-TF-19-ConfiguratonFileWatcher-6 ERROR Unable to create file logs/${ctx:domainId}/CNTCore.log java.io.IOException: The filename, directory name, or volume label syntax is incorrect
at java.io.WinNTFileSystem.canonicalize0(Native Method)
at java.io.WinNTFileSystem.canonicalize(WinNTFileSystem.java:428)
at java.io.File.getCanonicalPath(File.java:618)
at ....
2018-12-31 17:28:14,280 Log4j2-TF-19-ConfiguratonFileWatcher-6 ERROR Could not create plugin of type class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile: java.lang.IllegalStateException: ManagerFactory [...] unable to create manager for [logs/${ctx:domainId}/CNTCore.log] with data [...] java.lang.IllegalStateException: ManagerFactory [...] unable to create manager for [logs/${ctx:domainId}/CNTCore.log] with data [...]
at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:115)
at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:114)
at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.getFileManager(RollingFileManager.java:188)
at ....
看起來是因為配置文件里的RollingFile使用到了${ctx:domainId}導致了這個問題。百度了下，發現了log4j2的jira issue：Unable to invoke factory method in class class org.apache.logging.log4j.core.appender.RollingFileAppender for element RollingFile
該問題和我遇到的一樣，而在jira里有comment如下：
Question: Does system property logfile have a value?
結合項目的配置文件log4j2.xml:
<RollingFile name="logfile" immediateFlush="true" fileName="logs/${ctx:domainId}/CNTCore.log"
filePattern="logs/${ctx:domainId}/CNTCore.log.%d{yyyy-MM-dd-a}.gz" append="true">
<PatternLayout>
<pattern>%d %t %p %X{TracingMsg} %c - %m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy modulate="true" interval="1" />
</Policies>
</RollingFile>
可以看出，這個異常是由於RollingFile使用到了${ctx:domainId}，而該變量值是null，導致無法創建對應的RollingFile文件到磁盤。但是這個domainId是通過ThreadContext把值put進去的，不可能是null，從最終的效果來看，這個變量其實也是拿到了值的，因為對應的日志文件以及存在於磁盤上了。
既然如此，為什么還會出現這個異常呢？通過觀察控制台可以發現，每過一段時間就會出現一次該異常。從異常中可以看到ConfiguratonFileWatcher，好像有些明白為什么了。
ConfiguratonFileWatcher是用來掃描配置文件是否被改動過的，在配置文件中設置的掃描間隔是30s：
<configuration monitorInterval="30">
....
</configuration>
由於掃描文件時另外起一個線程去掃描的，而${ctx:domainId}的值是存放於ThreadContext中的，ThreadContext是線程安全的，同一個key對應的value在不同線程中是不一定相同的。而對於新啟動的線程來說，並沒有將domainId的值存放進去，於是新線程在掃描配置文件的RollingFile時，自然是無法獲取到${ctx:domainId}的值，故而每隔一段時間就會報上邊的異常。
解決方法
方案一
既然問題是因為掃描配置文件是否改動造成的，那么只要將動態加載的功能關閉就行了，如下：
<configuration monitorInterval="0">
....
</configuration>
方案二
如果希望不關閉動態加載配置文件的功能，可以將domainId的值存放到System.properties里：
System.setProperty("domainId", "xxx");
然后通過${sys:xxx}的方式來獲取該properties的值：
<RollingFile name="logfile" immediateFlush="true" fileName="logs/${sys:domainId}/CNTCore.log"
filePattern="logs/${sys:domainId}/CNTCore.log.%d{yyyy-MM-dd-a}.gz" append="true">
<PatternLayout>
<pattern>%d %t %p %X{TracingMsg} %c - %m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy modulate="true" interval="1" />
</Policies>
</RollingFile>
在log4j2中關於這些變量取值有以下這些種類：
| Prefix | Context |
|---|---|
| bundle | Resource bundle. The format is ${bundle:BundleName:BundleKey}. The bundle name follows package naming conventions, for example: ${bundle:com.domain.Messages:MyKey}. |
| ctx | Thread Context Map (MDC) |
| date | Inserts the current date and/or time using the specified format |
| env | System environment variables. The formats are ${env:ENV_NAME} and ${env:ENV_NAME:-default_value}. |
| jndi | A value set in the default JNDI Context. |
| jvmrunargs | A JVM input argument accessed through JMX, but not a main argument; see RuntimeMXBean.getInputArguments(). Not available on Android. |
| log4j | Log4j configuration properties. The expressions ${log4j:configLocation} and ${log4j:configParentLocation} respectively provide the absolute path to the log4j configuration file and its parent folder. |
| main | A value set with MapLookup.setMainArguments(String[]) |
| map | A value from a MapMessage |
| sd | A value from a StructuredDataMessage. The key "id" will return the name of the StructuredDataId without the enterprise number. The key "type" will return the message type. Other keys will retrieve individual elements from the Map. |
| sys | System properties. The formats are ${sys:some.property} and ${sys:some.property:-default_value}. |