这么香的日志动态级别与输出,你肯定不进来看看?——生产环境动态输入日志级别、文件

本文是一个系列,欢迎关注更新html

本文全篇高能,请作好心理准备后再食用,读完请记得点赞java

前言

上一篇咱们讨论了日志的性能以及日志的优缺点,有朋友说我没有干货,痛定思痛,决定来一篇干货,让小伙伴们见识一下员外真正的实力💪,讨论一下生产环境如何动态按一次请求、一个用户来调整日志级别,甚至输出独立文件。本文代码较多,建议读者运行一下。git

设想一个需求:客服妹妹反馈有用户线上发现了BUG,你拿来日志分析,一个 200M 的日志文件看的头大,最后仍是没找到有用的信息,你终于决定开启 DEBUG 日志,重启了项目,让用户再次操做一下,结果开了两分钟线上磁盘就告警了,因而你被运维人员痛批一顿,由于停生产环境又被 BOSS 大批一顿。github

试着给本身当一下产品经理,提些需求:数据库

  • 先定一个小目标,咱们能不能不停机就动态调整级别?
  • 咱们能不能将某一个用户甚至一次请求动态调整日志级别?
  • 让咱们进入强者的世界,不只仅要按照用户动态级别,是否能按照用户、请求临时输出一个文件?

整理了以上需求,咱们来尝试逐一解决。vim

实战一 动态调整日志级别(小目标实现)

这个需求很简单,想必你们也都会,Logback 和 Log4j2 都原生实现了日志监控日志文件热加载,使用起来也特别简单,只须要在配置文件中修改,固然,框架做者为了混(e)淆(xin)使用者,使用了不同的配置方式:缓存

<!-- logback 配置 -->
<configuration scan="true" scanPeriod="30 seconds" > 
  ...
</configuration> 

<!-- log4j2 配置 -->
<Configuration monitorInterval="30">
...
</Configuration>

实战二 更厉害的动态调整日志输出级别

如此简单的实现,不能很好知足咱们的需求,咱们决定再接再砺,毕竟咱们是有追求的人。服务器

咱们来分解一下问题:微信

  • 想要根据用户来动态级别,咱们确定要区分出用户;
  • 想要根据请求来区分日志级别,咱们须要识别请求;
  • 想要动态调整日志级别,咱们须要分析日志框架的实现;

咱们来逐一解决问题:session

  • 区分用户,还须要分解问题,主流 Web 项目有两种,老项目会使用 Session,新项目多使用 Token:
  • Session :Session 比较方便,放入 Session 一个日志级别便可。
  • Token : Token 也不复杂,提供一种解决方案,能够将 Token 放入到缓存,好比 Redis、数据库来存储(不推荐存数据库)。
  • 区分请求:
  • 给用户提供按钮,配合单页面应用,将全部 HTTP 请求附带一个参数,此方法危险,不适合互联网项目。
  • 特殊需求,在开发过程当中编码写入代码中。

区分用户最佳实践,给管理员开放功能,列出在线用户,点击用户便可选择用户输出的日志级别。

  • 动态调整日志级别,这个是咱们最棘手的地方,分析Logback API 会发现 ch.qos.logback.classic.Logger已经提供了#setLevel方法,这个方法看似可以在运行过程当中改变日志的输出级别,可是读过我以前文章的小伙伴确定知道,Logger 实例建议static final,因此Logger实例是多线程共享的,若是咱们修改了Logger的级别,确定会污染其余请求乃至其余用户,看来这样是行不通了,如何解决?

    没办法时只有两条路线,阅读源码以及翻阅文档,咱们先从源码入手,咱们先来分析一下Logback是如何决定是否输出一条日志的:

    咱们随便输出一条日志log.debug("A debug Log");,断点跟进去,发现真正的判断逻辑在filterAndLog_0_Or3Plus,源码以下:

    private void filterAndLog_0_Or3Plus(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params, final Throwable t) { // 神奇的方法
    final FilterReply decision = loggerContext .getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t); // 若是上面神奇的方法返回 NEUTRAL 才判断日志级别
    if (decision == FilterReply.NEUTRAL) { if (effectiveLevelInt > level.levelInt) { return; } // 返回 DENY 根本就不判断日志级别了
    } else if (decision == FilterReply.DENY) { return; } // 若是可以执行到这里,则输出日志
    buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t); }
     

    分析源码咱们得出结论,神奇的方法返回值优先级要高于日志级别判断,这样就有意思了,咱们能不能定制那个神奇方法呢,继续跟进去发现,TurboFilterList继承了CopyOnWriteArrayList<TurboFilter>,其自己就是一个List,其中的TurboFilterList#getTurboFilterChainDecision里面逻辑就是循环本身获取FilterReply而后返回,一块儿看一下代码:

    public FilterReply getTurboFilterChainDecision(final Marker marker, final Logger logger, final Level level, final String format, final Object[] params, final Throwable t) { final int size = size(); // 若是只有一个,直接返回结果,期间若是异常直接返回 NEUTRAL // size不多是0,由于调用者已经判断了,这里再也不展现
    if (size == 1) { try { TurboFilter tf = get(0); return tf.decide(marker, logger, level, format, params, t); } catch (IndexOutOfBoundsException iobe) { return FilterReply.NEUTRAL; } } // 若是有多个,循环获取第一个不是 NEUTRAL 的结果返回,其余再也不判断
    Object[] tfa = toArray(); final int len = tfa.length; for (int i = 0; i < len; i++) { // for (TurboFilter tf : this) {
      final TurboFilter tf = (TurboFilter) tfa[i]; final FilterReply r = tf .decide(marker, logger, level, format, params, t); if (r == FilterReply.DENY || r == FilterReply.ACCEPT) { return r; } } return FilterReply.NEUTRAL; }
     

为何做者要把一个TurboFilter时的逻辑与多个TurboFilter时的逻辑分开写?关注公众号回复TurboFilter获取答案(额外有一段解析,做为微信粉丝福利)。

梳理一下思路,每一条日志,不管级别,最终都会进入filterAndLog_0_Or3Plus方法进行判断是否输出,而其判断又会优先判断TurboFilterList#getTurboFilterChainDecision的返回值,getTurboFilterChainDecision中使用了TurboFilter,跟进源码咱们发现TurboFilterList是空的,咱们几乎能够断言,做者不会无缘无故搞一个空的List,必定是用来给咱们扩展的,咱们去翻翻文档,确定找获得扩展方法,翻看文档中关于TurboFilters的部分,咱们找到以下描述:

TurboFilters

TurboFilter objects all extend the TurboFilter abstract class. Like the regular filters, they use ternary logic to return their evaluation of the logging event.

Overall, they work much like the previously mentioned filters. However, there are two main differences between Filter and TurboFilter objects.

TurboFilter objects are tied to the logging context. Hence, they are called not only when a given appender is used, but each and every time a logging request is issued. Their scope is wider than appender-attached filters.

More importantly, they are called before the LoggingEvent object creation. TurboFilter objects do not require the instantiation of a logging event to filter a logging request. As such, turbo filters are intended for high performance filtering of logging events, even before the events are created.

大概意思和咱们分析的也差很少,TurboFilter也能够控制日志是否可以输出,并且优先级要高于普通的Filter,这不奇怪,毕竟Turbo嘛。

文档中给出了实例,接下来咱们来定义一个本身TurboFilter吧。

/** * DynamicLoggingFilter * * @author jiyanwai * @date 2020-01-15 16:09:16 */ @Slf4j public class DynamicLoggingFilter extends TurboFilter { public static final String DEBUG_HEADER_NAME = "X-Debug"; public static final String DEBUG_SESSION_KEY = DEBUG_HEADER_NAME; /** * 返回值 FilterReply.DENY,FilterReply.NEUTRAL或FilterReply.ACCEPT * 若是是 DENY,则不会再输出 * 若是是 ACCEPT,则直接输出 * 若是是 NEUTRAL,走来日志输出判断逻辑 * * @return FilterReply.DENY,FilterReply.NEUTRAL或FilterReply.ACCEPT */ @Override public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) { // 这里能够过滤咱们本身的logger
    boolean isMyLogger = logger.getName().startsWith("com.jiyuanwai"); if (!isMyLogger) { return FilterReply.NEUTRAL; } RequestAttributes requestAttributes = RequestContextHolder .getRequestAttributes(); // 项目启动或者运行定时器时,可能没有 RequestAttributes
    if (requestAttributes == null) { return FilterReply.NEUTRAL; } // 先判断 RequestHeader,用于区分线程
    ServletRequestAttributes servletRequestAttributes = (ServletRequestAttributes) requestAttributes; // 按照请求参数判断,实际生产环境能够开发功能给管理人员功能,将用户惟一标示放入缓存或者session
    HttpServletRequest request = servletRequestAttributes.getRequest(); String debug = request.getHeader(DEBUG_HEADER_NAME); boolean debugBoolean = Boolean.parseBoolean(debug); if (debugBoolean) { return FilterReply.ACCEPT; } // 再判断 Session
    HttpSession session = request.getSession(false); if (session == null) { return FilterReply.NEUTRAL; } Object attribute = session.getAttribute(DEBUG_SESSION_KEY); debugBoolean = Boolean.parseBoolean((String) attribute); if (debugBoolean) { return FilterReply.ACCEPT; } return FilterReply.NEUTRAL; } }

日志配置文件调整以下:

<configuration scan="false" debug="false">
    <turboFilter class="com.jiyuanwai.logging.extend.dynamic.DynamicLoggingFilter" /> ... <root level="error">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

 

 

写一个方法测试一下

@GetMapping public void debugLevel() { log.debug("A debug Log"); }

这里推荐你们使用Idea内置的 HTTP Request:

HTTP RequestHTTP Request

# 测试 RequestHeader 使用
GET http://localhost:8082/log/level
Accept: */*
# 经过Header,避免污染请求参数(不然文件上传会有问题)
X-Debug: true
Cache-Control: no-cache

###

执行以后,能够在控制台看到:

22:50:19.816 DEBUG [082-exec-5] c.j.l.e.c.LogController       (  35) - A debug Log

咱们完成了按照请求来动态调整日志。

继续测试一下Session,这里我就简单处理,仅仅在 Controller 增长一下做为测试,线上能够配合在线用户管理功能实现,小伙伴们能够按需扩展,若是有困难能够留言,我收集你们的困难统一解决。

@PutMapping
public void startDebugBySession(HttpSession session) {
  // 仅供测试,线上须要开发功能,获取对对应用户 session,而后放入属性
  session.setAttribute(DynamicLoggingFilter.DEBUG_SESSION_KEY, "true");
}

开启 Session 级别 debug 请求以下

# 以 Session 开启当前用户 DEBUG 模式
PUT http://localhost:8082/log/level
Accept: */*
Cache-Control: no-cache

###
# 去掉自定义Header,再次测试
GET http://localhost:8082/log/level
Accept: */*
Cache-Control: no-cache

###

结果以下

09:28:16.662 DEBUG [082-exec-1] c.j.l.e.c.LogController       (  40) - A debug Log
Tocken 与 Session 几乎没有差异,这里就再也不展现了。

至此,咱们已经很优雅的实现了按照请求、按照用户来动态输出日志,能够自豪一下了。

实战三 强者的世界

让咱们来实现最后一个需求,动态输出日志文件。

强者的世界强者的世界

咱们先分析一下需求,想要按照用户临时输出文件,区分用户可使用以前的方法,咱们须要解决的问题是,咱们如何将特定的用户输出到特定的文件?

读过员外之前文章的朋友都知道,真正负责输出日志的是 Appender,咱们优先去翻翻文档看看官方有没有解决方案,通过一番硬啃文档,咱们发现了 SiftingAppender配合discriminator再配合MDC 彷佛能解决咱们的需求,SiftingAppender能够根据用户会话分离日志事件,这样不一样用户生成的日志就能够进入不一样的日志文件,甚至能够每一个用户一个日志文件。discriminator很好理解按照字面意思就是鉴别器能够用来鉴别,但MDC是什么?

"Mapped Diagnostic Context" is essentially a map maintained by the logging framework where the application code provides key-value pairs which can then be inserted by the logging framework in log messages. MDC data can also be highly helpful in filtering messages or triggering certain actions.

简单翻译一下,MDC 就是日志框架维护的一个Map,能够用来过滤和触发操做,员外总结了两个最佳实践:

  • 读过之前文章的小伙伴(没读过的赶快关注公众号,点击往期回顾-日志系列便可查看)确定还记得我提过的超级 SessionId 与RequestId,如何实现?固然是MDC,见下文。
  • 另外就是discriminator配合MDC能够动态输出文件了,咱们来试一下。

实现思路,使用Filter而且第一个执行,直接来看代码

/** * LogFilter 用于处理动态日志 * * @author jiyanwai * @date 2020-01-16 06:05:19 */ @Slf4j @Component @Order(Integer.MIN_VALUE) @WebFilter("/*") public class LogFilter implements Filter { public static final String REQUEST_ID_MDC_KEY = "requestId"; public static final String SESSION_ID_MDC_KEY = "sessionId"; public static final String STAND_ALONE_HEADER_KEY = "X-StandAlone-File"; public static final String STAND_ALONE_SESSION_KEY = STAND_ALONE_HEADER_KEY; @Override public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException { try { try { HttpServletRequest request = (HttpServletRequest) servletRequest; // requestId 与超级 SessionId,能够根据需求自行定制
        String requestId = CommonUtils.generateRequestId(); MDC.put(REQUEST_ID_MDC_KEY, requestId); String sessionId = request.getRequestedSessionId(); MDC.put(SESSION_ID_MDC_KEY, sessionId); // 只有开启了独立文件输出,才放入MDC
        String standAlone = request.getHeader(STAND_ALONE_HEADER_KEY); if (standAlone == null) { standAlone = (String) request.getSession().getAttribute(STAND_ALONE_SESSION_KEY); } if (standAlone != null) { // 此处能够任意定制不一样路径,sessionId会被拼接到文件名,参考下文修改后的xml
 MDC.put(STAND_ALONE_SESSION_KEY, sessionId); } } catch (Exception e) { // 此到处理异常,不影响业务
        log.error("Error handler dynamic log", e); } // 继续执行,不处理其余Filter异常
 filterChain.doFilter(servletRequest, servletResponse); } finally { // 切记要清理环境
 MDC.clear(); } } }

 

 

配置文件增长SiftAppender

<appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
  <discriminator>
    <key>X-StandAlone-File</key>
    <!-- MDC取不到,默认“all” -->
    <defaultValue>all</defaultValue>
  </discriminator>
  <sift>
    <!-- Appender Name须要独立 -->
    <appender name="FILE-${X-StandAlone-File}" class="ch.qos.logback.core.FileAppender">
      <!-- 正在记录的日志文件的路径及文件名 -->
      <!-- 输出位置,${X-StandAlone-File}取MDC -->
      <file>${LOG_PATH}/${X-StandAlone-File}.log</file>
      <!-- 日志记录器的滚动策略,按日期,按大小记录 -->
      <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <!-- 按日滚动 -->
        <fileNamePattern>${LOG_PATH}/%d{yyyy-MM}/log-%d{yyyy-MM-dd-HH}-%i.${X-StandAlone-File}.gz</fileNamePattern>
        <!-- 单个文件最大50M -->
        <maxFileSize>50MB</maxFileSize>
        <!-- 最多占用5G磁盘空间,500个文件(总共不能超过该5G) -->
        <maxHistory>500</maxHistory>
        <totalSizeCap>5GB</totalSizeCap>
      </rollingPolicy>
      <!-- 追加方式记录日志 -->
      <append>true</append>
      <!-- 日志文件的格式 -->
      <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
        <pattern>${FILE_LOG_PATTERN}</pattern>
        <charset>utf-8</charset>
      </encoder>
    </appender>
  </sift>
  <root level="error">
    <!-- 为了方便测试,同时输出到控制台 -->
    <appender-ref ref="STDOUT"/>
    <appender-ref ref="SIFT"/>
  </root>
</appender>

调整Controller增长方法

/** * 为当前用户开启debug,测试使用,生产环境请配合在线用户管理相关功能来实现 * * @param session session */ @PutMapping public void startDebugBySession(HttpSession session, @RequestParam(required = false) boolean standAlone) { // 仅供测试,线上须要开发功能,获取对对应用户 session,而后放入属性
  session.setAttribute(DynamicLoggingFilter.DEBUG_SESSION_KEY, "true"); if (standAlone) { session.setAttribute(LogFilter.STAND_ALONE_SESSION_KEY, ""); } }

先使用Header模式来测试没有开启独立输出会文件结构如何

# 测试 RequestHeader 使用
GET http://localhost:8082/log/level
Accept: */*
# 经过Header,避免污染请求参数(不然文件上传会有问题)
X-Debug: true
Cache-Control: no-cache

###

非独立输出文件非独立输出文件

内容以下,能够看到咱们的RequestId与超级SessionId都成功的写到日志里面了

2020-01-16 09:54:05.827 DEBUG [http-nio-8082-exec-1] c.j.l.extend.controller.LogController    --- requestId=ee77a879576147bcafdcb745ba5767d3, sessionId=21F4DE2AADBA675F2135601D760BF18E : A debug Log

使用Http Request进行测试开启 debug,而且开启独立文件

# 以 Session 开启当前用户 DEBUG 模式
PUT http://localhost:8082/log/level
Accept: */*
Cache-Control: no-cache
Content-Type: application/x-www-form-urlencoded

standAlone=true

###

测试日志输出

# 测试 Session 模式使用
GET http://localhost:8082/log/level
Accept: */*
Cache-Control: no-cache

###

独立输出文件

独立输出文件

扩展

咱们以前采用了日志框架原生解决动态级别,问题在于修改起来不方便,须要链接线上服务器采用vim来修改,上文提到了 Logback 提供了API能够直接热修改,咱们来看一下:

/** * 修改单个日志级别 * * @param loggerName 日志实例名称 * @param level 级别 */ @PostMapping public void changeLoggingLevel(String loggerName, @RequestParam(required = false, defaultValue = "DEBUG") String level) { ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(loggerName); logger.setLevel(Level.toLevel(level)); }

测试一下:

# 测试 调整全局 日志级别 POST http://localhost:8082/log/level
Accept: */* Cache-Control: no-cache Content-Type: application/x-www-form-urlencoded loggerName=ROOT ###

若是咱们想要还原:

/** * 将日志级别重置为配置文件默认 */ @DeleteMapping public void restoreLoggingLevel() { LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); try { JoranConfigurator configurator = new JoranConfigurator(); configurator.setContext(context); context.reset(); configurator.doConfigure(new ClassPathResource("logback.xml").getInputStream()); } catch (JoranException | IOException ignore) { // StatusPrinter will handle this
 } StatusPrinter.printInCaseOfErrorsOrWarnings(context); }
继续测试
# 测试还原日志级别为配置文件级别
DELETE http://localhost:8082/log/level
Accept: */*
Cache-Control: no-cache

###

结束语

这一篇咱们实现了按请求、用户级别动态输出级别与文件,如今已经应该能知足 99% 的场景了,员外只用过 Logback,若是读者想使用 Log4j2,能够按照思路尝试本身实现,若是点赞超过 1000,我也能够实现出来给你们用,下一篇我会作一些前文勘误、读者问题反馈,还有少许的最佳实践,欢迎关注更新。

最后给你们贴一张分析过程的思惟导图,但愿可以帮助你们学会分析、解决问题。

分析问题导图

以上是我的观点,若是有问题或错误,欢迎留言讨论指正,码字不易,若是以为写的不错,求关注、求点赞、求转发

扫码关注公众号,第一时间得到更新

扫码关注

代码:https://github.com/jiyuanwai/logging-extend

原文出处:https://www.cnblogs.com/xuningfans/p/12202726.html

相关文章
相关标签/搜索