源码:
logback-test.xml文件如下加拿大28源码出售(www.1159880099.com)QQ1159880099 ,有2个需要我们重点关注的参数:
fileNamePattern:这里的日志文件名变动的部分是年月日时,外加1个文件分割自增变量,警告,年月日时的数值依赖于系统时间,自增变量依赖logback框架里运行时的内存变量。
maxFileSize:这里日志文件分割的条件为日志文件大小达到1M。
输出日志的源码如下,需要注意的是:
我们用while循环输出日志,比正常的日志输出强度高许多;
我们的日志内容是"Hello logback, line "+i。
根据源码:
第一步,我们现在要输出10万条日志到日志文件当中,每个文件大小为1MB,如图:
可以看到,实际的文件大小是不确定的1142KB,1152KB,都大于1MB,最后一个日志文件因为还没有填满而小于1MB。这是我们要弄明白的第一个问题,为什么日志文件大小实际上大于我们设定的上限值?
第二步,因为我们是用main方法输出日志,我们再运行一遍就相当于服务器重启一遍,这个时候我们把日志输出内容换成,“Hello logback, line ++++++”+i。
先看文件数量,循环次数相同,新增的日志文件数量是6个,前面0~6个文件是第一步里运行得到的,后面的7~12是这次生成的。
对比两张图里前面7个文件0~6,6号分割文件大小发生变化我们容易理解,但是0~5这6个文件怎么都增加了,这是我们要回答的第二个问题?
logback日志分割问题分析:
第一个问题:为什么日志分割实际大小大于设定的上限值?
原因分析:
一个日志文件分割时,有两个操作:
比较当前日志文件与设定值的大小,判断是否分割;
只要还未完成分割,持续向当前日志文件写入日志。
当你还在比较的时候,我已经输出几百米了。。。行。。。。
当判断出日志文件大小已经达到预定值的瞬间,日志文件还未进行分割,而此时日志文件仍然被写入日志。故正常情况下,日志文件的实际大小通常要大于设定值的大小。
超出多少:日志文件实际超出预定值的大小size,基本上取决于判定出日志文件大小达到临界值的时间点zeroPoint以后,日志记录的写入相对于日志文件创建的速度。
通常来说,日志在代码中的输出越频繁,超出临界值越多(我们这里的循环输出日志,强度是很大的)。
诡谲:JIT在作祟?多次重复以上的单个步骤,观察日志分割文件大小,我们不难发现,日志文件列表的开头几个文件总是比后面的日志文件要小一些。换句话说,运行时的日志输出速度发生了变化,我猜想这里极有可能是因为while循环被JIT编译器检测到为热点代码,所以进行了再编译,从而使日志的输出速度变得更快,导致后面的日志文件更大些。
第二个问题:为什么“重启”后,原本应该锁定的日志文件,再次被输入日志?
证据:检查0~6号文件的末尾,我们都可以发现“Hello logback, line ++++++”+i,这段记录的存在。也就是说,“重启”之前的、按理说已经“满格”达到上限值日志文件,在“重启”后,发生了日志再次写入的问题。
原因分析:
日志名称:test-log.2018-08-14-13.0.log。文件名称精确到小时,我们“重启”前后,都是在同一天的13点!
日志名称的变化依赖于时间,以及分割序号,时间由操作系统决定,分割序号由logback框架决定。分割序号对应的变量值是没有持久化的!一旦重启,就只能重头开始,所以在同一个时间段(这里是同一天的同一个小时)里发生重启,不会新建日志文件,而是在原有的日志里追加记录;
第一个问题里已经说了,日所以志文件在比较的时候(还未比较完成时),仍然在进行日志输出,所以日志文件会变大。
原文地址:http://blog.51cto.com/13923101/2159883