为啥公司业务上不去?要么程序没有输出日志到位,缺少价值数据。要么打印日志到位了,没有高效的分析工具!
为啥程序会崩溃?日志处理没到位呗,线上故障就得加班,浪费了时间还找不到问题根源!
别想为啥了,跟上来学习吧,本篇解决此类问题。
什么是日志(log)
想想,我们为什么要做笔记,翻看笔记?
或者说,每天写日记,
我们做了笔记是为了加强记忆,如果忘记了后面还能翻看。
日志就是类似笔记一样的东西。
小白问:那么日志能帮助开发者提高记忆,轻松学会写代码了?
这倒不是的。日志就想日记一样可以随时翻看,查看过去发生的事情。
好,下面来看雷学委的开发日常:
没错,像记日记一样,用程序记录了每个时刻做的事情,输出到文件,还能经常查看。这就是日志。
当我们把这些零散的日志归集起来,数据量大了,就能发现日志数据的规律和价值。
本文会使用log4js来进行日志使用的展示。Java开发是使用Log4J或者Slf4J,但是核心思想是一样的。
本文适用于任何语言,而且覆盖了单应用到大规模平台的处理。前面已经掌握了基本概念,下面继续看,
日志的简单应用
多种日志格式的使用和含义
实际项目如何管理和配置日志
大规模平台的日志管理与数据价值分析
学习的第一步都是先知道啥,怎么用,下面先使用。
先安装
我们这里先安装一个日志的模快。
打开终端执行下面命令:
npm install log4js
使用
看看雷学委的日记
const log4js = require('log4js') var logger = log4js.getLogger('雷学委开发日常') logger.level = 'info' logger.info('早上起床') logger.info('拥抱太阳') logger.info('吃完早餐') logger.info('充满希望') logger.info('开始了代码的一天')
保存上面代码为demo-fun.js ,然后运行:
node demo-fun.js
可以得到跟上面日志图片的效果,读完可以试试。
下面正式开发
这里会有三个例子,展示日志打印和日志输出控制。
最简单的例子
复制下面代码为demo.js
var log4js = require("log4js"); // 加载log4js库 var logger = log4js.getLogger();//获取默认的logger logger.level = "debug"; logger.debug("一些调试信息");
直接运行:node demo.js,效果如下:
很像console.log,不过多了一些东西,看起来像下面的格式:
[日期] [DEBUG] default - 日志消息详情。
这里的DEBUG为,一个日志级别,就像文件级别一样(有公开,内部可读,保密,绝密档案)
这只是一条日志记录。我们再看下面的,找找规律
再看一个例子:
//demo1.js var log4js = require("log4js"); var logger = log4js.getLogger(); logger.level = "debug"; logger.debug("一些调试信息"); logger.info(" 普通日志"); logger.debug("又是调试信息了");
复制上面的6行代码保存为demo1.js,运行打印如下信息:
这里打印了3行日志,看到规律了吗?
每一行都是:[日期] [日志级别] default - 具体的日志内容
好,这里稍微做一下解释。
logger对象提供了不同方法,像debug,info等表示不同的日志级别!
不同的日志级别又代表什么呢?
看下面一个稍微复杂的例子,就能明白。
避免新人写代码出错,雷学委这里又贴心的为小白/懒人,提供了直接可以复制运行的代码。
先花30秒耐心看一下,保存为demo2.js
//demo2.js const log4js = require("log4js"); //这里配置log4js使用fileAppender来输出“error”级别的日志。 //然后fileAppender是一个文件类型的日志累加器,输出日志到文件demo2.log log4js.configure({ appenders: { fileAppender: { type: "file", filename: "demo2.log" } }, categories: { default: { appenders: ["fileAppender"], level: "error" } } }); const logger = log4js.getLogger("demo"); //下面调用logger对象来打印一些日志。 logger.trace("一些程序跟踪信息"); logger.debug("这里输出调试信息."); logger.info("普通日志输出在这里!!!"); logger.warn("程序发现可疑问题,打印警告信息"); logger.error("雷学委,程序发现错误了,报警信息!"); logger.fatal("雷学委,这里通常是服务端/引擎吃不消了,打印严重错误日志。");
看懂了吗?
上面的代码分为两个部分
- 第一段加载并配置log4js对象,日志输出保存到哪里,输出的日志级别是什么,这里是‘error’级别
- 第二段为创建logger对象,并用它的不同方法来打印不同级别的日志。
运行效果如下:
node demo2.js, 如上所说,日志打印到文件demo2.log里面。
另外demo2.log内容只有 [ERROR] 和[FATAL]这两个级别的日志,也就是,只有logger.error和logger.fatal两个函数的日志详情被输出到文件中。
如果把ERROR比喻为公开级别,那么像DEBUG/TRACE等就是保密级别了,指定了输出公开信息等话,保密数据是绝对不能打印出来的。
理解一下日志分级
先说级别,不同级别日志会有级别的关键词,像日志中的‘ERROR’, ’DEBUG’ 这些。
既然是级别了就有高低级别之分。
可以用下面的表达式进行级别低到高排列:
TRACE < DEBUG < INFO < WARN < ERROR < FATAL
所以这解释了demo2.js代码中指定了‘error‘级别之后, 只有
logger.error 和 logger.fatal 两行日志被打印了。
看懂了吗?就像日常的信息保护级别,指定级别越高越不能暴露更多信息,在程序中级别指定越高,输出的信息越少,同一个道理。
信息量慢慢加大 - 全部日志级别
下图是log4js模块提供的方法和日志级别。
log4js 提供了getLogger方法,开发者可以调用这个获取一个logger对象,用来输出不同级别日志。
然后,这里是最全面的log4js的提供的日志级别。
重新整理整个日志级别的排列变更如下:
ALL <TRACE < DEBUG < INFO < WARN < ERROR < FATAL < OFF
上面这个公式务必背诵默写!
这里读者可自行运行文末实例代码。
这里ALL级别相当于整个日志信息都打印,暴露的信息量最多,OFF暴露的信息量是极少的。
雷学委也准备了代码,读者稍后可从文末下载执行。
到这里还不懂,雷学委精心准备了下图,看到这个图已经值了!
至此,整个日志框架的核心,您已掌握了。
喝杯水,下面继续看实际应用。
实际项目中如何应用日志
配置化日志管理
上面的demo2的代码配置,应该提取日志模块的配置到文件。
配置放在文件中,可以修改配置不改代码切换日志。
但是应用需要重启,可以代理logger对象实现不重启动态加载。
日志级别的使用建议
通常我们打印‘info’级别日志,记得常规用户行为,如登录/查看更新资料/其他业务访问的log等。
info级别以下的使用
在开发过程中可以使用logger.debug函数去打印程序内部信息,比如打印一些中间变量的值,打印中间处理状态等等。
对于trace级别的日志,这个比较低级别,通常用来本地跟踪代码的执行的详细信息!在服务端,服务器上运行的程序通常不会开启,因为日志量会很大。
对于all级别很少使用,可以根据情况自己定义,很多时候用到trace级别就很够信息量了。
对于info以上的高日志级别
warn级别:打印警告信息,就是可能是错误,或者是忽略的已知错误。
比如系统在调用一个不稳定的接口,有时候别人不稳定只能多次重试,这时候会使用logger.warn方法来打印日志内容”忽略第三方程序调用错误,准备重试“
error级别:顾名思义就是,程序错误,这个可以用来打印错误数据,错误请求的事件信息,比如java中抛出一些CheckedException的时候经常会在catch代码快中调用logger.error来记录此类异常。
这类成为错误记录,更多是程序内部处理,业务方面的错误记录。
fatal级别更多是在NodeJS引擎出现故障,或者JVM(java
虚拟机)这种引擎级别的故障可以用这个级别来打印。针对web应用,像访问底层数据库的失败的时候,也可以用这个fatal级别来记录。
出现这种问题一般是本应用的故障,或者因为网络,操作系统的故障导致的程序故障。
日志格式化问题
如下面的log4js配置一样,加了一个标准输出来展示。
这里的patern: “%d [%p] [%c] - %m%n” 就是我们打印日志的格式。%d是一个占位符,最简单可以理解,就是表示一个时间戳,代表打印日志的时间。
%p %c这些就是占位符,也就是代表了日志级别,日志对象(特定的logger)等。
%m 代表当前如logger.info方法传入的消息。
%n 为换行。
效果如下:
所有格式定义参考:https://github.com/log4js-node/log4js-node/blob/master/docs/layouts.md
log4js还可以支持将日志写到多个文件中参考:https://github.com/log4js-node/log4js-node/blob/master/docs/multiFile.md
重点说一下,日志格式其实不用过度纠结,但必须在输出准确日志信息的情况下,同时保证整个系统或者多个服务的配置达到统一标准。
统一标准,比如说格式上的输出标准,代码日志输出标准,路径的标准等等。不然容易失控,这需要在架构上达成一致。
日志文件滚动策略
开发的应用通常都是长期运行的,会不停的产生日志。
随着时间推移,把日志写在一个文件也不现实。
而且不利于复查问题,占用大量存储资源,另外,在大文件中搜索关键字速度也降低。
所以需要滚动(Rotate/Rolling)日志,也就是把日志设置一个固定规模,比如写日志到 LeixueweiDemoApp.log 文件,设置最大尺寸,当文件超过最大尺寸自动的创建新文件,同时可以设置最大的日志文件备份,比如保留一个月,半年,甚至更长期的日志。
这是log4js官网的:
JS的日志配置使用了JSON来呈现是非常直观的。
Java则更多使用logback或者SLF4J + logback/log4j ,配置的内容很像,但是呈现格式不一样,很多是xml文件或者properties文件。
这里可以拿一个XML文件(类似html标签化语义)来看看,如下:
<?xml version="1.0" encoding="UTF-8"?> <configuration> <property resource="application.properties" /> <!-- application.name在application.properties中定义 --> <contextName>${application.name}</contextName> <!-- 日志级别 --> <property name="logLevel" value="INFO" /> <!-- 日志文件名 --> <property name="logFileName" value="LeixueweiDemoApp"/> <!-- 保存60天 --> <property name="maxHistory" value="60"/> <!-- application.logHome在application.properties中定义 --> <property name="logPath" value="${application.logHome}/logs/${projectName}"/> <!--格式化输出:%d{yyyy-MM-dd HH:mm:ss.SSS} 表示特定时间格式日期,%thread表示线程名,%-5level:级别从左显示5个字符宽度,%msg:日志消息,%n是换行符--> <property name = "LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{35} - %msg%n"></property> <!-- 控制台输出 --> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"> <pattern>${LOG_PATTERN}</pattern> </encoder> </appender> <!-- 日志记录器,日期滚动记录 --> <appender name="FILEAppender" class="ch.qos.logback.core.rolling.RollingFileAppender"> <!--日志文件路径及文件名 --> <file>${logPath}/${logFileName}.log</file> <!-- 日志滚动策略,按日期记录 --> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <!-- 归档日志文件路径--> <fileNamePattern>${logPath}/${logFileName}.%d{yyyy-MM-dd}.log</fileNamePattern> <maxHistory>${maxHistory}</maxHistory> </rollingPolicy> <!-- 追加记录日志 --> <append>true</append> <!-- 日志文件格式 --> <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"> <pattern>${LOG_PATTERN}</pattern> </encoder> <!-- 记录info及其以上级别 --> <filter class="ch.qos.logback.classic.filter.LevelFilter"> <level>info</level> </filter> </appender> <!--适用上面两个appender--> <root level="${logLevel}"> <appender-ref ref="STDOUT"/> <appender-ref ref="FILEAppender"/> </root> </configuration>
上面定义了两个log appender 和 root根logger来配置全局logLevel。
其实配置的属性两个技术很相似。
到这里已经变得非常复杂了,但是一个完整的应用日志也就是上面的,文末的代码仓库链接有实例配置。
读到这里,基本可以解决单个应用的日志管理,而且能够做的成熟专业的应用日志处理了。
大规模分布式场景的日志管理与分析
高性能的处理
这里稍微提一下,在应用中打印日志不宜过多,会影响程序性能。比如访问了一个静态页面,服务器直接打印1G的log出来,这就很离谱。
但有时候比如一些重点信息很多,比如在很大请求量的情况下,要保证性能,又想要留住重要的信息跟踪,怎么处理?
这时候可以使用日志队列的方式来解决。
在使用NodeJS情况下,这里又得提到pm2了,使用集群模式运行,把多个worker节点日志发布到master进行统一化处理,减轻写同个日志或者轮转日志的负担。
Java中也有类似的方法,异步处理大量日志,可以查看logback的配置,AsyncAppender。
<appender name="ASYNC_LOG_INFO" class="ch.qos.logback.classic.AsyncAppender"> <!-- 设置为:不丢失日志 --> <discardingThreshold>0</discardingThreshold> <!-- 更改默认的队列的深度,该值会影响性能.默认值为256 --> <queueSize>${queueSize}</queueSize> <appender-ref ref="FILE_INFO"/> </appender>
这个配置的queueSize变量,得跟据应用的实际QPS日志流量来分析,其他参考:http://logback.qos.ch/manual/appenders.html#AsyncAppender
统一日志处理与分析
上面说的很多直接用来做一个应用的日志处理都可以。
统一日志处理说的是把一个大型系统的日志,统一的集中化管理。
重点是:分布式日志集中化管理。
这一点很重要,在运维大型平台的时候,有几百上千台服务器,上面很多服务,很多日志不可能一个一个登录上去看。
所以我们需要使用工具进行集中化,而且做一个大规模的统一分析。
思想是把本服务日志传输到一个中央分析主机,使用高效的分析工具,分析数据的规律
下面是一个简化的日志集中收集处理的架构,应用服务器多,日志收集终端可以把日志放到消息队列,缓冲处理日志。
这一块可以拓展的解决方案很多,是一个开放问题,后面可以写一篇专门Elastic技术棧的。
快速过一下elastic stack技术组件:
FileBeat: 一个收集日志的程序
Logstash: 接收网络端数据,有Pipeline进行日志解构与重组,格式化为结构化数据,方便分析
ElasticSearch: 一个高效的存储框架,支持快速数据存储查询
Kibana:一个数据可视化工具,支持快速对接elasticsearch的数据,快速的图表面板制作。
映射到上面的架构图,我们使用elastic stack的组件流程如下:
终端应用服务器日志收集(FileBeat) -> 统一日志处理(Logstash) -> 统一日志存储(ElasticSearch) -> 统一的数据展示面板(Kibana)
这里简单提一下,使用这些组件更多是继续配置整合,参考官网配置和文本的代码REPO即可。
小团队或者小公司可以使用/开发日志收集器(功能类似logstash+filebeat来传输处理日志),然后存储到elastic search来统一分析,最后使用Kibana做很多分析面板,这里就要求所有应用日志的格式统一,打印足够有效信息。
日志数据分析与价值揭示
不给有效数据,再怎么分析也是徒劳。数据采集的量也得足够,不能只来一两条,那是很零散的分布。
下面来看看Kibanan制作的一些数据分析面板
比如监控Nginx 的访问请求情况
然后还能细致分析到每一个用户请求的响应情况:
这两个图表的数据来源是Nginx组件产生的log(日志)文件,一天的用户请求访问日志的分析。
或者像MITRE 公司展示的各种黑客攻击的活动分析面板
它是一个数据安全领域的组织,下面面板数据来自:https://attackevals.mitre.org/evaluations.html?round=APT29
下面是一周的网络攻击活动统计,有高到低,左边为攻击手段排名,中间为具体技术总
如上图,把零散的数据导入作出面板,作出图表显现了数据的规律。上面揭示了各种安全攻击的分布,以及使用的主要技术。
这里可以感受到日志数据分析的价值了吧。
自研发平台也可以参考Kibana或者Grafana技术棧,实施日志收集分析方案。
读者可以去elastic网站看demo深度了解一下。
再回顾一下
日志处理与分析跟我们写程序思考是一样的,先把思路捋清楚,找去定标准,找合适的工具,还能挖掘出很多业务规律发现价值,创造营收
本文讲述了下面这些
日志的概念
日志的作用
日志的简单应用
多种日志格式的使用和含义
实际项目如何管理和配置日志
大平台/高并发场景的日志处理与价值分析