一、背景
随着互联网络的飞速发展,各行各业已经不限于知道信息,更是挖掘、把握住隐藏在信息后面的信息。海量的数据是一种宝贵的财富,如何按照不同维度、各种口径和规则从海量的、隐含的、杂乱的、重复的web日志或用户访问信息中发现、提炼、分析、统计出有用的知识和应用价值,进而提高服务质量,改进网站的结构和内容,挖掘出有意义的用户访问模式、规则以及相关的潜在用户群等是一件非常有意义的工作。
二、 原则
1.集中的日志服务器:在WEB集群节点越来越多的情况下,让开发及系统维护人员能很方便的查看日志信息。
2.日志信息输出策略:日志信息输出全而不乱,便于跟踪和分析问题。
3.关键业务的日志输出:基于数据采集、数据核查、系统安全等方面的考虑,关键业务系统对输出的日志信息有特殊的要求,需要做针对性的设计。
4.支持备份与保密机制:防止日志丢失,敏感信息应加密,分布式文件系统保证可靠性。
三、 日志框架
Java开发语言基于Slf4j,规范标准见本文八、标准规范
配置项自动加载
按时间切割日志,总体原则:文件大小大于100M切割一次,并定时迁移,基本格式为文件名.yyyy-MM-dd.自增长数字.log
错误日志单独放在一个文件,文件名统一命名为error.log
单条日志不能加有回车
catalina.out文件只打印系统日志(例如服务启动、停止日志)。禁止生产环境下,往catalina.out打印业务日志
禁止生产环境下,打印第三方依赖的debug、info日志
日志打印头定义中的每个字段按[]加空格分隔,日志头与日志体之间以“ - ”分隔
四、日志级别分类
日志为分trace、debug、info、warning、error、fatal六个级别,其中生产环境严禁打trace、debug日志
序号日志级别描述备注
1trace只是打印一些状态、提示信息,以便开发过程中观察,开发完成只限开放/测试环境,生产环境严禁打trace日志
2debug调试信息,可记录详细的业务处理步骤,以及当前的变量状态只限开放/测试环境,生产环境严禁打debug日志
3info有意义的事件信息,如程序启动、关闭事件、收到请求事件等
4warning警告信息,如接口的不当使用、运行状态不是期望的但仍可继续处理等
5error程序运行期的错误信息
数据可选项说明
可选项说明备注
M必选项必须包括此内容
C条件项在一定条件下,必须包括此内容
O可选项可有可无
五、日志格式
1、字段说明
以json格式提供监控,日志配置说明及代码样例,格式说明如下:
日志头格式:
除msg外,所有字段均采用“ [ ] ”做分隔,字段与字段之间用“ ”(空格)做分隔,具体内容请参照示例。msg中内容不能包含“[]”
[%{TimeStamp}] [%{ThreadName}][%{evn}] [%{LogLevel}][%{TraceId}] [%{SpanId}] [%{ParentId}] [%{ServerUrl}][%{Protocol}] [%{LogType}] - %msg%n
变量名描述是否强制示例
%{TimeStamp}时间戳M[2021-11-20 15:37:11.219]
%{ThreadName}线程名,用[]包含,强制要求统一M[http-nio-8080-exec-48]
%{evn}日志所属环境M[dev]、[test]、[uat]、[prod]
%{LogLevel}日志等级M[ERROR/WARN/INFO/DEBUG]
%{TraceId}唯一追踪字符串,可以用用户唯一标识,请求上下文唯一ID,与业务无关,不需要再拼接其它参数M
[03338aae9dd94fd6],对应MDC中的traceId
%{SpanId}当前事务中步骤唯一IDM[3916120105a8876c],对应MDC中的spanId
%{ParentId}当前事务上前一步骤唯一ID,通过此ID找前一步骤的信息,如果ID为空,则表示是第一步C[03338aae9dd94fd6],对应MDC中的parentId,非根节点下,必
选项;根节点下为空
%{ServerUrl}被请求服务的接口名、或者dubbo服务提供的接口名M[/cms/magic_goods/query]
%{Protocol}接口请求协议:HTTP、DUBBO、WEBSERVICEC[HTTP]、[DUBBO]、[WEBSERVICE]
[CONSOLE] 表示控制台执行的相关协议,如:定时任务、应用启动
%{LogType}日志类型,请求或响应,用[]包含C[request]、[response]、[app] 表示系统打印的记录日志
%{msg}JSON格式的业务日志M{"orderNo":"469070923081252174","resultCode":"1","randomNum":"GtTNxv4H4u"}
注意事项:
JSON日志中最好不要有嵌套, 内容不能包含“[]”
日志输出的字符集必须为UTF8
如JSON日志中某个字段值为数值时,不要对值加双引号。如"amount":199900,不要写成"amount":"199900"
2、Logback MDC参数清单
序号参数名称说明
1traceId唯一跟踪号
2spanId节点ID
3parentId父节点ID,根节点值为空
4serviceId接口名或者请求路径
5protocol接口请求协议
六、日志目录结构
日志目录为/logs/环境/xxxx/,其中xxxx为应用名称(如酒店应用名称为bdw-hotel),环境包含:dev、test、uat、product,xxxx下目录包含app、access、error等
子目录,其中强制输出项有app、access、interface、error、remote,而可选项有pool、other等,各子目录用途描述如下:
目录名称用途描述是否强制项备注
app记录业务详细信息,包括各个级别(开发、测试环境:如info、warn、debug等,生产环境下严禁打印debug日志),以方便定位问题是message 业务日志信息
access记录主要业务调用接口响应耗时、系统业务响应状态信息,用于运维监控是记录所有业务接口、内部调用等信息
error记录错误日志,包括业务错误日志、系统错误日志、堆栈日志等,是所有错误日志汇集是error message 具体异常信息
目录结构如下:
/logs/环境/应用名称/
备注:
环境:dev、test、uat、product
2. 应用名称:spring.application.name
|--bdx-hotel
|-- app
app.2021-01-03-12.0.log
app.2021-01-03-12.1.log
|-- access
access.2021-01-03-12.0.log
access.2021-01-03-12.1.log
|-- error
error.2021-01-03-12.0.log
error.2021-01-03-12.1.log
七、目录日志格式详解
1、access目录日志格式规范
接口日志直接打印为纯粹JSON格式。
一个完整的请求、响应,对应输出一条access监控日志。 一次完整的请求包含:a、收到请求,响应正常;b、收到请求,响应异常(长时间未处理,返回超时响应)。
包括上游系统请求当前系统,以及当前系统请求下游系统的(两条或以上access日志,通过类型区分当前系统、远程调用系统日志)。
例如:access目录中会有三条消息,interface收到一条请求及响应;发出两条remote请求(http、ws),则当前服务收到一次请求,发出两次请求记录,其中关于对端ip(ipAddress),interface收到的请求,打印的则是上游系统ip;remote发出去的请求,打印的则是下游系统的ip。
响应处理时间是以毫秒为单位。
接口请求时间、响应结束时间,要精确到毫秒。
根据各自业务特性,输出部分关键字段信息
字段名称属性是否可选备注
remoteIpString否对端ip地址或者远程ip地址,如:172.30.2.15
localIpString否本机ip,如:172.30.60.39
String否应用名称,如:bdx-hotel
functionString否接口名称/方法名,如:OnlineUnifiedTradeApi_publicPay
methodString否get、post、put、delete等
startTimeString否开始时间,格式:yyyy-MM-dd hh:MM:ss SSS
endTimeString否结束时间,格式:yyyy-MM-dd hh:MM:ss SSS
timeDiffString否接口总耗时,单位:毫秒
traceIdString否唯一追踪标识符,对应MDC中traceId
parentIdString是当前节点父节点ID,对应MDC中parentId,如果为空表示根节点
spanIdString否当前节点ID,对应MDC中spanId
codeString否接口结果: 0:失败, 1:成功
errorCodeString是返回错误码
errorDescString是对内错误描述
例:
{"remoteIp":"172.30.2.15","localIp":"172.30.60.39","applicationName":"bdx-hotel","functionName":"OnlineUnifiedTradeApi_publicPay","method":"post","startTime":"2021-12-20 15:56:27 020","endTime":"2021-12-20 15:56:30 410","timeDiff":"2534","traceId":"03338aae9dd94fd6","parentId":"", "spanId":"5b958fae9f633df8","code":"0","errorCode":"GA-0001","errorDesc":""}
2、APP目录日志格式规范
sql语句要通过debug级别打印出来(生产环境禁止打印SQL)。
打印应用服务所有业务日志,包括异常堆栈日志、业务逻辑处理日志。
ps:app输出的是业务堆栈日志,各个系统堆栈描述不一样,所以[%{ServerUrl}] [%{Protocol}][%{LogType}] 这三项会出现在有的系统没有的现象
例:[%{TimeStamp}] [%{ThreadName}][%{evn}] [%{LogLevel}][%{TraceId}] [%{SpanId}] [%{ParentId}] [%{ServerUrl}][%{Protocol}] [%{LogType}] - %msg%n
[2021-11-23 15:05:23:768] [thread-591][uat][INFO] [30033fddb3b11f07] [0fea249efb0034f3] [""] [/cms/magic_goods/query][request] -
{"header":{\"content-length\":\"181\",\"host\":\"10.0.0.31:20310\",\"content-type\":\"application/json;charset=UTF-8\",\"connection\":\"Keep-Alive\",\"accept\":\"*/*\",\"user-agent\":\"Apache-HttpClient/4.5.6 (Java/1.8.0_181)\"},"body":{\"account\":\"taobao20\",\"cache\":false,\"channelConfirmId\":\"1585842996424404799\",\"hotels\":\"FCHNYG\",\"sender\":\"\",\"sksDataSource\":\"GREEN_CLOUD\",\"unionCode\":\"157e0233d0f14e39b55a587fb2ba6d9a\"}
},"param":{\"appkey\":[\"300005\"],\"timestamp\":[\"1655867079166\"],\"token\":[\"352E1E75CA11530995CF9F8EA51C8277\"]}
}
[2021-11-23 15:05:23:768] [thread-591][uat][INFO] [30033fddb3b11f07] [0fea249efb0034f3] [""] [/cms/magic_goods/query][response] -
{"code":"1","errorCode":"GA-0001","errorDesc":"",
"data":{"orderDetail":{"settleFlag":0,"orderId":"4c9284d1-f0fa-47f1-b235- ed32921f177","traceNo":"774394941529210612","merchantName":"","outTradeNo":"114884830253056","tradeType":"31","terminalNo":"
00210101018330000062","amount":1000000,"orderNo":"774394941529210612","estimateClearTime":"2017-11-21 15:05:28","estimateSettleTime":"2017-11-21","tradeState":"0","tradeTime":"2017-11-21 15:05:28","kqDiscountAmount":0,"tradeStatus":"0","paymentMethod":9,"merchantNo":"001440395002090"}
}
}
3、error目录日志格式规范:
打印所有异常堆栈日志
[2021-11-23 14:58:59:343] [icb-payee-8][uat][ERROR] [OkHttpUtils] [30033fddb3b11f07] [0fea249efb0034f3]
[30033fddb3b11f07] [RiskBaseServiceImpl] [CASHBOX_Q_TRADE_WATER_DETAIL_V30] - getRiskInf error: Connection
refused
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_91]
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_91]
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[na:1.8.0_91]
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[na:1.8.0_91]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_91]
at java.net.Socket.connect(Socket.java:589) ~[na:1.8.0_91]
at com.squareup.okhttp.internal.Platform.connectSocket(Platform.java:100) ~[okhttp-2.5.0.jar:na]
八. 代码日志规范
1. 本地日志存放目录:
/logs/环境/应用名称/;
备注:
环境:dev、test、uat、product
2. 日志文件
1.命名:目录名称_%d{yyyy-MM-dd}.%i.log 备注:目录名称:app、access、interface、error、remote、pool、other等
2.单大小:100M
3. 本地本周生命:2天
4. 分布式日志生命:保存30天,因为有些异常具备以“周”为频次发生的特点
5. 归档:每天做一次归档,归档前需要对日志文件进行压缩
3. 日志系统操作权限:只能搜索查看日志,不能修改或删除日志
4. 代码日志:
【强制】对trace/debug/info级别的日志输出,必须使用条件输出形式或者使用占位符的方式。
logger.debug("Processing trade with id: {} symbol : {} ", id, symbol);
【强制】debug/info级别的信息,信息本身需要计算或合并的,必须加 isXxxEnabled() 判断在前,这样可以大大提高高并发下的效率。如果不加 isXxxEnabled() 判断,"Processing trade with id: " + id + " symbol: " + symbol在info级别下也会执行
说明:logger.debug("Processing trade with id: " + id + " symbol: " + symbol); 如果日志级别是warn,上述日志不会打印,但是会执行字符串拼接操作,如果symbol是对象,会执行toString()方法,浪费了系统资源,执行了上述操作,最终日志却没有 打印。
if (logger.isDebugEnabled()) {
logger.debug("Processing trade with id: " + id + " symbol: " + symbol);
}
【强制】避免重复打印日志,浪费磁盘空间,务必在log4j.xml中设置additivity=false。
<logger name="com.taobao.dubbo.config" additivity="false">
【强制】异常信息应该包括两类信息:案发现场信息和异常堆栈信息。如果不处理,那么通过关键字throws往上抛出。
logger.error(各类参数或者对象toString + "_" + e.getMessage(), e);
【推荐】谨慎地记录日志。生产环境禁止输出debug日志;有选择地输出info日志;如果使用warn来记录刚上线时的业务行为信息,一定要注意日志输出量的问题,避免把服务器磁盘撑爆,并记得及时删除这些观察日志。
说明:大量地输出无效日志,不利于系统性能提升,也不利于快速定位错误点。记录日志时请思考:这些日志真的有人看吗?看到这条日志你能做什么?能不能给问题排查带来好处?
【推荐】Web日志记录了用户对网站的每一次点击访问,即每一次接口的调用。但由于各种原因,web日志中有些记录是缺失或不完整的数据,推荐在每个接口调用后,在其入口输出调用类名及输入参数的日志,以及接口结束前输出返回数据的日志,
并 使用info级别。另外,重要方法入口,业务流程前后及处理的结果等,推荐记录log,并使用debug级别,因为对于非开发人员掌控的环境(无法做DEBUG),记录方法调用、入参、返回值的方式对于排查问题会有很大帮助。
【强制】禁止使用JDK Console输出(System.out, System.err, ex.printStackTrace(), etc.),应使用logger.debug、logger.error,输出到文本文件(TextFiles)的日志。
【强制】关注日志记录对于系统性能、安全性的影响,不要多次重复记录日志。日志记录太过于频繁,日志记录到文件IO或者数据库都是很费CPU和内存资源的事,会对系统的性能产生影响。关注日志是否会被恶意攻击频繁打印日志,使得日志文件超过100G、500G直到磁盘容量爆满,服务器挂掉。
【强制】记录要精简、不滥用日志,关注日志记录的正确性和必要性。分清楚什么时候应该记录日志,什么时候不需要记录日志。什么是TRACE、DEBUG信息,什么是INFO、ERROR信息。对于异常处理,不要多次重复的记录同一个异常的堆栈信息。比如在DAO层记录了异常堆栈信息,然后抛出异常,在web层catch了异常之后,又记录了一次异常堆栈信息。
【强制】在日志信息上添加便于检阅、查找的额外标识。每条日志都应有关键标识,能够尽快定位某条信息的位置。包括日期和时间,程序Java类的名称、方法甚至行号,错误类型或者错误代码。否则前端web页面报错,告诉开发人员去查找问题,开发人员很难去查找当时的操作日志或者异常信息。
【强制】注意error和warn级别的区别,导致业务不正常服务的,用error级别;错误是预期会发生的,并且已经有了其他的处理流程,使用warn级别。
【强制】Log的内容须确保不会因为Log语句的问题而抛出异常造成中断,如下有可能会抛出NullPointerException:
log.debug("Processing request with id: {}", request.getId());
【推荐】用户操作日志。用户操作日志面临记录频繁、数据结构异常多、数据流量非常大、数据价值如何提高等问题。在记录用户的操作日志尽量不要浪费系统的额外性能开销,但是我们记录的信息要方便下一步的数据挖掘用户行为分析。
(1)频繁记录日志会导致系统IO的消耗,我们可以采用Redis或memcached这一类内出数据库先行记录日志当量达到一定规模自动记录到日志文件中避免平凡调用IO进行文件数据写入或数据库写入。
(2)定义统一的数据结构,这样做的目的是为了能够方便使用相应的工具进行用户操作日志挖掘。
(3)提高用户数据价值,目的是为了提高分析用户数据,分析用户数据是为了分析出一种或几种用户行为模式。要做到易于分析用户模式需要建立相应的操作日志记录结构,规定好结构进行分析就降低了复杂度。
【推荐】当程序产生异常时,必须捕捉并处理异常、将异常记录到日志中(除非打算抛出异常),捕获异常后不处理也不输出log是一种非常不负责任的行为,这会造成问题很难被定位,极大地提高调试的成本。
如果确实有很多异常类型首先考虑用异常 描述来区别,throws/exception子句标明的异常最好不要超过三个。记录异常不要保存exception.getMessage(),而要记录exception.toString()
e.getMessage()、e.toString()、e.printStackTrace()三者的区别:
e.toString()获取的信息包括异常类型和异常详细消息;
e.getMessage()只是获取了异常的详细消息字符串;
e.printStackTrace();会打出详细异常,异常名称,出错位置,便于调试用,一般一个异常至少几十行。
try {
m = 1/0;
} catch (Exception e) {
System.out.println(e.toString());
System.out.println(e.getMessage());
}
输出结果: java.lang.ArithmeticException: / by zero
/ by zero
【推荐】日志信息中尽量包含数据和描述:easy to read, easy to parse,开发人员不能为了自己查找信息方便,输出类似“!@#$%”的Log。
【强制】日志记录必须支持多线程。当应用程序同时处理多个客户的请求时,不同客户之间的日志信息写同一个日志文件时不应产生冲突,不同请求的日志信息能被显示并区分出来。
【强制】日志不能包含类似上传下载文件内容
5. 日志内容存放系统:阿里云
日志系统呈现如下:
6.阿里云日志流程