Java日志记录的事儿

一、java日志组件

1、common-logging

common-logging是apache提供的一个通用的日志接口。用户可以自由选择第三方的日志组件作为具体实现,像log4j,或者jdk自带的logging, common-logging会通过动态查找的机制,在程序运行时自动找出真正使用的日志库。但由于它使用了ClassLoader寻找和载入底层的日 志库, 导致了象OSGI这样的框架无法正常工作,由于其不同的插件使用自己的ClassLoader。 OSGI的这种机制保证了插件互相独立,然而确使Apache Common-Logging无法工作。当然,common-logging内部有一个Simple logger的简单实现,但是功能很弱。所以使用common-logging,通常都是配合着log4j来使用。使用它的好处就是,代码依赖是common-logging而非log4j, 避免了和具体的日志方案直接耦合,在有必要时,可以更改日志实现的第三方库。

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;  

public class A {
    private static Log logger = LogFactory.getLog(this.getClass());
}

动态查找原理:Log 是一个接口声明。LogFactory 的内部会去装载具体的日志系统,并获得实现该Log 接口的实现类。LogFactory 内部装载日志系统的流程如下:

首先,寻找org.apache.commons.logging.LogFactory 属性配置。

否则,利用JDK1.3 开始提供的service 发现机制,会扫描classpah 下的META-INF/services/org.apache.commons.logging.LogFactory文件,若找到则装载里面的配置,使用里面的配置。

否则,从Classpath 里寻找commons-logging.properties ,找到则根据里面的配置加载。

否则,使用默认的配置:如果能找到Log4j 则默认使用log4j 实现,如果没有则使用JDK14Logger 实现,再没有则使用commons-logging 内部提供的SimpleLog 实现。

从上述加载流程来看,只要引入了log4j 并在classpath 配置了log4j.xml ,则commons-logging 就会使log4j 使用正常,而代码里不需要依赖任何log4j 的代码。

2、slf4j

slf4j全称为Simple Logging Facade for JAVA,java简单日志门面。类似于Apache Common-Logging,是对不同日志框架提供的一个门面封装,可以在部署的时候不修改任何配置即可接入一种日志实现方案。但是,他在编译时静态绑定真正的Log库。使用SLF4J时,如果你需要使用某一种日志实现,那么你必须选择正确的SLF4J的jar包的集合(各种桥接包)。

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

public class A {
    private static Log logger = LogFactory.getLog(this.getClass());
}

slf4j静态绑定原理:SLF4J 会在编译时会绑定import org.slf4j.impl.StaticLoggerBinder; 该类里面实现对具体日志方案的绑定接入。任何一种基于slf4j 的实现都要有一个这个类。如:org.slf4j.slf4j-log4j12-1.5.6: 提供对 log4j 的一种适配实现。注意:如果有任意两个实现slf4j 的包同时出现,那么就可能出现问题。

slf4j 与 common-logging 比较

common-logging通过动态查找的机制,在程序运行时自动找出真正使用的日志库。由于它使用了ClassLoader寻找和载入底层的日志库, 导致了象OSGI这样的框架无法正常工作,因为OSGI的不同的插件使用自己的ClassLoader。 OSGI的这种机制保证了插件互相独立,然而却使Apache Common-Logging无法工作。

slf4j在编译时静态绑定真正的Log库,因此可以再OSGI中使用。另外,SLF4J 支持参数化的log字符串,避免了之前为了减少字符串拼接的性能损耗而不得不写的if(logger.isDebugEnable()),现在你可以直接写:logger.debug(“current user is: {}”, user)。拼装消息被推迟到了它能够确定是不是要显示这条消息的时候,但是获取参数的代价并没有幸免。

Object[] params = {value1, value2, value3};

logger.debug("first value: {}, second value: {} and third value: {}.", params);

3、log4j

Apache的一个开放源代码项目,通过使用Log4j,我们可以控制日志信息输送的目的地是控制台、文件、GUI组件、甚至是套接口服务 器、NT的事件记录器、UNIX Syslog守护进程等;用户也可以控制每一条日志的输出格式;通过定义每一条日志信息的级别,用户能够更加细致地控制日志的生成过程。这些可以通过一个 配置文件来灵活地进行配置,而不需要修改程序代码。

4、logback

Logback是由log4j创始人设计的又一个开源日记组件。logback当前分成三个模块:logback-core,logback- classic和logback-access。logback-core是其它两个模块的基础模块。logback-classic是log4j的一个 改良版本。此外logback-classic完整实现SLF4J API使你可以很方便地更换成其它日记系统如log4j或JDK14 Logging。logback-access访问模块与Servlet容器集成提供通过Http来访问日记的功能。

    Log4j 与 LogBack 比较

LogBack作为一个通用可靠、快速灵活的日志框架,将作为Log4j的替代和SLF4J组成新的日志系统的完整实现。LOGBack声称具有极佳的性能,“ 某些关键操作,比如判定是否记录一条日志语句的操作,其性能得到了显著的提高。这个操作在LogBack中需要3纳秒,而在Log4J中则需要30纳秒。 LogBack创建记录器(logger)的速度也更快:13微秒,而在Log4J中需要23微秒。更重要的是,它获取已存在的记录器只需94纳秒,而 Log4J需要2234纳秒,时间减少到了1/23。跟JUL相比的性能提高也是显著的”。 另外,LOGBack的所有文档是全面免费提供的,不象Log4J那样只提供部分免费文档而需要用户去购买付费文档。

使用slf4j+logback的优势:

  • 支持按文件大小或基于时间的切分方式,可自定义命名模式
  • 支持文件打包(触发器方式)
  • 支持OSGI环境

如果在单纯的logging环境中,使用SLF4J意义不大。如果想在各种logger API中切换,SELF4J是理想选择,另外在新的项目中,使用SLF4J+Logback是比较好的日志框架选型。

logback.xml的配置

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- log output to file -->
    <appender name="ROLLING"
        class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 按天回滚 daily -->
            <!-- log.dir 在maven profile里配置 -->
            <fileNamePattern>${ms.log.home}/ms-api-%d{yyyy-MM-dd}.log
            </fileNamePattern>
            <!-- 日志最大的历史 7天 -->
            <maxHistory>7</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} [%file:%line] - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="API_QUERY_MONITOR"
        class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 按天回滚 daily -->
            <!-- log.dir 在maven profile里配置 -->
            <fileNamePattern>${ms.log.home}/ms-api-query-%d{yyyy-MM-dd}.log
            </fileNamePattern>
            <!-- 日志最大的历史 7天 -->
            <maxHistory>2</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} [%file:%line] - %msg%n</pattern>
        </encoder>
    </appender>
    <!-- log output to console -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36}[%file:%line] - %msg%n</pattern>
        </encoder>
    </appender>

    <!-- Perf4J appenders -->
    <!-- This AsyncCoalescingStatisticsAppender groups StopWatch log messages
        into GroupedTimingStatistics messages which it sends on the file appender
        defined below -->

    <!-- This file appender is used to output aggregated performance statistics -->
    <appender name="perf4jFileAppender"
        class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>${ms.log.home}/ms-performance.log</File>
        <encoder>
            <!-- <Pattern>%date %-5level [%thread] %logger{36} [%file:%line] %msg%n
                </Pattern> -->
            <Pattern>%date %-5level [%file:%line] %msg%n</Pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${ms.log.home}/ms-performance.%d{yyyy-MM-dd}.log
            </FileNamePattern>
            <maxHistory>2</maxHistory>
        </rollingPolicy>
    </appender>

    <appender name="CoalescingStatistics"
        class="org.perf4j.logback.AsyncCoalescingStatisticsAppender">
        <param name="TimeSlice" value="60000" />
        <appender-ref ref="perf4jFileAppender" />
    </appender>

    <!-- Loggers -->
    <!-- The Perf4J logger. Note that org.perf4j.TimingLogger is the value of
        the org.perf4j.StopWatch.DEFAULT_LOGGER_NAME constant. Also, note that additivity
        is set to false, which is usually what is desired - this means that timing
        statements will only be sent to this logger and NOT to upstream loggers. -->
    <logger name="org.perf4j.TimingLogger" additivity="false">
        <level value="INFO" />
        <appender-ref ref="CoalescingStatistics" />
    </logger>

    <logger name="com.wy.api.out.OutApi" level="debug">
        <appender-ref ref="ROLLING" />
    </logger>
    <logger name="com.wy.util.PlayerDataUtil" level="info">
        <appender-ref ref="ROLLING" />
    </logger>
    <logger name="com.wy.QueryServiceImpl" level="info">
        <appender-ref ref="REMOTE_QUERY_MONITOR" />
    </logger>
    <root level="info">
        <appender-ref ref="ROLLING" />
    </root>
</configuration>

二、如何记录日志

1、日志级别

在记录日志时,大家都会要选择合理的日志级别、合理的控制日志内容。我们都知道debug级别日志在生产环境中是不会输出到文件中的,但是也可能带来不小的开销。我们看下Log4j2.x性能文档中一组对比:

logger.debug("Entry number: " + i + " is " +  String.valueOf(entry[i]));
logger.debug("Entry number: {} is {}", i, entry[i]);

上面两条语句在日志输出上的效果是一样的,但是在关闭DEBUG日志时,它们的开销就不一样了,主要的影响在于字符串转换和字符串拼接上,无论是否生效,前者都会将变量转换为字符串并进行拼接,而后者则只会在需要时执行这些操作。Log4J官方的测试结论是两者在性能上能相差两个数量级。试想一下,如果某个对象的toString()方法里用了ToStringBuilder来反射输出几十个属性时,这时能省下多少资源。

因此,某些仍在使用Apache Commons Logging(它们不支持{}模板的写法)、Log4J 1.x或LogBack时,采用模版的方式。

2、日志内容

日志中一般都会记录日期、线程名、类信息、MDC变量、日志消息等等,根据Takipi的测试,如果在日志中加入class,性能会急剧下降,比起LogBack的默认配置,吞吐量的降幅在6成左右。如果一定要打印类信息,可以考虑用类名来命名Logger。

在分布式系统中,一个请求可能会经过多个不同的子系统,这时最好生成一个UUID附在请求中,每个子系统在打印日志时都将该UUID放在MDC里,便于后续查询相关的日志。

3、Appender

同步写的Appender在高并发大流量的系统里多少有些力不从心,这时就该使用AsyncAppender了,同样是使用LogBack:

在10线程并发下,输出200字符的INFO日志,AsyncAppender的吞吐量最高能是FileAppender的3.7倍。在不丢失日志的情况下,同样使用AsyncAppender,队列长度对性能也会有一定影响。

如果使用Log4J 2.x,那么除了有AsyncAppender,还可以考虑性能更高的异步Logger,由于底层用了Disruptor,没有锁的开销,性能更为惊人。根据Log4J 2.x的官方测试,同样使用Log4J 2.x:

64线程下,异步Logger比异步Appender快12倍,比同步Logger快68倍。

同样是异步,不同的库之间也会有差异:

同等硬件环境下,Log4J 2.x全部使用异步Logger会比LogBack的AsyncAppender快12倍,比Log4J 1.x的异步Appender快19倍。

如果一定要用同步的Appender,那么可以考虑使用ConsoleAppender,然后将STDOUT重定向到文件里,这样大约也能有10%左右的性能提升。

Log4J 2.x的异步Logger性能强悍,但也有不同的声音,觉得这只是个看上去很优雅,只能当成一个玩具。关于这个问题,还是留给读者自己来思考吧。

如何记录线程名称

往往日志中线程名称大部分类似 “http-nio-8080-exec-3″,这个是线程池或者容器给它们取的。线程名称是你日志中主要标记,你必须确保正确地使用它。这就意味着给线程取的名称必须结合上下文,例如servlet的名称或者任务此刻的意义,还有一些动态的上下文环境,例如一个用户或消息ID。与logid有异曲同工之妙,下文中会有说明。

因此,代码的入口处应该像下面这样:

Thread.currentThread().setName(ProcessTask.class.getName() + “: “+ message.getID);

一个更高级的写法是加载一个线程本地变量到当前线程中,并且配置一个自定义日志(appender),自动把这个变量加入到每一条日志记录中

分布式标识

在分布式的服务中,当我们的一个服务执行,可能会跨越多个服务。一旦服务执行失败了我们要知道是哪个环节出了问题。很多日志分析工具可以帮你进行日志归类,前提是你日志中带有它们可以用来做分类的唯一ID。(校对注:当A应用调用B应用接口时,而B应用的接口实现又需要调用应用C的接口时,一旦报错很难定位这个请求到底是在调用哪个应用时报错的?所以就使用一个唯一ID把这个请求链路串起来。)

这意味着每一个操作进入到你的系统中都应该有一个唯一的ID,用这个ID直到它执行完成。注意,那些持久化标示符,例如用户的ID在这里可能不是很好的选择,因为一个用户可能有多个操作发生在同一个日志中,这会使得隔离出一个特定的操作流变得更难。UUID在这边是一个很好的选择,这个值可以被作为线程的名称或者作为一个TLS-线程本地存储。

捕获外部调用

很多情况下,外部API调用失败的原因是提供的入参是未预知的。把那些输入参数现成的记录在日志中是你修复代码的关键。

这个点上你可能会选择不记录错误日志,但是必须记录抛出的异常,这是对的。在这种情况下,只需要尽可能多的收集传递给调用的相关参数,并且把他们格式化到异常错误信息中。

只需要却表异常被捕获,并且和调用栈一起被高日志级别记录。

try {
    return s3client.generatePresignedUrl(request);
} catch (Exception e) {
    String err = String.format(“Error generating request: %s bucket: %s key: %s. method: %s", request, bucket, path, method);
    log.error(err, e); //you can also throw a nested exception here with err instead.
}
时间: 2025-01-04 07:23:14

Java日志记录的事儿的相关文章

Java日志记录的5条规则

日志记录是在软件开发过程中常常需要考虑的关键因素. 当产品运行出错时,日志文件通常是我们进行错误分析的首要选择. 而且,在很多情况下,它们是我们手上唯一可以用来查明发生状况和问题根本原因的信息. 可见,正确记录需要的信息是极其重要的. 以下5条日志规则,让我们可以检查和改进在代码中操作日志记录的方式. 同时也请注意,我们既不会讨论怎么配置一个日志引擎,也不会相互比较. 规则1.日志是面向读者的 日志消息不仅要对书写(日志)代码的人有意义,也应该对日志文件的读者有意义. 这似乎是一条很明显但却经常

Java日志记录工具SLF4J介绍

SLF4J是什么 SLF4J是一个包装类,典型的facade模式的工具,对用户呈现统一的操作方式,兼容各种主流的日志记录框架,典型的有log4j/jdk logging/nop/simple/jakarta commons logging等. 有张图比较形象直观的展示这个知识: 下面给出几个maven配置的例子 logback-classic <dependency>   <groupId>ch.qos.logback</groupId>  <artifactId

java日志记录之Logger.getLogger()和LogFactory.getLog()的区别

最近研究项目代码时发现同一个项目用到关于日志的两种不同写法: Logger.getLogger()和LogFactory.getLog()的区别 1.Logger.getLogger()是使用log4j的方式记录日志:API文档 2.LogFactory.getLog()则来自apache的common-logging包.API文档 根据不同的性质,日志信息通常被分成不同的级别,从低到高依次是:"调试( DEBUG )""信息( INFO )""警告( W

Java 日志框架终极教程

概述 对于现代的 Java 应用程序来说,只要被部署到真实的生产环境,其日志的重要性就是不言而喻的,很难想象没有任何日志记录功能的应用程序被运行于生产环境中.日志 API 所能提供的功能是多种多样的,包括记录程序运行时产生的错误信息.状态信息.调试信息和执行时间信息等.在生产环境中,日志是查找问题来源的重要依据,应用程序运行时的产生的各种重要信息,都应该通过日志 API 来进行记录. 很多Java开发人员习惯于使用 System.out.println.System.err.println 以及

Java学习-007-Log4J 日志记录配置文件详解及实例源代码

此文主要讲述在初学 Java 时,常用的 Log4J 日志记录配置文件详解及实例源代码整理.希望能对初学 Java 编程的亲们有所帮助.若有不足之处,敬请大神指正,不胜感激!源代码测试通过日期为:2015-1-30 13:54:02,请知悉. 所需的 jar 包下载链接为:http://yunpan.cn/cKE56sxqtQCfP  访问密码 63d8 有关 Log4J 日志文件中日志级别及文件配置的详细情况,在 Log4J 的配置文件(xml.properties)中有详细的介绍,敬请参阅!

日志记录的作用和方法 java

程序中记录日志一般有两个目的:Troubleshooting和显示程序运行状态.好的日志记录方式可以提供我们足够多定位问题的依据.日志记录大家都会认为简单,但如何通过日志可以高效定位问题并不是简单的事情.这里列举下面三个方面的内容,辅以代码示例,总结如何写好日志,希望对他人有所启发和帮助: 怎样记日志可以方便Troubleshooting 程序运行状态可以记哪些 应该避免怎样的日志方式 怎样记日志可以方便Troubleshooting? 1. 对外部的调用封装 程序中对外部系统与模块的依赖调用前

JAVA实现通用日志记录

原文:http://blog.csdn.net/jinzhencs/article/details/51882751 前言: 之前想在filter层直接过滤httpServerletRequest请求进行日志处理,但是之后再getWriter()的 时候报 already been call异常.查了下,才发现原来流形式的只能读取一次..就好像食物,吃了就没了.. 所以在filter和inteceptor里面是没法通过获取request的流来进行日志记录的. 于是还是准备用通用的方法:contr

java动态代理详解,并用动态代理和注解实现日志记录功能

动态代理的概念 动态代理是程序在运行过程中自动创建一个代理对象来代替被代理的对象去执行相应的操作,例如, 我们有一个已经投入运行的项目中有一个用户DAO类UserDao用来对User对象进行数据库的增删改查操作,但是有一天,要求在对用户的增删改查操作时记录相应的日志,这是怎么办呢?难道我们去直接修改UserDao的源代码,然后在UserDao的每个方法中加入日志记录功能,这显然是不合理的,它违背了java的OCP原则,即对修改关闭对扩张开放.比如改现有的代码如下: 接口类 public inte

java Web应用配置log4j日志记录

第一步:首先建立一个WEB工程,去log4j官网下log4j的JAR包导入到工程的lib目录下 第二步:在src目录下建一个log4j.properties 文件,文件命名可以由自己,只是记加载时候和这里名字一致就行: log4j.properties  里边的内容如下: ### set log levels ### log4j.rootLogger = debug,stdout,E log4j.appender.stdout = org.apache.log4j.ConsoleAppender