网易视频云分享：最佳日志实践

vcloud.163.com网易视频云分享：最佳日志实践易视频云是网易倾力打造的一款基于云计算的分布式多媒体处理集群和专业音视频技术，提供稳定流畅、低时延、高并发的视频直播、录制、存储、转码及点播等音视频的PAAS服务，在线教育、远程医疗、娱乐秀场、在线金融等各行业及企业用户只需经过简单的开发即可打造在线音视频平台。现在，网易视频云的技术专家给大家分享一则技术文：最佳日志实践。前言日志用来记录用户操作、系统运行状态等，是一个系统的重要组成部分。然而由于日志并非系统核心功能，通常情况下并不受团队的重视。在出现问题需要通过日志来定位时，才发现日志还存在很多问题。日志记录的好坏直接关系到系统出现问题时定位的速度，同时可以通过对日志的观察和分析，提前发现系统可能的风险，避免线上事故的发生。我们在开发和运维NOS（网易对象存储，NeteaseObjectStorage）的过程中，对整个系统的日志进行了分析优化，积累出一些经验，归纳如下。相关问题经验整理1.关于日志级别我们通常使用的日志库（如log4j等），将日志基本分为以下几类（从低到高）：TRACE–TheTRACELeveldesignatesfiner-grainedinformationaleventsthantheDEBUGvcloud.163.comDEBUG–TheDEBUGLeveldesignatesfine-grainedinformationaleventsthataremostusefultodebuganapplication.INFO–TheINFOleveldesignatesinformationalmessagesthathighlighttheprogressoftheapplicationatcoarse-grainedlevel.WARN–TheWARNleveldesignatespotentiallyharmfulsituations.ERROR–TheERRORleveldesignateserroreventsthatmightstillallowtheapplicationtocontinuerunning.FATAL–TheFATALleveldesignatesverysevereerroreventsthatwillpresumablyleadtheapplicationtoabort.尽管log4j官方文档对各个日志级别进行了简单定义。然而在实践中，究竟哪些操作需要记入日志，哪种错误应该记为WARN级别，而哪种错误又为ERROR级别，还需要进行进一步讨论。关于该问题，在StackOverflow上有一个讨论贴进行过讨论。此处对贴子中的一些观点，加上我们在平时运维过程中遇到的相关问题进行归纳：一个项目各个log级别的定义应该是清楚明确的，是每个开发人员所遵循的；即使是TRACE或者DEBUG级别的日志，也应该有一定的规范，要保证除了开发人员自己以外，包括测试人员和运维人员都可以方便地通过日志定位问题；对于日志级别的分类，有以下参考：FATAL—表示需要立即被处理的系统级错误。当该错误发生时，表示服务已经出现了某种程度的不可用，系统管理员需要立即介入。这属于最严重的日志级别，因此该日志级别必须慎用，如果这种级别的日志经常出现，则该日志也失去了意义。通常vcloud.163.com情况下，一个进程的生命周期中应该只记录一次FATAL级别的日志，即该进程遇到无法恢复的错误而退出时。当然，如果某个系统的子系统遇到了不可恢复的错误，那该子系统的调用方也可以记入FATAL级别日志，以便通过日志报警提醒系统管理员修复；ERROR—该级别的错误也需要马上被处理，但是紧急程度要低于FATAL级别。当ERROR错误发生时，已经影响了用户的正常访问。从该意义上来说，实际上ERROR错误和FATAL错误对用户的影响是相当的。FATAL相当于服务已经挂了，而ERROR相当于好死不如赖活着，然而活着却无法提供正常的服务，只能不断地打印ERROR日志。特别需要注意的是，ERROR和FATAL都属于服务器自己的异常，是需要马上得到人工介入并处理的。而对于用户自己操作不当，如请求参数错误等等，是绝对不应该记为ERROR日志的；WARN—该日志表示系统可能出现问题，也可能没有，这种情况如网络的波动等。对于那些目前还不是错误，然而不及时处理也会变为错误的情况，也可以记为WARN日志，例如一个存储系统的磁盘使用量超过阀值，或者系统中某个用户的存储配额快用完等等。对于WARN级别的日志，虽然不需要系统管理员马上处理，也是需要即使查看并处理的。因此此种级别的日志也不应太多，能不打WARN级别的日志，就尽量不要打；INFO—该种日志记录系统的正常运行状态，例如某个子系统的初始化，某个请求的成功执行等等。通过查看INFO级别的日志，可以很快地对系统中出现的WARN,ERROR,FATAL错误进行定位。INFO日志不宜过多，通常情况下，INFO级别的日志应该不大于TRACE日志的10%；vcloud.163.comDEBUGorTRACE—这两种日志具体的规范应该由项目组自己定义，该级别日志的主要作用是对系统每一步的运行状态进行精确的记录。通过该种日志，可以查看某一个操作每一步的执行过程，可以准确定位是何种操作，何种参数，何种顺序导致了某种错误的发生。可以保证在不重现错误的情况下，也可以通过DEBUG（或TRACE）级别的日志对问题进行诊断。需要注意的是，DEBUG日志也需要规范日志格式，应该保证除了记录日志的开发人员自己外，其他的如运维，测试人员等也可以通过DEBUG（或TRACE）日志来定位问题；Rule1：整个团队（包括运维人员）需要对日志级别有明确的规定，什么日志记入什么级别的日志，什么级别的错误出现要如何处理等2.对记录的日志要进行更新维护由于DEBUG（或TRACE）级别的日志对于定位问题至关重要，因此该种日志记录是否完备且不冗余、格式是否规范等也需要花费大量精力来优化。此处有以下几个比较好的实践：定义好整个团队记录DEBUG（或TRACE）日志的规范，保证每个开发记录的日志格式统一；整个团队（包括开发，运维和测试）定期对记录的日志内容进行Review；开发做运维，通过在查问题的过程来优化日志记录的方式；运维或测试在日志中发现的问题，都需要及时向开发人员反映；Rule2：需要定期对日志内容进行优化更新，目的就是通过日志快速准确的定位问题3.关于日志分类日志从功能来说，可分为诊断日志、统计日志、审计日志。vcloud.163.com诊断日志，典型的有：请求入口和出口外部服务调用和返回资源消耗操作:打开文件等容错行为：譬如云硬盘的副本修复操作程序异常：譬如数据库无法连接后台操作：清理程序启动、关闭、配置加载抛出异常时，不记录日志统计日志：用户访问统计计费日志（如记录用户使用的网络资源或磁盘占用，格式较为严格，便于统计）审计日志：管理操作将不同需求的日志记入到不同的日志文件中，可以方便相关问题（管理平台操作审计，用户操作计费等）的处理。针对每一种需求，需要对日志的格式，日志记录的内容等进行特别的记录。Rule3：要明确不同日志的用途，对日志内容进行分类4.日志中不要记录无用信息在很多应用中，用户都需要通过Fuse方式来挂载使用NOS。vcloud.163.comPOSIX标准中文件系统接口不允许文件/a与目录/a/同时存在，而NOS作为对象存储系统，/a和/a/是不同的对象，是能够同时存在的，一般地，NOS中我们会规定/a/是目录，/a是文件，目录对象大小为0。POSIX标准对文件的getattr操作，无论是/a还是/a/，对应的请求都是/a。为了避免遗漏，需分别向NOS请求HeadObject(“/a“)和HeadObject(“/a/“)。如果命中/a，说明/a是一个文件，不用再请求getattr(“/a/“)。因此当用户访问*/a/b/c.txt*时，实际上向NOS发送了以下请求：#HeadObject(“/a”)#HeadObject(“/a/”)#HeadObject(“/a/b”)#HeadObject(“/a/b/”)#HeadObject(“/a/b/c.txt”)对于上面的请求，实际上HeadObject(“/a”)和HeadObject(“/a/b”)都会返回NoSuchKey错误，而Fuse正是该错误来判断该文件不存在，而可能是个目录的。然而对于NOS来说，这将导致产生大量无意义的NoSuchKey日志（整个日志文件的80%都是该错误日志）。这些日志对于开发人员进行日志观察，运维人员定位问题，日志监控等都造成了困难。Rule4:绝不要打印没有用的日志，防止无用日志淹没重要信息解决办法：Fuse请求时，在Http头部加入User-Agent字段，当NOS发现请求是Fuse发过来的且为HeadObject操作且为NoSuchKey错误时，则不打印错误日志。5.日志记录信息要完整vcloud.163.com问题描述：NOS提供分块上传的接口，用户可以通过以下的调用序列，来实现一次分块上传的流程：InitMultiUpload（生成一个UploadID）UploadPartUploadPart……UploadPartCompleteMultiUpload（AbortMultiUpload）之前在某个产品上线初期，由于其开发人员对NOS的熟悉程度不够等原因。出现过如下问题：客户端常常会收到NoSuchUpload的错误。该错误出现的原因是，用户在未调用InitMultiUpload之前，或者在调用了CompleteMultiUpload（AbortMultiUpload）之后再次调用UploadPart。然而当我们查日志，希望可以看到该UploadPart请求对哪个UploadID进行操作，该UploadID又对应哪些操作时，却发现我们的日志中没有记录UploadPart请求对应的UploadID。类似的问题还有很多，很多针对特定请求的日志缺失，导致很多问题无法定位。因此，需要进一步对日志中需要记录哪些内容进行规定，此处推荐的需要在日志中记录的内容有：在系统启动或初始化时记录重要的系统初始化参数记录系统运行过程中的所有的错误vcloud.163.com记录系统运行过程中的所有的警告在持久化数据修改时记录修改前和修改后的值记录系统各主要模块之间的请求和响应（如在NOS中的视频处理模块在接收到请求和发送应答时，或者向客户端发送回调请求时）重要的状态变化（如NOS中对系统白名单的修改等）系统中一些长期执行的任务的执行进度而不推荐记录日志的内容有：函数入口信息——除非该函数入口表示了一个重要事件的开始，或者将该信息记入DEBUG级别日志文件内容或者一大段消息的内容——如果实在需要记录，则可以截取其中一些重要的信息来记入日志“良性”错误——有时候虽然出现了错误，然而错误处理的流程可以正确解决这种情况，例如插入数据库时有重复的记录，尽管是个错误，然而错误处理流程可以对这种情况进行处理Rule5：日志信息要准确全面，能做到仅凭日志就可以定位问题解决办法：整理所有的请求处理流程，针对每一个操作（去重，分块上传……）打印特定的日志。6.测试的日志测试代码（单元测试，接口测试……）的日志同样重要。特别是，当一个测试失败时，可以通过日志很快确定是测试代码有问题，还是系统出现了故障，如果做不到这一点，那就需要优化测试的日志了。vcloud.163.com测试日志应该包含以下内容：测试执行的环境测试执行前的初始状态测试的详细步骤测试和系统的交互信息测试期望的返回结果测试实际的返回结果Rule6：要以同样严格的要求对待测试程序的日志7.从问题中完善日志在线上出现问题的时候，需要尽快发现问题并解决，而同时，需要借此机会好好思考一下当前系统的日志是否合理。需要考虑以下问题：如果定位问题花费了很长