我们都有过上机器查日志的经历,当集群数量增多的时候,这种原始的操作带来的低效率不仅给我们定位现网问题带来极大的挑战,同时,我们也无法对我们服务框架的各项指标进行有效的量化诊断,更无从谈有针对性的优化和改进。这个时候,构建具备信息查找,服务诊断,数据分析等功能的实时日志监控系统尤为重要。
ELK (ELK Stack: ElasticSearch, LogStash, Kibana, Beats) 是一套成熟的日志解决方案,其开源及高性能在各大公司广泛使用。而我们业务所使用的服务框架,如何接入 ELK 系统呢?
业务背景
我们的业务框架背景:
业务框架是基于 NodeJs 的 WebServer
服务使用 winston 日志模块将日志本地化
服务产生的日志存储在各自机器的磁盘上
服务部署在不同地域多台机器
我们将整个框架接入 ELK 简单归纳为下面几个步骤:
日志结构设计:由传统的纯文本日志改成结构化对象并输出为 JSON.
日志采集:在框架请求生命周期的一些关键节点输出日志
ES 索引模版定义:建立 JSON 到 ES 实际存储的映射
一、日志结构设计
传统的,我们在做日志输出的时候,是直接输出日志的等级(level)和日志的内容字符串(message)。然而我们不仅关注什么时间,发生了什么,可能还需要关注类似的日志发生了多少次,日志的细节与上下文,以及关联的日志。 因此我们不只是简单地将我们的日志结构化一下为对象,还要提取出日志关键的字段。
1. 将日志抽象为事件
我们将每一条日志的发生都抽像为一个事件。事件包含:
事件元字段
事件发生时间:datetime, timestamp
事件等级:level, 例如: ERROR, INFO, WARNING, DEBUG
事件名称: event, 例如:client-request
事件发生的相对时间(单位:纳秒):reqLife, 此字段为事件相对请求开始发生的时间(间隔)
事件发生的位置: line,代码位置; server, 服务器的位置
请求元字段
请求唯一ID: reqId, 此字段贯穿整个请求链路上发生的所有事件
请求用户ID: reqUid, 此字段为用户标识,可以跟踪用户的访问或请求链路
数据字段
不同类型的事件,需要输出的细节不尽相同,我们将这些细节(非元字段)统一放到d -- data,之中。使我们的事件结构更加清晰,同时,也能避免数据字段对元字段造成污染。
e.g. 如 client-init事件,该事件会在每次服务器接收到用户请求时打印,我们将用户的 ip, url等事件独有的统一归为数据字段放到 d 对象中
举个完整的例子
{ "datetime":"2018-11-07 21:38:09.271", "timestamp":1541597889271, "level":"INFO", "event":"client-init", "reqId":"rJtT5we6Q", "reqLife":5874, "reqUid": "999793fc03eda86", "d":{ "url":"https://www.jb51.net/", "ip":"9.9.9.9", "httpVersion":"1.1", "method":"GET", "userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.77 Safari/537.36", "headers":"*" }, "browser":"{"name":"Chrome","version":"70.0.3538.77","major":"70"}", "engine":"{"version":"537.36","name":"WebKit"}", "os":"{"name":"Mac OS","version":"10.14.0"}", "content":"(Empty)", "line":"middlewares/foo.js:14", "server":"127.0.0.1" }
一些字段,如:browser, os, engine为什么在外层 有时候我们希望日志尽量扁平(最大深度为2),以避免 ES 不必要的索引带来的性能损耗。在实际输出的时候,我们会将深度大于1的值输出为字符串。而有时候一些对象字段是我们关注的,所以我们将这些特殊字段放在外层,以保证输出深度不大于2的原则。一般的,我们在打印输出日志的时候,只须关注事件名称及数据字段即可。其他,我们可以在打印日志的方法中,通过访问上下文统一获取,计算,输出。
2. 日志改造输出
前面我们提到了如何定义一个日志事件, 那么,我们如何基于已有日志方案做升级,同时,兼容旧代码的日志调用方式。
升级关键节点的日志
// 改造前 logger.info('client-init => ' + JSON.stringfiy({ url, ip, browser, //... })); // 改造后 logger.info({ event: 'client-init', url, ip, browser, //... });
兼容旧的日志调用方式
logger.debug('checkLogin');
因为 winston 的 日志方法本身就支持 string 或者 object 的传入方式, 所以对于旧的字符串传入写法,formatter 接收到的实际上是{ level: 'debug', message: 'checkLogin' }。formatter 是 winston 的日志输出前调整日志格式的一道工序, 这一点使我们在日志输出前有机会将这类调用方式输出的日志,转为一个纯输出事件 -- 我们称它们为raw-log事件,而不需要修改调用方式。
改造日志输出格式