Logback统一配置及环境变量加载问题

关键字: logback.xml in jar logback environment variable

最近实现了一下将logback.xml的配置统一在基础框架的jar包中，如此所有业务应用都不用关心日志的规范格式或者存放位置，只要做一下简单的配置即可。
对于logback.xml与log4j的兼容或者适配问题，本文不做详细讨论。
参见：Java日志框架slf4j、jcl、jul、log4j1、log4j2、logback大总结

1. logback.xml配置

基本上也是主流配置，几个特别说明的点：

格式化的输出说明

请参照 http://logback.qos.ch/manual/layouts.html

<b>片段</b>:
%20logger false 20 none Left pad with spaces if the logger name is less than 20 characters long.
%-20logger true 20 none Right pad with spaces if the logger name is less than 20 characters long.
%.30logger NA none 30 Truncate from the beginning if the logger name is longer than 30 characters.
%20.30logger false 20 30 Left pad with spaces if the logger name is shorter than 20 characters. However, if logger name is longer than 30 characters, then truncate from the beginning.
%-20.30logger true 20 30 Right pad with spaces if the logger name is shorter than 20 characters. However, if logger name is longer than 30 characters, then truncate from the beginning.
%.-30logger NA none 30 Truncate from the end if the logger name is longer than 30 characters.

%d表示日期，
%thread: 表示线程名
%level：日志级别
%msg：日志消息
%logger: Java类名（含包名，这里设定了36位，若超过36位，包名会精简为类似a.b.c.JavaBean)
%line: Java类的行号

NEUTRAL使用

因为正常日志和错误异常日志是拆分成两个文件的，所以在appender=FILE中如果使用ThresholdFilter配置的level是最低阀值（一般是INFO）,
ERROR也会进入到sys.log中，这时需要将ERROR过滤掉，设置Match Error 直接DENY, Mismatch Error则Neutral中立继续走下面的filter。

环境变量的使用

这里配置了大量的环境变量，比如log.path（日志的路径），app.name（应用名称），log.root.level（日志root级别）等，
这些变量若在每个业务系统的本地，可以基于maven的profile filter resources进行变量替换即可，
但是当前的设计是想将logback.xml放在一个公共组件的jar包内, 这个maven是无法替换jar包内文件的内容的。引申出我们下面的实现。
（当然你可以使用一些maven plugin进行unzip,修改后再zip一把，实在太麻烦 >_<!）

<configuration>
    <!--<statusListener class="ch.qos.logback.core.status.NopStatusListener" />-->
    <jmxConfigurator/>
    
    <!-- 控制台输出 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>
                [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-36.36thread] [%-5level] [%-36.36logger{36}:%-4.4line] - %msg%n
            </pattern>
        </encoder>
    </appender>
    <!-- 按照每天生成日志文件 -->
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/${app.name}/sys.log</file>
        <!--拒绝ERROR日志-->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>DENY</onMatch>
            <onMisMatch>NEUTRAL</onMisMatch>
        </filter>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>${log.lowest.level}</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${log.path}/${app.name}/sys-%d{yyyy-MM-dd}-%i.log</FileNamePattern>
            <MaxHistory>90</MaxHistory>
            <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <MaxFileSize>10MB</MaxFileSize>
            </TimeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>
                [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-36.36thread] [%-5level] [%-36.36logger{36}:%-4.4line] - %msg%n
            </pattern>
        </encoder>
    </appender>
    <appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/${app.name}/sys-err.log</file>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${log.path}/${app.name}/sys-err-%d{yyyy-MM-dd}-%i.log</FileNamePattern>
            <MaxHistory>90</MaxHistory>
            <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <MaxFileSize>10MB</MaxFileSize>
            </TimeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-36.36thread] [%-5level] [%-36.36logger{36}:%-4.4line] - %msg%n
            </pattern>
        </encoder>
    </appender>

    <!-- show parameters for hibernate sql 专为 Hibernate 定制 -->
    <logger name="org.hibernate.type.descriptor.sql.BasicBinder"    additivity="true" level="${log.hibernate.level}" />
    <logger name="org.hibernate.type.descriptor.sql.BasicExtractor" additivity="true" level="${log.hibernate.level}" />
    <logger name="org.hibernate.SQL"                                additivity="true" level="${log.hibernate.level}" />
    <logger name="org.springframework"                              additivity="true" level="${log.spring.level}"/>
    <logger name="com.myown"                                        additivity="true" level="${log.root.level}"/>

    <!-- 日志输出级别 -->
    <root level="${log.root.level}">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE"/>
        <appender-ref ref="FILE-ERROR"/>
    </root>

</configuration>

2. web.xml 监听器的实现

上面logback.xml里设置了大量的环境变量，而这些环境变量都必须在Web应用启动之前设置完毕。
实现方式其实比较多：
a. 第一种： 设置JVM的启动参数 -Dlog.path=/logs/app/ -Dlog.root.level=INFO
b. 第二种：设置应用服务器的启动参数，比如tomcat，在bin文件夹下新增一个bat（windows)或者shell文件(linux)，命名为setenv.bat/sh,

setenv.bat内容:
set log.path=/usr/local/src/logs/test
set log.root.level=INFO
....

c. 第三种：前两种处理方式都有些不妥的地方就是，开发人员pull代码之后无法直接部署tomcat运行，还需要添加setenv文件，容易遗漏；
参数的设置不灵活：不能根据OS, 开发/测试/生产的环境变量动态调整log level或者log path。
（其实，在不同环境下的tomcat只要设定一次启动参数，业务应用日后的部署都是一劳永逸的, 不排除以后采用第二种方案 _）
现，决定，通过监听器来实现。

监听器示例代码如下：

public class LogbackListener implements ServletContextListener {
    @Override
    public void contextInitialized(ServletContextEvent event) {
        ServletContext sc = event.getServletContext();
        //添加系统属性示例代码
        if (org.apache.commons.lang3.SystemUtils.IS_OS_WINDOWS) {
           System.setProperty("log.path", "${CATALINA_HOME}" + SystemUtils.FILE_SEPARATOR + "logs");
        } else {//linux
           System.setProperty("log.path", "/logs");
        }

        if (isProductEnv) {
           System.setProperty("log.root.level", "INFO");
        } else {//非生产环境
           System.setProperty("log.root.level", "DEBUG");
        } 

        ..........................

        WebLogbackConfigurer.initLogging(sc);
    }

    @Override
    public void contextDestroyed(ServletContextEvent event){
        WebLogbackConfigurer.shutdownLogging(event.getServletContext());
    }
}

web.xml添加监听器配置，该监听器的配置尽量位于第一位，至少保证在其他有可能使用日志打印的监听器之前。

············
<!--logback日志环境变量配置-->
<listener>
    <listener-class>com.myown.framework.LogbackListener</listener-class>
</listener>
<!--Spring上下文-->
<listener>
    <listener-class>org.springframework.web.context.ContextLoaderListener</listener-class>
</listener>
············

3. TOMCAT + JNDI + Druid连接池的坑

因为某个核心系统期望能监控一下数据库连接方面的性能和请求情况，采用了开源连接池Druid, 在context.xml配置的jndi是这样的：

 <!--
 1. tomcat lib需添加mysql驱动 mysql-connector-java-5.1.38.jar
     2. 添加 druid-1.0.16.jar
 3. filter若使用log4j，tomcat lib需添加log4j.jar；若使用slf4j基于logback,需添加slf4j-api-1.7.13.jar
 -->     
<Resource 
     name="jndi/nicholas"
     factory="com.alibaba.druid.pool.DruidDataSourceFactory"
     auth="Container"
     type="javax.sql.DataSource"
     driverClassName="com.mysql.jdbc.Driver"
     url="jdbc:mysql://127.0.0.1:3306/nicholas?useUnicode=true&characterEncoding=utf-8"
     username="root" 
     password="root"
     initialSize="10"
     minIdle="10"
     maxActive="50"
     maxWait="10000"    
     timeBetweenEvictionRunsMillis="60000" 
     minEvictableIdleTimeMillis="300000"
     removeabandoned="true" 
     removeabandonedtimeout="180"
     logabandoned="true"
     filters="stat,wall,slf4j"/>

具体druid的配置和使用就不详谈，注意最后的filters 配置了slf4j, 它的实现是基于web应用配置的logback，请看下图首次进入LoggerContext的调用链情况。
其实此时的Tomcat启动优先加载了druid jndi连接池，而druid又需要打印日志，所以在我们的监听器初始化之前， logback的配置已经加载完毕了，而加载的logback.xml中的一堆变量都是undefined!
问题粗线了！现在看起来好像前面的第一种或者第二种方法才行得通了。。。这尼玛！

应用启动首次进入LoggerContext的堆栈信息

一个开源组件的依赖会带来如此不堪忍受的问题，这个事件的教训就是设计一个越基础的组件越要减少对其他组件的依赖，不然会有各种升级或者兼容层面的潜在隐患

目前本人的解决方案是在刚才的 LogbackListener 监听器中重置logback上下文！

  @Override
  public void contextInitialized(ServletContextEvent event) {

    //系统环境变量设置 System.setProperty()
    ..............
    LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
    //进入Web之前判断是否已加载了Logger，若已加载需要重置!
    if (loggerContext != null && loggerContext.getLoggerList().size() > 0) {
        //必须清空一下，否则之前加载的logger堆栈信息还保留着StatusPrinter.print会打印出之前的状态
        loggerContext.getStatusManager().clear();
        loggerContext.reset();
        ContextInitializer ci = new ContextInitializer(loggerContext);
        try {
            ci.autoConfig();
        } catch (JoranException e) {
            sc.log("-=-=-= Reset Logback status Failed =-=-=- \n" + ExceptionUtil.getStackTrace(e));
        }
    }

    WebLogbackConfigurer.initLogging(sc);
    StatusPrinter.print(loggerContext);
}

4. 默认赋值问题

某些情况下需要变量设置个默认值，以防出现比较恶心的 _IS_UNDEFINED 后缀（ log4j不存在的变量会留空）
只要使用" :- " 操作符即可(冒号+减号)。
比如 log.path 没有定义, 使用该变量的地方就会变成** log.path_IS_UNDEFINED**， 给他一个默认值

${log.path:-/var/logs/myapp}

5. 注意事项

Spring的WARN日志无法打印出来

检查spring是否exclude自带的commons-logging 即 jcl jar包，并同时添加 jcl-over-slf4j的jar包，将其适配给slf4j

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-core</artifactId>
    <version>${spring.version}</version>
    <exclusions>
        <exclusion>
            <groupId>commons-logging</groupId>
            <artifactId>commons-logging</artifactId>
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jcl-over-slf4j</artifactId>
</dependency>
Zookeeper/ZkClient等默认使用log4j的组件无法打印日志

需要exclude log4j包，并添加log4j-over-slf4j依赖 (注意 slf4j-log4j12 与 log4j-over-slf4j的环形依赖会导致异常)

<dependency>
        <groupId>com.github.sgroschupf</groupId>
        <artifactId>zkclient</artifactId>
        <version>0.1</version>
        <exclusions>
            <exclusion>
                <groupId>log4j</groupId>
                <artifactId>log4j</artifactId>
            </exclusion>
        </exclusions>
 </dependency>
 <!--zkClient和disconf都会依赖zookeeper,而zookeeper会依赖slf4j-log4j12和log4j,
 在我们使用logback的情况下，需要将log4j转为logback，则需依赖log4j-over-slf4j。
 slf4j-log4j12会与log4j-over-slf4j循环依赖导致冲突，
 所以所有依赖zookeeper的jar必须exclude掉slf4j-log4j12-->
<dependency>
    <groupId>org.apache.zookeeper</groupId>
    <artifactId>zookeeper</artifactId>
    <version>${zookeeper.version}</version>
    <exclusions>
        <exclusion>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
        </exclusion>
        <!--
        https://issues.apache.org/jira/browse/ZOOKEEPER-1371
        zookeeper Remove dependency on log4j in the source code.
        slf4j-log4j12会与log4j-over-slf4j循环依赖导致冲突
        -->
        <exclusion>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>log4j-over-slf4j</artifactId>
</dependency>
最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 201,681评论 5赞 474
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 84,710评论 2赞 377
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 148,623评论 0赞 334
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 54,202评论 1赞 272
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 63,232评论 5赞 363
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 48,368评论 1赞 281
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 37,795评论 3赞 393
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 36,461评论 0赞 256
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 40,647评论 1赞 295
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,476评论 2赞 317
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,525评论 1赞 329
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 33,226评论 3赞 318
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 38,785评论 3赞 303
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,857评论 0赞 19
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,090评论 1赞 258
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 42,647评论 2赞 348
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 42,215评论 2赞 341

推荐阅读更多精彩内容

  • Logback配置使用
    Log Java日志：（slf4j、log4j、logback、common-logging ） slf4j 是规...
    年少懵懂丶流年梦阅读 17,483评论 1赞 11
  • Log4j学习和总结
    在应用程序中添加日志记录总的来说基于三个目的：监视代码中变量的变化情况，周期性的记录到文件中供其他应用进行统计分析...
    时待吾阅读 4,915评论 1赞 13
  • slf4j+logback的配置及使用
    几种日志的区别 commons-loggingapache最早提供的日志的门面接口。避免和具体的日志方案直接耦合。...
    maxwellyue阅读 34,485评论 3赞 23
  • SLF4J Log4j Logback关系详解和相关用法
    写Java也有一段时间了，一直都有用slf4j log4j输出日志的习惯。但是始终都是抱着“拿来主义”的态度，复制...
    Minimumy阅读 1,371评论 1赞 7
  • 虚实
    湖光山色居远方，柴米油盐驻身旁。 遥望风景美如画，近观生活乱如麻。
    堯_212a阅读 209评论 2赞 0