I am using logback RollingFileAppender with SizeAndTimeBasedFNATP. Everything looks good other than rollover. Code is:
package com.rsa.springclasses.day3.logback;
import java.io.File;
import java.io.IOException;
import java.util.Iterator;
import java.util.Properties;
import org.slf4j.LoggerFactory;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.ComponentScan;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.io.ClassPathResource;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.Appender;
import ch.qos.logback.core.ConsoleAppender;
import ch.qos.logback.core.rolling.RollingFileAppender;
import ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP;
import ch.qos.logback.core.rolling.TimeBasedRollingPolicy;
import ch.qos.logback.core.status.OnConsoleStatusListener;
import ch.qos.logback.core.status.StatusManager;
@Configuration
@ComponentScan
public class AppConfig {
@Bean
public LoggerContext getLoggerContext() {
LoggerContext lctx = this.initLoggerContext();
return lctx;
}
public LoggerContext initLoggerContext() {
LoggerContext lctx = (LoggerContext) LoggerFactory.getILoggerFactory();
lctx.setName("ApplicationLogger");
lctx.reset();
StatusManager sm = lctx.getStatusManager();
OnConsoleStatusListener ocsl = new OnConsoleStatusListener();
sm.add(ocsl);
ocsl.start();
Properties lp = readLogbackProperties();
PatternLayoutEncoder cple = this.getPatternEncoder(lp);
cple.setContext(lctx);
//cple.stop();
cple.start();
System.out.println("Console logging pattern used: " + cple.getPattern());
// Appenders
ConsoleAppender<ILoggingEvent> capp = this.getConsoleAppender();
capp.setContext(lctx);
capp.setEncoder(cple);
//capp.stop();
capp.start();
System.out.println("Console appender started...");
PatternLayoutEncoder fple = this.getPatternEncoder(lp);
fple.setContext(lctx);
//fple.stop();
fple.start();
System.out.println("File logging pattern used: " + fple.getPattern());
RollingFileAppender<ILoggingEvent> rfapp = this.getRollingFileAdapter(lctx, fple, lp);
//rfapp.stop();
rfapp.start();
Logger rootLogger = lctx.getLogger(Logger.ROOT_LOGGER_NAME);
//lctx.stop();
rootLogger.detachAndStopAllAppenders();
rootLogger.addAppender(rfapp);
rootLogger.addAppender(capp);
this.setLoggerLevels(lctx, lp);
for (Logger l : lctx.getLoggerList()) {
System.out.println("Logger name: " + l.getName() + ", Log Level: " + l.getLevel());
}
lctx.start();
rootLogger.debug("Logger context created.");
Iterator<Appender<ILoggingEvent>> apps = rootLogger.iteratorForAppenders();
while(apps.hasNext()) {
Appender<ILoggingEvent> app = apps.next();
System.out.println("Appenders available: " + app.getName());
}
return lctx;
}
public RollingFileAppender<ILoggingEvent> getRollingFileAdapter(LoggerContext lctx, PatternLayoutEncoder ple, Properties lp) {
File logsdir = this.getLogDir(lp);
String logsFileName = "application.log";
if (lp.getProperty("FILE_NAME") != null) {
logsFileName = lp.getProperty("FILE_NAME");
}
String logsRollPattern = "application.%d{yyyy-MMM-dd_HH:mm:ss}.log";
if (lp.getProperty("ROLL_FILE_NAME_PATTERN") != null) {
logsRollPattern = lp.getProperty("ROLL_FILE_NAME_PATTERN");
}
System.out.println("File rolling pattern used: " + logsRollPattern);
RollingFileAppender<ILoggingEvent> appender = new RollingFileAppender<ILoggingEvent>();
appender.setName("ApplicationRollingFileAppender");
appender.setFile(logsdir.getAbsolutePath().replaceAll("\\\\", "/") + "/" + logsFileName);
appender.setContext(lctx);
appender.setEncoder(ple);
appender.setAppend(true);
SizeAndTimeBasedFNATP<ILoggingEvent> stbf = new SizeAndTimeBasedFNATP<>();
stbf.setContext(lctx);
stbf.setMaxFileSize("2KB");
TimeBasedRollingPolicy<ILoggingEvent> rollingPolicy = new TimeBasedRollingPolicy<>();
rollingPolicy.setContext(lctx);
rollingPolicy.setParent(appender);
rollingPolicy.setFileNamePattern(logsdir.getAbsolutePath().replaceAll("\\\\", "/") + "/" + logsRollPattern);
rollingPolicy.setMaxHistory(30);
rollingPolicy.setTimeBasedFileNamingAndTriggeringPolicy(stbf);
stbf.setTimeBasedRollingPolicy(rollingPolicy);
//rollingPolicy.stop();
rollingPolicy.start();
stbf.start();
appender.setRollingPolicy(rollingPolicy);
return appender;
}
public ConsoleAppender<ILoggingEvent> getConsoleAppender() {
ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>();
appender.setName("ApplicationConsoleAppender");
return appender;
}
public PatternLayoutEncoder getPatternEncoder(Properties props) {
if (props == null) {
props = this.readLogbackProperties();
}
String pattern = "%msg%n";
if (props.containsKey("PATTERN")) {
pattern = props.getProperty("PATTERN");
}
PatternLayoutEncoder ple = new PatternLayoutEncoder();
ple.setPattern(pattern);
return ple;
}
public void setLoggerLevels(LoggerContext lctx, Properties props) {
if (props == null) {
props = this.readLogbackProperties();
}
for(String lname: props.stringPropertyNames()) {
if (lname.startsWith("SET_LOGBACK_LEVEL_")) {
String level = props.getProperty(lname);
String pname = lname.substring(18);
lctx.getLogger(pname).setLevel(Level.valueOf(level));
}
}
}
public File getLogDir(Properties lp) {
if (lp == null) {
lp = this.readLogbackProperties();
}
if (lp.getProperty("LOGSDIR") == null) {
throw new IllegalArgumentException("LOGSDIR property not found in logback.properties");
}
File logsdir = new File(lp.getProperty("LOGSDIR"));
if (logsdir.exists()) {
System.out.println("Directory already available: " + logsdir.getAbsolutePath());
} else {
logsdir.mkdirs();
System.out.println("Directory created: " + logsdir.getAbsolutePath());
}
return logsdir;
}
public Properties readLogbackProperties() {
ClassPathResource cpr = new ClassPathResource("day3/logback/logback.properties");
System.out.println("File used to load the logback properties: " + cpr.getPath());
Properties p = new Properties();
try {
p.load(cpr.getInputStream());
} catch (IOException e) {
throw new IllegalArgumentException("Failed to find day3/logback/logback.properties in classpath. " + e.getMessage());
} catch (IllegalArgumentException iae) {
throw new IllegalArgumentException("Failed to read day3/logback/logback.properties in classpath. File might contain a malformed Unicode escape sequence. " + iae.getMessage());
}
return p;
}
}
When I ran the same program in debug mode, what I found is renameTo method in File class failed by returning false without any error message. I running my program on Windows 10. I double/triple checked using processMonitor (Procman.exe) to catch any process holding the file (application.log). No process is holding that file. Still fails with the below output. How to address this issue?
File used to load the logback properties: day3/logback/logback.properties
Console logging pattern used: %date{yyyy-MMM-dd_HH:mm:ss.SSS} [%thread] %-5level %logger{36} %msg%n
Console appender started...
File logging pattern used: %date{yyyy-MMM-dd_HH:mm:ss.SSS} [%thread] %-5level %logger{36} %msg%n
Directory already available: D:\EclipseProjects\springClasses\SpringClasses\target\log
File rolling pattern used: application.%d{yyyy-MMM-dd_HH:mm:ss}_%i.log
23:23:32,041 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@915416632 - No compression will be used
23:23:32,045 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@915416632 - Will use the pattern D:/EclipseProjects/springClasses/SpringClasses/target/log/application.%d{yyyy-MMM-dd_HH:mm:ss}_%i.log for the active file
23:23:32,047 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7f0eb4b4 - The date pattern is 'yyyy-MMM-dd_HH:mm:ss' from file name pattern 'D:/EclipseProjects/springClasses/SpringClasses/target/log/application.%d{yyyy-MMM-dd_HH:mm:ss}_%i.log'.
23:23:32,047 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7f0eb4b4 - Roll-over every second.
23:23:32,047 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7f0eb4b4 - Setting initial period to Sat Aug 20 22:09:46 IST 2016
23:23:32,050 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7f0eb4b4 - The date pattern is 'yyyy-MMM-dd_HH:mm:ss' from file name pattern 'D:/EclipseProjects/springClasses/SpringClasses/target/log/application.%d{yyyy-MMM-dd_HH:mm:ss}_%i.log'.
23:23:32,050 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7f0eb4b4 - Roll-over every second.
23:23:32,050 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7f0eb4b4 - Setting initial period to Sat Aug 20 22:09:46 IST 2016
23:23:32,052 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ApplicationRollingFileAppender] - Active log file name: D:/EclipseProjects/springClasses/SpringClasses/target/log/application.log
23:23:32,052 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ApplicationRollingFileAppender] - File property is set to [D:/EclipseProjects/springClasses/SpringClasses/target/log/application.log]
Logger name: ROOT, Log Level: DEBUG
Logger name: com, Log Level: null
Logger name: com.rsa, Log Level: null
Logger name: com.rsa.springclasses, Log Level: null
Logger name: com.rsa.springclasses.day3, Log Level: null
Logger name: com.rsa.springclasses.day3.logback, Log Level: DEBUG
Logger name: com.rsa.springclasses.day3.logback.AppConfigJunitTest, Log Level: TRACE
Logger name: org, Log Level: null
Logger name: org.hibernate, Log Level: ERROR
Logger name: org.hibernate.type, Log Level: ERROR
23:23:32,057 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [D:\EclipseProjects\springClasses\SpringClasses\target\log\application.log] to [D:\EclipseProjects\springClasses\SpringClasses\target\log\application.2016-Aug-20_22:09:46_0.log]
23:23:32,080 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [D:\EclipseProjects\springClasses\SpringClasses\target\log\application.log] as [D:\EclipseProjects\springClasses\SpringClasses\target\log\application.2016-Aug-20_22:09:46_0.log].
23:23:32,162 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Please consider leaving the [file] option of RollingFileAppender empty.
23:23:32,162 |-WARN in c.q.l.co.rolling.helper.RenameUtil - See also http://logback.qos.ch/codes.html#renamingError
23:23:32,214 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization
23:23:32,215 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - Multiple periods, i.e. 336 periods, seem to have elapsed. This is expected at application start.
2016-Aug-20_23:23:32.057 [main] DEBUG ROOT Logger context created.
Appenders available: ApplicationRollingFileAppender
Appenders available: ApplicationConsoleAppender
2016-Aug-20_23:23:32.434 [main] DEBUG c.r.s.d.logback.AppConfigJunitTest Debug message
2016-Aug-20_23:23:32.435 [main] ERROR c.r.s.d.logback.AppConfigJunitTest Error message
2016-Aug-20_23:23:32.435 [main] INFO c.r.s.d.logback.AppConfigJunitTest Info message
2016-Aug-20_23:23:32.436 [main] TRACE c.r.s.d.logback.AppConfigJunitTest Trace message
2016-Aug-20_23:23:32.436 [main] WARN c.r.s.d.logback.AppConfigJunitTest Warn message
I changed the rolling pattern to application_%d{yyyy-MMM-dd_HH_mm_ss}_%i.log, then file rename started working. Silly mistake. Basically, windows not accepting ":" in the file name. Would be very good if some error message is thrown by Java File.renameTo in such instances rather just returning false.