[logback-dev] [JIRA] Commented: (LBCORE-106) TimeBasedRollingPolicy append logs into a old log file, instead of rolling the log file.

Brian Chou (JIRA) noreply-jira at qos.ch
Mon Jul 13 21:29:10 CEST 2009


    [ http://jira.qos.ch/browse/LBCORE-106?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=11241#action_11241 ] 

Brian Chou commented on LBCORE-106:
-----------------------------------

Here's some additional info that was found over the weekend:

2009-07-13 06:45:08,618 INFO  [STDOUT] 06:45:08,618 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [/opt/di/system/jboss/jboss-4.2.3.GA-nova1b-sbfw-V2.0.0-onlineserv/server/default/log/server.log] to [/opt/di/system/jboss/jboss-4.2.3.GA-nova1b-sbfw-V2.0.0-onlineserv/server/default/log/server.2009-07-10.log]
2009-07-13 06:45:08,669 INFO  [STDOUT] 06:45:08,669 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [/opt/di/system/jboss/jboss-4.2.3.GA-nova1b-sbfw-V2.0.0-onlineserv/server/default/log/server_mc.log] to [/opt/di/system/jboss/jboss-4.2.3.GA-nova1b-sbfw-V2.0.0-onlineserv/server/default/log/server_mc.2009-07-10.log]

We have 2 servers running in an environment that developers do not have access to, and this is the only environment that we're seeing this issue on a normal basis. 

So a couple weird things going on here:

1. On the nova1b-qa server we output any STDOUT or console output to jboss.log and that rolls over in the format jboss.log.YYYY-MM-DD. Those logs are controlled by log4j since these are the JBoss logs. The weird thing is that there was NO output like above in the jboss.log.2009-07-11 or jboss.log.2009-07-12 files, only in today's jboss.log. 

2. On nova1b-qa we do have rollover files of: server.2009-07-10.log, server.2009-07-11.log, server.2009-07-12.log, server_mc.2009-07-10.log, server_mc.2009-07-11.log, and server_mc.2009-07-12.log, but again there was only 1 logback rollover output mentioned above. 

3. On nova1b-qa, most of today's application logging is going into server.2009-07-10.log and server_mc.2009-07-10.log instead of server.log and server_mc.log. 

4. On nova1a-qa, it seems like it may have been restarted or something over the weekend and possibly this morning, although I asked people who control this environment to see if it was restarted over the weekend and they weren't aware of any restarts. 

5. On nova1a-qa we only have 1 JBoss rollover log file for jboss.log.2009-07-12 with no logback rollover output whatsoever. 

6. On nova1a-qa we only have logback rollover files: server.2009-07-11.log, server.2009-07-12.log, server_mc.2009-07-11.log, and server_mc.2009-07-12.log. 

7. On nova1a-qa today's application logging is correctly going into server.log and server_mc.log. 

8. On nova1a-qa today's jboss.log which I've included, it looks like JBoss is reconfiguring all the logback appenders, etc. even though the server did not restart. 

Today's nova1a-qa jboss.log output:

2009-07-13 00:05:41,002 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 00:35:41,068 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 01:05:41,107 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 01:35:41,140 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 02:05:41,176 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 02:35:41,209 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 03:05:41,246 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 03:35:41,280 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 04:05:41,316 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 04:35:41,350 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 05:05:41,387 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 05:35:41,420 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 06:05:41,456 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 06:35:41,489 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 07:05:41,526 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 07:35:41,559 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 1800000
2009-07-13 07:45:51,259 INFO  [STDOUT] 07:45:51,256 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
2009-07-13 07:45:51,261 INFO  [STDOUT] 07:45:51,260 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/opt/jboss/sbfw-V2.0.0-onlineserv-home/server/default/conf/logback.xml]
2009-07-13 07:45:51,396 INFO  [STDOUT] 07:45:51,396 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
2009-07-13 07:45:51,400 INFO  [STDOUT] 07:45:51,400 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE]
2009-07-13 07:45:51,435 INFO  [STDOUT] 07:45:51,434 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [layout] on top of the object stack.
2009-07-13 07:45:51,460 INFO  [STDOUT] 07:45:51,460 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Popping appender named [CONSOLE] from the object stack
2009-07-13 07:45:51,460 INFO  [STDOUT] 07:45:51,460 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
2009-07-13 07:45:51,464 INFO  [STDOUT] 07:45:51,464 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
2009-07-13 07:45:51,474 INFO  [STDOUT] 07:45:51,474 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [rollingPolicy] on top of the object stack.
2009-07-13 07:45:51,479 INFO  [STDOUT] 07:45:51,479 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Adding parent to RollingPolicy: FILE
2009-07-13 07:45:51,483 INFO  [STDOUT] 07:45:51,483 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
2009-07-13 07:45:51,484 INFO  [STDOUT] 07:45:51,484 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern /opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server.%d{yyyy-MM-dd}.log for the active file
2009-07-13 07:45:51,494 INFO  [STDOUT] 07:45:51,494 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern '/opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server.%d{yyyy-MM-dd}.log'.
2009-07-13 07:45:51,495 INFO  [STDOUT] 07:45:51,495 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Roll-over at midnight.
2009-07-13 07:45:51,496 INFO  [STDOUT] 07:45:51,496 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [layout] on top of the object stack.
2009-07-13 07:45:51,497 INFO  [STDOUT] 07:45:51,497 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: /opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server.log
2009-07-13 07:45:51,497 INFO  [STDOUT] 07:45:51,497 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [/opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server.log]
2009-07-13 07:45:51,499 INFO  [STDOUT] 07:45:51,498 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Popping appender named [FILE] from the object stack
2009-07-13 07:45:51,499 INFO  [STDOUT] 07:45:51,499 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
2009-07-13 07:45:51,499 INFO  [STDOUT] 07:45:51,499 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [MCFILE]
2009-07-13 07:45:51,499 INFO  [STDOUT] 07:45:51,499 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [rollingPolicy] on top of the object stack.
2009-07-13 07:45:51,500 INFO  [STDOUT] 07:45:51,500 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Adding parent to RollingPolicy: MCFILE
2009-07-13 07:45:51,500 INFO  [STDOUT] 07:45:51,500 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
2009-07-13 07:45:51,500 INFO  [STDOUT] 07:45:51,500 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern /opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server_mc.%d{yyyy-MM-dd}.log for the active file
2009-07-13 07:45:51,501 INFO  [STDOUT] 07:45:51,501 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern '/opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server_mc.%d{yyyy-MM-dd}.log'.
2009-07-13 07:45:51,501 INFO  [STDOUT] 07:45:51,501 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Roll-over at midnight.
2009-07-13 07:45:51,502 INFO  [STDOUT] 07:45:51,502 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [layout] on top of the object stack.
2009-07-13 07:45:51,502 INFO  [STDOUT] 07:45:51,502 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[MCFILE] - Active log file name: /opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server_mc.log
2009-07-13 07:45:51,502 INFO  [STDOUT] 07:45:51,502 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[MCFILE] - File property is set to [/opt/di/system/jboss/jboss-4.2.3.GA-nova1a-sbfw-V2.0.0-onlineserv/server/default/log/server_mc.log]
2009-07-13 07:45:51,503 INFO  [STDOUT] 07:45:51,503 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Popping appender named [MCFILE] from the object stack
2009-07-13 07:45:51,503 INFO  [STDOUT] 07:45:51,503 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
2009-07-13 07:45:51,503 INFO  [STDOUT] 07:45:51,503 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [AuditLogger1]
2009-07-13 07:45:51,503 INFO  [STDOUT] 07:45:51,503 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [layout] on top of the object stack.
2009-07-13 07:45:51,504 INFO  [STDOUT] 07:45:51,504 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Popping appender named [AuditLogger1] from the object stack
2009-07-13 07:45:51,504 INFO  [STDOUT] 07:45:51,504 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [com.diginsite.services.integration.logging.logback.IAALogAppender]
2009-07-13 07:45:51,512 INFO  [STDOUT] 07:45:51,511 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [AuditLogger3]
2009-07-13 07:45:51,518 INFO  [STDOUT] 07:45:51,517 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [layout] on top of the object stack.
2009-07-13 07:45:51,547 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'com.diginsite.services.integration.dao.DaoConnectionManager'
2009-07-13 07:45:51,547 INFO  [STDOUT] 07:45:51,547 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Popping appender named [AuditLogger3] from the object stack
2009-07-13 07:45:51,547 INFO  [STDOUT] 07:45:51,547 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [com.diginsite.services.integration.logging.logback.IAALogAppender]
2009-07-13 07:45:51,547 INFO  [STDOUT] 07:45:51,547 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [AuditLogger4]
2009-07-13 07:45:51,547 INFO  [STDOUT] 07:45:51,547 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [layout] on top of the object stack.
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,549 |-ERROR in com.diginsite.services.integration.logging.logback.IAALogAppender[AuditLogger4] - null
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,550 |-ERROR in com.diginsite.services.integration.logging.logback.IAALogAppender[AuditLogger4] - Unable to parse configuration
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,550 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Popping appender named [AuditLogger4] from the object stack
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,550 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger] to false
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,550 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger level set to DEBUG
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,550 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.Scheduler] to false
2009-07-13 07:45:51,550 INFO  [STDOUT] 07:45:51,550 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.Scheduler level set to DEBUG
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI3729] to false
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI3729 level set to DEBUG
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI4567] to false
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI4567 level set to DEBUG
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI5678] to false
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI5678 level set to DEBUG
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI6789] to false
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI6789 level set to DEBUG
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI8901] to false
2009-07-13 07:45:51,551 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI8901 level set to DEBUG
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,551 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI9012] to false
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,552 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI9012 level set to DEBUG
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,552 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [FILogger.DI9999] to false
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,552 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - FILogger.DI9999 level set to DEBUG
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,552 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.tto] to false
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,552 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.tto level set to DEBUG
2009-07-13 07:45:51,552 INFO  [STDOUT] 07:45:51,552 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.tto]
2009-07-13 07:45:51,554 INFO  [STDOUT] 07:45:51,554 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw] to false
2009-07-13 07:45:51,554 INFO  [STDOUT] 07:45:51,554 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw level set to DEBUG
2009-07-13 07:45:51,554 INFO  [STDOUT] 07:45:51,554 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.sbfw]
2009-07-13 07:45:51,554 INFO  [STDOUT] 07:45:51,554 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.common] to false
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.common level set to DEBUG
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.sbfw.common]
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.common]
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.common.http.SecurityFilter] to false
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.common.http.SecurityFilter level set to DEBUG
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.sbfw.common.http.SecurityFilter]
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.common.http.SecurityFilter]
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.common.http.CallbackHandler] to false
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.common.http.CallbackHandler level set to DEBUG
2009-07-13 07:45:51,555 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.sbfw.common.http.CallbackHandler]
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.common.http.CallbackHandler]
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.common.http.IBCallbackHandler] to false
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.common.http.IBCallbackHandler level set to DEBUG
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.sbfw.common.http.IBCallbackHandler]
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.common.http.MCCallbackHandler] to false
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.common.http.MCCallbackHandler level set to DEBUG
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.common.http.MCCallbackHandler]
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.action.mc] to false
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.action.mc level set to DEBUG
2009-07-13 07:45:51,556 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.action.mc]
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,556 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.admin] to false
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.admin level set to DEBUG
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.admin]
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.sbfw.mc] to false
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.sbfw.mc level set to DEBUG
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[com.intuit.sbfw.mc]
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.intuit.iam] to false
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - com.intuit.iam level set to DEBUG
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[com.intuit.iam]
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [AuditLogger] to false
2009-07-13 07:45:51,557 INFO  [STDOUT] 07:45:51,557 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - AuditLogger level set to INFO
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [AuditLogger1] to Logger[AuditLogger]
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [AuditLogger3] to Logger[AuditLogger]
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[AuditLogger]
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [AuditLoggerBB] to false
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - AuditLoggerBB level set to INFO
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [AuditLogger1] to Logger[AuditLoggerBB]
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [AuditLogger4] to Logger[AuditLoggerBB]
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[AuditLoggerBB]
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [MCAuditLogger] to false
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - MCAuditLogger level set to INFO
2009-07-13 07:45:51,558 INFO  [STDOUT] 07:45:51,558 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [AuditLogger1] to Logger[MCAuditLogger]
2009-07-13 07:45:51,559 INFO  [STDOUT] 07:45:51,559 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [AuditLogger3] to Logger[MCAuditLogger]
2009-07-13 07:45:51,559 INFO  [STDOUT] 07:45:51,559 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[MCAuditLogger]
2009-07-13 07:45:51,559 INFO  [STDOUT] 07:45:51,559 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - root level set to DEBUG
2009-07-13 07:45:51,559 INFO  [STDOUT] 07:45:51,559 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[root]
2009-07-13 07:45:51,559 INFO  [STDOUT] 07:45:51,559 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MCFILE] to Logger[root]
2009-07-13 07:45:51,559 INFO  [STDOUT] 07:45:51,559 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.


> TimeBasedRollingPolicy append logs into a old log file, instead of rolling the log file.
> ----------------------------------------------------------------------------------------
>
>                 Key: LBCORE-106
>                 URL: http://jira.qos.ch/browse/LBCORE-106
>             Project: logback-core
>          Issue Type: Bug
>          Components: Appender
>    Affects Versions: 0.9.15
>         Environment: Linux, Sun JDK 5
>            Reporter: Ralph Goers
>            Assignee: Ceki Gulcu
>         Attachments: logback.xml
>
>
> It appears that LBCORE-26 was not completely fixed. I have users who seem the be having the same problem. The text below is the relevant portion of the email I received from them.
> There is same issue today also. Yesterday the nova1a-qa and nova1b-qa servers were restarted and after that the system logged the info to the server.log and server_mc.log files.
> Today the system logs most info to the server.2009-07-06.log and server_mc.2009-07-06.log files and some info to the server.log and server_mc.log files.
>  
> Below is example from the nova1a-qa:/opt/jboss/sbfw-V2.0.0-onlineserv-home/server/default/log
>  
> [akma4116 at nova1a-qa:/opt/jboss/sbfw-V2.0.0-onlineserv-home/server/default/log]$                                                                              ls -ltr
>  
> ...
>  
> -rw-rw-r--  1 jboss jboss   327312 Jul  5 23:50 server.2009-07-05.log
> -rw-rw-r--  1 jboss jboss   327312 Jul  5 23:50 server_mc.2009-07-05.log
> -rw-rw-r--  1 jboss jboss     6384 Jul  5 23:58 jboss.log.2009-07-05
> -rw-rw-r--  1 jboss jboss   250839 Jul  6 13:20 server_07_06_09_14_34_54.log
> -rw-rw-r--  1 jboss jboss   347440 Jul  6 13:20 server_mc_07_06_09_14_34_54.log
> -rw-rw-r--  1 jboss jboss   755260 Jul  6 14:18 console_07_06_09_14_34_54.log
> -rw-rw-r--  1 jboss jboss   856101 Jul  6 14:18 server_mc.2009-07-02.log
> -rw-rw-r--  1 jboss jboss   912958 Jul  6 14:18 server.2009-07-02.log
> -rw-rw-r--  1 jboss jboss    87149 Jul  6 14:34 boot.log
> -rw-rw-r--  1 jboss jboss 36091128 Jul  6 23:58 jboss.log.2009-07-06
> -rw-rw-r--  1 jboss jboss   108572 Jul  7 06:30 sbc_ib-exp_HQResponseTime.log
> -rw-rw-r--  1 jboss jboss    12810 Jul  7 07:48 server.log
> -rw-rw-r--  1 jboss jboss    18207 Jul  7 07:48 server_mc.log
> -rw-rw-r--  1 jboss jboss   148904 Jul  7 07:48 console.log
> -rw-rw-r--  1 jboss jboss   424746 Jul  7 08:20 ROOT_HQResponseTime.log
> -rw-rw-r--  1 jboss jboss   374460 Jul  7 08:25 hyperic-hq_HQResponseTime.log
> -rw-rw-r--  1 jboss jboss   231082 Jul  7 08:40 server_mc.2009-07-06.log
> -rw-rw-r--  1 jboss jboss   241730 Jul  7 08:40 server.2009-07-06.log
> -rw-rw-r--  1 jboss jboss    17574 Jul  7 08:42 sbc_mc-exp_HQResponseTime.log
> -rw-rw-r--  1 jboss jboss   556062 Jul  7 08:46 jboss.log
> [akma4116 at nova1a-qa:/opt/jboss/sbfw-V2.0.0-onlineserv-home/server/default/log]$ tail -f server.2009-07-06.log                                                08:40:00.018 [DefaultQuartzScheduler_Worker-4] DEBUG c.i.s.c.s.UpdateOnlinePayrollUserStatusJob [->:] - Exiting getAllPendingIOPUsers.
> 08:40:00.018 [DefaultQuartzScheduler_Worker-4] INFO  c.i.s.c.s.UpdateOnlinePayrollUserStatusJob [->:] - There were no Online Payroll users found in memory to sync and update.
> 08:40:00.018 [DefaultQuartzScheduler_Worker-4] DEBUG c.i.s.c.s.UpdateOnlinePayrollUserStatusJob [->:] - Exiting syncUsers.
> 08:40:00.018 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - Entering getAllActiveBMUsers.
> 08:40:00.018 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserMap [->:] - Entering isEmpty.
> 08:40:00.018 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserMap [->:] - User Map is empty: true
> 08:40:00.018 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserMap [->:] - Exiting isEmpty.
> 08:40:00.018 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - Exiting getAllActiveBMUsers.
> 08:40:00.019 [DefaultQuartzScheduler_Worker-3] INFO  c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - There were no Billing Manager users found in memory to sync and update.
> 08:40:00.019 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - Exiting syncUsers.
> ò
> [akma4116 at nova1a-qa:/opt/jboss/sbfw-V2.0.0-onlineserv-home/server/default/log]$ tail -f server.log
> 07:47:43.812 [Thread-30] DEBUG c.d.s.i.dao.slave.broker.Response [->00070:root] - Reading response input stream HEADER portion.
> 07:47:43.813 [Thread-29] DEBUG c.d.s.i.d.s.client.DIISBrokerAccess [->00070:root] -
>  
> Received DIIS response:
> DIISMessage{messageContent=<RSP>LOGMESSAGE<RC>0<OK>  ---LOGGED entry  OK---<TMHOST>19, messageId=00000000, validateHeader=true, isValidHeader=true}
>  
>  
> 07:47:43.813 [Thread-29] DEBUG c.d.s.i.dao.slave.diis.DIISLexer [->00070:root] - instantiated DIISLexer
> 07:47:43.813 [Thread-29] DEBUG c.d.s.i.dao.slave.diis.DIISParser [->00070:root] - constructor
> 07:47:43.813 [Thread-29] DEBUG c.d.s.i.logging.IAALogHandler [->00070:root] - Successfully published to the IAALog
>  
> ò
> [akma4116 at nova1a-qa:/opt/jboss/sbfw-V2.0.0-onlineserv-home/server/default/log]$ tail -f server.2009-07-06.log
> 08:50:00.098 [DefaultQuartzScheduler_Worker-4] DEBUG c.i.s.c.s.UpdateOnlinePayrollUserStatusJob [->:] - Exiting getAllPendingIOPUsers.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-4] INFO  c.i.s.c.s.UpdateOnlinePayrollUserStatusJob [->:] - There were no Online Payroll users found in memory to sync and update.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - Entering getAllActiveBMUsers.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-4] DEBUG c.i.s.c.s.UpdateOnlinePayrollUserStatusJob [->:] - Exiting syncUsers.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserMap [->:] - Entering isEmpty.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserMap [->:] - User Map is empty: true
> 08:50:00.098 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserMap [->:] - Exiting isEmpty.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - Exiting getAllActiveBMUsers.
> 08:50:00.098 [DefaultQuartzScheduler_Worker-3] INFO  c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - There were no Billing Manager users found in memory to sync and update.
> 08:50:00.099 [DefaultQuartzScheduler_Worker-3] DEBUG c.i.s.c.s.UpdateBillingManagerUserStatusJob [->:] - Exiting syncUsers.
>  

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

       


More information about the logback-dev mailing list