日志级别动态调整——小工具解决大问题

背景

随着外卖业务的快速发展,业务复杂度不断增加,线上系统环境有任何细小波动,对整个外卖业务都可能产生巨大的影响,甚至形成灾难性的雪崩效应,造成巨大的经济损失。每一次客诉、系统抖动等都是对技术人员的重大考验,我们必须立即响应,快速解决问题。

如何提高排查问题的效率呢?最有效的方式是通过分析系统日志。如果系统日志全面,会为我们排查解决线上问题带来绝大的帮助,但是要想保证系统日志全面,就必须打印出所有的系统或业务日志。这样就会带来另一个问题,那就是日志量的暴涨,过多的日志除了能够帮助我们解决问题外,同时会直接造成系统性能下降,极端情况下,甚至导致系统宕机。在这种背景下,为了兼顾性能和快速响应线上问题,我们设计开发了日志级别动态调整组件。通过使用该组件,可以在需要解决线上问题时,实时调整线上日志输出级别,获取全面的Debug日志,帮助工程师提高定位问题的效率。

简介

使用场景

场景一

业务依赖复杂。某一时刻,依赖的下游服务故障,导致请求大量超时,尤其是像外卖这种集中性特别明显的业务,平均每秒QPS在8000以上,1分钟的故障就会集中产生大量的错误日志,导致磁盘IO急剧提高,耗费大量CPU,进而导致整个服务瘫痪。如果该业务不能立即降级,怎么办?

从代码级别解决问题到发版上线,暂且不说流程长、操作麻烦,同时还存在引入其它故障的高风险。如果系统恰好使用Log4j版本,在极短时间内打印出了海量错误日志,会快速耗尽Buffer区内存,从而拖慢主线程,造成服务性能整体下降,甚至还没有来得及修复问题,海量日志已经拖垮服务,造成服务宕机,损失惨重。

场景二

大量的订单、结算等客诉问题反馈过来,一线工程师大量精力埋没于排查问题中,而排查定位问题的最终手段仍然是依赖线上日志。由于链路较长,任一日志的缺失,都给问题的排查带来极大的障碍,面对运营的催促,怎么办?

工程师为了以后排查问题的方便,在任一可能出现异常的地方,都会打印出关键日志,然后发版上线。但好不容易解决了本次问题,还没来得及收获喜悦,就又面临着一个新问题,那就是场景三。

场景三

由于线上业务系统默认日志打印级别是INFO级别,为了排查问题方便,调试型日志都以该级别打印出来。这样的话给系统带来了额外的负担,在高峰期大量调试日志时会拖慢系统性能,增大出故障的风险,怎么办?

一方面要快速响应业务,另一方面要兼顾系统性能,能不能两方面兼顾?我们的动态调整日志级别工具正是为了解决这种痛点。

能解决哪些问题

  1. 日志降级。 兼容Log4j、Log4j2和Logback主流日志框架,如果遇到场景一,可以通过我们的日志工具,快速调整日志输出级别,降低系统日志的输出,从而达到日志降级的效果,同时能够给RD争取充裕的排查问题时间。
  2. 规范日志级别滥用,帮助工程师快速定位解决线上问题。 使用日志级别动态调整组件,可以实时动态调整线上服务的日志打印级别,调试型日志可以使用低级别打印出,减轻线上服务的负载压力。遇到排查问题时,可以临时将日志级别调低,快速得到精准化的日志信息,排查解决问题。

系统基础架构

日志级别动态调整组件定位为中间件,在设计之初重点考虑了以下几点:

  1. 低侵入性
    • 接入服务仅需要引入JAR包和XML配置文件即可,不存在额外编码工作,业务耦合低、接入成本小。
  2. 安全可靠
    • 更改接入服务的日志输出级别,只能通过我们提供的管理系统,所有的操作记录有迹可查。
    • 引入权限认证,确保工程师只能操作自己负责的服务或系统,同时会把操作内容实时周知给系统的所有相关责任人,避免误伤。
  3. 可视化操作
    • 操作者可以通过我们提供的管理页面,定向修改一个或一批服务节点。
    • 提供可视化的操控开关,可以随时关闭或开启服务。

具体实现

调用组件

本组件采用工厂模式实现,保障其高可扩展性。目前已实现日志级别动态调整和方法调用处理单元,下面主要介绍日志级别动态调整处理单元的实现。

目前美团外卖业务系统基本统一采用的SLF4J日志框架,在应用初始化时,SLF4J会绑定具体的日志框架,如Log4j、Logback或Log4j2等。具体源码如下(slf4j-api-1.7.7):

private final static void bind() {  try {    // 查找classpath下所有的StaticLoggerBinder类。
    Set<URL> staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet(); 
    reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);    // 每一个slf4j桥接包中都有一个org.slf4j.impl.StaticLoggerBinder类,该类实现了LoggerFactoryBinder接口。
    // the next line does the binding
    StaticLoggerBinder.getSingleton();
    INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
    reportActualBinding(staticLoggerBinderPathSet);
    fixSubstitutedLoggers();
    ...
}

findPossibleStaticLoggerBinderPathSet方法用来查找当前classpath下所有的org.slf4j.impl.StaticLoggerBinder类。每一个slf4j桥接包中都有一个StaticLoggerBinder类,该类实现了LoggerFactoryBinder接口。具体绑定到哪一个日志框架则取决于类加载顺序。

接下来,咱们分三部分,来说说ChangeLogLevelProcessUnit类:

1. 初始化:确定所使用的日志框架,获取配置文件中所有的Logger内存实例,并将它们的引用缓存到Map容器中。

String type = StaticLoggerBinder.getSingleton().getLoggerFactoryClassStr();if (LogConstant.LOG4J_LOGGER_FACTORY.equals(type)) {
 logFrameworkType = LogFrameworkType.LOG4J;
 Enumeration enumeration = org.apache.log4j.LogManager.getCurrentLoggers(); while (enumeration.hasMoreElements()) {
     org.apache.log4j.Logger logger = (org.apache.log4j.Logger) enumeration.nextElement();     if (logger.getLevel() != null) {
         loggerMap.put(logger.getName(), logger);
     }
 }
 org.apache.log4j.Logger rootLogger = org.apache.log4j.LogManager.getRootLogger();
 loggerMap.put(rootLogger.getName(), rootLogger);
} else if (LogConstant.LOGBACK_LOGGER_FACTORY.equals(type)) {
 logFrameworkType = LogFrameworkType.LOGBACK;
 ch.qos.logback.classic.LoggerContext loggerContext = (ch.qos.logback.classic.LoggerContext) LoggerFactory.getILoggerFactory(); for (ch.qos.logback.classic.Logger logger : loggerContext.getLoggerList()) {     if (logger.getLevel() != null) {
         loggerMap.put(logger.getName(), logger);
     }
 }
 ch.qos.logback.classic.Logger rootLogger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
 loggerMap.put(rootLogger.getName(), rootLogger);
} else if (LogConstant.LOG4J2_LOGGER_FACTORY.equals(type)) {
 logFrameworkType = LogFrameworkType.LOG4J2;
 org.apache.logging.log4j.core.LoggerContext loggerContext = (org.apache.logging.log4j.core.LoggerContext) org.apache.logging.log4j.LogManager.getContext(false);
 Map<String, org.apache.logging.log4j.core.config.LoggerConfig> map = loggerContext.getConfiguration().getLoggers(); for (org.apache.logging.log4j.core.config.LoggerConfig loggerConfig : map.values()) {
     String key = loggerConfig.getName();     if (StringUtils.isBlank(key)) {
         key = "root";
     }
     loggerMap.put(key, loggerConfig);
 }
} else {
 logFrameworkType = LogFrameworkType.UNKNOWN;
 LOG.error("Log框架无法识别: type={}", type);
}

2. 获取Logger列表:从本地Map容器取出。

private String getLoggerList() {
 JSONObject result = new JSONObject();
 result.put("logFramework", logFrameworkType);
 JSONArray loggerList = new JSONArray(); for (ConcurrentMap.Entry<String, Object> entry : loggerMap.entrySet()) {
     JSONObject loggerJSON = new JSONObject();
     loggerJSON.put("loggerName", entry.getKey());     if (logFrameworkType == LogFrameworkType.LOG4J) {
         org.apache.log4j.Logger targetLogger = (org.apache.log4j.Logger) entry.getValue();
         loggerJSON.put("logLevel", targetLogger.getLevel().toString());
     } else if (logFrameworkType == LogFrameworkType.LOGBACK) {
         ch.qos.logback.classic.Logger targetLogger = (ch.qos.logback.classic.Logger) entry.getValue();
         loggerJSON.put("logLevel", targetLogger.getLevel().toString());
     } else if (logFrameworkType == LogFrameworkType.LOG4J2) {
         org.apache.logging.log4j.core.config.LoggerConfig targetLogger = (org.apache.logging.log4j.core.config.LoggerConfig) entry.getValue();
         loggerJSON.put("logLevel", targetLogger.getLevel().toString());
     } else {
         loggerJSON.put("logLevel", "Logger的类型未知,无法处理!");
     }
     loggerList.add(loggerJSON);
 }
 result.put("loggerList", loggerList);
 LOG.info("getLoggerList: result={}", result.toString()); return result.toString();
}

3. 修改Logger的级别。

private String setLogLevel(JSONArray data) {
 LOG.info("setLogLevel: data={}", data);
 List<LoggerBean> loggerList = parseJsonData(data); if (CollectionUtils.isEmpty(loggerList)) {     return "";
 } for (LoggerBean loggerbean : loggerList) {
     Object logger = loggerMap.get(loggerbean.getName());     if (logger == null) {         throw new RuntimeException("需要修改日志级别的Logger不存在");
     }     if (logFrameworkType == LogFrameworkType.LOG4J) {
         org.apache.log4j.Logger targetLogger = (org.apache.log4j.Logger) logger;
         org.apache.log4j.Level targetLevel = org.apache.log4j.Level.toLevel(loggerbean.getLevel());
         targetLogger.setLevel(targetLevel);
     } else if (logFrameworkType == LogFrameworkType.LOGBACK) {
         ch.qos.logback.classic.Logger targetLogger = (ch.qos.logback.classic.Logger) logger;
         ch.qos.logback.classic.Level targetLevel = ch.qos.logback.classic.Level.toLevel(loggerbean.getLevel());
         targetLogger.setLevel(targetLevel);
     } else if (logFrameworkType == LogFrameworkType.LOG4J2) {
         org.apache.logging.log4j.core.config.LoggerConfig loggerConfig = (org.apache.logging.log4j.core.config.LoggerConfig) logger;
         org.apache.logging.log4j.Level targetLevel = org.apache.logging.log4j.Level.toLevel(loggerbean.getLevel());
         loggerConfig.setLevel(targetLevel);
         org.apache.logging.log4j.core.LoggerContext ctx = (org.apache.logging.log4j.core.LoggerContext) org.apache.logging.log4j.LogManager.getContext(false);
         ctx.updateLoggers(); // This causes all Loggers to refetch information from their LoggerConfig.
     } else {         throw new RuntimeException("Logger的类型未知,无法处理!");
     }
 } return "success";
}

上面介绍了如何拿到日志配置文件中的Logger,以及修改Logger的级别。

通信方式

我们根据Web项目和纯粹RPC项目,分别提供HTTP和Thrift两种通信协议。

场景一、Thrift服务

所有的请求信息都包含在JSON String的数据结构里面,其中包含有签名信息,请求时签名验证失败将直接抛出异常。

引入组件提供的dynamic-invoker.xml配置,将会在系统中自动注入开启一个专为日志级别调整的接口服务,该接口是一个单纯的Thrift服务,能够通过ZooKeeper实现服务注册与发现,并且有可视化的开启与关闭管理后台,简单明了,操作方便。

场景二、HTTP服务

对于一些Web项目,暴露一个RPC服务相当不安全。为此,我们提供了HTTP协议接口,接入流程完全一样,在真正修改日志输出级别时,会根据系统类型自主判断使用哪种协议,有独立实现的签名认证,安全可靠。

结束语

从2016年9月V1.0版本上线以来,陆续接入外卖配送的20多个核心应用,覆盖推送、接单、配送调度、斑马配送、活动等核心交易服务。

举例:

  • 问题描述:发配送服务化项目由于间接依赖,引入了Logback日志框架。在项目启动加载时,SLF4J动态绑定到Logback框架上,但是由于发配送项目使用的Log4j,并未配置Logback.xml文件,导致在打印日志时,SLF4J无法匹配到具体的日志配置,从而为项目自动创建了一个日志级别为Debug的ROOT节点,所有的日志以该级别打印输出,导致发配送服务化项目在中午11:30左右高峰期,短时间内打印过多的系统日志,引起Load飙高,重新修改发版上线已经来不及,如果不能立即解决,势必造成服务化宕机,损失非常严重。
  • 处理结果:使用我们这个日志工具,批量将服务化项目所有的日志输出级别调整为ERROR级别,大大减少了日志量的输出,给工程师留出充裕的的时间完美的解决了该问题,避免造成更大的系统故障。
  • 后记:更重要的是以该工具组件为切入点,帮助各业务系统逐渐规范系统日志使用,取得很好效果。

后续我们规划将其推广成为公司级别的工具,为越来越多的项目提供便利。

欢迎感兴趣的同学与我们进一步交流。

参考文献

  1. Simple Logging Facade for Java (SLF4J)
  2. Log4j 2 Architecture - Apache Log4j 2
  3. Hash-based message authentication code - Wikipedia

原文发布于微信公众号 - 美团点评技术团队(meituantech)

原文发表时间:2017-02-17

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

1 条评论
登录 后参与评论

相关文章

来自专栏技术分享

.NET应用架构设计—服务端开发多线程使用小结(多线程使用常识)

有一段时间没有更新博客了,最近半年都在着写书《.NET框架设计—大型企业级框架设计艺术》,很高兴这本书将于今年的10月份由图灵出版社出版,有关本书的具体介绍等书...

1725
来自专栏美团技术团队

【美团技术团队博客】序列化和反序列化

摘要 序列化和反序列化几乎是工程师们每天都要面对的事情,但是要精确掌握这两个概念并不容易:一方面,它们往往作为框架的一部分出现而湮没在框架之中;另一方面,它们...

3629
来自专栏老九学堂

【编程解惑】Java、JavaEE、JavaSE、Java Web、JavaScript有什么区别?

很多有想入门Java的小伙伴在听到Java那么多叫法的时候,是不是表示一脸懵逼,今天老九君就给大家捋一捋Java大家族间的分门别类。 ? Java分为:Jav...

3359
来自专栏Linyb极客之路

杂谈Java高并发

对于我们开发的网站,如果网站的访问量非常大的话,那么我们就需要考虑相关的并发访问问题了。而并发问题是绝大部分的程序员头疼的问题,但话又说回来了,既然逃避不掉,那...

815
来自专栏闵开慧

hadoop负载均衡与垃圾回收

负载均衡 负载的均衡,是分布式系统中一个永恒的话题,要让大家各尽其力齐心干活,发挥各自独特的优势,不能忙得忙死闲得闲死,影响战斗力。而且,负载均衡也是一个...

3378
来自专栏Java帮帮-微信公众号-技术文章全总结

Java面试系列3

Java面试系列3 01 不得不知道的Java名词 1 . J2EE (Java 2 Enterprise Edition)是一种利用Java 2平台来简化企业...

2745
来自专栏偏前端工程师的驿站

Architecture Pattern: Publish-subscribe Pattern

1. Brief                               一直对Observer Pattern和Pub/Sub Pattern有所混淆,下...

17710
来自专栏大数据人工智能

ZStack--工作流引擎

在IaaS软件中的任务通常有很长的执行路径,一个错误可能发生在任意一个给定的步骤。为了保持系统的完整性,一个IaaS软件必须提供一套机制用于回滚先前的操作步骤。...

4094
来自专栏禁心尽力

如何在分布式环境中同步solr索引库和缓存信息

     搜索无处不在,相信各位每天都免不了与它的亲密接触,那么我想你确实有必要来了解一下它们,就上周在公司实现的一个小需求来给各位分享一下:如何在分布式环境...

2089
来自专栏何俊林

Android app内存管理的16点建议

前言:内存管理,在iOS开发中和C++开发中可以说是天天提到。对于Android平台,Google其实早有文档说明,本文翻译自Google官方文档,如有不正确,...

2847

扫描关注云+社区