Java高并发查看日志_高并发场景下,Java 日志的最佳应用实践

日志技术选型

Log 门面层选型

《阿里巴巴 Java 开发规范》【强制】应用中不可使用日志系统(Log4J、Logback)中的 API,而应依赖使用日志框架 SLF4J 中的 API。使用门面模式的日志框架,有利于维护和各个类的日志处理方式统一。

上面所说的是阿里 Java 开发规范中的规则,应用必须使用门面模式的日志框架,首选我们回顾一下门面设计模式。

门面模式,又叫外观模式,它为子系统中的一组接口提供一个统一的高层接口,使的子系统更容易使用。使用门面模式的优点是:

解耦,通过统一对外的接口,屏蔽了与子系统的依赖和子系统的复杂性。

提高了灵活性,子系统内部的变化,只要不影响到门面对象,任其变化。其结构见下图。

fddb72730d90

image.png

通过上面的回顾,我们也了解了门面设计模式。应用使用门面模式的日志框架,可以部署时,根据需要切换不同的日志框架。Java 中有哪些门面模式的日志框架呢?常见的有 Apache Common-Logging、SLF4J。

Commons Logging 实现机制:

Apache Common-Logging 使用了 ClassLoader 寻找和载入底层的日志库,存在一定加载问题。

SLF4J 实现机制:

SLF4J 在编译期间,静态绑定本地的 Log 库。它是通过查找类路径下 org.slf4j.impl.StaticLoggerBinder,然后在 StaticLoggerBinder 中进行绑定。使用 SLF4J 时,需要指定具体的日志器实现,常用的 Log4j、Log4j2、Logback、JDK-logging、SLF4J-simple 都可以实现,对于不同的日志实现方案,封装出不同的桥接组件。下图是 SLF4J 与各组件 API 打通的的相关方案。

fddb72730d90

image.png

门面框架的选择:

考虑到 SLF4J 的广泛通用性及静态编译支持,门面层使用 SLF4J 作为日志 API 层选型。

日志引擎层技术选型

下图是各个日志框架性能测试如下(来自 Log4j2 官方网站):

fddb72730d90

image.png

下图是 garbage-free async loggers (无垃圾异步模式)在测试的所有配置中都具有最佳响应 time 行为。

fddb72730d90

image.png

根据以上数据显示,Log4j2 通过异步化支持及队列的使用使性能得到的极大的提升。这是如何工作的,应用线程完成了最少量的工作来捕获 log event 中的所有必需信息,然后将此 log event 放在队列中以供后续线程稍后处理。如果队列的大小足够大,那么应用线程应该能够在 logging 调用上花费很少的 time,并且非常快速地返回到业务逻辑。

事实证明,队列的选择对于峰值吞吐量非常重要。 Log4j2 的 Async Loggers 使用无锁数据结构(Disruptor),而 Logback、Log4j 1.2 和 Log4j2 的异步 Appenders 使用 ArrayBlockingQueue。使用阻塞队列时,对线程应用在尝试将 log event 排入队列时经常会遇到锁争用。所以 Log4j2 的 Async Loggers 在一定程度上提供更好的吞吐量,但是一旦队列已满,appender 线程需要等待,直到队列中的一个插槽可用,并且吞吐量将降至最大最好的基础 appenders 的持续吞吐量。

并且 Log4j2 改版以后,组件和功能极大丰富,有兴趣的同学可以去官网:

日志引擎框架的选择:

经过上述的分析,所以在日志引擎层毫无疑问选用 Log4j2 是最佳选择。

Log4j2 简介

关于 Log4j2

Apache Log4j 2 是 Log4j 1 的继任者,2014 年 7 月其 GA 版本(正式发布版)发布。该框架被从头重写,并从现有的日志解决方案中获得灵感(包括 Log4j 1 和 JUL)。该版本与 Log4j 1 的主要差异是:

改进的配置语法。

支持 XML 和 JSON 配置。

改进的过滤器。

属性(Property)支持。

标记。

提高速度。

模块化,Log4j 2 支持插件系统。

提高了可靠性。

配置自动重装。

Log4j 2 的最被认可的特点之一是“异步记录器”的性能。Log4j 2 利用了 LMAX Disruptor。例如,在相同的环- 境下,Log4j 2 可以写每秒超过 18,000,000 条信息,而其他框架(像 Logback 和 Log4j 1)每秒只能写< 2,000,000 条消息。

Log4j 2 提供对 SLF4J、Commons Logging、Apache Flume 和 Log4j 1 的支持。

异步 Loggers

异步是 Log4j2 最大的亮点,性能提升的关键,应用无锁模式(Disruptor)实现。在实践中,官方推荐使用 Async Logger 的全异步方式,进行异步日志的配置。唯一的缺点就是如果异常可能不能通知给应用程序,这一点根据实际情况处理。

Garbage-free Logging

许多 logging libraries,包括以前版本的 Log4j,在稳定 state logging 期间分配临时 objects,如 log event objects、Strings、char 数组、字节数组等。这会对垃圾收集器造成压力并增加 GC 暂停发生的频率。

从 version 2.6 开始,默认情况下 Log4j 以“无垃圾”模式运行,其中重复使用 objects 和 buffers,并且尽可能不分配临时 objects,原理是通过 ThreadLocal 实现复用。

Spring Boot 集成 Log4j2

Maven 配置

首先剔除 Spring Boot 自带的 Logback 配置、加入 Log4j2 starter 和异步依赖的 disruptor 配置。

org.springframework.boot

spring-boot-starter

org.springframework.boot

spring-boot-starter-logging

org.springframework.boot

spring-boot-starter-log4j2

com.lmax

disruptor

3.4.2

org.springframework.boot

spring-boot-starter-web

org.springframework.boot

spring-boot-starter-aop

com.alibaba

fastjson

1.2.68

日志格式很重要,在微服务中,经常会用到 elk 等组件来收集日志,统一查询。为了方便查找问题,定位问题,我们实践中最佳的输出格式如下:

[机器 IP 地址] | [线程 ID] | [微服务名] | [时间] | [日志级别] | [包名] | [日志信息]

数据项

收集方式

配置方式

机器 IP 地址

在应用启动时通过 MDC 注入本机 IP 如:MDC.put("ip", "129.12.31.1");

%X{ip}

线程 ID

日志组件自动收集

%t

微服务名

在应用启动时通过 MDC 注入服务名 如:MDC.put("serverName",”user-center“);

%X{serverName}

时间

组件自动收集

%d{yyyy-MM-dd HH:mm:ss,SSS}

日志级别

配置

%p

包名

组件自动收集

%c

日志信息

程序输出 如:log.info()

%m

Log4j2 配置文件在 resource 下生成 log4j2.xml。

内容如下,实际使用中根据情况修改:

./logs

UTF-8

%X{ip}|%t|%X{serverName}|%d{yyyy-MM-dd HH:mm:ss,SSS}|%p|%c|%m%n

fileName="${logPath}/error.log"

filePattern="${logPath}/error.%d{yyyy-MM-dd}.gz"

ignoreExceptions="false">

fileName="${logPath}/warn.log"

filePattern="${logPath}/warn.%d{yyyy-MM-dd}-%i.gz"

ignoreExceptions="false">

fileName="${logPath}/info.log"

filePattern="${logPath}/info.%d{yyyy-MM-dd}-%i.gz"

ignoreExceptions="false">

然后在 application.properties 指定 Log4j2 的配置文件,如下:

logging.config=classpath:log4j2.xml

配置日志为全异步方式,在 resource 下创建 log4j2.component.properties 文件,内容如下,开启全异步模式:

Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

配置文件结构如下图:

fddb72730d90

image.png

主程序通过 MDC 方式注入 IP 和 serverName:

public class DemoApplication {

public static void main(String[] args) {

initMainThreadLogProperties();

SpringApplication.run(DemoApplication.class, args);

}

private static void initMainThreadLogProperties() {

PropertiesUtil propertiesUtil;

try {

propertiesUtil = new PropertiesUtil("application.properties");

MDC.put("ip", getLocalIp());

MDC.put("serverName", getServerName());

} catch (Exception e) {

e.printStackTrace();

}

}

}

业务线程通过 Filter 的方式注入 IP 和 serverName:

@Order(1)

@WebFilter(filterName = "logFilter", urlPatterns = "/*")

public class LogFilter implements Filter {

@Value("${spring.application.name}")

private String serverName;

@Override

public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {

HttpServletRequest request = (HttpServletRequest) servletRequest;

MDC.put("ip", request.getLocalAddr());

MDC.put("serverName", serverName);

filterChain.doFilter(servletRequest, servletResponse);

}

}

通过 AOP 打印入参、出参、和接口耗时信息:

@Aspect

@Order(5)

@Component

@Slf4j

public class LogAspect {

@Pointcut("execution(public * com.example.demo.controller..*(..))")

public void weblog() {

}

/**

* 请求执行过程 记录 ip、入参、出参、耗时

*

* @param joinPoint

*/

@Around("weblog()")

public Object aroundAdvice(ProceedingJoinPoint joinPoint) throws Throwable {

Object[] args = joinPoint.getArgs();

HttpServletRequest request = getRequestContext();

StopWatch stopWatch = new StopWatch();

stopWatch.start();

try {

Object result = joinPoint.proceed(args);

stopWatch.stop();

if (log.isInfoEnabled()) {

log.info("client_ip={},url={} ,cost_time={}ms,args={},result={}", request.getRemoteAddr(),

request.getRequestURL().toString(), stopWatch.getTotalTimeMillis(), JSON.toJSONString(args), JSON.toJSONString(result));

}

return result;

} catch (Throwable e) {

log.error("client_ip={},url={} ,cost_time={}ms,,args={}", request.getRemoteAddr(),

request.getRequestURL().toString(), stopWatch.getTotalTimeMillis(), JSON.toJSONString(args), e);

throw e;

}

}

/**

* 获取 HttpServletRequest

*

* @return

*/

private HttpServletRequest getRequestContext() {

ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();

HttpServletRequest request = attributes.getRequest();

return request;

}

}

以上就是日志集成的一个最佳实践,我把具体的 Demo 上传到 GitHub 上了,感兴趣的朋友可以下载下来,里面的 Demo 都可以直接运行,Demo 里还包括接口统一异常处理和日志打印的处理。地址:

高并发场景下

日志打印的的正确姿势

// 传统的字符串产生方式,如果没有要记录 Debug 等级的信息,就会浪费时间在产生不必要的信息上

logger.debug("There are now " + count + " user accounts: " + userAccountList);

// 为了避免上述问题,我们可以先检查是不是开启了 Debug 信息记录功能,只是程序的编码会比较复杂

if (logger.isDebugEnabled()) {

logger.debug("There are now " + count + " user accounts: " + userAccountList);

}

//应用占位符的方式, 如果 Debug 等级没有开启,则不会产生不必要的字符串,同时也能保持程序编码的简洁

logger.debug("There are now {} user accounts: {}", count, userAccountList);

如上述第一行代码,如果日志级别是 WARN 级别,虽然 logger.debug 不会输出日志,但还会进行字符串拼接,并发量大的时候存在性能问题。为了避免这个问题可以先检查是否开启了 Debug 级别,可以通过这个 logger.isDebugEnabled() 方法,但这样会使编码比较复杂,代码不够简洁。在这里推荐上述代码中的第三中方式,占位符方式,这种方式即使没有开启 Debug 登记,也不会产生不必要的字符串拼接等操作,也能保持代码的简洁性。

高并发场景下,一定要用异步和缓冲模式来打印日志,同步方式会造成大量系统文件 IO 操作,导致应用并发上不去,甚至挂掉。记得多年前,当时配置日志,只会从网上 copy 一份修改一下,里面的参数并不清楚是什么作用,不知道读者是不是也会这样。所以配置日志的时候,一定要非常清楚各个参数的意义,如果不清楚,建议去官方看一看。

分布式系统日志链路跟踪方案与原理

随着系统的微服务化,一次业务接口的调用可能需要多个微服务间协同调用来完成。那如何直观的了解系统的调用及运行情况呢。可以在业务日志中增加调用链 ID, 把业务日志和调用链关联起来,可以方便查看一次业务接口调用相关的所有日志信息,方便定位问题。

如何在日志中埋入调用链 ID 呢?

两种方式,一是客户端发送请求时生成调用链 Id(TraceId),二是服务端调用的首节点负责生成。生成方式可以通过 UUID 等方式。然后通过线程上下文(ThreadLocal)传递 TraceId,跨节点时,通过 RPC 框架或 HTTP 通过传参显示的传到下一节点。

如果使用 MQ 异步操作时怎么办呢?

各位小伙伴可以自己想一想。这是我们自己实现日志追踪的方案,有些代码的侵入,那有没有更方便的呢?答案肯定是有的,那就是 JavaAgent 技术,如阿里开源的 SkyWalking 分布式追踪系统,通过动态字节码技术,无侵入的实现服务之间的追踪,并提供 UI 界面查看调用链情况,非常方便,感兴趣的可以深入研究。

结束语

希望上述写的,能在实际项目中帮到你,感兴趣的可以深入了解日志中应用到的技术,我在结尾附上,我觉得写的不错的博客,大家也可以去看一看。欢迎留言讨论。

关于 Disruptor:

关于 MDC:

关于 ThreadLocal:

关于 SkyWalking:

已标记关键词 清除标记
表情包
插入表情
评论将由博主筛选后显示,对所有人可见 | 还能输入1000个字符
相关推荐
©️2020 CSDN 皮肤主题: 深蓝海洋 设计师:CSDN官方博客 返回首页