|
||||||||
|
This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira |
||||||||
_______________________________________________ logback-dev mailing list [email protected] http://mailman.qos.ch/mailman/listinfo/logback-dev
Hi,
In the example I use a java:comp/env/APP_CONFIG_FOLDER, a variable in the web.xml configuration file.
When the app starts the configuration is loaded correctly. After I modify the included configuration file (appLogbackConfig.xml), the ReconfigureOnChangeFilter detects a change and fire the ReconfiguringThread.
This thread has no access to the webapp enviroment, for example: the variable APP_CONFIG_FOLDER that was correctly read when the app started is undefined for the ReconfiguringThread. The same with APP_LOG_FOLDER.
WebSphere logging:
[2/18/15 11:20:35:545 ART] 00000031 ApplicationMg A WSVR0221I: Application started: SimpleWeb_war
[2/18/15 11:20:35:553 ART] 00000031 CompositionUn A WSVR0191I: Composition unit WebSphere:cuname=SimpleWeb_war in BLA WebSphere:blaname=SimpleWeb_war started.
----- FIRST SERVLET REQUEST -----
[2/18/15 11:21:21:472 ART] 000002a2 SystemOut O 11:21:21,450 |-INFO in ReconfigureOnChangeFilter
{invocationCounter=0} - Will scan for changes in [[/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/installedApps/DWS06CT0001Cell01/SimpleWeb_war.ear/SimpleWeb.war/WEB-INF/classes/logback.xml]] every 60 seconds.[2/18/15 11:21:21:477 ART] 000002a2 SystemOut O 11:21:21,476 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
[2/18/15 11:21:21:499 ART] 000002a2 SystemOut O 11:21:21,499 |-INFO in ch.qos.logback.classic.joran.action.ContextNameAction - Setting logger context name as [SIMPLE_WEB]
[2/18/15 11:21:21:536 ART] 000002a2 SystemOut O 11:21:21,535 |-INFO in ch.qos.logback.classic.joran.action.InsertFromJNDIAction - Setting variable [APP_CONFIG_FOLDER] to [/data/simple] in [LOCAL] scope
[2/18/15 11:21:21:543 ART] 000002a2 SystemOut O 11:21:21,543 |-INFO in ch.qos.logback.classic.joran.action.InsertFromJNDIAction - Setting variable [APP_LOG_FOLDER] to [simple] in [LOCAL] scope
[2/18/15 11:21:21:558 ART] 000002a2 SystemOut O 11:21:21,558 |-INFO in ch.qos.logback.classic.joran.action.InsertFromJNDIAction - Setting variable [COMMON_LOG_FOLDER] to [/data/logs] in [LOCAL] scope
[2/18/15 11:21:21:584 ART] 000002a2 SystemOut O 11:21:21,583 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@1ddf1ddf - Adding file:/data/simple/helper/log/appLogbackConf.xml to configuration watch list.
[2/18/15 11:21:21:605 ART] 000002a2 SystemOut O 11:21:21,602 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
[2/18/15 11:21:21:657 ART] 000002a2 SystemOut O 11:21:21,657 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
[2/18/15 11:21:21:809 ART] 000002a2 SystemOut O 11:21:21,808 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
[2/18/15 11:21:22:390 ART] 000002a2 SystemOut O #logback.classic pattern: %cyan(%d{HH:mm:ss.SSS}) [%thread] %highlight(%-5level) %logger{36} - %msg%n
[2/18/15 11:21:22:392 ART] 000002a2 SystemOut O 11:21:22,392 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
[2/18/15 11:21:22:414 ART] 000002a2 SystemOut O 11:21:22,414 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
[2/18/15 11:21:22:622 ART] 000002a2 SystemOut O 11:21:22,622 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use gz compression
[2/18/15 11:21:22:640 ART] 000002a2 SystemOut O 11:21:22,640 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern /data/logs/simple/SimpleWeb_%d{yyyyMMdd}_DWS06CT0001.log for the active file
[2/18/15 11:21:22:684 ART] 000002a2 SystemOut O 11:21:22,684 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyyMMdd' from file name pattern '/data/logs/simple/SimpleWeb_%d{yyyyMMdd}_DWS06CT0001.log.gz'.
[2/18/15 11:21:22:685 ART] 000002a2 SystemOut O 11:21:22,685 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
[2/18/15 11:21:22:688 ART] 000002a2 SystemOut O 11:21:22,687 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Wed Feb 18 11:21:22 ART 2015
[2/18/15 11:21:22:704 ART] 000002a2 SystemOut O 11:21:22,703 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
[2/18/15 11:21:22:742 ART] 000002a2 SystemOut O 11:21:22,742 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: /data/logs/simple/SimpleWeb_20150218_DWS06CT0001.log
[2/18/15 11:21:22:743 ART] 000002a2 SystemOut O 11:21:22,743 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [null]
[2/18/15 11:21:22:805 ART] 000002a2 SystemOut O 11:21:22,804 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [package] to DEBUG
[2/18/15 11:21:22:808 ART] 000002a2 SystemOut O 11:21:22,805 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [package] to false
[2/18/15 11:21:22:810 ART] 000002a2 SystemOut O 11:21:22,810 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ar.com.bna]
[2/18/15 11:21:22:817 ART] 000002a2 SystemOut O 11:21:22,817 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ar.com.bna]
[2/18/15 11:21:22:818 ART] 000002a2 SystemOut O 11:21:22,818 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to OFF
[2/18/15 11:21:22:820 ART] 000002a2 SystemOut O 11:21:22,820 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
[2/18/15 11:21:22:829 ART] 000002a2 SystemOut O 11:21:22,828 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@b0b0b0b - Registering current configuration as safe fallback point
[2/18/15 11:21:23:015 ART] 000002a2 servlet I com.ibm.ws.webcontainer.servlet.ServletWrapper init SRVE0242I: [SimpleWeb_war] [/simple] [EntryPoint]: Initialization successful.
[2/18/15 11:21:23:097 ART] 000002a2 SystemOut O 11:21:23.068 [WebContainer : 5] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo7
[2/18/15 11:21:23:279 ART] 000002a2 SystemOut O 11:21:23.272 [WebContainer : 5] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
----- CHANGED appLogbackConf.xml LOGGER LEVEL -----
[2/18/15 11:25:05:711 ART] 000002a8 SystemOut O 11:25:05.706 [WebContainer : 10] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo8
[2/18/15 11:25:05:715 ART] 000002a8 SystemOut O 11:25:05.714 [WebContainer : 10] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:22:429 ART] 000002a8 SystemOut O 11:25:22.427 [WebContainer : 10] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo9
[2/18/15 11:25:22:431 ART] 000002a8 SystemOut O 11:25:22.430 [WebContainer : 10] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:48:141 ART] 00000045 SystemOut O 11:25:48.139 [WebContainer : 1] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo10
[2/18/15 11:25:48:144 ART] 00000045 SystemOut O 11:25:48.144 [WebContainer : 1] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:53:533 ART] 000002a5 SystemOut O 11:25:53.531 [WebContainer : 8] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo10
[2/18/15 11:25:53:539 ART] 000002a5 SystemOut O 11:25:53.538 [WebContainer : 8] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:54:219 ART] 000002a5 SystemOut O 11:25:54.218 [WebContainer : 8] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo10
[2/18/15 11:25:54:221 ART] 000002a5 SystemOut O 11:25:54.220 [WebContainer : 8] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:54:821 ART] 000002a5 SystemOut O 11:25:54.820 [WebContainer : 8] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo10
[2/18/15 11:25:54:823 ART] 000002a5 SystemOut O 11:25:54.822 [WebContainer : 8] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:55:462 ART] 000002a5 SystemOut O 11:25:55.461 [WebContainer : 8] DEBUG ar.com.bna.simpleWeb.EntryPoint - algo10
[2/18/15 11:25:55:464 ART] 000002a5 SystemOut O 11:25:55,464 |-INFO in ReconfigureOnChangeFilter{invocationCounter=16} - Detected change in [[/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/installedApps/DWS06CT0001Cell01/SimpleWeb_war.ear/SimpleWeb.war/WEB-INF/classes/logback.xml, /data/simple/helper/log/appLogbackConf.xml]]
[2/18/15 11:25:55:512 ART] 000002a5 SystemOut O 11:25:55.509 [WebContainer : 8] INFO ar.com.bna.simpleWeb.EntryPoint - Var: APP_CONFIG_FOLDER --> /data/simple
[2/18/15 11:25:55:533 ART] 000003ed SystemOut O 11:25:55,531 |-INFO in ReconfigureOnChangeFilter{invocationCounter=16} - Will reset and reconfigure context named [SIMPLE_WEB]
[2/18/15 11:25:55:556 ART] 000003ed SystemOut O 11:25:55,464 |-INFO in ReconfigureOnChangeFilter{invocationCounter=16} - Detected change in [[/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/installedApps/DWS06CT0001Cell01/SimpleWeb_war.ear/SimpleWeb.war/WEB-INF/classes/logback.xml, /data/simple/helper/log/appLogbackConf.xml]]
[2/18/15 11:25:55:557 ART] 000003ed SystemOut O 11:25:55,531 |-INFO in ReconfigureOnChangeFilter{invocationCounter=16} - Will reset and reconfigure context named [SIMPLE_WEB]
[2/18/15 11:25:55:559 ART] 000003ed SystemOut O 11:25:55,559 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0}
- Will scan for changes in [[/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/installedApps/DWS06CT0001Cell01/SimpleWeb_war.ear/SimpleWeb.war/WEB-INF/classes/logback.xml]] every 60 seconds.
[2/18/15 11:25:55:560 ART] 000003ed SystemOut O 11:25:55,560 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
[2/18/15 11:25:55:579 ART] 000003ed SystemOut O 11:25:55,579 |-INFO in ch.qos.logback.classic.joran.action.ContextNameAction - Setting logger context name as [SIMPLE_WEB]
[2/18/15 11:25:55:586 ART] 000003ed SystemOut O 11:25:55,586 |-ERROR in ch.qos.logback.classic.joran.action.InsertFromJNDIAction - [java:comp/env/APP_CONFIG_FOLDER] has null or empty value
[2/18/15 11:25:55:589 ART] 000003ed SystemOut O 11:25:55,589 |-ERROR in ch.qos.logback.classic.joran.action.InsertFromJNDIAction - [java:comp/env/APP_LOG_FOLDER] has null or empty value
[2/18/15 11:25:55:592 ART] 000003ed SystemOut O 11:25:55,592 |-INFO in ch.qos.logback.classic.joran.action.InsertFromJNDIAction - Setting variable [COMMON_LOG_FOLDER] to [/data/logs] in [LOCAL] scope
[2/18/15 11:25:55:599 ART] 000003ed SystemOut O 11:25:55,597 |-ERROR in ch.qos.logback.core.joran.action.PropertyAction - Could not find properties file [APP_CONFIG_FOLDER_IS_UNDEFINED/helper/log/logback.properties].
[2/18/15 11:25:55:601 ART] 000003ed SystemOut O 11:25:55,601 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@1ddf1ddf - Adding file:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/APP_CONFIG_FOLDER_IS_UNDEFINED/helper/log/appLogbackConf.xml to configuration watch list.
[2/18/15 11:25:55:612 ART] 000003ed SystemOut O 11:25:55,603 |-ERROR in ch.qos.logback.core.joran.action.IncludeAction - Failed to open file:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/APP_CONFIG_FOLDER_IS_UNDEFINED/helper/log/appLogbackConf.xml java.io.FileNotFoundException: /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/APP_CONFIG_FOLDER_IS_UNDEFINED/helper/log/appLogbackConf.xml (No such file or directory)
at java.io.FileNotFoundException: /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/APP_CONFIG_FOLDER_IS_UNDEFINED/helper/log/appLogbackConf.xml (No such file or directory)
at at java.io.FileInputStream.open(Native Method)
at at java.io.FileInputStream.<init>(FileInputStream.java:126)
at at java.io.FileInputStream.<init>(FileInputStream.java:85)
at at sun.net.www.protocol.file.FileURLConnection.connect(FileURLConnection.java:70)
at at sun.net.www.protocol.file.FileURLConnection.getInputStream(FileURLConnection.java:161)
at at java.net.URL.openStream(URL.java:1011)
at at ch.qos.logback.core.joran.action.IncludeAction.openURL(IncludeAction.java:144)
at at ch.qos.logback.core.joran.action.IncludeAction.getInputStream(IncludeAction.java:212)
at at ch.qos.logback.core.joran.action.IncludeAction.begin(IncludeAction.java:60)
at at ch.qos.logback.core.joran.spi.Interpreter.callBeginAction(Interpreter.java:275)
at at ch.qos.logback.core.joran.spi.Interpreter.startElement(Interpreter.java:147)
at at ch.qos.logback.core.joran.spi.Interpreter.startElement(Interpreter.java:129)
at at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:50)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
at at ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter$ReconfiguringThread.performXMLConfiguration(ReconfigureOnChangeFilter.java:216)
at at ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter$ReconfiguringThread.run(ReconfigureOnChangeFilter.java:194)
at at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at at java.lang.Thread.run(Thread.java:736)
[2/18/15 11:25:55:614 ART] 000003ed SystemOut O 11:25:55,613 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to OFF
[2/18/15 11:25:55:615 ART] 000003ed SystemOut O 11:25:55,614 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
[2/18/15 11:25:55:616 ART] 000003ed SystemOut O 11:25:55,616 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@44da44da - Registering current configuration as safe fallback point