A bug of logback1.11

logback is the successor of log4j, they are written by a same author, it is supposed to be more advanced and convenient.But there is a bug lies in version logback1.11, we should not ignore this.

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.

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

时间： 2024-11-09 02:13:50

A bug of logback1.11的相关文章

Oracle Bug 某脚本一直处于执行状态，等待事件为：asynch descriptor resize

问题描述:       项目反馈数据库服务器的CPU持续100%的情况,跟踪发现很多活动会话的等待事件是"asynch descriptor resize",并且这些会话一直处于Active状态,而这些会话执行的查询并不复杂,感觉很是奇怪.       查阅了一下资料,对应Oracle的Bug 9829397,Excessive CPU and many "asynch descriptor resize" waits for SQL using Async IO,

一个bug引发的血案——从程序员角度看罗一笑事件

我这人有个毛病一直改不掉,不过好像也没怎么试过去改,那就是自命清高.这应该是文青的一大特点,总觉得跟文化这么高雅的东西挂钩怎么都低俗不了. 在做公众号这件事情上,自命清高就体现在不谈热点.去年一年火的事情不少--阿尔法狗大战李世乭.王宝强事件,以及川普当选美国总统.为什么不谈呢?首先是因为大家都在谈,我也跟着凑上去有种蹭热点的嫌疑,而且更有种人云亦云的庸俗感.其次是因为有一贯关注的主题,平时工作已经够忙的了,闲下来的时间还是要分配给它们. 到了新的一年,我要洗心革命,要跟人民群众靠拢,不能再做一

引用对象的使用和易产生bug的示例

本文属原创,转载请注明出处:http://www.cnblogs.com/robinjava77/p/5481608.html  (Robin) QuoteTest(引用对象技巧) 1 import java.util.ArrayList; 2 import java.util.HashMap; 3 import java.util.List; 4 import java.util.Map; 5 6 /** 7 * Created by robin on 2016/4/13. 8 * 引用型对向

Grid目录过大，命中Bug

今天在例行巡检的时候,发现SMIDB的两个节点grid安装目录使用空间均为36G+,但是wssdb的目录6个G不到,相对比较正常. df命令结果: [[email protected] oraagent_grid]$ df -h/dev/mapper/vg_smi-lvora                       60G   46G   11G  81% /oracle 使用率为81%,二节点使用率为79% 再进一步看哪些目录占用了目录空间: [[email protected] app]

总结--折腾的2015，职场太现实 辞退让人心寒

早就想写2015年的工作总结了,因为这一年发生了让我意想不到的事情,这些事情也许今生也会难忘.当然要总结自己的问题,但是也看清了社会上一些不曾体会到的东西. 楼主在2015年7月份从H公司跳槽到S公司,这两家公司还算是很不错的公司,都是大公司,各方面都还不错,H公司是S公司的一家子公司,就是H公司里面有一部分人会外包到S公司,而S公司是一家超级大的外资公司,它的人员构成是自己的正式员工与外包的员工.当时跳槽到S公司时,H公司里面同项目组的一个成员也要去S公司,H公司的这个项目当时也是正在招人阶段

备库简介

备库类型:1.物理备库:2.逻辑备库:3.快照备库. 可以同时配置1个或多个类型的备库 1.物理备库 是主库的块对块的拷贝,应用重做日志,通过从主库接受重做数据应用到物理备库上的机制 可以以read only模式打开,11g之后可以配置active DG以只读模式打开应用重做数据 物理备库的好处: 1. 灾难恢复和高可用 2. 数据保护 支持多有的DDL和DML操作 3. 减小主库负载 以只读模式打开,用于报表和查询 4. 性能 底层拷贝,绕过SQL级别代码层 2. 逻辑备库 通过SQL应用更新

豪华版飞机大战系列(二)

既上一篇介绍了游戏的主要概况下,这篇来开始讲一下游戏中的各个文件. 先来看看cocos2d-x 3.0 中一个比较赞的功能,比起3.0以前的要令人非常激动的.虽说3.0出来很久了,我还是说下这个功能,知道的飘过. 对于在不同环境下用cocos2d-x开发手游,屏幕尺寸是一个比较蛋疼的问题,比如在3.0以前,在代码中修改屏幕尺寸还是比较麻烦的,而且在电脑上运行良好的尺寸到手机端感觉效果就差了一点. AppDelegate.cpp是整个游戏的入口程序,3.0以前设置游戏尺寸时主要代码如下: bool

ash停止不动无法产生报告问题解决

1.数据库版本 oracle  11.2.0.3.0 2.问题现象 使用ashrpt.sql生成ash报告时,在输入完成起始时间.指定报告文件存放路径与文件名称后,静止无反应. SQL> @?/rdbms/admin/ashrpt.sql ...... Using the report name /home/oracle/ashrpt_1_0802_1932.html Summary of All User Input ------------------------- Format      

每周代码及工作总结（第十周）

工作日期:2016.11.17-2016.11.23 工作内容: PSP C类别         C内容 S开始时间 ST结束时间 I中断时间 T净时间(分) 活动 本周站立会议 -- -- -- 240 本周代码相关 -- -- -- 160 其他事项 -- -- -- 220 文档 11月20日 版本控制报告 9:00 10:30 0 90   12:30 14:00 35 55 11月21日 根据需求规格说明书找Bug 9:40 11:00 0 80   22:00 23:00 0 60