A bug of logback1.11

标签：actor   str   led   package   org   nts   path   conf   false   

The bug is that: When a thread is writing log continuously, the log filename which set as pattern:${LOG_HOME}/XXXX.%d{yyyy-MM-dd}.log won‘t change to new file after 00:00:00 of next day, and if a new thread begins to write log after 00:00:00 of next day, it‘s log will still be written to yesterday‘s file.

That‘s to say:While a thread is writing log continuously, the log file name can‘t change as pattern:XXXX.%d{yyyy-MM-dd}.log.

Here is my logback‘s configuration file:

log back configuration file:

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
<!-- Where are log files -->
<property name="LOG_HOME" value="d:/logs" />

<!-- Output to Console -->
<appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <encoder
        class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
        <!--%d:date，%thread:thread，%-5level：error/debug/info... %msg：message，%n:new line -->
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} -%msg%n</pattern>
    </encoder>
</appender>

<!-- Output to File -->
<appender name="FILE"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
    <rollingPolicy
        class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <!--log file pathname -->
        <FileNamePattern>${LOG_HOME}/logbackCfg.log.%d{yyyy-MM-dd}.log
        </FileNamePattern>
        <!--days log files will be kept -->
        <MaxHistory>30</MaxHistory>
    </rollingPolicy>
    <encoder
        class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
        <!--%d:date，%thread:thread，%-5level：error/debug/info... %msg：message，%n:new line -->
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} -%msg%n</pattern>
    </encoder>
    <!--size -->
    <triggeringPolicy
        class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
        <MaxFileSize>10MB</MaxFileSize>
    </triggeringPolicy>
</appender>

<!-- log level TRACE, DEBUG, INFO, WARN, ERROR, ALL and OFF,default：DEBUG。-->
<root level="ALL">
    <appender-ref ref="STDOUT" /> <!-- show log on console -->
    <appender-ref ref="FILE" /> <!-- show log in file -->
</root>

</configuration>

For verifying the bug ,I created two threads. Here is thread one：

thread01
package logbackCfg;

import java.io.File;
import java.io.FileWriter;
import java.io.PrintWriter;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

class Runner extends Thread {
private String file;

public Runner(String file) {
    this.file=file;
}

public void run() {
    while(true) {
        try {
            Thread.sleep(5000);
            Thread.currentThread().interrupt();

            File f=new File(file);
            FileWriter fw = new FileWriter(f, true);

            PrintWriter pw = new PrintWriter(fw);
            pw.println("追加内容");
            pw.println("落霞与孤鹜齐飞");
            pw.println("秋水共长天一色");
            pw.println("滕王阁序 唐.王勃");
            pw.flush();

            pw.close();
            fw.close();

        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

}

public class App {
private final static Logger logger = LoggerFactory.getLogger(App.class);

public static void main(String[] args) throws InterruptedException {
    //Runner r=new Runner("D:\\logs\\logbackCfg.log.2020-01-15.log");
    //r.start();

    while(true) {
        Thread.sleep(5000);
        logger.info("秦时明月汉时关");
        logger.error("万里长征人未还");
        logger.debug("但使龙城飞将在");
        logger.trace("不教胡马度阴山");
    }
}

}

Thread two:

thread02
package logbackCfg;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class App2 {
private final static Logger logger = LoggerFactory.getLogger(App2.class);

public static void main(String[] args) throws InterruptedException {

    while(true) {
        Thread.sleep(8000);
        logger.info("九里山前作战场");
        logger.error("牧童拾得旧刀枪");
        logger.debug("微风吹皱乌江水");
        logger.trace("恰似虞姬别霸王");
    }
}

}
Thread three：it will begin to write logs after 00:00:00 of next day:

thread03
package logbackCfg;

import java.text.ParseException;
import java.text.SimpleDateFormat;
import java.util.Date;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class NewDayThread {
private final static Logger logger = LoggerFactory.getLogger(NewDayThread.class);

public static void main(String[] args) throws InterruptedException {

    while(true) {
        Date currentTime = new Date();

        if(currentTime.compareTo(fixedDate())>0) {
            Thread.sleep(8000);
            logger.info("万里赴戎机，关山度若飞。");
            logger.error("朔气传金柝，寒光照铁衣。");
            logger.debug("将军百战死，壮士十年归。");
        }
    }
}

private static Date fixedDate() {
    SimpleDateFormat formatter = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss");
    try {
        return formatter.parse("2020-01-17 00:00:00");
    } catch (ParseException e) {
        return new Date();
    }
}

}

I ran the three thread in the afternoon of 2020-01-16, and found they were still written to file:‘logbackCfg.log.2020-01-16.log‘ after 00:00:00 of 2020-01-17，here is the evidence:

Error rendering macro ‘code‘: Invalid value specified for parameter ‘com.atlassian.confluence.ext.code.render.InvalidValueException‘
...
2020-01-16 23:59:40.808 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-16 23:59:42.527 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-16 23:59:42.527 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-16 23:59:42.527 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-16 23:59:42.527 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-16 23:59:45.809 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-16 23:59:45.809 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-16 23:59:45.809 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-16 23:59:45.809 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-16 23:59:50.528 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-16 23:59:50.528 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-16 23:59:50.528 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-16 23:59:50.528 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-16 23:59:50.809 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-16 23:59:50.809 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-16 23:59:50.809 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-16 23:59:50.809 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-16 23:59:55.810 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-16 23:59:55.810 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-16 23:59:55.810 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-16 23:59:55.810 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-16 23:59:58.529 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-16 23:59:58.529 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-16 23:59:58.529 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-16 23:59:58.529 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:00.810 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:00.810 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:00.810 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:00.810 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:05.811 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:05.811 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:05.811 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:05.811 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:06.530 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:06.530 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:06.530 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:06.530 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:08.004 [main] INFO logbackCfg.NewDayThread -万里赴戎机，关山度若飞。
2020-01-17 00:00:08.007 [main] ERROR logbackCfg.NewDayThread -朔气传金柝，寒光照铁衣。
2020-01-17 00:00:08.007 [main] DEBUG logbackCfg.NewDayThread -将军百战死，壮士十年归。
2020-01-17 00:00:10.811 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:10.811 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:10.811 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:10.811 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:14.530 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:14.530 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:14.530 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:14.530 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:15.812 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:15.812 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:15.812 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:15.812 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:16.008 [main] INFO logbackCfg.NewDayThread -万里赴戎机，关山度若飞。
2020-01-17 00:00:16.008 [main] ERROR logbackCfg.NewDayThread -朔气传金柝，寒光照铁衣。
2020-01-17 00:00:16.008 [main] DEBUG logbackCfg.NewDayThread -将军百战死，壮士十年归。
2020-01-17 00:00:20.812 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:20.812 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:20.812 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:20.812 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:22.530 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:22.530 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:22.530 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:22.530 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:24.008 [main] INFO logbackCfg.NewDayThread -万里赴戎机，关山度若飞。
2020-01-17 00:00:24.008 [main] ERROR logbackCfg.NewDayThread -朔气传金柝，寒光照铁衣。
2020-01-17 00:00:24.008 [main] DEBUG logbackCfg.NewDayThread -将军百战死，壮士十年归。
2020-01-17 00:00:25.812 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:25.812 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:25.812 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:25.812 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:30.531 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:30.531 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:30.531 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:30.531 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:30.812 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:30.812 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:30.812 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:30.812 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:32.009 [main] INFO logbackCfg.NewDayThread -万里赴戎机，关山度若飞。
2020-01-17 00:00:32.009 [main] ERROR logbackCfg.NewDayThread -朔气传金柝，寒光照铁衣。
2020-01-17 00:00:32.009 [main] DEBUG logbackCfg.NewDayThread -将军百战死，壮士十年归。
2020-01-17 00:00:35.812 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:35.812 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:35.812 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:35.812 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:38.532 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:38.532 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:38.532 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:38.532 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:40.010 [main] INFO logbackCfg.NewDayThread -万里赴戎机，关山度若飞。
2020-01-17 00:00:40.010 [main] ERROR logbackCfg.NewDayThread -朔气传金柝，寒光照铁衣。
2020-01-17 00:00:40.010 [main] DEBUG logbackCfg.NewDayThread -将军百战死，壮士十年归。
2020-01-17 00:00:40.813 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:40.813 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:40.813 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:40.813 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:45.813 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:45.813 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:45.813 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:45.813 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:46.532 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:46.532 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:46.532 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:46.532 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王
2020-01-17 00:00:48.010 [main] INFO logbackCfg.NewDayThread -万里赴戎机，关山度若飞。
2020-01-17 00:00:48.010 [main] ERROR logbackCfg.NewDayThread -朔气传金柝，寒光照铁衣。
2020-01-17 00:00:48.010 [main] DEBUG logbackCfg.NewDayThread -将军百战死，壮士十年归。
2020-01-17 00:00:50.814 [main] INFO logbackCfg.App -秦时明月汉时关
2020-01-17 00:00:50.814 [main] ERROR logbackCfg.App -万里长征人未还
2020-01-17 00:00:50.814 [main] DEBUG logbackCfg.App -但使龙城飞将在
2020-01-17 00:00:50.814 [main] TRACE logbackCfg.App -不教胡马度阴山
2020-01-17 00:00:54.533 [main] INFO logbackCfg.App2 -九里山前作战场
2020-01-17 00:00:54.533 [main] ERROR logbackCfg.App2 -牧童拾得旧刀枪
2020-01-17 00:00:54.533 [main] DEBUG logbackCfg.App2 -微风吹皱乌江水
2020-01-17 00:00:54.533 [main] TRACE logbackCfg.App2 -恰似虞姬别霸王

And the new file:‘logbackCfg.log.2020-01-17.log‘ supposed to take place won‘t be created!

Until I stopped the three thread,then restarted them, the file:‘logbackCfg.log.2020-01-17.log‘ was created.

That‘s all , you can try by yourself to verify the bug.

A bug of logback1.11

标签：actor   str   led   package   org   nts   path   conf   false   

原文地址：https://blog.51cto.com/7726611/2467408